openhab / org.openhab.binding.zigbee

openHAB binding for ZigBee
Eclipse Public License 2.0
74 stars 112 forks source link

Add support for SONOFF SNZB-02ZigBee Temperature & Humidity Sensor #638

Closed walermanril closed 2 years ago

walermanril commented 3 years ago

as per https://community.openhab.org/t/zigbee-sonoff-snzb-02-discovery-cannot-be-completed-error-node-has-not-completed-discovery/116661 there needs to be some changes to make that switches work with the zigbee binding

cdjackson commented 3 years ago

there needs to be some changes to make that switches work with the zigbee binding

Please clearly define what these changes are, or preferably provide a PR with the changes made. Since you have the device (I assume?) you are in the best position to do this.

pmknowles commented 3 years ago

This is the openhab.log entry when I scan for 1) A SNZB-02 T & H Sensor 2) A SNZB-01 Wireless Switch

2021-04-28 17:24:08.800 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00124B00226924FC: Starting ZigBee device discovery
2021-04-28 17:24:08.804 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zigbee:device:ZigBeeUSB:00124b00226924fc' to inbox.
2021-04-28 17:24:24.385 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00124B00226587F1: Starting ZigBee device discovery
2021-04-28 17:24:24.395 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zigbee:device:ZigBeeUSB:00124b00226587f1' to inbox.

In events.log

