[SOLVED] Items receive commands but stopped to update their states

Hi @rossko57 and @chris,

I had the time to do a little more research here and I came up with another observation.

I can clearly differentiate the “working” devices from the “not working” devices by the fact that the latter ones fail to be initialized correctly.

So, when I, via Paper UI and the thing configuration page, trigger the “Initialize device” switch in the settings, I do get an error “Error opening device level controls” in the logs. This occurs for these things where the linked items do not update their states.

There is no such error in the logs for these things where the linked items do update their states.

Here you go with debug logs for the “not working” device initialization:

2020-07-26 15:28:46.199 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'Investigation.items'

==> /var/log/openhab2/events.log <==

2020-07-26 15:29:52.905 [ome.event.ItemCommandEvent] - Item 'TestItem_NotWorking' received command 27

2020-07-26 15:29:58.909 [ome.event.ItemCommandEvent] - Item 'TestItem_NotWorking' received command 100

2020-07-26 15:30:08.698 [me.event.ThingUpdatedEvent] - Thing 'zigbee:device:0137F59F:0017880103d08243' has been updated.

==> /var/log/openhab2/openhab.log <==

2020-07-26 15:30:09.906 [ERROR] [converter.ZigBeeConverterSwitchLevel] - 0017880103D08243: Error opening device level controls

2020-07-26 15:30:09.909 [INFO ] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880103D08243: Channel zigbee:device:0137F59F:0017880103d08243:0017880103D08243_11_dimmer failed to initialise device

2020-07-26 15:30:36.128 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00158D00015C55E3: Polling...

2020-07-26 15:30:41.954 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0019, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=38], lastHopLqi=255, lastHopRssi=-42, sender=65E6, bindingIndex=255, addressIndex=255, messageContents=01 DA 01 00 9D 11 01 11 12 14 03 17]

2020-07-26 15:30:41.961 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=65E6/1, destinationAddress=0000/1, profile=0104, cluster=0019, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=38, rssi=-42, lqi=FF, payload=01 DA 01 00 9D 11 01 11 12 14 03 17]

2020-07-26 15:30:41.963 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=218, commandId=1]

2020-07-26 15:30:41.966 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: QueryNextImageCommand [Ota Upgrade: 65E6/1 -> 0000/1, cluster=0019, TID=DA, fieldControl=0, manufacturerCode=4509, imageType=4353, fileVersion=386077714, hardwareVersion=null]

2020-07-26 15:30:41.968 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: QueryNextImageCommand [Ota Upgrade: 65E6/1 -> 0000/1, cluster=0019, TID=DA, fieldControl=0, manufacturerCode=4509, imageType=4353, fileVersion=386077714, hardwareVersion=null] 

2020-07-26 15:30:41.972 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00158D000315530D: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00158D000315530D queueTime=0, state=WAITING, sendCnt=0, command=QueryNextImageResponse [Ota Upgrade: 0000/0 -> 65E6/1, cluster=0019, TID=DA, status=NO_IMAGE_AVAILABLE, manufacturerCode=4509, imageType=4353, fileVersion=386077714, imageSize=0]]

2020-07-26 15:30:41.975 [DEBUG] [transaction.ZigBeeTransactionManager] - 65E6/1: Sending ZigBeeTransaction [ieeeAddress=00158D000315530D queueTime=4, state=WAITING, sendCnt=0, command=QueryNextImageResponse [Ota Upgrade: 0000/0 -> 65E6/1, cluster=0019, TID=DA, status=NO_IMAGE_AVAILABLE, manufacturerCode=4509, imageType=4353, fileVersion=386077714, imageSize=0]]

2020-07-26 15:30:41.977 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding

2020-07-26 15:30:41.980 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: QueryNextImageResponse [Ota Upgrade: 0000/0 -> 65E6/1, cluster=0019, TID=DA, status=NO_IMAGE_AVAILABLE, manufacturerCode=4509, imageType=4353, fileVersion=386077714, imageSize=0]

