ZigBee Binding and new Tradfri E14 250lm bulb - Error initialising device

Add-ons Bindings
1

Hello!

I have purchased a few of the new Tradfri bulbs with model ID TRADFRIbulbE14WWclear250lm and are failing to add it, see IKEA page. I have several other ZigBee devices working well in the system.

The Thing is found and one channel for dimming is identified. However, the device can’t be initialized. The debug logs below are from where the initialization fails, note the Failed to bind on off control cluster. Is it possible to conclude from these why it’s failing? I am happy to test any updates to the binding and to capture more logs if needed.

Openhab version: 3.1.0
ZigBee binding version: 3.1.0

2021-09-29 16:26:42.001 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - EC1BBDFFFE20FE45: ZigBee node property discovery complete: {zigbee_logicaltype=ROUTER, zigbee_powerlevel=FULL, zigbee_manufacturercode=0x117c, modelId=TRADFRIbulbE14WWclear250lm, zigbee_networkaddress=60268, zigbee_powersource=MAINS, zigbee_stkversion=103, zigbee_datecode=20200826, zigbee_zclversion=3, vendor=IKEA of Sweden, zigbee_powermode=RECEIVER_ON_IDLE, zigbee_powersources=[MAINS], hardwareVersion=1, firmwareVersion=0x00010010, zigbee_applicationVersion=16, zigbee_device_initialised=false}

2021-09-29 16:26:42.005 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - EC1BBDFFFE20FE45: Checking endpoint 1 channels

2021-09-29 16:26:42.012 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=8A]

2021-09-29 16:26:42.016 [DEBUG] [er.ZigBeeChannelConverterFactoryImpl] - EC1BBDFFFE20FE45: Removing channel zigbee:switch_onoff in favor of zigbee:switch_level

2021-09-29 16:26:42.019 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - EC1BBDFFFE20FE45: Checking endpoint 242 channels

2021-09-29 16:26:42.029 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - EC1BBDFFFE20FE45: Dynamically created 1 channels

2021-09-29 16:26:42.031 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - EC1BBDFFFE20FE45: Initializing device

2021-09-29 16:26:42.034 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - EC1BBDFFFE20FE45: Initializing channel zigbee:device:01370B76:ec1bbdfffe20fe45:EC1BBDFFFE20FE45_1_dimmer with org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel@8f7ede

2021-09-29 16:26:42.039 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - EC1BBDFFFE20FE45: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=0, state=WAITING, sendCnt=0, command=BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=--, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=8, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]]

2021-09-29 16:26:42.042 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3

2021-09-29 16:26:46.702 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=EB6C, apsFrame=EmberApsFrame [profileId=0000, clusterId=0000, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=8A], messageTag=77, status=EMBER_DELIVERY_FAILED, messageContents=]

2021-09-29 16:26:46.706 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=77 state=RX_NAK

2021-09-29 16:26:46.711 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=77, state=RX_NAK, outstanding=1

2021-09-29 16:26:46.714 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=4737, state=FAILED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> EB6C/0, cluster=0000, TID=77, ieeeAddr=EC1BBDFFFE20FE45, requestType=0, startIndex=0]]

2021-09-29 16:26:46.718 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding

2021-09-29 16:26:46.720 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - EC1BBDFFFE20FE45: transactionComplete, state=FAILED, outstanding=0

2021-09-29 16:26:46.724 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - EC1BBDFFFE20FE45: Added transaction to queue, len=2, transaction=ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=4747, state=WAITING, sendCnt=1, command=NetworkAddressRequest [0000/0 -> EB6C/0, cluster=0000, TID=77, ieeeAddr=EC1BBDFFFE20FE45, requestType=0, startIndex=0]]

2021-09-29 16:26:46.727 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3

