Zigbee binding very slow

I’ve been having the same issues with Zigbee devices acting very slowly. Sometimes it takes upwards of 30 seconds before a command is registered on the bulb. I am using an Osram Smart+ bulb (listed as LEDVANCE) with color temp and dimmer. I have also move to Openhabian on my Pi 4, and am using the regular Zigbee binding (version 2.5.5). Finally, I am trying the snapshot build as well. Using an xbee usb dongle.

30 seconds seems to be the longest wait, sometimes it’s instantaneous. Also, if I do multiple commands they all go into effect after that 30 seconds has lapsed. (dim and change the color temp, for example). I read somewhere that if the initial command is not registered it would wait 30 seconds and poll again. (to be honest I’m not sure the exact details but this is what it seems to be doing).

I don’t have a lot of experience with Openhab yet, so direction would be very helpful. I’m only playing right now so I am willing to try anything.

I was able to get logs. I don’t know what I’m looking at but here they are. It seems to me that the command to the bulb is being sent but immediately goes into a transaction queue vs going directly to the light. Maybe this is correct? Have a look and let me know what you think:

2020-05-27 17:52:49.198 [ome.event.ItemCommandEvent] - Item 'LEDVANCEA19TW10Year_ColorTemperature' received command 1

2020-05-27 17:52:49.235 [nt.ItemStatePredictedEvent] - LEDVANCEA19TW10Year_ColorTemperature predicted to become 1

2020-05-27 17:52:49.257 [vent.ItemStateChangedEvent] - LEDVANCEA19TW10Year_ColorTemperature changed from 84 to 1

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

2020-05-27 17:52:49.267 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: Added transaction to queue, len=3, transaction=ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=0, state=WAITING, sendCnt=0, command=MoveToColorTemperatureCommand [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=--, colorTemperature=154, transitionTime=10]]

2020-05-27 17:52:49.271 [DEBUG] [transaction.ZigBeeTransactionManager] - ED83/1: Sending ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=103006, state=WAITING, sendCnt=1, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=54, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:52:49.274 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding

2020-05-27 17:52:49.276 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=54, commandIdentifier=10, statusCode=SUCCESS]

2020-05-27 17:52:49.278 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=84, commandId=11]

2020-05-27 17:52:49.280 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=ED83/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=14, rssi=--, lqi=--, payload=10 54 0B 0A 00]

2020-05-27 17:52:49.282 [DEBUG] [.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee send: XBeeTransmitRequestExplicitCommand [frameId=null, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 54 0B 0A 00]

2020-05-27 17:52:49.285 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeTransmitRequestExplicitCommand [frameId=41, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 54 0B 0A 00]

2020-05-27 17:52:49.287 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeTransmitRequestExplicitCommand [frameId=41, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 54 0B 0A 00]

2020-05-27 17:52:49.289 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 19 11 29 F0 D1 B8 00 00 02 71 52 ED 83 01 01 03 00 01 04 00 00 10 54 0B 0A 00 94

2020-05-27 17:52:49.319 [DEBUG] [transaction.ZigBeeTransactionManager] - ED83/1: Sending ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=106328, state=WAITING, sendCnt=1, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=53, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:52:49.320 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding

2020-05-27 17:52:49.322 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=53, commandIdentifier=10, statusCode=SUCCESS]

2020-05-27 17:52:49.324 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=83, commandId=11]

2020-05-27 17:52:49.325 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=ED83/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=15, rssi=--, lqi=--, payload=10 53 0B 0A 00]