2020-07-26 15:30:41.983 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=218, commandId=2]

2020-07-26 15:30:41.986 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=65E6/1, profile=0104, cluster=0019, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=D0, rssi=--, lqi=--, payload=19 DA 02 98]

2020-07-26 15:30:42.000 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=12]

2020-07-26 15:30:42.049 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=65E6, apsFrame=EmberApsFrame [profileId=0104, clusterId=0019, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=12], messageTag=DA, status=EMBER_SUCCESS, messageContents=]

2020-07-26 15:30:42.051 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=DA state=RX_ACK

2020-07-26 15:30:42.053 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=DA, state=RX_ACK, outstanding=1

2020-07-26 15:30:42.055 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00158D000315530D queueTime=84, state=COMPLETE, sendCnt=1, command=QueryNextImageResponse [Ota Upgrade: 0000/0 -> 65E6/1, cluster=0019, TID=DA, status=NO_IMAGE_AVAILABLE, manufacturerCode=4509, imageType=4353, fileVersion=386077714, imageSize=0]]

2020-07-26 15:30:42.057 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding

2020-07-26 15:30:42.059 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00158D000315530D: transactionComplete COMPLETE 0

2020-07-26 15:30:42.061 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID DA -> RX_ACK == COMPLETE

2020-07-26 15:30:48.650 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0019, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=1F], lastHopLqi=255, lastHopRssi=-41, sender=D30F, bindingIndex=255, addressIndex=255, messageContents=01 1A 01 00 9D 11 01 11 12 14 03 17]

2020-07-26 15:30:48.653 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=D30F/1, destinationAddress=0000/1, profile=0104, cluster=0019, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=1F, rssi=-41, lqi=FF, payload=01 1A 01 00 9D 11 01 11 12 14 03 17]

2020-07-26 15:30:48.655 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=26, commandId=1]

2020-07-26 15:30:48.657 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: QueryNextImageCommand [Ota Upgrade: D30F/1 -> 0000/1, cluster=0019, TID=1A, fieldControl=0, manufacturerCode=4509, imageType=4353, fileVersion=386077714, hardwareVersion=null]

2020-07-26 15:30:48.659 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: QueryNextImageCommand [Ota Upgrade: D30F/1 -> 0000/1, cluster=0019, TID=1A, fieldControl=0, manufacturerCode=4509, imageType=4353, fileVersion=386077714, hardwareVersion=null] 

2020-07-26 15:30:48.663 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00158D00015C4E6C: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00158D00015C4E6C queueTime=0, state=WAITING, sendCnt=0, command=QueryNextImageResponse [Ota Upgrade: 0000/0 -> D30F/1, cluster=0019, TID=1A, status=NO_IMAGE_AVAILABLE, manufacturerCode=4509, imageType=4353, fileVersion=386077714, imageSize=0]]

2020-07-26 15:30:48.666 [DEBUG] [transaction.ZigBeeTransactionManager] - D30F/1: Sending ZigBeeTransaction [ieeeAddress=00158D00015C4E6C queueTime=3, state=WAITING, sendCnt=0, command=QueryNextImageResponse [Ota Upgrade: 0000/0 -> D30F/1, cluster=0019, TID=1A, status=NO_IMAGE_AVAILABLE, manufacturerCode=4509, imageType=4353, fileVersion=386077714, imageSize=0]]

2020-07-26 15:30:48.668 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding

2020-07-26 15:30:48.671 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: QueryNextImageResponse [Ota Upgrade: 0000/0 -> D30F/1, cluster=0019, TID=1A, status=NO_IMAGE_AVAILABLE, manufacturerCode=4509, imageType=4353, fileVersion=386077714, imageSize=0]

2020-07-26 15:30:48.674 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=26, commandId=2]

2020-07-26 15:30:48.676 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=D30F/1, profile=0104, cluster=0019, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=D1, rssi=--, lqi=--, payload=19 1A 02 98]

2020-07-26 15:30:48.691 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=13]

