Zigbee - Device wont pair

[Mr-JR (James R)]

Raspberry Pi 4
Dual Nortek USB Zigbee/Zwave
openHAB 4.1.1 Release Build

I am having a frustrating time getting a previously paired zigbee device to re-join … Device had previously worked but stopped, so I decided to Delete it, reset the device to factory defaults and redo the scanning process.

Well after many attempts and trying various things like a reboot it will not join.

Does anyone have experience with the zigbee binding that could offer some tricks to try? The debug log doesn’t seem to show much. Im comfortable reading code but I dont even know the basic process that the zigbee binding goes through. I had another deivce that behaved the same. That device itself could be paired with a Smartthings Hub with no problem.

This is a Keen Smart Vent.

From the logs is the device communicating? It seems it is since if I run the scan when it is off I dont see any entries. But with the device in pairing mode there is activity.

Any thoughts on what I might try?

2024-11-10 08:52:44.455 [INFO ] [openhab.event.InboxRemovedEvent     ] - Discovery Result with UID 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' has been removed.
2024-11-10 09:00:06.385 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Discovery: Starting discovery for existing device
2024-11-10 09:05:12.293 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0022A3000011CF86: ZigBee saving network state complete.
2024-11-10 09:05:40.981 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0022A3000011CF86: ZigBee saving network state complete.
2024-11-10 09:05:41.720 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0022A3000011CF86: ZigBee saving network state complete.
2024-11-10 09:05:50.982 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0022A3000011CF86: ZigBee saving network state complete.
2024-11-10 09:07:38.592 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0022A3000011CF86: ZigBee saving network state complete.
2024-11-10 09:08:07.539 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0022A3000011CF86: ZigBee saving network state complete.
2024-11-10 09:08:17.211 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0022A3000011CF86: ZigBee saving network state complete.
2024-11-10 09:14:57.797 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Starting ZigBee device discovery
2024-11-10 09:14:57.798 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:ZigBee_Bridge
2024-11-10 09:14:57.801 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' to inbox.
2024-11-10 09:14:57.802 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Node discovery not complete
2024-11-10 09:14:57.805 [INFO ] [openhab.event.InboxAddedEvent       ] - Discovery Result with UID 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' has been added.
2024-11-10 09:19:43.167 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Starting ZigBee device discovery
2024-11-10 09:19:43.170 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:ZigBee_Bridge
2024-11-10 09:19:43.173 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Node discovery not complete
2024-11-10 10:25:26.433 [INFO ] [openhab.event.InboxRemovedEvent     ] - Discovery Result with UID 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' has been removed.
2024-11-10 10:25:26.454 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' changed from UNINITIALIZED to INITIALIZING
2024-11-10 10:25:26.468 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Initializing ZigBee thing handler zigbee:device:ZigBee_Bridge:0022a3000011cf86
2024-11-10 10:25:26.471 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Coordinator status changed to ONLINE.
2024-11-10 10:25:26.471 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' changed from INITIALIZING to UNKNOWN
2024-11-10 10:25:26.472 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Coordinator is ONLINE. Starting device initialisation.
2024-11-10 10:25:26.489 [INFO ] [penhab.event.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:device:ZigBee_Bridge:0022a3000011cf86 changed to UNKNOWN.
2024-11-10 10:25:34.050 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:25:34.053 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' changed from UNKNOWN to OFFLINE: Node has not completed discovery
2024-11-10 10:25:45.145 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Handler dispose.
2024-11-10 10:25:45.147 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Can't find OTA cluster
2024-11-10 10:25:45.148 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker removed for thingUID=zigbee:device:ZigBee_Bridge:0022a3000011cf86
2024-11-10 10:25:45.149 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Initializing ZigBee thing handler zigbee:device:ZigBee_Bridge:0022a3000011cf86
2024-11-10 10:25:45.151 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Coordinator status changed to ONLINE.
2024-11-10 10:25:45.152 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' changed from OFFLINE: Node has not completed discovery to UNKNOWN
2024-11-10 10:25:45.154 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Coordinator is ONLINE. Starting device initialisation.
2024-11-10 10:26:04.344 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:26:04.347 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' changed from UNKNOWN to OFFLINE: Node has not completed discovery
2024-11-10 10:28:55.327 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Discovery: Starting discovery for existing device
2024-11-10 10:33:00.877 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Starting ZigBee device discovery
2024-11-10 10:33:00.879 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:ZigBee_Bridge
2024-11-10 10:33:00.882 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Node discovery not complete
2024-11-10 10:33:25.709 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Discovery: Starting discovery for existing device
2024-11-10 10:38:08.974 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Starting ZigBee device discovery
2024-11-10 10:38:08.976 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:ZigBee_Bridge
2024-11-10 10:38:08.979 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Node discovery not complete
2024-11-10 10:40:11.811 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Discovery: Starting discovery for existing device
2024-11-10 10:40:38.824 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' changed from OFFLINE: Node has not completed discovery to REMOVING
2024-11-10 10:40:38.830 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - 0022A3000011CF86: ZigBee leave command
2024-11-10 10:40:38.832 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - 0022A3000011CF86: ZigBee leave command to 35636
2024-11-10 10:42:48.885 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' changed from REMOVING to UNINITIALIZED
2024-11-10 10:42:48.902 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Handler dispose.
2024-11-10 10:42:48.904 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Can't find OTA cluster
2024-11-10 10:42:48.905 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker removed for thingUID=zigbee:device:ZigBee_Bridge:0022a3000011cf86
2024-11-10 10:42:48.942 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2024-11-10 10:44:00.457 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Discovery: Starting discovery for existing device
2024-11-10 10:45:21.410 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Discovery: Starting discovery for existing device
2024-11-10 10:45:21.879 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0022A3000011CF86: ZigBee saving network state complete.
2024-11-10 10:45:38.843 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0022A3000011CF86: ZigBee removing network state complete
2024-11-10 10:46:02.461 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Starting ZigBee device discovery
2024-11-10 10:46:02.464 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:ZigBee_Bridge
2024-11-10 10:46:02.468 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' to inbox.
2024-11-10 10:46:02.469 [INFO ] [openhab.event.InboxAddedEvent       ] - Discovery Result with UID 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' has been added.
2024-11-10 10:46:02.470 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Node discovery not complete
2024-11-10 10:46:31.824 [INFO ] [openhab.event.InboxRemovedEvent     ] - Discovery Result with UID 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' has been removed.
2024-11-10 10:46:31.869 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' changed from UNINITIALIZED to INITIALIZING
2024-11-10 10:46:31.884 [INFO ] [penhab.event.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:device:ZigBee_Bridge:0022a3000011cf86 changed to UNKNOWN.
2024-11-10 10:46:31.894 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Initializing ZigBee thing handler zigbee:device:ZigBee_Bridge:0022a3000011cf86
2024-11-10 10:46:31.897 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Coordinator status changed to ONLINE.
2024-11-10 10:46:31.898 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Coordinator is ONLINE. Starting device initialisation.
2024-11-10 10:46:31.899 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' changed from INITIALIZING to UNKNOWN
2024-11-10 10:46:47.391 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=3EC8, endpoints=[]]
2024-11-10 10:46:47.652 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0022A3000011CF86: ZigBee saving network state complete.
2024-11-10 10:47:37.019 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1972611ms
2024-11-10 10:47:37.022 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:47:37.024 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1825290ms
2024-11-10 10:47:37.209 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:47:37.210 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1815506ms
2024-11-10 10:47:42.018 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:47:42.019 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1846530ms
2024-11-10 10:47:42.021 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:47:42.022 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1973027ms
2024-11-10 10:47:42.420 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:47:42.421 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1920227ms
2024-11-10 10:47:47.032 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:47:47.033 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1803156ms
2024-11-10 10:47:47.035 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:47:47.036 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1953331ms
2024-11-10 10:47:47.225 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:47:47.226 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1828526ms
2024-11-10 10:47:52.029 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:47:52.030 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1896737ms
2024-11-10 10:47:52.032 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:47:52.033 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1966238ms
2024-11-10 10:47:52.221 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:47:52.222 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1884162ms
2024-11-10 10:47:59.391 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:47:59.400 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:ZigBee_Bridge:0022a3000011cf86' changed from UNKNOWN to OFFLINE: Node has not completed discovery
2024-11-10 10:48:02.023 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:02.025 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1857675ms
2024-11-10 10:48:02.027 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:02.029 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1886847ms
2024-11-10 10:48:02.217 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:02.219 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1824805ms
2024-11-10 10:48:07.024 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:07.026 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1931185ms
2024-11-10 10:48:07.045 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:07.047 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1821907ms
2024-11-10 10:48:07.218 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:07.219 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1922851ms
2024-11-10 10:48:12.029 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:12.030 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1952099ms
2024-11-10 10:48:12.032 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:12.034 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1920158ms
2024-11-10 10:48:12.218 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:12.219 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1859614ms
2024-11-10 10:48:17.029 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:17.030 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1801108ms
2024-11-10 10:48:17.032 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:17.033 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1881073ms
2024-11-10 10:48:17.223 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:17.224 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1832044ms
2024-11-10 10:48:22.034 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:22.035 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1943214ms
2024-11-10 10:48:22.037 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:22.038 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1813558ms
2024-11-10 10:48:22.242 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:22.244 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1901419ms
2024-11-10 10:48:27.035 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:27.036 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1903121ms
2024-11-10 10:48:27.039 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:27.040 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1971240ms
2024-11-10 10:48:27.228 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:48:27.230 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1901998ms
2024-11-10 10:48:30.076 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:50:41.091 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.094 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.101 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.105 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.108 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.129 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.134 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.139 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.142 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.148 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.154 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.157 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.161 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.163 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.166 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.168 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.170 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.173 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.176 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.178 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=7D2D, endpoints=[]]
2024-11-10 10:50:41.450 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0022A3000011CF86: ZigBee saving network state complete.
2024-11-10 10:52:17.163 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Starting ZigBee device discovery
2024-11-10 10:52:17.165 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:ZigBee_Bridge
2024-11-10 10:52:17.169 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Node discovery not complete
2024-11-10 10:52:22.206 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.209 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.212 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.215 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.218 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.221 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.224 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.227 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.229 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.232 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.236 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.239 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.242 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.245 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.248 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.251 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.255 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.257 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.259 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:52:22.261 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node has not finished discovery
2024-11-10 10:56:03.776 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Starting ZigBee device discovery
2024-11-10 10:56:03.777 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:ZigBee_Bridge
2024-11-10 10:56:03.780 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Node discovery not complete
2024-11-10 10:56:03.789 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Starting ZigBee device discovery
2024-11-10 10:56:03.791 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:ZigBee_Bridge
2024-11-10 10:56:03.794 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Node discovery not complete
2024-11-10 10:57:12.216 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Discovery: Starting discovery for existing device
2024-11-10 10:57:49.026 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:57:49.028 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1903065ms
2024-11-10 10:57:49.048 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:57:49.049 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1964012ms
2024-11-10 10:57:53.775 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:57:53.776 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1951336ms
2024-11-10 10:57:53.778 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:57:53.779 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1811665ms
2024-11-10 10:57:53.970 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:57:53.971 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1873615ms
2024-11-10 10:57:58.777 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:57:58.779 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1853700ms
2024-11-10 10:57:58.780 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:57:58.781 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1882179ms
2024-11-10 10:57:58.968 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:57:58.969 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1864892ms
2024-11-10 10:58:03.782 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:03.783 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1871955ms
2024-11-10 10:58:03.785 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:03.787 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1800752ms
2024-11-10 10:58:03.976 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:03.977 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1806658ms
2024-11-10 10:58:08.778 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:08.780 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1910951ms
2024-11-10 10:58:08.782 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:08.784 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1929373ms
2024-11-10 10:58:08.969 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:08.970 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1860396ms
2024-11-10 10:58:13.781 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:13.783 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1871039ms
2024-11-10 10:58:13.784 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:13.786 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1803086ms
2024-11-10 10:58:13.976 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:13.977 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1837403ms
2024-11-10 10:58:17.481 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=CCD9, endpoints=[]]
2024-11-10 10:58:17.489 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=CCD9, endpoints=[]]
2024-11-10 10:58:17.492 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=CCD9, endpoints=[]]
2024-11-10 10:58:17.752 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0022A3000011CF86: ZigBee saving network state complete.
2024-11-10 10:58:18.783 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:18.785 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1874197ms
2024-11-10 10:58:18.786 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:18.788 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1850019ms
2024-11-10 10:58:18.974 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:18.975 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1833570ms
2024-11-10 10:58:23.778 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:23.780 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1836701ms
2024-11-10 10:58:23.799 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:23.801 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1850576ms
2024-11-10 10:58:23.802 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:23.804 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1936555ms
2024-11-10 10:58:23.805 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:23.806 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1833029ms
2024-11-10 10:58:27.481 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=AA39, endpoints=[]]
2024-11-10 10:58:27.489 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=AA39, endpoints=[]]
2024-11-10 10:58:27.492 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=AA39, endpoints=[]]
2024-11-10 10:58:27.497 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=AA39, endpoints=[]]
2024-11-10 10:58:27.501 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=AA39, endpoints=[]]
2024-11-10 10:58:27.504 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=AA39, endpoints=[]]
2024-11-10 10:58:27.507 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=AA39, endpoints=[]]
2024-11-10 10:58:27.509 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=AA39, endpoints=[]]
2024-11-10 10:58:27.512 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=AA39, endpoints=[]]
2024-11-10 10:58:27.516 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=AA39, endpoints=[]]
2024-11-10 10:58:27.521 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=AA39, endpoints=[]]
2024-11-10 10:58:27.526 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=AA39, endpoints=[]]
2024-11-10 10:58:27.538 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=AA39, endpoints=[]]
2024-11-10 10:58:27.543 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=AA39, endpoints=[]]
2024-11-10 10:58:27.801 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0022A3000011CF86: ZigBee saving network state complete.
2024-11-10 10:58:29.400 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:29.401 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1937387ms
2024-11-10 10:58:29.421 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:29.423 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1881515ms
2024-11-10 10:58:31.307 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:31.308 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1826432ms
2024-11-10 10:58:33.778 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:33.779 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1827277ms
2024-11-10 10:58:33.974 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:33.975 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1896751ms
2024-11-10 10:58:36.938 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=8822, endpoints=[]]
2024-11-10 10:58:36.945 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=8822, endpoints=[]]
2024-11-10 10:58:36.947 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=8822, endpoints=[]]
2024-11-10 10:58:37.209 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0022A3000011CF86: ZigBee saving network state complete.
2024-11-10 10:58:38.782 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:38.784 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1857594ms
2024-11-10 10:58:38.785 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:38.786 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1863670ms
2024-11-10 10:58:39.172 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:39.173 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1913296ms
2024-11-10 10:58:43.787 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:43.788 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1863175ms
2024-11-10 10:58:43.790 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:43.791 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1921060ms
2024-11-10 10:58:43.979 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling stopped
2024-11-10 10:58:43.980 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Polling initialised at 1826988ms
2024-11-10 10:58:56.390 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=D9F5, endpoints=[]]
2024-11-10 10:58:56.397 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=D9F5, endpoints=[]]
2024-11-10 10:58:56.468 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=D9F5, endpoints=[]]
2024-11-10 10:58:56.471 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0022A3000011CF86: Node updated - ZigBeeNode [state=ONLINE, IEEE=0022A3000011CF86, NWK=D9F5, endpoints=[]]
2024-11-10 10:58:56.737 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0022A3000011CF86: ZigBee saving network state complete.
2024-11-10 10:59:30.138 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Discovery: Starting discovery for existing device