2021-04-28 17:24:08.805 [INFO ] [openhab.event.InboxAddedEvent       ] - Discovery Result with UID 'zigbee:device:ZigBeeUSB:00124b00226924fc' has been added.
2021-04-28 17:24:24.396 [INFO ] [openhab.event.InboxAddedEvent       ] - Discovery Result with UID 'zigbee:device:ZigBeeUSB:00124b00226587f1' has been added.
2021-04-28 17:24:58.930 [INFO ] [openhab.event.InboxRemovedEvent     ] - Discovery Result with UID 'zigbee:device:ZigBeeUSB:00124b00226587f1' has been removed.
2021-04-28 17:24:58.933 [INFO ] [openhab.event.InboxRemovedEvent     ] - Discovery Result with UID 'zigbee:device:ZigBeeUSB:00124b00226924fc' has been removed.
2021-04-28 17:24:58.940 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:ZigBeeUSB:00124b00226587f1' changed from UNINITIALIZED to INITIALIZING
2021-04-28 17:24:58.944 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:ZigBeeUSB:00124b00226924fc' changed from UNINITIALIZED to INITIALIZING
2021-04-28 17:24:58.952 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:ZigBeeUSB:00124b00226587f1' changed from INITIALIZING to UNKNOWN
2021-04-28 17:24:58.955 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:ZigBeeUSB:00124b00226924fc' changed from INITIALIZING to UNKNOWN
2021-04-28 17:24:58.967 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:ZigBeeUSB:00124b00226587f1' changed from UNKNOWN to OFFLINE: Node has not completed discovery
2021-04-28 17:24:58.969 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zigbee:device:ZigBeeUSB:00124b00226924fc' changed from UNKNOWN to OFFLINE: Node has not completed discovery
2021-04-28 17:24:59.384 [INFO ] [penhab.event.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:device:ZigBeeUSB:00124b00226587f1 changed to UNKNOWN.
2021-04-28 17:24:59.428 [INFO ] [penhab.event.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:device:ZigBeeUSB:00124b00226924fc changed to UNKNOWN.

In the status screen for the Thing it says OFFLINE and 'Node has not completed discovery'

There are no other log entries. Without some form of error message explaining why it hasn't completed discovery I wouldn't know where to look.

cdjackson commented 3 years ago

It's pretty hard to comment on this log as there's so little information. Please take a look at the binding docs to see how to provide debug logging.

However I suspect one of the following is likely your issue -:

pmknowles commented 3 years ago

Here is the debug log for adding the 2 devices 2021-04-28 22:16:12.914 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_cc2531:ZigBeeUSB 2021-04-28 22:16:12.916 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Permit join to FFFC/0 for 60 seconds. 2021-04-28 22:16:12.917 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=null queueTime=0, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]] 2021-04-28 22:16:12.918 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=2, sleepy=0/3 2021-04-28 22:16:12.919 [DEBUG] [transaction.ZigBeeTransactionManager] - FFFC/0: Sending ZigBeeTransaction [ieeeAddress=null queueTime=2, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=30, permitDuration=60, tcSignificance=true]] 2021-04-28 22:16:12.920 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding 2021-04-28 22:16:12.921 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=30, permitDuration=60, tcSignificance=true] 2021-04-28 22:16:12.922 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=FFFC/0, profile=0000, cluster=0036, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=E6, rssi=--, lqi=--, payload=30 3C 01] 2021-04-28 22:16:12.924 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 FC FF 00 00 36 00 E6 30 08 03 30 3C 01 CD, checksum=CD, error=false) 2021-04-28 22:16:12.924 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00124B001CD406D4: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00124B001CD406D4 queueTime=0, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]] 2021-04-28 22:16:12.925 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=2, sleepy=0/3 2021-04-28 22:16:12.926 [DEBUG] [transaction.ZigBeeTransactionManager] - 0000/0: Sending ZigBeeTransaction [ieeeAddress=00124B001CD406D4 queueTime=2, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=31, permitDuration=60, tcSignificance=true]] 2021-04-28 22:16:12.927 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding 2021-04-28 22:16:12.928 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=31, permitDuration=60, tcSignificance=true] 2021-04-28 22:16:12.929 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=0000/0, profile=0000, cluster=0036, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=E7, rssi=--, lqi=--, payload=31 3C 01] 2021-04-28 22:16:12.938 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2021-04-28 22:16:12.939 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=30 state=TX_ACK 2021-04-28 22:16:12.940 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=30, state=TX_ACK, outstanding=2 2021-04-28 22:16:12.941 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 00 00 00 00 36 00 E7 30 08 03 31 3C 01 CE, checksum=CE, error=false) 2021-04-28 22:16:12.941 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=null queueTime=23, state=COMPLETE, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=30, permitDuration=60, tcSignificance=true]] 2021-04-28 22:16:12.942 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding 2021-04-28 22:16:12.943 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete, state=COMPLETE, outstanding=0 2021-04-28 22:16:12.943 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3 2021-04-28 22:16:12.944 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=FFFC, TID=30, event=TX_ACK, state=COMPLETE 2021-04-28 22:16:12.959 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2021-04-28 22:16:12.960 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 01 45 CB 3C B3) 2021-04-28 22:16:12.960 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=31 state=TX_ACK 2021-04-28 22:16:12.962 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=1, apiId=45 CB, data=FE 01 45 CB 3C B3, checksum=B3, error=false 2021-04-28 22:16:12.963 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45cb 2021-04-28 22:16:12.963 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=31, state=TX_ACK, outstanding=1 2021-04-28 22:16:12.968 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00124B001CD406D4 queueTime=43, state=COMPLETE, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=31, permitDuration=60, tcSignificance=true]] 2021-04-28 22:16:12.969 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding 2021-04-28 22:16:12.969 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00124B001CD406D4: transactionComplete, state=COMPLETE, outstanding=0 2021-04-28 22:16:12.970 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3 2021-04-28 22:16:12.970 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=0000, TID=31, event=TX_ACK, state=COMPLETE 2021-04-28 22:16:12.980 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 03 45 B6 00 00 00 F0) 2021-04-28 22:16:12.981 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=3, apiId=45 B6, data=FE 03 45 B6 00 00 00 F0, checksum=F0, error=false 2021-04-28 22:16:12.982 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45b6 2021-04-28 22:16:12.983 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0A 45 FF 00 00 00 36 80 00 31 00 00 00 37) 2021-04-28 22:16:12.984 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=10, apiId=45 FF, data=FE 0A 45 FF 00 00 00 36 80 00 31 00 00 00 37, checksum=37, error=false 2021-04-28 22:16:12.985 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=0000/0, profile=0000, cluster=8036, addressMode=null, radius=0, apsSecurity=false, ackRequest=false, apsCounter=--, rssi=--, lqi=--, payload=00 00] 2021-04-28 22:16:12.987 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningResponse [0000/0 -> 0000/0, cluster=8036, TID=00, status=SUCCESS] 2021-04-28 22:16:12.988 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningResponse [0000/0 -> 0000/0, cluster=8036, TID=00, status=SUCCESS] 2021-04-28 22:16:24.953 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0C 45 CA AB 52 F1 87 65 22 00 4B 12 00 00 00 12) 2021-04-28 22:16:24.954 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=12, apiId=45 CA, data=FE 0C 45 CA AB 52 F1 87 65 22 00 4B 12 00 00 00 12, checksum=12, error=false 2021-04-28 22:16:24.955 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45ca 2021-04-28 22:16:25.965 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 C1 AB 52 AB 52 F1 87 65 22 00 4B 12 00 80 61) 2021-04-28 22:16:25.966 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 C1, data=FE 0D 45 C1 AB 52 AB 52 F1 87 65 22 00 4B 12 00 80 61, checksum=61, error=false 2021-04-28 22:16:25.967 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=52AB/0, destinationAddress=0000/0, profile=0000, cluster=0013, addressMode=null, radius=0, apsSecurity=false, ackRequest=false, apsCounter=--, rssi=--, lqi=--, payload=52 AB 52 F1 87 65 22 00 4B 12 00 80] 2021-04-28 22:16:25.968 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Incoming message from unknown node 52AB: Notifying announce listeners 2021-04-28 22:16:25.969 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - NWK Discovery for 52AB scheduling node discovery 2021-04-28 22:16:25.970 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DeviceAnnounce [52AB/0 -> 0000/0, cluster=0013, TID=52, nwkAddrOfInterest=52AB, ieeeAddr=00124B00226587F1, capability=80] 2021-04-28 22:16:25.971 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DeviceAnnounce [52AB/0 -> 0000/0, cluster=0013, TID=52, nwkAddrOfInterest=52AB, ieeeAddr=00124B00226587F1, capability=80] 2021-04-28 22:16:25.972 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - NWK Discovery for 52AB starting node discovery 2021-04-28 22:16:25.972 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 00124B00226587F1: Device announce received. From 52AB, for 52AB 2021-04-28 22:16:25.973 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 00124B00226587F1: NWK Discovery add node 52AB 2021-04-28 22:16:25.974 [DEBUG] [transaction.ZigBeeTransactionManager] - Attempt to send command with unknown destination: ZigBeeTransaction [ieeeAddress=null queueTime=-, state=WAITING, sendCnt=0, command=IeeeAddressRequest [0000/0 -> 52AB/0, cluster=0001, TID=--, nwkAddrOfInterest=52AB, requestType=0, startIndex=0]] 2021-04-28 22:16:25.974 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 00124B00226587F1: Node state updated from UNKNOWN to ONLINE 2021-04-28 22:16:25.975 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B00226587F1: Updating node NWK=52AB 2021-04-28 22:16:25.975 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Default: Added transaction to queue, len=9, transaction=ZigBeeTransaction [ieeeAddress=null queueTime=0, state=WAITING, sendCnt=0, command=IeeeAddressRequest [0000/0 -> 52AB/0, cluster=0001, TID=--, nwkAddrOfInterest=52AB, requestType=0, startIndex=0]] 2021-04-28 22:16:25.976 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3 2021-04-28 22:16:25.976 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 00124B00226587F1: Data store: Deferring write for 250ms. 2021-04-28 22:16:25.979 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - 00124B00226587F1: DISCOVERY Extension: Adding discoverer for node 2021-04-28 22:16:25.980 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00226587F1: Node SVC Discovery: created discoverer 2021-04-28 22:16:25.981 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00226587F1: Node SVC Discovery: start discovery 2021-04-28 22:16:25.982 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00226587F1: Node SVC Discovery: starting new tasks [ACTIVE_ENDPOINTS, NWK_ADDRESS, NODE_DESCRIPTOR, POWER_DESCRIPTOR] 2021-04-28 22:16:25.983 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00226587F1: Node SVC Discovery: scheduled [NWK_ADDRESS, POWER_DESCRIPTOR, NODE_DESCRIPTOR, ACTIVE_ENDPOINTS] 2021-04-28 22:16:25.985 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 14 45 FF AB 52 01 13 00 00 00 00 00 AB 52 F1 87 65 22 00 4B 12 00 80 54) 2021-04-28 22:16:25.986 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=20, apiId=45 FF, data=FE 14 45 FF AB 52 01 13 00 00 00 00 00 AB 52 F1 87 65 22 00 4B 12 00 80 54, checksum=54, error=false 2021-04-28 22:16:25.987 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=52AB/0, destinationAddress=0000/0, profile=0000, cluster=0013, addressMode=null, radius=0, apsSecurity=false, ackRequest=false, apsCounter=--, rssi=--, lqi=--, payload=00 AB 52 F1 87 65 22 00 4B 12 00 80] 2021-04-28 22:16:25.989 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DeviceAnnounce [52AB/0 -> 0000/0, cluster=0013, TID=00, nwkAddrOfInterest=52AB, ieeeAddr=00124B00226587F1, capability=80] 2021-04-28 22:16:25.990 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00124B00226587F1: Starting ZigBee device discovery 2021-04-28 22:16:25.995 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 00124B00226587F1: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_cc2531:ZigBeeUSB 2021-04-28 22:16:25.997 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DeviceAnnounce [52AB/0 -> 0000/0, cluster=0013, TID=00, nwkAddrOfInterest=52AB, ieeeAddr=00124B00226587F1, capability=80] 2021-04-28 22:16:25.999 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 00124B00226587F1: Device announce received. From 52AB, for 52AB 2021-04-28 22:16:25.999 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zigbee:device:ZigBeeUSB:00124b00226587f1' to inbox. 2021-04-28 22:16:26.000 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 00124B00226587F1: NWK Discovery add node 52AB 2021-04-28 22:16:26.000 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 00124B00226587F1: Node state updated from UNKNOWN to ONLINE 2021-04-28 22:16:26.001 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 00124B00226587F1: Node discovery not complete 2021-04-28 22:16:26.001 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B00226587F1: Updating node NWK=52AB 2021-04-28 22:16:26.002 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B00226587F1: Node update. NWK Address=52AB 2021-04-28 22:16:26.003 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B00226587F1: Node 52AB is not updated 2021-04-28 22:16:26.228 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 00124B00226587F1: Data store: Writing node. 2021-04-28 22:16:26.259 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 00124B00226587F1: ZigBee saving network state complete. 2021-04-28 22:16:27.065 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00226587F1: Node SVC Discovery: running NWK_ADDRESS 2021-04-28 22:16:27.067 [DEBUG] [transaction.ZigBeeTransactionManager] - 00124B00226587F1: Creating new Transaction Queue 2021-04-28 22:16:27.069 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00124B00226587F1: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=1, interTransactionDelay=50, maxRetries=2] 2021-04-28 22:16:27.071 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00124B00226587F1: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00124B00226587F1 queueTime=1, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> 52AB/0, cluster=0000, TID=--, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0]] 2021-04-28 22:16:27.072 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=2, sleepy=0/3 2021-04-28 22:16:27.073 [DEBUG] [transaction.ZigBeeTransactionManager] - 52AB/0: Sending ZigBeeTransaction [ieeeAddress=00124B00226587F1 queueTime=3, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> 52AB/0, cluster=0000, TID=32, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0]] 2021-04-28 22:16:27.073 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding 2021-04-28 22:16:27.074 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> 52AB/0, cluster=0000, TID=32, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0] 2021-04-28 22:16:27.075 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=52AB/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=E8, rssi=--, lqi=--, payload=32 F1 87 65 22 00 4B 12 00 00 00] 2021-04-28 22:16:27.077 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 AB 52 00 00 00 00 E8 30 08 0B 32 F1 87 65 22 00 4B 12 00 00 00 48, checksum=48, error=false) 2021-04-28 22:16:27.091 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2021-04-28 22:16:27.093 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=32 state=TX_ACK 2021-04-28 22:16:27.094 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=32, state=TX_ACK, outstanding=1 2021-04-28 22:16:27.095 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=52AB, TID=32, event=TX_ACK, state=TRANSMITTED 2021-04-28 22:16:28.046 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 FF AB 52 00 00 80 00 32 00 00 84 00 00 00 78) 2021-04-28 22:16:28.047 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 FF, data=FE 0D 45 FF AB 52 00 00 80 00 32 00 00 84 00 00 00 78, checksum=78, error=false 2021-04-28 22:16:28.049 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=52AB/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] 2021-04-28 22:16:28.051 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressResponse [52AB/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]] 2021-04-28 22:16:28.052 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: NetworkAddressResponse [52AB/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]] 2021-04-28 22:16:28.054 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZB_FIND_DEVICE_CONFIRM (FE 0B 46 85 01 52 00 00 80 00 32 00 00 84 00 AD) 2021-04-28 22:16:28.054 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=11, apiId=46 85, data=FE 0B 46 85 01 52 00 00 80 00 32 00 00 84 00 AD, checksum=AD, error=false 2021-04-28 22:16:28.055 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x4685 2021-04-28 22:16:35.096 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00124B00226587F1 queueTime=8025, state=FAILED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> 52AB/0, cluster=0000, TID=32, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0]] 2021-04-28 22:16:35.097 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding 2021-04-28 22:16:35.098 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00124B00226587F1: transactionComplete, state=FAILED, outstanding=0 2021-04-28 22:16:35.099 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00124B00226587F1: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00124B00226587F1 queueTime=8029, state=WAITING, sendCnt=1, command=NetworkAddressRequest [0000/0 -> 52AB/0, cluster=0000, TID=32, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0]] 2021-04-28 22:16:35.100 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=2, sleepy=0/3 2021-04-28 22:16:35.102 [DEBUG] [transaction.ZigBeeTransactionManager] - 52AB/0: Sending ZigBeeTransaction [ieeeAddress=00124B00226587F1 queueTime=8031, state=WAITING, sendCnt=1, command=NetworkAddressRequest [0000/0 -> 52AB/0, cluster=0000, TID=32, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0]] 2021-04-28 22:16:35.103 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding 2021-04-28 22:16:35.104 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> 52AB/0, cluster=0000, TID=32, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0] 2021-04-28 22:16:35.105 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=52AB/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=E9, rssi=--, lqi=--, payload=32 F1 87 65 22 00 4B 12 00 00 00] 2021-04-28 22:16:35.106 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 AB 52 00 00 00 00 E9 30 08 0B 32 F1 87 65 22 00 4B 12 00 00 00 49, checksum=49, error=false) 2021-04-28 22:16:35.120 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2021-04-28 22:16:35.122 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=32 state=TX_ACK 2021-04-28 22:16:35.123 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=32, state=TX_ACK, outstanding=1 2021-04-28 22:16:35.127 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=52AB, TID=32, event=TX_ACK, state=TRANSMITTED 2021-04-28 22:16:35.620 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 FF AB 52 00 00 80 00 32 00 00 84 00 00 00 78) 2021-04-28 22:16:35.621 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 FF, data=FE 0D 45 FF AB 52 00 00 80 00 32 00 00 84 00 00 00 78, checksum=78, error=false 2021-04-28 22:16:35.623 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=52AB/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] 2021-04-28 22:16:35.625 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressResponse [52AB/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]] 2021-04-28 22:16:35.626 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: NetworkAddressResponse [52AB/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]] 2021-04-28 22:16:35.627 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZB_FIND_DEVICE_CONFIRM (FE 0B 46 85 01 52 00 00 80 00 32 00 00 84 00 AD) 2021-04-28 22:16:35.627 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=11, apiId=46 85, data=FE 0B 46 85 01 52 00 00 80 00 32 00 00 84 00 AD, checksum=AD, error=false 2021-04-28 22:16:35.628 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x4685 2021-04-28 22:16:39.152 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 C9 A1 2A FC 24 69 22 00 4B 12 00 00 00 00 C0) 2021-04-28 22:16:39.153 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 C9, data=FE 0D 45 C9 A1 2A FC 24 69 22 00 4B 12 00 00 00 00 C0, checksum=C0, error=false 2021-04-28 22:16:39.154 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45c9 2021-04-28 22:16:41.571 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0C 45 CA FC A9 FC 24 69 22 00 4B 12 00 00 00 1C) 2021-04-28 22:16:41.572 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=12, apiId=45 CA, data=FE 0C 45 CA FC A9 FC 24 69 22 00 4B 12 00 00 00 1C, checksum=1C, error=false 2021-04-28 22:16:41.573 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45ca 2021-04-28 22:16:42.049 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 C1 FC A9 FC A9 FC 24 69 22 00 4B 12 00 80 C3) 2021-04-28 22:16:42.050 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 C1, data=FE 0D 45 C1 FC A9 FC A9 FC 24 69 22 00 4B 12 00 80 C3, checksum=C3, error=false 2021-04-28 22:16:42.052 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=A9FC/0, destinationAddress=0000/0, profile=0000, cluster=0013, addressMode=null, radius=0, apsSecurity=false, ackRequest=false, apsCounter=--, rssi=--, lqi=--, payload=A9 FC A9 FC 24 69 22 00 4B 12 00 80] 2021-04-28 22:16:42.053 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Incoming message from unknown node A9FC: Notifying announce listeners 2021-04-28 22:16:42.054 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - NWK Discovery for A9FC scheduling node discovery 2021-04-28 22:16:42.055 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DeviceAnnounce [A9FC/0 -> 0000/0, cluster=0013, TID=A9, nwkAddrOfInterest=A9FC, ieeeAddr=00124B00226924FC, capability=80] 2021-04-28 22:16:42.056 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - NWK Discovery for A9FC starting node discovery 2021-04-28 22:16:42.057 [DEBUG] [transaction.ZigBeeTransactionManager] - Attempt to send command with unknown destination: ZigBeeTransaction [ieeeAddress=null queueTime=-, state=WAITING, sendCnt=0, command=IeeeAddressRequest [0000/0 -> A9FC/0, cluster=0001, TID=--, nwkAddrOfInterest=A9FC, requestType=0, startIndex=0]] 2021-04-28 22:16:42.058 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DeviceAnnounce [A9FC/0 -> 0000/0, cluster=0013, TID=A9, nwkAddrOfInterest=A9FC, ieeeAddr=00124B00226924FC, capability=80] 2021-04-28 22:16:42.059 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Default: Added transaction to queue, len=10, transaction=ZigBeeTransaction [ieeeAddress=null queueTime=0, state=WAITING, sendCnt=0, command=IeeeAddressRequest [0000/0 -> A9FC/0, cluster=0001, TID=--, nwkAddrOfInterest=A9FC, requestType=0, startIndex=0]] 2021-04-28 22:16:42.060 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 00124B00226924FC: Device announce received. From A9FC, for A9FC 2021-04-28 22:16:42.060 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3 2021-04-28 22:16:42.061 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 00124B00226924FC: NWK Discovery add node A9FC 2021-04-28 22:16:42.063 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 00124B00226924FC: Node state updated from UNKNOWN to ONLINE 2021-04-28 22:16:42.065 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B00226924FC: Updating node NWK=A9FC 2021-04-28 22:16:42.066 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 00124B00226924FC: Data store: Deferring write for 250ms. 2021-04-28 22:16:42.067 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - 00124B00226924FC: DISCOVERY Extension: Adding discoverer for node 2021-04-28 22:16:42.068 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00226924FC: Node SVC Discovery: created discoverer 2021-04-28 22:16:42.068 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00226924FC: Node SVC Discovery: start discovery 2021-04-28 22:16:42.069 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00226924FC: Node SVC Discovery: starting new tasks [ACTIVE_ENDPOINTS, NWK_ADDRESS, NODE_DESCRIPTOR, POWER_DESCRIPTOR] 2021-04-28 22:16:42.070 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 14 45 FF FC A9 01 13 00 00 00 00 00 FC A9 FC 24 69 22 00 4B 12 00 80 F6) 2021-04-28 22:16:42.070 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00226924FC: Node SVC Discovery: scheduled [NWK_ADDRESS, POWER_DESCRIPTOR, NODE_DESCRIPTOR, ACTIVE_ENDPOINTS] 2021-04-28 22:16:42.071 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=20, apiId=45 FF, data=FE 14 45 FF FC A9 01 13 00 00 00 00 00 FC A9 FC 24 69 22 00 4B 12 00 80 F6, checksum=F6, error=false 2021-04-28 22:16:42.072 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=A9FC/0, destinationAddress=0000/0, profile=0000, cluster=0013, addressMode=null, radius=0, apsSecurity=false, ackRequest=false, apsCounter=--, rssi=--, lqi=--, payload=00 FC A9 FC 24 69 22 00 4B 12 00 80] 2021-04-28 22:16:42.073 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DeviceAnnounce [A9FC/0 -> 0000/0, cluster=0013, TID=00, nwkAddrOfInterest=A9FC, ieeeAddr=00124B00226924FC, capability=80] 2021-04-28 22:16:42.074 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DeviceAnnounce [A9FC/0 -> 0000/0, cluster=0013, TID=00, nwkAddrOfInterest=A9FC, ieeeAddr=00124B00226924FC, capability=80] 2021-04-28 22:16:42.075 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 00124B00226924FC: Device announce received. From A9FC, for A9FC 2021-04-28 22:16:42.077 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 00124B00226924FC: NWK Discovery add node A9FC 2021-04-28 22:16:42.078 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 00124B00226924FC: Node state updated from UNKNOWN to ONLINE 2021-04-28 22:16:42.078 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00124B00226924FC: Starting ZigBee device discovery 2021-04-28 22:16:42.078 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 00124B00226924FC: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_cc2531:ZigBeeUSB 2021-04-28 22:16:42.079 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B00226924FC: Updating node NWK=A9FC 2021-04-28 22:16:42.080 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B00226924FC: Node update. NWK Address=A9FC 2021-04-28 22:16:42.081 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zigbee:device:ZigBeeUSB:00124b00226924fc' to inbox. 2021-04-28 22:16:42.082 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B00226924FC: Node A9FC is not updated 2021-04-28 22:16:42.082 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 00124B00226924FC: Node discovery not complete 2021-04-28 22:16:42.147 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00226924FC: Node SVC Discovery: running NWK_ADDRESS 2021-04-28 22:16:42.149 [DEBUG] [transaction.ZigBeeTransactionManager] - 00124B00226924FC: Creating new Transaction Queue 2021-04-28 22:16:42.151 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00124B00226924FC: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=1, interTransactionDelay=50, maxRetries=2] 2021-04-28 22:16:42.154 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00124B00226924FC: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00124B00226924FC queueTime=0, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> A9FC/0, cluster=0000, TID=--, ieeeAddr=00124B00226924FC, requestType=0, startIndex=0]] 2021-04-28 22:16:42.155 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=2, sleepy=0/3 2021-04-28 22:16:42.157 [DEBUG] [transaction.ZigBeeTransactionManager] - A9FC/0: Sending ZigBeeTransaction [ieeeAddress=00124B00226924FC queueTime=3, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> A9FC/0, cluster=0000, TID=33, ieeeAddr=00124B00226924FC, requestType=0, startIndex=0]] 2021-04-28 22:16:42.158 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding 2021-04-28 22:16:42.160 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> A9FC/0, cluster=0000, TID=33, ieeeAddr=00124B00226924FC, requestType=0, startIndex=0] 2021-04-28 22:16:42.162 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=A9FC/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=EA, rssi=--, lqi=--, payload=33 FC 24 69 22 00 4B 12 00 00 00] 2021-04-28 22:16:42.163 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FC A9 00 00 00 00 EA 30 08 0B 33 FC 24 69 22 00 4B 12 00 00 00 45, checksum=45, error=false) 2021-04-28 22:16:42.177 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2021-04-28 22:16:42.178 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=33 state=TX_ACK 2021-04-28 22:16:42.179 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=33, state=TX_ACK, outstanding=2 2021-04-28 22:16:42.180 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=A9FC, TID=33, event=TX_ACK, state=TRANSMITTED 2021-04-28 22:16:42.318 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 00124B00226924FC: Data store: Writing node. 2021-04-28 22:16:42.334 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 00124B00226924FC: ZigBee saving network state complete. 2021-04-28 22:16:43.109 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 FF FC A9 00 00 80 00 33 00 00 84 00 00 00 D5) 2021-04-28 22:16:43.111 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 FF, data=FE 0D 45 FF FC A9 00 00 80 00 33 00 00 84 00 00 00 D5, checksum=D5, error=false 2021-04-28 22:16:43.112 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=A9FC/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] 2021-04-28 22:16:43.114 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressResponse [A9FC/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]] 2021-04-28 22:16:43.115 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: NetworkAddressResponse [A9FC/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]] 2021-04-28 22:16:43.117 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZB_FIND_DEVICE_CONFIRM (FE 0B 46 85 01 A9 00 00 80 00 33 00 00 84 00 57) 2021-04-28 22:16:43.118 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=11, apiId=46 85, data=FE 0B 46 85 01 A9 00 00 80 00 33 00 00 84 00 57, checksum=57, error=false 2021-04-28 22:16:43.119 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x4685 2021-04-28 22:16:43.127 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00124B00226587F1 queueTime=16057, state=FAILED, sendCnt=2, command=NetworkAddressRequest [0000/0 -> 52AB/0, cluster=0000, TID=32, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0]] 2021-04-28 22:16:43.129 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding 2021-04-28 22:16:43.130 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00124B00226587F1: transactionComplete, state=FAILED, outstanding=0 2021-04-28 22:16:43.130 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00124B00226587F1: transactionComplete exceeded max retries 2 2021-04-28 22:16:43.132 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=00124B00226587F1 queueTime=16061, state=CANCELLED, sendCnt=2, command=NetworkAddressRequest [0000/0 -> 52AB/0, cluster=0000, TID=32, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0]] 2021-04-28 22:16:43.133 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00226587F1: Node SVC Discovery: NetworkAddressRequest returned null 2021-04-28 22:16:43.133 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00124B00226587F1 queueTime=16062, state=CANCELLED, sendCnt=2, command=NetworkAddressRequest [0000/0 -> 52AB/0, cluster=0000, TID=32, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0]] 2021-04-28 22:16:43.134 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding 2021-04-28 22:16:43.135 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00124B00226587F1: transactionComplete but not outstanding, state=CANCELLED, outstanding=0 2021-04-28 22:16:43.137 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3 2021-04-28 22:16:43.138 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=null queueTime=0, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=--, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0]] 2021-04-28 22:16:43.139 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=2, sleepy=0/3 2021-04-28 22:16:43.139 [DEBUG] [transaction.ZigBeeTransactionManager] - FFFF/0: Sending ZigBeeTransaction [ieeeAddress=null queueTime=1, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=34, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0]] 2021-04-28 22:16:43.140 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding 2021-04-28 22:16:43.140 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=34, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0] 2021-04-28 22:16:43.141 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=FFFF/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=EB, rssi=--, lqi=--, payload=34 F1 87 65 22 00 4B 12 00 00 00] 2021-04-28 22:16:43.142 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=2, outstandingQueues=1, sleepy=0/3 2021-04-28 22:16:43.142 [DEBUG] [31.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 EB 30 08 0B 34 F1 87 65 22 00 4B 12 00 00 00 B4, checksum=B4, error=false) 2021-04-28 22:16:43.160 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2021-04-28 22:16:43.161 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=34 state=TX_ACK 2021-04-28 22:16:43.162 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=34, state=TX_ACK, outstanding=2 2021-04-28 22:16:43.174 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=FFFF, TID=34, event=TX_ACK, state=TRANSMITTED 2021-04-28 22:16:50.182 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00124B00226924FC queueTime=8028, state=FAILED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> A9FC/0, cluster=0000, TID=33, ieeeAddr=00124B00226924FC, requestType=0, startIndex=0]] 2021-04-28 22:16:50.183 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding 2021-04-28 22:16:50.184 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00124B00226924FC: transactionComplete, state=FAILED, outstanding=0 2021-04-28 22:16:50.186 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00124B00226924FC: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00124B00226924FC queueTime=8032, state=WAITING, sendCnt=1, command=NetworkAddressRequest [0000/0 -> A9FC/0, cluster=0000, TID=33, ieeeAddr=00124B00226924FC, requestType=0, startIndex=0]] 2021-04-28 22:16:50.187 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=2, sleepy=0/3 2021-04-28 22:16:50.189 [DEBUG] [transaction.ZigBeeTransactionManager] - A9FC/0: Sending ZigBeeTransaction [ieeeAddress=00124B00226924FC queueTime=8035, state=WAITING, sendCnt=1, command=NetworkAddressRequest [0000/0 -> A9FC/0, cluster=0000, TID=33, ieeeAddr=00124B00226924FC, requestType=0, startIndex=0]] 2021-04-28 22:16:50.190 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding 2021-04-28 22:16:50.190 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> A9FC/0, cluster=0000, TID=33, ieeeAddr=00124B00226924FC, requestType=0, startIndex=0] 2021-04-28 22:16:50.191 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=A9FC/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=EC, rssi=--, lqi=--, payload=33 FC 24 69 22 00 4B 12 00 00 00] 2021-04-28 22:16:50.192 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FC A9 00 00 00 00 EC 30 08 0B 33 FC 24 69 22 00 4B 12 00 00 00 43, checksum=43, error=false) 2021-04-28 22:16:50.206 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2021-04-28 22:16:50.208 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=33 state=TX_ACK 2021-04-28 22:16:50.208 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=33, state=TX_ACK, outstanding=2 2021-04-28 22:16:50.213 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=A9FC, TID=33, event=TX_ACK, state=TRANSMITTED 2021-04-28 22:16:50.845 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 FF FC A9 00 00 80 00 33 00 00 84 00 00 00 D5) 2021-04-28 22:16:50.846 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 FF, data=FE 0D 45 FF FC A9 00 00 80 00 33 00 00 84 00 00 00 D5, checksum=D5, error=false 2021-04-28 22:16:50.847 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=A9FC/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] 2021-04-28 22:16:50.849 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressResponse [A9FC/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]] 2021-04-28 22:16:50.850 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: NetworkAddressResponse [A9FC/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]] 2021-04-28 22:16:50.851 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZB_FIND_DEVICE_CONFIRM (FE 0B 46 85 01 A9 00 00 80 00 33 00 00 84 00 57) 2021-04-28 22:16:50.852 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=11, apiId=46 85, data=FE 0B 46 85 01 A9 00 00 80 00 33 00 00 84 00 57, checksum=57, error=false 2021-04-28 22:16:50.852 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x4685 2021-04-28 22:16:51.165 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=null queueTime=8026, state=FAILED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=34, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0]] 2021-04-28 22:16:51.166 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding 2021-04-28 22:16:51.167 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete, state=FAILED, outstanding=0 2021-04-28 22:16:51.168 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete exceeded max retries 1 2021-04-28 22:16:51.169 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=null queueTime=8031, state=CANCELLED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=34, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0]] 2021-04-28 22:16:51.171 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00226587F1: Node SVC Discovery: NetworkAddressRequest returned null 2021-04-28 22:16:51.172 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00226587F1: Node SVC Discovery: NetworkAddressRequest failed after unicast and broadcast 2021-04-28 22:16:51.173 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00226587F1: Node SVC Discovery: request NWK_ADDRESS failed. Retry 1, wait 2321ms before retry. 2021-04-28 22:16:51.174 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=null queueTime=8036, state=CANCELLED, sendCnt=1, command=NetworkAddressRequest [0000/0 -> FFFF/0, cluster=0000, TID=34, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0]] 2021-04-28 22:16:51.175 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding 2021-04-28 22:16:51.176 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete but not outstanding, state=CANCELLED, outstanding=0 2021-04-28 22:16:51.177 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3 2021-04-28 22:16:51.178 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3 2021-04-28 22:16:53.497 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00226587F1: Node SVC Discovery: running NWK_ADDRESS 2021-04-28 22:16:53.499 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00124B00226587F1: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00124B00226587F1 queueTime=0, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> 52AB/0, cluster=0000, TID=--, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0]] 2021-04-28 22:16:53.500 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=2, sleepy=0/3 2021-04-28 22:16:53.502 [DEBUG] [transaction.ZigBeeTransactionManager] - 52AB/0: Sending ZigBeeTransaction [ieeeAddress=00124B00226587F1 queueTime=3, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> 52AB/0, cluster=0000, TID=35, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0]] 2021-04-28 22:16:53.503 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding 2021-04-28 22:16:53.504 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> 52AB/0, cluster=0000, TID=35, ieeeAddr=00124B00226587F1, requestType=0, startIndex=0] 2021-04-28 22:16:53.506 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=52AB/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=ED, rssi=--, lqi=--, payload=35 F1 87 65 22 00 4B 12 00 00 00] 2021-04-28 22:16:53.507 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 AB 52 00 00 00 00 ED 30 08 0B 35 F1 87 65 22 00 4B 12 00 00 00 4A, checksum=4A, error=false) 2021-04-28 22:16:53.521 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2021-04-28 22:16:53.523 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=35 state=TX_ACK 2021-04-28 22:16:53.524 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=35, state=TX_ACK, outstanding=2 2021-04-28 22:16:53.525 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=52AB, TID=35, event=TX_ACK, state=TRANSMITTED 2021-04-28 22:16:54.417 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 FF AB 52 00 00 80 00 35 00 00 84 00 00 00 7F) 2021-04-28 22:16:54.418 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 FF, data=FE 0D 45 FF AB 52 00 00 80 00 35 00 00 84 00 00 00 7F, checksum=7F, error=false 2021-04-28 22:16:54.419 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=52AB/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] 2021-04-28 22:16:54.420 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressResponse [52AB/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]] 2021-04-28 22:16:54.421 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: NetworkAddressResponse [52AB/0 -> 0000/0, cluster=8000, TID=00, status=NOT_SUPPORTED, ieeeAddrRemoteDev=null, nwkAddrRemoteDev=NULL, startIndex=null, nwkAddrAssocDevList=[]] 2021-04-28 22:16:54.425 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZB_FIND_DEVICE_CONFIRM (FE 0B 46 85 01 52 00 00 80 00 35 00 00 84 00 AA) 2021-04-28 22:16:54.426 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=11, apiId=46 85, data=FE 0B 46 85 01 52 00 00 80 00 35 00 00 84 00 AA, checksum=AA, error=false 2021-04-28 22:16:54.426 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x4685

