tail -f /var/log/openhab/openhab.log /var/log/openhab/events.log 2023-01-20 19:12:52.495 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspChildJoinHandler [networkId=0, index=2, joining=true, childId=B8E7, childEui64=0017880106F5330F, childType=EMBER_SLEEPY_END_DEVICE] 2023-01-20 19:12:52.497 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: nodeStatusUpdate - node status is UNSECURED_JOIN, network address is B8E7. 2023-01-20 19:12:52.501 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: Device status updated. NWK=B8E7 2023-01-20 19:12:52.503 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling stopped 2023-01-20 19:12:52.504 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: NWK Discovery add node B8E7 2023-01-20 19:12:52.506 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling initialised at 1930565ms 2023-01-20 19:12:52.506 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Updating node NWK=B8E7 2023-01-20 19:12:52.508 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspTrustCenterJoinHandler [networkId=0, newNodeId=B8E7, newNodeEui64=0017880106F5330F, status=EMBER_STANDARD_SECURITY_SECURED_REJOIN, policyDecision=EMBER_NO_ACTION, parentOfNewNodeId=0000] 2023-01-20 19:12:52.509 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=B8E7 2023-01-20 19:12:52.511 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: nodeStatusUpdate - node status is SECURED_REJOIN, network address is B8E7. 2023-01-20 19:12:52.513 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 0017880106F5330F: Node state updated FROM OFFLINE TO ONLINE 2023-01-20 19:12:52.513 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling stopped 2023-01-20 19:12:52.515 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: Device status updated. NWK=B8E7 2023-01-20 19:12:52.516 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880106F5330F: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=1, interTransactionDelay=50, maxRetries=2] 2023-01-20 19:12:52.516 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling initialised at 1914459ms 2023-01-20 19:12:52.517 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 0017880106F5330F: Data store: Deferring write for 250ms. 2023-01-20 19:12:52.520 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: NWK Discovery add node B8E7 2023-01-20 19:12:52.521 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - 0017880106F5330F: DISCOVERY Extension: Adding discoverer for node 2023-01-20 19:12:52.522 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Updating node NWK=B8E7 2023-01-20 19:12:52.522 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Node updated - ZigBeeNode [state=ONLINE, IEEE=0017880106F5330F, NWK=B8E7, Type=END_DEVICE, endpoints=[1, 2]] 2023-01-20 19:12:52.525 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=B8E7 2023-01-20 19:12:52.525 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: created discoverer 2023-01-20 19:12:52.528 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: start discovery 2023-01-20 19:12:52.529 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node B8E7 is not updated from ZigBeeNode [state=ONLINE, IEEE=0017880106F5330F, NWK=B8E7, endpoints=[]] 2023-01-20 19:12:52.530 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: starting new tasks [NWK_ADDRESS] 2023-01-20 19:12:52.533 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: scheduled [NWK_ADDRESS] 2023-01-20 19:12:52.769 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 0017880106F5330F: Data store: Writing node. 2023-01-20 19:12:52.829 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0017880106F5330F: ZigBee saving network state complete. 2023-01-20 19:12:53.110 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspChildJoinHandler [networkId=0, index=2, joining=true, childId=B8E7, childEui64=0017880106F5330F, childType=EMBER_SLEEPY_END_DEVICE] 2023-01-20 19:12:53.111 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: nodeStatusUpdate - node status is UNSECURED_JOIN, network address is B8E7. 2023-01-20 19:12:53.112 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: Device status updated. NWK=B8E7 2023-01-20 19:12:53.112 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling stopped 2023-01-20 19:12:53.113 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspTrustCenterJoinHandler [networkId=0, newNodeId=B8E7, newNodeEui64=0017880106F5330F, status=EMBER_STANDARD_SECURITY_UNSECURED_REJOIN, policyDecision=EMBER_USE_PRECONFIGURED_KEY, parentOfNewNodeId=0000] 2023-01-20 19:12:53.114 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: NWK Discovery add node B8E7 2023-01-20 19:12:53.114 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling initialised at 1909282ms 2023-01-20 19:12:53.114 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: nodeStatusUpdate - node status is UNSECURED_REJOIN, network address is B8E7. 2023-01-20 19:12:53.115 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Updating node NWK=B8E7 2023-01-20 19:12:53.115 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: Device status updated. NWK=B8E7 2023-01-20 19:12:53.116 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling stopped 2023-01-20 19:12:53.117 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: NWK Discovery add node B8E7 2023-01-20 19:12:53.117 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=B8E7 2023-01-20 19:12:53.117 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling initialised at 1881647ms 2023-01-20 19:12:53.118 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Updating node NWK=B8E7 2023-01-20 19:12:53.118 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node B8E7 is not updated from ZigBeeNode [state=ONLINE, IEEE=0017880106F5330F, NWK=B8E7, endpoints=[]] 2023-01-20 19:12:53.119 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=B8E7 2023-01-20 19:12:53.120 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node B8E7 is not updated from ZigBeeNode [state=ONLINE, IEEE=0017880106F5330F, NWK=B8E7, endpoints=[]] 2023-01-20 19:12:53.800 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: running NWK_ADDRESS 2023-01-20 19:12:53.802 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880106F5330F: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0017880106F5330F queueTime=1, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> B8E7/0, cluster=0000, TID=--, ieeeAddr=0017880106F5330F, requestType=0, startIndex=0]] 2023-01-20 19:12:53.807 [DEBUG] [transaction.ZigBeeTransactionManager] - B8E7/0: Sending ZigBeeTransaction [ieeeAddress=0017880106F5330F queueTime=5, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> B8E7/0, cluster=0000, TID=76, ieeeAddr=0017880106F5330F, requestType=0, startIndex=0]] 2023-01-20 19:12:53.811 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> B8E7/0, cluster=0000, TID=76, ieeeAddr=0017880106F5330F, requestType=0, startIndex=0] 2023-01-20 19:12:53.871 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressResponse [0000/0 -> 0000/0, cluster=8000, TID=76, status=SUCCESS, ieeeAddrRemoteDev=0017880106F5330F, nwkAddrRemoteDev=B8E7, startIndex=null, nwkAddrAssocDevList=[]] 2023-01-20 19:12:53.873 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: NetworkAddressResponse [0000/0 -> 0000/0, cluster=8000, TID=76, status=SUCCESS, ieeeAddrRemoteDev=0017880106F5330F, nwkAddrRemoteDev=B8E7, startIndex=null, nwkAddrAssocDevList=[]] 2023-01-20 19:12:53.875 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0017880106F5330F queueTime=73, state=COMPLETE, sendCnt=1, command=NetworkAddressRequest [0000/0 -> B8E7/0, cluster=0000, TID=76, ieeeAddr=0017880106F5330F, requestType=0, startIndex=0]] 2023-01-20 19:12:53.875 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: NetworkAddressRequest returned NetworkAddressResponse [0000/0 -> 0000/0, cluster=8000, TID=76, status=SUCCESS, ieeeAddrRemoteDev=0017880106F5330F, nwkAddrRemoteDev=B8E7, startIndex=null, nwkAddrAssocDevList=[]] 2023-01-20 19:12:53.877 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: NetworkAddressRequest confirmed by unicast 2023-01-20 19:12:53.879 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880106F5330F: transactionComplete, state=COMPLETE, outstanding=0 2023-01-20 19:12:53.879 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: request NWK_ADDRESS successful. Advancing to null. 2023-01-20 19:12:53.881 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: complete 2023-01-20 19:12:53.883 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Updating node NWK=B8E7 2023-01-20 19:12:53.885 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=B8E7 2023-01-20 19:12:53.887 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node B8E7 is not updated from ZigBeeNode [state=UNKNOWN, IEEE=0017880106F5330F, NWK=B8E7, endpoints=[]] 2023-01-20 19:13:00.004 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspChildJoinHandler [networkId=0, index=2, joining=false, childId=B8E7, childEui64=0017880106F5330F, childType=EMBER_SLEEPY_END_DEVICE] 2023-01-20 19:13:00.006 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: nodeStatusUpdate - node status is DEVICE_LEFT, network address is B8E7. 2023-01-20 19:13:00.009 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Updating node NWK=NULL 2023-01-20 19:13:00.012 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=NULL 2023-01-20 19:13:00.014 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 0017880106F5330F: Node state updated FROM ONLINE TO OFFLINE 2023-01-20 19:13:00.016 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: stopped 2023-01-20 19:13:00.016 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 0017880106F5330F: Data store: Deferring write for 250ms. 2023-01-20 19:13:00.018 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Node updated - ZigBeeNode [state=OFFLINE, IEEE=0017880106F5330F, NWK=B8E7, Type=END_DEVICE, endpoints=[1, 2]] 2023-01-20 19:13:00.016 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880106F5330F: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=1, interTransactionDelay=50, maxRetries=2] 2023-01-20 19:13:00.017 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling stopped 2023-01-20 19:13:00.023 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling initialised at 1961033ms 2023-01-20 19:13:00.271 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 0017880106F5330F: Data store: Writing node. 2023-01-20 19:13:00.332 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0017880106F5330F: ZigBee saving network state complete. 2023-01-20 19:13:12.162 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspChildJoinHandler [networkId=0, index=2, joining=true, childId=B8E7, childEui64=0017880106F5330F, childType=EMBER_SLEEPY_END_DEVICE] 2023-01-20 19:13:12.164 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: nodeStatusUpdate - node status is UNSECURED_JOIN, network address is B8E7. 2023-01-20 19:13:12.166 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: Device status updated. NWK=B8E7 2023-01-20 19:13:12.167 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling stopped 2023-01-20 19:13:12.167 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspTrustCenterJoinHandler [networkId=0, newNodeId=B8E7, newNodeEui64=0017880106F5330F, status=EMBER_STANDARD_SECURITY_SECURED_REJOIN, policyDecision=EMBER_NO_ACTION, parentOfNewNodeId=0000] 2023-01-20 19:13:12.168 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: NWK Discovery add node B8E7 2023-01-20 19:13:12.169 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling initialised at 1832332ms 2023-01-20 19:13:12.169 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: nodeStatusUpdate - node status is SECURED_REJOIN, network address is B8E7. 2023-01-20 19:13:12.171 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Updating node NWK=B8E7 2023-01-20 19:13:12.172 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: Device status updated. NWK=B8E7 2023-01-20 19:13:12.172 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling stopped 2023-01-20 19:13:12.174 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=B8E7 2023-01-20 19:13:12.174 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling initialised at 1905052ms 2023-01-20 19:13:12.174 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: NWK Discovery add node B8E7 2023-01-20 19:13:12.176 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 0017880106F5330F: Node state updated FROM OFFLINE TO ONLINE 2023-01-20 19:13:12.177 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Updating node NWK=B8E7 2023-01-20 19:13:12.179 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 0017880106F5330F: Data store: Deferring write for 250ms. 2023-01-20 19:13:12.180 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - 0017880106F5330F: DISCOVERY Extension: Adding discoverer for node 2023-01-20 19:13:12.180 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=B8E7 2023-01-20 19:13:12.180 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880106F5330F: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=1, interTransactionDelay=50, maxRetries=2] 2023-01-20 19:13:12.182 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: created discoverer 2023-01-20 19:13:12.183 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node B8E7 is not updated from ZigBeeNode [state=ONLINE, IEEE=0017880106F5330F, NWK=B8E7, endpoints=[]] 2023-01-20 19:13:12.184 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Node updated - ZigBeeNode [state=ONLINE, IEEE=0017880106F5330F, NWK=B8E7, Type=END_DEVICE, endpoints=[1, 2]] 2023-01-20 19:13:12.185 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: start discovery 2023-01-20 19:13:12.187 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: starting new tasks [NWK_ADDRESS] 2023-01-20 19:13:12.189 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: scheduled [NWK_ADDRESS] 2023-01-20 19:13:12.432 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 0017880106F5330F: Data store: Writing node. 2023-01-20 19:13:12.497 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 0017880106F5330F: ZigBee saving network state complete. 2023-01-20 19:13:12.778 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspChildJoinHandler [networkId=0, index=2, joining=true, childId=B8E7, childEui64=0017880106F5330F, childType=EMBER_SLEEPY_END_DEVICE] 2023-01-20 19:13:12.779 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: nodeStatusUpdate - node status is UNSECURED_JOIN, network address is B8E7. 2023-01-20 19:13:12.781 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: Device status updated. NWK=B8E7 2023-01-20 19:13:12.781 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspTrustCenterJoinHandler [networkId=0, newNodeId=B8E7, newNodeEui64=0017880106F5330F, status=EMBER_STANDARD_SECURITY_UNSECURED_REJOIN, policyDecision=EMBER_USE_PRECONFIGURED_KEY, parentOfNewNodeId=0000] 2023-01-20 19:13:12.781 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling stopped 2023-01-20 19:13:12.782 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling initialised at 1941634ms 2023-01-20 19:13:12.782 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: NWK Discovery add node B8E7 2023-01-20 19:13:12.783 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: nodeStatusUpdate - node status is UNSECURED_REJOIN, network address is B8E7. 2023-01-20 19:13:12.784 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Updating node NWK=B8E7 2023-01-20 19:13:12.785 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: Device status updated. NWK=B8E7 2023-01-20 19:13:12.785 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling stopped 2023-01-20 19:13:12.786 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=B8E7 2023-01-20 19:13:12.787 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling initialised at 1879066ms 2023-01-20 19:13:12.786 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: NWK Discovery add node B8E7 2023-01-20 19:13:12.788 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node B8E7 is not updated from ZigBeeNode [state=ONLINE, IEEE=0017880106F5330F, NWK=B8E7, endpoints=[]] 2023-01-20 19:13:12.789 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Updating node NWK=B8E7 2023-01-20 19:13:12.790 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=B8E7 2023-01-20 19:13:12.791 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node B8E7 is not updated from ZigBeeNode [state=ONLINE, IEEE=0017880106F5330F, NWK=B8E7, endpoints=[]] 2023-01-20 19:13:13.753 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: running NWK_ADDRESS 2023-01-20 19:13:13.757 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880106F5330F: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0017880106F5330F queueTime=0, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> B8E7/0, cluster=0000, TID=--, ieeeAddr=0017880106F5330F, requestType=0, startIndex=0]] 2023-01-20 19:13:13.761 [DEBUG] [transaction.ZigBeeTransactionManager] - B8E7/0: Sending ZigBeeTransaction [ieeeAddress=0017880106F5330F queueTime=5, state=WAITING, sendCnt=0, command=NetworkAddressRequest [0000/0 -> B8E7/0, cluster=0000, TID=77, ieeeAddr=0017880106F5330F, requestType=0, startIndex=0]] 2023-01-20 19:13:13.766 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0000/0 -> B8E7/0, cluster=0000, TID=77, ieeeAddr=0017880106F5330F, requestType=0, startIndex=0] 2023-01-20 19:13:13.836 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressResponse [0000/0 -> 0000/0, cluster=8000, TID=77, status=SUCCESS, ieeeAddrRemoteDev=0017880106F5330F, nwkAddrRemoteDev=B8E7, startIndex=null, nwkAddrAssocDevList=[]] 2023-01-20 19:13:13.838 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: NetworkAddressResponse [0000/0 -> 0000/0, cluster=8000, TID=77, status=SUCCESS, ieeeAddrRemoteDev=0017880106F5330F, nwkAddrRemoteDev=B8E7, startIndex=null, nwkAddrAssocDevList=[]] 2023-01-20 19:13:13.841 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0017880106F5330F queueTime=86, state=COMPLETE, sendCnt=1, command=NetworkAddressRequest [0000/0 -> B8E7/0, cluster=0000, TID=77, ieeeAddr=0017880106F5330F, requestType=0, startIndex=0]] 2023-01-20 19:13:13.841 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: NetworkAddressRequest returned NetworkAddressResponse [0000/0 -> 0000/0, cluster=8000, TID=77, status=SUCCESS, ieeeAddrRemoteDev=0017880106F5330F, nwkAddrRemoteDev=B8E7, startIndex=null, nwkAddrAssocDevList=[]] 2023-01-20 19:13:13.843 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: NetworkAddressRequest confirmed by unicast 2023-01-20 19:13:13.844 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880106F5330F: transactionComplete, state=COMPLETE, outstanding=0 2023-01-20 19:13:13.846 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: request NWK_ADDRESS successful. Advancing to null. 2023-01-20 19:13:13.848 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0017880106F5330F: Node SVC Discovery: complete 2023-01-20 19:13:13.849 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Updating node NWK=B8E7 2023-01-20 19:13:13.851 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=B8E7 2023-01-20 19:13:13.853 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node B8E7 is not updated from ZigBeeNode [state=UNKNOWN, IEEE=0017880106F5330F, NWK=B8E7, endpoints=[]] 2023-01-20 19:13:15.570 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspChildJoinHandler [networkId=0, index=2, joining=true, childId=B8E7, childEui64=0017880106F5330F, childType=EMBER_SLEEPY_END_DEVICE] 2023-01-20 19:13:15.573 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: nodeStatusUpdate - node status is UNSECURED_JOIN, network address is B8E7. 2023-01-20 19:13:15.577 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling stopped 2023-01-20 19:13:15.577 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: Device status updated. NWK=B8E7 2023-01-20 19:13:15.579 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: NWK Discovery add node B8E7 2023-01-20 19:13:15.581 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling initialised at 1840125ms 2023-01-20 19:13:15.581 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Updating node NWK=B8E7 2023-01-20 19:13:15.583 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=B8E7 2023-01-20 19:13:15.586 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node B8E7 is not updated from ZigBeeNode [state=ONLINE, IEEE=0017880106F5330F, NWK=B8E7, endpoints=[]] 2023-01-20 19:13:15.586 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspTrustCenterJoinHandler [networkId=0, newNodeId=B8E7, newNodeEui64=0017880106F5330F, status=EMBER_STANDARD_SECURITY_UNSECURED_REJOIN, policyDecision=EMBER_USE_PRECONFIGURED_KEY, parentOfNewNodeId=0000] 2023-01-20 19:13:15.589 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: nodeStatusUpdate - node status is UNSECURED_REJOIN, network address is B8E7. 2023-01-20 19:13:15.592 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: Device status updated. NWK=B8E7 2023-01-20 19:13:15.593 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling stopped 2023-01-20 19:13:15.594 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: NWK Discovery add node B8E7 2023-01-20 19:13:15.596 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Polling initialised at 1820141ms 2023-01-20 19:13:15.596 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Updating node NWK=B8E7 2023-01-20 19:13:15.598 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=B8E7 2023-01-20 19:13:15.600 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node B8E7 is not updated from ZigBeeNode [state=ONLINE, IEEE=0017880106F5330F, NWK=B8E7, endpoints=[]] 2023-01-20 19:13:16.270 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=NULL 2023-01-20 19:13:16.273 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node B8E7 is not updated from ZigBeeNode [state=ONLINE, IEEE=0017880106F5330F, NWK=----, endpoints=[]] 2023-01-20 19:13:16.276 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DeviceAnnounce [B8E7/0 -> 0000/0, cluster=0013, TID=2A, nwkAddrOfInterest=B8E7, ieeeAddr=0017880106F5330F, capability=80] 2023-01-20 19:13:16.278 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DeviceAnnounce [B8E7/0 -> 0000/0, cluster=0013, TID=2A, nwkAddrOfInterest=B8E7, ieeeAddr=0017880106F5330F, capability=80] 2023-01-20 19:13:16.280 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: Device announce received. From B8E7, for B8E7 2023-01-20 19:13:16.282 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: NWK Discovery add node B8E7 2023-01-20 19:13:16.284 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Updating node NWK=B8E7 2023-01-20 19:13:16.286 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=B8E7 2023-01-20 19:13:16.288 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node B8E7 is not updated from ZigBeeNode [state=ONLINE, IEEE=0017880106F5330F, NWK=B8E7, endpoints=[]] 2023-01-20 19:13:17.411 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=NULL 2023-01-20 19:13:17.413 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node B8E7 is not updated from ZigBeeNode [state=ONLINE, IEEE=0017880106F5330F, NWK=----, endpoints=[]] 2023-01-20 19:13:17.415 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DeviceAnnounce [B8E7/0 -> 0000/0, cluster=0013, TID=2B, nwkAddrOfInterest=B8E7, ieeeAddr=0017880106F5330F, capability=80] 2023-01-20 19:13:17.416 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DeviceAnnounce [B8E7/0 -> 0000/0, cluster=0013, TID=2B, nwkAddrOfInterest=B8E7, ieeeAddr=0017880106F5330F, capability=80] 2023-01-20 19:13:17.418 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: Device announce received. From B8E7, for B8E7 2023-01-20 19:13:17.419 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0017880106F5330F: NWK Discovery add node B8E7 2023-01-20 19:13:17.421 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Updating node NWK=B8E7 2023-01-20 19:13:17.422 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=B8E7 2023-01-20 19:13:17.424 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node B8E7 is not updated from ZigBeeNode [state=ONLINE, IEEE=0017880106F5330F, NWK=B8E7, endpoints=[]] 2023-01-20 19:13:22.023 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node update. NWK Address=NULL 2023-01-20 19:13:22.025 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 0017880106F5330F: Node B8E7 is not updated from ZigBeeNode [state=ONLINE, IEEE=0017880106F5330F, NWK=----, endpoints=[]] 2023-01-20 19:13:22.034 [DEBUG] [l.converter.ZigBeeConverterOccupancy] - 0017880106F5330F: ZigBee attribute reports ZclAttribute [cluster=Occupancy Sensing, id=0, name=Occupancy, dataType=BITMAP_8_BIT, lastValue=0, lastReportTime=Fri Jan 20 19:13:22 CET 2023, implemented=false] 2023-01-20 19:13:22.034 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880106F5330F: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=0017880106F5330F queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Occupancy Sensing: 0000/0 -> B8E7/2, cluster=0406, TID=A4, commandIdentifier=10, statusCode=SUCCESS]] 2023-01-20 19:13:22.036 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 0017880106F5330F: Channel zigbee:philips_sml001:9ad428b154:0017880106f5330f:motion updated to OFF 2023-01-20 19:13:22.038 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880106F5330F: Updating ZigBee channel state zigbee:philips_sml001:9ad428b154:0017880106f5330f:motion to OFF 2023-01-20 19:13:22.038 [DEBUG] [transaction.ZigBeeTransactionManager] - B8E7/2: Sending ZigBeeTransaction [ieeeAddress=0017880106F5330F queueTime=4, state=WAITING, sendCnt=0, command=DefaultResponse [Occupancy Sensing: 0000/0 -> B8E7/2, cluster=0406, TID=A4, commandIdentifier=10, statusCode=SUCCESS]] 2023-01-20 19:13:22.040 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:philips_sml001:9ad428b154:0017880106f5330f 2023-01-20 19:13:22.043 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:philips_sml001:9ad428b154:0017880106f5330f 2023-01-20 19:13:22.046 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:philips_sml001:9ad428b154:0017880106f5330f in 1830 seconds 2023-01-20 19:13:22.107 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=0017880106F5330F queueTime=74, state=COMPLETE, sendCnt=1, command=DefaultResponse [Occupancy Sensing: 0000/0 -> B8E7/2, cluster=0406, TID=A4, commandIdentifier=10, statusCode=SUCCESS]] 2023-01-20 19:13:22.111 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 0017880106F5330F: transactionComplete, state=COMPLETE, outstanding=0