2020-07-26 15:30:48.785 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteErrorHandler [networkId=0, status=EMBER_SOURCE_ROUTE_FAILURE, target=D30F]

2020-07-26 15:30:48.809 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=D30F, apsFrame=EmberApsFrame [profileId=0104, clusterId=0019, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=13], messageTag=1A, status=EMBER_SUCCESS, messageContents=]

2020-07-26 15:30:48.811 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=1A state=RX_ACK

2020-07-26 15:30:48.813 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=1A, state=RX_ACK, outstanding=1

2020-07-26 15:30:48.816 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00158D00015C4E6C queueTime=153, state=COMPLETE, sendCnt=1, command=QueryNextImageResponse [Ota Upgrade: 0000/0 -> D30F/1, cluster=0019, TID=1A, status=NO_IMAGE_AVAILABLE, manufacturerCode=4509, imageType=4353, fileVersion=386077714, imageSize=0]]

2020-07-26 15:30:48.818 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding

2020-07-26 15:30:48.820 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00158D00015C4E6C: transactionComplete COMPLETE 0

2020-07-26 15:30:48.822 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 1A -> RX_ACK == COMPLETE

2020-07-26 15:30:56.455 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880103D08243: Configuration received: {zigbee_macaddress=0017880103D08243, zigbee_initialise_device=true}

2020-07-26 15:30:56.457 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880103D08243: Configuration update: Ignored zigbee_macaddress as no change

2020-07-26 15:30:56.459 [DEBUG] [e.internal.ZigBeeDeviceConfigHandler] - Configuration update: Ignored zigbee_macaddress as no change

2020-07-26 15:30:56.464 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880103D08243: Configuration updated: Reinitialise device

2020-07-26 15:30:56.466 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880103D08243: Initializing device

==> /var/log/openhab2/events.log <==

2020-07-26 15:30:56.467 [me.event.ThingUpdatedEvent] - Thing 'zigbee:device:0137F59F:0017880103d08243' has been updated.

==> /var/log/openhab2/openhab.log <==

2020-07-26 15:30:56.469 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880103D08243: Initializing channel zigbee:device:0137F59F:0017880103d08243:0017880103D08243_11_colortemperature with org.openhab.binding.zigbee.internal.converter.ZigBeeConverterColorTemperature@bb857b

2020-07-26 15:30:56.472 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880103D08243: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=0, state=WAITING, sendCnt=0, command=BindRequest [0000/0 -> CB64/0, cluster=0021, TID=--, srcAddress=0017880103D08243, srcEndpoint=11, bindCluster=768, dstAddrMode=3, dstAddress=000D6F000D3AF646, dstEndpoint=1]]

2020-07-26 15:30:56.475 [DEBUG] [transaction.ZigBeeTransactionManager] - CB64/0: Sending ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=3, state=WAITING, sendCnt=0, command=BindRequest [0000/0 -> CB64/0, cluster=0021, TID=6D, srcAddress=0017880103D08243, srcEndpoint=11, bindCluster=768, dstAddrMode=3, dstAddress=000D6F000D3AF646, dstEndpoint=1]]

2020-07-26 15:30:56.476 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding

2020-07-26 15:30:56.479 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: BindRequest [0000/0 -> CB64/0, cluster=0021, TID=6D, srcAddress=0017880103D08243, srcEndpoint=11, bindCluster=768, dstAddrMode=3, dstAddress=000D6F000D3AF646, dstEndpoint=1]

2020-07-26 15:30:56.482 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=CB64/0, profile=0000, cluster=0021, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=D2, rssi=--, lqi=--, payload=6D 43 82 D0 03 01 88 17 00 0B 00 03 03 46 F6 3A 0D 00 6F 0D 00 01]

2020-07-26 15:30:56.497 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=14]

2020-07-26 15:30:56.546 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=CB64, sourceEui=0017880103D08243, lastHopLqi=255, lastHopRssi=-41, relayList=F753]

