diff --git a/src/balena-model.ts b/src/balena-model.ts index 3d3c316c5c..0f881adf46 100644 --- a/src/balena-model.ts +++ b/src/balena-model.ts @@ -350,6 +350,7 @@ export interface Device { id: number; actor: number; api_heartbeat_state: 'online' | 'offline' | 'timeout' | 'unknown'; + last_api_heartbeat_state_change_event: DateString | null; uuid: string; local_id: string | null; device_name: string | null; diff --git a/src/balena.sbvr b/src/balena.sbvr index d95b045ed5..ca46f0cde1 100644 --- a/src/balena.sbvr +++ b/src/balena.sbvr @@ -160,6 +160,9 @@ Term: known issue list Term: label name Concept Type: Short Text (Type) +Term: last api heartbeat state change event + Concept Type: Date Time (Type) + Term: last connectivity event Concept Type: Date Time (Type) @@ -365,6 +368,9 @@ Term: device Necessity: each device has exactly one api heartbeat state Definition: "online" or "offline" or "timeout" or "unknown" + Fact type: device has last api heartbeat state change event + Necessity: each device has at most one last api heartbeat state change event. + Fact type: device has env var name Term Form: device environment variable Database Table Name: device environment variable @@ -440,7 +446,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/device-online-state-manager.ts similarity index 100% rename from src/features/device-heartbeat/index.ts rename to src/features/device-heartbeat/device-online-state-manager.ts diff --git a/src/features/device-heartbeat/hooks.ts b/src/features/device-heartbeat/hooks.ts new file mode 100644 index 0000000000..58828b682f --- /dev/null +++ b/src/features/device-heartbeat/hooks.ts @@ -0,0 +1,9 @@ +import { hooks } from '@balena/pinejs'; + +hooks.addPureHook('PATCH', 'resin', 'device', { + POSTPARSE: ({ request }) => { + if (request.values.api_heartbeat_state != null) { + request.values.last_api_heartbeat_state_change_event = new Date(); + } + }, +}); diff --git a/src/hooks.ts b/src/hooks.ts index ef20121210..8a68cab218 100644 --- a/src/hooks.ts +++ b/src/hooks.ts @@ -4,6 +4,7 @@ import './features/application-types/hooks'; import './features/ci-cd/hooks'; import './features/cascade-delete/hooks'; import './features/devices/hooks'; +import './features/device-heartbeat/hooks'; import './features/device-types/hooks'; import './features/device-urls/hooks'; import './features/hostapp/hooks'; diff --git a/src/index.ts b/src/index.ts index b54281331e..d5d096f77c 100644 --- a/src/index.ts +++ b/src/index.ts @@ -120,7 +120,7 @@ import { DeviceOnlineStates, getPollInterval, getInstance as getDeviceOnlineStateManager, -} from './features/device-heartbeat'; +} from './features/device-heartbeat/device-online-state-manager'; import { registryAuth } from './features/registry/certs'; import { ALLOWED_NAMES, diff --git a/src/migrations/0077-device-last-api-heartbeat-state-change-event.sql b/src/migrations/0077-device-last-api-heartbeat-state-change-event.sql new file mode 100644 index 0000000000..4faf6223c0 --- /dev/null +++ b/src/migrations/0077-device-last-api-heartbeat-state-change-event.sql @@ -0,0 +1,2 @@ +ALTER TABLE "device" +ADD COLUMN IF NOT EXISTS "last api heartbeat state change event" TIMESTAMP NULL; diff --git a/test/03_device-state.ts b/test/03_device-state.ts index b2878c7ed3..a2d9dc0f86 100644 --- a/test/03_device-state.ts +++ b/test/03_device-state.ts @@ -8,10 +8,13 @@ import { supertest, UserObjectParam } from './test-lib/supertest'; import { version } from './test-lib/versions'; import { pineTest } from './test-lib/pinetest'; import * as configMock from '../src/lib/config'; -import * as stateMock from '../src/features/device-heartbeat'; +import * as stateMock from '../src/features/device-heartbeat/device-online-state-manager'; import { waitFor } from './test-lib/common'; import * as fixtures from './test-lib/fixtures'; -import { expectResourceToMatch } from './test-lib/api-helpers'; +import { + expectResourceToMatch, + thatIsDateStringAfter, +} from './test-lib/api-helpers'; import { redis, redisRO } from '../src/infra/redis'; import { setTimeout } from 'timers/promises'; import { MINUTES, SECONDS } from '@balena/env-parsing'; @@ -227,20 +230,20 @@ mockery.registerMock('../src/lib/config', configMock); ({ tokenType, getActor, 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); - - expect(body.d[0]).to.not.be.undefined; - expect(body.d[0]).to.have.property( - 'api_heartbeat_state', - DeviceOnlineStates.Unknown, - 'API heartbeat state is not unknown (default)', + await expectResourceToMatch( + getActor(), + 'device', + getDevice().id, + { + api_heartbeat_state: DeviceOnlineStates.Unknown, + last_api_heartbeat_state_change_event: null, + }, ); }); it(`Should have the "${heartbeatAfterGet}" heartbeat state after a state poll`, async () => { stateChangeEventSpy.resetHistory(); + const stateUpdatedAfter = new Date(); await getState(); if (heartbeatAfterGet !== DeviceOnlineStates.Unknown) { @@ -256,15 +259,17 @@ mockery.registerMock('../src/lib/config', configMock); : undefined, ); - const { body } = await supertest(getActor()) - .get(`/${version}/device(${getDevice().id})`) - .expect(200); - - expect(body.d[0]).to.not.be.undefined; - expect(body.d[0]).to.have.property( - 'api_heartbeat_state', - heartbeatAfterGet, - `API heartbeat state is not ${heartbeatAfterGet}`, + await expectResourceToMatch( + getActor(), + 'device', + getDevice().id, + { + api_heartbeat_state: heartbeatAfterGet, + last_api_heartbeat_state_change_event: + heartbeatAfterGet === DeviceOnlineStates.Unknown + ? null + : thatIsDateStringAfter(stateUpdatedAfter), + }, ); }); @@ -276,29 +281,38 @@ mockery.registerMock('../src/lib/config', configMock); devicePollInterval / 1000 } seconds`, async () => { stateChangeEventSpy.resetHistory(); + let stateUpdatedAfter = new Date(); await setTimeout(devicePollInterval); - await waitFor({ checkFn: () => stateChangeEventSpy.called }); + await waitFor({ + checkFn: () => { + if (stateChangeEventSpy.called) { + return true; + } + stateUpdatedAfter = new Date(); + return false; + }, + }); expect(tracker.states[getDevice().id]).to.equal( DeviceOnlineStates.Timeout, ); - const { body } = await supertest(getActor()) - .get(`/${version}/device(${getDevice().id})`) - .expect(200); - - expect(body.d[0]).to.not.be.undefined; - expect(body.d[0]).to.have.property( - 'api_heartbeat_state', - DeviceOnlineStates.Timeout, - 'API heartbeat state is not timeout', + await expectResourceToMatch( + getActor(), + 'device', + getDevice().id, + { + api_heartbeat_state: DeviceOnlineStates.Timeout, + last_api_heartbeat_state_change_event: + thatIsDateStringAfter(stateUpdatedAfter), + }, ); }); it(`Should see state become "online" again, following a state poll`, async () => { stateChangeEventSpy.resetHistory(); - + const stateUpdatedAfter = new Date(); await getState(); await waitFor({ checkFn: () => stateChangeEventSpy.called }); @@ -307,15 +321,15 @@ mockery.registerMock('../src/lib/config', configMock); DeviceOnlineStates.Online, ); - const { body } = await supertest(getActor()) - .get(`/${version}/device(${getDevice().id})`) - .expect(200); - - expect(body.d[0]).to.not.be.undefined; - expect(body.d[0]).to.have.property( - 'api_heartbeat_state', - DeviceOnlineStates.Online, - 'API heartbeat state is not online', + await expectResourceToMatch( + getActor(), + 'device', + getDevice().id, + { + api_heartbeat_state: DeviceOnlineStates.Online, + last_api_heartbeat_state_change_event: + thatIsDateStringAfter(stateUpdatedAfter), + }, ); }); @@ -323,27 +337,33 @@ mockery.registerMock('../src/lib/config', configMock); TIMEOUT_SEC + devicePollInterval / 1000 } seconds`, async () => { stateChangeEventSpy.resetHistory(); - + let stateUpdatedAfter = new Date(); 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 = new Date(); + return false; + }, }); expect(tracker.states[getDevice().id]).to.equal( DeviceOnlineStates.Offline, ); - const { body } = await supertest(getActor()) - .get(`/${version}/device(${getDevice().id})`) - .expect(200); - - expect(body.d[0]).to.not.be.undefined; - expect(body.d[0]).to.have.property( - 'api_heartbeat_state', - DeviceOnlineStates.Offline, - 'API heartbeat state is not offline', + await expectResourceToMatch( + getActor(), + 'device', + getDevice().id, + { + api_heartbeat_state: DeviceOnlineStates.Offline, + last_api_heartbeat_state_change_event: + thatIsDateStringAfter(stateUpdatedAfter), + }, ); }); }); @@ -383,16 +403,9 @@ mockery.registerMock('../src/lib/config', configMock); DeviceOnlineStates.Offline, ); - const { body } = await supertest(admin) - .get(`/${version}/device(${device.id})`) - .expect(200); - - expect(body.d[0]).to.not.be.undefined; - 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 () => { @@ -421,16 +434,9 @@ mockery.registerMock('../src/lib/config', configMock); DeviceOnlineStates.Online, ); - const { body } = await supertest(admin) - .get(`/${version}/device(${device.id})`) - .expect(200); - - expect(body.d[0]).to.not.be.undefined; - 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, + }); }); }); }); @@ -439,6 +445,23 @@ mockery.registerMock('../src/lib/config', configMock); let device2: fakeDevice.Device; const device2ChangeEventSpy = sinon.spy(); let lastPersistedTimestamp: number | undefined; + let lastApiHeartbeatStateChangeEvent: string | null = null; + + async function getLastApiHeartbeatStateChangeEvent( + id: number, + ): Promise { + return ( + await pineUser + .get({ + resource: 'device', + id, + options: { + $select: 'last_api_heartbeat_state_change_event', + }, + }) + .expect(200) + ).body.last_api_heartbeat_state_change_event; + } before(async () => { device2 = await fakeDevice.provisionDevice(admin, applicationId); @@ -450,6 +473,7 @@ mockery.registerMock('../src/lib/config', configMock); }); await expectResourceToMatch(pineUser, 'device', device2.id, { api_heartbeat_state: DeviceOnlineStates.Unknown, + last_api_heartbeat_state_change_event: null, }); }); beforeEach(function () { @@ -467,9 +491,19 @@ mockery.registerMock('../src/lib/config', configMock); 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, + last_api_heartbeat_state_change_event: (prop) => + prop.that.is.a('string'), + }, + ); + + lastApiHeartbeatStateChangeEvent = + fetchedDevice.last_api_heartbeat_state_change_event; }); it('should not update the DB heartbeat on subsequent polls', async () => { @@ -478,6 +512,12 @@ mockery.registerMock('../src/lib/config', configMock); 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, + last_api_heartbeat_state_change_event: + lastApiHeartbeatStateChangeEvent, + }); }); it('will trust Redis and not update the DB heartbeat on subsequent polls even if the DB has diverged :(', async () => { @@ -488,12 +528,17 @@ mockery.registerMock('../src/lib/config', configMock); 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, + last_api_heartbeat_state_change_event: + lastApiHeartbeatStateChangeEvent, }); }); }); @@ -511,6 +556,8 @@ mockery.registerMock('../src/lib/config', configMock); 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 () => { @@ -518,6 +565,9 @@ mockery.registerMock('../src/lib/config', configMock); await waitFor({ checkFn: () => device2ChangeEventSpy.called }); await expectResourceToMatch(pineUser, 'device', device2.id, { api_heartbeat_state: DeviceOnlineStates.Online, + last_api_heartbeat_state_change_event: thatIsDateStringAfter( + lastApiHeartbeatStateChangeEvent, + ), }); }); @@ -530,6 +580,9 @@ mockery.registerMock('../src/lib/config', configMock); api_heartbeat_state: DeviceOnlineStates.Unknown, }, }); + lastApiHeartbeatStateChangeEvent = + await getLastApiHeartbeatStateChangeEvent(device2.id); + for (let i = 0; i < 3; i++) { await fakeDevice.getState(device2, device2.uuid, stateVersion); } @@ -538,6 +591,8 @@ mockery.registerMock('../src/lib/config', configMock); expect(device2ChangeEventSpy.called).to.be.false; await expectResourceToMatch(pineUser, 'device', device2.id, { api_heartbeat_state: DeviceOnlineStates.Unknown, + last_api_heartbeat_state_change_event: + lastApiHeartbeatStateChangeEvent, }); }); @@ -547,6 +602,9 @@ mockery.registerMock('../src/lib/config', configMock); await waitFor({ checkFn: () => device2ChangeEventSpy.called }); await expectResourceToMatch(pineUser, 'device', device2.id, { api_heartbeat_state: DeviceOnlineStates.Online, + last_api_heartbeat_state_change_event: thatIsDateStringAfter( + lastApiHeartbeatStateChangeEvent, + ), }); }); }); @@ -563,17 +621,30 @@ mockery.registerMock('../src/lib/config', configMock); 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 last_api_heartbeat_state_change_event the first time`, async () => { for (let i = 0; i < 3; i++) { await fakeDevice.getState(device2, device2.uuid, stateVersion); await waitFor({ checkFn: () => device2ChangeEventSpy.called }); device2ChangeEventSpy.resetHistory(); + const fetchedDevice = await expectResourceToMatch( + pineUser, + 'device', + device2.id, + { + api_heartbeat_state: DeviceOnlineStates.Online, + last_api_heartbeat_state_change_event: + i === 0 + ? thatIsDateStringAfter(lastApiHeartbeatStateChangeEvent) + : lastApiHeartbeatStateChangeEvent, + }, + ); + lastApiHeartbeatStateChangeEvent = + fetchedDevice.last_api_heartbeat_state_change_event; } - await expectResourceToMatch(pineUser, 'device', device2.id, { - api_heartbeat_state: DeviceOnlineStates.Online, - }); }); }); @@ -590,6 +661,8 @@ mockery.registerMock('../src/lib/config', configMock); api_heartbeat_state: DeviceOnlineStates.Unknown, }, }); + lastApiHeartbeatStateChangeEvent = + await getLastApiHeartbeatStateChangeEvent(device2.id); }); it(`should not update the DB heartbeat on polls within the validity period`, async () => { @@ -601,6 +674,8 @@ mockery.registerMock('../src/lib/config', configMock); expect(device2ChangeEventSpy.called).to.be.false; await expectResourceToMatch(pineUser, 'device', device2.id, { api_heartbeat_state: DeviceOnlineStates.Unknown, + last_api_heartbeat_state_change_event: + lastApiHeartbeatStateChangeEvent, }); }); }); @@ -621,6 +696,8 @@ mockery.registerMock('../src/lib/config', configMock); expect(device2ChangeEventSpy.called).to.be.false; await expectResourceToMatch(pineUser, 'device', device2.id, { api_heartbeat_state: DeviceOnlineStates.Unknown, + last_api_heartbeat_state_change_event: + lastApiHeartbeatStateChangeEvent, }); }); @@ -630,6 +707,9 @@ mockery.registerMock('../src/lib/config', configMock); await waitFor({ checkFn: () => device2ChangeEventSpy.called }); await expectResourceToMatch(pineUser, 'device', device2.id, { api_heartbeat_state: DeviceOnlineStates.Online, + last_api_heartbeat_state_change_event: thatIsDateStringAfter( + lastApiHeartbeatStateChangeEvent, + ), }); }); }); @@ -969,10 +1049,8 @@ mockery.registerMock('../src/lib/config', configMock); ); await expectResourceToMatch(pineUser, 'device', device.id, { - is_running__release: (chaiPropertyAssetion) => - chaiPropertyAssetion.that.is - .an('object') - .that.has.property('__id', r.id), + is_running__release: (prop) => + prop.that.is.an('object').that.has.property('__id', r.id), }); } }); diff --git a/test/test-lib/api-helpers.ts b/test/test-lib/api-helpers.ts index 2cfc9fab9e..f0340eb539 100644 --- a/test/test-lib/api-helpers.ts +++ b/test/test-lib/api-helpers.ts @@ -2,7 +2,7 @@ import { Release } from '../../src/balena-model'; import { supertest, UserObjectParam } from '../test-lib/supertest'; import { expect } from 'chai'; import { version } from './versions'; -import type { PineTest } from './pinetest'; +import { pineTest, PineTest } from './pinetest'; interface MockReleaseParams { belongs_to__application: number; @@ -82,7 +82,7 @@ export const addImageToRelease = async ( }; export const expectResourceToMatch = async ( - pineUser: PineTest, + pineUserOrUserParam: PineTest | string | UserObjectParam, resource: string, id: number | AnyObject, expectations: Dictionary< @@ -93,6 +93,14 @@ export const expectResourceToMatch = async ( | ((chaiPropertyAssetion: Chai.Assertion) => void) >, ) => { + const pineUser = + pineUserOrUserParam instanceof PineTest + ? pineUserOrUserParam + : pineTest.clone({ + passthrough: { + user: pineUserOrUserParam, + }, + }); const { body: result } = await pineUser .get({ resource, @@ -111,3 +119,19 @@ export const expectResourceToMatch = async ( } return result; }; + +export const thatIsDateStringAfter = (dateParam: Date | string | null) => { + if (dateParam == null) { + throw new Error( + `The date ${dateParam} provided to thatIsAfterDateString has to have a value`, + ); + } + const date = typeof dateParam === 'string' ? new Date(dateParam) : dateParam; + return (prop: Chai.Assertion) => + prop.that.is + .a('string') + .that.satisfies( + (d: string) => new Date(d) > date, + `Expected date to be after ${date}`, + ); +}; diff --git a/test/test-lib/init-tests.ts b/test/test-lib/init-tests.ts index 2a6221aa32..d0344f0c8c 100644 --- a/test/test-lib/init-tests.ts +++ b/test/test-lib/init-tests.ts @@ -13,7 +13,7 @@ export const preInit = async () => { // override the interval used to emit the queue stats event... const { DeviceOnlineStateManager } = await import( - '../../src/features/device-heartbeat' + '../../src/features/device-heartbeat/device-online-state-manager' ); (DeviceOnlineStateManager as any)['QUEUE_STATS_INTERVAL_MSEC'] = 1000; }; diff --git a/test/test-lib/pinetest.ts b/test/test-lib/pinetest.ts index 6ab4d59c3c..87c447d966 100644 --- a/test/test-lib/pinetest.ts +++ b/test/test-lib/pinetest.ts @@ -3,5 +3,5 @@ import { PineTest } from 'pinejs-client-supertest'; import { app } from '../../init'; import { version } from './versions'; -export type { PineTest }; +export { PineTest }; export const pineTest = new PineTest({ apiPrefix: `${version}/` }, { app });