Sent from Mailhttps://go.microsoft.com/fwlink/?LinkId=550986 for Windows 10

From: Chris @.> Sent: 28 April 2021 20:33 To: @.> Cc: @.>; @.> Subject: Re: [openhab/org.openhab.binding.zigbee] Add support for SONOFF SNZB-02ZigBee Temperature & Humidity Sensor (#638)

It's pretty hard to comment on this log as there's so little information. Please take a look at the binding docs to see how to provide debug logging.

However I suspect one of the following is likely your issue -:

- You are receiving this because you commented. Reply to this email directly, view it on GitHubhttps://emea01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fopenhab%2Forg.openhab.binding.zigbee%2Fissues%2F638%23issuecomment-828723529&data=04%7C01%7C%7C7f9cba830ae543e81c6d08d90a7c84c7%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637552352183898072%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C1000&sdata=1AZTPL2bOz9YNw05WQnTwlloLe%2FRUB7gcFEuGCw%2Bpn4%3D&reserved=0, or unsubscribehttps://emea01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fnotifications%2Funsubscribe-auth%2FAI5KPM3MOEOEY7FWFP6IAQTTLBPJBANCNFSM4YCVCSHA&data=04%7C01%7C%7C7f9cba830ae543e81c6d08d90a7c84c7%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637552352183908026%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C1000&sdata=9UOgSie6CWhG3lcOISRc9Y6TPS3iAFBigISonC8KKFU%3D&reserved=0.

cdjackson commented 3 years ago
Endpoint          : 1
Device Profile    : 0x0104, ZIGBEE_HOME_AUTOMATION
Device Type       : 0x0302, TEMPERATURE_SENSOR
Device Version    : 0
Input Clusters    : (Server)
   0000 Basic
     - APS Security disabled
        S       0 r-- UNSIGNED_8_BIT_INTEGER    ZCL Version                               
        S       1 r-- UNSIGNED_8_BIT_INTEGER    Application Version                       
        S       2 r-- UNSIGNED_8_BIT_INTEGER    Stack Version                             
        S       3 r-- UNSIGNED_8_BIT_INTEGER    HW Version                                
        S       4 r-- CHARACTER_STRING          Manufacturer Name                         
        S       5 r-- CHARACTER_STRING          Model Identifier                          
        S       6 r-- CHARACTER_STRING          Date Code                                 
        S       7 r-- ENUMERATION_8_BIT         Power Source                              
        S       8 r-- ENUMERATION_8_BIT         Generic Device Class                      
        S       9 r-- ENUMERATION_8_BIT         Generic Device Type                       
        S      10 r-- CHARACTER_STRING          Product Code                              
        S      11 r-- CHARACTER_STRING          Product URL                               
        S      16 rw- CHARACTER_STRING          Location Description                      
        S      17 rw- ENUMERATION_8_BIT         Physical Environment                      
        S      18 rw- BOOLEAN                   Device Enabled                            
        S      19 rw- BITMAP_8_BIT              Alarm Mask                                
        S      20 rw- BITMAP_8_BIT              Disable Local Config                      
        S   16384 r-- CHARACTER_STRING          SW Build ID                               
   0001 Power Configuration
     - APS Security disabled
        S       0 r-- UNSIGNED_16_BIT_INTEGER   Mains Voltage                             
        S       1 r-- UNSIGNED_16_BIT_INTEGER   Mains Frequency                           
        S      16 rw- BITMAP_8_BIT              Mains Alarm Mask                          
        S      17 rw- UNSIGNED_16_BIT_INTEGER   Mains Voltage Min Threshold               
        S      18 rw- UNSIGNED_16_BIT_INTEGER   Mains Voltage Max Threshold               
        S      19 rw- UNSIGNED_16_BIT_INTEGER   Mains Voltage Dwell Trip Point            
        S      32 r-- UNSIGNED_8_BIT_INTEGER    Battery Voltage                           
        S      33 r-s UNSIGNED_8_BIT_INTEGER    Battery Percentage Remaining              
        S      48 rw- CHARACTER_STRING          Battery Manufacturer                      
        S      49 rw- ENUMERATION_8_BIT         Battery Size                              
        S      50 rw- UNSIGNED_16_BIT_INTEGER   Battery A Hr Rating                       
        S      51 rw- UNSIGNED_8_BIT_INTEGER    Battery Quantity                          
        S      52 rw- UNSIGNED_8_BIT_INTEGER    Battery Rated Voltage                     
        S      53 rw- BITMAP_8_BIT              Battery Alarm Mask                        
        S      54 rw- UNSIGNED_8_BIT_INTEGER    Battery Voltage Min Threshold             
        S      55 rw- UNSIGNED_8_BIT_INTEGER    Battery Voltage Threshold 1               
        S      56 rw- UNSIGNED_8_BIT_INTEGER    Battery Voltage Threshold 2               
        S      57 rw- UNSIGNED_8_BIT_INTEGER    Battery Voltage Threshold 3               
        S      58 rw- UNSIGNED_8_BIT_INTEGER    Battery Percentage Min Threshold          
        S      59 rw- UNSIGNED_8_BIT_INTEGER    Battery Percentage Threshold 1            
        S      60 rw- UNSIGNED_8_BIT_INTEGER    Battery Percentage Threshold 2            
        S      61 rw- UNSIGNED_8_BIT_INTEGER    Battery Percentage Threshold 3            
        S      62 r-- BITMAP_32_BIT             Battery Alarm State                       
   0003 Identify
     - APS Security disabled
        S       0 rw- UNSIGNED_16_BIT_INTEGER   Identify Time                             
   0402 Temperature Measurement
     - APS Security disabled
        S       0 r-s SIGNED_16_BIT_INTEGER     Measured Value                            
        S       1 r-- SIGNED_16_BIT_INTEGER     Min Measured Value                        
        S       2 r-- SIGNED_16_BIT_INTEGER     Max Measured Value                        
        S       3 r-s UNSIGNED_16_BIT_INTEGER   Tolerance                                 
   0405 Relative Humidity Measurement
     - APS Security disabled
        S       0 r-s UNSIGNED_16_BIT_INTEGER   Measured Value                            
        S       1 r-- UNSIGNED_16_BIT_INTEGER   Min Measured Value                        
        S       2 r-- UNSIGNED_16_BIT_INTEGER   Max Measured Value                        
        S       3 r-s UNSIGNED_16_BIT_INTEGER   Tolerance                                 
Output Clusters   : (Client)
   0003 Identify
     - APS Security disabled
joerg1985 commented 3 years ago

I was able to pair it after multiple attemps, but there seens to be more wrong with these sensors or the bindings. After some time (20h - 60h) all of the sensors stop updating values and go offline. After reinitialization of the gateway the sensors are back online, but they will still not update values.

I will try a fresh install, after the debian 11 release and could provide logs, if someone could tell what kind of logs are needed.

cdjackson commented 3 years ago

Probably if it stops receiving data, there will just be nothing in the logs, but please feel free to provide the debug logs and I will take a look.

nailyk-fr commented 3 years ago

I have plenty of those SNZB-02ZigBee devices and they are all working fine. However, they can be very tricky to pair. One of the trick I have is to be super slow and to wait that the name is displayed in the inbox. Might have to redo the pairing process multiples times.

image

However, they are reported as eWeLink TH01 so might not be the exact same model.

FranzSchi commented 2 years ago

Hi,

I can confirm that the device is detected as eWeLink TH01. Just one more small wish on this issue:

22843 593B 00124B00251333B3 END_DEVICE ONLINE 1 ZIGBEE_HOME_AUTOMATION TEMPERATURE_SENSOR eWeLink TH01

The device would also have a cluster for the Battery Lifetime:

0001 Power Configuration

Could you support here and return the battery Level also? Here would be the XML file from OH.

00124B00251333B3.zip

cdjackson commented 2 years ago

The device would also have a cluster for the Battery Lifetime:

I'm not sure what you mean by battery lifetime, but the battery level as a voltage and percentage are already supported in the binding. If the device supports these attributes it should already be supported.

FranzSchi commented 2 years ago

Hi Chris,

yes the device has a Cluster 1 The only problem is it is not bound, but I can bind it manually. Now I have the chicken Egg Problem. If I delete the device it's gone again, so I can never see it in OpenHab. Could It be that this device has a specific configuration missing Cluster 1?

Bildschirmfoto 2022-01-13 um 21 27 39

BR /Franz

FranzSchi commented 2 years ago

Dear valued friends,

and it seems even to report something.

openhab> zigbee nodes | grep 00124B00251333B3 46535 B5C7 00124B00251333B3 END_DEVICE ONLINE 1 ZIGBEE_HOME_AUTOMATION TEMPERATURE_SENSOR eWeLink TH01 openhab> zigbee endpoint 46535/1 IEEE Address : 00124B00251333B3 Network Address : 46535 Endpoint : 1 Device Profile : 0x0104, ZIGBEE_HOME_AUTOMATION Device Type : 0x0302, TEMPERATURE_SENSOR Device Version : 0 Input Clusters : (Server) 0000 Basic

FranzSchi commented 2 years ago

Hi @cdjackson,

I have 2 more questions on that behavior.

  1. What is the criterial for the Binding to create the Binding Table entry? Because that one is missing and even if i create it for the power 0001 Power Configuration cluster the Battery Level does not appear.

  2. I've figured out that the device is reporting every 10 Seconds. If you are not using a gas driven glass melting oven then I guess this is to often. For sure I can adjust it on my own.... for Temperature and Humidity.

zigbee subscribe 19620/1 0x0402 0x0000 120 900 20 zigbee subscribe 19620/1 0x0405 0x0000 120 900 50

But I've wanted to ask you if we could add this into the Binding so that I could edit it in the channel detail settings like shown below.

Thanks a lot /Franz

image

cdjackson commented 2 years ago

The only problem is it is not bound, but I can bind it manually.

It's not about if it has this cluster - the question is what attributes it supports - that is the problem. Binding to the cluster will do nothing in itself. The zigbee binding will try and detect what attributes the device supports, and if it supports the attributes the binding knows, then it will provide the channel.

and it seems even to report something.

I don't know what you're trying to indicate with this dump. This information doesn't mean that the device supports a particular feature - other than the clusters.

What is the criterial for the Binding to create the Binding Table entry? Because that one is missing and even if i create it for the power 0001 Power Configuration cluster the Battery Level does not appear.

So I guess this is my point above - binding is clearly important, but it won't help if the device doesn't support the attribute you want to report.

But I've wanted to ask you if we could add this into the Binding so that I could edit it in the channel detail settings like shown below.

I can look at adding this, but you can also reduce the minimum reporting period if it's reporting too fast. If you want to only report every 60 seconds, then change this in the configuration.

FranzSchi commented 2 years ago

Hi Chris,

thanks so far

I can look at adding this, but you can also reduce the minimum reporting period if it's reporting too fast. If you want to only report every 60 seconds, then change this in the configuration.

Which configuration? If I add it like this: zigbee subscribe 19620/1 0x0402 0x0000 120 900 20 zigbee subscribe 19620/1 0x0405 0x0000 120 900 50 Then it's gone after restart of OpenHab. Is there somewhere a config file?

I guess it would be good in general to have this reporting settings in all Channels (why not)?

So I guess this is my point above - binding is clearly important, but it won't help if the device doesn't support the attribute you want to report.

Could I config this Power behavior also somewhere in a config? What's the meaning of "doesn't support"? The cluster is there, I can read the config, I see that a subscription is there, is it the command attsupported that report the supported? Then I would be confused because it does not return anything for any cluster (see below)

openhab> zigbee attsupported 19620/1 0x0402
> zigbee attsupported 19620/1 0x0405
> zigbee attsupported 19620/1 0x001
Failed to retrieve supported attributes

Failed to retrieve supported attributes

Failed to retrieve supported attributes

openhab>

Also if I take a look to other projects it looks like there is nothing special.

image

Source (Line 105 ff from) https://github.com/Koenkk/zigbee-herdsman-converters/blob/master/devices/sonoff.js

Sorry for my unskilled questions /Franz

cdjackson commented 2 years ago

Then it's gone after restart of OpenHab.

I would need to see a log to find out why the device is being reprogrammed as you state here. The configuration is stored in the DEVICE, not in the binding.

I guess it would be good in general to have this reporting settings in all Channels (why not)?

It should be in most channels, but maybe some are missing. If so, please raise a specific issue for the channel and it can be looked at.

Could I config this Power behavior also somewhere in a config?

You should be able to configure it using the command line if it is using a standard zigbee configuration (ie attributes). I don't really know what is used here.

What's the meaning of "doesn't support"?

Most attributes are optional - a device doesn't have to support them, and if it's not supported by the device then the binding can't do anything.

Also if I take a look to other projects it looks like there is nothing special.

I'm not familiar with this code and do not know what attributes these point to "under the hood" so I think without this information it's impossible to say if this is using standard zigbee functionality (which I guess is what you mean by "nothing special") or if it is using something custom in the other project to support non-standard features. Maybe you already know this? If so, please can we talk about attributes, rather than code from another project that is not really relevant.

FranzSchi commented 2 years ago

Hello @cdjackson,

sorry for the very late reply I was out of order for a few days.

Then it's gone after restart of OpenHab.

I would need to see a log to find out why the device is being reprogrammed as you state here. The configuration is stored in the DEVICE, not in the binding.

I just tried it out by rebooting OH. But was no longer able to reproduce this issue (the reporting remains as it was before) Maybe its related to the fact that I exchanged the Osram Smart Plug+ Plugs that also confused my Motion sensors.

I guess it would be good in general to have this reporting settings in all Channels (why not)?

It should be in most channels, but maybe some are missing. If so, please raise a specific issue for the channel and it can be looked at.

As recommended I created this Ticket: https://github.com/openhab/org.openhab.binding.zigbee/issues/743

I'm not familiar with this code and do not know what attributes these point to "under the hood" so I think without this information it's impossible to say if this is using standard zigbee functionality (which I guess is what you mean by "nothing special") or if it is using something custom in the other project to support non-standard features. Maybe you already know this? If so, please can we talk about attributes, rather than code from another project that is not really relevant.

About the power configuration: So it looks like this: Cluster 0x0001 Attribute: 33

openhab> zigbee endpoint 19620/1 IEEE Address : 00124B00251333B3 Network Address : 19620 Endpoint : 1 Device Profile : 0x0104, ZIGBEE_HOME_AUTOMATION Device Type : 0x0302, TEMPERATURE_SENSOR Device Version : 0 Input Clusters : (Server) 0000 Basic

The attribute is there, as the date shows its frequently updated.

I can read the attribute:

openhab> zigbee read 19620/1 0x0001 33
Reading endpoint 4CA4/1, cluster server cluster Power Configuration (0001), attributes Battery Percentage Remaining
Response for cluster 0x0001
Attribute   33  Battery Percentage Remaining                        UNSIGNED_8_BIT_INTEGER          200

I can bind it to the device. and read it back.

openhab> zigbee bindtable 19620
Binding table for node 19620 [00124B00251333B3]
Src Address          | Dest Address         | Group | Mode    | Cluster
00124B00251333B3/1   | 04CD15FFFEBB3E7B/1   |       | Address | 0405:RELATIVE_HUMIDITY_MEASUREMENT
00124B00251333B3/1   | 04CD15FFFEBB3E7B/1   |       | Address | 0001:POWER_CONFIGURATION
00124B00251333B3/1   | 04CD15FFFEBB3E7B/1   |       | Address | 0402:TEMPERATURE_MEASUREMENT

And this is what I see in the log for the Reporting:

2022-03-12 13:22:35.470 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880102B9F368: transactionComplete, state=COMPLETE, outstanding=0
2022-03-12 13:22:35.473 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=5, outstandingQueues=5, sleepy=2/3
2022-03-12 13:22:35.761 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4CA4/1, destinationAddress=0000/1, profile=0104, cluster=0001, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=38, rssi=-58, lqi=A8, payload=18 48 0A 20 00 20 1E]
2022-03-12 13:22:35.765 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B00251333B3: Node update. NWK Address=4CA4
2022-03-12 13:22:35.768 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B00251333B3: Node 4CA4 is not updated
2022-03-12 13:22:35.770 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=72, commandId=10]
2022-03-12 13:22:35.773 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Power Configuration: 4CA4/1 -> 0000/1, cluster=0001, TID=48, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=32, attributeValue=30]]]
2022-03-12 13:22:35.776 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Power Configuration: 4CA4/1 -> 0000/1, cluster=0001, TID=48, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=32, attributeValue=30]]] 
2022-03-12 13:22:35.951 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4CA4/1, destinationAddress=0000/1, profile=0104, cluster=0001, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=3A, rssi=-58, lqi=A8, payload=18 49 0A 21 00 20 C8]
2022-03-12 13:22:35.955 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B00251333B3: Node update. NWK Address=4CA4
2022-03-12 13:22:35.958 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B00251333B3: Node 4CA4 is not updated
2022-03-12 13:22:35.960 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=73, commandId=10]
2022-03-12 13:22:35.963 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Power Configuration: 4CA4/1 -> 0000/1, cluster=0001, TID=49, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=33, attributeValue=200]]]
2022-03-12 13:22:35.966 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Power Configuration: 4CA4/1 -> 0000/1, cluster=0001, TID=49, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=33, attributeValue=200]]] 
2022-03-12 13:22:38.449 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=FD state=RX_NAK
2022-03-12 13:22:38.452 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=FD, state=RX_NAK, outstanding=5
2022-03-12 13:22:38.455 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=001788010634ABB9 queueTime=8448, state=FAILED, sendCnt=1, command=ManagementBindRequest [0000/0 -> 0DCD/0, cluster=0033, TID=FD, startIndex=0]]
2022-03-12 13:22:38.457 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 4 outstanding

