Open discusion on half lost of end device

[zoic21]

Hello,

I want to open discusion on half lost of end device. I explain :

What device type of device ?

Danfoss ally, but same thing on eurotornics valve, danalock v3.... All battery power device with action

What's it does ?

I can received communication from device (like temperature for valve) but I can't send any command (error on each request). So device is connected to network (it's not a pairing issue)

I send :

[2020-12-02 10:11:53][DEBUG] : [0xb42f] Extending timeout for 0x49 request
[2020-12-02 10:11:53][DEBUG] : Sending Zigbee request with tsn 73 under 74 request id, data: b'0049021200293408'
[2020-12-02 10:11:53][DEBUG] : Command Command.aps_data_request (23, 74, 0, <DeconzAddressEndpoint address_mode=2 address=0xB42F endpoint=1>, 260, 513, 1, b'\x00I\x02\x12\x00)4\x08', 2, 0)
[2020-12-02 10:11:53][DEBUG] : Send: 0x12aa001e0017004a00022fb4010401010201080000490212002934080200
[2020-12-02 10:11:53][DEBUG] : Frame received: 0x12aa0009000200224a
[2020-12-02 10:11:53][DEBUG] : APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 74]
[2020-12-02 10:11:53][DEBUG] : Frame received: 0x0eab000700a600
[2020-12-02 10:11:53][DEBUG] : Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0]
[2020-12-02 10:11:53][DEBUG] : Command Command.aps_data_confirm (0,)
[2020-12-02 10:11:53][DEBUG] : Send: 0x04ab0007000000
[2020-12-02 10:11:53][DEBUG] : Frame received: 0x04ab0013000c00224a022fb401010000000000
[2020-12-02 10:11:53][DEBUG] : APS data confirm response for request with id 74: 00
[2020-12-02 10:11:53][DEBUG] : Request id: 0x4a 'aps_data_confirm' for <DeconzAddressEndpoint address_mode=ADDRESS_MODE.NWK address=0xb42f endpoint=1>, status: 0x00

Error :

[2020-12-02 10:12:21][DEBUG] : Traceback (most recent call last):
File "/var/www/html/plugins/zigbee/resources/zigbeed/restServer.py", line 164, in put
await zdevices.write_attributes(self.json_args)
File "/var/www/html/plugins/zigbee/resources/zigbeed/zdevices.py", line 87, in write_attributes
await cluster.write_attributes(attributes,manufacturer=manufacturer)
File "/usr/local/lib/python3.7/dist-packages/zigpy/zcl/__init__.py", line 352, in write_attributes
result = await self._write_attributes(args, manufacturer=manufacturer)
File "/usr/local/lib/python3.7/dist-packages/zigpy/device.py", line 210, in request
result = await asyncio.wait_for(req.result, timeout)
File "/usr/lib/python3.7/asyncio/tasks.py", line 423, in wait_for
raise futures.TimeoutError()
concurrent.futures._base.TimeoutError

Or [0x49c6:43:0x0502]: Message send failure

When it's happen ?

I think it's happen when device send message on gateway and gateway is not here.

Workarround

Remove device battery wait 30s and reinsert it. Device reboot and it's ok

Conclusion

I think I miss something on the functioning of the zigbee, maybe we need to send a specific message to device to say "hello I'am here again".

Does anyone have experience with this kind of problem?

Thank in advance

[Adminiuga]

Do a packet capture.
Device does receive the write attribute request: [2020-12-02 10:11:53][DEBUG] : APS data confirm response for request with id 74: 00
You do not get the "write attribute response" request back from the device. Why 🤷

And yes, if the coordinator is the "parent' of the device and is not available for some time then device should start looking for other parents. But if no other parents are available, then really it should continue trying, but in reality it is vendor dependent. Xiaomi just drops off the network.

[MattWestb]

Is the end device connected through one router and if wah router is it (some old OSRAM routers is not playing nice and not forwarding all acks from end device or corrupting them) ?

My Philips HUE have starting changing to very crazy routes with the worse signal im my mesh but i think they is not liking real zigbee 3 routers.

[zoic21]

Ok after 48h valve accept again order (without remove battery). It's driving me crazy I can't understand how someone can code 48hours rececheck of something to allow order but not after send information successfull

[HiFiPhile]

Hi,
I'm working on a Danfoss Ally with CC2652R and facing the same issue. The CC2652R act as coordinator and always online, about 2 hours later i can no longer send command to the valve.

