2019-06-18 12:29:26.231 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=38949, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=208], messageTag=190, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:26.235 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=38949, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=208], messageTag=190, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:26.818 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=209], messageTag=191, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:26.821 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=209], messageTag=191, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:26.939 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=210], messageTag=192, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:26.943 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=210], messageTag=192, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:27.906 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0, clusterId=6, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=182], lastHopLqi=255, lastHopRssi=-60, sender=54214, bindingIndex=255, addressIndex=255, messageContents=47 FD FF 04 01 01 19 00 00] 2019-06-18 12:29:27.910 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=54214/0, destinationAddress=0/0, profile=0000, cluster=6, addressMode=null, radius=0, apsSecurity=false, apsCounter=182, payload=47 FD FF 04 01 01 19 00 00] 2019-06-18 12:29:27.913 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: MatchDescriptorRequest [54214/0 -> 0/0, cluster=0006, TID=NULL, nwkAddrOfInterest=65533, profileId=260, inClusterList=[25], outClusterList=[]] 2019-06-18 12:29:27.923 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - DEDF7EC48B36116E: ClusterMatcher received request MatchDescriptorRequest [54214/0 -> 0/0, cluster=0006, TID=NULL, nwkAddrOfInterest=65533, profileId=260, inClusterList=[25], outClusterList=[]] 2019-06-18 12:29:27.931 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - DEDF7EC48B36116E: ClusterMatcher sending match MatchDescriptorResponse [null -> 54214/0, cluster=8006, TID=NULL, status=SUCCESS, nwkAddrOfInterest=65533, matchList=[1]] 2019-06-18 12:29:27.934 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: MatchDescriptorResponse [0/0 -> 54214/0, cluster=8006, TID=C1, status=SUCCESS, nwkAddrOfInterest=65533, matchList=[1]] 2019-06-18 12:29:27.938 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=54214/0, profile=0000, cluster=32774, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=193, payload=00 00 FD FF 01 01] 2019-06-18 12:29:27.942 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=54214, apsFrame=EmberApsFrame [profileId=0, clusterId=32774, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=193], messageTag=193, messageContents=00 00 FD FF 01 01] 2019-06-18 12:29:28.073 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=211] 2019-06-18 12:29:28.076 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=211] 2019-06-18 12:29:28.080 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=54214, apsFrame=EmberApsFrame [profileId=0, clusterId=32774, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=211], messageTag=193, status=EMBER_SUCCESS, messageContents=] 2019-06-18 12:29:28.082 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=54214, apsFrame=EmberApsFrame [profileId=0, clusterId=32774, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=211], messageTag=193, status=EMBER_SUCCESS, messageContents=] 2019-06-18 12:29:29.413 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 38949/0, cluster=0031, TID=BE, startIndex=0] 2019-06-18 12:29:29.416 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000310CE77: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:29:29.419 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000310CE77: Node SVC Discovery: request NEIGHBORS failed. Retry 2, wait 4216ms before retry. 2019-06-18 12:29:29.998 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 21242/0, cluster=0031, TID=BF, startIndex=0] 2019-06-18 12:29:30.006 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:29:30.009 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: request NEIGHBORS failed. Retry 2, wait 2114ms before retry. 2019-06-18 12:29:30.091 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 5378/0, cluster=0031, TID=C0, startIndex=0] 2019-06-18 12:29:30.094 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:29:30.097 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: request NEIGHBORS failed. Retry 2, wait 2178ms before retry. 2019-06-18 12:29:32.126 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: running 2019-06-18 12:29:32.130 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 21242/0, cluster=0031, TID=C2, startIndex=0] 2019-06-18 12:29:32.133 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=21242/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=194, payload=00 00] 2019-06-18 12:29:32.136 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=194], messageTag=194, messageContents=00 00] 2019-06-18 12:29:32.249 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=212] 2019-06-18 12:29:32.252 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=212] 2019-06-18 12:29:32.278 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: running 2019-06-18 12:29:32.282 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 5378/0, cluster=0031, TID=C3, startIndex=0] 2019-06-18 12:29:32.286 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=5378/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=195, payload=00 00] 2019-06-18 12:29:32.290 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, 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=195], messageTag=195, messageContents=00 00] 2019-06-18 12:29:32.405 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=213] 2019-06-18 12:29:32.408 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=213] 2019-06-18 12:29:33.637 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000310CE77: Node SVC Discovery: running 2019-06-18 12:29:33.641 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 38949/0, cluster=0031, TID=C4, startIndex=0] 2019-06-18 12:29:33.645 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=38949/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=196, payload=00 00] 2019-06-18 12:29:33.648 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=38949, 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=196], messageTag=196, messageContents=00 00] 2019-06-18 12:29:33.763 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=214] 2019-06-18 12:29:33.768 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=214] 2019-06-18 12:29:33.927 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=183], lastHopLqi=255, lastHopRssi=-61, sender=54214, bindingIndex=255, addressIndex=255, messageContents=48 00 00 00 00] 2019-06-18 12:29:33.932 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=54214/0, destinationAddress=0/0, profile=0000, cluster=1, addressMode=null, radius=0, apsSecurity=false, apsCounter=183, payload=48 00 00 00 00] 2019-06-18 12:29:33.936 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: IeeeAddressRequest [54214/0 -> 0/0, cluster=0001, TID=NULL, nwkAddrOfInterest=0, requestType=0, startIndex=0] 2019-06-18 12:29:36.946 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=212], messageTag=194, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:36.951 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=212], messageTag=194, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:37.209 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=213], messageTag=195, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:37.212 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=213], messageTag=195, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:37.726 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspTrustCenterJoinHandler [newNodeId=38949, newNodeEui64=00158D000310CE77, status=EMBER_DEVICE_LEFT, policyDecision=EMBER_NO_ACTION, parentOfNewNodeId=65535] 2019-06-18 12:29:37.728 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00158D000310CE77: nodeStatusUpdate - node status is DEVICE_LEFT, network address is 38949. 2019-06-18 12:29:37.732 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00158D000310CE77: Node 38949 is removed from the network 2019-06-18 12:29:37.735 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Removing discoverer for 00158D000310CE77 2019-06-18 12:29:37.751 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start. 2019-06-18 12:29:37.886 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done. 2019-06-18 12:29:38.459 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=38949, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=214], messageTag=196, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:38.461 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=38949, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=214], messageTag=196, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:39.892 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=1030, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=199], lastHopLqi=255, lastHopRssi=-58, sender=45569, bindingIndex=255, addressIndex=255, messageContents=18 81 0A 00 00 18 01] 2019-06-18 12:29:39.895 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=45569/1, destinationAddress=0/1, profile=0104, cluster=1030, addressMode=null, radius=0, apsSecurity=false, apsCounter=199, payload=18 81 0A 00 00 18 01] 2019-06-18 12:29:39.899 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=129, commandId=10] 2019-06-18 12:29:39.903 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Occupancy sensing: 45569/1 -> 0/1, cluster=0406, TID=81, reports=[Attribute Report: attributeDataType=BITMAP_8_BIT, attributeIdentifier=0, attributeValue=1]] 2019-06-18 12:29:40.131 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 21242/0, cluster=0031, TID=C2, startIndex=0] 2019-06-18 12:29:40.133 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:29:40.136 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: request NEIGHBORS failed. Retry 3, wait 4228ms before retry. 2019-06-18 12:29:40.282 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 5378/0, cluster=0031, TID=C3, startIndex=0] 2019-06-18 12:29:40.285 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:29:40.288 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: request NEIGHBORS failed. Retry 3, wait 6534ms before retry. 2019-06-18 12:29:41.641 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 38949/0, cluster=0031, TID=C4, startIndex=0] 2019-06-18 12:29:41.644 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000310CE77: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:29:41.647 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000310CE77: Node SVC Discovery: request NEIGHBORS failed. Retry 3, wait 2108ms before retry. 2019-06-18 12:29:43.760 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000310CE77: Node SVC Discovery: running 2019-06-18 12:29:43.764 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 38949/0, cluster=0031, TID=C5, startIndex=0] 2019-06-18 12:29:43.767 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=38949/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=197, payload=00 00] 2019-06-18 12:29:43.770 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=38949, 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=197], messageTag=197, messageContents=00 00] 2019-06-18 12:29:43.883 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=216] 2019-06-18 12:29:43.886 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=216] 2019-06-18 12:29:44.367 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: running 2019-06-18 12:29:44.371 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 21242/0, cluster=0031, TID=C6, startIndex=0] 2019-06-18 12:29:44.374 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=21242/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=198, payload=00 00] 2019-06-18 12:29:44.377 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=198], messageTag=198, messageContents=00 00] 2019-06-18 12:29:44.491 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=217] 2019-06-18 12:29:44.493 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=217] 2019-06-18 12:29:46.827 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: running 2019-06-18 12:29:46.830 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 5378/0, cluster=0031, TID=C7, startIndex=0] 2019-06-18 12:29:46.833 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=5378/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=199, payload=00 00] 2019-06-18 12:29:46.836 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, 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=199], messageTag=199, messageContents=00 00] 2019-06-18 12:29:46.950 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=218] 2019-06-18 12:29:46.952 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=218] 2019-06-18 12:29:48.583 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=38949, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=216], messageTag=197, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:48.595 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=38949, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=216], messageTag=197, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:49.186 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=217], messageTag=198, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:49.189 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=217], messageTag=198, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:49.902 [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_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=184], lastHopLqi=254, lastHopRssi=-59, sender=54214, bindingIndex=255, addressIndex=255, messageContents=01 A4 01 00 66 11 00 07 70 14 00 20] 2019-06-18 12:29:49.905 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=54214/1, destinationAddress=0/1, profile=0104, cluster=25, addressMode=null, radius=0, apsSecurity=false, apsCounter=184, payload=01 A4 01 00 66 11 00 07 70 14 00 20] 2019-06-18 12:29:49.915 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=164, commandId=1] 2019-06-18 12:29:49.919 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: QueryNextImageCommand [OTA Upgrade: 54214/1 -> 0/1, cluster=0019, TID=A4, fieldControl=0, manufacturerCode=4454, imageType=1792, fileVersion=536876144, hardwareVersion=null] 2019-06-18 12:29:49.928 [DEBUG] [ee.app.otaserver.ZclOtaUpgradeServer] - 54214/1 OTA Error: Invalid server state OTA_UNINITIALISED when handling QueryNextImageCommand. 2019-06-18 12:29:51.647 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=218], messageTag=199, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:51.653 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=218], messageTag=199, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:29:51.764 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 38949/0, cluster=0031, TID=C5, startIndex=0] 2019-06-18 12:29:51.774 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000310CE77: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:29:51.778 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000310CE77: Node SVC Discovery: request NEIGHBORS failed. Retry 4, wait 10540ms before retry. 2019-06-18 12:29:52.370 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 21242/0, cluster=0031, TID=C6, startIndex=0] 2019-06-18 12:29:52.376 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:29:52.380 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: request NEIGHBORS failed. Retry 4, wait 6342ms before retry. ==> /var/log/openhab2/events.log <== 2019-06-18 12:29:54.609 [vent.ItemStateChangedEvent] - ZigBeeUSBDongle_DataFramesReceived changed from 29362 to 29384 ==> /var/log/openhab2/openhab.log <== 2019-06-18 12:29:54.830 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 5378/0, cluster=0031, TID=C7, startIndex=0] 2019-06-18 12:29:54.834 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:29:54.838 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: request NEIGHBORS failed. Retry 4, wait 10890ms before retry. 2019-06-18 12:29:58.726 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: running 2019-06-18 12:29:58.729 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 21242/0, cluster=0031, TID=C8, startIndex=0] 2019-06-18 12:29:58.732 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=21242/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=200, payload=00 00] 2019-06-18 12:29:58.735 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=200], messageTag=200, messageContents=00 00] 2019-06-18 12:29:58.849 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=219] 2019-06-18 12:29:58.854 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=219] 2019-06-18 12:30:02.323 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000310CE77: Node SVC Discovery: running 2019-06-18 12:30:02.328 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 38949/0, cluster=0031, TID=C9, startIndex=0] 2019-06-18 12:30:02.332 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=38949/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=201, payload=00 00] 2019-06-18 12:30:02.337 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=38949, 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=201], messageTag=201, messageContents=00 00] 2019-06-18 12:30:02.451 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=220] 2019-06-18 12:30:02.455 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=220] 2019-06-18 12:30:03.546 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=219], messageTag=200, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:03.550 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=219], messageTag=200, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:05.731 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: running 2019-06-18 12:30:05.735 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 5378/0, cluster=0031, TID=CA, startIndex=0] 2019-06-18 12:30:05.738 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=5378/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=202, payload=00 00] 2019-06-18 12:30:05.741 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, 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=202], messageTag=202, messageContents=00 00] 2019-06-18 12:30:05.855 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=221] 2019-06-18 12:30:05.859 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=221] 2019-06-18 12:30:06.729 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 21242/0, cluster=0031, TID=C8, startIndex=0] 2019-06-18 12:30:06.737 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:30:06.740 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: request NEIGHBORS failed. Retry 5, wait 8456ms before retry. 2019-06-18 12:30:07.148 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=38949, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=220], messageTag=201, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:07.152 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=38949, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=220], messageTag=201, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:07.904 [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_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=185], lastHopLqi=255, lastHopRssi=-62, sender=54214, bindingIndex=255, addressIndex=255, messageContents=01 A5 01 00 66 11 00 07 70 14 00 20] 2019-06-18 12:30:07.909 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=54214/1, destinationAddress=0/1, profile=0104, cluster=25, addressMode=null, radius=0, apsSecurity=false, apsCounter=185, payload=01 A5 01 00 66 11 00 07 70 14 00 20] 2019-06-18 12:30:07.912 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=165, commandId=1] 2019-06-18 12:30:07.917 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: QueryNextImageCommand [OTA Upgrade: 54214/1 -> 0/1, cluster=0019, TID=A5, fieldControl=0, manufacturerCode=4454, imageType=1792, fileVersion=536876144, hardwareVersion=null] 2019-06-18 12:30:07.920 [DEBUG] [ee.app.otaserver.ZclOtaUpgradeServer] - 54214/1 OTA Error: Invalid server state OTA_UNINITIALISED when handling QueryNextImageCommand. 2019-06-18 12:30:09.011 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00158D000342D902: Polling... 2019-06-18 12:30:09.015 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00158D000342D902: Polling zigbee:device:a1db185549b3f644a5860d717257592e:00158d000342d902:00158D000342D902_1_colortemperature 2019-06-18 12:30:09.024 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=COLOR_CONTROL, id=7, name=ColorTemperature, dataType=UNSIGNED_16_BIT_INTEGER, lastValue=65535, lastReportTime=Tue Jun 18 12:29:05 CEST 2019] 2019-06-18 12:30:09.028 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Color Control: 0/0 -> 54214/1, cluster=0300, TID=CB, identifiers=[7]] 2019-06-18 12:30:09.031 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=203, commandId=0] 2019-06-18 12:30:09.034 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=54214/1, profile=0104, cluster=768, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=203, payload=00 CB 00 07 00] 2019-06-18 12:30:09.037 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=54214, apsFrame=EmberApsFrame [profileId=260, clusterId=768, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=203], messageTag=203, messageContents=00 CB 00 07 00] 2019-06-18 12:30:09.170 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=222] 2019-06-18 12:30:09.173 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=222] 2019-06-18 12:30:09.178 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=54214, apsFrame=EmberApsFrame [profileId=260, clusterId=768, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=222], messageTag=203, status=EMBER_SUCCESS, messageContents=] 2019-06-18 12:30:09.181 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=54214, apsFrame=EmberApsFrame [profileId=260, clusterId=768, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=222], messageTag=203, status=EMBER_SUCCESS, messageContents=] 2019-06-18 12:30:09.188 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=768, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=186], lastHopLqi=254, lastHopRssi=-66, sender=54214, bindingIndex=255, addressIndex=255, messageContents=18 CB 01 07 00 00 21 FF FF] 2019-06-18 12:30:09.191 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=54214/1, destinationAddress=0/1, profile=0104, cluster=768, addressMode=null, radius=0, apsSecurity=false, apsCounter=186, payload=18 CB 01 07 00 00 21 FF FF] 2019-06-18 12:30:09.194 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=203, commandId=1] 2019-06-18 12:30:09.196 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReadAttributesResponse [Color Control: 54214/1 -> 0/1, cluster=0300, TID=CB, records=[ReadAttributeStatusRecord [attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=7, status=SUCCESS, attributeValue=65535]]] 2019-06-18 12:30:09.200 [DEBUG] [rter.ZigBeeConverterColorTemperature] - 00158D000342D902: ZigBee attribute reports ZclAttribute [cluster=COLOR_CONTROL, id=7, name=ColorTemperature, dataType=UNSIGNED_16_BIT_INTEGER, lastValue=65535, lastReportTime=Tue Jun 18 12:30:09 CEST 2019] on endpoint 1 2019-06-18 12:30:09.200 [DEBUG] [.converter.ZigBeeConverterColorColor] - 00158D000342D902: ZigBee attribute reports ZclAttribute [cluster=COLOR_CONTROL, id=7, name=ColorTemperature, dataType=UNSIGNED_16_BIT_INTEGER, lastValue=65535, lastReportTime=Tue Jun 18 12:30:09 CEST 2019] 2019-06-18 12:30:09.210 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ReadAttributesCommand [Color Control: 0/0 -> 54214/1, cluster=0300, TID=CB, identifiers=[7]] 2019-06-18 12:30:10.328 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 38949/0, cluster=0031, TID=C9, startIndex=0] 2019-06-18 12:30:10.333 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000310CE77: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:30:10.336 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000310CE77: Node SVC Discovery: request NEIGHBORS failed. Retry 5, wait 6324ms before retry. 2019-06-18 12:30:10.552 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=221], messageTag=202, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:10.555 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=221], messageTag=202, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:13.735 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 5378/0, cluster=0031, TID=CA, startIndex=0] 2019-06-18 12:30:13.738 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:30:13.742 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: request NEIGHBORS failed. Retry 5, wait 8712ms before retry. 2019-06-18 12:30:15.199 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: running 2019-06-18 12:30:15.203 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 21242/0, cluster=0031, TID=CC, startIndex=0] 2019-06-18 12:30:15.206 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=21242/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=204, payload=00 00] 2019-06-18 12:30:15.208 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=204], messageTag=204, messageContents=00 00] 2019-06-18 12:30:15.322 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=223] 2019-06-18 12:30:15.324 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=223] 2019-06-18 12:30:16.664 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000310CE77: Node SVC Discovery: running 2019-06-18 12:30:16.668 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 38949/0, cluster=0031, TID=CD, startIndex=0] 2019-06-18 12:30:16.673 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=38949/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=205, payload=00 00] 2019-06-18 12:30:16.676 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=38949, 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=205], messageTag=205, messageContents=00 00] 2019-06-18 12:30:16.789 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=224] 2019-06-18 12:30:16.792 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=224] 2019-06-18 12:30:20.025 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=223], messageTag=204, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:20.029 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=223], messageTag=204, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:21.489 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=38949, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=224], messageTag=205, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:21.493 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=38949, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=224], messageTag=205, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:22.458 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: running 2019-06-18 12:30:22.462 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 5378/0, cluster=0031, TID=CE, startIndex=0] 2019-06-18 12:30:22.466 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=5378/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=206, payload=00 00] 2019-06-18 12:30:22.470 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, 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=206], messageTag=206, messageContents=00 00] 2019-06-18 12:30:22.586 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=225] 2019-06-18 12:30:22.590 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=225] 2019-06-18 12:30:23.203 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 21242/0, cluster=0031, TID=CC, startIndex=0] 2019-06-18 12:30:23.212 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:30:23.216 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: request NEIGHBORS failed. Retry 6, wait 4228ms before retry. ==> /var/log/openhab2/events.log <== 2019-06-18 12:30:24.605 [vent.ItemStateChangedEvent] - ZigBeeUSBDongle_DataFramesReceived changed from 29384 to 29399 ==> /var/log/openhab2/openhab.log <== 2019-06-18 12:30:24.668 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 38949/0, cluster=0031, TID=CD, startIndex=0] 2019-06-18 12:30:24.679 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000310CE77: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:30:24.682 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000310CE77: Node SVC Discovery: request NEIGHBORS failed. Retry 6, wait 14756ms before retry. 2019-06-18 12:30:25.901 [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_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=187], lastHopLqi=254, lastHopRssi=-63, sender=54214, bindingIndex=255, addressIndex=255, messageContents=01 A6 01 00 66 11 00 07 70 14 00 20] 2019-06-18 12:30:25.905 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=54214/1, destinationAddress=0/1, profile=0104, cluster=25, addressMode=null, radius=0, apsSecurity=false, apsCounter=187, payload=01 A6 01 00 66 11 00 07 70 14 00 20] 2019-06-18 12:30:25.908 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=166, commandId=1] 2019-06-18 12:30:25.912 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: QueryNextImageCommand [OTA Upgrade: 54214/1 -> 0/1, cluster=0019, TID=A6, fieldControl=0, manufacturerCode=4454, imageType=1792, fileVersion=536876144, hardwareVersion=null] 2019-06-18 12:30:25.916 [DEBUG] [ee.app.otaserver.ZclOtaUpgradeServer] - 54214/1 OTA Error: Invalid server state OTA_UNINITIALISED when handling QueryNextImageCommand. 2019-06-18 12:30:27.283 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=225], messageTag=206, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:27.286 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=225], messageTag=206, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:27.448 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: running 2019-06-18 12:30:27.452 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 21242/0, cluster=0031, TID=CF, startIndex=0] 2019-06-18 12:30:27.455 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=21242/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=207, payload=00 00] 2019-06-18 12:30:27.458 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=207], messageTag=207, messageContents=00 00] 2019-06-18 12:30:27.573 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=226] 2019-06-18 12:30:27.577 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=226] 2019-06-18 12:30:30.463 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 5378/0, cluster=0031, TID=CE, startIndex=0] 2019-06-18 12:30:30.466 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:30:30.470 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: request NEIGHBORS failed. Retry 6, wait 4356ms before retry. 2019-06-18 12:30:32.271 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=226], messageTag=207, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:32.275 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=226], messageTag=207, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:34.829 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: running 2019-06-18 12:30:34.833 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 5378/0, cluster=0031, TID=D0, startIndex=0] 2019-06-18 12:30:34.836 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=5378/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=208, payload=00 00] 2019-06-18 12:30:34.839 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, 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=208], messageTag=208, messageContents=00 00] 2019-06-18 12:30:34.953 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=227] 2019-06-18 12:30:34.956 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=227] 2019-06-18 12:30:35.170 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=1030, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=32], lastHopLqi=255, lastHopRssi=-35, sender=21242, bindingIndex=255, addressIndex=255, messageContents=18 DD 0A 00 00 18 01] 2019-06-18 12:30:35.173 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=21242/1, destinationAddress=0/1, profile=0104, cluster=1030, addressMode=null, radius=0, apsSecurity=false, apsCounter=32, payload=18 DD 0A 00 00 18 01] 2019-06-18 12:30:35.176 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=221, commandId=10] 2019-06-18 12:30:35.179 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Occupancy sensing: 21242/1 -> 0/1, cluster=0406, TID=DD, reports=[Attribute Report: attributeDataType=BITMAP_8_BIT, attributeIdentifier=0, attributeValue=1]] 2019-06-18 12:30:35.188 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 21242/1: Cluster 1030 not found for attribute response 2019-06-18 12:30:35.452 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 21242/0, cluster=0031, TID=CF, startIndex=0] 2019-06-18 12:30:35.456 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:30:35.459 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: request NEIGHBORS failed. Retry 7, wait 14798ms before retry. 2019-06-18 12:30:38.638 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=18, sourceEndpoint=2, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=163], lastHopLqi=255, lastHopRssi=-62, sender=22577, bindingIndex=255, addressIndex=255, messageContents=18 28 0A 55 00 21 02 00] 2019-06-18 12:30:38.641 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=22577/2, destinationAddress=0/1, profile=0104, cluster=18, addressMode=null, radius=0, apsSecurity=false, apsCounter=163, payload=18 28 0A 55 00 21 02 00] 2019-06-18 12:30:38.644 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=40, commandId=10] 2019-06-18 12:30:38.647 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Multistate Input (Basic): 22577/2 -> 0/1, cluster=0012, TID=28, reports=[Attribute Report: attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=85, attributeValue=2]] 2019-06-18 12:30:38.655 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 22577: NWK Discovery scheduling node discovery 2019-06-18 12:30:38.660 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 22577: NWK Discovery starting node discovery 2019-06-18 12:30:38.663 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 22577/0, cluster=0001, TID=D1, nwkAddrOfInterest=22577, requestType=1, startIndex=0] 2019-06-18 12:30:38.666 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=22577/0, profile=0000, cluster=1, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=209, payload=00 31 58 01 00] 2019-06-18 12:30:38.670 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=22577, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=209], messageTag=209, messageContents=00 31 58 01 00] 2019-06-18 12:30:38.784 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=228] 2019-06-18 12:30:38.787 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=228] 2019-06-18 12:30:39.442 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000310CE77: Node SVC Discovery: running 2019-06-18 12:30:39.445 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 38949/0, cluster=0031, TID=D2, startIndex=0] 2019-06-18 12:30:39.448 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=38949/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=210, payload=00 00] 2019-06-18 12:30:39.451 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=38949, 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=210], messageTag=210, messageContents=00 00] 2019-06-18 12:30:39.649 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=229] 2019-06-18 12:30:39.651 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=229] 2019-06-18 12:30:39.663 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=227], messageTag=208, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:39.666 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=227], messageTag=208, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:40.236 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=1030, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=33], lastHopLqi=255, lastHopRssi=-36, sender=21242, bindingIndex=255, addressIndex=255, messageContents=18 DE 0A 00 00 18 01] 2019-06-18 12:30:40.239 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=21242/1, destinationAddress=0/1, profile=0104, cluster=1030, addressMode=null, radius=0, apsSecurity=false, apsCounter=33, payload=18 DE 0A 00 00 18 01] 2019-06-18 12:30:40.241 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=222, commandId=10] 2019-06-18 12:30:40.245 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Occupancy sensing: 21242/1 -> 0/1, cluster=0406, TID=DE, reports=[Attribute Report: attributeDataType=BITMAP_8_BIT, attributeIdentifier=0, attributeValue=1]] 2019-06-18 12:30:40.249 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 21242/1: Cluster 1030 not found for attribute response 2019-06-18 12:30:42.832 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 5378/0, cluster=0031, TID=D0, startIndex=0] 2019-06-18 12:30:42.835 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:30:42.837 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: request NEIGHBORS failed. Retry 7, wait 10890ms before retry. 2019-06-18 12:30:43.482 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=22577, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=228], messageTag=209, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:43.487 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=22577, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=228], messageTag=209, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:44.262 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=38949, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=229], messageTag=210, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:44.268 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=38949, apsFrame=EmberApsFrame [profileId=0, clusterId=49, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=229], messageTag=210, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:46.663 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: IeeeAddressRequest [0/0 -> 22577/0, cluster=0001, TID=D1, nwkAddrOfInterest=22577, requestType=1, startIndex=0] 2019-06-18 12:30:47.445 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 38949/0, cluster=0031, TID=D2, startIndex=0] 2019-06-18 12:30:47.450 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000310CE77: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-06-18 12:30:47.454 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000310CE77: Node SVC Discovery: request NEIGHBORS failed. Retry 7, wait 14756ms before retry. 2019-06-18 12:30:48.167 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 22577/0, cluster=0001, TID=D3, nwkAddrOfInterest=22577, requestType=1, startIndex=0] 2019-06-18 12:30:48.169 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=22577/0, profile=0000, cluster=1, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=211, payload=00 31 58 01 00] 2019-06-18 12:30:48.171 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=22577, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=211], messageTag=211, messageContents=00 31 58 01 00] 2019-06-18 12:30:48.282 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=230] 2019-06-18 12:30:48.284 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=230] 2019-06-18 12:30:50.261 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D0002F900D0: Node SVC Discovery: running 2019-06-18 12:30:50.266 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 21242/0, cluster=0031, TID=D4, startIndex=0] 2019-06-18 12:30:50.269 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=21242/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=212, payload=00 00] 2019-06-18 12:30:50.272 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=212], messageTag=212, messageContents=00 00] 2019-06-18 12:30:50.386 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=231] 2019-06-18 12:30:50.388 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=231] 2019-06-18 12:30:52.982 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=22577, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=230], messageTag=211, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:52.985 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=22577, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=230], messageTag=211, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:53.406 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0, clusterId=6, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=188], lastHopLqi=255, lastHopRssi=-70, sender=54214, bindingIndex=255, addressIndex=255, messageContents=49 FD FF 04 01 01 19 00 00] 2019-06-18 12:30:53.409 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=54214/0, destinationAddress=0/0, profile=0000, cluster=6, addressMode=null, radius=0, apsSecurity=false, apsCounter=188, payload=49 FD FF 04 01 01 19 00 00] 2019-06-18 12:30:53.413 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: MatchDescriptorRequest [54214/0 -> 0/0, cluster=0006, TID=NULL, nwkAddrOfInterest=65533, profileId=260, inClusterList=[25], outClusterList=[]] 2019-06-18 12:30:53.416 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - DEDF7EC48B36116E: ClusterMatcher received request MatchDescriptorRequest [54214/0 -> 0/0, cluster=0006, TID=NULL, nwkAddrOfInterest=65533, profileId=260, inClusterList=[25], outClusterList=[]] 2019-06-18 12:30:53.429 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - DEDF7EC48B36116E: ClusterMatcher sending match MatchDescriptorResponse [null -> 54214/0, cluster=8006, TID=NULL, status=SUCCESS, nwkAddrOfInterest=65533, matchList=[1]] 2019-06-18 12:30:53.435 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: MatchDescriptorResponse [0/0 -> 54214/0, cluster=8006, TID=D5, status=SUCCESS, nwkAddrOfInterest=65533, matchList=[1]] 2019-06-18 12:30:53.438 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=54214/0, profile=0000, cluster=32774, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=213, payload=00 00 FD FF 01 01] 2019-06-18 12:30:53.442 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=54214, apsFrame=EmberApsFrame [profileId=0, clusterId=32774, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=213], messageTag=213, messageContents=00 00 FD FF 01 01] 2019-06-18 12:30:53.575 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=232] 2019-06-18 12:30:53.579 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=232] 2019-06-18 12:30:53.587 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=54214, apsFrame=EmberApsFrame [profileId=0, clusterId=32774, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=232], messageTag=213, status=EMBER_SUCCESS, messageContents=] 2019-06-18 12:30:53.590 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=54214, apsFrame=EmberApsFrame [profileId=0, clusterId=32774, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=232], messageTag=213, status=EMBER_SUCCESS, messageContents=] 2019-06-18 12:30:53.730 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00158D000309D056: Node SVC Discovery: running 2019-06-18 12:30:53.734 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 5378/0, cluster=0031, TID=D6, startIndex=0] 2019-06-18 12:30:53.737 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=5378/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=214, payload=00 00] 2019-06-18 12:30:53.740 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=5378, 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=214], messageTag=214, messageContents=00 00] 2019-06-18 12:30:53.854 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=233] 2019-06-18 12:30:53.858 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=233] ==> /var/log/openhab2/events.log <== 2019-06-18 12:30:54.608 [vent.ItemStateChangedEvent] - ZigBeeUSBDongle_DataFramesReceived changed from 29399 to 29419 ==> /var/log/openhab2/openhab.log <== 2019-06-18 12:30:55.086 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=231], messageTag=212, status=EMBER_DELIVERY_FAILED, messageContents=] 2019-06-18 12:30:55.088 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=21242, 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=231], messageTag=212, status=EMBER_DELIVERY_FAILED, messageContents=]