[chris (Chris Jackson)]

I’m not really sure what’s going on here - there are lots of repeat messages in this log so I suspect there’s something amiss with your system and this makes it hard to work out what is going on…

[Mr-JR (James R)]

Yes sorry Chris - I just realized I didnt have all the debug on … this log the device is definitely not responding to the NodeDescriptorRequest and PowerDescriptorRequest … any ideas what could be happening?

2024-11-10 12:55:48.629 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: running NODE_DESCRIPTOR
2024-11-10 12:55:48.631 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=0, state=WAITING, sendCnt=0, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=--, nwkAddrOfInterest=D9F5]]
2024-11-10 12:55:48.634 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=3, state=WAITING, sendCnt=0, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=4E, nwkAddrOfInterest=D9F5]]
2024-11-10 12:55:58.637 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10005, state=FAILED, sendCnt=1, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=4E, nwkAddrOfInterest=D9F5]]
2024-11-10 12:55:58.638 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 12:55:58.640 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10008, state=WAITING, sendCnt=1, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=4E, nwkAddrOfInterest=D9F5]]
2024-11-10 12:55:58.642 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10010, state=WAITING, sendCnt=1, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=4E, nwkAddrOfInterest=D9F5]]
2024-11-10 12:56:08.644 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20012, state=FAILED, sendCnt=2, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=4E, nwkAddrOfInterest=D9F5]]
2024-11-10 12:56:08.646 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 12:56:08.647 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete exceeded max retries 2
2024-11-10 12:56:08.648 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20016, state=CANCELLED, sendCnt=2, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=4E, nwkAddrOfInterest=D9F5]]
2024-11-10 12:56:08.649 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: NodeDescriptorResponse returned null
2024-11-10 12:56:08.649 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20017, state=CANCELLED, sendCnt=2, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=4E, nwkAddrOfInterest=D9F5]]
2024-11-10 12:56:08.650 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: request NODE_DESCRIPTOR failed. Retry 9, wait 19368ms before retry.
2024-11-10 12:56:08.652 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2024-11-10 12:56:28.019 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: running NODE_DESCRIPTOR
2024-11-10 12:56:28.021 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=0, state=WAITING, sendCnt=0, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=--, nwkAddrOfInterest=D9F5]]
2024-11-10 12:56:28.023 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=2, state=WAITING, sendCnt=0, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=53, nwkAddrOfInterest=D9F5]]
2024-11-10 12:56:38.026 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10005, state=FAILED, sendCnt=1, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=53, nwkAddrOfInterest=D9F5]]
2024-11-10 12:56:38.028 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 12:56:38.029 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10008, state=WAITING, sendCnt=1, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=53, nwkAddrOfInterest=D9F5]]
2024-11-10 12:56:38.031 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10010, state=WAITING, sendCnt=1, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=53, nwkAddrOfInterest=D9F5]]
2024-11-10 12:56:48.033 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20012, state=FAILED, sendCnt=2, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=53, nwkAddrOfInterest=D9F5]]
2024-11-10 12:56:48.035 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 12:56:48.037 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete exceeded max retries 2
2024-11-10 12:56:48.038 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20017, state=CANCELLED, sendCnt=2, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=53, nwkAddrOfInterest=D9F5]]
2024-11-10 12:56:48.040 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: NodeDescriptorResponse returned null
2024-11-10 12:56:48.041 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: request NODE_DESCRIPTOR failed. Retry 10, wait 23672ms before retry.
2024-11-10 12:56:48.041 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20019, state=CANCELLED, sendCnt=2, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=53, nwkAddrOfInterest=D9F5]]
2024-11-10 12:56:48.043 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2024-11-10 12:57:11.714 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: running NODE_DESCRIPTOR
2024-11-10 12:57:11.716 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=0, state=WAITING, sendCnt=0, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=--, nwkAddrOfInterest=D9F5]]
2024-11-10 12:57:11.718 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=3, state=WAITING, sendCnt=0, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=59, nwkAddrOfInterest=D9F5]]
2024-11-10 12:57:21.721 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10005, state=FAILED, sendCnt=1, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=59, nwkAddrOfInterest=D9F5]]
2024-11-10 12:57:21.728 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 12:57:21.730 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10014, state=WAITING, sendCnt=1, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=59, nwkAddrOfInterest=D9F5]]
2024-11-10 12:57:21.732 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10017, state=WAITING, sendCnt=1, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=59, nwkAddrOfInterest=D9F5]]
2024-11-10 12:57:31.735 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20019, state=FAILED, sendCnt=2, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=59, nwkAddrOfInterest=D9F5]]
2024-11-10 12:57:31.737 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete exceeded max retries 2
2024-11-10 12:57:31.737 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 12:57:31.739 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20023, state=CANCELLED, sendCnt=2, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=59, nwkAddrOfInterest=D9F5]]
2024-11-10 12:57:31.740 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: NodeDescriptorResponse returned null
2024-11-10 12:57:31.740 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20024, state=CANCELLED, sendCnt=2, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=59, nwkAddrOfInterest=D9F5]]
2024-11-10 12:57:31.741 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: request NODE_DESCRIPTOR failed. Retry 11, wait 10760ms before retry.
2024-11-10 12:57:31.742 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2024-11-10 12:57:42.502 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: running NODE_DESCRIPTOR
2024-11-10 12:57:42.504 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=0, state=WAITING, sendCnt=0, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=--, nwkAddrOfInterest=D9F5]]
2024-11-10 12:57:42.506 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=3, state=WAITING, sendCnt=0, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=5C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:57:52.509 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10005, state=FAILED, sendCnt=1, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=5C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:57:52.511 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 12:57:52.512 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10008, state=WAITING, sendCnt=1, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=5C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:57:52.515 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10012, state=WAITING, sendCnt=1, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=5C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:58:02.518 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20014, state=FAILED, sendCnt=2, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=5C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:58:02.520 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 12:58:02.521 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete exceeded max retries 2
2024-11-10 12:58:02.522 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20018, state=CANCELLED, sendCnt=2, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=5C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:58:02.523 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: NodeDescriptorResponse returned null
2024-11-10 12:58:02.523 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20020, state=CANCELLED, sendCnt=2, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=5C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:58:02.525 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2024-11-10 12:58:02.525 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: request NODE_DESCRIPTOR failed. Retry 12, wait 23672ms before retry.
2024-11-10 12:58:26.198 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: running NODE_DESCRIPTOR
2024-11-10 12:58:26.199 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=0, state=WAITING, sendCnt=0, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=--, nwkAddrOfInterest=D9F5]]
2024-11-10 12:58:26.202 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=2, state=WAITING, sendCnt=0, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=67, nwkAddrOfInterest=D9F5]]
2024-11-10 12:58:36.204 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10004, state=FAILED, sendCnt=1, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=67, nwkAddrOfInterest=D9F5]]
2024-11-10 12:58:36.206 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 12:58:36.207 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10008, state=WAITING, sendCnt=1, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=67, nwkAddrOfInterest=D9F5]]
2024-11-10 12:58:36.209 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10010, state=WAITING, sendCnt=1, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=67, nwkAddrOfInterest=D9F5]]
2024-11-10 12:58:46.211 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20011, state=FAILED, sendCnt=2, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=67, nwkAddrOfInterest=D9F5]]
2024-11-10 12:58:46.213 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 12:58:46.214 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete exceeded max retries 2
2024-11-10 12:58:46.215 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20015, state=CANCELLED, sendCnt=2, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=67, nwkAddrOfInterest=D9F5]]
2024-11-10 12:58:46.216 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: NodeDescriptorResponse returned null
2024-11-10 12:58:46.216 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20017, state=CANCELLED, sendCnt=2, command=NodeDescriptorRequest [0000/0 -> D9F5/0, cluster=0002, TID=67, nwkAddrOfInterest=D9F5]]
2024-11-10 12:58:46.217 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: request NODE_DESCRIPTOR failed after 13 attempts.
2024-11-10 12:58:46.218 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2024-11-10 12:58:46.218 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: running POWER_DESCRIPTOR
2024-11-10 12:58:46.222 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=0, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=--, nwkAddrOfInterest=D9F5]]
2024-11-10 12:58:46.224 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=3, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=6C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:58:56.227 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10005, state=FAILED, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=6C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:58:56.229 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 12:58:56.230 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10008, state=WAITING, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=6C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:58:56.232 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10011, state=WAITING, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=6C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:06.234 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20013, state=FAILED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=6C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:06.236 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 12:59:06.237 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete exceeded max retries 2
2024-11-10 12:59:06.238 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20017, state=CANCELLED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=6C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:06.239 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: PowerDescriptorResponse returned null
2024-11-10 12:59:06.239 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20018, state=CANCELLED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=6C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:06.241 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2024-11-10 12:59:06.241 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: request POWER_DESCRIPTOR failed. Retry 1, wait 2152ms before retry.
2024-11-10 12:59:08.394 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: running POWER_DESCRIPTOR
2024-11-10 12:59:08.395 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=0, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=--, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:08.398 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=2, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=73, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:18.400 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10004, state=FAILED, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=73, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:18.402 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 12:59:18.403 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10008, state=WAITING, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=73, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:18.405 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10010, state=WAITING, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=73, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:24.630 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Discovery: Starting discovery for existing device
2024-11-10 12:59:24.642 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Starting ZigBee device discovery
2024-11-10 12:59:24.644 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:ZigBee_Bridge
2024-11-10 12:59:24.648 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 0022A3000011CF86: Node discovery not complete
2024-11-10 12:59:28.408 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20012, state=FAILED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=73, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:28.410 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete exceeded max retries 2
2024-11-10 12:59:28.410 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 12:59:28.412 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20016, state=CANCELLED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=73, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:28.413 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: PowerDescriptorResponse returned null
2024-11-10 12:59:28.413 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20018, state=CANCELLED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=73, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:28.414 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: request POWER_DESCRIPTOR failed. Retry 2, wait 2152ms before retry.
2024-11-10 12:59:28.415 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2024-11-10 12:59:30.567 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: running POWER_DESCRIPTOR
2024-11-10 12:59:30.569 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=0, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=--, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:30.571 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=2, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=7C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:40.574 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10004, state=FAILED, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=7C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:40.576 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 12:59:40.577 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10007, state=WAITING, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=7C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:40.579 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10009, state=WAITING, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=7C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:50.581 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20011, state=FAILED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=7C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:50.583 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 12:59:50.584 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete exceeded max retries 2
2024-11-10 12:59:50.585 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20015, state=CANCELLED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=7C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:50.586 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: PowerDescriptorResponse returned null
2024-11-10 12:59:50.586 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20017, state=CANCELLED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=7C, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:50.587 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: request POWER_DESCRIPTOR failed. Retry 3, wait 6456ms before retry.
2024-11-10 12:59:50.588 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2024-11-10 12:59:57.044 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: running POWER_DESCRIPTOR
2024-11-10 12:59:57.046 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=0, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=--, nwkAddrOfInterest=D9F5]]
2024-11-10 12:59:57.048 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=2, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=85, nwkAddrOfInterest=D9F5]]
2024-11-10 13:00:07.050 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10004, state=FAILED, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=85, nwkAddrOfInterest=D9F5]]
2024-11-10 13:00:07.052 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 13:00:07.054 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10007, state=WAITING, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=85, nwkAddrOfInterest=D9F5]]
2024-11-10 13:00:07.056 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10009, state=WAITING, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=85, nwkAddrOfInterest=D9F5]]
2024-11-10 13:00:17.058 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20012, state=FAILED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=85, nwkAddrOfInterest=D9F5]]
2024-11-10 13:00:17.060 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 13:00:17.061 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete exceeded max retries 2
2024-11-10 13:00:17.062 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20016, state=CANCELLED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=85, nwkAddrOfInterest=D9F5]]
2024-11-10 13:00:17.064 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: PowerDescriptorResponse returned null
2024-11-10 13:00:17.064 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20017, state=CANCELLED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=85, nwkAddrOfInterest=D9F5]]
2024-11-10 13:00:17.065 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: request POWER_DESCRIPTOR failed. Retry 4, wait 8608ms before retry.
2024-11-10 13:00:17.066 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2024-11-10 13:00:25.674 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: running POWER_DESCRIPTOR
2024-11-10 13:00:25.676 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=0, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=--, nwkAddrOfInterest=D9F5]]
2024-11-10 13:00:25.678 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=3, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=8E, nwkAddrOfInterest=D9F5]]
2024-11-10 13:00:35.680 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10005, state=FAILED, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=8E, nwkAddrOfInterest=D9F5]]
2024-11-10 13:00:35.682 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 13:00:35.683 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10008, state=WAITING, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=8E, nwkAddrOfInterest=D9F5]]
2024-11-10 13:00:35.686 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10010, state=WAITING, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=8E, nwkAddrOfInterest=D9F5]]
2024-11-10 13:00:45.688 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20012, state=FAILED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=8E, nwkAddrOfInterest=D9F5]]
2024-11-10 13:00:45.690 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete exceeded max retries 2
2024-11-10 13:00:45.690 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 13:00:45.691 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20016, state=CANCELLED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=8E, nwkAddrOfInterest=D9F5]]
2024-11-10 13:00:45.692 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: PowerDescriptorResponse returned null
2024-11-10 13:00:45.692 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20017, state=CANCELLED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=8E, nwkAddrOfInterest=D9F5]]
2024-11-10 13:00:45.694 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: request POWER_DESCRIPTOR failed. Retry 5, wait 4304ms before retry.
2024-11-10 13:00:45.695 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2024-11-10 13:00:49.999 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: running POWER_DESCRIPTOR
2024-11-10 13:00:50.001 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=0, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=--, nwkAddrOfInterest=D9F5]]
2024-11-10 13:00:50.003 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=3, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=96, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:00.005 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10005, state=FAILED, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=96, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:00.008 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 13:01:00.009 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10008, state=WAITING, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=96, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:00.011 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10010, state=WAITING, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=96, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:10.013 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20012, state=FAILED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=96, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:10.015 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete exceeded max retries 2
2024-11-10 13:01:10.015 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 13:01:10.017 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20016, state=CANCELLED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=96, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:10.018 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: PowerDescriptorResponse returned null
2024-11-10 13:01:10.018 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20017, state=CANCELLED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=96, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:10.019 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: request POWER_DESCRIPTOR failed. Retry 6, wait 4304ms before retry.
2024-11-10 13:01:10.020 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2024-11-10 13:01:14.324 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: running POWER_DESCRIPTOR
2024-11-10 13:01:14.326 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=0, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=--, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:14.328 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=2, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=9B, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:24.330 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10004, state=FAILED, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=9B, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:24.332 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 13:01:24.334 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10007, state=WAITING, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=9B, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:24.336 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10009, state=WAITING, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=9B, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:34.338 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20012, state=FAILED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=9B, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:34.340 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 13:01:34.341 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete exceeded max retries 2
2024-11-10 13:01:34.342 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20016, state=CANCELLED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=9B, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:34.343 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: PowerDescriptorResponse returned null
2024-11-10 13:01:34.343 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20017, state=CANCELLED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=9B, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:34.345 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2024-11-10 13:01:34.345 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: request POWER_DESCRIPTOR failed. Retry 7, wait 6456ms before retry.
2024-11-10 13:01:40.802 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: running POWER_DESCRIPTOR
2024-11-10 13:01:40.803 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=0, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=--, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:40.806 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=3, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=A4, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:50.808 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10005, state=FAILED, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=A4, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:50.810 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 13:01:50.811 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10008, state=WAITING, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=A4, nwkAddrOfInterest=D9F5]]
2024-11-10 13:01:50.813 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=10010, state=WAITING, sendCnt=1, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=A4, nwkAddrOfInterest=D9F5]]
2024-11-10 13:02:00.816 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20012, state=FAILED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=A4, nwkAddrOfInterest=D9F5]]
2024-11-10 13:02:00.819 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete, state=FAILED, outstanding=0
2024-11-10 13:02:00.821 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete exceeded max retries 2
2024-11-10 13:02:00.822 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20019, state=CANCELLED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=A4, nwkAddrOfInterest=D9F5]]
2024-11-10 13:02:00.824 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: PowerDescriptorResponse returned null
2024-11-10 13:02:00.824 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=20020, state=CANCELLED, sendCnt=2, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=A4, nwkAddrOfInterest=D9F5]]
2024-11-10 13:02:00.825 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: request POWER_DESCRIPTOR failed. Retry 8, wait 12912ms before retry.
2024-11-10 13:02:00.826 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2024-11-10 13:02:13.739 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0022A3000011CF86: Node SVC Discovery: running POWER_DESCRIPTOR
2024-11-10 13:02:13.740 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0022A3000011CF86: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=0, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=--, nwkAddrOfInterest=D9F5]]
2024-11-10 13:02:13.742 [DEBUG] [transaction.ZigBeeTransactionManager] - D9F5/0: Sending ZigBeeTransaction [ieeeAddress=0022A3000011CF86 queueTime=2, state=WAITING, sendCnt=0, command=PowerDescriptorRequest [0000/0 -> D9F5/0, cluster=0003, TID=AD, nwkAddrOfInterest=D9F5]]