2021-09-29 16:26:46.731 [DEBUG] [transaction.ZigBeeTransactionManager] - EB6C/0: Sending ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=4754, state=WAITING, sendCnt=1, command=NetworkAddressRequest [0000/0 -> EB6C/0, cluster=0000, TID=77, ieeeAddr=EC1BBDFFFE20FE45, requestType=0, startIndex=0]]

2021-09-29 16:26:46.734 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding

2021-09-29 16:26:46.737 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> EB6C/0, cluster=0000, TID=77, ieeeAddr=EC1BBDFFFE20FE45, requestType=0, startIndex=0]

2021-09-29 16:26:46.740 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=EB6C/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=4A, rssi=--, lqi=--, payload=77 45 FE 20 FE FF BD 1B EC 00 00]

2021-09-29 16:26:46.744 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=EB6C, TID=77, event=RX_NAK, state=DISPATCHED

2021-09-29 16:26:46.756 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=8B]

2021-09-29 16:26:46.780 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3

2021-09-29 16:26:51.446 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=EB6C, apsFrame=EmberApsFrame [profileId=0000, clusterId=0000, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=8B], messageTag=77, status=EMBER_DELIVERY_FAILED, messageContents=]

2021-09-29 16:26:51.451 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=77 state=RX_NAK

2021-09-29 16:26:51.453 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=77, state=RX_NAK, outstanding=1

2021-09-29 16:26:51.457 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=9480, state=FAILED, sendCnt=2, command=NetworkAddressRequest [0000/0 -> EB6C/0, cluster=0000, TID=77, ieeeAddr=EC1BBDFFFE20FE45, requestType=0, startIndex=0]]

2021-09-29 16:26:51.462 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding

2021-09-29 16:26:51.465 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - EC1BBDFFFE20FE45: transactionComplete, state=FAILED, outstanding=0

2021-09-29 16:26:51.467 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - EC1BBDFFFE20FE45: transactionComplete exceeded max retries 2

2021-09-29 16:26:51.471 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=9494, state=CANCELLED, sendCnt=2, command=NetworkAddressRequest [0000/0 -> EB6C/0, cluster=0000, TID=77, ieeeAddr=EC1BBDFFFE20FE45, requestType=0, startIndex=0]]

2021-09-29 16:26:51.475 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - EC1BBDFFFE20FE45: NWK Discovery: Rediscovery using broadcast

2021-09-29 16:26:51.475 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=9498, state=CANCELLED, sendCnt=2, command=NetworkAddressRequest [0000/0 -> EB6C/0, cluster=0000, TID=77, ieeeAddr=EC1BBDFFFE20FE45, requestType=0, startIndex=0]]

2021-09-29 16:26:51.477 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding

2021-09-29 16:26:51.481 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - EC1BBDFFFE20FE45: transactionComplete but not outstanding, state=CANCELLED, outstanding=0

2021-09-29 16:26:51.483 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3

2021-09-29 16:26:51.487 [DEBUG] [transaction.ZigBeeTransactionManager] - EB6C/0: Sending ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=9449, state=WAITING, sendCnt=0, command=BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=78, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=8, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]]

2021-09-29 16:26:51.490 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding

2021-09-29 16:26:51.493 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=78, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=8, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]

2021-09-29 16:26:51.497 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=EB6C/0, profile=0000, cluster=0021, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=4B, rssi=--, lqi=--, payload=78 45 FE 20 FE FF BD 1B EC 01 08 00 03 A7 D1 86 0C 00 6F 0D 00 01]

2021-09-29 16:26:51.501 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=0, sleepy=0/3

2021-09-29 16:26:51.504 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=EB6C, TID=77, event=RX_NAK, state=CANCELLED

2021-09-29 16:26:51.505 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=null queueTime=0, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> FFFD/0, cluster=0000, TID=--, ieeeAddr=EC1BBDFFFE20FE45, requestType=0, startIndex=0]]

2021-09-29 16:26:51.512 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3

2021-09-29 16:26:51.515 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=8C]