The full log is here: https://drive.google.com/file/d/11g4-O0ZBCjRKC_leHtE0H1KYGyALpKnV/view?usp=sharing

cdjackson commented 2 years ago

The battery percent remaining channel is already supported. If it is not showing in your device, then probably it was not detected during the initialisation of your device. Try reinitialising and keeping the device awake by pressing the button every second or so and it should be detected.

cdjackson commented 2 years ago

About the power configuration: So it looks like this:

Just to note that this printout doesn't show what the device supports - it shows the complete configuration of this cluster in the zigbee standards. What you list here is exactly what I listed earlier in this thread and doesn't show that the device supports any specific attribute.

Clearly attribute 33 is supported though as you see the reports. As above, it is therefore likely an issue with initialisation.

FranzSchi commented 2 years ago

Hi @cdjackson,

very good that we are clear with the meaning of supporting now.

Just to note that this printout doesn't show what the device supports - it shows the complete configuration of this cluster in the ZigBee standards. It thought by printing a date and a value close to the attribute means that the value could be read and is therefore supported. Is there any difference?

Try reinitialising and keeping the device awake by pressing the button every second or so and it should be detected.

What I tried is to use the "reinitialize device" slider and press every second the button -> did not succeed Next I tried to remove the device and added it again while pressing the button every second -> unlucky also not.

