Hi,
After I have migrated from OH2.5 to OH3, I decided to add my Zigbee coordinator via the new webinterface and remove the text-based one, as per the recommendation. As a consequence, I had to re-add all my Zigbee devices to the Zigbee network. So far I tried 3 different Ikea Tradfri bulbs, but none of them got recognized. They only appear as “Unknown Zigbee Device” in the inbox.
The documentation of the Zigbee Binding recommends turning on debug logging via de OpenHAB console. So I did, and I started a discovery session with one of the bulbs. I did factory reset the bulb by turning it on and off 6 times. Here’s the log:
2020-12-30 14:55:14.774 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 000D6FFFFE03C639: Discovery: Starting discovery for existing device
2020-12-30 14:55:14.788 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 000D6FFFFE03C639: Starting ZigBee device discovery
2020-12-30 14:55:14.795 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 000D6FFFFE03C639: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:a5254cef6e
2020-12-30 14:55:14.813 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 000D6FFFFE03C639: ZigBee node property discovery start
2020-12-30 14:55:14.821 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 000D6FFFFE03C639: ZigBee node property discovery using basic cluster on endpoint 0103/1
2020-12-30 14:55:14.865 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=0, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=--, identifiers=[5, 4, 3, 2, 6, 0, 1]]]
2020-12-30 14:55:14.870 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=5, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=9C, identifiers=[5, 4, 3, 2, 6, 0, 1]]]
2020-12-30 14:55:19.618 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4753, state=FAILED, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=9C, identifiers=[5, 4, 3, 2, 6, 0, 1]]]
2020-12-30 14:55:19.623 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:55:19.625 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4761, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=9C, identifiers=[5, 4, 3, 2, 6, 0, 1]]]
2020-12-30 14:55:19.632 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4767, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=9C, identifiers=[5, 4, 3, 2, 6, 0, 1]]]
2020-12-30 14:55:24.357 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9492, state=FAILED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=9C, identifiers=[5, 4, 3, 2, 6, 0, 1]]]
2020-12-30 14:55:24.385 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:55:24.388 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete exceeded max retries 2
2020-12-30 14:55:24.392 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9526, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=9C, identifiers=[5, 4, 3, 2, 6, 0, 1]]]
2020-12-30 14:55:24.396 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9531, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=9C, identifiers=[5, 4, 3, 2, 6, 0, 1]]]
2020-12-30 14:55:24.400 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2020-12-30 14:55:24.451 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=0, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=--, identifiers=[4]]]
2020-12-30 14:55:24.456 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A0, identifiers=[4]]]
2020-12-30 14:55:29.183 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4731, state=FAILED, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A0, identifiers=[4]]]
2020-12-30 14:55:29.187 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:55:29.190 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4738, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A0, identifiers=[4]]]
2020-12-30 14:55:29.195 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4743, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A0, identifiers=[4]]]
2020-12-30 14:55:33.951 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9499, state=FAILED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A0, identifiers=[4]]]
2020-12-30 14:55:33.964 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:55:33.966 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete exceeded max retries 2
2020-12-30 14:55:33.969 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9517, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A0, identifiers=[4]]]
2020-12-30 14:55:33.971 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 000D6FFFFE03C639: Manufacturer request failed
2020-12-30 14:55:33.973 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9520, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A0, identifiers=[4]]]
2020-12-30 14:55:33.980 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2020-12-30 14:55:33.988 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=0, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=--, identifiers=[5]]]
2020-12-30 14:55:33.993 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=6, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A3, identifiers=[5]]]
2020-12-30 14:55:38.759 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4767, state=FAILED, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A3, identifiers=[5]]]
2020-12-30 14:55:38.767 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:55:38.772 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4783, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A3, identifiers=[5]]]
2020-12-30 14:55:38.780 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4792, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A3, identifiers=[5]]]
2020-12-30 14:55:43.522 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9534, state=FAILED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A3, identifiers=[5]]]
2020-12-30 14:55:43.532 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:55:43.536 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete exceeded max retries 2
2020-12-30 14:55:43.541 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9551, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A3, identifiers=[5]]]
2020-12-30 14:55:43.545 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 000D6FFFFE03C639: Model request failed
2020-12-30 14:55:43.549 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9557, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A3, identifiers=[5]]]
2020-12-30 14:55:43.557 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2020-12-30 14:55:43.567 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=0, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=--, identifiers=[3]]]
2020-12-30 14:55:43.572 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=7, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A6, identifiers=[3]]]
2020-12-30 14:55:46.279 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspTrustCenterJoinHandler [networkId=0, newNodeId=0103, newNodeEui64=000D6FFFFE03C639, status=EMBER_STANDARD_SECURITY_UNSECURED_JOIN, policyDecision=EMBER_SEND_KEY_IN_THE_CLEAR, parentOfNewNodeId=0000]
2020-12-30 14:55:46.281 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6FFFFE03C639: nodeStatusUpdate - node status is UNSECURED_JOIN, network address is 0103.
2020-12-30 14:55:46.284 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 000D6FFFFE03C639: Device status updated. NWK=0103
2020-12-30 14:55:46.288 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 000D6FFFFE03C639: NWK Discovery add node 0103
2020-12-30 14:55:46.290 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6FFFFE03C639: Node state updated from UNKNOWN to ONLINE
2020-12-30 14:55:46.293 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6FFFFE03C639: Updating node NWK=0103
2020-12-30 14:55:46.295 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6FFFFE03C639: Node update. NWK Address=0103
2020-12-30 14:55:46.298 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6FFFFE03C639: Node 0103 is not updated
2020-12-30 14:55:46.753 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0103, sourceEui=000D6FFFFE03C639, lastHopLqi=255, lastHopRssi=-39, relayList=]
2020-12-30 14:55:53.579 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=10013, state=FAILED, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A6, identifiers=[3]]]
2020-12-30 14:55:53.588 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:55:53.592 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=10026, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A6, identifiers=[3]]]
2020-12-30 14:55:53.598 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=10032, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A6, identifiers=[3]]]
2020-12-30 14:55:58.323 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=14757, state=FAILED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A6, identifiers=[3]]]
2020-12-30 14:55:58.331 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:55:58.333 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete exceeded max retries 2
2020-12-30 14:55:58.335 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=14770, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A6, identifiers=[3]]]
2020-12-30 14:55:58.338 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 000D6FFFFE03C639: Hardware version failed
2020-12-30 14:55:58.338 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=14772, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A6, identifiers=[3]]]
2020-12-30 14:55:58.342 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2020-12-30 14:55:58.349 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=0, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=--, identifiers=[1]]]
2020-12-30 14:55:58.353 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=5, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A9, identifiers=[1]]]
2020-12-30 14:56:03.072 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4723, state=FAILED, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A9, identifiers=[1]]]
2020-12-30 14:56:03.076 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:56:03.078 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4729, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A9, identifiers=[1]]]
2020-12-30 14:56:03.083 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4734, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A9, identifiers=[1]]]
2020-12-30 14:56:07.804 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspTrustCenterJoinHandler [networkId=0, newNodeId=0103, newNodeEui64=000D6FFFFE03C639, status=EMBER_STANDARD_SECURITY_UNSECURED_JOIN, policyDecision=EMBER_SEND_KEY_IN_THE_CLEAR, parentOfNewNodeId=0000]
2020-12-30 14:56:07.806 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9457, state=FAILED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A9, identifiers=[1]]]
2020-12-30 14:56:07.809 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:56:07.808 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6FFFFE03C639: nodeStatusUpdate - node status is UNSECURED_JOIN, network address is 0103.
2020-12-30 14:56:07.811 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete exceeded max retries 2
2020-12-30 14:56:07.813 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 000D6FFFFE03C639: Device status updated. NWK=0103
2020-12-30 14:56:07.815 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 000D6FFFFE03C639: NWK Discovery add node 0103
2020-12-30 14:56:07.818 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6FFFFE03C639: Node state updated from UNKNOWN to ONLINE
2020-12-30 14:56:07.818 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9469, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A9, identifiers=[1]]]
2020-12-30 14:56:07.821 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6FFFFE03C639: Updating node NWK=0103
2020-12-30 14:56:07.823 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6FFFFE03C639: Node update. NWK Address=0103
2020-12-30 14:56:07.824 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9475, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=A9, identifiers=[1]]]
2020-12-30 14:56:07.828 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 000D6FFFFE03C639: Application version failed
2020-12-30 14:56:07.827 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6FFFFE03C639: Node 0103 is not updated
2020-12-30 14:56:07.831 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2020-12-30 14:56:07.849 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=0, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=--, identifiers=[2]]]
2020-12-30 14:56:07.868 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=7, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=AC, identifiers=[2]]]
2020-12-30 14:56:07.918 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0103, sourceEui=000D6FFFFE03C639, lastHopLqi=255, lastHopRssi=-39, relayList=]
2020-12-30 14:56:17.874 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=10025, state=FAILED, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=AC, identifiers=[2]]]
2020-12-30 14:56:17.884 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:56:17.888 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=10039, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=AC, identifiers=[2]]]
2020-12-30 14:56:17.897 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=10048, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=AC, identifiers=[2]]]
2020-12-30 14:56:22.649 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=14800, state=FAILED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=AC, identifiers=[2]]]
2020-12-30 14:56:22.653 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:56:22.655 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete exceeded max retries 2
2020-12-30 14:56:22.658 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=14809, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=AC, identifiers=[2]]]
2020-12-30 14:56:22.660 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 000D6FFFFE03C639: Stack version failed
2020-12-30 14:56:22.660 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=14811, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=AC, identifiers=[2]]]
2020-12-30 14:56:22.665 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2020-12-30 14:56:22.673 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=1, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=--, identifiers=[0]]]
2020-12-30 14:56:22.679 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=7, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=B1, identifiers=[0]]]
2020-12-30 14:56:27.408 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4736, state=FAILED, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=B1, identifiers=[0]]]
2020-12-30 14:56:27.413 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:56:27.417 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4745, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=B1, identifiers=[0]]]
2020-12-30 14:56:27.423 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4751, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=B1, identifiers=[0]]]
2020-12-30 14:56:32.160 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9488, state=FAILED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=B1, identifiers=[0]]]
2020-12-30 14:56:32.167 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:56:32.170 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete exceeded max retries 2
2020-12-30 14:56:32.173 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9501, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=B1, identifiers=[0]]]
2020-12-30 14:56:32.177 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 000D6FFFFE03C639: ZCL version failed
2020-12-30 14:56:32.177 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9505, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=B1, identifiers=[0]]]
2020-12-30 14:56:32.182 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2020-12-30 14:56:32.190 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=0, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=--, identifiers=[6]]]
2020-12-30 14:56:32.195 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=5, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=B4, identifiers=[6]]]
2020-12-30 14:56:36.914 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4724, state=FAILED, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=B4, identifiers=[6]]]
2020-12-30 14:56:36.918 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:56:36.921 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4731, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=B4, identifiers=[6]]]
2020-12-30 14:56:36.926 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4736, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=B4, identifiers=[6]]]
2020-12-30 14:56:41.644 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9454, state=FAILED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=B4, identifiers=[6]]]
2020-12-30 14:56:41.648 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:56:41.650 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete exceeded max retries 2
2020-12-30 14:56:41.653 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9463, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=B4, identifiers=[6]]]
2020-12-30 14:56:41.656 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 000D6FFFFE03C639: Date code failed
2020-12-30 14:56:41.659 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 000D6FFFFE03C639: ZigBee node property discovery using OTA cluster on endpoint 0103/1
2020-12-30 14:56:41.660 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9470, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Basic: 0000/0 -> 0103/1, cluster=0000, TID=B4, identifiers=[6]]]
2020-12-30 14:56:41.663 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2020-12-30 14:56:41.671 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=0, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Ota Upgrade: 0000/0 -> 0103/1, cluster=0019, TID=--, identifiers=[2]]]
2020-12-30 14:56:41.678 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=7, state=WAITING, sendCnt=0, command=ReadAttributesCommand [Ota Upgrade: 0000/0 -> 0103/1, cluster=0019, TID=B5, identifiers=[2]]]
2020-12-30 14:56:46.407 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4736, state=FAILED, sendCnt=1, command=ReadAttributesCommand [Ota Upgrade: 0000/0 -> 0103/1, cluster=0019, TID=B5, identifiers=[2]]]
2020-12-30 14:56:46.413 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:56:46.418 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4747, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Ota Upgrade: 0000/0 -> 0103/1, cluster=0019, TID=B5, identifiers=[2]]]
2020-12-30 14:56:46.423 [DEBUG] [transaction.ZigBeeTransactionManager] - 0103/1: Sending ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=4753, state=WAITING, sendCnt=1, command=ReadAttributesCommand [Ota Upgrade: 0000/0 -> 0103/1, cluster=0019, TID=B5, identifiers=[2]]]
2020-12-30 14:56:51.148 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9477, state=FAILED, sendCnt=2, command=ReadAttributesCommand [Ota Upgrade: 0000/0 -> 0103/1, cluster=0019, TID=B5, identifiers=[2]]]
2020-12-30 14:56:51.152 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete, state=FAILED, outstanding=0
2020-12-30 14:56:51.153 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete exceeded max retries 2
2020-12-30 14:56:51.156 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9485, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Ota Upgrade: 0000/0 -> 0103/1, cluster=0019, TID=B5, identifiers=[2]]]
2020-12-30 14:56:51.159 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 000D6FFFFE03C639: Could not get OTA firmware version from device
2020-12-30 14:56:51.159 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6FFFFE03C639 queueTime=9488, state=CANCELLED, sendCnt=2, command=ReadAttributesCommand [Ota Upgrade: 0000/0 -> 0103/1, cluster=0019, TID=B5, identifiers=[2]]]
2020-12-30 14:56:51.162 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 000D6FFFFE03C639: ZigBee node property discovery complete: {zigbee_logicaltype=ROUTER, zigbee_powerlevel=FULL, zigbee_manufacturercode=0x117c, zigbee_networkaddress=259, zigbee_powermode=RECEIVER_ON_IDLE, zigbee_powersources=[MAINS], zigbee_powersource=MAINS}
2020-12-30 14:56:51.164 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6FFFFE03C639: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2020-12-30 14:56:51.169 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 000D6FFFFE03C639: Data store: Deferring write for 250ms.
2020-12-30 14:56:51.423 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 000D6FFFFE03C639: Data store: Writing node.
2020-12-30 14:56:51.591 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 000D6FFFFE03C639: ZigBee saving network state complete.
There’s a lot of information in this log. As far as I understand it, the device is discovered, and then some commands are sent to it to get information like manufacturer, type, etc. It seems the bulb won’t answer those questions.
What’s going wrong here? I did add those bulbs to my previous setup successfully. The bulbs aren’t changed. I see the binding is updated to also support Zigbee 3.0, which my bulbs obviously don’t support. Maybe there’s something going wrong in that area? What can I do to get my bulbs recognized again?
@chris Can you help? I’m a developer myself, so I’m not afraid to try funky stuff on a console or something… Thanks in advance for any help!
Best regards,
Bart