DEBUG:zigpy.device:[0x020c] Extending timeout for 0x02 request
DEBUG:zigpy_znp.zigbee.application:Starting watchdog loop
DEBUG:zigpy_znp.api:Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x020C), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=513, TSN=2, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK|ACK_REQUEST: 48>, Radius=30, Data=b'\x00\x02\x15\x00\x00\x64')
DEBUG:zigpy_znp.api:Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
DEBUG:zigpy_znp.api:Received command: AF.DataConfirm.Callback(Status=<Status.NWK_NO_ROUTE: 205>, Endpoint=1, TSN=2)
DEBUG:zigpy_znp.zigbee.application:Request failed (Unsuccessful request status code: <Status.NWK_NO_ROUTE: 205>), retry attempt 1 of 5
DEBUG:zigpy_znp.api:Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x020C), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=513, TSN=2, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK|ACK_REQUEST: 48>, Radius=30, Data=b'\x00\x02\x15\x00\x00\x64')
DEBUG:zigpy_znp.api:Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
DEBUG:zigpy_znp.api:Received command: AF.DataConfirm.Callback(Status=<Status.NWK_NO_ROUTE: 205>, Endpoint=1, TSN=2)
DEBUG:zigpy_znp.api:Sending request: ZDO.ExtRouteDisc.Req(Dst=0x020C, Options=<RouteDiscoveryOptions.UNICAST: 0>, Radius=30)
DEBUG:zigpy_znp.api:Received command: ZDO.ExtRouteDisc.Rsp(Status=<Status.SUCCESS: 0>)
DEBUG:zigpy_znp.zigbee.application:Request failed (Unsuccessful request status code: <Status.NWK_NO_ROUTE: 205>), retry attempt 2 of 5
DEBUG:zigpy_znp.api:Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x020C), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=513, TSN=2, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK|ACK_REQUEST: 48>, Radius=30, Data=b'\x00\x02\x15\x00\x00\x64')
DEBUG:zigpy_znp.api:Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
DEBUG:zigpy_znp.api:Received command: AF.DataConfirm.Callback(Status=<Status.NWK_NO_ROUTE: 205>, Endpoint=1, TSN=2)
DEBUG:zigpy_znp.zigbee.application:Request failed (Unsuccessful request status code: <Status.NWK_NO_ROUTE: 205>), retry attempt 3 of 5
DEBUG:zigpy_znp.api:Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x020C), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=513, TSN=2, Options=<TransmitOptions.ACK_REQUEST: 16>, Radius=30, Data=b'\x00\x02\x15\x00\x00\x64')
DEBUG:zigpy_znp.api:Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
DEBUG:zigpy_znp.api:Received command: AF.DataConfirm.Callback(Status=<Status.NWK_NO_ROUTE: 205>, Endpoint=1, TSN=2)
DEBUG:zigpy_znp.zigbee.application:Request failed (Unsuccessful request status code: <Status.NWK_NO_ROUTE: 205>), retry attempt 4 of 5
DEBUG:zigpy_znp.api:Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x020C), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=513, TSN=2, Options=<TransmitOptions.ACK_REQUEST: 16>, Radius=30, Data=b'\x00\x02\x15\x00\x00\x64')
DEBUG:zigpy_znp.api:Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
DEBUG:zigpy_znp.api:Received command: AF.DataConfirm.Callback(Status=<Status.NWK_NO_ROUTE: 205>, Endpoint=1, TSN=2)
DEBUG:zigpy_znp.zigbee.application:Request failed (Unsuccessful request status code: <Status.NWK_NO_ROUTE: 205>), retry attempt 5 of 5
Request failed after 5 attempts: <Status.NWK_NO_ROUTE: 205>

As they are binded, I can still receive reports:

DEBUG:zigpy_znp.api:Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=513, SrcAddr=0x020C, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=78, SecurityUse=<Bool.false: 0>, TimeStamp=15337998, TSN=0, Data=b'\x08\x7A\x0A\x00\x00\x29\x04\x09', MacSrcAddr=0x020C, MsgResultRadius=29)
DEBUG:zigpy.zcl:[0x020c:1:0x0201] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=122 command_id=Command.Report_Attributes>
DEBUG:zigpy.zcl:[0x020c:1:0x0201] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=int16s, value=2308>)]]
DEBUG:zigpy.zcl:[0x020c:1:0x0201] Attribute report received: local_temp=2308
<__main__.MainListener object at 0x7f207963e5b0>
17:30:45 Received an attribute update local_temp(0)=2308 from device 84:2e:14:ff:fe:5e:55:14 RSSI=None LQI=78
DEBUG:zigpy_znp.api:Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x020C), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=513, TSN=122, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK: 32>, Radius=30, Data=b'\x18\x7A\x0B\x0A\x00')
DEBUG:aiosqlite:executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f2079ecf990>, 'INSERT OR REPLACE INTO attributes VALUES (?, ?, ?, ?, ?)', (84:2e:14:ff:fe:5e:55:14, 1, 513, 0, 2308))
DEBUG:aiosqlite:operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f2079ecf990>, 'INSERT OR REPLACE INTO attributes VALUES (?, ?, ?, ?, ?)', (84:2e:14:ff:fe:5e:55:14, 1, 513, 0, 2308)) completed
DEBUG:aiosqlite:executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f2079ecf990>)
DEBUG:aiosqlite:operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f2079ecf990>) completed
DEBUG:zigpy_znp.api:Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
DEBUG:zigpy_znp.api:Received command: AF.DataConfirm.Callback(Status=<Status.MAC_NO_ACK: 233>, Endpoint=1, TSN=122)
DEBUG:zigpy_znp.zigbee.application:Request failed (Unsuccessful request status code: <Status.MAC_NO_ACK: 233>), retry attempt 1 of 5
DEBUG:zigpy_znp.api:Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x020C), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=513, TSN=122, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK: 32>, Radius=30, Data=b'\x18\x7A\x0B\x0A\x00')
DEBUG:zigpy_znp.api:Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
DEBUG:zigpy_znp.api:Received command: AF.DataConfirm.Callback(Status=<Status.MAC_NO_ACK: 233>, Endpoint=1, TSN=122)
DEBUG:zigpy_znp.api:Sending request: ZDO.ExtRouteDisc.Req(Dst=0x020C, Options=<RouteDiscoveryOptions.UNICAST: 0>, Radius=30)
DEBUG:zigpy_znp.api:Received command: ZDO.ExtRouteDisc.Rsp(Status=<Status.SUCCESS: 0>)
DEBUG:zigpy_znp.zigbee.application:Request failed (Unsuccessful request status code: <Status.MAC_NO_ACK: 233>), retry attempt 2 of 5
DEBUG:zigpy_znp.api:Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x020C), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=513, TSN=122, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK: 32>, Radius=30, Data=b'\x18\x7A\x0B\x0A\x00')
DEBUG:zigpy_znp.api:Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
DEBUG:zigpy_znp.api:Received command: AF.DataConfirm.Callback(Status=<Status.MAC_NO_ACK: 233>, Endpoint=1, TSN=122)
DEBUG:zigpy_znp.zigbee.application:Request failed (Unsuccessful request status code: <Status.MAC_NO_ACK: 233>), retry attempt 3 of 5
DEBUG:zigpy_znp.api:Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x020C), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=513, TSN=122, Options=<TransmitOptions.NONE: 0>, Radius=30, Data=b'\x18\x7A\x0B\x0A\x00')
DEBUG:zigpy_znp.api:Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
DEBUG:zigpy_znp.api:Received command: AF.DataConfirm.Callback(Status=<Status.MAC_NO_ACK: 233>, Endpoint=1, TSN=122)
DEBUG:zigpy_znp.zigbee.application:Request failed (Unsuccessful request status code: <Status.MAC_NO_ACK: 233>), retry attempt 4 of 5
DEBUG:zigpy_znp.api:Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x020C), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=513, TSN=122, Options=<TransmitOptions.NONE: 0>, Radius=30, Data=b'\x18\x7A\x0B\x0A\x00')
DEBUG:zigpy_znp.api:Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
DEBUG:zigpy_znp.api:Received command: AF.DataConfirm.Callback(Status=<Status.MAC_NO_ACK: 233>, Endpoint=1, TSN=122)
DEBUG:zigpy_znp.zigbee.application:Request failed (Unsuccessful request status code: <Status.MAC_NO_ACK: 233>), retry attempt 5 of 5
DEBUG:zigpy_znp.api:Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=513, SrcAddr=0x020C, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=81, SecurityUse=<Bool.false: 0>, TimeStamp=15717430, TSN=0, Data=b'\x08\x7A\x0A\x00\x00\x29\x04\x09', MacSrcAddr=0x020C, MsgResultRadius=29)
DEBUG:zigpy.zcl:[0x020c:1:0x0201] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=122 command_id=Command.Report_Attributes>
DEBUG:zigpy.zcl:[0x020c:1:0x0201] ZCL request 0x000a: [[Attribute(attrid=0, value=<TypeValue type=int16s, value=2308>)]]
DEBUG:zigpy.zcl:[0x020c:1:0x0201] Attribute report received: local_temp=2308
<__main__.MainListener object at 0x7f207963e5b0>
17:30:52 Received an attribute update local_temp(0)=2308 from device 84:2e:14:ff:fe:5e:55:14 RSSI=None LQI=81
DEBUG:zigpy.util:Duplicate 122 TSN
DEBUG:aiosqlite:executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f2079ecf990>, 'INSERT OR REPLACE INTO attributes VALUES (?, ?, ?, ?, ?)', (84:2e:14:ff:fe:5e:55:14, 1, 513, 0, 2308))
DEBUG:aiosqlite:operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7f2079ecf990>, 'INSERT OR REPLACE INTO attributes VALUES (?, ?, ?, ?, ?)', (84:2e:14:ff:fe:5e:55:14, 1, 513, 0, 2308)) completed
DEBUG:aiosqlite:executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f2079ecf990>)
DEBUG:aiosqlite:operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f2079ecf990>) completed

[Ebbe]

Perhaps this is not a problem with zigpy. I run the official deconz software with a Conbee II. Sometimes when writing to an Ally thermostat is simply fails. I still get data, but sometimes writes just fails. I came here to see if zigpy was more stable, but perhaps it's the hardware or firmware. I've updated them to the latest (1.08: https://www.danfoss.com/en/products/smart-heating/dhs/smart-heating/danfoss-ally/danfoss-ally-support/#tab-software) but no change.

[github-actions]

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.