From 4367bec87697114eb2d7f449925f591c232edad6 Mon Sep 17 00:00:00 2001 From: Nerivec <62446222+Nerivec@users.noreply.github.com> Date: Fri, 11 Oct 2024 16:06:41 +0200 Subject: [PATCH] feat!: Improve permit join (#1214) * feat!: Improve permit join. * Fix permitJoinTimeout never `undefined` (`0` equals disabled). * Dont allow >254sec for permit join. --- src/controller/controller.ts | 84 ++++++++--------- src/controller/events.ts | 1 - test/controller.test.ts | 175 +++++++++++++++++++++-------------- 3 files changed, 145 insertions(+), 115 deletions(-) diff --git a/src/controller/controller.ts b/src/controller/controller.ts index 1a43225736..501621e82c 100644 --- a/src/controller/controller.ts +++ b/src/controller/controller.ts @@ -78,9 +78,8 @@ class Controller extends events.EventEmitter { // @ts-expect-error assigned and validated in start() private touchlink: Touchlink; - private permitJoinNetworkClosedTimer: NodeJS.Timeout | undefined; private permitJoinTimeoutTimer: NodeJS.Timeout | undefined; - private permitJoinTimeout: number | undefined; + private permitJoinTimeout: number; private backupTimer: NodeJS.Timeout | undefined; private databaseSaveTimer: NodeJS.Timeout | undefined; private stopping: boolean; @@ -100,6 +99,7 @@ class Controller extends events.EventEmitter { this.adapterDisconnected = true; // set false after adapter.start() is successfully called this.options = mixinDeep(JSON.parse(JSON.stringify(DefaultOptions)), options); this.unknownDevices = new Set(); + this.permitJoinTimeout = 0; // Validate options for (const channel of this.options.network.channelList) { @@ -274,62 +274,52 @@ class Controller extends events.EventEmitter { await this.adapter.addInstallCode(ieeeAddr, key); } - public async permitJoin(permit: boolean, device?: Device, time?: number): Promise { - await this.permitJoinInternal(permit, 'manual', device, time); - } - - public async permitJoinInternal(permit: boolean, reason: 'manual' | 'timer_expired', device?: Device, time?: number): Promise { - clearInterval(this.permitJoinNetworkClosedTimer); + public async permitJoin(time: number, device?: Device): Promise { clearInterval(this.permitJoinTimeoutTimer); - this.permitJoinNetworkClosedTimer = undefined; this.permitJoinTimeoutTimer = undefined; - this.permitJoinTimeout = undefined; - - if (permit) { - await this.adapter.permitJoin(254, device?.networkAddress); - await this.greenPower.permitJoin(254, device?.networkAddress); - - // TODO: remove https://github.com/Koenkk/zigbee-herdsman/issues/940 - // Zigbee 3 networks automatically close after max 255 seconds, keep network open. - this.permitJoinNetworkClosedTimer = setInterval(async (): Promise => { - try { - await this.adapter.permitJoin(254, device?.networkAddress); - await this.greenPower.permitJoin(254, device?.networkAddress); - } catch (error) { - logger.error(`Failed to keep permit join alive: ${error}`, NS); + this.permitJoinTimeout = 0; + + if (time > 0) { + // never permit more than uint8, and never permit 255 that is often equal to "forever" + assert(time <= 254, `Cannot permit join for more than 254 seconds.`); + + await this.adapter.permitJoin(time, device?.networkAddress); + await this.greenPower.permitJoin(time, device?.networkAddress); + + // TODO: should use setTimeout and timer only for open/close emit + // let the other end (frontend) do the sec-by-sec updating (without mqtt publish) + // Also likely creates a gap of a few secs between what Z2M says and what the stack actually has => unreliable timer end + this.permitJoinTimeout = time; + this.permitJoinTimeoutTimer = setInterval(async (): Promise => { + // assumed valid number while in interval + this.permitJoinTimeout--; + + if (this.permitJoinTimeout <= 0) { + clearInterval(this.permitJoinTimeoutTimer); + this.permitJoinTimeoutTimer = undefined; + this.permitJoinTimeout = 0; + + this.emit('permitJoinChanged', {permitted: false, timeout: this.permitJoinTimeout}); + } else { + this.emit('permitJoinChanged', {permitted: true, timeout: this.permitJoinTimeout}); } - }, 200 * 1000); - - // TODO: prevent many mqtt messages by doing this on the other end? - if (typeof time === 'number') { - this.permitJoinTimeout = time; - this.permitJoinTimeoutTimer = setInterval(async (): Promise => { - // assumed valid number while in interval - this.permitJoinTimeout!--; - - if (this.permitJoinTimeout! <= 0) { - await this.permitJoinInternal(false, 'timer_expired'); - } else { - this.emit('permitJoinChanged', {permitted: true, timeout: this.permitJoinTimeout, reason}); - } - }, 1000); - } + }, 1000); - this.emit('permitJoinChanged', {permitted: true, reason, timeout: this.permitJoinTimeout}); + this.emit('permitJoinChanged', {permitted: true, timeout: this.permitJoinTimeout}); } else { logger.debug('Disable joining', NS); + await this.greenPower.permitJoin(0); await this.adapter.permitJoin(0); - this.emit('permitJoinChanged', {permitted: false, reason, timeout: this.permitJoinTimeout}); + this.emit('permitJoinChanged', {permitted: false, timeout: this.permitJoinTimeout}); } } - public getPermitJoin(): boolean { - return this.permitJoinNetworkClosedTimer != undefined; - } - - public getPermitJoinTimeout(): number | undefined { + /** + * @returns Timeout until permit joining expires. [0-254], with 0 being "not permitting joining". + */ + public getPermitJoinTimeout(): number { return this.permitJoinTimeout; } @@ -354,7 +344,7 @@ class Controller extends events.EventEmitter { this.databaseSave(); } else { try { - await this.permitJoinInternal(false, 'manual'); + await this.permitJoin(0); } catch (error) { logger.error(`Failed to disable join on stop: ${error}`, NS); } diff --git a/src/controller/events.ts b/src/controller/events.ts index f4db44705d..282950f6b6 100644 --- a/src/controller/events.ts +++ b/src/controller/events.ts @@ -25,7 +25,6 @@ interface DeviceLeavePayload { interface PermitJoinChangedPayload { permitted: boolean; - reason: 'timer_expired' | 'manual'; timeout?: number; } diff --git a/test/controller.test.ts b/test/controller.test.ts index 8449126b7e..f14b30f99f 100755 --- a/test/controller.test.ts +++ b/test/controller.test.ts @@ -540,7 +540,11 @@ describe('Controller', () => { configureReportDefaultRsp = false; enroll170 = true; options.network.channelList = [15]; - Object.keys(events).forEach((key) => (events[key] = [])); + + for (const event in events) { + events[event] = []; + } + Device.resetCache(); Group.resetCache(); @@ -2358,88 +2362,134 @@ describe('Controller', () => { ); }); - it('Controller permit joining', async () => { + it('Controller permit joining all, disabled automatically', async () => { await controller.start(); - await controller.permitJoin(true); + await controller.permitJoin(254); + + expect(mockAdapterPermitJoin).toHaveBeenCalledTimes(1); + expect(mockAdapterPermitJoin.mock.calls[0][0]).toStrictEqual(254); + expect(events.permitJoinChanged.length).toStrictEqual(1); + expect(events.permitJoinChanged[0]).toStrictEqual({permitted: true, timeout: 254}); + expect(controller.getPermitJoinTimeout()).toStrictEqual(254); + + // Green power + const commisionFrameEnable = Zcl.Frame.create(1, 1, true, undefined, 2, 'commisioningMode', 33, {options: 0x0b, commisioningWindow: 254}, {}); + + expect(mocksendZclFrameToAll).toHaveBeenCalledTimes(1); + expect(mocksendZclFrameToAll.mock.calls[0][0]).toStrictEqual(ZSpec.GP_ENDPOINT); + expect(deepClone(mocksendZclFrameToAll.mock.calls[0][1])).toStrictEqual(deepClone(commisionFrameEnable)); + expect(mocksendZclFrameToAll.mock.calls[0][2]).toStrictEqual(ZSpec.GP_ENDPOINT); + + await jest.advanceTimersByTimeAsync(250 * 1000); + + expect(mocksendZclFrameToAll).toHaveBeenCalledTimes(1); + expect(mockAdapterPermitJoin).toHaveBeenCalledTimes(1); + expect(controller.getPermitJoinTimeout()).toStrictEqual(4); + + // Timer expired + await jest.advanceTimersByTimeAsync(10 * 1000); + expect(mockAdapterPermitJoin).toHaveBeenCalledTimes(1); - expect(mockAdapterPermitJoin.mock.calls[0][0]).toBe(254); - expect(events.permitJoinChanged.length).toBe(1); - expect(events.permitJoinChanged[0]).toStrictEqual({permitted: true, reason: 'manual', timeout: undefined}); - expect(controller.getPermitJoin()).toBe(true); + expect(events.permitJoinChanged.length).toStrictEqual(255); + expect(events.permitJoinChanged[254]).toStrictEqual({permitted: false, timeout: 0}); + expect(controller.getPermitJoinTimeout()).toStrictEqual(0); // Green power expect(mocksendZclFrameToAll).toHaveBeenCalledTimes(1); + }); + + it('Controller permit joining all, disabled manually', async () => { + await controller.start(); + await controller.permitJoin(254); + expect(mockAdapterPermitJoin).toHaveBeenCalledTimes(1); + expect(mockAdapterPermitJoin.mock.calls[0][0]).toStrictEqual(254); + expect(events.permitJoinChanged.length).toStrictEqual(1); + expect(events.permitJoinChanged[0]).toStrictEqual({permitted: true, timeout: 254}); + expect(controller.getPermitJoinTimeout()).toStrictEqual(254); + + // Green power const commisionFrameEnable = Zcl.Frame.create(1, 1, true, undefined, 2, 'commisioningMode', 33, {options: 0x0b, commisioningWindow: 254}, {}); - expect(mocksendZclFrameToAll.mock.calls[0][0]).toBe(ZSpec.GP_ENDPOINT); + + expect(mocksendZclFrameToAll).toHaveBeenCalledTimes(1); + expect(mocksendZclFrameToAll.mock.calls[0][0]).toStrictEqual(ZSpec.GP_ENDPOINT); expect(deepClone(mocksendZclFrameToAll.mock.calls[0][1])).toStrictEqual(deepClone(commisionFrameEnable)); - expect(mocksendZclFrameToAll.mock.calls[0][2]).toBe(ZSpec.GP_ENDPOINT); + expect(mocksendZclFrameToAll.mock.calls[0][2]).toStrictEqual(ZSpec.GP_ENDPOINT); - // should call it again ever +- 200 seconds - jest.advanceTimersByTime(210 * 1000); - await flushPromises(); - expect(mocksendZclFrameToAll).toHaveBeenCalledTimes(2); - expect(mockAdapterPermitJoin).toHaveBeenCalledTimes(2); - expect(mockAdapterPermitJoin.mock.calls[1][0]).toBe(254); - jest.advanceTimersByTime(210 * 1000); - await flushPromises(); - expect(mocksendZclFrameToAll).toHaveBeenCalledTimes(3); - expect(mockAdapterPermitJoin).toHaveBeenCalledTimes(3); - expect(mockAdapterPermitJoin.mock.calls[2][0]).toBe(254); - expect(events.permitJoinChanged.length).toBe(1); - expect(controller.getPermitJoin()).toBe(true); + await jest.advanceTimersByTimeAsync(250 * 1000); + + expect(mocksendZclFrameToAll).toHaveBeenCalledTimes(1); + expect(mockAdapterPermitJoin).toHaveBeenCalledTimes(1); + expect(events.permitJoinChanged.length).toStrictEqual(251); + expect(controller.getPermitJoinTimeout()).toStrictEqual(4); // Disable - await controller.permitJoin(false); - expect(mockAdapterPermitJoin).toHaveBeenCalledTimes(4); - expect(mockAdapterPermitJoin.mock.calls[3][0]).toBe(0); - jest.advanceTimersByTime(210 * 1000); - expect(mockAdapterPermitJoin).toHaveBeenCalledTimes(4); - expect(events.permitJoinChanged.length).toBe(2); - expect(events.permitJoinChanged[1]).toStrictEqual({permitted: false, reason: 'manual', timeout: undefined}); - expect(controller.getPermitJoin()).toBe(false); + await controller.permitJoin(0); + + expect(mockAdapterPermitJoin).toHaveBeenCalledTimes(2); + expect(mockAdapterPermitJoin.mock.calls[1][0]).toStrictEqual(0); + expect(events.permitJoinChanged.length).toStrictEqual(252); + expect(events.permitJoinChanged[251]).toStrictEqual({permitted: false, timeout: 0}); + expect(controller.getPermitJoinTimeout()).toStrictEqual(0); // Green power - expect(mocksendZclFrameToAll).toHaveBeenCalledTimes(4); - const commissionFrameDisable = Zcl.Frame.create(1, 1, true, undefined, 5, 'commisioningMode', 33, {options: 0x0a, commisioningWindow: 0}, {}); - expect(mocksendZclFrameToAll.mock.calls[3][0]).toBe(ZSpec.GP_ENDPOINT); - expect(deepClone(mocksendZclFrameToAll.mock.calls[3][1])).toStrictEqual(deepClone(commissionFrameDisable)); - expect(mocksendZclFrameToAll.mock.calls[3][2]).toBe(ZSpec.GP_ENDPOINT); - expect(mocksendZclFrameToAll).toHaveBeenCalledTimes(4); + const commissionFrameDisable = Zcl.Frame.create(1, 1, true, undefined, 3, 'commisioningMode', 33, {options: 0x0a, commisioningWindow: 0}, {}); + + expect(mocksendZclFrameToAll).toHaveBeenCalledTimes(2); + expect(mocksendZclFrameToAll.mock.calls[1][0]).toStrictEqual(ZSpec.GP_ENDPOINT); + expect(deepClone(mocksendZclFrameToAll.mock.calls[1][1])).toStrictEqual(deepClone(commissionFrameDisable)); + expect(mocksendZclFrameToAll.mock.calls[1][2]).toStrictEqual(ZSpec.GP_ENDPOINT); }); it('Controller permit joining through specific device', async () => { await controller.start(); await mockAdapterEvents['deviceJoined']({networkAddress: 129, ieeeAddr: '0x129'}); - await controller.permitJoin(true, controller.getDeviceByIeeeAddr('0x129')); + await controller.permitJoin(254, controller.getDeviceByIeeeAddr('0x129')); + expect(mockAdapterPermitJoin).toHaveBeenCalledTimes(1); - expect(mockAdapterPermitJoin.mock.calls[0][0]).toBe(254); - expect(mockAdapterPermitJoin.mock.calls[0][1]).toBe(129); + expect(mockAdapterPermitJoin.mock.calls[0][0]).toStrictEqual(254); + expect(mockAdapterPermitJoin.mock.calls[0][1]).toStrictEqual(129); + expect(controller.getPermitJoinTimeout()).toStrictEqual(254); - jest.advanceTimersByTime(210 * 1000); - expect(mockAdapterPermitJoin).toHaveBeenCalledTimes(2); - expect(mockAdapterPermitJoin.mock.calls[1][0]).toBe(254); - expect(mockAdapterPermitJoin.mock.calls[1][1]).toBe(129); + // Timer expired + await jest.advanceTimersByTimeAsync(300 * 1000); + + expect(mockAdapterPermitJoin).toHaveBeenCalledTimes(1); + expect(controller.getPermitJoinTimeout()).toStrictEqual(0); }); it('Controller permit joining for specific time', async () => { await controller.start(); - await controller.permitJoin(true, undefined, 10); + await controller.permitJoin(10); + expect(mockAdapterPermitJoin).toHaveBeenCalledTimes(1); - expect(mockAdapterPermitJoin.mock.calls[0][0]).toBe(254); - expect(events.permitJoinChanged.length).toBe(1); - expect(events.permitJoinChanged[0]).toStrictEqual({permitted: true, reason: 'manual', timeout: 10}); + expect(mockAdapterPermitJoin.mock.calls[0][0]).toStrictEqual(10); + expect(events.permitJoinChanged.length).toStrictEqual(1); + expect(events.permitJoinChanged[0]).toStrictEqual({permitted: true, timeout: 10}); + expect(controller.getPermitJoinTimeout()).toStrictEqual(10); - // Timer ends - jest.advanceTimersByTime(5 * 1000); - await flushPromises(); - expect(controller.getPermitJoinTimeout()).toBe(5); - jest.advanceTimersByTime(7 * 1000); - await flushPromises(); - expect(mockAdapterPermitJoin).toHaveBeenCalledTimes(2); - expect(mockAdapterPermitJoin.mock.calls[1][0]).toBe(0); - expect(events.permitJoinChanged.length).toBe(11); - expect(events.permitJoinChanged[5]).toStrictEqual({permitted: true, reason: 'manual', timeout: 5}); - expect(events.permitJoinChanged[10]).toStrictEqual({permitted: false, reason: 'timer_expired', timeout: undefined}); + await jest.advanceTimersByTimeAsync(5 * 1000); + + expect(events.permitJoinChanged.length).toStrictEqual(6); + expect(events.permitJoinChanged[5]).toStrictEqual({permitted: true, timeout: 5}); + expect(controller.getPermitJoinTimeout()).toStrictEqual(5); + + // Timer expired + await jest.advanceTimersByTimeAsync(7 * 1000); + + expect(mockAdapterPermitJoin).toHaveBeenCalledTimes(1); + expect(events.permitJoinChanged.length).toStrictEqual(11); + expect(events.permitJoinChanged[10]).toStrictEqual({permitted: false, timeout: 0}); + expect(controller.getPermitJoinTimeout()).toStrictEqual(0); + }); + + it('Controller permit joining for too long time throws', async () => { + await controller.start(); + + expect(async () => { + await controller.permitJoin(255); + }).rejects.toThrow(`Cannot permit join for more than 254 seconds.`); + expect(mockAdapterPermitJoin).toHaveBeenCalledTimes(0); + expect(events.permitJoinChanged.length).toStrictEqual(0); }); it('Shouldnt create backup when adapter doesnt support it', async () => { @@ -10226,15 +10276,6 @@ describe('Controller', () => { }); }); - it('Adapter permitJoin fails to keep alive', async () => { - await controller.start(); - mockAdapterPermitJoin.mockResolvedValueOnce(undefined).mockRejectedValueOnce('timeout'); - await controller.permitJoin(true); - await jest.advanceTimersByTimeAsync(240 * 1000); - - expect(mockLogger.error).toHaveBeenCalledWith(`Failed to keep permit join alive: timeout`, 'zh:controller'); - }); - it('Adapter permitJoin fails during stop', async () => { await controller.start(); mockAdapterPermitJoin.mockRejectedValueOnce('timeout');