Here is what the log of that procedure. I wonder why it might not appear Cluster 0001 is very often mentioned. openhab.zip

@nailyk-fr: I've seen you've added the sensor to the list of supported devices here: https://github.com/openhab/org.openhab.binding.zigbee/pull/742/commits/3d90740b30714a15ed5da18c5cead4acffc1f42c can you see the Battery Remaining Channel in OpenHab?

BR /Franz

cdjackson commented 2 years ago

I've simplified the way the converter detects the channel - this might solve the problem as the device doesn't support some of the standard zigbee commands used to detect what attributes it supports.

FranzSchi commented 2 years ago

Hello @cdjackson ,

I've just installed the Snapshot bundle:update -r org.openhab.binding.zigbee https://openhab.jfrog.io/artifactory/libs-snapshot-local/org/openhab/addons/bundles/org.openhab.binding.zigbee/3.3.0-SNAPSHOT/org.openhab.binding.zigbee-3.3.0-20220318.033610-15.jar

I can confirm that the Battery Channel is now visible and returns a value.

image

The bindtable contains the POWER_CONFIGURATION cluster.

openhab> zigbee bindtable 00124B0025128716
Binding table for node 22338 [00124B0025128716]
Src Address          | Dest Address         | Group | Mode    | Cluster
00124B0025128716/1   | 04CD15FFFEBB3E7B/1   |       | Address | 0001:POWER_CONFIGURATION
00124B0025128716/1   | 04CD15FFFEBB3E7B/1   |       | Address | 0405:RELATIVE_HUMIDITY_MEASUREMENT
00124B0025128716/1   | 04CD15FFFEBB3E7B/1   |       | Address | 0402:TEMPERATURE_MEASUREMENT