[chris (Chris Jackson)]

Well, it means the device isn’t responding to some basic commands, so it’s basically not communicating and we need to address this first…

What version of firmware do you have in the Nortek? By default this is quite old and I think might not support Z3 devices. Some Z3 devices will leave the network if they don’t see certain traffic shortly after they join… That said, you do say this used to work, and I’m assuming it is with the same system?

Also, I’m not sure how you filtered the logs, but if you can get logging for all of the com.zsmartsystems.zigbee packages, then we can use the online log viewer to view this which is a lot easier

[Mr-JR (James R)]

Ok, let me make sure I have all the com.zsmartsystems.zigbee packages on DEBUG …

I am filtering the output for this device (grep -i cf86) … I have 7 of these devices and the others are all the same model and firmware versions. This one is the only device having trouble and yes it worked on this system previously.

If I dont filter for this zigbee device the output will be quite large, is that what you want?

[chris (Chris Jackson)]

Possibly this grep is killing off the info since the IEEE address isn’t used for all (or in fact much) communication - normally the short address is used.

The length generally doesn’t matter (within reason) since the reader will filter out what it needs to display.

[Mr-JR (James R)]

Ok, yes I didn’t have the ember debug on …

CF96-Zigbee-log.txt (918.4 KB)

Hopefully this has enough info in it a quick glance it appears the device is responding.