2020-07-26 15:30:56.629 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=CB64, apsFrame=EmberApsFrame [profileId=0000, clusterId=0021, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=14], messageTag=6D, status=EMBER_SUCCESS, messageContents=]

2020-07-26 15:30:56.630 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=6D state=RX_ACK

2020-07-26 15:30:56.631 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=6D, state=RX_ACK, outstanding=1

2020-07-26 15:30:56.632 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 6D -> RX_ACK == ACKED

2020-07-26 15:30:56.651 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=CB64, sourceEui=0017880103D08243, lastHopLqi=255, lastHopRssi=-42, relayList=F753]

2020-07-26 15:30:56.716 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=8021, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=93], lastHopLqi=255, lastHopRssi=-41, sender=CB64, bindingIndex=255, addressIndex=255, messageContents=6D 00]

2020-07-26 15:30:56.717 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=CB64/0, destinationAddress=0000/0, profile=0000, cluster=8021, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=93, rssi=-41, lqi=FF, payload=6D 00]

2020-07-26 15:30:56.719 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: BindResponse [CB64/0 -> 0000/0, cluster=8021, TID=6D, status=SUCCESS]

2020-07-26 15:30:56.720 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: BindResponse [CB64/0 -> 0000/0, cluster=8021, TID=6D, status=SUCCESS] 

2020-07-26 15:30:56.722 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: BindResponse [CB64/0 -> 0000/0, cluster=8021, TID=6D, status=SUCCESS] ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=250, state=ACKED, sendCnt=1, command=BindRequest [0000/0 -> CB64/0, cluster=0021, TID=6D, srcAddress=0017880103D08243, srcEndpoint=11, bindCluster=768, dstAddrMode=3, dstAddress=000D6F000D3AF646, dstEndpoint=1]]

2020-07-26 15:30:56.723 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=252, state=COMPLETE, sendCnt=1, command=BindRequest [0000/0 -> CB64/0, cluster=0021, TID=6D, srcAddress=0017880103D08243, srcEndpoint=11, bindCluster=768, dstAddrMode=3, dstAddress=000D6F000D3AF646, dstEndpoint=1]]

2020-07-26 15:30:56.723 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880103D08243: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=0, state=WAITING, sendCnt=0, command=ConfigureReportingCommand [Color Control: 0000/0 -> CB64/11, cluster=0300, TID=--, records=[AttributeReportingConfigurationRecord [attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=7, direction=0, minimumReportingInterval=1, maximumReportingInterval=7200, reportableChange=1]]]]

2020-07-26 15:30:56.725 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding

2020-07-26 15:30:56.725 [DEBUG] [transaction.ZigBeeTransactionManager] - CB64/11: Sending ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=2, state=WAITING, sendCnt=0, command=ConfigureReportingCommand [Color Control: 0000/0 -> CB64/11, cluster=0300, TID=6E, records=[AttributeReportingConfigurationRecord [attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=7, direction=0, minimumReportingInterval=1, maximumReportingInterval=7200, reportableChange=1]]]]

2020-07-26 15:30:56.727 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding

2020-07-26 15:30:56.729 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ConfigureReportingCommand [Color Control: 0000/0 -> CB64/11, cluster=0300, TID=6E, records=[AttributeReportingConfigurationRecord [attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=7, direction=0, minimumReportingInterval=1, maximumReportingInterval=7200, reportableChange=1]]]

2020-07-26 15:30:56.731 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=110, commandId=6]

2020-07-26 15:30:56.732 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=CB64/11, profile=0104, cluster=0300, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=D3, rssi=--, lqi=--, payload=00 6E 06 00 07 00 21 01 00 20 1C 01 00]

2020-07-26 15:30:56.735 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880103D08243: transactionComplete COMPLETE 1

2020-07-26 15:30:56.747 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=15]

2020-07-26 15:30:56.796 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=CB64, sourceEui=0017880103D08243, lastHopLqi=255, lastHopRssi=-42, relayList=F753]