Good Job Chris! Thank you so much and have a great weekend!

/Franz

daccy2001 commented 2 years ago

I've been watching this issue for a while before deciding to buy this Sonoff sensor... so a big thanks to Chris from me, too, for improving support for this sensor, and to Franz and others for collecting all the debug info. I can also report that the Battery Level works with the current snapshot.

I'm also keen to understand more about if/how the reporting interval can be configured (nicely via the gui would be great... but I'm learning more about what I can do via the console all the time). I've only had this sensor for a couple of days, so I've no idea if changing the reporting rate will make the battery last substantially longer (so no idea if this is really a big deal), but the updates do seem to be far more frequent than I need them!

//Andrew

cdjackson commented 2 years ago

You shouldn't need to play around too much with the reporting. Reporting is not done on time (it is, but it's relatively long) - it's done on change.

The binding sets temperatures to report every 0.1 degree of change - if the temperature doesn't change very fast, then the binding sets the device to report once every 2 hours - just so that it knows it's still alive and ONLINE.

I might look to make this configurable, but for me the battery on these small devices lasts a long time (I've had a similar one running for 18 months and it's still going strong).

FranzSchi commented 2 years ago

Hi @daccy2001 ,

thanks for your feedback. I've already created an Issue here to set the Reporting in the GUI. https://github.com/openhab/org.openhab.binding.zigbee/issues/743 It's also interesting for other devices like my smart plugs with Metering because then I would be able to poll them from the Plugin and not from the console.