[chris (Chris Jackson)]

@Mr-JR

Keen Smart Vent

Is this a mains or battery device? When the binding goes looking for the device on the network, it sends out a network address request -:

The interesting thing here is that the coordinator replies - this normally happens when the device is a battery device, and the parent will then respond instead of the response coming from the device itself as it would from a mains device.

Maybe the device needs waking up, although if it’s a vent, I assume that it wakes periodically to receive commands so it should be ok to receive these.

In any case, there is no communications received from the device, so either it’s not working (dead batteries if it’s battery operated), or it’s left the network, or something.

I would remove it completely from the network - delete the thing - force delete if necessary, then reset the device (not sure how to do that, but I guess there’s a button for it), then enable discovery in OH and start joining on the device… I’d keep logging running and if it doesn’t work, send it over and I’ll take another look.

[Mr-JR (James R)]

ok. It’s a battery device, and the others show END_DEVICE (see attached)

Yes I done multiple (dozens) of factory resets, and restarting the discovery process. I’ll try to capture the start of that process in the logs (but there’s a lot of unrelated activity so I have to cut the log down)

@chris

In any case, there is no communications received from the device, so either it’s not working (dead batteries if it’s battery operated), or it’s left the network, or something.

Yes, the batteries are fine (it is flashed green to indicate its in the join state) … when you say “left the network” … I am wondering if its related to it being connected (and working previously) and then I REMOVED the device (and did a force removal) … is it possible some info is remaining in the ember that is messing it up?