2020-07-26 15:30:56.879 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=CB64, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=11, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=15], messageTag=6E, status=EMBER_SUCCESS, messageContents=]

2020-07-26 15:30:56.880 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=6E state=RX_ACK

2020-07-26 15:30:56.881 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=6E, state=RX_ACK, outstanding=1

2020-07-26 15:30:56.882 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 6E -> RX_ACK == ACKED

2020-07-26 15:30:56.901 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=CB64, sourceEui=0017880103D08243, lastHopLqi=255, lastHopRssi=-42, relayList=F753]

2020-07-26 15:30:56.969 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=11, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=94], lastHopLqi=255, lastHopRssi=-41, sender=CB64, bindingIndex=255, addressIndex=255, messageContents=18 6E 0B 06 82]

2020-07-26 15:30:56.972 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=CB64/11, destinationAddress=0000/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=94, rssi=-41, lqi=FF, payload=18 6E 0B 06 82]

2020-07-26 15:30:56.973 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=110, commandId=11]

2020-07-26 15:30:56.976 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DefaultResponse [Color Control: CB64/11 -> 0000/1, cluster=0300, TID=6E, commandIdentifier=6, statusCode=UNSUP_GENERAL_COMMAND]

2020-07-26 15:30:56.978 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [Color Control: CB64/11 -> 0000/1, cluster=0300, TID=6E, commandIdentifier=6, statusCode=UNSUP_GENERAL_COMMAND] 

2020-07-26 15:30:56.981 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [Color Control: CB64/11 -> 0000/1, cluster=0300, TID=6E, commandIdentifier=6, statusCode=UNSUP_GENERAL_COMMAND] ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=257, state=ACKED, sendCnt=1, command=ConfigureReportingCommand [Color Control: 0000/0 -> CB64/11, cluster=0300, TID=6E, records=[AttributeReportingConfigurationRecord [attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=7, direction=0, minimumReportingInterval=1, maximumReportingInterval=7200, reportableChange=1]]]]

2020-07-26 15:30:56.984 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=260, state=COMPLETE, sendCnt=1, command=ConfigureReportingCommand [Color Control: 0000/0 -> CB64/11, cluster=0300, TID=6E, records=[AttributeReportingConfigurationRecord [attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=7, direction=0, minimumReportingInterval=1, maximumReportingInterval=7200, reportableChange=1]]]]

2020-07-26 15:30:56.984 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880103D08243: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=0, state=WAITING, sendCnt=0, command=ConfigureReportingCommand [Color Control: 0000/0 -> CB64/11, cluster=0300, TID=--, records=[AttributeReportingConfigurationRecord [attributeDataType=ENUMERATION_8_BIT, attributeIdentifier=8, direction=0, minimumReportingInterval=1, maximumReportingInterval=7200]]]]

2020-07-26 15:30:56.986 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding

2020-07-26 15:30:56.988 [DEBUG] [transaction.ZigBeeTransactionManager] - CB64/11: Sending ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=4, state=WAITING, sendCnt=0, command=ConfigureReportingCommand [Color Control: 0000/0 -> CB64/11, cluster=0300, TID=6F, records=[AttributeReportingConfigurationRecord [attributeDataType=ENUMERATION_8_BIT, attributeIdentifier=8, direction=0, minimumReportingInterval=1, maximumReportingInterval=7200]]]]

2020-07-26 15:30:56.991 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding

2020-07-26 15:30:56.994 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ConfigureReportingCommand [Color Control: 0000/0 -> CB64/11, cluster=0300, TID=6F, records=[AttributeReportingConfigurationRecord [attributeDataType=ENUMERATION_8_BIT, attributeIdentifier=8, direction=0, minimumReportingInterval=1, maximumReportingInterval=7200]]]

2020-07-26 15:30:56.997 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=111, commandId=6]

2020-07-26 15:30:57.001 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=CB64/11, profile=0104, cluster=0300, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=D4, rssi=--, lqi=--, payload=00 6F 06 00 08 00 30 01 00 20 1C]

