2019-06-23 22:06:33.159 [hingStatusInfoChangedEvent] - ‘zigbee:xiaomi_lumisensorht:1d153709’ changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2019-06-23 22:06:37.490 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running
2019-06-23 22:06:37.495 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=34, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:06:37.501 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=52, payload=00 9F AD E1 18 00 4B 12 00 00 00]
2019-06-23 22:06:45.494 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=34, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:06:45.501 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null
2019-06-23 22:06:45.503 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 5, wait 9140ms before retry.
2019-06-23 22:06:47.405 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45ca
2019-06-23 22:06:54.645 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running
2019-06-23 22:06:54.647 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=35, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:06:54.650 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=53, payload=00 9F AD E1 18 00 4B 12 00 00 00]
2019-06-23 22:06:59.677 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45cb
2019-06-23 22:07:02.648 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=35, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:07:02.656 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null
2019-06-23 22:07:02.661 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 6, wait 11425ms before retry.
2019-06-23 22:07:04.674 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_cc2531:zigbeestick
2019-06-23 22:07:04.679 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Permit join to 65532/0 for 60 seconds.
2019-06-23 22:07:04.683 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=36, permitDuration=60, tcSignificance=true]
2019-06-23 22:07:04.689 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65532/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=54, payload=00 3C 01]
2019-06-23 22:07:04.824 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=37, permitDuration=60, tcSignificance=true]
2019-06-23 22:07:04.829 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=55, payload=00 3C 01]
2019-06-23 22:07:04.972 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45cb
2019-06-23 22:07:04.980 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45b6
2019-06-23 22:07:04.989 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32822, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00]
2019-06-23 22:07:04.992 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=NULL, status=SUCCESS]
2019-06-23 22:07:08.860 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45ca
2019-06-23 22:07:12.701 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45ca
2019-06-23 22:07:14.090 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running
2019-06-23 22:07:14.094 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=38, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:07:14.098 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=56, payload=00 9F AD E1 18 00 4B 12 00 00 00]
2019-06-23 22:07:22.094 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=38, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:07:22.101 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null
2019-06-23 22:07:22.104 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 7, wait 15995ms before retry.
2019-06-23 22:07:38.101 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running
2019-06-23 22:07:38.104 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=39, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:07:38.107 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=57, payload=00 9F AD E1 18 00 4B 12 00 00 00]
2019-06-23 22:07:46.104 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=39, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:07:46.111 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null
2019-06-23 22:07:46.113 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 8, wait 11425ms before retry.
2019-06-23 22:07:57.542 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running
2019-06-23 22:07:57.547 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=3A, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:07:57.553 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=58, payload=00 9F AD E1 18 00 4B 12 00 00 00]
2019-06-23 22:08:04.970 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45cb
2019-06-23 22:08:05.546 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=3A, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:08:05.552 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null
2019-06-23 22:08:05.555 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 9, wait 9140ms before retry.
2019-06-23 22:08:14.698 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running
2019-06-23 22:08:14.704 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=3B, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:08:14.718 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=59, payload=00 9F AD E1 18 00 4B 12 00 00 00]
2019-06-23 22:08:22.703 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=3B, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:08:22.709 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null
2019-06-23 22:08:22.714 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 10, wait 18280ms before retry.
2019-06-23 22:08:40.997 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running
2019-06-23 22:08:41.001 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=3C, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:08:41.004 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=60, payload=00 9F AD E1 18 00 4B 12 00 00 00]
2019-06-23 22:08:49.002 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=3C, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:08:49.009 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null
2019-06-23 22:08:49.014 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 11, wait 9140ms before retry.
2019-06-23 22:08:58.159 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running
2019-06-23 22:08:58.162 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=3D, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:08:58.165 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=61, payload=00 9F AD E1 18 00 4B 12 00 00 00]
2019-06-23 22:09:06.163 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=3D, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:09:06.173 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null
2019-06-23 22:09:06.178 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 12, wait 29705ms before retry.
2019-06-23 22:09:35.888 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running
2019-06-23 22:09:35.893 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=3E, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:09:35.899 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=62, payload=00 9F AD E1 18 00 4B 12 00 00 00]
2019-06-23 22:09:43.893 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=3E, ieeeAddr=, requestType=0, startIndex=0]
2019-06-23 22:09:43.905 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null
2019-06-23 22:09:43.910 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed after 13 attempts.
2019-06-23 22:09:43.914 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running
2019-06-23 22:09:43.917 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=3F, startIndex=0]
2019-06-23 22:09:43.921 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=63, payload=00 00]
2019-06-23 22:09:44.076 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32817, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 01 00 01 53 76 A0 0B 5F CD 9C 89 8A 73 F8 02 00 8D 15 00 39 84 12 02 01 AA]
2019-06-23 22:09:44.082 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=1, startIndex=0, neighborTableList=[NeighborTable [extendedPanId=899CCD5F0BA07653, extendedAddress=00158D0002F8738A, networkAddress=33849, deviceType=END_DEVICE, rxOnWhenIdle=RX_OFF, relationship=CHILD, permitJoining=UNKNOWN, depth=1, lqi=170]]]
2019-06-23 22:09:44.100 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=3F, startIndex=0]
2019-06-23 22:09:44.111 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32817, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 01 00 01 53 76 A0 0B 5F CD 9C 89 8A 73 F8 02 00 8D 15 00 39 84 12 02 01 AA]
2019-06-23 22:09:44.110 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: ManagementLqiRequest response CommandResult [SUCCESS, ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=1, startIndex=0, neighborTableList=[NeighborTable [extendedPanId=899CCD5F0BA07653, extendedAddress=00158D0002F8738A, networkAddress=33849, deviceType=END_DEVICE, rxOnWhenIdle=RX_OFF, relationship=CHILD, permitJoining=UNKNOWN, depth=1, lqi=170]]]]
2019-06-23 22:09:44.115 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: ManagementLqiRequest complete [1 neighbors]
2019-06-23 22:09:44.118 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=1, startIndex=0, neighborTableList=[NeighborTable [extendedPanId=899CCD5F0BA07653, extendedAddress=00158D0002F8738A, networkAddress=33849, deviceType=END_DEVICE, rxOnWhenIdle=RX_OFF, relationship=CHILD, permitJoining=UNKNOWN, depth=1, lqi=170]]]
2019-06-23 22:09:44.122 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - : Neighbor table updated: [NeighborTable [extendedPanId=899CCD5F0BA07653, extendedAddress=00158D0002F8738A, networkAddress=33849, deviceType=END_DEVICE, rxOnWhenIdle=RX_OFF, relationship=CHILD, permitJoining=UNKNOWN, depth=1, lqi=170]]
2019-06-23 22:09:44.126 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NEIGHBORS successful. Advanced to null.
2019-06-23 22:09:44.131 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running
2019-06-23 22:09:44.135 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: complete
2019-06-23 22:09:44.139 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - : Node 0 update
2019-06-23 22:09:44.143 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state
2019-06-23 22:09:44.164 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2019-06-23 22:09:44.168 [me.event.ThingUpdatedEvent] - Thing ‘zigbee:coordinator_cc2531:zigbeestick’ has been updated.
2019-06-23 22:09:44.195 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.