2020-05-27 17:52:49.327 [DEBUG] [.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee send: XBeeTransmitRequestExplicitCommand [frameId=null, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 53 0B 0A 00]

2020-05-27 17:52:49.330 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeTransmitRequestExplicitCommand [frameId=42, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 53 0B 0A 00]

2020-05-27 17:52:49.417 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 8B 29 ED 83 00 00 00 DB

2020-05-27 17:52:49.418 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeTransmitStatusResponse [frameId=41, networkAddress=60803, transmitRetryCount=0, deliveryStatus=SUCCESS, discoveryStatus=NO_DISCOVERY_OVERHEAD]

2020-05-27 17:52:49.419 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeTransmitRequestExplicitCommand [frameId=42, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 53 0B 0A 00]

2020-05-27 17:52:49.422 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 19 11 2A F0 D1 B8 00 00 02 71 52 ED 83 01 01 03 00 01 04 00 00 10 53 0B 0A 00 94

2020-05-27 17:52:49.566 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 8B 2A ED 83 00 00 00 DA

2020-05-27 17:52:49.567 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeTransmitStatusResponse [frameId=42, networkAddress=60803, transmitRetryCount=0, deliveryStatus=SUCCESS, discoveryStatus=NO_DISCOVERY_OVERHEAD]

2020-05-27 17:52:59.277 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=113012, state=FAILED, sendCnt=2, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=54, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:52:59.279 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding

2020-05-27 17:52:59.280 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: transactionComplete FAILED 1

2020-05-27 17:52:59.282 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: transactionComplete exceeded retries 2

2020-05-27 17:52:59.285 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction terminated: ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=113020, state=FAILED, sendCnt=2, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=54, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:52:59.288 [DEBUG] [transaction.ZigBeeTransactionManager] - ED83/1: Sending ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=10021, state=WAITING, sendCnt=0, command=MoveToColorTemperatureCommand [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=A5, colorTemperature=154, transitionTime=10]]

2020-05-27 17:52:59.291 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding

2020-05-27 17:52:59.294 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: MoveToColorTemperatureCommand [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=A5, colorTemperature=154, transitionTime=10]

2020-05-27 17:52:59.297 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=165, commandId=10]

2020-05-27 17:52:59.300 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=ED83/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=16, rssi=--, lqi=--, payload=01 A5 0A 9A 00 0A 00]

2020-05-27 17:52:59.304 [DEBUG] [.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee send: XBeeTransmitRequestExplicitCommand [frameId=null, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=01 A5 0A 9A 00 0A 00]

2020-05-27 17:52:59.307 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeTransmitRequestExplicitCommand [frameId=43, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=01 A5 0A 9A 00 0A 00]

2020-05-27 17:52:59.311 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeTransmitRequestExplicitCommand [frameId=43, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=01 A5 0A 9A 00 0A 00]

2020-05-27 17:52:59.319 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 1B 11 2B F0 D1 B8 00 00 02 71 52 ED 83 01 01 03 00 01 04 00 00 01 A5 0A 9A 00 0A 00 B7

2020-05-27 17:52:59.323 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=116331, state=FAILED, sendCnt=2, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=53, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:52:59.325 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding

2020-05-27 17:52:59.327 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: transactionComplete FAILED 1

2020-05-27 17:52:59.329 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: transactionComplete exceeded retries 2

2020-05-27 17:52:59.332 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction terminated: ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=116340, state=FAILED, sendCnt=2, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=53, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:52:59.480 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 17 91 F0 D1 B8 00 00 02 71 52 ED 83 01 01 03 00 01 04 01 08 A5 0B 0A 00 F3

2020-05-27 17:52:59.483 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeReceivePacketExplicitEvent [ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, clusterId=768, profileId=260, receiveOptions=PACKET_ACKNOWLEDGED, data=08 A5 0B 0A 00]

2020-05-27 17:52:59.486 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=ED83/1, destinationAddress=0000/1, profile=0104, cluster=0300, addressMode=null, radius=0, apsSecurity=false, ackRequest=false, apsCounter=--, rssi=--, lqi=--, payload=08 A5 0B 0A 00]

2020-05-27 17:52:59.488 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=165, commandId=11]

2020-05-27 17:52:59.490 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DefaultResponse [Color Control: ED83/1 -> 0000/1, cluster=0300, TID=A5, commandIdentifier=10, statusCode=SUCCESS]

2020-05-27 17:52:59.492 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [Color Control: ED83/1 -> 0000/1, cluster=0300, TID=A5, commandIdentifier=10, statusCode=SUCCESS] 

2020-05-27 17:52:59.495 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [Color Control: ED83/1 -> 0000/1, cluster=0300, TID=A5, commandIdentifier=10, statusCode=SUCCESS] ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=10228, state=DISPATCHED, sendCnt=1, command=MoveToColorTemperatureCommand [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=A5, colorTemperature=154, transitionTime=10]]