2021-09-29 16:26:51.516 [DEBUG] [transaction.ZigBeeTransactionManager] - FFFD/0: Sending ZigBeeTransaction [ieeeAddress=null queueTime=11, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> FFFD/0, cluster=0000, TID=79, ieeeAddr=EC1BBDFFFE20FE45, requestType=0, startIndex=0]]

2021-09-29 16:26:51.520 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding

2021-09-29 16:26:51.523 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> FFFD/0, cluster=0000, TID=79, ieeeAddr=EC1BBDFFFE20FE45, requestType=0, startIndex=0]

2021-09-29 16:26:51.527 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=FFFD/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=4C, rssi=--, lqi=--, payload=79 45 FE 20 FE FF BD 1B EC 00 00]

2021-09-29 16:26:51.541 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendBroadcastResponse [networkId=0, status=EMBER_SUCCESS, sequence=8D]

2021-09-29 16:26:51.562 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_BROADCAST_LOOPBACK, apsFrame=EmberApsFrame [profileId=0000, clusterId=0000, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=8D], lastHopLqi=255, lastHopRssi=0, sender=0000, bindingIndex=255, addressIndex=255, messageContents=79 45 FE 20 FE FF BD 1B EC 00 00]

2021-09-29 16:26:52.504 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_BROADCAST, indexOrDestination=FFFD, apsFrame=EmberApsFrame [profileId=0000, clusterId=0000, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=8D], messageTag=79, status=EMBER_SUCCESS, messageContents=]

2021-09-29 16:26:52.508 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=79 state=RX_ACK

2021-09-29 16:26:52.511 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=79, state=RX_ACK, outstanding=2

2021-09-29 16:26:52.514 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=FFFD, TID=79, event=RX_ACK, state=ACKED

2021-09-29 16:26:56.205 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=EB6C, apsFrame=EmberApsFrame [profileId=0000, clusterId=0021, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=8C], messageTag=78, status=EMBER_DELIVERY_FAILED, messageContents=]

2021-09-29 16:26:56.209 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=78 state=RX_NAK

2021-09-29 16:26:56.212 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=78, state=RX_NAK, outstanding=2

2021-09-29 16:26:56.216 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=14178, state=FAILED, sendCnt=1, command=BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=78, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=8, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]]

2021-09-29 16:26:56.220 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding

2021-09-29 16:26:56.222 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - EC1BBDFFFE20FE45: transactionComplete, state=FAILED, outstanding=0

2021-09-29 16:26:56.227 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - EC1BBDFFFE20FE45: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=14188, state=WAITING, sendCnt=1, command=BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=78, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=8, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]]

2021-09-29 16:26:56.231 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3

2021-09-29 16:26:56.235 [DEBUG] [transaction.ZigBeeTransactionManager] - EB6C/0: Sending ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=14197, state=WAITING, sendCnt=1, command=BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=78, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=8, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]]

2021-09-29 16:26:56.238 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding

2021-09-29 16:26:56.242 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=78, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=8, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]

2021-09-29 16:26:56.246 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=EB6C/0, profile=0000, cluster=0021, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=4D, rssi=--, lqi=--, payload=78 45 FE 20 FE FF BD 1B EC 01 08 00 03 A7 D1 86 0C 00 6F 0D 00 01]

2021-09-29 16:26:56.250 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=EB6C, TID=78, event=RX_NAK, state=DISPATCHED

2021-09-29 16:26:56.263 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=8E]

2021-09-29 16:27:00.953 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=EB6C, apsFrame=EmberApsFrame [profileId=0000, clusterId=0021, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=8E], messageTag=78, status=EMBER_DELIVERY_FAILED, messageContents=]

2021-09-29 16:27:00.957 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=78 state=RX_NAK

2021-09-29 16:27:00.960 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=78, state=RX_NAK, outstanding=2

2021-09-29 16:27:00.965 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=18926, state=FAILED, sendCnt=2, command=BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=78, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=8, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]]

