Zigbee Errors

I’m getting a really long latency on all devices most of the time. I’m running latest versions of everything because I only built this a few days ago. I’m using openhabian on a Pi4 with an Xbee stick. Sometimes, the devices take 20 seconds or more to respond. I’ve enabled logging and I’m getting lots of messages, lots of which state “transactioncomplete Failed 1”. I read in one of the many posts that lots of errors can cause delays on other devices as transactions are queued and retried.

I have no idea which bits of information are useful so I’ve just copied a chunk of the log in the hope that someone might spot something:

2020-05-12 00:57:49.686 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00158D000476832A: transactionComplete FAILED 1

2020-05-12 00:57:49.687 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00158D000476832A: transactionComplete exceeded retries 2

2020-05-12 00:57:49.689 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction terminated: ZigBeeTransaction [ieeeAddress=00158D000476832A queueTime=71018, state=FAILED, sendCnt=2, command=DefaultResponse [Color Control: 0000/0 -> 1EF6/1, cluster=0300, TID=12, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-12 00:57:49.691 [DEBUG] [transaction.ZigBeeTransactionManager] - 1EF6/1: Sending ZigBeeTransaction [ieeeAddress=00158D000476832A queueTime=7167, state=WAITING, sendCnt=0, command=QueryNextImageResponse [Ota Upgrade: 0000/0 -> 1EF6/1, cluster=0019, TID=D0, status=NO_IMAGE_AVAILABLE, manufacturerCode=4478, imageType=269, fileVersion=1, imageSize=0]]

2020-05-12 00:57:49.692 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 3 outstanding

2020-05-12 00:57:49.693 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: QueryNextImageResponse [Ota Upgrade: 0000/0 -> 1EF6/1, cluster=0019, TID=D0, status=NO_IMAGE_AVAILABLE, manufacturerCode=4478, imageType=269, fileVersion=1, imageSize=0]

2020-05-12 00:57:49.695 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=208, commandId=2]

2020-05-12 00:57:49.697 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=1EF6/1, profile=0104, cluster=0019, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=8A, rssi=--, lqi=--, payload=19 D0 02 98]