2020-05-27 17:52:59.498 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 8B 2B ED 83 00 00 00 D9

2020-05-27 17:52:59.498 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=10231, state=COMPLETE, sendCnt=1, command=MoveToColorTemperatureCommand [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=A5, colorTemperature=154, transitionTime=10]]

2020-05-27 17:52:59.500 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeTransmitStatusResponse [frameId=43, networkAddress=60803, transmitRetryCount=0, deliveryStatus=SUCCESS, discoveryStatus=NO_DISCOVERY_OVERHEAD]

2020-05-27 17:52:59.501 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding

2020-05-27 17:52:59.504 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: transactionComplete COMPLETE 0

2020-05-27 17:52:59.522 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 1A 91 F0 D1 B8 00 00 02 71 52 ED 83 01 01 03 00 01 04 01 08 55 0A 07 00 21 71 01 B4

2020-05-27 17:52:59.525 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeReceivePacketExplicitEvent [ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, clusterId=768, profileId=260, receiveOptions=PACKET_ACKNOWLEDGED, data=08 55 0A 07 00 21 71 01]

2020-05-27 17:52:59.527 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=ED83/1, destinationAddress=0000/1, profile=0104, cluster=0300, addressMode=null, radius=0, apsSecurity=false, ackRequest=false, apsCounter=--, rssi=--, lqi=--, payload=08 55 0A 07 00 21 71 01]

2020-05-27 17:52:59.529 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=85, commandId=10]

2020-05-27 17:52:59.532 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Color Control: ED83/1 -> 0000/1, cluster=0300, TID=55, reports=[AttributeReport [attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=7, attributeValue=369]]]

2020-05-27 17:52:59.534 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Color Control: ED83/1 -> 0000/1, cluster=0300, TID=55, reports=[AttributeReport [attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=7, attributeValue=369]]] 

2020-05-27 17:52:59.538 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=55, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:52:59.541 [DEBUG] [transaction.ZigBeeTransactionManager] - ED83/1: Sending ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=3, state=WAITING, sendCnt=0, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=55, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:52:59.543 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding

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

2020-05-27 17:52:59.549 [vent.ItemStateChangedEvent] - LEDVANCEA19TW10Year_ColorTemperature changed from 1 to 84

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

2020-05-27 17:52:59.546 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=55, commandIdentifier=10, statusCode=SUCCESS]

2020-05-27 17:52:59.556 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=85, commandId=11]

2020-05-27 17:52:59.559 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=ED83/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=17, rssi=--, lqi=--, payload=10 55 0B 0A 00]

2020-05-27 17:52:59.562 [DEBUG] [.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee send: XBeeTransmitRequestExplicitCommand [frameId=null, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 55 0B 0A 00]

2020-05-27 17:52:59.566 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeTransmitRequestExplicitCommand [frameId=44, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 55 0B 0A 00]

2020-05-27 17:52:59.568 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeTransmitRequestExplicitCommand [frameId=44, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 55 0B 0A 00]

2020-05-27 17:52:59.575 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 19 11 2C F0 D1 B8 00 00 02 71 52 ED 83 01 01 03 00 01 04 00 00 10 55 0B 0A 00 90

2020-05-27 17:52:59.710 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 8B 2C ED 83 00 00 00 D8

2020-05-27 17:52:59.711 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeTransmitStatusResponse [frameId=44, networkAddress=60803, transmitRetryCount=0, deliveryStatus=SUCCESS, discoveryStatus=NO_DISCOVERY_OVERHEAD]

2020-05-27 17:53:01.674 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 1A 91 F0 D1 B8 00 00 02 71 52 ED 83 01 01 03 00 01 04 01 08 56 0A 07 00 21 9A 00 8B

2020-05-27 17:53:01.677 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeReceivePacketExplicitEvent [ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, clusterId=768, profileId=260, receiveOptions=PACKET_ACKNOWLEDGED, data=08 56 0A 07 00 21 9A 00]

2020-05-27 17:53:01.679 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=ED83/1, destinationAddress=0000/1, profile=0104, cluster=0300, addressMode=null, radius=0, apsSecurity=false, ackRequest=false, apsCounter=--, rssi=--, lqi=--, payload=08 56 0A 07 00 21 9A 00]