Probably unrelated, but I have a bunch of old devices in my zigbee inbox that I cant get rid of. Every time I remove them, they come back. Even though they are never powered on. Where is that old information being stored?

[chris (Chris Jackson)]

@Mr-JR

Yes I done multiple (dozens) of factory resets, and restarting the discovery process.

Ok, cool. Do you remove the node from OH (and force remove if it fails)?

@Mr-JR

I’ll try to capture the start of that process in the logs (but there’s a lot of unrelated activity so I have to cut the log down)

Ok, just make sure not to remove anything zigbee related…

@Mr-JR

is it possible some info is remaining in the ember that is messing it up?

Nothing is stored in the ember chip relating to devices.

@Mr-JR

Where is that old information being stored?

It’s stored in the OH data folder. You can probably remove nodes with the zigbee leave fnr XXXX command (where XXXX is the node address). This should force remove the specified old device and should remove all info relating to it.

[Mr-JR (James R)]

@chris

@Mr-JR

Yes I done multiple (dozens) of factory resets, and restarting the discovery process.

Ok, cool. Do you remove the node from OH (and force remove if it fails)?

Yes, I remove it. An aside the warning about “could corrupt the binding” has confused me.

@chris

It’s stored in the OH data folder. You can probably remove nodes with the zigbee leave fnr XXXX command (where XXXX is the node address). This should force remove the specified old device and should remove all info relating to it.