2020-07-26 15:30:57.004 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880103D08243: transactionComplete COMPLETE 1

2020-07-26 15:30:57.015 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=16]

2020-07-26 15:30:57.069 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=CB64, sourceEui=0017880103D08243, lastHopLqi=255, lastHopRssi=-41, relayList=F753]

2020-07-26 15:30:57.149 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=CB64, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=11, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=16], messageTag=6F, status=EMBER_SUCCESS, messageContents=]

2020-07-26 15:30:57.151 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=6F state=RX_ACK

2020-07-26 15:30:57.153 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=6F, state=RX_ACK, outstanding=1

2020-07-26 15:30:57.156 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 6F -> RX_ACK == ACKED

2020-07-26 15:30:57.172 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=CB64, sourceEui=0017880103D08243, lastHopLqi=255, lastHopRssi=-41, relayList=F753]

2020-07-26 15:30:57.230 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=11, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=95], lastHopLqi=255, lastHopRssi=-41, sender=CB64, bindingIndex=255, addressIndex=255, messageContents=18 6F 0B 06 82]

2020-07-26 15:30:57.232 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=CB64/11, destinationAddress=0000/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=95, rssi=-41, lqi=FF, payload=18 6F 0B 06 82]

2020-07-26 15:30:57.235 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=111, commandId=11]

2020-07-26 15:30:57.237 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DefaultResponse [Color Control: CB64/11 -> 0000/1, cluster=0300, TID=6F, commandIdentifier=6, statusCode=UNSUP_GENERAL_COMMAND]

2020-07-26 15:30:57.240 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [Color Control: CB64/11 -> 0000/1, cluster=0300, TID=6F, commandIdentifier=6, statusCode=UNSUP_GENERAL_COMMAND] 

2020-07-26 15:30:57.242 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [Color Control: CB64/11 -> 0000/1, cluster=0300, TID=6F, commandIdentifier=6, statusCode=UNSUP_GENERAL_COMMAND] ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=258, state=ACKED, sendCnt=1, command=ConfigureReportingCommand [Color Control: 0000/0 -> CB64/11, cluster=0300, TID=6F, records=[AttributeReportingConfigurationRecord [attributeDataType=ENUMERATION_8_BIT, attributeIdentifier=8, direction=0, minimumReportingInterval=1, maximumReportingInterval=7200]]]]

2020-07-26 15:30:57.245 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=262, state=COMPLETE, sendCnt=1, command=ConfigureReportingCommand [Color Control: 0000/0 -> CB64/11, cluster=0300, TID=6F, records=[AttributeReportingConfigurationRecord [attributeDataType=ENUMERATION_8_BIT, attributeIdentifier=8, direction=0, minimumReportingInterval=1, maximumReportingInterval=7200]]]]

2020-07-26 15:30:57.246 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880103D08243: Initializing channel zigbee:device:0137F59F:0017880103d08243:0017880103D08243_11_dimmer with org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel@476977

2020-07-26 15:30:57.248 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding

2020-07-26 15:30:57.250 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880103D08243: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=0, state=WAITING, sendCnt=0, command=BindRequest [0000/0 -> CB64/0, cluster=0021, TID=--, srcAddress=0017880103D08243, srcEndpoint=11, bindCluster=8, dstAddrMode=3, dstAddress=000D6F000D3AF646, dstEndpoint=1]]

2020-07-26 15:30:57.254 [DEBUG] [transaction.ZigBeeTransactionManager] - CB64/0: Sending ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=4, state=WAITING, sendCnt=0, command=BindRequest [0000/0 -> CB64/0, cluster=0021, TID=70, srcAddress=0017880103D08243, srcEndpoint=11, bindCluster=8, dstAddrMode=3, dstAddress=000D6F000D3AF646, dstEndpoint=1]]

2020-07-26 15:30:57.257 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding

2020-07-26 15:30:57.260 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: BindRequest [0000/0 -> CB64/0, cluster=0021, TID=70, srcAddress=0017880103D08243, srcEndpoint=11, bindCluster=8, dstAddrMode=3, dstAddress=000D6F000D3AF646, dstEndpoint=1]

2020-07-26 15:30:57.263 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=CB64/0, profile=0000, cluster=0021, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=D5, rssi=--, lqi=--, payload=70 43 82 D0 03 01 88 17 00 0B 08 00 03 46 F6 3A 0D 00 6F 0D 00 01]

2020-07-26 15:30:57.266 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880103D08243: transactionComplete COMPLETE 1

2020-07-26 15:30:57.281 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=17]

2020-07-26 15:30:57.328 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=CB64, sourceEui=0017880103D08243, lastHopLqi=255, lastHopRssi=-42, relayList=F753]

2020-07-26 15:30:57.395 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=CB64, apsFrame=EmberApsFrame [profileId=0000, clusterId=0021, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=17], messageTag=70, status=EMBER_SUCCESS, messageContents=]

2020-07-26 15:30:57.397 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=70 state=RX_ACK

2020-07-26 15:30:57.399 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=70, state=RX_ACK, outstanding=1

2020-07-26 15:30:57.401 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 70 -> RX_ACK == ACKED

2020-07-26 15:30:57.422 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=CB64, sourceEui=0017880103D08243, lastHopLqi=255, lastHopRssi=-41, relayList=F753]

2020-07-26 15:30:57.489 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=8021, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=96], lastHopLqi=255, lastHopRssi=-41, sender=CB64, bindingIndex=255, addressIndex=255, messageContents=70 8C]

2020-07-26 15:30:57.491 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=CB64/0, destinationAddress=0000/0, profile=0000, cluster=8021, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=96, rssi=-41, lqi=FF, payload=70 8C]

2020-07-26 15:30:57.493 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: BindResponse [CB64/0 -> 0000/0, cluster=8021, TID=70, status=TABLE_FULL]

2020-07-26 15:30:57.495 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: BindResponse [CB64/0 -> 0000/0, cluster=8021, TID=70, status=TABLE_FULL] 

2020-07-26 15:30:57.498 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: BindResponse [CB64/0 -> 0000/0, cluster=8021, TID=70, status=TABLE_FULL] ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=248, state=ACKED, sendCnt=1, command=BindRequest [0000/0 -> CB64/0, cluster=0021, TID=70, srcAddress=0017880103D08243, srcEndpoint=11, bindCluster=8, dstAddrMode=3, dstAddress=000D6F000D3AF646, dstEndpoint=1]]

2020-07-26 15:30:57.501 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=251, state=COMPLETE, sendCnt=1, command=BindRequest [0000/0 -> CB64/0, cluster=0021, TID=70, srcAddress=0017880103D08243, srcEndpoint=11, bindCluster=8, dstAddrMode=3, dstAddress=000D6F000D3AF646, dstEndpoint=1]]

2020-07-26 15:30:57.501 [DEBUG] [converter.ZigBeeConverterSwitchLevel] - 0017880103D08243: Failed to bind level control cluster

2020-07-26 15:30:57.503 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding

2020-07-26 15:30:57.504 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880103D08243: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=0, state=WAITING, sendCnt=0, command=BindRequest [0000/0 -> CB64/0, cluster=0021, TID=--, srcAddress=0017880103D08243, srcEndpoint=11, bindCluster=6, dstAddrMode=3, dstAddress=000D6F000D3AF646, dstEndpoint=1]]

2020-07-26 15:30:57.509 [DEBUG] [transaction.ZigBeeTransactionManager] - CB64/0: Sending ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=5, state=WAITING, sendCnt=0, command=BindRequest [0000/0 -> CB64/0, cluster=0021, TID=71, srcAddress=0017880103D08243, srcEndpoint=11, bindCluster=6, dstAddrMode=3, dstAddress=000D6F000D3AF646, dstEndpoint=1]]