2020-05-27 17:53:01.682 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=86, commandId=10]

2020-05-27 17:53:01.684 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Color Control: ED83/1 -> 0000/1, cluster=0300, TID=56, reports=[AttributeReport [attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=7, attributeValue=154]]]

2020-05-27 17:53:01.686 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Color Control: ED83/1 -> 0000/1, cluster=0300, TID=56, reports=[AttributeReport [attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=7, attributeValue=154]]] 

2020-05-27 17:53:01.690 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Color Control: ED83/1 -> 0000/1, cluster=0300, TID=56, reports=[AttributeReport [attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=7, attributeValue=154]]] ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=2152, state=DISPATCHED, sendCnt=1, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=55, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:53:01.694 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=56, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:53:01.696 [DEBUG] [transaction.ZigBeeTransactionManager] - ED83/1: Sending ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=3, state=WAITING, sendCnt=0, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=56, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:53:01.699 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding

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

2020-05-27 17:53:01.705 [vent.ItemStateChangedEvent] - LEDVANCEA19TW10Year_ColorTemperature changed from 84 to 0

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

2020-05-27 17:53:01.704 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=56, commandIdentifier=10, statusCode=SUCCESS]

2020-05-27 17:53:01.712 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=86, commandId=11]

2020-05-27 17:53:01.715 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=ED83/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=18, rssi=--, lqi=--, payload=10 56 0B 0A 00]

2020-05-27 17:53:01.717 [DEBUG] [.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee send: XBeeTransmitRequestExplicitCommand [frameId=null, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 56 0B 0A 00]

2020-05-27 17:53:01.720 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeTransmitRequestExplicitCommand [frameId=45, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 56 0B 0A 00]

2020-05-27 17:53:01.723 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeTransmitRequestExplicitCommand [frameId=45, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 56 0B 0A 00]

2020-05-27 17:53:01.730 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 19 11 2D F0 D1 B8 00 00 02 71 52 ED 83 01 01 03 00 01 04 00 00 10 56 0B 0A 00 8E

2020-05-27 17:53:01.855 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 8B 2D ED 83 00 00 00 D7

2020-05-27 17:53:01.857 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeTransmitStatusResponse [frameId=45, networkAddress=60803, transmitRetryCount=0, deliveryStatus=SUCCESS, discoveryStatus=NO_DISCOVERY_OVERHEAD]

2020-05-27 17:53:07.692 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 1B 91 F0 D1 B8 00 00 02 71 52 ED 83 00 00 00 06 00 00 02 05 FD FF 04 01 01 19 00 00 98

2020-05-27 17:53:07.694 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeReceivePacketExplicitEvent [ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=0, destinationEndpoint=0, clusterId=6, profileId=0, receiveOptions=PACKET_BROADCAST, data=05 FD FF 04 01 01 19 00 00]

2020-05-27 17:53:07.697 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=ED83/0, destinationAddress=0000/0, profile=0000, cluster=0006, addressMode=null, radius=0, apsSecurity=false, ackRequest=false, apsCounter=--, rssi=--, lqi=--, payload=05 FD FF 04 01 01 19 00 00]

2020-05-27 17:53:07.700 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: MatchDescriptorRequest [ED83/0 -> 0000/0, cluster=0006, TID=05, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]]

2020-05-27 17:53:07.703 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: MatchDescriptorRequest [ED83/0 -> 0000/0, cluster=0006, TID=05, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]] 

2020-05-27 17:53:07.706 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: MatchDescriptorRequest [ED83/0 -> 0000/0, cluster=0006, TID=05, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]] ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=8168, state=DISPATCHED, sendCnt=1, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=55, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:53:07.710 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: MatchDescriptorRequest [ED83/0 -> 0000/0, cluster=0006, TID=05, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]] ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=6016, state=DISPATCHED, sendCnt=1, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=56, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:53:07.713 [DEBUG] [stems.zigbee.internal.ClusterMatcher] - 51145391B4ED9DF0: ClusterMatcher received request MatchDescriptorRequest [ED83/0 -> 0000/0, cluster=0006, TID=05, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]]