Ok, did the zigbee leave fnr XXXX so far so good (they are not coming back.)

Here’s a new log unfiltered.

zigbee-cf86.txt (981.7 KB)

Here’s a bit of other info that confuses me … I notice there are neighbors reporting the target device 0022A3000011CF86 … this next log shows this, and the device had been removed and was off when I turned on the zigbee debug. (Q: How is it getting populated into the other devices?)

zigbee-cf86-in-neighbors.txt (19.0 KB)

As I mentioned earlier, I have another device that exhibits the same or similar behavior. But that is a simple Sensor device that I can easily add to a Smartthings hub, but it wont pair with OH. What is causing these devices to not join?

[Mr-JR (James R)]

FYI - This vent immediately pairs with my old SmartThings hub which confirms the device itself is working fine. Something in the OH Zigbee system is preventing it from joining. Exact same results with a sensor device I mentioned earlier.

[chris (Chris Jackson)]

From this log we do initially see some traffic with this devices parent (requests for address information), but direct comms fails so the binding doesn’t complete the interview/discovery phase. This could be because the device is sleepy (it is a battery device, so it will sleep), or it could be that it decided to leave the network as the network is not secure enough.

I don’t actually see the start of discovery in this log though - ie the join command - so it’s hard be sure when the device paired.

@Mr-JR