2020-05-12 00:57:49.698 [DEBUG] [.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee send: XBeeTransmitRequestExplicitCommand [frameId=null, ieeeAddress=00158D000476832A, networkAddress=7926, sourceEndpoint=1, destinationEndpoint=1, cluster=25, profileId=260, broadcastRadius=0, options=[], data=19 D0 02 98]

2020-05-12 00:57:49.700 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeTransmitRequestExplicitCommand [frameId=154, ieeeAddress=00158D000476832A, networkAddress=7926, sourceEndpoint=1, destinationEndpoint=1, cluster=25, profileId=260, broadcastRadius=0, options=[], data=19 D0 02 98]

2020-05-12 00:57:49.702 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeTransmitRequestExplicitCommand [frameId=154, ieeeAddress=00158D000476832A, networkAddress=7926, sourceEndpoint=1, destinationEndpoint=1, cluster=25, profileId=260, broadcastRadius=0, options=[], data=19 D0 02 98]

2020-05-12 00:57:49.705 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 18 11 9A 00 15 8D 00 04 76 83 2A 1E F6 01 01 00 19 01 04 00 00 19 D0 02 98 D4

2020-05-12 00:57:49.803 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 8B 9A 1E F6 00 00 00 C6

2020-05-12 00:57:49.804 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeTransmitStatusResponse [frameId=154, networkAddress=7926, transmitRetryCount=0, deliveryStatus=SUCCESS, discoveryStatus=NO_DISCOVERY_OVERHEAD]

2020-05-12 00:57:53.930 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00158D000476832A queueTime=14250, state=FAILED, sendCnt=1, command=DefaultResponse [Color Control: 0000/0 -> 1EF6/1, cluster=0300, TID=BC, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-12 00:57:53.932 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 2 outstanding

2020-05-12 00:57:53.935 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00158D000476832A: transactionComplete FAILED 1

2020-05-12 00:57:53.938 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00158D000476832A: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00158D000476832A queueTime=14258, state=WAITING, sendCnt=1, command=DefaultResponse [Color Control: 0000/0 -> 1EF6/1, cluster=0300, TID=BC, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-12 00:57:55.066 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 0F A1 28 6D 97 00 01 0C 9D 86 79 F4 00 01 24 3A 36

2020-05-12 00:57:55.067 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeRouteRecordEvent [ieeeAddress=286D9700010C9D86, networkAddress=31220, receiveOptions=UNKNOWN, addressList=243A]

2020-05-12 00:57:55.069 [DEBUG] [.zigbee.dongle.xbee.ZigBeeDongleXBee] - Unhandled XBee Frame: XBeeRouteRecordEvent [ieeeAddress=286D9700010C9D86, networkAddress=31220, receiveOptions=UNKNOWN, addressList=243A]

2020-05-12 00:57:55.138 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 1B 91 28 6D 97 00 01 0C 9D 86 79 F4 01 01 05 00 01 04 01 09 28 00 21 00 00 00 00 00 46

2020-05-12 00:57:55.140 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeReceivePacketExplicitEvent [ieeeAddress=286D9700010C9D86, networkAddress=31220, sourceEndpoint=1, destinationEndpoint=1, clusterId=1280, profileId=260, receiveOptions=PACKET_ACKNOWLEDGED, data=09 28 00 21 00 00 00 00 00]

2020-05-12 00:57:55.141 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=79F4/1, destinationAddress=0000/1, profile=0104, cluster=0500, addressMode=null, radius=0, apsSecurity=false, ackRequest=false, apsCounter=--, rssi=--, lqi=--, payload=09 28 00 21 00 00 00 00 00]

2020-05-12 00:57:55.143 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=40, commandId=0]

2020-05-12 00:57:55.145 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ZoneStatusChangeNotificationCommand [IAS Zone: 79F4/1 -> 0000/1, cluster=0500, TID=28, zoneStatus=33, extendedStatus=0, zoneId=0, delay=0]

2020-05-12 00:57:55.146 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ZoneStatusChangeNotificationCommand [IAS Zone: 79F4/1 -> 0000/1, cluster=0500, TID=28, zoneStatus=33, extendedStatus=0, zoneId=0, delay=0] 

2020-05-12 00:57:55.147 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ZoneStatusChangeNotificationCommand [IAS Zone: 79F4/1 -> 0000/1, cluster=0500, TID=28, zoneStatus=33, extendedStatus=0, zoneId=0, delay=0] ZigBeeTransaction [ieeeAddress=286D9700010C9D86 queueTime=29496, state=DISPATCHED, sendCnt=2, command=DefaultResponse [IAS Zone: 0000/0 -> 79F4/1, cluster=0500, TID=25, commandIdentifier=0, statusCode=SUCCESS]]

2020-05-12 00:57:55.149 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ZoneStatusChangeNotificationCommand [IAS Zone: 79F4/1 -> 0000/1, cluster=0500, TID=28, zoneStatus=33, extendedStatus=0, zoneId=0, delay=0] ZigBeeTransaction [ieeeAddress=00158D000476832A queueTime=12625, state=DISPATCHED, sendCnt=1, command=QueryNextImageResponse [Ota Upgrade: 0000/0 -> 1EF6/1, cluster=0019, TID=D0, status=NO_IMAGE_AVAILABLE, manufacturerCode=4478, imageType=269, fileVersion=1, imageSize=0]]

At the moment, I’m toying with moving back to SmartThings :slight_smile: Response times on that were near instantaneous but this is slow to the point that it’s not really viable. I just went to the fridge in the utility room to get milk. There’s a motion sensor in there that on SmartThings would respond as soon as you crossed the threshold. This evening I went in, got the milk from the fridge and was back in the kitchen about 10m away before the light came on.

This topic was automatically closed 41 days after the last reply. New replies are no longer allowed.