@cdjackson, yes the Sensor supports the "On Changed Value" The problem is more the 1 for Min reporting because the Sensor reports by default every 10 seconds.

attribute.setReporting(1, REPORTING_PERIOD_DEFAULT_MAX, 0.1).get();

I'm also not sure about 0.1 as changed value, If I modify the reporting on the console I use (10) because the value is stored in a 4 Digit format. like 2514 means 25.14 ° zigbee subscribe 19620/1 0x0402 0x0000 120 900 10

            if (bindResponse.isSuccess()) {
                // Configure reporting
                ZclAttribute attribute = serverCluster
                        .getAttribute(ZclTemperatureMeasurementCluster.ATTR_MEASUREDVALUE);
                CommandResult reportingResponse = attribute.setReporting(1, REPORTING_PERIOD_DEFAULT_MAX, 0.1).get();
                handleReportingResponse(reportingResponse, POLLING_PERIOD_DEFAULT, REPORTING_PERIOD_DEFAULT_MAX);
            } else {

Have a good Sunday /Franz

cdjackson commented 2 years ago

The problem is more the 1 for Min reporting because the Sensor reports by default every 10 seconds.

I don't understand what you mean here? If the sensor always reports every 10 seconds, then that's not something that I can influence in the binding if it will always report at 10 seconds (is that what you mean?). The binding sets the reporting to a value between 1 second and 2 hours - if the data is changing quickly, then it will report as fast as 1 second - if the data is not changing quickly, then it will report every 2 hours. I don't set anything to 10 seconds.

I'm also not sure about 0.1 as changed value, If I modify the reporting on the console I use (10) because the value is stored in a 4 Digit format. like 2514 means 25.14 °

Hmmm - now this is a very (very!) good point. I'm of course aware that the temperature is presented with a calibration that is " / 100", but mistakes happen and I think that you are correct here that this should be 10. This may be the root cause of your issue with the 10 second reporting.

Have a good Sunday

Sadly it's Monday already here.

FranzSchi commented 2 years ago

Hello fellows,

@cdjackson: I'm not sure about Monday / Sunday. Are you located now in NZ or in the UK? Because Github Still sails UK but Monday is Sunday would also point to NZ.

testing Time :-) IMG_1119-min