Here’s a bit of other info that confuses me … I notice there are neighbors reporting the target device 0022A3000011CF86 … this next log shows this, and the device had been removed and was off when I turned on the zigbee debug. (Q: How is it getting populated into the other devices?)

If I understand the question, then these neighbour entries will persist after a device is removed since neighbours won’t know a device is gone. Over time these tables time out and old entries will be removed. IIRC in the coordinator there’s a setting to control this aging, but for other devices it will be in their firmware and is likely to be around 24 hours.

@chris

What version of firmware do you have in the Nortek? By default this is quite old and I think might not support Z3 devices. Some Z3 devices will leave the network if they don’t see certain traffic shortly after they join… That said, you do say this used to work, and I’m assuming it is with the same system?

This is important since if you have old firmware, it could cause this behaviour.

@Mr-JR

Something in the OH Zigbee system is preventing it from joining. Exact same results with a sensor device I mentioned earlier.

As far as I can see there’s nothing wrong as such - the device just doesn’t seem to respond to requests. It could have gone to sleep or it could have left the network - it’s hard to say when there’s just no response to communications.

[Mr-JR (James R)]

Thanks Chris …

@chris

If I understand the question, then these neighbour entries will persist after a device is removed since neighbours won’t know a device is gone.

But I wouldnt have thought the neighbors would be populated until the device finished the joining. It’s been many days (maybe months) since this device was in the network.

