From 181ec087c221a0ce4de8ee2253d56448e0db712e Mon Sep 17 00:00:00 2001 From: slugzero Date: Sun, 19 Mar 2023 09:06:31 +0100 Subject: [PATCH] Z-Stack: Rewrite device entry in the coordinator's child table if sending fails (#680) * Attempt to rewrite device entry in the child table if sending fails Sometimes the coordinator stops setting the PENDING flag before sending frames to sleepy end devices. Rewriting the device entry in the child table seems to fix this, at least temporarily. If sending a frame fails, try to rewrite the device's entry and try again (if there is already an entry, and only if the device is listed as a sleepy end device, aka CHILD_RFD) * Additional test for branch coverage * Check for AssocAdd/AssocRemove support; fix debug output --- src/adapter/z-stack/adapter/zStackAdapter.ts | 14 ++++++++ test/adapter/z-stack/adapter.test.ts | 37 ++++++++++++++++++-- 2 files changed, 48 insertions(+), 3 deletions(-) diff --git a/src/adapter/z-stack/adapter/zStackAdapter.ts b/src/adapter/z-stack/adapter/zStackAdapter.ts index 94b8dec439..f2ca0ae104 100644 --- a/src/adapter/z-stack/adapter/zStackAdapter.ts +++ b/src/adapter/z-stack/adapter/zStackAdapter.ts @@ -501,6 +501,20 @@ class ZStackAdapter extends Adapter { } catch (error) { debug('Response timeout (%s:%d,%d)', ieeeAddr, networkAddress, responseAttempt); if (responseAttempt < 1 && !disableRecovery) { + // No response could be because the radio of the end device is turned off: + // Sometimes the coordinator does not properly set the PENDING flag. + // Try to rewrite the device entry in the association table, this fixes it sometimes. + const match = await this.znp.request( + Subsystem.UTIL, 'assocGetWithAddress',{extaddr: ieeeAddr, nwkaddr: networkAddress} + ); + debug(`Response timeout recovery: Node relation ${match.payload.noderelation} (${ieeeAddr})`); + if (this.supportsAssocAdd() && this.supportsAssocRemove() && match.payload.noderelation == 1) { + debug(`Response timeout recovery: Rewrite association table entry (${ieeeAddr})`); + await this.znp.request(Subsystem.UTIL, 'assocRemove', {ieeeadr: ieeeAddr}); + assocRestore = + {ieeeadr: ieeeAddr, nwkaddr: networkAddress, noderelation: match.payload.noderelation}; + await this.znp.request(Subsystem.UTIL, 'assocAdd', assocRestore); + } // No response could be of invalid route, e.g. when message is send to wrong parent of end device. await this.discoverRoute(networkAddress); return this.sendZclFrameToEndpointInternal( diff --git a/test/adapter/z-stack/adapter.test.ts b/test/adapter/z-stack/adapter.test.ts index 451157f2d9..85ed6ec299 100644 --- a/test/adapter/z-stack/adapter.test.ts +++ b/test/adapter/z-stack/adapter.test.ts @@ -2453,6 +2453,34 @@ describe("zstack-adapter", () => { basicMocks(); await adapter.start(); + mockZnpRequest.mockClear(); + assocGetWithAddressNodeRelation = 2; + const responseMismatchFrame = Zcl.ZclFrame.create(Zcl.FrameType.GLOBAL, Zcl.Direction.SERVER_TO_CLIENT, true, null, 102, 'readRsp', 0, [{attrId: 0, attrData: 5, dataType: 32, status: 0}]); + const frame = Zcl.ZclFrame.create(Zcl.FrameType.GLOBAL, Zcl.Direction.CLIENT_TO_SERVER, false, null, 100, 'read', 0, [{attrId: 0}]); + const objectMismatch = {type: Type.AREQ, subsystem: Subsystem.AF, command: 'incomingMsg', payload: {clusterid: 0, srcendpoint: 20, srcaddr: 2, linkquality: 101, groupid: 12, data: responseMismatchFrame.toBuffer()}}; + let error; + try { + mockSetTimeout(); + const response = adapter.sendZclFrameToEndpoint('0x02', 2, 20, frame, 1, false, false); + znpReceived(objectMismatch); + await response; + } catch (e) { + error = e; + } + + expect(mockQueueExecute.mock.calls[0][1]).toBe(2); + expect(mockZnpRequest).toBeCalledTimes(4); + expect(mockZnpRequest).toHaveBeenNthCalledWith(1, 4, "dataRequest", {"clusterid": 0, "data": frame.toBuffer(), "destendpoint": 20, "dstaddr": 2, "len": 5, "options": 0, "radius": 30, "srcendpoint": 1, "transid": 1}, 99) + expect(mockZnpRequest).toHaveBeenNthCalledWith(2, 7, "assocGetWithAddress", {extaddr: '0x02', nwkaddr: 2}) + expect(mockZnpRequest).toHaveBeenNthCalledWith(3, 5, 'extRouteDisc', {dstAddr: 2, options: 0, radius: Constants.AF.DEFAULT_RADIUS}) + expect(mockZnpRequest).toHaveBeenNthCalledWith(4, 4, "dataRequest", {"clusterid": 0, "data": frame.toBuffer(), "destendpoint": 20, "dstaddr": 2, "len": 5, "options": 0, "radius": 30, "srcendpoint": 1, "transid": 2}, 99) + expect(error).toStrictEqual(new Error("Timeout - 2 - 20 - 100 - 0 - 1 after 1ms")); + }); + + it('Send zcl frame network address timeout should discover route, rewrite child entry and retry for sleepy end device', async () => { + basicMocks(); + await adapter.start(); + mockZnpRequest.mockClear(); const responseMismatchFrame = Zcl.ZclFrame.create(Zcl.FrameType.GLOBAL, Zcl.Direction.SERVER_TO_CLIENT, true, null, 102, 'readRsp', 0, [{attrId: 0, attrData: 5, dataType: 32, status: 0}]); @@ -2469,10 +2497,13 @@ describe("zstack-adapter", () => { } expect(mockQueueExecute.mock.calls[0][1]).toBe(2); - expect(mockZnpRequest).toBeCalledTimes(3); + expect(mockZnpRequest).toBeCalledTimes(6); expect(mockZnpRequest).toHaveBeenNthCalledWith(1, 4, "dataRequest", {"clusterid": 0, "data": frame.toBuffer(), "destendpoint": 20, "dstaddr": 2, "len": 5, "options": 0, "radius": 30, "srcendpoint": 1, "transid": 1}, 99) - expect(mockZnpRequest).toHaveBeenNthCalledWith(2, 5, 'extRouteDisc', {dstAddr: 2, options: 0, radius: Constants.AF.DEFAULT_RADIUS}) - expect(mockZnpRequest).toHaveBeenNthCalledWith(3, 4, "dataRequest", {"clusterid": 0, "data": frame.toBuffer(), "destendpoint": 20, "dstaddr": 2, "len": 5, "options": 0, "radius": 30, "srcendpoint": 1, "transid": 2}, 99) + expect(mockZnpRequest).toHaveBeenNthCalledWith(2, 7, "assocGetWithAddress", {extaddr: '0x02', nwkaddr: 2}) + expect(mockZnpRequest).toHaveBeenNthCalledWith(3, 7, "assocRemove", {ieeeadr: '0x02'}) + expect(mockZnpRequest).toHaveBeenNthCalledWith(4, 7, "assocAdd", {ieeeadr: '0x02', nwkaddr: 2, noderelation: 1}) + expect(mockZnpRequest).toHaveBeenNthCalledWith(5, 5, 'extRouteDisc', {dstAddr: 2, options: 0, radius: Constants.AF.DEFAULT_RADIUS}) + expect(mockZnpRequest).toHaveBeenNthCalledWith(6, 4, "dataRequest", {"clusterid": 0, "data": frame.toBuffer(), "destendpoint": 20, "dstaddr": 2, "len": 5, "options": 0, "radius": 30, "srcendpoint": 1, "transid": 2}, 99) expect(error).toStrictEqual(new Error("Timeout - 2 - 20 - 100 - 0 - 1 after 1ms")); });