2020-05-27 17:53:07.716 [DEBUG] [stems.zigbee.internal.ClusterMatcher] - 51145391B4ED9DF0: ClusterMatcher sending match MatchDescriptorResponse [null -> ED83/0, cluster=8006, TID=05, status=SUCCESS, nwkAddrOfInterest=0000, matchList=[1]]

2020-05-27 17:53:07.719 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=0, state=WAITING, sendCnt=0, command=MatchDescriptorResponse [0000/0 -> ED83/0, cluster=8006, TID=05, status=SUCCESS, nwkAddrOfInterest=0000, matchList=[1]]]

2020-05-27 17:53:09.546 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=10009, state=FAILED, sendCnt=1, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=55, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:53:09.548 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding

2020-05-27 17:53:09.550 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: transactionComplete FAILED 1

2020-05-27 17:53:09.553 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: Added transaction to queue, len=2, transaction=ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=10015, state=WAITING, sendCnt=1, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=55, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:53:09.555 [DEBUG] [transaction.ZigBeeTransactionManager] - ED83/1: Sending ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=10018, state=WAITING, sendCnt=1, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=55, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:53:09.557 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding

2020-05-27 17:53:09.560 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=55, commandIdentifier=10, statusCode=SUCCESS]

2020-05-27 17:53:09.562 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=85, commandId=11]

2020-05-27 17:53:09.564 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=ED83/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=19, rssi=--, lqi=--, payload=10 55 0B 0A 00]

2020-05-27 17:53:09.567 [DEBUG] [.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee send: XBeeTransmitRequestExplicitCommand [frameId=null, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 55 0B 0A 00]

2020-05-27 17:53:09.569 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeTransmitRequestExplicitCommand [frameId=46, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 55 0B 0A 00]

2020-05-27 17:53:09.572 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeTransmitRequestExplicitCommand [frameId=46, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 55 0B 0A 00]

2020-05-27 17:53:09.579 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 19 11 2E F0 D1 B8 00 00 02 71 52 ED 83 01 01 03 00 01 04 00 00 10 55 0B 0A 00 8E

2020-05-27 17:53:09.719 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 8B 2E ED 83 00 00 00 D6

2020-05-27 17:53:09.721 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeTransmitStatusResponse [frameId=46, networkAddress=60803, transmitRetryCount=0, deliveryStatus=SUCCESS, discoveryStatus=NO_DISCOVERY_OVERHEAD]

2020-05-27 17:53:11.704 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=10010, state=FAILED, sendCnt=1, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=56, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:53:11.706 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding

2020-05-27 17:53:11.708 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: transactionComplete FAILED 1

2020-05-27 17:53:11.711 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: Added transaction to queue, len=2, transaction=ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=10017, state=WAITING, sendCnt=1, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=56, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:53:11.715 [DEBUG] [transaction.ZigBeeTransactionManager] - ED83/1: Sending ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=10021, state=WAITING, sendCnt=1, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=56, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:53:11.716 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding

2020-05-27 17:53:11.720 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=56, commandIdentifier=10, statusCode=SUCCESS]

2020-05-27 17:53:11.722 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=86, commandId=11]

2020-05-27 17:53:11.726 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=ED83/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=1A, rssi=--, lqi=--, payload=10 56 0B 0A 00]