@chris

That said, you do say this used to work, and I’m assuming it is with the same system?

Yes, this device has been working with the exact same Nortek … and 6 others devices with the same device firmware are also working fine. The coordinator version is 5.4.1.0

Here’s a link to the larger file with all the zigbee debug. Maybe this will show something.

https://www.dropbox.com/scl/fi/5i7mkgdnpjtn9ajrmfte5/zigbee-cf86-large.txt?rlkey=qzpmov8b6g0xl5rqmc7bafi2a&dl=0

[chris (Chris Jackson)]

@Mr-JR

But I wouldnt have thought the neighbors would be populated until the device finished the joining.

I’m not sure, and it’s not defined in the standard so it will be up to the implementation in the device. In the Silabs SDK, it is added when heard, and then aged out over a defined period.

@Mr-JR

The coordinator version is 5.4.1.0

This is really super old and I would suggest to update to at least 6.4 if not higher. I’m not even sure what stack version 5.4 is, but it is very old now.

@Mr-JR

Here’s a link to the larger file with all the zigbee debug. Maybe this will show something.

I’ll take a look to see if it has anything…

[chris (Chris Jackson)]

There’s definately some issues going on here.

This shows that 3 different devices are reporting to be this devices parent. With Zigbee, the parent acts as a proxy - it stores any messages for up to ~7 seconds while the child is asleep.

Here we seem to see 3 devices reporting 3 different network addresses for the device. I don’t know what’s going to happen, but there’s a 66% chance it won’t work as only one (at most!) can be correct.

In theory this is a different issue than you raised earlier with the neighbour tables since there should only be a single parent responsible for a device at any time. The parent can change, but I don’t know what will happen in the case we see here…

[Mr-JR (James R)]

Yes I was noticing the same thing. I thought it was strange that it was changing network addresses … I have no idea what would cause that but it surely is related to why it is failing.

Meanwhile, I have paired it using my old SmartThings hub and wrote a bridge for it. I bet that if I take one of the Vents that is working and do the same thing (remove it and reset to factory defaults, it will probably also not be able to join again (and have the network address changing).

Any idea of things I could try to get more info? Sounds like an interesting issue.

[chris (Chris Jackson)]

@Mr-JR

I thought it was strange that it was changing network addresses

It’s not changing network address. With Zigbee, the parent of a child device (ie ZED) provides the address when the device joins the network (or rejoins with a different parent). When the coordinator wants to find the network address of any device, it sends out a request asking who owns, or can provide the network address given the IEEE address. For a powered device (ie router), the device itself will respond. For a child device, the parent responds.

So, the problem here (I assume) is that all 3 of these devices think they are the parent for the ZED, so they all respond with their version of the address.

I would try the console leave command I mentioned previously, but this time, add another parameter… This command can send the leave command directly to a parent so hopefully we can force it out of the child tables.

zigbee leave fnr XXXX YYYY command (where XXXX is the node address of the end device, and YYYY is the node address of the parent).

Let’s see if that helps.

[Mr-JR (James R)]

Thanks Chris.

Ok, I am reproducing the similar results with my Water Sensor that I also cannot pair. It seems to be doing the exact same thing (having multiple parents). Here is the full log:

https://www.dropbox.com/scl/fi/jcveveo74xjmxrr480hms/Water-24FD5B000107E804.txt?rlkey=1lfsflk8z1cqsg27wzqmyftm4&dl=0

I am trying your suggested zigbee leave fnr 2FC4 EF15 command with various Nodes, but the syntax is wrong. I get:

openhab> zigbee leave fnr 2FC4 EF15                                                                                                                                                                                                                                                  
Error: Exception during command execution (IllegalArgumentException): Too many arguments

The help command seems to indicate the fnr is optional so I tried:

openhab> zigbee leave 2FC4 EF15                                                                                                                                                                                                                                                  
Error: Exception during command execution (IllegalArgumentException): Node '2FC4' is not found.

Then after trying many of the various Nodes, I found I always get node not found

In fact, as I watch the debug log, it is constantly “changing” … in the log i provided you can see it goes through 7 different NWK addresses:

2024-11-13 07:56:29.999 24FD5B000107E804: Device status updated. NWK=3407
2024-11-13 07:56:36.020 24FD5B000107E804: Device status updated. NWK=B839
2024-11-13 07:56:42.040 24FD5B000107E804: Device status updated. NWK=22B8
2024-11-13 07:56:48.037 24FD5B000107E804: Device status updated. NWK=9EB3
2024-11-13 07:57:06.046 24FD5B000107E804: Device status updated. NWK=A4A6
2024-11-13 07:57:12.046 24FD5B000107E804: Device status updated. NWK=C1AA
2024-11-13 07:57:24.057 24FD5B000107E804: Device status updated. NWK=2FC4

I am sure if I keep running the log it will constantly change.

So I’m not sure how I can force it to “leave” when it keeps changing.

[chris (Chris Jackson)]

Try turning it off and leaving it off for a day or two. Hopefully (!!) this will age it out of the router child tables. you could also then request the neighbour tables from these routers to see what they say about their relationship - possibly also power cycling the routers may help this relationship “go away”.

You should be able to use the openhab:zigbee neighbors command to read the various neighbour tables.