2019-12-02 23:51:07.560 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 7CB03EAA0A002E4F: Discovery: Starting discovery for existing device
2019-12-02 23:51:07.561 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_ember:cc9950e6
2019-12-02 23:51:07.562 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Permit join to 65532/0 for 60 seconds.
2019-12-02 23:51:07.563 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=59, permitDuration=60, tcSignificance=true]
2019-12-02 23:51:07.564 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65532/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=89, payload=00 3C 01]
2019-12-02 23:51:07.565 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendBroadcastRequest [destination=65532, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=89], radius=31, messageTag=89, messageContents=00 3C 01]
2019-12-02 23:51:07.572 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 7CB03EAA0A002E4F: Starting ZigBee device discovery
2019-12-02 23:51:07.573 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 7CB03EAA0A002E4F: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:cc9950e6
2019-12-02 23:51:07.573 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=5A, permitDuration=60, tcSignificance=true]
2019-12-02 23:51:07.575 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 7CB03EAA0A002E4F: ZigBee node property discovery start
2019-12-02 23:51:07.575 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=90, payload=00 3C 01]
2019-12-02 23:51:07.575 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 7CB03EAA0A002E4F: ZigBee node property discovery using 14815/3
2019-12-02 23:51:07.576 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 7CB03EAA0A002E4F: ZigBee node property discovery complete: {zigbee_logicaltype=ROUTER, zigbee_powerlevel=FULL, modelId=Plug 01, zigbee_networkaddress=14815, zigbee_powersource=MAINS, zigbee_stkversion=2, zigbee_datecode=20140331DEOS****, zigbee_zclversion=1, vendor=OSRAM, zigbee_powermode=RECEIVER_ON_IDLE, zigbee_powersources=[MAINS, DISPOSABLE_BATTERY, RECHARGABLE_BATTERY], hardwareVersion=1, firmwareVersion=01020412}
2019-12-02 23:51:07.576 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=90], messageTag=90, messageContents=00 3C 01]
2019-12-02 23:51:07.577 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 7CB03EAA0A002E4F: Update ZigBee device zigbee:device with bridge zigbee:coordinator_ember:cc9950e6, label 'OSRAM Plug 01'
2019-12-02 23:51:07.587 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2019-12-02 23:51:07.620 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2019-12-02 23:51:07.685 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendBroadcastResponse [status=EMBER_SUCCESS, sequence=59]
2019-12-02 23:51:07.685 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendBroadcastResponse [status=EMBER_SUCCESS, sequence=59]
2019-12-02 23:51:07.694 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST_LOOPBACK, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=59], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 3C 01]
2019-12-02 23:51:07.695 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=null, radius=0, apsSecurity=false, apsCounter=59, payload=00 3C 01]
2019-12-02 23:51:07.696 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=NULL, permitDuration=60, tcSignificance=true]
2019-12-02 23:51:07.919 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=60]
2019-12-02 23:51:07.919 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=60]
2019-12-02 23:51:07.922 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=60], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 3C 01]
2019-12-02 23:51:07.922 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=null, radius=0, apsSecurity=false, apsCounter=60, payload=00 3C 01]
2019-12-02 23:51:07.923 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=NULL, permitDuration=60, tcSignificance=true]
2019-12-02 23:51:07.925 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32822, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=61], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]
2019-12-02 23:51:07.926 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32822, addressMode=null, radius=0, apsSecurity=false, apsCounter=61, payload=00 00]
2019-12-02 23:51:07.927 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=NULL, status=SUCCESS]
2019-12-02 23:51:07.929 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=60], messageTag=90, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:07.929 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=60], messageTag=90, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:08.701 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_BROADCAST, indexOrDestination=65532, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=59], messageTag=89, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:08.702 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_BROADCAST, indexOrDestination=65532, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=59], messageTag=89, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:10.669 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=57], messageTag=87, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:51:10.670 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=57], messageTag=87, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:51:11.200 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=58], messageTag=88, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:51:11.201 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=58], messageTag=88, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:51:13.861 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 14815/0, cluster=0031, TID=57, startIndex=0]
2019-12-02 23:51:13.861 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT]
2019-12-02 23:51:13.862 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: request NEIGHBORS failed. Retry 12, wait 14700ms before retry.
2019-12-02 23:51:14.076 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ReadAttributesCommand [On/Off: 0/0 -> 14815/3, cluster=0006, TID=58, identifiers=[0]]
2019-12-02 23:51:14.077 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Polling zigbee:device:cc9950e6:7cb03eaa0a002e4f:7CB03EAA0A002E4F_3_activepower
2019-12-02 23:51:14.078 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=ELECTRICAL_MEASUREMENT, id=772, name=TotalActivePower, dataType=SIGNED_32_BIT_INTEGER, lastValue=null]
2019-12-02 23:51:14.078 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Electrical Measurement: 0/0 -> 14815/3, cluster=0B04, TID=5B, identifiers=[772]]
2019-12-02 23:51:14.079 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=91, commandId=0]
2019-12-02 23:51:14.079 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=14815/3, profile=0104, cluster=2820, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=91, payload=00 5B 00 04 03]
2019-12-02 23:51:14.080 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=91], messageTag=91, messageContents=00 5B 00 04 03]
2019-12-02 23:51:14.297 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=62]
2019-12-02 23:51:14.297 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=62]
2019-12-02 23:51:18.889 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=62], messageTag=91, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:51:18.890 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=62], messageTag=91, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:51:22.079 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ReadAttributesCommand [Electrical Measurement: 0/0 -> 14815/3, cluster=0B04, TID=5B, identifiers=[772]]
2019-12-02 23:51:28.562 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: running
2019-12-02 23:51:28.563 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 14815/0, cluster=0031, TID=5C, startIndex=0]
2019-12-02 23:51:28.563 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=14815/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=92, payload=00 00]
2019-12-02 23:51:28.564 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=92], messageTag=92, messageContents=00 00]
2019-12-02 23:51:28.778 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=63]
2019-12-02 23:51:28.778 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=63]
2019-12-02 23:51:33.372 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=63], messageTag=92, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:51:33.373 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=63], messageTag=92, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:51:33.930 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspChildJoinHandler [index=0, joining=true, childId=39956, childEui64=00158D0001FF8F6A, childType=EMBER_SLEEPY_END_DEVICE]
2019-12-02 23:51:33.931 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00158D0001FF8F6A: nodeStatusUpdate - node status is UNSECURED_JOIN, network address is 39956.
2019-12-02 23:51:33.932 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 00158D0001FF8F6A: Device status updated. NWK=39956
2019-12-02 23:51:33.933 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00158D0001FF8F6A: Node 39956 added to the network
2019-12-02 23:51:33.934 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for 00158D0001FF8F6A
2019-12-02 23:51:33.935 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: start discovery
2019-12-02 23:51:33.936 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: scheduled [NODE_DESCRIPTOR, NWK_ADDRESS, POWER_DESCRIPTOR, ACTIVE_ENDPOINTS, NEIGHBORS]
2019-12-02 23:51:33.937 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2019-12-02 23:51:33.947 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00158D0001FF8F6A: Starting ZigBee device discovery
2019-12-02 23:51:33.948 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 00158D0001FF8F6A: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:cc9950e6
2019-12-02 23:51:33.949 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zigbee:device:cc9950e6:00158d0001ff8f6a' to inbox.
2019-12-02 23:51:33.950 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 00158D0001FF8F6A: Node discovery not complete
2019-12-02 23:51:33.985 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2019-12-02 23:51:34.327 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspTrustCenterJoinHandler [newNodeId=39956, newNodeEui64=00158D0001FF8F6A, status=EMBER_STANDARD_SECURITY_UNSECURED_JOIN, policyDecision=EMBER_USE_PRECONFIGURED_KEY, parentOfNewNodeId=0]
2019-12-02 23:51:34.328 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00158D0001FF8F6A: nodeStatusUpdate - node status is UNSECURED_JOIN, network address is 39956.
2019-12-02 23:51:34.328 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 00158D0001FF8F6A: Device status updated. NWK=39956
2019-12-02 23:51:34.329 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00158D0001FF8F6A: Node 39956 update
2019-12-02 23:51:34.332 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2019-12-02 23:51:34.341 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00158D0001FF8F6A: Starting ZigBee device discovery
2019-12-02 23:51:34.342 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 00158D0001FF8F6A: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:cc9950e6
2019-12-02 23:51:34.370 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 00158D0001FF8F6A: Node discovery not complete
2019-12-02 23:51:34.373 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2019-12-02 23:51:34.714 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0, clusterId=19, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=108], lastHopLqi=254, lastHopRssi=-35, sender=39956, bindingIndex=255, addressIndex=255, messageContents=81 14 9C 6A 8F FF 01 00 8D 15 00 80]
2019-12-02 23:51:34.715 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/0, destinationAddress=0/0, profile=0000, cluster=19, addressMode=null, radius=0, apsSecurity=false, apsCounter=108, payload=81 14 9C 6A 8F FF 01 00 8D 15 00 80]
2019-12-02 23:51:34.715 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DeviceAnnounce [39956/0 -> 0/0, cluster=0013, TID=NULL, nwkAddrOfInterest=39956, ieeeAddr=00158D0001FF8F6A, capability=128]
2019-12-02 23:51:34.716 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Mesh related command received. Triggering mesh update.
2019-12-02 23:51:34.718 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Start mesh update task with interval of 300 seconds
2019-12-02 23:51:34.717 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 00158D0001FF8F6A: Device announce received. NWK=39956
2019-12-02 23:51:34.718 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00158D0001FF8F6A: Node 39956 update
2019-12-02 23:51:34.724 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2019-12-02 23:51:34.729 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update
2019-12-02 23:51:34.729 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update for 000D6F000DD02801
2019-12-02 23:51:34.730 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: Update mesh
2019-12-02 23:51:34.730 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: scheduled [ROUTES, NEIGHBORS]
2019-12-02 23:51:34.730 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update for 00158D0001FF8F6A
2019-12-02 23:51:34.731 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: Update mesh
2019-12-02 23:51:34.732 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: already scheduled or running
2019-12-02 23:51:34.732 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00158D0001FF8F6A: Starting ZigBee device discovery
2019-12-02 23:51:34.733 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: scheduled [NODE_DESCRIPTOR, NWK_ADDRESS, POWER_DESCRIPTOR, ACTIVE_ENDPOINTS, NEIGHBORS, ROUTES]
2019-12-02 23:51:34.733 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 00158D0001FF8F6A: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:cc9950e6
2019-12-02 23:51:34.733 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update for 7CB03EAA0A002E4F
2019-12-02 23:51:34.734 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: Update mesh
2019-12-02 23:51:34.735 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: already scheduled or running
2019-12-02 23:51:34.735 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: scheduled [NEIGHBORS]
2019-12-02 23:51:34.761 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2019-12-02 23:51:34.763 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 00158D0001FF8F6A: Node discovery not complete
2019-12-02 23:51:34.901 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: running
2019-12-02 23:51:34.902 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NodeDescriptorRequest [0/0 -> 39956/0, cluster=0002, TID=5D, nwkAddrOfInterest=39956]
2019-12-02 23:51:34.902 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=39956/0, profile=0000, cluster=2, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=93, payload=00 14 9C]
2019-12-02 23:51:34.903 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=93], messageTag=93, messageContents=00 14 9C]
2019-12-02 23:51:35.122 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=66]
2019-12-02 23:51:35.122 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=66]
2019-12-02 23:51:35.124 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspZigbeeKeyEstablishmentHandler [partner=00158D0001FF8F6A, status=EMBER_EEPROM_MFG_VERSION_MISMATCH]
2019-12-02 23:51:35.125 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspZigbeeKeyEstablishmentHandler [partner=00158D0001FF8F6A, status=EMBER_EEPROM_MFG_VERSION_MISMATCH]
2019-12-02 23:51:35.350 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: running
2019-12-02 23:51:35.350 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NodeDescriptorRequest [0/0 -> 39956/0, cluster=0002, TID=5E, nwkAddrOfInterest=39956]
2019-12-02 23:51:35.351 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=39956/0, profile=0000, cluster=2, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=94, payload=00 14 9C]
2019-12-02 23:51:35.351 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=94], messageTag=94, messageContents=00 14 9C]
2019-12-02 23:51:35.466 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=66], messageTag=93, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:35.467 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=66], messageTag=93, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:35.468 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32770, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=111], lastHopLqi=254, lastHopRssi=-35, sender=39956, bindingIndex=255, addressIndex=255, messageContents=00 00 14 9C 02 40 80 37 10 7F 64 00 00 2C 64 00 00]
2019-12-02 23:51:35.469 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/0, destinationAddress=0/0, profile=0000, cluster=32770, addressMode=null, radius=0, apsSecurity=false, apsCounter=111, payload=00 00 14 9C 02 40 80 37 10 7F 64 00 00 2C 64 00 00]
2019-12-02 23:51:35.470 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NodeDescriptorResponse [39956/0 -> 0/0, cluster=8002, TID=NULL, status=SUCCESS, nwkAddrOfInterest=39956, nodeDescriptor=NodeDescriptor [apsFlags=0, bufferSize=127, complexDescriptorAvailable=false, manufacturerCode=4151, logicalType=END_DEVICE, serverCapabilities=[], incomingTransferSize=100, outgoingTransferSize=100, userDescriptorAvailable=false, frequencyBands=[FREQ_2400_MHZ], macCapabilities=[REDUCED_FUNCTION_DEVICE], extendedEndpointListAvailable=false, extendedSimpleDescriptorListAvailable=false, stackCompliance=22]]
2019-12-02 23:51:35.473 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: NodeDescriptorRequest [0/0 -> 39956/0, cluster=0002, TID=5D, nwkAddrOfInterest=39956]
2019-12-02 23:51:35.473 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: NodeDescriptorRequest [0/0 -> 39956/0, cluster=0002, TID=5E, nwkAddrOfInterest=39956]
2019-12-02 23:51:35.474 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: NodeDescriptorResponse returned NodeDescriptorResponse [39956/0 -> 0/0, cluster=8002, TID=NULL, status=SUCCESS, nwkAddrOfInterest=39956, nodeDescriptor=NodeDescriptor [apsFlags=0, bufferSize=127, complexDescriptorAvailable=false, manufacturerCode=4151, logicalType=END_DEVICE, serverCapabilities=[], incomingTransferSize=100, outgoingTransferSize=100, userDescriptorAvailable=false, frequencyBands=[FREQ_2400_MHZ], macCapabilities=[REDUCED_FUNCTION_DEVICE], extendedEndpointListAvailable=false, extendedSimpleDescriptorListAvailable=false, stackCompliance=22]]
2019-12-02 23:51:35.474 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=68]
2019-12-02 23:51:35.474 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: NodeDescriptorResponse returned NodeDescriptorResponse [39956/0 -> 0/0, cluster=8002, TID=NULL, status=SUCCESS, nwkAddrOfInterest=39956, nodeDescriptor=NodeDescriptor [apsFlags=0, bufferSize=127, complexDescriptorAvailable=false, manufacturerCode=4151, logicalType=END_DEVICE, serverCapabilities=[], incomingTransferSize=100, outgoingTransferSize=100, userDescriptorAvailable=false, frequencyBands=[FREQ_2400_MHZ], macCapabilities=[REDUCED_FUNCTION_DEVICE], extendedEndpointListAvailable=false, extendedSimpleDescriptorListAvailable=false, stackCompliance=22]]
2019-12-02 23:51:35.475 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: request NODE_DESCRIPTOR successful. Advanced to NWK_ADDRESS.
2019-12-02 23:51:35.475 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=68]
2019-12-02 23:51:35.475 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: request NODE_DESCRIPTOR successful. Advanced to NWK_ADDRESS.
2019-12-02 23:51:35.475 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: running
2019-12-02 23:51:35.475 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: running
2019-12-02 23:51:35.476 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=5F, ieeeAddr=00158D0001FF8F6A, requestType=0, startIndex=0]
2019-12-02 23:51:35.476 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=60, ieeeAddr=00158D0001FF8F6A, requestType=0, startIndex=0]
2019-12-02 23:51:35.478 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=96, payload=00 6A 8F FF 01 00 8D 15 00 00 00]
2019-12-02 23:51:35.478 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=95, payload=00 6A 8F FF 01 00 8D 15 00 00 00]
2019-12-02 23:51:35.478 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendBroadcastRequest [destination=65535, apsFrame=EmberApsFrame [profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=96], radius=31, messageTag=96, messageContents=00 6A 8F FF 01 00 8D 15 00 00 00]
2019-12-02 23:51:35.478 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendBroadcastRequest [destination=65535, apsFrame=EmberApsFrame [profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=95], radius=31, messageTag=95, messageContents=00 6A 8F FF 01 00 8D 15 00 00 00]
2019-12-02 23:51:35.776 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendBroadcastResponse [status=EMBER_SUCCESS, sequence=70]
2019-12-02 23:51:35.777 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendBroadcastResponse [status=EMBER_SUCCESS, sequence=70]
2019-12-02 23:51:35.994 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST_LOOPBACK, apsFrame=EmberApsFrame [profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=70], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 6A 8F FF 01 00 8D 15 00 00 00]
2019-12-02 23:51:35.994 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=0, addressMode=null, radius=0, apsSecurity=false, apsCounter=70, payload=00 6A 8F FF 01 00 8D 15 00 00 00]
2019-12-02 23:51:35.995 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressRequest [0/0 -> 0/0, cluster=0000, TID=NULL, ieeeAddr=00158D0001FF8F6A, requestType=0, startIndex=0]
2019-12-02 23:51:35.998 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32768, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=71], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 6A 8F FF 01 00 8D 15 00 14 9C]
2019-12-02 23:51:35.998 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32768, addressMode=null, radius=0, apsSecurity=false, apsCounter=71, payload=00 00 6A 8F FF 01 00 8D 15 00 14 9C]
2019-12-02 23:51:35.999 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressResponse [0/0 -> 0/0, cluster=8000, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=00158D0001FF8F6A, nwkAddrRemoteDev=39956, startIndex=null, nwkAddrAssocDevList=[]]
2019-12-02 23:51:36.000 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=60, ieeeAddr=00158D0001FF8F6A, requestType=0, startIndex=0]
2019-12-02 23:51:36.000 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=5F, ieeeAddr=00158D0001FF8F6A, requestType=0, startIndex=0]
2019-12-02 23:51:36.001 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 39956: Node SVC Discovery: NetworkAddressRequest returned NetworkAddressResponse [0/0 -> 0/0, cluster=8000, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=00158D0001FF8F6A, nwkAddrRemoteDev=39956, startIndex=null, nwkAddrAssocDevList=[]]
2019-12-02 23:51:36.001 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 39956: Node SVC Discovery: NetworkAddressRequest returned NetworkAddressResponse [0/0 -> 0/0, cluster=8000, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=00158D0001FF8F6A, nwkAddrRemoteDev=39956, startIndex=null, nwkAddrAssocDevList=[]]
2019-12-02 23:51:36.001 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: request NWK_ADDRESS successful. Advanced to POWER_DESCRIPTOR.
2019-12-02 23:51:36.001 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: request NWK_ADDRESS successful. Advanced to POWER_DESCRIPTOR.
2019-12-02 23:51:36.002 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: running
2019-12-02 23:51:36.002 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: running
2019-12-02 23:51:36.002 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: PowerDescriptorRequest [0/0 -> 39956/0, cluster=0003, TID=61, nwkAddrOfInterest=39956]
2019-12-02 23:51:36.002 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: PowerDescriptorRequest [0/0 -> 39956/0, cluster=0003, TID=62, nwkAddrOfInterest=39956]
2019-12-02 23:51:36.003 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=39956/0, profile=0000, cluster=3, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=97, payload=00 14 9C]
2019-12-02 23:51:36.003 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=39956/0, profile=0000, cluster=3, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=98, payload=00 14 9C]
2019-12-02 23:51:36.003 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=3, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=97], messageTag=97, messageContents=00 14 9C]
2019-12-02 23:51:36.003 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=3, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=98], messageTag=98, messageContents=00 14 9C]
2019-12-02 23:51:36.212 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=68], messageTag=94, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:36.213 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=2, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=68], messageTag=94, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:36.215 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32770, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=113], lastHopLqi=255, lastHopRssi=-36, sender=39956, bindingIndex=255, addressIndex=255, messageContents=00 00 14 9C 02 40 80 37 10 7F 64 00 00 2C 64 00 00]
2019-12-02 23:51:36.216 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/0, destinationAddress=0/0, profile=0000, cluster=32770, addressMode=null, radius=0, apsSecurity=false, apsCounter=113, payload=00 00 14 9C 02 40 80 37 10 7F 64 00 00 2C 64 00 00]
2019-12-02 23:51:36.216 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NodeDescriptorResponse [39956/0 -> 0/0, cluster=8002, TID=NULL, status=SUCCESS, nwkAddrOfInterest=39956, nodeDescriptor=NodeDescriptor [apsFlags=0, bufferSize=127, complexDescriptorAvailable=false, manufacturerCode=4151, logicalType=END_DEVICE, serverCapabilities=[], incomingTransferSize=100, outgoingTransferSize=100, userDescriptorAvailable=false, frequencyBands=[FREQ_2400_MHZ], macCapabilities=[REDUCED_FUNCTION_DEVICE], extendedEndpointListAvailable=false, extendedSimpleDescriptorListAvailable=false, stackCompliance=22]]
2019-12-02 23:51:36.220 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0, clusterId=54, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=114], lastHopLqi=254, lastHopRssi=-35, sender=39956, bindingIndex=255, addressIndex=255, messageContents=83 B4 01]
2019-12-02 23:51:36.221 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=null, radius=0, apsSecurity=false, apsCounter=114, payload=83 B4 01]
2019-12-02 23:51:36.222 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningRequest [39956/0 -> 0/0, cluster=0036, TID=NULL, permitDuration=180, tcSignificance=true]
2019-12-02 23:51:36.230 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendBroadcastResponse [status=EMBER_SUCCESS, sequence=72]
2019-12-02 23:51:36.231 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendBroadcastResponse [status=EMBER_SUCCESS, sequence=72]
2019-12-02 23:51:36.233 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST_LOOPBACK, apsFrame=EmberApsFrame [profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=72], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 6A 8F FF 01 00 8D 15 00 00 00]
2019-12-02 23:51:36.233 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=0, addressMode=null, radius=0, apsSecurity=false, apsCounter=72, payload=00 6A 8F FF 01 00 8D 15 00 00 00]
2019-12-02 23:51:36.234 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressRequest [0/0 -> 0/0, cluster=0000, TID=NULL, ieeeAddr=00158D0001FF8F6A, requestType=0, startIndex=0]
2019-12-02 23:51:36.275 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: running
2019-12-02 23:51:36.276 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 14815/0, cluster=0031, TID=63, startIndex=0]
2019-12-02 23:51:36.276 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=14815/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=99, payload=00 00]
2019-12-02 23:51:36.277 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=99], messageTag=99, messageContents=00 00]
2019-12-02 23:51:36.520 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: running
2019-12-02 23:51:36.521 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=64, startIndex=0]
2019-12-02 23:51:36.521 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=100, payload=00 00]
2019-12-02 23:51:36.522 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=100], messageTag=100, messageContents=00 00]
2019-12-02 23:51:36.563 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 14815/0, cluster=0031, TID=5C, startIndex=0]
2019-12-02 23:51:36.564 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT]
2019-12-02 23:51:36.565 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: request NEIGHBORS failed after 13 attempts.
2019-12-02 23:51:36.565 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: running
2019-12-02 23:51:36.566 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: complete
2019-12-02 23:51:36.567 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 7CB03EAA0A002E4F: Node 14815 update
2019-12-02 23:51:36.568 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Node updated - ZigBeeNode [IEEE=7CB03EAA0A002E4F, NWK=39DF, Type=ROUTER]
2019-12-02 23:51:36.571 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2019-12-02 23:51:36.604 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32768, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=73], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 6A 8F FF 01 00 8D 15 00 14 9C]
2019-12-02 23:51:36.604 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32768, addressMode=null, radius=0, apsSecurity=false, apsCounter=73, payload=00 00 6A 8F FF 01 00 8D 15 00 14 9C]
2019-12-02 23:51:36.605 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressResponse [0/0 -> 0/0, cluster=8000, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=00158D0001FF8F6A, nwkAddrRemoteDev=39956, startIndex=null, nwkAddrAssocDevList=[]]
2019-12-02 23:51:36.609 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32768, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=115], lastHopLqi=254, lastHopRssi=-36, sender=39956, bindingIndex=255, addressIndex=255, messageContents=00 00 6A 8F FF 01 00 8D 15 00 14 9C]
2019-12-02 23:51:36.610 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/0, destinationAddress=0/0, profile=0000, cluster=32768, addressMode=null, radius=0, apsSecurity=false, apsCounter=115, payload=00 00 6A 8F FF 01 00 8D 15 00 14 9C]
2019-12-02 23:51:36.611 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressResponse [39956/0 -> 0/0, cluster=8000, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=00158D0001FF8F6A, nwkAddrRemoteDev=39956, startIndex=null, nwkAddrAssocDevList=[]]
2019-12-02 23:51:36.612 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2019-12-02 23:51:36.613 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32768, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=116], lastHopLqi=255, lastHopRssi=-35, sender=39956, bindingIndex=255, addressIndex=255, messageContents=00 00 6A 8F FF 01 00 8D 15 00 14 9C]
2019-12-02 23:51:36.614 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/0, destinationAddress=0/0, profile=0000, cluster=32768, addressMode=null, radius=0, apsSecurity=false, apsCounter=116, payload=00 00 6A 8F FF 01 00 8D 15 00 14 9C]
2019-12-02 23:51:36.615 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressResponse [39956/0 -> 0/0, cluster=8000, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=00158D0001FF8F6A, nwkAddrRemoteDev=39956, startIndex=null, nwkAddrAssocDevList=[]]
2019-12-02 23:51:36.624 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_BROADCAST, indexOrDestination=65535, apsFrame=EmberApsFrame [profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=70], messageTag=96, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:36.624 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_BROADCAST, indexOrDestination=65535, apsFrame=EmberApsFrame [profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=70], messageTag=96, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:36.921 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=74]
2019-12-02 23:51:36.922 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=74]
2019-12-02 23:51:37.025 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=3, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=74], messageTag=97, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:37.025 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=3, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=74], messageTag=97, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:37.028 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32771, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=117], lastHopLqi=254, lastHopRssi=-34, sender=39956, bindingIndex=255, addressIndex=255, messageContents=00 00 14 9C 40 C4]
2019-12-02 23:51:37.028 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/0, destinationAddress=0/0, profile=0000, cluster=32771, addressMode=null, radius=0, apsSecurity=false, apsCounter=117, payload=00 00 14 9C 40 C4]
2019-12-02 23:51:37.029 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: PowerDescriptorResponse [39956/0 -> 0/0, cluster=8003, TID=NULL, status=SUCCESS, nwkAddrOfInterest=39956, powerDescriptor=RECEIVER_ON_IDLE, [DISPOSABLE_BATTERY], DISPOSABLE_BATTERY, FULL]
2019-12-02 23:51:37.029 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: PowerDescriptorRequest [0/0 -> 39956/0, cluster=0003, TID=61, nwkAddrOfInterest=39956]
2019-12-02 23:51:37.029 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: PowerDescriptorRequest [0/0 -> 39956/0, cluster=0003, TID=62, nwkAddrOfInterest=39956]
2019-12-02 23:51:37.030 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: PowerDescriptorResponse returned PowerDescriptorResponse [39956/0 -> 0/0, cluster=8003, TID=NULL, status=SUCCESS, nwkAddrOfInterest=39956, powerDescriptor=RECEIVER_ON_IDLE, [DISPOSABLE_BATTERY], DISPOSABLE_BATTERY, FULL]
2019-12-02 23:51:37.030 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: PowerDescriptorResponse returned PowerDescriptorResponse [39956/0 -> 0/0, cluster=8003, TID=NULL, status=SUCCESS, nwkAddrOfInterest=39956, powerDescriptor=RECEIVER_ON_IDLE, [DISPOSABLE_BATTERY], DISPOSABLE_BATTERY, FULL]
2019-12-02 23:51:37.031 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: request POWER_DESCRIPTOR successful. Advanced to ACTIVE_ENDPOINTS.
2019-12-02 23:51:37.031 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_BROADCAST, indexOrDestination=65535, apsFrame=EmberApsFrame [profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=72], messageTag=95, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:37.031 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: request POWER_DESCRIPTOR successful. Advanced to ACTIVE_ENDPOINTS.
2019-12-02 23:51:37.031 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: running
2019-12-02 23:51:37.031 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_BROADCAST, indexOrDestination=65535, apsFrame=EmberApsFrame [profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=72], messageTag=95, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:37.032 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: running
2019-12-02 23:51:37.032 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ActiveEndpointsRequest [0/0 -> 39956/0, cluster=0005, TID=65, nwkAddrOfInterest=39956]
2019-12-02 23:51:37.032 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ActiveEndpointsRequest [0/0 -> 39956/0, cluster=0005, TID=66, nwkAddrOfInterest=39956]
2019-12-02 23:51:37.032 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=39956/0, profile=0000, cluster=5, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=101, payload=00 14 9C]
2019-12-02 23:51:37.033 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=39956/0, profile=0000, cluster=5, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=102, payload=00 14 9C]
2019-12-02 23:51:37.033 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=5, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=101], messageTag=101, messageContents=00 14 9C]
2019-12-02 23:51:37.033 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=5, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=102], messageTag=102, messageContents=00 14 9C]
2019-12-02 23:51:37.221 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=75]
2019-12-02 23:51:37.221 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=75]
2019-12-02 23:51:37.325 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=3, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=75], messageTag=98, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:37.326 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=3, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=75], messageTag=98, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:37.328 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32771, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=118], lastHopLqi=255, lastHopRssi=-35, sender=39956, bindingIndex=255, addressIndex=255, messageContents=00 00 14 9C 40 C4]
2019-12-02 23:51:37.328 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/0, destinationAddress=0/0, profile=0000, cluster=32771, addressMode=null, radius=0, apsSecurity=false, apsCounter=118, payload=00 00 14 9C 40 C4]
2019-12-02 23:51:37.329 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: PowerDescriptorResponse [39956/0 -> 0/0, cluster=8003, TID=NULL, status=SUCCESS, nwkAddrOfInterest=39956, powerDescriptor=RECEIVER_ON_IDLE, [DISPOSABLE_BATTERY], DISPOSABLE_BATTERY, FULL]
2019-12-02 23:51:37.553 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=76]
2019-12-02 23:51:37.554 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=76]
2019-12-02 23:51:38.015 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=77]
2019-12-02 23:51:38.016 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=77]
2019-12-02 23:51:38.119 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=77], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]
2019-12-02 23:51:38.120 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=null, radius=0, apsSecurity=false, apsCounter=77, payload=00 00]
2019-12-02 23:51:38.120 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=NULL, startIndex=0]
2019-12-02 23:51:38.124 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32818, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=78], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 10 00 0F DF 39 01 DF 39 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00]
2019-12-02 23:51:38.126 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, apsSecurity=false, apsCounter=78, payload=00 00 10 00 0F DF 39 01 DF 39 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00]
2019-12-02 23:51:38.127 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=16, startIndex=0, routingTableList=[RoutingTable [destinationAddress=14815, status=DISCOVERY_UNDERWAY, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=14815], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]
2019-12-02 23:51:38.127 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=64, startIndex=0]
2019-12-02 23:51:38.129 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=77], messageTag=100, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:38.130 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=77], messageTag=100, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:38.131 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: ManagementRoutingRequest returned CommandResult [SUCCESS, ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=16, startIndex=0, routingTableList=[RoutingTable [destinationAddress=14815, status=DISCOVERY_UNDERWAY, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=14815], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]]
2019-12-02 23:51:38.132 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=67, startIndex=15]
2019-12-02 23:51:38.133 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=103, payload=00 0F]
2019-12-02 23:51:38.134 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=103], messageTag=103, messageContents=00 0F]
2019-12-02 23:51:38.252 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=79]
2019-12-02 23:51:38.253 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=79]
2019-12-02 23:51:38.521 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=5, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=79], messageTag=101, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:38.522 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=5, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=79], messageTag=101, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:38.524 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32773, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=119], lastHopLqi=255, lastHopRssi=-33, sender=39956, bindingIndex=255, addressIndex=255, messageContents=00 00 14 9C 01 01]
2019-12-02 23:51:38.524 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/0, destinationAddress=0/0, profile=0000, cluster=32773, addressMode=null, radius=0, apsSecurity=false, apsCounter=119, payload=00 00 14 9C 01 01]
2019-12-02 23:51:38.525 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ActiveEndpointsResponse [39956/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=39956, activeEpList=[1]]
2019-12-02 23:51:38.527 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ActiveEndpointsRequest [0/0 -> 39956/0, cluster=0005, TID=65, nwkAddrOfInterest=39956]
2019-12-02 23:51:38.527 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ActiveEndpointsRequest [0/0 -> 39956/0, cluster=0005, TID=66, nwkAddrOfInterest=39956]
2019-12-02 23:51:38.528 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: ActiveEndpointsResponse returned CommandResult [SUCCESS, ActiveEndpointsResponse [39956/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=39956, activeEpList=[1]]]
2019-12-02 23:51:38.528 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: ActiveEndpointsResponse returned CommandResult [SUCCESS, ActiveEndpointsResponse [39956/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=39956, activeEpList=[1]]]
2019-12-02 23:51:38.529 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: SimpleDescriptorRequest [0/0 -> 39956/0, cluster=0004, TID=68, nwkAddrOfInterest=39956, endpoint=1]
2019-12-02 23:51:38.529 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: SimpleDescriptorRequest [0/0 -> 39956/0, cluster=0004, TID=69, nwkAddrOfInterest=39956, endpoint=1]
2019-12-02 23:51:38.529 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=39956/0, profile=0000, cluster=4, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=104, payload=00 14 9C 01]
2019-12-02 23:51:38.530 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=39956/0, profile=0000, cluster=4, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=105, payload=00 14 9C 01]
2019-12-02 23:51:38.530 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=4, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=104], messageTag=104, messageContents=00 14 9C 01]
2019-12-02 23:51:38.530 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=4, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=105], messageTag=105, messageContents=00 14 9C 01]
2019-12-02 23:51:38.722 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=80]
2019-12-02 23:51:38.723 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=80]
2019-12-02 23:51:38.724 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=5, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=80], messageTag=102, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:38.725 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=5, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=80], messageTag=102, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:38.928 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32773, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=120], lastHopLqi=255, lastHopRssi=-34, sender=39956, bindingIndex=255, addressIndex=255, messageContents=00 00 14 9C 01 01]
2019-12-02 23:51:38.928 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/0, destinationAddress=0/0, profile=0000, cluster=32773, addressMode=null, radius=0, apsSecurity=false, apsCounter=120, payload=00 00 14 9C 01 01]
2019-12-02 23:51:38.929 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ActiveEndpointsResponse [39956/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=39956, activeEpList=[1]]
2019-12-02 23:51:39.067 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=81]
2019-12-02 23:51:39.067 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=81]
2019-12-02 23:51:39.069 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=81], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 0F]
2019-12-02 23:51:39.070 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=null, radius=0, apsSecurity=false, apsCounter=81, payload=00 0F]
2019-12-02 23:51:39.070 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=NULL, startIndex=15]
2019-12-02 23:51:39.072 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32818, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=82], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 10 0F 01 00 00 03 00 00]
2019-12-02 23:51:39.072 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, apsSecurity=false, apsCounter=82, payload=00 00 10 0F 01 00 00 03 00 00]
2019-12-02 23:51:39.073 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=16, startIndex=15, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]
2019-12-02 23:51:39.073 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=67, startIndex=15]
2019-12-02 23:51:39.074 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: ManagementRoutingRequest returned CommandResult [SUCCESS, ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=16, startIndex=15, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]]
2019-12-02 23:51:39.075 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: ManagementLqiRequest complete [2 routes]
2019-12-02 23:51:39.075 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=81], messageTag=103, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:39.075 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000DD02801: Routing table NEW: [RoutingTable [destinationAddress=14815, status=DISCOVERY_UNDERWAY, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=14815], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]
2019-12-02 23:51:39.075 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=81], messageTag=103, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:39.076 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000DD02801: Routing table OLD: [RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=4740, status=DISCOVERY_UNDERWAY, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=14815]]
2019-12-02 23:51:39.076 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000DD02801: Routing table updated: [RoutingTable [destinationAddress=14815, status=DISCOVERY_UNDERWAY, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=14815], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]
2019-12-02 23:51:39.077 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: request ROUTES successful. Advanced to NEIGHBORS.
2019-12-02 23:51:39.077 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: running
2019-12-02 23:51:39.078 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=6A, startIndex=0]
2019-12-02 23:51:39.078 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=106, payload=00 00]
2019-12-02 23:51:39.079 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=106], messageTag=106, messageContents=00 00]
2019-12-02 23:51:39.408 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=83]
2019-12-02 23:51:39.408 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=83]
2019-12-02 23:51:39.734 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=4, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=83], messageTag=104, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:39.735 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=4, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=83], messageTag=104, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:39.738 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32772, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=121], lastHopLqi=255, lastHopRssi=-35, sender=39956, bindingIndex=255, addressIndex=255, messageContents=00 00 14 9C 22 01 04 01 01 03 01 06 00 00 01 00 03 00 01 02 19 00 0A 00 07 00 00 01 00 03 00 04 00 01 02 19 00 0A 00]
2019-12-02 23:51:39.739 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/0, destinationAddress=0/0, profile=0000, cluster=32772, addressMode=null, radius=0, apsSecurity=false, apsCounter=121, payload=00 00 14 9C 22 01 04 01 01 03 01 06 00 00 01 00 03 00 01 02 19 00 0A 00 07 00 00 01 00 03 00 04 00 01 02 19 00 0A 00]
2019-12-02 23:51:39.739 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: SimpleDescriptorResponse [39956/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=39956, length=34, simpleDescriptor=SimpleDescriptor [endpoint=1, profileId=0104, deviceId=769, deviceVersion=1, inputClusterList=[0, 1, 3, 513, 25, 10], outputClusterList=[0, 1, 3, 4, 513, 25, 10]]]
2019-12-02 23:51:39.741 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: SimpleDescriptorRequest [0/0 -> 39956/0, cluster=0004, TID=68, nwkAddrOfInterest=39956, endpoint=1]
2019-12-02 23:51:39.741 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: SimpleDescriptorRequest [0/0 -> 39956/0, cluster=0004, TID=69, nwkAddrOfInterest=39956, endpoint=1]
2019-12-02 23:51:39.742 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: SimpleDescriptorResponse returned SimpleDescriptorResponse [39956/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=39956, length=34, simpleDescriptor=SimpleDescriptor [endpoint=1, profileId=0104, deviceId=769, deviceVersion=1, inputClusterList=[0, 1, 3, 513, 25, 10], outputClusterList=[0, 1, 3, 4, 513, 25, 10]]]
2019-12-02 23:51:39.742 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: SimpleDescriptorResponse returned SimpleDescriptorResponse [39956/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=39956, length=34, simpleDescriptor=SimpleDescriptor [endpoint=1, profileId=0104, deviceId=769, deviceVersion=1, inputClusterList=[0, 1, 3, 513, 25, 10], outputClusterList=[0, 1, 3, 4, 513, 25, 10]]]
2019-12-02 23:51:39.743 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting input clusters [0, 1, 3, 513, 25, 10]
2019-12-02 23:51:39.743 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting input clusters [0, 1, 3, 513, 25, 10]
2019-12-02 23:51:39.743 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster BASIC as server
2019-12-02 23:51:39.744 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster BASIC as server
2019-12-02 23:51:39.745 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster POWER_CONFIGURATION as server
2019-12-02 23:51:39.745 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster POWER_CONFIGURATION as server
2019-12-02 23:51:39.745 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster IDENTIFY as server
2019-12-02 23:51:39.745 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster IDENTIFY as server
2019-12-02 23:51:39.746 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster THERMOSTAT as server
2019-12-02 23:51:39.746 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster THERMOSTAT as server
2019-12-02 23:51:39.747 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster OTA_UPGRADE as server
2019-12-02 23:51:39.747 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster OTA_UPGRADE as server
2019-12-02 23:51:39.747 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster TIME as server
2019-12-02 23:51:39.747 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster TIME as server
2019-12-02 23:51:39.748 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting output clusters [0, 1, 3, 4, 513, 25, 10]
2019-12-02 23:51:39.748 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting output clusters [0, 1, 3, 4, 513, 25, 10]
2019-12-02 23:51:39.749 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster BASIC as client
2019-12-02 23:51:39.749 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster BASIC as client
2019-12-02 23:51:39.749 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster POWER_CONFIGURATION as client
2019-12-02 23:51:39.750 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster POWER_CONFIGURATION as client
2019-12-02 23:51:39.750 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster IDENTIFY as client
2019-12-02 23:51:39.750 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster GROUPS as client
2019-12-02 23:51:39.750 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster IDENTIFY as client
2019-12-02 23:51:39.751 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster THERMOSTAT as client
2019-12-02 23:51:39.751 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster GROUPS as client
2019-12-02 23:51:39.751 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster OTA_UPGRADE as client
2019-12-02 23:51:39.752 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster THERMOSTAT as client
2019-12-02 23:51:39.752 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster TIME as client
2019-12-02 23:51:39.753 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster OTA_UPGRADE as client
2019-12-02 23:51:39.753 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: request ACTIVE_ENDPOINTS successful. Advanced to NEIGHBORS.
2019-12-02 23:51:39.753 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 39956/1: Setting cluster TIME as client
2019-12-02 23:51:39.754 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: running
2019-12-02 23:51:39.755 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: request ACTIVE_ENDPOINTS successful. Advanced to NEIGHBORS.
2019-12-02 23:51:39.755 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 39956/0, cluster=0031, TID=6B, startIndex=0]
2019-12-02 23:51:39.756 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: running
2019-12-02 23:51:39.756 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=39956/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=107, payload=00 00]
2019-12-02 23:51:39.756 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 39956/0, cluster=0031, TID=6C, startIndex=0]
2019-12-02 23:51:39.757 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=107], messageTag=107, messageContents=00 00]
2019-12-02 23:51:39.757 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=39956/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=108, payload=00 00]
2019-12-02 23:51:39.758 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=108], messageTag=108, messageContents=00 00]
2019-12-02 23:51:40.031 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=84]
2019-12-02 23:51:40.031 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=84]
2019-12-02 23:51:40.135 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=4, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=84], messageTag=105, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:40.136 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=4, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=84], messageTag=105, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:40.139 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32772, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=122], lastHopLqi=255, lastHopRssi=-34, sender=39956, bindingIndex=255, addressIndex=255, messageContents=00 00 14 9C 22 01 04 01 01 03 01 06 00 00 01 00 03 00 01 02 19 00 0A 00 07 00 00 01 00 03 00 04 00 01 02 19 00 0A 00]
2019-12-02 23:51:40.140 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/0, destinationAddress=0/0, profile=0000, cluster=32772, addressMode=null, radius=0, apsSecurity=false, apsCounter=122, payload=00 00 14 9C 22 01 04 01 01 03 01 06 00 00 01 00 03 00 01 02 19 00 0A 00 07 00 00 01 00 03 00 04 00 01 02 19 00 0A 00]
2019-12-02 23:51:40.140 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: SimpleDescriptorResponse [39956/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=39956, length=34, simpleDescriptor=SimpleDescriptor [endpoint=1, profileId=0104, deviceId=769, deviceVersion=1, inputClusterList=[0, 1, 3, 513, 25, 10], outputClusterList=[0, 1, 3, 4, 513, 25, 10]]]
2019-12-02 23:51:40.286 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=85]
2019-12-02 23:51:40.286 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=85]
2019-12-02 23:51:40.288 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=85], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]
2019-12-02 23:51:40.288 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=null, radius=0, apsSecurity=false, apsCounter=85, payload=00 00]
2019-12-02 23:51:40.289 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=NULL, startIndex=0]
2019-12-02 23:51:40.493 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32817, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=86], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 01 00 01 33 9A 88 7B 08 39 69 07 6A 8F FF 01 00 8D 15 00 14 9C 12 00 01 FF]
2019-12-02 23:51:40.493 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32817, addressMode=null, radius=0, apsSecurity=false, apsCounter=86, payload=00 00 01 00 01 33 9A 88 7B 08 39 69 07 6A 8F FF 01 00 8D 15 00 14 9C 12 00 01 FF]
2019-12-02 23:51:40.494 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=1, startIndex=0, neighborTableList=[NeighborTable [extendedPanId=076939087B889A33, extendedAddress=00158D0001FF8F6A, networkAddress=39956, deviceType=END_DEVICE, rxOnWhenIdle=RX_OFF, relationship=CHILD, permitJoining=DISABLED, depth=1, lqi=255]]]
2019-12-02 23:51:40.495 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=6A, startIndex=0]
2019-12-02 23:51:40.495 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: 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=076939087B889A33, extendedAddress=00158D0001FF8F6A, networkAddress=39956, deviceType=END_DEVICE, rxOnWhenIdle=RX_OFF, relationship=CHILD, permitJoining=DISABLED, depth=1, lqi=255]]]]
2019-12-02 23:51:40.496 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: ManagementLqiRequest complete [1 neighbors]
2019-12-02 23:51:40.496 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=85], messageTag=106, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:40.497 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=85], messageTag=106, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:40.497 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000DD02801: Neighbor table updated: [NeighborTable [extendedPanId=076939087B889A33, extendedAddress=00158D0001FF8F6A, networkAddress=39956, deviceType=END_DEVICE, rxOnWhenIdle=RX_OFF, relationship=CHILD, permitJoining=DISABLED, depth=1, lqi=255]]
2019-12-02 23:51:40.497 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: request NEIGHBORS successful. Advanced to null.
2019-12-02 23:51:40.498 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: running
2019-12-02 23:51:40.498 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: complete
2019-12-02 23:51:40.499 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6F000DD02801: Node 0 update
2019-12-02 23:51:40.503 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2019-12-02 23:51:40.550 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2019-12-02 23:51:40.810 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=87]
2019-12-02 23:51:40.810 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=87]
2019-12-02 23:51:40.812 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=87], messageTag=107, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:40.813 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=87], messageTag=107, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:40.915 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32817, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=123], lastHopLqi=255, lastHopRssi=-44, sender=39956, bindingIndex=255, addressIndex=255, messageContents=00 00 01 00 01 33 9A 88 7B 08 39 69 07 01 28 D0 0D 00 6F 0D 00 00 00 04 02 00 74]
2019-12-02 23:51:40.916 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/0, destinationAddress=0/0, profile=0000, cluster=32817, addressMode=null, radius=0, apsSecurity=false, apsCounter=123, payload=00 00 01 00 01 33 9A 88 7B 08 39 69 07 01 28 D0 0D 00 6F 0D 00 00 00 04 02 00 74]
2019-12-02 23:51:40.918 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [39956/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=1, startIndex=0, neighborTableList=[NeighborTable [extendedPanId=076939087B889A33, extendedAddress=000D6F000DD02801, networkAddress=0, deviceType=COORDINATOR, rxOnWhenIdle=RX_ON, relationship=PARENT, permitJoining=UNKNOWN, depth=0, lqi=116]]]
2019-12-02 23:51:40.920 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementLqiRequest [0/0 -> 39956/0, cluster=0031, TID=6B, startIndex=0]
2019-12-02 23:51:40.920 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementLqiRequest [0/0 -> 39956/0, cluster=0031, TID=6C, startIndex=0]
2019-12-02 23:51:40.921 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: ManagementLqiRequest response CommandResult [SUCCESS, ManagementLqiResponse [39956/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=1, startIndex=0, neighborTableList=[NeighborTable [extendedPanId=076939087B889A33, extendedAddress=000D6F000DD02801, networkAddress=0, deviceType=COORDINATOR, rxOnWhenIdle=RX_ON, relationship=PARENT, permitJoining=UNKNOWN, depth=0, lqi=116]]]]
2019-12-02 23:51:40.922 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: ManagementLqiRequest complete [1 neighbors]
2019-12-02 23:51:40.925 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: ManagementLqiRequest response CommandResult [SUCCESS, ManagementLqiResponse [39956/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=1, startIndex=0, neighborTableList=[NeighborTable [extendedPanId=076939087B889A33, extendedAddress=000D6F000DD02801, networkAddress=0, deviceType=COORDINATOR, rxOnWhenIdle=RX_ON, relationship=PARENT, permitJoining=UNKNOWN, depth=0, lqi=116]]]]
2019-12-02 23:51:40.926 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: ManagementLqiRequest complete [1 neighbors]
2019-12-02 23:51:40.928 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 00158D0001FF8F6A: Neighbor table updated: [NeighborTable [extendedPanId=076939087B889A33, extendedAddress=000D6F000DD02801, networkAddress=0, deviceType=COORDINATOR, rxOnWhenIdle=RX_ON, relationship=PARENT, permitJoining=UNKNOWN, depth=0, lqi=116]]
2019-12-02 23:51:40.928 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 00158D0001FF8F6A: Neighbor table updated: [NeighborTable [extendedPanId=076939087B889A33, extendedAddress=000D6F000DD02801, networkAddress=0, deviceType=COORDINATOR, rxOnWhenIdle=RX_ON, relationship=PARENT, permitJoining=UNKNOWN, depth=0, lqi=116]]
2019-12-02 23:51:40.929 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: request NEIGHBORS successful. Advanced to ROUTES.
2019-12-02 23:51:40.929 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: request NEIGHBORS successful. Advanced to ROUTES.
2019-12-02 23:51:40.929 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: running
2019-12-02 23:51:40.930 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 39956/0, cluster=0032, TID=6D, startIndex=0]
2019-12-02 23:51:40.931 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=39956/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=109, payload=00 00]
2019-12-02 23:51:40.932 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=109], messageTag=109, messageContents=00 00]
2019-12-02 23:51:40.929 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: running
2019-12-02 23:51:40.933 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 39956/0, cluster=0032, TID=6E, startIndex=0]
2019-12-02 23:51:40.934 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=39956/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=110, payload=00 00]
2019-12-02 23:51:40.935 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=110], messageTag=110, messageContents=00 00]
2019-12-02 23:51:41.155 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=88]
2019-12-02 23:51:41.156 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=88]
2019-12-02 23:51:41.157 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=88], messageTag=108, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:41.158 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=88], messageTag=108, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:41.260 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32817, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=124], lastHopLqi=255, lastHopRssi=-43, sender=39956, bindingIndex=255, addressIndex=255, messageContents=00 00 01 00 01 33 9A 88 7B 08 39 69 07 01 28 D0 0D 00 6F 0D 00 00 00 04 02 00 6D]
2019-12-02 23:51:41.261 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/0, destinationAddress=0/0, profile=0000, cluster=32817, addressMode=null, radius=0, apsSecurity=false, apsCounter=124, payload=00 00 01 00 01 33 9A 88 7B 08 39 69 07 01 28 D0 0D 00 6F 0D 00 00 00 04 02 00 6D]
2019-12-02 23:51:41.261 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [39956/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=1, startIndex=0, neighborTableList=[NeighborTable [extendedPanId=076939087B889A33, extendedAddress=000D6F000DD02801, networkAddress=0, deviceType=COORDINATOR, rxOnWhenIdle=RX_ON, relationship=PARENT, permitJoining=UNKNOWN, depth=0, lqi=109]]]
2019-12-02 23:51:41.423 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=89]
2019-12-02 23:51:41.424 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=89]
2019-12-02 23:51:41.425 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=89], messageTag=109, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:41.426 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=89], messageTag=109, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:41.528 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32818, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=125], lastHopLqi=254, lastHopRssi=-43, sender=39956, bindingIndex=255, addressIndex=255, messageContents=00 84]
2019-12-02 23:51:41.529 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, apsSecurity=false, apsCounter=125, payload=00 84]
2019-12-02 23:51:41.530 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [39956/0 -> 0/0, cluster=8032, TID=NULL, status=NOT_SUPPORTED, routingTableEntries=null, startIndex=null, routingTableList=[]]
2019-12-02 23:51:41.531 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementRoutingRequest [0/0 -> 39956/0, cluster=0032, TID=6E, startIndex=0]
2019-12-02 23:51:41.531 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementRoutingRequest [0/0 -> 39956/0, cluster=0032, TID=6D, startIndex=0]
2019-12-02 23:51:41.532 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: ManagementRoutingRequest returned CommandResult [ERROR (UNKNOWN,0xFF), ManagementRoutingResponse [39956/0 -> 0/0, cluster=8032, TID=NULL, status=NOT_SUPPORTED, routingTableEntries=null, startIndex=null, routingTableList=[]]]
2019-12-02 23:51:41.532 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: ManagementRoutingRequest returned CommandResult [ERROR (UNKNOWN,0xFF), ManagementRoutingResponse [39956/0 -> 0/0, cluster=8032, TID=NULL, status=NOT_SUPPORTED, routingTableEntries=null, startIndex=null, routingTableList=[]]]
2019-12-02 23:51:41.533 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery ManagementLqiRequest not supported
2019-12-02 23:51:41.533 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery ManagementLqiRequest not supported
2019-12-02 23:51:41.534 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: request ROUTES successful. Advanced to null.
2019-12-02 23:51:41.534 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: request ROUTES successful. Advanced to null.
2019-12-02 23:51:41.535 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: running
2019-12-02 23:51:41.535 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: running
2019-12-02 23:51:41.536 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: complete
2019-12-02 23:51:41.536 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: complete
2019-12-02 23:51:41.536 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00158D0001FF8F6A: Node 39956 update
2019-12-02 23:51:41.536 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00158D0001FF8F6A: Node 39956 update
2019-12-02 23:51:41.544 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2019-12-02 23:51:41.552 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00158D0001FF8F6A: Starting ZigBee device discovery
2019-12-02 23:51:41.552 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 00158D0001FF8F6A: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_ember:cc9950e6
2019-12-02 23:51:41.554 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 00158D0001FF8F6A: ZigBee node property discovery start
2019-12-02 23:51:41.554 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 00158D0001FF8F6A: ZigBee node property discovery using 39956/1
2019-12-02 23:51:41.555 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=BASIC, id=4, name=ManufacturerName, dataType=CHARACTER_STRING, lastValue=null]
2019-12-02 23:51:41.555 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Basic: 0/0 -> 39956/1, cluster=0000, TID=6F, identifiers=[4]]
2019-12-02 23:51:41.556 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=111, commandId=0]
2019-12-02 23:51:41.557 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=39956/1, profile=0104, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=111, payload=00 6F 00 04 00]
2019-12-02 23:51:41.557 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=111], messageTag=111, messageContents=00 6F 00 04 00]
2019-12-02 23:51:41.595 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2019-12-02 23:51:41.599 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2019-12-02 23:51:41.663 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2019-12-02 23:51:41.723 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=90]
2019-12-02 23:51:41.724 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=90]
2019-12-02 23:51:41.928 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=90], messageTag=110, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:41.929 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=90], messageTag=110, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:41.930 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32818, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=126], lastHopLqi=255, lastHopRssi=-42, sender=39956, bindingIndex=255, addressIndex=255, messageContents=00 84]
2019-12-02 23:51:41.931 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, apsSecurity=false, apsCounter=126, payload=00 84]
2019-12-02 23:51:41.931 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [39956/0 -> 0/0, cluster=8032, TID=NULL, status=NOT_SUPPORTED, routingTableEntries=null, startIndex=null, routingTableList=[]]
2019-12-02 23:51:42.227 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=91]
2019-12-02 23:51:42.230 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=91]
2019-12-02 23:51:42.232 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=76], messageTag=99, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:51:42.232 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=76], messageTag=99, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:51:42.234 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=91], messageTag=111, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:42.234 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=91], messageTag=111, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:42.236 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=127], lastHopLqi=254, lastHopRssi=-45, sender=39956, bindingIndex=255, addressIndex=255, messageContents=18 6F 01 04 00 00 42 0A 45 75 72 6F 74 72 6F 6E 69 63]
2019-12-02 23:51:42.237 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/1, destinationAddress=0/1, profile=0104, cluster=0, addressMode=null, radius=0, apsSecurity=false, apsCounter=127, payload=18 6F 01 04 00 00 42 0A 45 75 72 6F 74 72 6F 6E 69 63]
2019-12-02 23:51:42.237 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=111, commandId=1]
2019-12-02 23:51:42.238 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReadAttributesResponse [Basic: 39956/1 -> 0/1, cluster=0000, TID=6F, records=[ReadAttributeStatusRecord [attributeDataType=CHARACTER_STRING, attributeIdentifier=4, status=SUCCESS, attributeValue=Eurotronic]]]
2019-12-02 23:51:42.239 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ReadAttributesCommand [Basic: 0/0 -> 39956/1, cluster=0000, TID=6F, identifiers=[4]]
2019-12-02 23:51:42.241 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=BASIC, id=5, name=ModelIdentifier, dataType=CHARACTER_STRING, lastValue=null]
2019-12-02 23:51:42.241 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Basic: 0/0 -> 39956/1, cluster=0000, TID=70, identifiers=[5]]
2019-12-02 23:51:42.242 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=112, commandId=0]
2019-12-02 23:51:42.245 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=39956/1, profile=0104, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=112, payload=00 70 00 05 00]
2019-12-02 23:51:42.245 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=112], messageTag=112, messageContents=00 70 00 05 00]
2019-12-02 23:51:42.586 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=92]
2019-12-02 23:51:42.586 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=92]
2019-12-02 23:51:42.589 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=92], messageTag=112, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:42.590 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=92], messageTag=112, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:42.592 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=128], lastHopLqi=255, lastHopRssi=-42, sender=39956, bindingIndex=255, addressIndex=255, messageContents=18 70 01 05 00 00 42 08 53 50 5A 42 30 30 30 31]
2019-12-02 23:51:42.593 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/1, destinationAddress=0/1, profile=0104, cluster=0, addressMode=null, radius=0, apsSecurity=false, apsCounter=128, payload=18 70 01 05 00 00 42 08 53 50 5A 42 30 30 30 31]
2019-12-02 23:51:42.594 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=112, commandId=1]
2019-12-02 23:51:42.594 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReadAttributesResponse [Basic: 39956/1 -> 0/1, cluster=0000, TID=70, records=[ReadAttributeStatusRecord [attributeDataType=CHARACTER_STRING, attributeIdentifier=5, status=SUCCESS, attributeValue=SPZB0001]]]
2019-12-02 23:51:42.598 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ReadAttributesCommand [Basic: 0/0 -> 39956/1, cluster=0000, TID=70, identifiers=[5]]
2019-12-02 23:51:42.599 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=BASIC, id=3, name=HWVersion, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=null]
2019-12-02 23:51:42.599 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Basic: 0/0 -> 39956/1, cluster=0000, TID=71, identifiers=[3]]
2019-12-02 23:51:42.600 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=113, commandId=0]
2019-12-02 23:51:42.601 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=39956/1, profile=0104, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=113, payload=00 71 00 03 00]
2019-12-02 23:51:42.602 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=113], messageTag=113, messageContents=00 71 00 03 00]
2019-12-02 23:51:42.884 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=93]
2019-12-02 23:51:42.884 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=93]
2019-12-02 23:51:42.885 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=93], messageTag=113, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:42.885 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=93], messageTag=113, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:42.886 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=129], lastHopLqi=254, lastHopRssi=-38, sender=39956, bindingIndex=255, addressIndex=255, messageContents=18 71 01 03 00 00 20 23]
2019-12-02 23:51:42.887 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/1, destinationAddress=0/1, profile=0104, cluster=0, addressMode=null, radius=0, apsSecurity=false, apsCounter=129, payload=18 71 01 03 00 00 20 23]
2019-12-02 23:51:42.887 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=113, commandId=1]
2019-12-02 23:51:42.887 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReadAttributesResponse [Basic: 39956/1 -> 0/1, cluster=0000, TID=71, records=[ReadAttributeStatusRecord [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=3, status=SUCCESS, attributeValue=35]]]
2019-12-02 23:51:42.888 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ReadAttributesCommand [Basic: 0/0 -> 39956/1, cluster=0000, TID=71, identifiers=[3]]
2019-12-02 23:51:42.889 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=BASIC, id=2, name=StackVersion, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=null]
2019-12-02 23:51:42.889 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Basic: 0/0 -> 39956/1, cluster=0000, TID=72, identifiers=[2]]
2019-12-02 23:51:42.889 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=114, commandId=0]
2019-12-02 23:51:42.890 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=39956/1, profile=0104, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=114, payload=00 72 00 02 00]
2019-12-02 23:51:42.890 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=114], messageTag=114, messageContents=00 72 00 02 00]
2019-12-02 23:51:43.200 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=94]
2019-12-02 23:51:43.201 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=94]
2019-12-02 23:51:43.202 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=94], messageTag=114, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:43.203 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=94], messageTag=114, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:43.205 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=130], lastHopLqi=254, lastHopRssi=-35, sender=39956, bindingIndex=255, addressIndex=255, messageContents=18 72 01 02 00 00 20 05]
2019-12-02 23:51:43.205 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/1, destinationAddress=0/1, profile=0104, cluster=0, addressMode=null, radius=0, apsSecurity=false, apsCounter=130, payload=18 72 01 02 00 00 20 05]
2019-12-02 23:51:43.206 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=114, commandId=1]
2019-12-02 23:51:43.206 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReadAttributesResponse [Basic: 39956/1 -> 0/1, cluster=0000, TID=72, records=[ReadAttributeStatusRecord [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=2, status=SUCCESS, attributeValue=5]]]
2019-12-02 23:51:43.208 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ReadAttributesCommand [Basic: 0/0 -> 39956/1, cluster=0000, TID=72, identifiers=[2]]
2019-12-02 23:51:43.208 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=BASIC, id=0, name=ZCLVersion, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=null]
2019-12-02 23:51:43.209 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Basic: 0/0 -> 39956/1, cluster=0000, TID=73, identifiers=[0]]
2019-12-02 23:51:43.210 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=115, commandId=0]
2019-12-02 23:51:43.210 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=39956/1, profile=0104, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=115, payload=00 73 00 00 00]
2019-12-02 23:51:43.211 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=115], messageTag=115, messageContents=00 73 00 00 00]
2019-12-02 23:51:43.401 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=95]
2019-12-02 23:51:43.401 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=95]
2019-12-02 23:51:43.404 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=95], messageTag=115, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:43.404 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=95], messageTag=115, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:43.406 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=131], lastHopLqi=255, lastHopRssi=-36, sender=39956, bindingIndex=255, addressIndex=255, messageContents=18 73 01 00 00 00 20 02]
2019-12-02 23:51:43.407 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/1, destinationAddress=0/1, profile=0104, cluster=0, addressMode=null, radius=0, apsSecurity=false, apsCounter=131, payload=18 73 01 00 00 00 20 02]
2019-12-02 23:51:43.407 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=115, commandId=1]
2019-12-02 23:51:43.407 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReadAttributesResponse [Basic: 39956/1 -> 0/1, cluster=0000, TID=73, records=[ReadAttributeStatusRecord [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, status=SUCCESS, attributeValue=2]]]
2019-12-02 23:51:43.409 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ReadAttributesCommand [Basic: 0/0 -> 39956/1, cluster=0000, TID=73, identifiers=[0]]
2019-12-02 23:51:43.410 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=BASIC, id=6, name=DateCode, dataType=CHARACTER_STRING, lastValue=null]
2019-12-02 23:51:43.411 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Basic: 0/0 -> 39956/1, cluster=0000, TID=74, identifiers=[6]]
2019-12-02 23:51:43.411 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=116, commandId=0]
2019-12-02 23:51:43.411 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=39956/1, profile=0104, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=116, payload=00 74 00 06 00]
2019-12-02 23:51:43.412 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=116], messageTag=116, messageContents=00 74 00 06 00]
2019-12-02 23:51:43.576 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=96]
2019-12-02 23:51:43.576 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=96]
2019-12-02 23:51:43.579 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=96], messageTag=116, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:43.579 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=96], messageTag=116, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:43.582 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=0, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=132], lastHopLqi=255, lastHopRssi=-36, sender=39956, bindingIndex=255, addressIndex=255, messageContents=18 74 01 06 00 00 42 08 32 30 31 39 31 30 31 34]
2019-12-02 23:51:43.582 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/1, destinationAddress=0/1, profile=0104, cluster=0, addressMode=null, radius=0, apsSecurity=false, apsCounter=132, payload=18 74 01 06 00 00 42 08 32 30 31 39 31 30 31 34]
2019-12-02 23:51:43.583 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=116, commandId=1]
2019-12-02 23:51:43.584 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReadAttributesResponse [Basic: 39956/1 -> 0/1, cluster=0000, TID=74, records=[ReadAttributeStatusRecord [attributeDataType=CHARACTER_STRING, attributeIdentifier=6, status=SUCCESS, attributeValue=20191014]]]
2019-12-02 23:51:43.586 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ReadAttributesCommand [Basic: 0/0 -> 39956/1, cluster=0000, TID=74, identifiers=[6]]
2019-12-02 23:51:43.587 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=OTA_UPGRADE, id=2, name=CurrentFileVersion, dataType=UNSIGNED_32_BIT_INTEGER, lastValue=null]
2019-12-02 23:51:43.588 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [OTA Upgrade: 0/0 -> 39956/1, cluster=0019, TID=75, identifiers=[2]]
2019-12-02 23:51:43.589 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=117, commandId=0]
2019-12-02 23:51:43.590 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=39956/1, profile=0104, cluster=25, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=117, payload=08 75 00 02 00]
2019-12-02 23:51:43.591 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=25, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=117], messageTag=117, messageContents=08 75 00 02 00]
2019-12-02 23:51:43.961 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=97]
2019-12-02 23:51:43.961 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=97]
2019-12-02 23:51:43.963 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=25, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=97], messageTag=117, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:43.964 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=260, clusterId=25, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=97], messageTag=117, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:51:43.966 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=25, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=133], lastHopLqi=255, lastHopRssi=-36, sender=39956, bindingIndex=255, addressIndex=255, messageContents=10 75 01 02 00 00 23 D2 E9 62 01]
2019-12-02 23:51:43.966 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/1, destinationAddress=0/1, profile=0104, cluster=25, addressMode=null, radius=0, apsSecurity=false, apsCounter=133, payload=10 75 01 02 00 00 23 D2 E9 62 01]
2019-12-02 23:51:43.967 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=117, commandId=1]
2019-12-02 23:51:43.967 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReadAttributesResponse [OTA Upgrade: 39956/1 -> 0/1, cluster=0019, TID=75, records=[ReadAttributeStatusRecord [attributeDataType=UNSIGNED_32_BIT_INTEGER, attributeIdentifier=2, status=SUCCESS, attributeValue=23259602]]]
2019-12-02 23:51:43.969 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ReadAttributesCommand [OTA Upgrade: 0/0 -> 39956/1, cluster=0019, TID=75, identifiers=[2]]
2019-12-02 23:51:43.970 [DEBUG] [scovery.ZigBeeNodePropertyDiscoverer] - 00158D0001FF8F6A: ZigBee node property discovery complete: {zigbee_logicaltype=END_DEVICE, zigbee_powerlevel=FULL, modelId=SPZB0001, zigbee_networkaddress=39956, zigbee_powersource=DISPOSABLE_BATTERY, zigbee_stkversion=5, zigbee_datecode=20191014, zigbee_zclversion=2, vendor=Eurotronic, zigbee_powermode=RECEIVER_ON_IDLE, zigbee_powersources=[DISPOSABLE_BATTERY], hardwareVersion=35, firmwareVersion=0162E9D2}
2019-12-02 23:51:43.971 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 00158D0001FF8F6A: Update ZigBee device zigbee:device with bridge zigbee:coordinator_ember:cc9950e6, label 'Eurotronic SPZB0001'
2019-12-02 23:51:43.978 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2019-12-02 23:51:44.060 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2019-12-02 23:51:44.276 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 14815/0, cluster=0031, TID=63, startIndex=0]
2019-12-02 23:51:44.277 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT]
2019-12-02 23:51:44.277 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: request NEIGHBORS failed. Retry 1, wait 2100ms before retry.
2019-12-02 23:51:46.378 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: running
2019-12-02 23:51:46.378 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: complete
2019-12-02 23:51:46.379 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 7CB03EAA0A002E4F: Node 14815 update
2019-12-02 23:51:46.380 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Node updated - ZigBeeNode [IEEE=7CB03EAA0A002E4F, NWK=39DF, Type=ROUTER]
2019-12-02 23:51:46.382 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2019-12-02 23:51:46.440 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2019-12-02 23:51:58.231 [INFO ] [el.script.Temp_Outside_MinMaxAverage] - I_Geb_OutsideTemp24HMin set to -2.3000000000000003
2019-12-02 23:51:58.270 [INFO ] [el.script.Temp_Outside_MinMaxAverage] - I_Geb_OutsideTemp24HMax set to 10.200000000000001
2019-12-02 23:51:58.303 [INFO ] [el.script.Temp_Outside_MinMaxAverage] - I_Geb_OutsideTemp24HAvg set to 2.185631655239745
2019-12-02 23:52:10.879 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Polling...
2019-12-02 23:52:10.880 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Polling zigbee:device:cc9950e6:7cb03eaa0a002e4f:7CB03EAA0A002E4F_3_switch
2019-12-02 23:52:10.880 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Mon Dec 02 23:13:18 CET 2019]
2019-12-02 23:52:10.881 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [On/Off: 0/0 -> 14815/3, cluster=0006, TID=76, identifiers=[0]]
2019-12-02 23:52:10.881 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=118, commandId=0]
2019-12-02 23:52:10.882 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=14815/3, profile=0104, cluster=6, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=118, payload=00 76 00 00 00]
2019-12-02 23:52:10.882 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=118], messageTag=118, messageContents=00 76 00 00 00]
2019-12-02 23:52:10.997 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=98]
2019-12-02 23:52:10.998 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=98]
2019-12-02 23:52:15.791 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=98], messageTag=118, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:52:15.792 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=98], messageTag=118, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:52:18.881 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ReadAttributesCommand [On/Off: 0/0 -> 14815/3, cluster=0006, TID=76, identifiers=[0]]
2019-12-02 23:52:18.882 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Polling zigbee:device:cc9950e6:7cb03eaa0a002e4f:7CB03EAA0A002E4F_3_activepower
2019-12-02 23:52:18.883 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=ELECTRICAL_MEASUREMENT, id=772, name=TotalActivePower, dataType=SIGNED_32_BIT_INTEGER, lastValue=null]
2019-12-02 23:52:18.884 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Electrical Measurement: 0/0 -> 14815/3, cluster=0B04, TID=77, identifiers=[772]]
2019-12-02 23:52:18.884 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=119, commandId=0]
2019-12-02 23:52:18.885 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=14815/3, profile=0104, cluster=2820, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=119, payload=00 77 00 04 03]
2019-12-02 23:52:18.885 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=119], messageTag=119, messageContents=00 77 00 04 03]
2019-12-02 23:52:19.100 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=99]
2019-12-02 23:52:19.100 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=99]
2019-12-02 23:52:23.791 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=99], messageTag=119, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:52:23.792 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=99], messageTag=119, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:52:26.884 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ReadAttributesCommand [Electrical Measurement: 0/0 -> 14815/3, cluster=0B04, TID=77, identifiers=[772]]
2019-12-02 23:52:58.137 [INFO ] [el.script.Temp_Outside_MinMaxAverage] - I_Geb_OutsideTemp24HMin set to -2.3000000000000003
2019-12-02 23:52:58.169 [INFO ] [el.script.Temp_Outside_MinMaxAverage] - I_Geb_OutsideTemp24HMax set to 10.200000000000001
2019-12-02 23:52:58.193 [INFO ] [el.script.Temp_Outside_MinMaxAverage] - I_Geb_OutsideTemp24HAvg set to 2.185219410599207
2019-12-02 23:53:15.685 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Polling...
2019-12-02 23:53:15.686 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Polling zigbee:device:cc9950e6:7cb03eaa0a002e4f:7CB03EAA0A002E4F_3_switch
2019-12-02 23:53:15.686 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Mon Dec 02 23:13:18 CET 2019]
2019-12-02 23:53:15.687 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [On/Off: 0/0 -> 14815/3, cluster=0006, TID=78, identifiers=[0]]
2019-12-02 23:53:15.687 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=120, commandId=0]
2019-12-02 23:53:15.687 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=14815/3, profile=0104, cluster=6, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=120, payload=00 78 00 00 00]
2019-12-02 23:53:15.688 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=120], messageTag=120, messageContents=00 78 00 00 00]
2019-12-02 23:53:15.805 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=100]
2019-12-02 23:53:15.806 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=100]
2019-12-02 23:53:20.596 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=100], messageTag=120, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:53:20.597 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=100], messageTag=120, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:53:23.688 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ReadAttributesCommand [On/Off: 0/0 -> 14815/3, cluster=0006, TID=78, identifiers=[0]]
2019-12-02 23:53:23.690 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Polling zigbee:device:cc9950e6:7cb03eaa0a002e4f:7CB03EAA0A002E4F_3_activepower
2019-12-02 23:53:23.690 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=ELECTRICAL_MEASUREMENT, id=772, name=TotalActivePower, dataType=SIGNED_32_BIT_INTEGER, lastValue=null]
2019-12-02 23:53:23.691 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Electrical Measurement: 0/0 -> 14815/3, cluster=0B04, TID=79, identifiers=[772]]
2019-12-02 23:53:23.691 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=121, commandId=0]
2019-12-02 23:53:23.692 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=14815/3, profile=0104, cluster=2820, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=121, payload=00 79 00 04 03]
2019-12-02 23:53:23.692 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=121], messageTag=121, messageContents=00 79 00 04 03]
2019-12-02 23:53:23.806 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=101]
2019-12-02 23:53:23.806 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=101]
2019-12-02 23:53:28.603 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=101], messageTag=121, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:53:28.604 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=101], messageTag=121, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:53:31.691 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ReadAttributesCommand [Electrical Measurement: 0/0 -> 14815/3, cluster=0B04, TID=79, identifiers=[772]]
2019-12-02 23:53:58.023 [INFO ] [el.script.Temp_Outside_MinMaxAverage] - I_Geb_OutsideTemp24HMin set to -2.3000000000000003
2019-12-02 23:53:58.060 [INFO ] [el.script.Temp_Outside_MinMaxAverage] - I_Geb_OutsideTemp24HMax set to 10.200000000000001
2019-12-02 23:53:58.089 [INFO ] [el.script.Temp_Outside_MinMaxAverage] - I_Geb_OutsideTemp24HAvg set to 2.184773849656389
2019-12-02 23:54:20.489 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Polling...
2019-12-02 23:54:20.490 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Polling zigbee:device:cc9950e6:7cb03eaa0a002e4f:7CB03EAA0A002E4F_3_switch
2019-12-02 23:54:20.490 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Mon Dec 02 23:13:18 CET 2019]
2019-12-02 23:54:20.491 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [On/Off: 0/0 -> 14815/3, cluster=0006, TID=7A, identifiers=[0]]
2019-12-02 23:54:20.491 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=122, commandId=0]
2019-12-02 23:54:20.492 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=14815/3, profile=0104, cluster=6, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=122, payload=00 7A 00 00 00]
2019-12-02 23:54:20.492 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=122], messageTag=122, messageContents=00 7A 00 00 00]
2019-12-02 23:54:20.708 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=102]
2019-12-02 23:54:20.708 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=102]
2019-12-02 23:54:25.400 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=102], messageTag=122, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:54:25.401 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=102], messageTag=122, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:54:28.492 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ReadAttributesCommand [On/Off: 0/0 -> 14815/3, cluster=0006, TID=7A, identifiers=[0]]
2019-12-02 23:54:28.496 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Polling zigbee:device:cc9950e6:7cb03eaa0a002e4f:7CB03EAA0A002E4F_3_activepower
2019-12-02 23:54:28.497 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=ELECTRICAL_MEASUREMENT, id=772, name=TotalActivePower, dataType=SIGNED_32_BIT_INTEGER, lastValue=null]
2019-12-02 23:54:28.497 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Electrical Measurement: 0/0 -> 14815/3, cluster=0B04, TID=7B, identifiers=[772]]
2019-12-02 23:54:28.498 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=123, commandId=0]
2019-12-02 23:54:28.498 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=14815/3, profile=0104, cluster=2820, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=123, payload=00 7B 00 04 03]
2019-12-02 23:54:28.499 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=123], messageTag=123, messageContents=00 7B 00 04 03]
2019-12-02 23:54:28.614 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=103]
2019-12-02 23:54:28.615 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=103]
2019-12-02 23:54:33.407 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=103], messageTag=123, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:54:33.408 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=103], messageTag=123, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:54:36.498 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ReadAttributesCommand [Electrical Measurement: 0/0 -> 14815/3, cluster=0B04, TID=7B, identifiers=[772]]
2019-12-02 23:54:40.235 [INFO ] [pse.smarthome.model.script.AstroRule] - Calculated projected angle: -64.60328435777285
2019-12-02 23:54:40.236 [INFO ] [pse.smarthome.model.script.AstroRule] - Calculated projected angle: Less than 0
2019-12-02 23:54:40.238 [INFO ] [pse.smarthome.model.script.AstroRule] - Calculated projected angle for facade 1: -1.0E-4
2019-12-02 23:54:40.247 [INFO ] [pse.smarthome.model.script.AstroRule] - Calculated projected angle: 76.14233685675414
2019-12-02 23:54:40.248 [INFO ] [e.smarthome.model.script.PowerInput4] - PowerInput4 set to 0
2019-12-02 23:54:40.250 [INFO ] [pse.smarthome.model.script.AstroRule] - Calculated projected angle for facade 2: 76.14233685675414
2019-12-02 23:54:40.255 [INFO ] [pse.smarthome.model.script.AstroRule] - Calculated projected angle: 64.60328435777285
2019-12-02 23:54:40.292 [INFO ] [pse.smarthome.model.script.AstroRule] - Calculated projected angle for facade 3: 64.60328435777285
2019-12-02 23:54:40.296 [INFO ] [pse.smarthome.model.script.AstroRule] - Calculated projected angle: -76.14233685675416
2019-12-02 23:54:40.296 [INFO ] [e.smarthome.model.script.PowerInput1] - PowerInput1 set to 0
2019-12-02 23:54:40.297 [INFO ] [pse.smarthome.model.script.AstroRule] - Calculated projected angle: Less than 0
2019-12-02 23:54:40.299 [INFO ] [pse.smarthome.model.script.AstroRule] - Calculated projected angle for facade 4: -1.0E-4
2019-12-02 23:54:40.363 [INFO ] [e.smarthome.model.script.PowerInput3] - PowerInput3 set to 0
2019-12-02 23:54:40.363 [INFO ] [e.smarthome.model.script.PowerInput2] - PowerInput2 set to 0
2019-12-02 23:54:57.922 [INFO ] [el.script.Temp_Outside_MinMaxAverage] - I_Geb_OutsideTemp24HMin set to -2.3000000000000003
2019-12-02 23:54:57.950 [INFO ] [el.script.Temp_Outside_MinMaxAverage] - I_Geb_OutsideTemp24HMax set to 10.200000000000001
2019-12-02 23:54:57.968 [INFO ] [el.script.Temp_Outside_MinMaxAverage] - I_Geb_OutsideTemp24HAvg set to 2.184427646172862
2019-12-02 23:55:25.293 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Polling...
2019-12-02 23:55:25.293 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Polling zigbee:device:cc9950e6:7cb03eaa0a002e4f:7CB03EAA0A002E4F_3_switch
2019-12-02 23:55:25.294 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Mon Dec 02 23:13:18 CET 2019]
2019-12-02 23:55:25.294 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [On/Off: 0/0 -> 14815/3, cluster=0006, TID=7C, identifiers=[0]]
2019-12-02 23:55:25.294 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=124, commandId=0]
2019-12-02 23:55:25.295 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=14815/3, profile=0104, cluster=6, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=124, payload=00 7C 00 00 00]
2019-12-02 23:55:25.295 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=124], messageTag=124, messageContents=00 7C 00 00 00]
2019-12-02 23:55:25.410 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=104]
2019-12-02 23:55:25.410 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=104]
2019-12-02 23:55:30.204 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=104], messageTag=124, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:55:30.205 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=104], messageTag=124, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:55:33.295 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ReadAttributesCommand [On/Off: 0/0 -> 14815/3, cluster=0006, TID=7C, identifiers=[0]]
2019-12-02 23:55:33.297 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Polling zigbee:device:cc9950e6:7cb03eaa0a002e4f:7CB03EAA0A002E4F_3_activepower
2019-12-02 23:55:33.297 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=ELECTRICAL_MEASUREMENT, id=772, name=TotalActivePower, dataType=SIGNED_32_BIT_INTEGER, lastValue=null]
2019-12-02 23:55:33.298 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Electrical Measurement: 0/0 -> 14815/3, cluster=0B04, TID=7D, identifiers=[772]]
2019-12-02 23:55:33.298 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=125, commandId=0]
2019-12-02 23:55:33.299 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=14815/3, profile=0104, cluster=2820, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=125, payload=00 7D 00 04 03]
2019-12-02 23:55:33.299 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=125], messageTag=125, messageContents=00 7D 00 04 03]
2019-12-02 23:55:33.515 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=105]
2019-12-02 23:55:33.515 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=105]
2019-12-02 23:55:38.205 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=105], messageTag=125, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:55:38.206 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=105], messageTag=125, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:55:41.298 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ReadAttributesCommand [Electrical Measurement: 0/0 -> 14815/3, cluster=0B04, TID=7D, identifiers=[772]]
2019-12-02 23:55:57.815 [INFO ] [el.script.Temp_Outside_MinMaxAverage] - I_Geb_OutsideTemp24HMin set to -2.3000000000000003
2019-12-02 23:55:57.846 [INFO ] [el.script.Temp_Outside_MinMaxAverage] - I_Geb_OutsideTemp24HMax set to 10.200000000000001
2019-12-02 23:55:57.864 [INFO ] [el.script.Temp_Outside_MinMaxAverage] - I_Geb_OutsideTemp24HAvg set to 2.184080661816324
2019-12-02 23:56:30.100 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Polling...
2019-12-02 23:56:30.101 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Polling zigbee:device:cc9950e6:7cb03eaa0a002e4f:7CB03EAA0A002E4F_3_switch
2019-12-02 23:56:30.101 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=true, lastReportTime=Mon Dec 02 23:13:18 CET 2019]
2019-12-02 23:56:30.102 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [On/Off: 0/0 -> 14815/3, cluster=0006, TID=7E, identifiers=[0]]
2019-12-02 23:56:30.103 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=126, commandId=0]
2019-12-02 23:56:30.103 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=14815/3, profile=0104, cluster=6, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=126, payload=00 7E 00 00 00]
2019-12-02 23:56:30.104 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=126], messageTag=126, messageContents=00 7E 00 00 00]
2019-12-02 23:56:30.220 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=106]
2019-12-02 23:56:30.220 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=106]
2019-12-02 23:56:34.719 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update
2019-12-02 23:56:34.719 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update for 000D6F000DD02801
2019-12-02 23:56:34.720 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: Update mesh
2019-12-02 23:56:34.720 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: scheduled [ROUTES, NEIGHBORS]
2019-12-02 23:56:34.721 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update for 00158D0001FF8F6A
2019-12-02 23:56:34.721 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: Update mesh
2019-12-02 23:56:34.722 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: scheduled [NEIGHBORS]
2019-12-02 23:56:34.722 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update for 7CB03EAA0A002E4F
2019-12-02 23:56:34.723 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: Update mesh
2019-12-02 23:56:34.723 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: scheduled [NEIGHBORS]
2019-12-02 23:56:35.014 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=106], messageTag=126, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:56:35.015 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=106], messageTag=126, status=EMBER_DELIVERY_FAILED, messageContents=]
2019-12-02 23:56:35.149 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: running
2019-12-02 23:56:35.149 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 39956/0, cluster=0031, TID=7F, startIndex=0]
2019-12-02 23:56:35.150 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=39956/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=127, payload=00 00]
2019-12-02 23:56:35.151 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=127], messageTag=127, messageContents=00 00]
2019-12-02 23:56:35.267 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=107]
2019-12-02 23:56:35.267 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=107]
2019-12-02 23:56:36.213 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A002E4F: Node SVC Discovery: running
2019-12-02 23:56:36.214 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 14815/0, cluster=0031, TID=80, startIndex=0]
2019-12-02 23:56:36.214 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=14815/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=128, payload=00 00]
2019-12-02 23:56:36.215 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=128], messageTag=128, messageContents=00 00]
2019-12-02 23:56:36.329 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=108]
2019-12-02 23:56:36.329 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=108]
2019-12-02 23:56:36.334 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: running
2019-12-02 23:56:36.335 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=81, startIndex=0]
2019-12-02 23:56:36.335 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=129, payload=00 00]
2019-12-02 23:56:36.336 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=129], messageTag=129, messageContents=00 00]
2019-12-02 23:56:36.486 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=109]
2019-12-02 23:56:36.487 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=109]
2019-12-02 23:56:36.489 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=109], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]
2019-12-02 23:56:36.489 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=null, radius=0, apsSecurity=false, apsCounter=109, payload=00 00]
2019-12-02 23:56:36.490 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=NULL, startIndex=0]
2019-12-02 23:56:36.503 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32818, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=110], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 10 00 0F DF 39 01 DF 39 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00]
2019-12-02 23:56:36.504 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, apsSecurity=false, apsCounter=110, payload=00 00 10 00 0F DF 39 01 DF 39 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00]
2019-12-02 23:56:36.505 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=16, startIndex=0, routingTableList=[RoutingTable [destinationAddress=14815, status=DISCOVERY_UNDERWAY, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=14815], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]
2019-12-02 23:56:36.508 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=81, startIndex=0]
2019-12-02 23:56:36.510 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=109], messageTag=129, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:56:36.510 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: ManagementRoutingRequest returned CommandResult [SUCCESS, ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=16, startIndex=0, routingTableList=[RoutingTable [destinationAddress=14815, status=DISCOVERY_UNDERWAY, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=14815], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]]
2019-12-02 23:56:36.511 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=109], messageTag=129, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:56:36.512 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=82, startIndex=15]
2019-12-02 23:56:36.512 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=130, payload=00 0F]
2019-12-02 23:56:36.513 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=130], messageTag=130, messageContents=00 0F]
2019-12-02 23:56:36.747 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=111]
2019-12-02 23:56:36.747 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=111]
2019-12-02 23:56:36.749 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=111], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 0F]
2019-12-02 23:56:36.750 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=null, radius=0, apsSecurity=false, apsCounter=111, payload=00 0F]
2019-12-02 23:56:36.750 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=NULL, startIndex=15]
2019-12-02 23:56:36.753 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32818, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=112], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 10 0F 01 00 00 03 00 00]
2019-12-02 23:56:36.754 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, apsSecurity=false, apsCounter=112, payload=00 00 10 0F 01 00 00 03 00 00]
2019-12-02 23:56:36.754 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=16, startIndex=15, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]
2019-12-02 23:56:36.755 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=82, startIndex=15]
2019-12-02 23:56:36.756 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: ManagementRoutingRequest returned CommandResult [SUCCESS, ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=16, startIndex=15, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]]
2019-12-02 23:56:36.756 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=111], messageTag=130, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:56:36.756 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: ManagementLqiRequest complete [2 routes]
2019-12-02 23:56:36.757 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=111], messageTag=130, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:56:36.757 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000DD02801: Routing table NEW: [RoutingTable [destinationAddress=14815, status=DISCOVERY_UNDERWAY, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=14815], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]
2019-12-02 23:56:36.758 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000DD02801: Routing table OLD: [RoutingTable [destinationAddress=14815, status=DISCOVERY_UNDERWAY, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=14815], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]
2019-12-02 23:56:36.759 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000DD02801: Routing table unchanged
2019-12-02 23:56:36.759 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: request ROUTES successful. Advanced to NEIGHBORS.
2019-12-02 23:56:36.759 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: running
2019-12-02 23:56:36.760 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=83, startIndex=0]
2019-12-02 23:56:36.760 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=131, payload=00 00]
2019-12-02 23:56:36.761 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=131], messageTag=131, messageContents=00 00]
2019-12-02 23:56:36.997 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=113]
2019-12-02 23:56:36.997 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=113]
2019-12-02 23:56:36.999 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=113], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00]
2019-12-02 23:56:37.000 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=null, radius=0, apsSecurity=false, apsCounter=113, payload=00 00]
2019-12-02 23:56:37.000 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=NULL, startIndex=0]
2019-12-02 23:56:37.003 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32817, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=114], lastHopLqi=255, lastHopRssi=0, sender=0, bindingIndex=255, addressIndex=255, messageContents=00 00 01 00 01 33 9A 88 7B 08 39 69 07 6A 8F FF 01 00 8D 15 00 14 9C 12 00 01 FF]
2019-12-02 23:56:37.004 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32817, addressMode=null, radius=0, apsSecurity=false, apsCounter=114, payload=00 00 01 00 01 33 9A 88 7B 08 39 69 07 6A 8F FF 01 00 8D 15 00 14 9C 12 00 01 FF]
2019-12-02 23:56:37.005 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=1, startIndex=0, neighborTableList=[NeighborTable [extendedPanId=076939087B889A33, extendedAddress=00158D0001FF8F6A, networkAddress=39956, deviceType=END_DEVICE, rxOnWhenIdle=RX_OFF, relationship=CHILD, permitJoining=DISABLED, depth=1, lqi=255]]]
2019-12-02 23:56:37.005 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=83, startIndex=0]
2019-12-02 23:56:37.006 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: 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=076939087B889A33, extendedAddress=00158D0001FF8F6A, networkAddress=39956, deviceType=END_DEVICE, rxOnWhenIdle=RX_OFF, relationship=CHILD, permitJoining=DISABLED, depth=1, lqi=255]]]]
2019-12-02 23:56:37.007 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=113], messageTag=131, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:56:37.007 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: ManagementLqiRequest complete [1 neighbors]
2019-12-02 23:56:37.007 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=113], messageTag=131, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:56:37.007 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000DD02801: Neighbor table unchanged
2019-12-02 23:56:37.008 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: request NEIGHBORS successful. Advanced to null.
2019-12-02 23:56:37.008 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: running
2019-12-02 23:56:37.009 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DD02801: Node SVC Discovery: complete
2019-12-02 23:56:37.010 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6F000DD02801: Node 0 update
2019-12-02 23:56:37.013 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2019-12-02 23:56:37.066 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2019-12-02 23:56:38.102 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ReadAttributesCommand [On/Off: 0/0 -> 14815/3, cluster=0006, TID=7E, identifiers=[0]]
2019-12-02 23:56:38.103 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A002E4F: Polling zigbee:device:cc9950e6:7cb03eaa0a002e4f:7CB03EAA0A002E4F_3_activepower
2019-12-02 23:56:38.103 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=ELECTRICAL_MEASUREMENT, id=772, name=TotalActivePower, dataType=SIGNED_32_BIT_INTEGER, lastValue=null]
2019-12-02 23:56:38.104 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Electrical Measurement: 0/0 -> 14815/3, cluster=0B04, TID=84, identifiers=[772]]
2019-12-02 23:56:38.104 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=132, commandId=0]
2019-12-02 23:56:38.105 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=14815/3, profile=0104, cluster=2820, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=132, payload=00 84 00 04 03]
2019-12-02 23:56:38.105 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=14815, apsFrame=EmberApsFrame [profileId=260, clusterId=2820, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=132], messageTag=132, messageContents=00 84 00 04 03]
2019-12-02 23:56:38.221 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=115]
2019-12-02 23:56:38.221 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=115]
2019-12-02 23:56:39.642 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=107], messageTag=127, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:56:39.643 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=39956, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=107], messageTag=127, status=EMBER_SUCCESS, messageContents=]
2019-12-02 23:56:39.646 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32817, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=134], lastHopLqi=255, lastHopRssi=-36, sender=39956, bindingIndex=255, addressIndex=255, messageContents=00 00 01 00 01 33 9A 88 7B 08 39 69 07 01 28 D0 0D 00 6F 0D 00 00 00 04 02 00 6B]
2019-12-02 23:56:39.647 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=39956/0, destinationAddress=0/0, profile=0000, cluster=32817, addressMode=null, radius=0, apsSecurity=false, apsCounter=134, payload=00 00 01 00 01 33 9A 88 7B 08 39 69 07 01 28 D0 0D 00 6F 0D 00 00 00 04 02 00 6B]
2019-12-02 23:56:39.647 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [39956/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=1, startIndex=0, neighborTableList=[NeighborTable [extendedPanId=076939087B889A33, extendedAddress=000D6F000DD02801, networkAddress=0, deviceType=COORDINATOR, rxOnWhenIdle=RX_ON, relationship=PARENT, permitJoining=UNKNOWN, depth=0, lqi=107]]]
2019-12-02 23:56:39.649 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementLqiRequest [0/0 -> 39956/0, cluster=0031, TID=7F, startIndex=0]
2019-12-02 23:56:39.650 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: ManagementLqiRequest response CommandResult [SUCCESS, ManagementLqiResponse [39956/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=1, startIndex=0, neighborTableList=[NeighborTable [extendedPanId=076939087B889A33, extendedAddress=000D6F000DD02801, networkAddress=0, deviceType=COORDINATOR, rxOnWhenIdle=RX_ON, relationship=PARENT, permitJoining=UNKNOWN, depth=0, lqi=107]]]]
2019-12-02 23:56:39.651 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: ManagementLqiRequest complete [1 neighbors]
2019-12-02 23:56:39.652 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 00158D0001FF8F6A: Neighbor table updated: [NeighborTable [extendedPanId=076939087B889A33, extendedAddress=000D6F000DD02801, networkAddress=0, deviceType=COORDINATOR, rxOnWhenIdle=RX_ON, relationship=PARENT, permitJoining=UNKNOWN, depth=0, lqi=107]]
2019-12-02 23:56:39.652 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: request NEIGHBORS successful. Advanced to null.
2019-12-02 23:56:39.653 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: running
2019-12-02 23:56:39.654 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0001FF8F6A: Node SVC Discovery: complete
2019-12-02 23:56:39.654 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00158D0001FF8F6A: Node 39956 update
2019-12-02 23:56:39.657 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2019-12-02 23:56:39.700 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.