2020-05-27 17:53:11.728 [DEBUG] [.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee send: XBeeTransmitRequestExplicitCommand [frameId=null, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 56 0B 0A 00]

2020-05-27 17:53:11.732 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeTransmitRequestExplicitCommand [frameId=47, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 56 0B 0A 00]

2020-05-27 17:53:11.734 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeTransmitRequestExplicitCommand [frameId=47, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 56 0B 0A 00]

2020-05-27 17:53:11.738 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 19 11 2F F0 D1 B8 00 00 02 71 52 ED 83 01 01 03 00 01 04 00 00 10 56 0B 0A 00 8C

2020-05-27 17:53:11.880 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 8B 2F ED 83 00 00 00 D5

2020-05-27 17:53:11.881 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeTransmitStatusResponse [frameId=47, networkAddress=60803, transmitRetryCount=0, deliveryStatus=SUCCESS, discoveryStatus=NO_DISCOVERY_OVERHEAD]

2020-05-27 17:53:19.560 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=20022, state=FAILED, sendCnt=2, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=55, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:53:19.562 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding

2020-05-27 17:53:19.563 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: transactionComplete FAILED 1

2020-05-27 17:53:19.565 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: transactionComplete exceeded retries 2

2020-05-27 17:53:19.568 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction terminated: ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=20030, state=FAILED, sendCnt=2, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=55, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:53:19.570 [DEBUG] [transaction.ZigBeeTransactionManager] - ED83/0: Sending ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=11852, state=WAITING, sendCnt=0, command=MatchDescriptorResponse [0000/0 -> ED83/0, cluster=8006, TID=05, status=SUCCESS, nwkAddrOfInterest=0000, matchList=[1]]]

2020-05-27 17:53:19.572 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding

2020-05-27 17:53:19.574 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: MatchDescriptorResponse [0000/0 -> ED83/0, cluster=8006, TID=05, status=SUCCESS, nwkAddrOfInterest=0000, matchList=[1]]

2020-05-27 17:53:19.577 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=ED83/0, profile=0000, cluster=8006, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=1B, rssi=--, lqi=--, payload=05 00 00 00 01 01]

2020-05-27 17:53:19.579 [DEBUG] [.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee send: XBeeTransmitRequestExplicitCommand [frameId=null, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=0, destinationEndpoint=0, cluster=32774, profileId=0, broadcastRadius=0, options=[], data=05 00 00 00 01 01]

2020-05-27 17:53:19.582 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeTransmitRequestExplicitCommand [frameId=48, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=0, destinationEndpoint=0, cluster=32774, profileId=0, broadcastRadius=0, options=[], data=05 00 00 00 01 01]

2020-05-27 17:53:19.584 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeTransmitRequestExplicitCommand [frameId=48, ieeeAddress=F0D1B80000027152, networkAddress=60803, sourceEndpoint=0, destinationEndpoint=0, cluster=32774, profileId=0, broadcastRadius=0, options=[], data=05 00 00 00 01 01]

2020-05-27 17:53:19.588 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 1A 11 30 F0 D1 B8 00 00 02 71 52 ED 83 00 00 80 06 00 00 00 00 05 00 00 00 01 01 83

2020-05-27 17:53:19.724 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 8B 30 ED 83 00 00 00 D4

2020-05-27 17:53:19.725 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeTransmitStatusResponse [frameId=48, networkAddress=60803, transmitRetryCount=0, deliveryStatus=SUCCESS, discoveryStatus=NO_DISCOVERY_OVERHEAD]

2020-05-27 17:53:21.720 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=20026, state=FAILED, sendCnt=2, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=56, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:53:21.722 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding

2020-05-27 17:53:21.724 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: transactionComplete FAILED 1

2020-05-27 17:53:21.726 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: transactionComplete exceeded retries 2

2020-05-27 17:53:21.729 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction terminated: ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=20035, state=FAILED, sendCnt=2, command=DefaultResponse [Color Control: 0000/0 -> ED83/1, cluster=0300, TID=56, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-27 17:53:29.575 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=21856, state=FAILED, sendCnt=1, command=MatchDescriptorResponse [0000/0 -> ED83/0, cluster=8006, TID=05, status=SUCCESS, nwkAddrOfInterest=0000, matchList=[1]]]

2020-05-27 17:53:29.577 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding

2020-05-27 17:53:29.579 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: transactionComplete FAILED 0

2020-05-27 17:53:29.581 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - F0D1B80000027152: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=F0D1B80000027152 queueTime=21862, state=WAITING, sendCnt=1, command=MatchDescriptorResponse [0000/0 -> ED83/0, cluster=8006, TID=05, status=SUCCESS, nwkAddrOfInterest=0000, matchList=[1]]]

Thanks - these are useful logs and I can see what the issue is. The problem is that the XBee driver doesn’t support some of the new features from the ZSS ZigBee library and this creates a 10 second delay in some transactions.

I will try and look at this soon.

4 Likes

Cool, thanks for taking a look!