2021-09-29 16:27:00.969 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding

2021-09-29 16:27:00.971 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - EC1BBDFFFE20FE45: transactionComplete, state=FAILED, outstanding=0

2021-09-29 16:27:00.974 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - EC1BBDFFFE20FE45: transactionComplete exceeded max retries 2

2021-09-29 16:27:00.978 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=18940, state=CANCELLED, sendCnt=2, command=BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=78, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=8, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]]

2021-09-29 16:27:00.983 [DEBUG] [converter.ZigBeeConverterSwitchLevel] - EC1BBDFFFE20FE45: Failed to bind level control cluster

2021-09-29 16:27:00.984 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=18946, state=CANCELLED, sendCnt=2, command=BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=78, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=8, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]]

2021-09-29 16:27:00.988 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding

2021-09-29 16:27:00.990 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - EC1BBDFFFE20FE45: transactionComplete but not outstanding, state=CANCELLED, outstanding=0

2021-09-29 16:27:00.993 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=0, sleepy=0/3

2021-09-29 16:27:00.996 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=0, sleepy=0/3

2021-09-29 16:27:00.999 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=EB6C, TID=78, event=RX_NAK, state=CANCELLED

2021-09-29 16:27:01.000 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - EC1BBDFFFE20FE45: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=1, state=WAITING, sendCnt=0, command=BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=--, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=6, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]]

2021-09-29 16:27:01.004 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3

2021-09-29 16:27:01.008 [DEBUG] [transaction.ZigBeeTransactionManager] - EB6C/0: Sending ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=9, state=WAITING, sendCnt=0, command=BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=7A, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=6, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]]

2021-09-29 16:27:01.012 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding

2021-09-29 16:27:01.015 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=7A, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=6, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]

2021-09-29 16:27:01.020 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=EB6C/0, profile=0000, cluster=0021, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=4E, rssi=--, lqi=--, payload=7A 45 FE 20 FE FF BD 1B EC 01 06 00 03 A7 D1 86 0C 00 6F 0D 00 01]

2021-09-29 16:27:01.037 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=8F]

2021-09-29 16:27:01.523 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=null queueTime=10018, state=FAILED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> FFFD/0, cluster=0000, TID=79, ieeeAddr=EC1BBDFFFE20FE45, requestType=0, startIndex=0]]

2021-09-29 16:27:01.525 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding

2021-09-29 16:27:01.527 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete, state=FAILED, outstanding=0

2021-09-29 16:27:01.529 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete exceeded max retries 1

2021-09-29 16:27:01.531 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=null queueTime=10027, state=CANCELLED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> FFFD/0, cluster=0000, TID=79, ieeeAddr=EC1BBDFFFE20FE45, requestType=0, startIndex=0]]

2021-09-29 16:27:01.534 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - EC1BBDFFFE20FE45: NWK Discovery NetworkAddressRequest returned from null

2021-09-29 16:27:01.534 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=null queueTime=10030, state=CANCELLED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> FFFD/0, cluster=0000, TID=79, ieeeAddr=EC1BBDFFFE20FE45, requestType=0, startIndex=0]]

2021-09-29 16:27:01.536 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding

2021-09-29 16:27:01.537 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - EC1BBDFFFE20FE45: NWK Discovery node rediscovery request failed.

2021-09-29 16:27:01.538 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete but not outstanding, state=CANCELLED, outstanding=0

2021-09-29 16:27:01.540 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - EC1BBDFFFE20FE45: NWK Discovery finishing node rediscovery

2021-09-29 16:27:01.540 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=0, sleepy=0/3

2021-09-29 16:27:01.543 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=0, sleepy=0/3

2021-09-29 16:27:05.728 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=EB6C, apsFrame=EmberApsFrame [profileId=0000, clusterId=0021, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=8F], messageTag=7A, status=EMBER_DELIVERY_FAILED, messageContents=]