4 Brand new Sensors.

Updated the Plugin: bundle:update -r org.openhab.binding.zigbee https://openhab.jfrog.io/artifactory/libs-snapshot-local/org/openhab/addons/bundles/org.openhab.binding.zigbee/3.3.0-SNAPSHOT/org.openhab.binding.zigbee-3.3.0-20220402.033612-17.jar

Checked the Configuration ....

openhab> zigbee reportcfg 30810/1 0x0402 0
Cluster 1026, Attribute 0, type SIGNED_16_BIT_INTEGER, minimum reporting interval: 1, maximum reporting interval: 7200, timeout: 0

openhab> zigbee reportcfg 30810/1 0x0405 0
Cluster 1029, Attribute 0, type UNSIGNED_16_BIT_INTEGER, minimum reporting interval: 1, maximum reporting interval: 7200, timeout: 0

And the result is much better:

image

THX to all contributors and have a nice Weekend

/Franz

cdjackson commented 2 years ago

Are you located now in NZ or in the UK?

I'm in New Zealand - we moved here about a year ago now :)

I'm pleased it's all working well. Shall we close this issue or is there still something that's not quite right?

openhab-bot commented 2 years ago

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/zigbee-popp-z701721-thermostatic-radiator-valve-trv-exposing-all-available-items/135370/2