diff --git a/src/balena-model.ts b/src/balena-model.ts index 1e16a7524..13aa172a5 100644 --- a/src/balena-model.ts +++ b/src/balena-model.ts @@ -682,6 +682,7 @@ export interface Device { id: Types['Serial']['Read']; actor: { __id: Actor['Read']['id'] } | [Actor['Read']]; api_heartbeat_state: 'online' | 'offline' | 'timeout' | 'unknown'; + changed_api_heartbeat_state_on__date: Types['Date Time']['Read'] | null; uuid: Types['Text']['Read']; local_id: Types['Short Text']['Read'] | null; device_name: Types['Short Text']['Read'] | null; @@ -786,6 +787,7 @@ export interface Device { id: Types['Serial']['Write']; actor: Actor['Write']['id']; api_heartbeat_state: 'online' | 'offline' | 'timeout' | 'unknown'; + changed_api_heartbeat_state_on__date: Types['Date Time']['Write'] | null; uuid: Types['Text']['Write']; local_id: Types['Short Text']['Write'] | null; device_name: Types['Short Text']['Write'] | null; diff --git a/src/balena.sbvr b/src/balena.sbvr index e68c4aa32..df01337f3 100644 --- a/src/balena.sbvr +++ b/src/balena.sbvr @@ -374,6 +374,9 @@ Term: device Necessity: each device has exactly one api heartbeat state Definition: "online" or "offline" or "timeout" or "unknown" + Fact type: device [changed api heartbeat state on] date + Necessity: each device [changed api heartbeat state on] at most one date. + Fact type: device has env var name Term Form: device environment variable Database Table Name: device environment variable @@ -451,7 +454,7 @@ Fact type: user (Auth) has public key -- user public key Fact type: user public key has title - Necessity: each user public key has exactly one title + Necessity: each user public key has exactly one title -- application type diff --git a/src/features/device-heartbeat/index.ts b/src/features/device-heartbeat/index.ts index 9db0f45d6..74edfa284 100644 --- a/src/features/device-heartbeat/index.ts +++ b/src/features/device-heartbeat/index.ts @@ -250,7 +250,7 @@ export class DeviceOnlineStateManager extends EventEmitter<{ try { // patch the api_heartbeat_state value to the new state... - const body = { + const baseBody = { api_heartbeat_state: newState, }; await api.resin.patch({ @@ -259,10 +259,17 @@ export class DeviceOnlineStateManager extends EventEmitter<{ id: deviceId, options: { $filter: { - $not: body, + $not: baseBody, }, }, - body, + body: { + ...baseBody, + // Since the heartbeat manager is the only place that we update the heartbeat state + // we are updating the heartbeat's change date in here rather than a hook, so that + // we can avoid the extra DB request that a generic hook would require for checking + // whether the value actually changed or not. + changed_api_heartbeat_state_on__date: Date.now(), + }, }); } catch ($err) { err = $err; diff --git a/src/migrations/00093-device-last-api-heartbeat-state-change-event.sql b/src/migrations/00093-device-last-api-heartbeat-state-change-event.sql new file mode 100644 index 000000000..52345a08d --- /dev/null +++ b/src/migrations/00093-device-last-api-heartbeat-state-change-event.sql @@ -0,0 +1,2 @@ +ALTER TABLE "device" +ADD COLUMN IF NOT EXISTS "changed api heartbeat state on-date" TIMESTAMP NULL; diff --git a/src/translations/v7/v7.sbvr b/src/translations/v7/v7.sbvr index 59433dbd5..6f5aa3ab8 100644 --- a/src/translations/v7/v7.sbvr +++ b/src/translations/v7/v7.sbvr @@ -379,6 +379,9 @@ Term: device Necessity: each device has exactly one api heartbeat state Definition: "online" or "offline" or "timeout" or "unknown" + Fact type: device [changed api heartbeat state on] date + Necessity: each device [changed api heartbeat state on] at most one date. + Fact type: device has env var name Term Form: device environment variable Database Table Name: device environment variable diff --git a/test/03_device-state.ts b/test/03_device-state.ts index 15832b7b3..03bab0446 100644 --- a/test/03_device-state.ts +++ b/test/03_device-state.ts @@ -11,7 +11,10 @@ import * as config from '../src/lib/config.js'; import * as stateMock from '../src/features/device-heartbeat/index.js'; import { assertExists, itExpectsError, waitFor } from './test-lib/common.js'; import * as fixtures from './test-lib/fixtures.js'; -import { expectResourceToMatch } from './test-lib/api-helpers.js'; +import { + expectResourceToMatch, + thatIsDateStringAfter, +} from './test-lib/api-helpers.js'; import { redis, redisRO } from '../src/infra/redis/index.js'; import { setTimeout } from 'timers/promises'; import { MINUTES, SECONDS } from '@balena/env-parsing'; @@ -253,7 +256,10 @@ export default () => { [ { tokenType: 'device API Key', - getActor: () => device, + getPineActor: () => + pineTest.clone({ + passthrough: { user: device }, + }), heartbeatAfterGet: DeviceOnlineStates.Online, getDevice: () => device, getState: () => @@ -261,7 +267,10 @@ export default () => { }, { tokenType: 'user token', - getActor: () => admin, + getPineActor: () => + pineTest.clone({ + passthrough: { user: admin }, + }), heartbeatAfterGet: DeviceOnlineStates.Unknown, getDevice: () => deviceUserRequestedState, getState: () => @@ -274,27 +283,44 @@ export default () => { ].forEach( ({ tokenType, - getActor, + getPineActor, heartbeatAfterGet, getDevice, getState, }) => { describe(`Given a ${tokenType}`, function () { it('Should see state initially as "unknown"', async () => { - const { body } = await supertest(getActor()) - .get(`/${version}/device(${getDevice().id})`) - .expect(200); - - assertExists(body.d[0]); - expect(body.d[0]).to.have.property( - 'api_heartbeat_state', - DeviceOnlineStates.Unknown, - 'API heartbeat state is not unknown (default)', + await expectResourceToMatch( + getPineActor(), + 'device', + getDevice().id, + { + api_heartbeat_state: DeviceOnlineStates.Unknown, + ...(versions.gte(version, 'v7') && { + changed_api_heartbeat_state_on__date: null, + }), + }, ); }); + if (versions.lte(version, 'v6')) { + it('Should not be able to retrieve the changed_api_heartbeat_state_on__date property', async () => { + const { body } = await pineUser + .get({ + resource: 'device', + id: getDevice().id, + }) + .expect(200); + expect(body).to.have.property('api_heartbeat_state'); + expect(body).to.not.have.property( + 'changed_api_heartbeat_state_on__date', + ); + }); + } + it(`Should have the "${heartbeatAfterGet}" heartbeat state after a state poll`, async () => { stateChangeEventSpy.resetHistory(); + const stateUpdatedAfter = Date.now(); await getState(); if (heartbeatAfterGet !== DeviceOnlineStates.Unknown) { @@ -312,15 +338,19 @@ export default () => { : undefined, ); - const { body } = await supertest(getActor()) - .get(`/${version}/device(${getDevice().id})`) - .expect(200); - - assertExists(body.d[0]); - expect(body.d[0]).to.have.property( - 'api_heartbeat_state', - heartbeatAfterGet, - `API heartbeat state is not ${heartbeatAfterGet}`, + await expectResourceToMatch( + getPineActor(), + 'device', + getDevice().id, + { + api_heartbeat_state: heartbeatAfterGet, + ...(versions.gte(version, 'v7') && { + changed_api_heartbeat_state_on__date: + heartbeatAfterGet === DeviceOnlineStates.Unknown + ? null + : thatIsDateStringAfter(stateUpdatedAfter), + }), + }, ); }); @@ -332,31 +362,45 @@ export default () => { devicePollInterval / 1000 } seconds`, async () => { stateChangeEventSpy.resetHistory(); + let stateUpdatedAfter = Date.now(); await setTimeout(devicePollInterval); await waitFor({ - checkFn: () => stateChangeEventSpy.called, + checkFn: () => { + if (stateChangeEventSpy.called) { + return true; + } + stateUpdatedAfter = Math.max( + // The 10ms are there to account for concurrency between + // the spy check and the DB commiting the TX. + Date.now() - 10, + stateUpdatedAfter, + ); + return false; + }, }); expect(tracker.states[getDevice().id]).to.equal( DeviceOnlineStates.Timeout, ); - const { body } = await supertest(getActor()) - .get(`/${version}/device(${getDevice().id})`) - .expect(200); - - assertExists(body.d[0]); - expect(body.d[0]).to.have.property( - 'api_heartbeat_state', - DeviceOnlineStates.Timeout, - 'API heartbeat state is not timeout', + await expectResourceToMatch( + getPineActor(), + 'device', + getDevice().id, + { + api_heartbeat_state: DeviceOnlineStates.Timeout, + ...(versions.gte(version, 'v7') && { + changed_api_heartbeat_state_on__date: + thatIsDateStringAfter(stateUpdatedAfter), + }), + }, ); }); it(`Should see state become "online" again, following a state poll`, async () => { stateChangeEventSpy.resetHistory(); - + const stateUpdatedAfter = Date.now(); await getState(); await waitFor({ @@ -367,15 +411,17 @@ export default () => { DeviceOnlineStates.Online, ); - const { body } = await supertest(getActor()) - .get(`/${version}/device(${getDevice().id})`) - .expect(200); - - assertExists(body.d[0]); - expect(body.d[0]).to.have.property( - 'api_heartbeat_state', - DeviceOnlineStates.Online, - 'API heartbeat state is not online', + await expectResourceToMatch( + getPineActor(), + 'device', + getDevice().id, + { + api_heartbeat_state: DeviceOnlineStates.Online, + ...(versions.gte(version, 'v7') && { + changed_api_heartbeat_state_on__date: + thatIsDateStringAfter(stateUpdatedAfter), + }), + }, ); }); @@ -383,27 +429,40 @@ export default () => { TIMEOUT_SEC + devicePollInterval / 1000 } seconds`, async () => { stateChangeEventSpy.resetHistory(); - + let stateUpdatedAfter = Date.now(); await setTimeout(devicePollInterval + TIMEOUT_SEC * 1000); // it will be called for TIMEOUT and OFFLINE... await waitFor({ - checkFn: () => stateChangeEventSpy.calledTwice, + checkFn: () => { + if (stateChangeEventSpy.calledTwice) { + return true; + } + stateUpdatedAfter = Math.max( + // The 10ms are there to account for concurrency between + // the spy check and the DB commiting the TX. + Date.now() - 10, + stateUpdatedAfter, + ); + return false; + }, }); expect(tracker.states[getDevice().id]).to.equal( DeviceOnlineStates.Offline, ); - const { body } = await supertest(getActor()) - .get(`/${version}/device(${getDevice().id})`) - .expect(200); - - assertExists(body.d[0]); - expect(body.d[0]).to.have.property( - 'api_heartbeat_state', - DeviceOnlineStates.Offline, - 'API heartbeat state is not offline', + await expectResourceToMatch( + getPineActor(), + 'device', + getDevice().id, + { + api_heartbeat_state: DeviceOnlineStates.Offline, + ...(versions.gte(version, 'v7') && { + changed_api_heartbeat_state_on__date: + thatIsDateStringAfter(stateUpdatedAfter), + }), + }, ); }); }); @@ -443,16 +502,9 @@ export default () => { DeviceOnlineStates.Offline, ); - const { body } = await supertest(admin) - .get(`/${version}/device(${device.id})`) - .expect(200); - - assertExists(body.d[0]); - expect(body.d[0]).to.have.property( - 'api_heartbeat_state', - DeviceOnlineStates.Offline, - 'API heartbeat state changed using an expired api key', - ); + await expectResourceToMatch(pineUser, 'device', device.id, { + api_heartbeat_state: DeviceOnlineStates.Offline, + }); }); it(`should see state become "online" again following a state poll after removing the expiry date from the api key`, async () => { @@ -481,16 +533,9 @@ export default () => { DeviceOnlineStates.Online, ); - const { body } = await supertest(admin) - .get(`/${version}/device(${device.id})`) - .expect(200); - - assertExists(body.d[0]); - expect(body.d[0]).to.have.property( - 'api_heartbeat_state', - DeviceOnlineStates.Online, - 'API heartbeat state is not online', - ); + await expectResourceToMatch(pineUser, 'device', device.id, { + api_heartbeat_state: DeviceOnlineStates.Online, + }); }); }); }); @@ -499,6 +544,26 @@ export default () => { let device2: fakeDevice.Device; const device2ChangeEventSpy = sinon.spy(); let lastPersistedTimestamp: number | undefined; + let lastApiHeartbeatStateChangeEvent: string | null; + + async function getLastApiHeartbeatStateChangeEvent( + id: number, + ): Promise { + if (versions.lte(version, 'v6')) { + return null; + } + const { body } = await pineUser + .get({ + resource: 'device', + id, + options: { + $select: 'changed_api_heartbeat_state_on__date', + }, + }) + .expect(200); + assertExists(body); + return body.changed_api_heartbeat_state_on__date; + } before(async () => { device2 = await fakeDevice.provisionDevice(admin, applicationId); @@ -510,6 +575,9 @@ export default () => { }); await expectResourceToMatch(pineUser, 'device', device2.id, { api_heartbeat_state: DeviceOnlineStates.Unknown, + ...(versions.gte(version, 'v7') && { + changed_api_heartbeat_state_on__date: null, + }), }); }); beforeEach(function () { @@ -526,9 +594,21 @@ export default () => { it('The initial state poll should update the DB heartbeat to Online', async () => { await fakeDevice.getState(device2, device2.uuid, stateVersion); await waitFor({ checkFn: () => device2ChangeEventSpy.called }); - await expectResourceToMatch(pineUser, 'device', device2.id, { - api_heartbeat_state: DeviceOnlineStates.Online, - }); + const fetchedDevice = await expectResourceToMatch( + pineUser, + 'device', + device2.id, + { + api_heartbeat_state: DeviceOnlineStates.Online, + ...(versions.gte(version, 'v7') && { + changed_api_heartbeat_state_on__date: (prop) => + prop.that.is.a('string'), + }), + }, + ); + + lastApiHeartbeatStateChangeEvent = + fetchedDevice.changed_api_heartbeat_state_on__date; }); it('should not update the DB heartbeat on subsequent polls', async () => { @@ -537,6 +617,14 @@ export default () => { await setTimeout(1000); expect(tracker.states[device2.id]).to.be.undefined; expect(device2ChangeEventSpy.called).to.be.false; + + await expectResourceToMatch(pineUser, 'device', device2.id, { + api_heartbeat_state: DeviceOnlineStates.Online, + ...(versions.gte(version, 'v7') && { + changed_api_heartbeat_state_on__date: + lastApiHeartbeatStateChangeEvent, + }), + }); }); it('will trust Redis and not update the DB heartbeat on subsequent polls even if the DB has diverged :(', async () => { @@ -547,12 +635,19 @@ export default () => { api_heartbeat_state: DeviceOnlineStates.Offline, }, }); + lastApiHeartbeatStateChangeEvent = + await getLastApiHeartbeatStateChangeEvent(device2.id); + await fakeDevice.getState(device2, device2.uuid, stateVersion); await setTimeout(1000); expect(tracker.states[device2.id]).to.be.undefined; expect(device2ChangeEventSpy.called).to.be.false; await expectResourceToMatch(pineUser, 'device', device2.id, { api_heartbeat_state: DeviceOnlineStates.Offline, + ...(versions.gte(version, 'v7') && { + changed_api_heartbeat_state_on__date: + lastApiHeartbeatStateChangeEvent, + }), }); }); @@ -814,6 +909,8 @@ export default () => { api_heartbeat_state: DeviceOnlineStates.Unknown, }, }); + lastApiHeartbeatStateChangeEvent = + await getLastApiHeartbeatStateChangeEvent(device2.id); }); it('should update the DB heartbeat on the first request that finds the ttl being null', async () => { @@ -821,6 +918,11 @@ export default () => { await waitFor({ checkFn: () => device2ChangeEventSpy.called }); await expectResourceToMatch(pineUser, 'device', device2.id, { api_heartbeat_state: DeviceOnlineStates.Online, + ...(versions.gte(version, 'v7') && { + changed_api_heartbeat_state_on__date: thatIsDateStringAfter( + lastApiHeartbeatStateChangeEvent, + ), + }), }); }); @@ -833,6 +935,9 @@ export default () => { api_heartbeat_state: DeviceOnlineStates.Unknown, }, }); + lastApiHeartbeatStateChangeEvent = + await getLastApiHeartbeatStateChangeEvent(device2.id); + for (let i = 0; i < 3; i++) { await fakeDevice.getState( device2, @@ -845,6 +950,10 @@ export default () => { expect(device2ChangeEventSpy.called).to.be.false; await expectResourceToMatch(pineUser, 'device', device2.id, { api_heartbeat_state: DeviceOnlineStates.Unknown, + ...(versions.gte(version, 'v7') && { + changed_api_heartbeat_state_on__date: + lastApiHeartbeatStateChangeEvent, + }), }); }); @@ -855,6 +964,11 @@ export default () => { await waitFor({ checkFn: () => device2ChangeEventSpy.called }); await expectResourceToMatch(pineUser, 'device', device2.id, { api_heartbeat_state: DeviceOnlineStates.Online, + ...(versions.gte(version, 'v7') && { + changed_api_heartbeat_state_on__date: thatIsDateStringAfter( + lastApiHeartbeatStateChangeEvent, + ), + }), }); }); }); @@ -870,9 +984,11 @@ export default () => { api_heartbeat_state: DeviceOnlineStates.Unknown, }, }); + lastApiHeartbeatStateChangeEvent = + await getLastApiHeartbeatStateChangeEvent(device2.id); }); - it(`should update the DB heartbeat on every poll`, async () => { + it(`should update the DB heartbeat on every poll, but only change the changed_api_heartbeat_state_on__date the first time`, async () => { for (let i = 0; i < 3; i++) { await fakeDevice.getState( device2, @@ -883,10 +999,25 @@ export default () => { checkFn: () => device2ChangeEventSpy.called, }); device2ChangeEventSpy.resetHistory(); + const fetchedDevice = await expectResourceToMatch( + pineUser, + 'device', + device2.id, + { + api_heartbeat_state: DeviceOnlineStates.Online, + ...(versions.gte(version, 'v7') && { + changed_api_heartbeat_state_on__date: + i === 0 + ? thatIsDateStringAfter( + lastApiHeartbeatStateChangeEvent, + ) + : lastApiHeartbeatStateChangeEvent, + }), + }, + ); + lastApiHeartbeatStateChangeEvent = + fetchedDevice.changed_api_heartbeat_state_on__date; } - await expectResourceToMatch(pineUser, 'device', device2.id, { - api_heartbeat_state: DeviceOnlineStates.Online, - }); }); }); @@ -902,6 +1033,8 @@ export default () => { api_heartbeat_state: DeviceOnlineStates.Unknown, }, }); + lastApiHeartbeatStateChangeEvent = + await getLastApiHeartbeatStateChangeEvent(device2.id); }); it(`should not update the DB heartbeat on polls within the validity period`, async () => { @@ -917,6 +1050,10 @@ export default () => { expect(device2ChangeEventSpy.called).to.be.false; await expectResourceToMatch(pineUser, 'device', device2.id, { api_heartbeat_state: DeviceOnlineStates.Unknown, + ...(versions.gte(version, 'v7') && { + changed_api_heartbeat_state_on__date: + lastApiHeartbeatStateChangeEvent, + }), }); }); }); @@ -940,6 +1077,10 @@ export default () => { expect(device2ChangeEventSpy.called).to.be.false; await expectResourceToMatch(pineUser, 'device', device2.id, { api_heartbeat_state: DeviceOnlineStates.Unknown, + ...(versions.gte(version, 'v7') && { + changed_api_heartbeat_state_on__date: + lastApiHeartbeatStateChangeEvent, + }), }); }); @@ -950,6 +1091,11 @@ export default () => { await waitFor({ checkFn: () => device2ChangeEventSpy.called }); await expectResourceToMatch(pineUser, 'device', device2.id, { api_heartbeat_state: DeviceOnlineStates.Online, + ...(versions.gte(version, 'v7') && { + changed_api_heartbeat_state_on__date: thatIsDateStringAfter( + lastApiHeartbeatStateChangeEvent, + ), + }), }); }); }); @@ -1425,10 +1571,7 @@ export default () => { ); await expectResourceToMatch(pineUser, 'device', device.id, { - is_running__release: (chaiPropertyAssetion) => - chaiPropertyAssetion.that.is - .an('object') - .that.has.property('__id', r.id), + is_running__release: { __id: r.id }, }); } }); diff --git a/test/test-lib/api-helpers.ts b/test/test-lib/api-helpers.ts index ee042b217..1d75311ac 100644 --- a/test/test-lib/api-helpers.ts +++ b/test/test-lib/api-helpers.ts @@ -188,6 +188,24 @@ export const getUserFromToken = (token: string) => { return user; }; +export const thatIsDateStringAfter = ( + dateParam: Date | string | number | null, +) => { + if (dateParam == null) { + throw new Error( + `The date ${dateParam} provided to thatIsAfterDateString has to have a value`, + ); + } + const date = !_.isDate(dateParam) ? new Date(dateParam) : dateParam; + return (prop: Chai.Assertion, value: unknown) => + prop.that.is + .a('string') + .that.satisfies( + (d: string) => new Date(d) > date, + `Expected ${value} to be after ${date.toISOString()}`, + ); +}; + const validJwtProps = ['id', 'jwt_secret', 'authTime', 'iat', 'exp'].sort(); export function expectJwt(tokenOrJwt: string | AnyObject) {