Zigbee - Sonoff SNZB - 02 - Discovery cannot be completed - Error: "Node has not completed discovery"

Hello!

  • Platform information:
    • Hardware: RP3
    • OS: Openhabian 3.0.1 Release
    • Java Runtime Environment: openjdk version “11.0.10” 2021-01-19 LTS
      OpenJDK Runtime Environment Zulu11.45+27-CA (build 11.0.10+9-LTS)
      OpenJDK Client VM Zulu11.45+27-CA (build 11.0.10+9-LTS, mixed mode)
    • openHAB version: 3.0.1 - Release Build

Actual results:
The Device appears OFFLINE. It’s not responsive and it’s not sending expected data.
The setup works well with TRADFRI Zigbee bulbs (full discovery and functionality).

The Sensor was discovered well on binding version ~2.5, but not sure since I wasn’t documenting then. (2 weeks ago when the issue started).

Expected Results:
The Device appears ONLINE. Can be linked to Item and sends the expected data.

Repro Steps:

  • From things menu on localhost:8080 start a new discovery
  • Select Zigbee binding
  • Select Scan
  • Reset the device by pressing the button for 5 s - the light flashes 3 times
  • Observe discovery new hit of “Unknown ZigBee Device 00124B00226A3582”
  • Add as a Thing
  • Observe Device status: OFFLINE - Node has not completed discovery

Things I tried:

  • Disabling and Enabling the Device
  • Restarting the Device
  • Removing the Device and discover it again
  • Reinstalling binding
  • Fresh install of OH3

Configuration:

  • cc2531.things:
Thing zigbee:coordinator_cc2531:stick1 "Zigbee USB Stick" [zigbee_port="/dev/ttyACM0", zigbee_baud=57600, zigbee_initialise=true]

Logs:

12:43:26.675 [INFO ] [gbee.discovery.ZigBeeDiscoveryService] - 00124B00226A3582: Starting ZigBee device discovery
12:43:26.678 [DEBUG] [app.discovery.ZigBeeNetworkDiscoverer] - 00124B00226A3582: NWK Discovery add node E9FA
12:43:26.677 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 00124B00226A3582: Node SVC Discovery: start discovery
12:43:26.679 [DEBUG] [gbee.discovery.ZigBeeDiscoveryService] - 00124B00226A3582: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_cc2531:stick1
12:43:26.682 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode  ] - 00124B00226A3582: Node state updated from UNKNOWN to ONLINE
12:43:26.685 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 00124B00226A3582: Node SVC Discovery: starting new tasks [NWK_ADDRESS, NODE_DESCRIPTOR, POWER_DESCRIPTOR, ACTIVE_ENDPOINTS]
12:43:26.689 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 00124B00226A3582: Updating node NWK=E9FA
12:43:26.693 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 00124B00226A3582: Node SVC Discovery: scheduled [NWK_ADDRESS, NODE_DESCRIPTOR, POWER_DESCRIPTOR, ACTIVE_ENDPOINTS]
12:43:26.689 [INFO ] [openhab.event.InboxAddedEvent        ] - Discovery Result with UID 'zigbee:device:stick1:00124b00226a3582' has been added.
12:43:26.695 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 00124B00226A3582: Node update. NWK Address=E9FA
12:43:26.690 [INFO ] [ig.discovery.internal.PersistentInbox] - Added new thing 'zigbee:device:stick1:00124b00226a3582' to inbox.
12:43:26.702 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 00124B00226A3582: Node E9FA is not updated
12:43:26.704 [DEBUG] [gbee.discovery.ZigBeeDiscoveryService] - 00124B00226A3582: Node discovery not complete
12:43:26.811 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 00124B00226A3582: Node SVC Discovery: running NWK_ADDRESS
12:43:26.818 [DEBUG] [.transaction.ZigBeeTransactionManager] - 00124B00226A3582: Creating new Transaction Queue
12:43:26.825 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=1, interTransactionDelay=50, maxRetries=2]
12:43:26.837 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=0, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=--, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:43:26.841 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=2, sleepy=0/3
12:43:26.846 [DEBUG] [.transaction.ZigBeeTransactionManager] - E9FA/0: Sending ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=13, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=96, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:43:26.849 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
12:43:26.854 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=96, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]
12:43:26.859 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=E9FA/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=DF, rssi=--, lqi=--, payload=96 82 35 6A 22 00 4B 12 00 00 00]
12:43:26.863 [DEBUG] [531.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FA E9 00 00 00 00 DF 30 08 0B 96 82 35 6A 22 00 4B 12 00 00 00 FF, checksum=FF, error=false)
12:43:26.898 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
12:43:26.903 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=96 state=TX_ACK
12:43:26.909 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=96, state=TX_ACK, outstanding=1
12:43:26.914 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=E9FA, TID=96, event=TX_ACK, state=TRANSMITTED
12:43:26.923 [DEBUG] [database.ZigBeeNetworkDatabaseManager] - 00124B00226A3582: Data store: Writing node.
12:43:26.941 [DEBUG] [nding.zigbee.internal.ZigBeeDataStore] - 00124B00226A3582: ZigBee saving network state complete.
12:43:27.705 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 FF FA E9 00 00 80 00 96 00 00 84 00 00 00 36)
12:43:27.711 [DEBUG] [531.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 FF, data=FE 0D 45 FF FA E9 00 00 80 00 96 00 00 84 00 00 00 36, checksum=36, error=false
12:43:27.719 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=E9FA/0, destinationAddress=0000/0, profile=0000, cluster=8000, addressMode=null, radius=0, apsSecurity=false, ackRequest=false, apsCounter=--, rssi=--, lqi=--, payload=00 84 00 00 00]
12:43:27.737 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressResponse [E9FA/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]]
12:43:27.741 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: NetworkAddressResponse [E9FA/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]]
12:43:27.744 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-- ZB_FIND_DEVICE_CONFIRM (FE 0B 46 85 01 E9 00 00 80 00 96 00 00 84 00 B2)
12:43:27.748 [DEBUG] [531.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=11, apiId=46 85, data=FE 0B 46 85 01 E9 00 00 80 00 96 00 00 84 00 B2, checksum=B2, error=false
12:43:27.751 [DEBUG] [ee.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x4685
12:43:34.917 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=8083, state=FAILED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=96, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:43:34.923 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
12:43:34.929 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: transactionComplete, state=FAILED, outstanding=0
12:43:34.937 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=8103, state=WAITING, sendCnt=1, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=96, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:43:34.940 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=2, sleepy=0/3
12:43:34.945 [DEBUG] [.transaction.ZigBeeTransactionManager] - E9FA/0: Sending ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=8113, state=WAITING, sendCnt=1, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=96, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:43:34.948 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
12:43:34.952 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=96, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]
12:43:34.956 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=E9FA/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=E0, rssi=--, lqi=--, payload=96 82 35 6A 22 00 4B 12 00 00 00]
12:43:34.960 [DEBUG] [531.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FA E9 00 00 00 00 E0 30 08 0B 96 82 35 6A 22 00 4B 12 00 00 00 C0, checksum=C0, error=false)
12:43:34.987 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
12:43:34.991 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=96 state=TX_ACK
12:43:34.995 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=96, state=TX_ACK, outstanding=1
12:43:34.999 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=E9FA, TID=96, event=TX_ACK, state=TRANSMITTED
12:43:35.293 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 FF FA E9 00 00 80 00 96 00 00 84 00 00 00 36)
12:43:35.298 [DEBUG] [531.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 FF, data=FE 0D 45 FF FA E9 00 00 80 00 96 00 00 84 00 00 00 36, checksum=36, error=false
12:43:35.305 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=E9FA/0, destinationAddress=0000/0, profile=0000, cluster=8000, addressMode=null, radius=0, apsSecurity=false, ackRequest=false, apsCounter=--, rssi=--, lqi=--, payload=00 84 00 00 00]
12:43:35.311 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressResponse [E9FA/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]]
12:43:35.315 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: NetworkAddressResponse [E9FA/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]]
12:43:35.319 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-- ZB_FIND_DEVICE_CONFIRM (FE 0B 46 85 01 E9 00 00 80 00 96 00 00 84 00 B2)
12:43:35.323 [DEBUG] [531.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=11, apiId=46 85, data=FE 0B 46 85 01 E9 00 00 80 00 96 00 00 84 00 B2, checksum=B2, error=false
12:43:35.326 [DEBUG] [ee.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x4685
12:43:43.001 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=16168, state=FAILED, sendCnt=2, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=96, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:43:43.008 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
12:43:43.013 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: transactionComplete, state=FAILED, outstanding=0
12:43:43.019 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: transactionComplete exceeded max retries 2
12:43:43.025 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=16192, state=CANCELLED, sendCnt=2, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=96, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:43:43.028 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 00124B00226A3582: Node SVC Discovery: NetworkAddressRequest returned null
12:43:43.029 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=16197, state=CANCELLED, sendCnt=2, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=96, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:43:43.034 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
12:43:43.037 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
12:43:43.041 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3
12:43:43.044 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3
12:43:43.048 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - Broadcast: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=null queueTime=0, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=--, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:43:43.051 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=2, sleepy=0/3
12:43:43.055 [DEBUG] [.transaction.ZigBeeTransactionManager] - FFFF/0: Sending ZigBeeTransaction [ieeeAddress=null queueTime=6, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=97, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:43:43.058 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
12:43:43.062 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=97, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]
12:43:43.067 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=FFFF/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=E1, rssi=--, lqi=--, payload=97 82 35 6A 22 00 4B 12 00 00 00]
12:43:43.072 [DEBUG] [531.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 E1 30 08 0B 97 82 35 6A 22 00 4B 12 00 00 00 D3, checksum=D3, error=false)
12:43:43.107 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
12:43:43.112 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=97 state=TX_ACK
12:43:43.116 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=97, state=TX_ACK, outstanding=1
12:43:43.121 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=FFFF, TID=97, event=TX_ACK, state=TRANSMITTED
12:43:51.123 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=null queueTime=8073, state=FAILED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=97, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:43:51.128 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
12:43:51.132 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete, state=FAILED, outstanding=0
12:43:51.136 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete exceeded max retries 1
12:43:51.141 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=null queueTime=8092, state=CANCELLED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=97, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:43:51.146 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 00124B00226A3582: Node SVC Discovery: NetworkAddressRequest returned null
12:43:51.146 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=null queueTime=8098, state=CANCELLED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=97, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:43:51.150 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 00124B00226A3582: Node SVC Discovery: NetworkAddressRequest failed after unicast and broadcast
12:43:51.152 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
12:43:51.154 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 00124B00226A3582: Node SVC Discovery: request NWK_ADDRESS failed. Retry 1, wait 2115ms before retry.
12:43:51.156 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
12:43:51.161 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3
12:43:51.164 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3
12:43:53.274 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 00124B00226A3582: Node SVC Discovery: running NWK_ADDRESS
12:43:53.282 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=0, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=--, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:43:53.287 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=2, sleepy=0/3
12:43:53.293 [DEBUG] [.transaction.ZigBeeTransactionManager] - E9FA/0: Sending ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=12, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=98, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:43:53.299 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
12:43:53.303 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=98, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]
12:43:53.308 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=E9FA/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=E2, rssi=--, lqi=--, payload=98 82 35 6A 22 00 4B 12 00 00 00]
12:43:53.312 [DEBUG] [531.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FA E9 00 00 00 00 E2 30 08 0B 98 82 35 6A 22 00 4B 12 00 00 00 CC, checksum=CC, error=false)
12:43:53.339 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
12:43:53.343 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=98 state=TX_ACK
12:43:53.348 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=98, state=TX_ACK, outstanding=1
12:43:53.352 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=E9FA, TID=98, event=TX_ACK, state=TRANSMITTED
12:43:54.085 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 FF FA E9 00 00 80 00 98 00 00 84 00 00 00 38)
12:43:54.090 [DEBUG] [531.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 FF, data=FE 0D 45 FF FA E9 00 00 80 00 98 00 00 84 00 00 00 38, checksum=38, error=false
12:43:54.097 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=E9FA/0, destinationAddress=0000/0, profile=0000, cluster=8000, addressMode=null, radius=0, apsSecurity=false, ackRequest=false, apsCounter=--, rssi=--, lqi=--, payload=00 84 00 00 00]
12:43:54.106 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressResponse [E9FA/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]]
12:43:54.110 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: NetworkAddressResponse [E9FA/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]]
12:43:54.114 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-- ZB_FIND_DEVICE_CONFIRM (FE 0B 46 85 01 E9 00 00 80 00 98 00 00 84 00 BC)
12:43:54.118 [DEBUG] [531.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=11, apiId=46 85, data=FE 0B 46 85 01 E9 00 00 80 00 98 00 00 84 00 BC, checksum=BC, error=false
12:43:54.121 [DEBUG] [ee.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x4685
12:44:01.353 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=8072, state=FAILED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=98, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:01.360 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
12:44:01.364 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: transactionComplete, state=FAILED, outstanding=0
12:44:01.368 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=8087, state=WAITING, sendCnt=1, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=98, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:01.372 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=2, sleepy=0/3
12:44:01.376 [DEBUG] [.transaction.ZigBeeTransactionManager] - E9FA/0: Sending ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=8095, state=WAITING, sendCnt=1, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=98, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:01.379 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
12:44:01.383 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=98, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]
12:44:01.389 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=E9FA/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=E3, rssi=--, lqi=--, payload=98 82 35 6A 22 00 4B 12 00 00 00]
12:44:01.393 [DEBUG] [531.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FA E9 00 00 00 00 E3 30 08 0B 98 82 35 6A 22 00 4B 12 00 00 00 CD, checksum=CD, error=false)
12:44:01.423 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
12:44:01.428 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=98 state=TX_ACK
12:44:01.432 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=98, state=TX_ACK, outstanding=1
12:44:01.437 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=E9FA, TID=98, event=TX_ACK, state=TRANSMITTED
12:44:01.658 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 FF FA E9 00 00 80 00 98 00 00 84 00 00 00 38)
12:44:01.663 [DEBUG] [531.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 FF, data=FE 0D 45 FF FA E9 00 00 80 00 98 00 00 84 00 00 00 38, checksum=38, error=false
12:44:01.669 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=E9FA/0, destinationAddress=0000/0, profile=0000, cluster=8000, addressMode=null, radius=0, apsSecurity=false, ackRequest=false, apsCounter=--, rssi=--, lqi=--, payload=00 84 00 00 00]
12:44:01.674 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressResponse [E9FA/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]]
12:44:01.679 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: NetworkAddressResponse [E9FA/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]]
12:44:01.684 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-- ZB_FIND_DEVICE_CONFIRM (FE 0B 46 85 01 E9 00 00 80 00 98 00 00 84 00 BC)
12:44:01.687 [DEBUG] [531.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=11, apiId=46 85, data=FE 0B 46 85 01 E9 00 00 80 00 98 00 00 84 00 BC, checksum=BC, error=false
12:44:01.691 [DEBUG] [ee.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x4685
12:44:09.438 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=16157, state=FAILED, sendCnt=2, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=98, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:09.444 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
12:44:09.450 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: transactionComplete, state=FAILED, outstanding=0
12:44:09.455 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: transactionComplete exceeded max retries 2
12:44:09.462 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=16181, state=CANCELLED, sendCnt=2, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=98, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:09.466 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 00124B00226A3582: Node SVC Discovery: NetworkAddressRequest returned null
12:44:09.466 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=16185, state=CANCELLED, sendCnt=2, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=98, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:09.471 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
12:44:09.474 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
12:44:09.478 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3
12:44:09.481 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3
12:44:09.485 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - Broadcast: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=null queueTime=0, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=--, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:09.488 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=2, sleepy=0/3
12:44:09.492 [DEBUG] [.transaction.ZigBeeTransactionManager] - FFFF/0: Sending ZigBeeTransaction [ieeeAddress=null queueTime=7, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=99, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:09.495 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
12:44:09.499 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=99, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]
12:44:09.503 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=FFFF/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=E4, rssi=--, lqi=--, payload=99 82 35 6A 22 00 4B 12 00 00 00]
12:44:09.506 [DEBUG] [531.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 E4 30 08 0B 99 82 35 6A 22 00 4B 12 00 00 00 D8, checksum=D8, error=false)
12:44:09.539 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
12:44:09.543 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=99 state=TX_ACK
12:44:09.547 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=99, state=TX_ACK, outstanding=1
12:44:09.552 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=FFFF, TID=99, event=TX_ACK, state=TRANSMITTED
12:44:15.554 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 01 45 CB 00 8F)
12:44:15.559 [DEBUG] [531.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=1, apiId=45 CB, data=FE 01 45 CB 00 8F, checksum=8F, error=false
12:44:15.564 [DEBUG] [ee.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45cb
12:44:17.552 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=null queueTime=8068, state=FAILED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=99, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:17.557 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
12:44:17.565 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete, state=FAILED, outstanding=0
12:44:17.570 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete exceeded max retries 1
12:44:17.575 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=null queueTime=8091, state=CANCELLED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=99, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:17.579 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 00124B00226A3582: Node SVC Discovery: NetworkAddressRequest returned null
12:44:17.580 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=null queueTime=8095, state=CANCELLED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=99, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:17.582 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 00124B00226A3582: Node SVC Discovery: NetworkAddressRequest failed after unicast and broadcast
12:44:17.584 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
12:44:17.586 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 00124B00226A3582: Node SVC Discovery: request NWK_ADDRESS failed. Retry 2, wait 2115ms before retry.
12:44:17.588 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
12:44:17.592 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3
12:44:17.595 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3
12:44:19.511 [INFO ] [openhab.event.InboxRemovedEvent      ] - Discovery Result with UID 'zigbee:device:stick1:00124b00226a3582' has been removed.
12:44:19.528 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:stick1:00124b00226a3582' changed from UNINITIALIZED to INITIALIZING
12:44:19.540 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - 00124B00226A3582: Initializing ZigBee thing handler zigbee:device:stick1:00124b00226a3582
12:44:19.545 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:stick1:00124b00226a3582' changed from INITIALIZING to UNKNOWN
12:44:19.545 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - 00124B00226A3582: Coordinator status changed to ONLINE.
12:44:19.551 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - 00124B00226A3582: Coordinator is ONLINE. Starting device initialisation.
12:44:19.554 [DEBUG] [app.discovery.ZigBeeNetworkDiscoverer] - 00124B00226A3582: NWK Discovery starting node rediscovery
12:44:19.558 [DEBUG] [app.discovery.ZigBeeNetworkDiscoverer] - 00124B00226A3582: NWK Discovery: Rediscovery using unicast to E9FA
12:44:19.562 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=0, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=--, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:19.565 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - 00124B00226A3582: Node has not finished discovery
12:44:19.566 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=2, sleepy=0/3
12:44:19.571 [DEBUG] [.transaction.ZigBeeTransactionManager] - E9FA/0: Sending ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=9, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=9A, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:19.571 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:stick1:00124b00226a3582' changed from UNKNOWN to OFFLINE: Node has not completed discovery
12:44:19.575 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
12:44:19.580 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=9A, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]
12:44:19.584 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=E9FA/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=E5, rssi=--, lqi=--, payload=9A 82 35 6A 22 00 4B 12 00 00 00]
12:44:19.587 [DEBUG] [531.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FA E9 00 00 00 00 E5 30 08 0B 9A 82 35 6A 22 00 4B 12 00 00 00 C9, checksum=C9, error=false)
12:44:19.615 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
12:44:19.619 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=9A state=TX_ACK
12:44:19.625 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=9A, state=TX_ACK, outstanding=1
12:44:19.631 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=E9FA, TID=9A, event=TX_ACK, state=TRANSMITTED
12:44:19.705 [DEBUG] [discovery.ZigBeeNodeServiceDiscoverer] - 00124B00226A3582: Node SVC Discovery: running NWK_ADDRESS
12:44:19.710 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=0, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=--, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:19.714 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=2, sleepy=0/3
12:44:19.944 [INFO ] [openhab.event.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:device:stick1:00124b00226a3582 changed to UNKNOWN.
12:44:20.445 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 FF FA E9 00 00 80 00 9A 00 00 84 00 00 00 3A)
12:44:20.449 [DEBUG] [531.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 FF, data=FE 0D 45 FF FA E9 00 00 80 00 9A 00 00 84 00 00 00 3A, checksum=3A, error=false
12:44:20.458 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=E9FA/0, destinationAddress=0000/0, profile=0000, cluster=8000, addressMode=null, radius=0, apsSecurity=false, ackRequest=false, apsCounter=--, rssi=--, lqi=--, payload=00 84 00 00 00]
12:44:20.463 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressResponse [E9FA/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]]
12:44:20.469 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: NetworkAddressResponse [E9FA/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]]
12:44:20.474 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-- ZB_FIND_DEVICE_CONFIRM (FE 0B 46 85 01 E9 00 00 80 00 9A 00 00 84 00 BE)
12:44:20.477 [DEBUG] [531.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=11, apiId=46 85, data=FE 0B 46 85 01 E9 00 00 80 00 9A 00 00 84 00 BE, checksum=BE, error=false
12:44:20.480 [DEBUG] [ee.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x4685
12:44:27.632 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=8068, state=FAILED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=9A, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:27.637 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
12:44:27.642 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: transactionComplete, state=FAILED, outstanding=0
12:44:27.647 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: Added transaction to queue, len=2, transaction=ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=8084, state=WAITING, sendCnt=1, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=9A, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:27.652 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=2, sleepy=0/3
12:44:27.656 [DEBUG] [.transaction.ZigBeeTransactionManager] - E9FA/0: Sending ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=8093, state=WAITING, sendCnt=1, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=9A, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:27.659 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
12:44:27.663 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=9A, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]
12:44:27.667 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=E9FA/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=E6, rssi=--, lqi=--, payload=9A 82 35 6A 22 00 4B 12 00 00 00]
12:44:27.671 [DEBUG] [531.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FA E9 00 00 00 00 E6 30 08 0B 9A 82 35 6A 22 00 4B 12 00 00 00 CA, checksum=CA, error=false)
12:44:27.699 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
12:44:27.703 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=9A state=TX_ACK
12:44:27.708 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=9A, state=TX_ACK, outstanding=1
12:44:27.713 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=E9FA, TID=9A, event=TX_ACK, state=TRANSMITTED
12:44:35.714 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=16151, state=FAILED, sendCnt=2, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=9A, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:35.719 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
12:44:35.723 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: transactionComplete, state=FAILED, outstanding=0
12:44:35.727 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: transactionComplete exceeded max retries 2
12:44:35.731 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=16169, state=CANCELLED, sendCnt=2, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=9A, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:35.736 [DEBUG] [app.discovery.ZigBeeNetworkDiscoverer] - 00124B00226A3582: NWK Discovery: Rediscovery using broadcast
12:44:35.737 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=16174, state=CANCELLED, sendCnt=2, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=9A, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:35.742 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
12:44:35.745 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
12:44:35.748 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=2, sleepy=0/3
12:44:35.752 [DEBUG] [.transaction.ZigBeeTransactionManager] - E9FA/0: Sending ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=16042, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=9B, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:35.755 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
12:44:35.759 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=9B, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]
12:44:35.763 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=E9FA/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=E7, rssi=--, lqi=--, payload=9B 82 35 6A 22 00 4B 12 00 00 00]
12:44:35.766 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3
12:44:35.767 [DEBUG] [531.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FA E9 00 00 00 00 E7 30 08 0B 9B 82 35 6A 22 00 4B 12 00 00 00 CA, checksum=CA, error=false)
12:44:35.771 [DEBUG] [ee.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=00124B00226A3582, requestType=0, startIndex=0]]
12:44:35.775 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=2, sleepy=0/3
12:44:35.779 [DEBUG] [.transaction.ZigBeeTransactionManager] - FFFD/0: Sending ZigBeeTransaction [ieeeAddress=null queueTime=9, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> FFFD/0, cluster=0000, TID=9C, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:35.782 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding
12:44:35.786 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> FFFD/0, cluster=0000, TID=9C, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]
12:44:35.790 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=FFFD/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=E8, rssi=--, lqi=--, payload=9C 82 35 6A 22 00 4B 12 00 00 00]
12:44:35.798 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
12:44:35.802 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=9B state=TX_ACK
12:44:35.805 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=9B, state=TX_ACK, outstanding=2
12:44:35.809 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=E9FA, TID=9B, event=TX_ACK, state=TRANSMITTED
12:44:35.812 [DEBUG] [531.network.impl.CommandInterfaceImpl] - ->  AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FD FF 00 00 00 00 E8 30 08 0B 9C 82 35 6A 22 00 4B 12 00 00 00 D3, checksum=D3, error=false)
12:44:35.842 [DEBUG] [531.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)
12:44:35.848 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=9C state=TX_ACK
12:44:35.852 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=9C, state=TX_ACK, outstanding=2
12:44:35.861 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=FFFD, TID=9C, event=TX_ACK, state=TRANSMITTED
12:44:43.810 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=24100, state=FAILED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=9B, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:43.817 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding
12:44:43.823 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: transactionComplete, state=FAILED, outstanding=0
12:44:43.829 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 00124B00226A3582: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00124B00226A3582 queueTime=24119, state=WAITING, sendCnt=1, command=NetworkAddressRequest [0000/0 -> E9FA/0, cluster=0000, TID=9B, ieeeAddr=00124B00226A3582, requestType=0, startIndex=0]]
12:44:43.835 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Nex

Have u found a solution for this yet?

I had a similar problem, see [OH3.1.0 M1] Zigbee Device not recognized - Worked with 3.0.1

I gave up, bought a conbee II/ deconz zigbee stick: ConBee II Übersicht and everything worked smooth.

regards

No, this is still reproing for me.

@ChristophM

I ran into the same problem when recently updating to OH3.1.0 RB from OH3.0 with Zigbee binding and cc2531 stick. I have also tried a fresh install of OH.
As there seems to be no solution up to now, I am looking into using either zigbee2mqtt or getting me a Conbee Device. You’ve said

Does it mean it worked smooth by using the deCONZ binding?

Best reagrds

Hello Rainer,

of course there are some minor issues with the deCONZ binding as well. I gess they are mostly on my side.
Overall deCONZ is a very good and stable solution. Every Zigbee device i bought paired and worked without any problems.

regards

If I a device worked with an earlier version, then it is highly likely that it will work with the current version. I’m unable to test with the 2531 though, and if you’re looking for a new stick, I would recommend a new device with the Ember chipset (I think people are having good success with the EleLabs stick).