2021-09-29 16:27:05.733 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=7A state=RX_NAK

2021-09-29 16:27:05.736 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=7A, state=RX_NAK, outstanding=1

2021-09-29 16:27:05.740 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=4741, state=FAILED, sendCnt=1, command=BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=7A, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=6, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]]

2021-09-29 16:27:05.745 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding

2021-09-29 16:27:05.748 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - EC1BBDFFFE20FE45: transactionComplete, state=FAILED, outstanding=0

2021-09-29 16:27:05.752 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - EC1BBDFFFE20FE45: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=4753, state=WAITING, sendCnt=1, command=BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=7A, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=6, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]]

2021-09-29 16:27:05.756 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3

2021-09-29 16:27:05.760 [DEBUG] [transaction.ZigBeeTransactionManager] - EB6C/0: Sending ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=4761, state=WAITING, sendCnt=1, command=BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=7A, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=6, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]]

2021-09-29 16:27:05.765 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding

2021-09-29 16:27:05.768 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=7A, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=6, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]

2021-09-29 16:27:05.773 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=EB6C/0, profile=0000, cluster=0021, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=4F, rssi=--, lqi=--, payload=7A 45 FE 20 FE FF BD 1B EC 01 06 00 03 A7 D1 86 0C 00 6F 0D 00 01]

2021-09-29 16:27:05.777 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=EB6C, TID=7A, event=RX_NAK, state=DISPATCHED

2021-09-29 16:27:05.791 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=90]

2021-09-29 16:27:10.480 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=EB6C, apsFrame=EmberApsFrame [profileId=0000, clusterId=0021, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=90], messageTag=7A, status=EMBER_DELIVERY_FAILED, messageContents=]

2021-09-29 16:27:10.484 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=7A state=RX_NAK

2021-09-29 16:27:10.488 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=7A, state=RX_NAK, outstanding=1

2021-09-29 16:27:10.492 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=9492, state=FAILED, sendCnt=2, command=BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=7A, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=6, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]]

2021-09-29 16:27:10.496 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding

2021-09-29 16:27:10.499 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - EC1BBDFFFE20FE45: transactionComplete, state=FAILED, outstanding=0

2021-09-29 16:27:10.502 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - EC1BBDFFFE20FE45: transactionComplete exceeded max retries 2

2021-09-29 16:27:10.506 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=EC1BBDFFFE20FE45 queueTime=9507, state=CANCELLED, sendCnt=2, command=BindRequest [0000/0 -> EB6C/0, cluster=0021, TID=7A, srcAddress=EC1BBDFFFE20FE45, srcEndpoint=1, bindCluster=6, dstAddrMode=3, dstAddress=000D6F000C86D1A7, dstEndpoint=1]]

2021-09-29 16:27:10.511 [DEBUG] [converter.ZigBeeConverterSwitchLevel] - EC1BBDFFFE20FE45: Failed to bind on off control cluster

2021-09-29 16:27:10.514 [ERROR] [converter.ZigBeeConverterSwitchLevel] - EC1BBDFFFE20FE45: Error initialising device
2

It looks like the device stops responding, so the transaction times out. Can you describe your system please - what versions of firmware are used, what dongle?

I think these devices require a Zigbee 3 dongle or they will leave the network shortly after joining, and what you see here is the result, so it might be that, but I’m of course guessing without knowing your system.

3

Aha, I see.

I use a Bitron Video dongle, identified as Ember EM35x NCP with firmwareVersion 5.8.0.0.

4

So this is quite old, and I think that my guess above is correct. You should look to update the firmware - take a look at the very latest binding docs as there is a link there to some firmware that should work fine for this device.

5

Thank you for the quick reply Chris. I’ve had the philosophy to not update if it works but I guess I’ve reached the end of that streak.

I’ll do an update in the weekend and will post back about the result. Thanks again :+1:

1 Like