2020-07-26 15:30:57.511 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding

2020-07-26 15:30:57.515 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: BindRequest [0000/0 -> CB64/0, cluster=0021, TID=71, srcAddress=0017880103D08243, srcEndpoint=11, bindCluster=6, dstAddrMode=3, dstAddress=000D6F000D3AF646, dstEndpoint=1]

2020-07-26 15:30:57.518 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=CB64/0, profile=0000, cluster=0021, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=D6, rssi=--, lqi=--, payload=71 43 82 D0 03 01 88 17 00 0B 06 00 03 46 F6 3A 0D 00 6F 0D 00 01]

2020-07-26 15:30:57.521 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880103D08243: transactionComplete COMPLETE 1

2020-07-26 15:30:57.536 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=18]

2020-07-26 15:30:57.591 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=CB64, sourceEui=0017880103D08243, lastHopLqi=255, lastHopRssi=-42, relayList=F753]

2020-07-26 15:30:57.668 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=CB64, apsFrame=EmberApsFrame [profileId=0000, clusterId=0021, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=18], messageTag=71, status=EMBER_SUCCESS, messageContents=]

2020-07-26 15:30:57.672 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=71 state=RX_ACK

2020-07-26 15:30:57.674 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=71, state=RX_ACK, outstanding=1

2020-07-26 15:30:57.676 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 71 -> RX_ACK == ACKED

2020-07-26 15:30:57.691 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=CB64, sourceEui=0017880103D08243, lastHopLqi=255, lastHopRssi=-41, relayList=F753]

2020-07-26 15:30:57.758 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=8021, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=97], lastHopLqi=255, lastHopRssi=-41, sender=CB64, bindingIndex=255, addressIndex=255, messageContents=71 8C]

2020-07-26 15:30:57.761 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=CB64/0, destinationAddress=0000/0, profile=0000, cluster=8021, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=97, rssi=-41, lqi=FF, payload=71 8C]

2020-07-26 15:30:57.763 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: BindResponse [CB64/0 -> 0000/0, cluster=8021, TID=71, status=TABLE_FULL]

2020-07-26 15:30:57.765 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: BindResponse [CB64/0 -> 0000/0, cluster=8021, TID=71, status=TABLE_FULL] 

2020-07-26 15:30:57.768 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: BindResponse [CB64/0 -> 0000/0, cluster=8021, TID=71, status=TABLE_FULL] ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=264, state=ACKED, sendCnt=1, command=BindRequest [0000/0 -> CB64/0, cluster=0021, TID=71, srcAddress=0017880103D08243, srcEndpoint=11, bindCluster=6, dstAddrMode=3, dstAddress=000D6F000D3AF646, dstEndpoint=1]]

2020-07-26 15:30:57.770 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0017880103D08243 queueTime=266, state=COMPLETE, sendCnt=1, command=BindRequest [0000/0 -> CB64/0, cluster=0021, TID=71, srcAddress=0017880103D08243, srcEndpoint=11, bindCluster=6, dstAddrMode=3, dstAddress=000D6F000D3AF646, dstEndpoint=1]]

2020-07-26 15:30:57.772 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding

2020-07-26 15:30:57.770 [DEBUG] [converter.ZigBeeConverterSwitchLevel] - 0017880103D08243: Failed to bind on off control cluster

2020-07-26 15:30:57.774 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880103D08243: transactionComplete COMPLETE 0

2020-07-26 15:30:57.775 [ERROR] [converter.ZigBeeConverterSwitchLevel] - 0017880103D08243: Error opening device level controls

2020-07-26 15:30:57.778 [INFO ] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880103D08243: Channel zigbee:device:0137F59F:0017880103d08243:0017880103D08243_11_dimmer failed to initialise device

I also did some searching around and found this thread (Zigbee Binding fails to initialize dimmer) and an corresponding issue (https://github.com/openhab/org.openhab.binding.zigbee/issues/522).

Maybe there’s some connection? Do you have any idea on this one?

Thanks and best!