2020-05-10 00:55:27.504 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-55, relayList=A4A5] 2020-05-10 00:55:27.603 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=67], lastHopLqi=255, lastHopRssi=-55, sender=0DEC, bindingIndex=255, addressIndex=255, messageContents=08 43 0A 00 00 29 2E 08] 2020-05-10 00:55:27.603 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0DEC/1, destinationAddress=0000/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=67, rssi=-55, lqi=FF, payload=08 43 0A 00 00 29 2E 08] 2020-05-10 00:55:27.603 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=67, commandId=10] 2020-05-10 00:55:27.603 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=43, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=0, attributeValue=2094]]] 2020-05-10 00:55:27.603 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=43, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=0, attributeValue=2094]]] 2020-05-10 00:55:27.604 [DEBUG] [onverterThermostatOutdoorTemperature] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2094, lastReportTime=Sun May 10 00:55:27 EDT 2020, implemented=false] 2020-05-10 00:55:27.604 [DEBUG] [ZigBeeConverterThermostatRunningMode] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2094, lastReportTime=Sun May 10 00:55:27 EDT 2020, implemented=false] 2020-05-10 00:55:27.604 [DEBUG] [ConverterThermostatUnoccupiedCooling] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2094, lastReportTime=Sun May 10 00:55:27 EDT 2020, implemented=false] 2020-05-10 00:55:27.604 [DEBUG] [eeConverterThermostatOccupiedCooling] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2094, lastReportTime=Sun May 10 00:55:27 EDT 2020, implemented=false] 2020-05-10 00:55:27.604 [DEBUG] [ConverterThermostatUnoccupiedHeating] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2094, lastReportTime=Sun May 10 00:55:27 EDT 2020, implemented=false] 2020-05-10 00:55:27.604 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=43, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:55:27.604 [DEBUG] [eConverterThermostatLocalTemperature] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2094, lastReportTime=Sun May 10 00:55:27 EDT 2020, implemented=false] 2020-05-10 00:55:27.604 [DEBUG] [eeConverterThermostatOccupiedHeating] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2094, lastReportTime=Sun May 10 00:55:27 EDT 2020, implemented=false] 2020-05-10 00:55:27.604 [DEBUG] [.ZigBeeConverterThermostatSystemMode] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2094, lastReportTime=Sun May 10 00:55:27 EDT 2020, implemented=false] 2020-05-10 00:55:27.604 [DEBUG] [transaction.ZigBeeTransactionManager] - 0DEC/1: Sending ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=43, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:55:27.604 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 000D6F00036B0BA5: Channel zigbee:device:5e4256a6:000d6f00036b0ba5:000D6F00036B0BA5_1_thermostatlocaltemp updated to 20.94 °C 2020-05-10 00:55:27.604 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding 2020-05-10 00:55:27.604 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000D6F00036B0BA5: Updating ZigBee channel state zigbee:device:5e4256a6:000d6f00036b0ba5:000D6F00036B0BA5_1_thermostatlocaltemp to 20.94 °C 2020-05-10 00:55:27.604 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=43, commandIdentifier=10, statusCode=SUCCESS] 2020-05-10 00:55:27.604 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=67, commandId=11] 2020-05-10 00:55:27.604 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=0DEC/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=D2, rssi=--, lqi=--, payload=10 43 0B 0A 00] 2020-05-10 00:55:27.605 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 2020-05-10 00:55:27.605 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Canceling timeout task for thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 2020-05-10 00:55:27.605 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Scheduling timeout task for thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 in 14430 seconds 2020-05-10 00:55:27.623 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=15] 2020-05-10 00:55:29.519 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:55:29.595 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=3564, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=15], messageTag=43, status=EMBER_SUCCESS, messageContents=] 2020-05-10 00:55:29.595 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=43 state=RX_ACK 2020-05-10 00:55:29.595 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=43, state=RX_ACK, outstanding=1 2020-05-10 00:55:29.595 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=1991, state=COMPLETE, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=43, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:55:29.595 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding 2020-05-10 00:55:29.595 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: transactionComplete COMPLETE 0 2020-05-10 00:55:29.596 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 43 -> RX_ACK == COMPLETE 2020-05-10 00:55:30.519 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-55, relayList=A4A5] 2020-05-10 00:56:02.952 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=0F], lastHopLqi=255, lastHopRssi=-72, sender=8E93, bindingIndex=255, addressIndex=255, messageContents=79 FD FF 04 01 01 19 00 00] 2020-05-10 00:56:02.952 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=8E93/0, destinationAddress=0000/0, profile=0000, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=0F, rssi=-72, lqi=FF, payload=79 FD FF 04 01 01 19 00 00] 2020-05-10 00:56:02.952 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: MatchDescriptorRequest [8E93/0 -> 0000/0, cluster=0006, TID=79, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]] 2020-05-10 00:56:02.952 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: MatchDescriptorRequest [8E93/0 -> 0000/0, cluster=0006, TID=79, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]] 2020-05-10 00:56:02.952 [DEBUG] [stems.zigbee.internal.ClusterMatcher] - 228832E9670B3745: ClusterMatcher received request MatchDescriptorRequest [8E93/0 -> 0000/0, cluster=0006, TID=79, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]] 2020-05-10 00:56:02.953 [DEBUG] [stems.zigbee.internal.ClusterMatcher] - 228832E9670B3745: ClusterMatcher sending match MatchDescriptorResponse [null -> 8E93/0, cluster=8006, TID=79, status=SUCCESS, nwkAddrOfInterest=0000, matchList=[1]] 2020-05-10 00:56:02.953 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F000B1B5AA9: Added transaction to queue, len=2, transaction=ZigBeeTransaction [ieeeAddress=000D6F000B1B5AA9 queueTime=0, state=WAITING, sendCnt=0, command=MatchDescriptorResponse [0000/0 -> 8E93/0, cluster=8006, TID=79, status=SUCCESS, nwkAddrOfInterest=0000, matchList=[1]]] 2020-05-10 00:56:02.953 [DEBUG] [transaction.ZigBeeTransactionManager] - 8E93/0: Sending ZigBeeTransaction [ieeeAddress=000D6F000B1B5AA9 queueTime=586342, state=WAITING, sendCnt=1, command=MatchDescriptorResponse [0000/0 -> 8E93/0, cluster=8006, TID=78, status=SUCCESS, nwkAddrOfInterest=0000, matchList=[1]]] 2020-05-10 00:56:02.953 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding 2020-05-10 00:56:02.953 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: MatchDescriptorResponse [0000/0 -> 8E93/0, cluster=8006, TID=78, status=SUCCESS, nwkAddrOfInterest=0000, matchList=[1]] 2020-05-10 00:56:02.953 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=8E93/0, profile=0000, cluster=8006, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=D3, rssi=--, lqi=--, payload=78 00 00 00 01 01] 2020-05-10 00:56:02.964 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=16] 2020-05-10 00:56:07.654 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=36499, apsFrame=EmberApsFrame [profileId=0000, clusterId=8006, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=16], messageTag=78, status=EMBER_DELIVERY_FAILED, messageContents=] 2020-05-10 00:56:07.654 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=78 state=RX_NAK 2020-05-10 00:56:07.654 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=78, state=RX_NAK, outstanding=1 2020-05-10 00:56:07.655 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6F000B1B5AA9 queueTime=591044, state=FAILED, sendCnt=2, command=MatchDescriptorResponse [0000/0 -> 8E93/0, cluster=8006, TID=78, status=SUCCESS, nwkAddrOfInterest=0000, matchList=[1]]] 2020-05-10 00:56:07.655 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding 2020-05-10 00:56:07.655 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F000B1B5AA9: transactionComplete FAILED 0 2020-05-10 00:56:07.655 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F000B1B5AA9: transactionComplete exceeded retries 2 2020-05-10 00:56:07.655 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction terminated: ZigBeeTransaction [ieeeAddress=000D6F000B1B5AA9 queueTime=591044, state=FAILED, sendCnt=2, command=MatchDescriptorResponse [0000/0 -> 8E93/0, cluster=8006, TID=78, status=SUCCESS, nwkAddrOfInterest=0000, matchList=[1]]] 2020-05-10 00:56:07.655 [DEBUG] [transaction.ZigBeeTransactionManager] - 8E93/0: Sending ZigBeeTransaction [ieeeAddress=000D6F000B1B5AA9 queueTime=4702, state=WAITING, sendCnt=0, command=MatchDescriptorResponse [0000/0 -> 8E93/0, cluster=8006, TID=79, status=SUCCESS, nwkAddrOfInterest=0000, matchList=[1]]] 2020-05-10 00:56:07.655 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding 2020-05-10 00:56:07.655 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: MatchDescriptorResponse [0000/0 -> 8E93/0, cluster=8006, TID=79, status=SUCCESS, nwkAddrOfInterest=0000, matchList=[1]] 2020-05-10 00:56:07.655 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=8E93/0, profile=0000, cluster=8006, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=D4, rssi=--, lqi=--, payload=79 00 00 00 01 01] 2020-05-10 00:56:07.656 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 78 -> RX_NAK == FAILED 2020-05-10 00:56:07.666 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=17] 2020-05-10 00:56:11.904 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:56:11.982 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=000A, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=68], lastHopLqi=255, lastHopRssi=-56, sender=0DEC, bindingIndex=255, addressIndex=255, messageContents=00 44 00 07 00] 2020-05-10 00:56:11.982 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0DEC/1, destinationAddress=0000/1, profile=0104, cluster=000A, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=68, rssi=-56, lqi=FF, payload=00 44 00 07 00] 2020-05-10 00:56:11.982 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=68, commandId=0] 2020-05-10 00:56:11.983 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Unsupported local server cluster 000A 2020-05-10 00:56:11.983 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Time: 0000/0 -> 0DEC/1, cluster=000A, TID=44, commandIdentifier=0, statusCode=FAILURE]] 2020-05-10 00:56:11.983 [DEBUG] [transaction.ZigBeeTransactionManager] - 0DEC/1: Sending ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Time: 0000/0 -> 0DEC/1, cluster=000A, TID=44, commandIdentifier=0, statusCode=FAILURE]] 2020-05-10 00:56:11.983 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding 2020-05-10 00:56:11.983 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Time: 0000/0 -> 0DEC/1, cluster=000A, TID=44, commandIdentifier=0, statusCode=FAILURE] 2020-05-10 00:56:11.983 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=68, commandId=11] 2020-05-10 00:56:11.983 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=0DEC/1, profile=0104, cluster=000A, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=D5, rssi=--, lqi=--, payload=18 44 0B 00 01] 2020-05-10 00:56:11.983 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Incoming message from node 0DEC did not translate to command 2020-05-10 00:56:11.996 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=18] 2020-05-10 00:56:12.356 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=36499, apsFrame=EmberApsFrame [profileId=0000, clusterId=8006, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=17], messageTag=79, status=EMBER_DELIVERY_FAILED, messageContents=] 2020-05-10 00:56:12.356 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=79 state=RX_NAK 2020-05-10 00:56:12.356 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=79, state=RX_NAK, outstanding=2 2020-05-10 00:56:12.356 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6F000B1B5AA9 queueTime=9403, state=FAILED, sendCnt=1, command=MatchDescriptorResponse [0000/0 -> 8E93/0, cluster=8006, TID=79, status=SUCCESS, nwkAddrOfInterest=0000, matchList=[1]]] 2020-05-10 00:56:12.356 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding 2020-05-10 00:56:12.356 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F000B1B5AA9: transactionComplete FAILED 0 2020-05-10 00:56:12.356 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F000B1B5AA9: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6F000B1B5AA9 queueTime=9403, state=WAITING, sendCnt=1, command=MatchDescriptorResponse [0000/0 -> 8E93/0, cluster=8006, TID=79, status=SUCCESS, nwkAddrOfInterest=0000, matchList=[1]]] 2020-05-10 00:56:12.357 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 79 -> RX_NAK == WAITING 2020-05-10 00:56:13.923 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:56:14.001 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=3564, apsFrame=EmberApsFrame [profileId=0104, clusterId=000A, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=18], messageTag=44, status=EMBER_SUCCESS, messageContents=] 2020-05-10 00:56:14.001 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=44 state=RX_ACK 2020-05-10 00:56:14.001 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=44, state=RX_ACK, outstanding=1 2020-05-10 00:56:14.002 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=2019, state=COMPLETE, sendCnt=1, command=DefaultResponse [Time: 0000/0 -> 0DEC/1, cluster=000A, TID=44, commandIdentifier=0, statusCode=FAILURE]] 2020-05-10 00:56:14.002 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding 2020-05-10 00:56:14.002 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: transactionComplete COMPLETE 0 2020-05-10 00:56:14.002 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 44 -> RX_ACK == COMPLETE 2020-05-10 00:56:14.924 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:56:15.927 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=254, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:56:24.975 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=144B, sourceEui=00178801032AF6F2, lastHopLqi=255, lastHopRssi=-72, relayList=0D0D] 2020-05-10 00:56:25.059 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0400, sourceEndpoint=2, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=57], lastHopLqi=255, lastHopRssi=-72, sender=144B, bindingIndex=255, addressIndex=255, messageContents=08 16 0A 00 00 21 00 00] 2020-05-10 00:56:25.059 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=144B/2, destinationAddress=0000/1, profile=0104, cluster=0400, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=57, rssi=-72, lqi=FF, payload=08 16 0A 00 00 21 00 00] 2020-05-10 00:56:25.059 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=22, commandId=10] 2020-05-10 00:56:25.059 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Illuminance Measurement: 144B/2 -> 0000/1, cluster=0400, TID=16, reports=[AttributeReport [attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=0, attributeValue=0]]] 2020-05-10 00:56:25.059 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Illuminance Measurement: 144B/2 -> 0000/1, cluster=0400, TID=16, reports=[AttributeReport [attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=0, attributeValue=0]]] 2020-05-10 00:56:25.060 [DEBUG] [converter.ZigBeeConverterIlluminance] - 00178801032AF6F2: ZigBee attribute reports ZclAttribute [cluster=Illuminance Measurement, id=0, name=Measured Value, dataType=UNSIGNED_16_BIT_INTEGER, lastValue=0, lastReportTime=Sun May 10 00:56:25 EDT 2020, implemented=false] 2020-05-10 00:56:25.060 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00178801032AF6F2: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00178801032AF6F2 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Illuminance Measurement: 0000/0 -> 144B/2, cluster=0400, TID=16, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:56:25.060 [DEBUG] [converter.ZigBeeConverterIlluminance] - 00178801032AF6F2: ZigBee attribute reports ZclAttribute [cluster=Illuminance Measurement, id=0, name=Measured Value, dataType=UNSIGNED_16_BIT_INTEGER, lastValue=0, lastReportTime=Sun May 10 00:56:25 EDT 2020, implemented=false] 2020-05-10 00:56:25.060 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 00178801032AF6F2: Channel zigbee:device:5e4256a6:00178801032af6f2:00178801032AF6F2_2_illuminance updated to 0.0 2020-05-10 00:56:25.060 [DEBUG] [transaction.ZigBeeTransactionManager] - 144B/2: Sending ZigBeeTransaction [ieeeAddress=00178801032AF6F2 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Illuminance Measurement: 0000/0 -> 144B/2, cluster=0400, TID=16, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:56:25.060 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 00178801032AF6F2: Channel zigbee:philips_sml001:5e4256a6:00178801032af6f2:illuminance updated to 0.0 2020-05-10 00:56:25.060 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00178801032AF6F2: Updating ZigBee channel state zigbee:device:5e4256a6:00178801032af6f2:00178801032AF6F2_2_illuminance to 0.0 2020-05-10 00:56:25.060 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding 2020-05-10 00:56:25.060 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00178801032AF6F2: Updating ZigBee channel state zigbee:philips_sml001:5e4256a6:00178801032af6f2:illuminance to 0.0 2020-05-10 00:56:25.060 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Illuminance Measurement: 0000/0 -> 144B/2, cluster=0400, TID=16, commandIdentifier=10, statusCode=SUCCESS] 2020-05-10 00:56:25.060 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:5e4256a6:00178801032af6f2 2020-05-10 00:56:25.060 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=22, commandId=11] 2020-05-10 00:56:25.060 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Canceling timeout task for thingUID=zigbee:device:5e4256a6:00178801032af6f2 2020-05-10 00:56:25.060 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=144B/2, profile=0104, cluster=0400, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=D6, rssi=--, lqi=--, payload=10 16 0B 0A 00] 2020-05-10 00:56:25.060 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Scheduling timeout task for thingUID=zigbee:device:5e4256a6:00178801032af6f2 in 1830 seconds 2020-05-10 00:56:25.060 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:philips_sml001:5e4256a6:00178801032af6f2 2020-05-10 00:56:25.061 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Canceling timeout task for thingUID=zigbee:philips_sml001:5e4256a6:00178801032af6f2 2020-05-10 00:56:25.061 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Scheduling timeout task for thingUID=zigbee:philips_sml001:5e4256a6:00178801032af6f2 in 1830 seconds 2020-05-10 00:56:25.071 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=19] 2020-05-10 00:56:26.499 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=144B, sourceEui=00178801032AF6F2, lastHopLqi=255, lastHopRssi=-72, relayList=0D0D] 2020-05-10 00:56:26.576 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=5195, apsFrame=EmberApsFrame [profileId=0104, clusterId=0400, sourceEndpoint=1, destinationEndpoint=2, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=19], messageTag=16, status=EMBER_SUCCESS, messageContents=] 2020-05-10 00:56:26.576 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=16 state=RX_ACK 2020-05-10 00:56:26.576 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=16, state=RX_ACK, outstanding=1 2020-05-10 00:56:26.576 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00178801032AF6F2 queueTime=1516, state=COMPLETE, sendCnt=1, command=DefaultResponse [Illuminance Measurement: 0000/0 -> 144B/2, cluster=0400, TID=16, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:56:26.576 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding 2020-05-10 00:56:26.577 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00178801032AF6F2: transactionComplete COMPLETE 0 2020-05-10 00:56:26.577 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 16 -> RX_ACK == COMPLETE 2020-05-10 00:56:27.501 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=254, lastHopRssi=-59, relayList=A4A5] 2020-05-10 00:56:27.585 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=69], lastHopLqi=255, lastHopRssi=-56, sender=0DEC, bindingIndex=255, addressIndex=255, messageContents=08 45 0A 00 00 29 28 08] 2020-05-10 00:56:27.585 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0DEC/1, destinationAddress=0000/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=69, rssi=-56, lqi=FF, payload=08 45 0A 00 00 29 28 08] 2020-05-10 00:56:27.585 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=69, commandId=10] 2020-05-10 00:56:27.585 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=45, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=0, attributeValue=2088]]] 2020-05-10 00:56:27.585 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=45, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=0, attributeValue=2088]]] 2020-05-10 00:56:27.586 [DEBUG] [ZigBeeConverterThermostatRunningMode] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2088, lastReportTime=Sun May 10 00:56:27 EDT 2020, implemented=false] 2020-05-10 00:56:27.586 [DEBUG] [onverterThermostatOutdoorTemperature] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2088, lastReportTime=Sun May 10 00:56:27 EDT 2020, implemented=false] 2020-05-10 00:56:27.586 [DEBUG] [ConverterThermostatUnoccupiedCooling] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2088, lastReportTime=Sun May 10 00:56:27 EDT 2020, implemented=false] 2020-05-10 00:56:27.586 [DEBUG] [eeConverterThermostatOccupiedCooling] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2088, lastReportTime=Sun May 10 00:56:27 EDT 2020, implemented=false] 2020-05-10 00:56:27.586 [DEBUG] [ConverterThermostatUnoccupiedHeating] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2088, lastReportTime=Sun May 10 00:56:27 EDT 2020, implemented=false] 2020-05-10 00:56:27.586 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=45, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:56:27.586 [DEBUG] [eeConverterThermostatOccupiedHeating] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2088, lastReportTime=Sun May 10 00:56:27 EDT 2020, implemented=false] 2020-05-10 00:56:27.586 [DEBUG] [eConverterThermostatLocalTemperature] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2088, lastReportTime=Sun May 10 00:56:27 EDT 2020, implemented=false] 2020-05-10 00:56:27.586 [DEBUG] [.ZigBeeConverterThermostatSystemMode] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2088, lastReportTime=Sun May 10 00:56:27 EDT 2020, implemented=false] 2020-05-10 00:56:27.586 [DEBUG] [transaction.ZigBeeTransactionManager] - 0DEC/1: Sending ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=45, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:56:27.586 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 000D6F00036B0BA5: Channel zigbee:device:5e4256a6:000d6f00036b0ba5:000D6F00036B0BA5_1_thermostatlocaltemp updated to 20.88 °C 2020-05-10 00:56:27.586 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding 2020-05-10 00:56:27.586 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000D6F00036B0BA5: Updating ZigBee channel state zigbee:device:5e4256a6:000d6f00036b0ba5:000D6F00036B0BA5_1_thermostatlocaltemp to 20.88 °C 2020-05-10 00:56:27.586 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=45, commandIdentifier=10, statusCode=SUCCESS] 2020-05-10 00:56:27.586 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=69, commandId=11] 2020-05-10 00:56:27.586 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=0DEC/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=D7, rssi=--, lqi=--, payload=10 45 0B 0A 00] 2020-05-10 00:56:27.587 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 2020-05-10 00:56:27.587 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Canceling timeout task for thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 2020-05-10 00:56:27.587 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Scheduling timeout task for thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 in 14430 seconds 2020-05-10 00:56:27.597 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=1A] 2020-05-10 00:56:29.521 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-58, relayList=A4A5] 2020-05-10 00:56:29.602 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=3564, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=1A], messageTag=45, status=EMBER_SUCCESS, messageContents=] 2020-05-10 00:56:29.602 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=45 state=RX_ACK 2020-05-10 00:56:29.602 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=45, state=RX_ACK, outstanding=1 2020-05-10 00:56:29.602 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=2016, state=COMPLETE, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=45, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:56:29.602 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding 2020-05-10 00:56:29.602 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: transactionComplete COMPLETE 0 2020-05-10 00:56:29.603 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 45 -> RX_ACK == COMPLETE 2020-05-10 00:56:30.519 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=253, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:56:42.504 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:56:42.594 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=6A], lastHopLqi=255, lastHopRssi=-55, sender=0DEC, bindingIndex=255, addressIndex=255, messageContents=08 46 0A 00 00 29 23 08] 2020-05-10 00:56:42.594 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0DEC/1, destinationAddress=0000/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=6A, rssi=-55, lqi=FF, payload=08 46 0A 00 00 29 23 08] 2020-05-10 00:56:42.594 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=70, commandId=10] 2020-05-10 00:56:42.594 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=46, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=0, attributeValue=2083]]] 2020-05-10 00:56:42.594 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=46, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=0, attributeValue=2083]]] 2020-05-10 00:56:42.595 [DEBUG] [ConverterThermostatUnoccupiedCooling] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2083, lastReportTime=Sun May 10 00:56:42 EDT 2020, implemented=false] 2020-05-10 00:56:42.595 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=46, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:56:42.595 [DEBUG] [onverterThermostatOutdoorTemperature] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2083, lastReportTime=Sun May 10 00:56:42 EDT 2020, implemented=false] 2020-05-10 00:56:42.595 [DEBUG] [ZigBeeConverterThermostatRunningMode] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2083, lastReportTime=Sun May 10 00:56:42 EDT 2020, implemented=false] 2020-05-10 00:56:42.595 [DEBUG] [eeConverterThermostatOccupiedCooling] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2083, lastReportTime=Sun May 10 00:56:42 EDT 2020, implemented=false] 2020-05-10 00:56:42.595 [DEBUG] [ConverterThermostatUnoccupiedHeating] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2083, lastReportTime=Sun May 10 00:56:42 EDT 2020, implemented=false] 2020-05-10 00:56:42.595 [DEBUG] [eConverterThermostatLocalTemperature] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2083, lastReportTime=Sun May 10 00:56:42 EDT 2020, implemented=false] 2020-05-10 00:56:42.595 [DEBUG] [transaction.ZigBeeTransactionManager] - 0DEC/1: Sending ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=1, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=46, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:56:42.595 [DEBUG] [eeConverterThermostatOccupiedHeating] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2083, lastReportTime=Sun May 10 00:56:42 EDT 2020, implemented=false] 2020-05-10 00:56:42.595 [DEBUG] [.ZigBeeConverterThermostatSystemMode] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2083, lastReportTime=Sun May 10 00:56:42 EDT 2020, implemented=false] 2020-05-10 00:56:42.595 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding 2020-05-10 00:56:42.595 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 000D6F00036B0BA5: Channel zigbee:device:5e4256a6:000d6f00036b0ba5:000D6F00036B0BA5_1_thermostatlocaltemp updated to 20.83 °C 2020-05-10 00:56:42.595 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=46, commandIdentifier=10, statusCode=SUCCESS] 2020-05-10 00:56:42.595 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000D6F00036B0BA5: Updating ZigBee channel state zigbee:device:5e4256a6:000d6f00036b0ba5:000D6F00036B0BA5_1_thermostatlocaltemp to 20.83 °C 2020-05-10 00:56:42.595 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=70, commandId=11] 2020-05-10 00:56:42.595 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=0DEC/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=D8, rssi=--, lqi=--, payload=10 46 0B 0A 00] 2020-05-10 00:56:42.595 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 2020-05-10 00:56:42.595 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Canceling timeout task for thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 2020-05-10 00:56:42.596 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Scheduling timeout task for thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 in 14430 seconds 2020-05-10 00:56:42.607 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=1B] 2020-05-10 00:56:44.527 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:56:44.605 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=3564, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=1B], messageTag=46, status=EMBER_SUCCESS, messageContents=] 2020-05-10 00:56:44.605 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=46 state=RX_ACK 2020-05-10 00:56:44.605 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=46, state=RX_ACK, outstanding=1 2020-05-10 00:56:44.605 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=2011, state=COMPLETE, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=46, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:56:44.605 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding 2020-05-10 00:56:44.606 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: transactionComplete COMPLETE 0 2020-05-10 00:56:44.606 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 46 -> RX_ACK == COMPLETE 2020-05-10 00:56:45.527 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:56:56.697 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000D6F00036B0BA5: Command for channel zigbee:device:5e4256a6:000d6f00036b0ba5:000D6F00036B0BA5_1_thermostatoccupiedheating --> 70 °F [QuantityType] 2020-05-10 00:56:56.698 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - 000D6F00036B0BA5: Writing Server cluster 513, attribute 18, value 2112, as dataType SIGNED_16_BIT_INTEGER 2020-05-10 00:56:56.698 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=WriteAttributesCommand [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=--, records=[WriteAttributeRecord [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]]] 2020-05-10 00:56:56.698 [DEBUG] [transaction.ZigBeeTransactionManager] - 0DEC/1: Sending ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=WriteAttributesCommand [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, records=[WriteAttributeRecord [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]]] 2020-05-10 00:56:56.698 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding 2020-05-10 00:56:56.699 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: WriteAttributesCommand [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, records=[WriteAttributeRecord [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]] 2020-05-10 00:56:56.699 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=53, commandId=2] 2020-05-10 00:56:56.699 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=0DEC/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=D9, rssi=--, lqi=--, payload=00 35 02 12 00 29 40 08] 2020-05-10 00:56:56.712 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=1C] 2020-05-10 00:56:57.505 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:56:57.599 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=6B], lastHopLqi=255, lastHopRssi=-56, sender=0DEC, bindingIndex=255, addressIndex=255, messageContents=08 47 0A 00 00 29 28 08] 2020-05-10 00:56:57.599 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0DEC/1, destinationAddress=0000/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=6B, rssi=-56, lqi=FF, payload=08 47 0A 00 00 29 28 08] 2020-05-10 00:56:57.599 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=71, commandId=10] 2020-05-10 00:56:57.599 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=47, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=0, attributeValue=2088]]] 2020-05-10 00:56:57.599 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=47, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=0, attributeValue=2088]]] 2020-05-10 00:56:57.599 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=47, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=0, attributeValue=2088]]] ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=901, state=DISPATCHED, sendCnt=1, command=WriteAttributesCommand [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, records=[WriteAttributeRecord [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]]] 2020-05-10 00:56:57.600 [DEBUG] [ZigBeeConverterThermostatRunningMode] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2088, lastReportTime=Sun May 10 00:56:57 EDT 2020, implemented=false] 2020-05-10 00:56:57.600 [DEBUG] [onverterThermostatOutdoorTemperature] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2088, lastReportTime=Sun May 10 00:56:57 EDT 2020, implemented=false] 2020-05-10 00:56:57.600 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=47, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:56:57.600 [DEBUG] [ConverterThermostatUnoccupiedCooling] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2088, lastReportTime=Sun May 10 00:56:57 EDT 2020, implemented=false] 2020-05-10 00:56:57.600 [DEBUG] [eeConverterThermostatOccupiedCooling] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2088, lastReportTime=Sun May 10 00:56:57 EDT 2020, implemented=false] 2020-05-10 00:56:57.600 [DEBUG] [ConverterThermostatUnoccupiedHeating] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2088, lastReportTime=Sun May 10 00:56:57 EDT 2020, implemented=false] 2020-05-10 00:56:57.600 [DEBUG] [eeConverterThermostatOccupiedHeating] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2088, lastReportTime=Sun May 10 00:56:57 EDT 2020, implemented=false] 2020-05-10 00:56:57.600 [DEBUG] [.ZigBeeConverterThermostatSystemMode] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2088, lastReportTime=Sun May 10 00:56:57 EDT 2020, implemented=false] 2020-05-10 00:56:57.600 [DEBUG] [eConverterThermostatLocalTemperature] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=0, name=Local Temperature, dataType=SIGNED_16_BIT_INTEGER, lastValue=2088, lastReportTime=Sun May 10 00:56:57 EDT 2020, implemented=false] 2020-05-10 00:56:57.600 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 000D6F00036B0BA5: Channel zigbee:device:5e4256a6:000d6f00036b0ba5:000D6F00036B0BA5_1_thermostatlocaltemp updated to 20.88 °C 2020-05-10 00:56:57.600 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000D6F00036B0BA5: Updating ZigBee channel state zigbee:device:5e4256a6:000d6f00036b0ba5:000D6F00036B0BA5_1_thermostatlocaltemp to 20.88 °C 2020-05-10 00:56:57.601 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 2020-05-10 00:56:57.601 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Canceling timeout task for thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 2020-05-10 00:56:57.601 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Scheduling timeout task for thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 in 14430 seconds 2020-05-10 00:56:58.566 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:56:58.646 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=6C], lastHopLqi=255, lastHopRssi=-56, sender=0DEC, bindingIndex=255, addressIndex=255, messageContents=08 35 04 00] 2020-05-10 00:56:58.646 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0DEC/1, destinationAddress=0000/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=6C, rssi=-56, lqi=FF, payload=08 35 04 00] 2020-05-10 00:56:58.646 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=53, commandId=4] 2020-05-10 00:56:58.646 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: WriteAttributesResponse [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=35, records=[WriteAttributeStatusRecord [status=SUCCESS, attributeIdentifier=0]]] 2020-05-10 00:56:58.646 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: WriteAttributesResponse [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=35, records=[WriteAttributeStatusRecord [status=SUCCESS, attributeIdentifier=0]]] 2020-05-10 00:56:58.647 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: WriteAttributesResponse [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=35, records=[WriteAttributeStatusRecord [status=SUCCESS, attributeIdentifier=0]]] ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=1949, state=DISPATCHED, sendCnt=1, command=WriteAttributesCommand [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, records=[WriteAttributeRecord [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]]] 2020-05-10 00:56:58.647 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=1949, state=COMPLETE, sendCnt=1, command=WriteAttributesCommand [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, records=[WriteAttributeRecord [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]]] 2020-05-10 00:56:58.647 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=2, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, commandIdentifier=4, statusCode=SUCCESS]] 2020-05-10 00:56:58.647 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding 2020-05-10 00:56:58.647 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: transactionComplete COMPLETE 0 2020-05-10 00:56:58.647 [DEBUG] [transaction.ZigBeeTransactionManager] - 0DEC/1: Sending ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=1047, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=47, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:56:58.647 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding 2020-05-10 00:56:58.648 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=47, commandIdentifier=10, statusCode=SUCCESS] 2020-05-10 00:56:58.648 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=71, commandId=11] 2020-05-10 00:56:58.648 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=0DEC/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=DA, rssi=--, lqi=--, payload=10 47 0B 0A 00] 2020-05-10 00:56:58.654 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:56:58.660 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=1D] 2020-05-10 00:56:58.735 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=3564, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=1C], messageTag=35, status=EMBER_SUCCESS, messageContents=] 2020-05-10 00:56:58.735 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=35 state=RX_ACK 2020-05-10 00:56:58.735 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=35, state=RX_ACK, outstanding=1 2020-05-10 00:56:59.143 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:56:59.228 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=6D], lastHopLqi=255, lastHopRssi=-56, sender=0DEC, bindingIndex=255, addressIndex=255, messageContents=08 48 0A 12 00 29 40 08] 2020-05-10 00:56:59.228 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0DEC/1, destinationAddress=0000/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=6D, rssi=-56, lqi=FF, payload=08 48 0A 12 00 29 40 08] 2020-05-10 00:56:59.228 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=72, commandId=10] 2020-05-10 00:56:59.228 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=48, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]] 2020-05-10 00:56:59.228 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=48, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]] 2020-05-10 00:56:59.229 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=48, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]] ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=1629, state=DISPATCHED, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=47, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:56:59.229 [DEBUG] [eeConverterThermostatOccupiedCooling] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:56:59 EDT 2020, implemented=false] 2020-05-10 00:56:59.229 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=2, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=48, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:56:59.229 [DEBUG] [onverterThermostatOutdoorTemperature] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:56:59 EDT 2020, implemented=false] 2020-05-10 00:56:59.229 [DEBUG] [ZigBeeConverterThermostatRunningMode] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:56:59 EDT 2020, implemented=false] 2020-05-10 00:56:59.229 [DEBUG] [ConverterThermostatUnoccupiedCooling] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:56:59 EDT 2020, implemented=false] 2020-05-10 00:56:59.229 [DEBUG] [eConverterThermostatLocalTemperature] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:56:59 EDT 2020, implemented=false] 2020-05-10 00:56:59.229 [DEBUG] [eeConverterThermostatOccupiedHeating] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:56:59 EDT 2020, implemented=false] 2020-05-10 00:56:59.229 [DEBUG] [.ZigBeeConverterThermostatSystemMode] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:56:59 EDT 2020, implemented=false] 2020-05-10 00:56:59.229 [DEBUG] [ConverterThermostatUnoccupiedHeating] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:56:59 EDT 2020, implemented=false] 2020-05-10 00:56:59.230 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 000D6F00036B0BA5: Channel zigbee:device:5e4256a6:000d6f00036b0ba5:000D6F00036B0BA5_1_thermostatoccupiedheating updated to 21.12 °C 2020-05-10 00:56:59.230 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000D6F00036B0BA5: Updating ZigBee channel state zigbee:device:5e4256a6:000d6f00036b0ba5:000D6F00036B0BA5_1_thermostatoccupiedheating to 21.12 °C 2020-05-10 00:56:59.230 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 2020-05-10 00:56:59.230 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Canceling timeout task for thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 2020-05-10 00:56:59.230 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Scheduling timeout task for thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 in 14430 seconds 2020-05-10 00:57:00.571 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-58, relayList=A4A5] 2020-05-10 00:57:00.657 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=6E], lastHopLqi=255, lastHopRssi=-56, sender=0DEC, bindingIndex=255, addressIndex=255, messageContents=08 35 04 00] 2020-05-10 00:57:00.657 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0DEC/1, destinationAddress=0000/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=6E, rssi=-56, lqi=FF, payload=08 35 04 00] 2020-05-10 00:57:00.657 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=53, commandId=4] 2020-05-10 00:57:00.658 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: WriteAttributesResponse [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=35, records=[WriteAttributeStatusRecord [status=SUCCESS, attributeIdentifier=0]]] 2020-05-10 00:57:00.658 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: WriteAttributesResponse [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=35, records=[WriteAttributeStatusRecord [status=SUCCESS, attributeIdentifier=0]]] 2020-05-10 00:57:00.658 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: WriteAttributesResponse [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=35, records=[WriteAttributeStatusRecord [status=SUCCESS, attributeIdentifier=0]]] ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=3058, state=DISPATCHED, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=47, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:57:00.658 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=3, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, commandIdentifier=4, statusCode=SUCCESS]] 2020-05-10 00:57:01.133 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:57:01.225 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=6C], lastHopLqi=255, lastHopRssi=-56, sender=0DEC, bindingIndex=255, addressIndex=255, messageContents=08 35 04 00] 2020-05-10 00:57:01.225 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0DEC/1, destinationAddress=0000/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=6C, rssi=-56, lqi=FF, payload=08 35 04 00] 2020-05-10 00:57:01.225 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=53, commandId=4] 2020-05-10 00:57:01.225 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: WriteAttributesResponse [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=35, records=[WriteAttributeStatusRecord [status=SUCCESS, attributeIdentifier=0]]] 2020-05-10 00:57:01.225 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: WriteAttributesResponse [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=35, records=[WriteAttributeStatusRecord [status=SUCCESS, attributeIdentifier=0]]] 2020-05-10 00:57:01.226 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: WriteAttributesResponse [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=35, records=[WriteAttributeStatusRecord [status=SUCCESS, attributeIdentifier=0]]] ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=3626, state=DISPATCHED, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=47, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:57:01.226 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=4, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, commandIdentifier=4, statusCode=SUCCESS]] 2020-05-10 00:57:01.251 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-59, relayList=A4A5] 2020-05-10 00:57:01.332 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=6F], lastHopLqi=255, lastHopRssi=-56, sender=0DEC, bindingIndex=255, addressIndex=255, messageContents=08 49 0A 12 00 29 40 08] 2020-05-10 00:57:01.332 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0DEC/1, destinationAddress=0000/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=6F, rssi=-56, lqi=FF, payload=08 49 0A 12 00 29 40 08] 2020-05-10 00:57:01.332 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=73, commandId=10] 2020-05-10 00:57:01.332 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=49, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]] 2020-05-10 00:57:01.332 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=49, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]] 2020-05-10 00:57:01.332 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=49, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]] ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=3732, state=DISPATCHED, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=47, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:57:01.333 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=5, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=49, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:57:01.333 [DEBUG] [onverterThermostatOutdoorTemperature] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:01 EDT 2020, implemented=false] 2020-05-10 00:57:01.333 [DEBUG] [ConverterThermostatUnoccupiedCooling] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:01 EDT 2020, implemented=false] 2020-05-10 00:57:01.333 [DEBUG] [ZigBeeConverterThermostatRunningMode] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:01 EDT 2020, implemented=false] 2020-05-10 00:57:01.333 [DEBUG] [ConverterThermostatUnoccupiedHeating] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:01 EDT 2020, implemented=false] 2020-05-10 00:57:01.333 [DEBUG] [eeConverterThermostatOccupiedHeating] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:01 EDT 2020, implemented=false] 2020-05-10 00:57:01.333 [DEBUG] [.ZigBeeConverterThermostatSystemMode] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:01 EDT 2020, implemented=false] 2020-05-10 00:57:01.333 [DEBUG] [eeConverterThermostatOccupiedCooling] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:01 EDT 2020, implemented=false] 2020-05-10 00:57:01.333 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 000D6F00036B0BA5: Channel zigbee:device:5e4256a6:000d6f00036b0ba5:000D6F00036B0BA5_1_thermostatoccupiedheating updated to 21.12 °C 2020-05-10 00:57:01.333 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000D6F00036B0BA5: Updating ZigBee channel state zigbee:device:5e4256a6:000d6f00036b0ba5:000D6F00036B0BA5_1_thermostatoccupiedheating to 21.12 °C 2020-05-10 00:57:01.334 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 2020-05-10 00:57:01.334 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Canceling timeout task for thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 2020-05-10 00:57:01.334 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Scheduling timeout task for thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 in 14430 seconds 2020-05-10 00:57:01.335 [DEBUG] [eConverterThermostatLocalTemperature] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:01 EDT 2020, implemented=false] 2020-05-10 00:57:02.407 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=254, lastHopRssi=-63, relayList=A4A5] 2020-05-10 00:57:02.520 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=6D], lastHopLqi=255, lastHopRssi=-59, sender=0DEC, bindingIndex=255, addressIndex=255, messageContents=08 48 0A 12 00 29 40 08] 2020-05-10 00:57:02.520 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0DEC/1, destinationAddress=0000/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=6D, rssi=-59, lqi=FF, payload=08 48 0A 12 00 29 40 08] 2020-05-10 00:57:02.520 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=72, commandId=10] 2020-05-10 00:57:02.520 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=48, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]] 2020-05-10 00:57:02.520 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=48, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]] 2020-05-10 00:57:02.520 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=48, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]] ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=4920, state=DISPATCHED, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=47, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:57:02.521 [DEBUG] [onverterThermostatOutdoorTemperature] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:02 EDT 2020, implemented=false] 2020-05-10 00:57:02.521 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=6, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=48, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:57:02.521 [DEBUG] [ZigBeeConverterThermostatRunningMode] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:02 EDT 2020, implemented=false] 2020-05-10 00:57:02.521 [DEBUG] [ConverterThermostatUnoccupiedCooling] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:02 EDT 2020, implemented=false] 2020-05-10 00:57:02.521 [DEBUG] [ConverterThermostatUnoccupiedHeating] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:02 EDT 2020, implemented=false] 2020-05-10 00:57:02.521 [DEBUG] [eConverterThermostatLocalTemperature] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:02 EDT 2020, implemented=false] 2020-05-10 00:57:02.521 [DEBUG] [eeConverterThermostatOccupiedHeating] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:02 EDT 2020, implemented=false] 2020-05-10 00:57:02.521 [DEBUG] [.ZigBeeConverterThermostatSystemMode] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:02 EDT 2020, implemented=false] 2020-05-10 00:57:02.521 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 000D6F00036B0BA5: Channel zigbee:device:5e4256a6:000d6f00036b0ba5:000D6F00036B0BA5_1_thermostatoccupiedheating updated to 21.12 °C 2020-05-10 00:57:02.521 [DEBUG] [eeConverterThermostatOccupiedCooling] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:02 EDT 2020, implemented=false] 2020-05-10 00:57:02.521 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000D6F00036B0BA5: Updating ZigBee channel state zigbee:device:5e4256a6:000d6f00036b0ba5:000D6F00036B0BA5_1_thermostatoccupiedheating to 21.12 °C 2020-05-10 00:57:02.522 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 2020-05-10 00:57:02.522 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Canceling timeout task for thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 2020-05-10 00:57:02.522 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Scheduling timeout task for thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 in 14430 seconds 2020-05-10 00:57:02.547 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-58, relayList=A4A5] 2020-05-10 00:57:02.630 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0019, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=70], lastHopLqi=255, lastHopRssi=-56, sender=0DEC, bindingIndex=255, addressIndex=255, messageContents=01 4A 01 00 DF C2 03 00 8C 46 18 14] 2020-05-10 00:57:02.630 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0DEC/1, destinationAddress=0000/1, profile=0104, cluster=0019, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=70, rssi=-56, lqi=FF, payload=01 4A 01 00 DF C2 03 00 8C 46 18 14] 2020-05-10 00:57:02.630 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=74, commandId=1] 2020-05-10 00:57:02.630 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: QueryNextImageCommand [Ota Upgrade: 0DEC/1 -> 0000/1, cluster=0019, TID=4A, fieldControl=0, manufacturerCode=49887, imageType=3, fileVersion=337135244, hardwareVersion=null] 2020-05-10 00:57:02.630 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: QueryNextImageCommand [Ota Upgrade: 0DEC/1 -> 0000/1, cluster=0019, TID=4A, fieldControl=0, manufacturerCode=49887, imageType=3, fileVersion=337135244, hardwareVersion=null] 2020-05-10 00:57:02.630 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: QueryNextImageCommand [Ota Upgrade: 0DEC/1 -> 0000/1, cluster=0019, TID=4A, fieldControl=0, manufacturerCode=49887, imageType=3, fileVersion=337135244, hardwareVersion=null] ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=5030, state=DISPATCHED, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=47, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:57:02.631 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=7, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=QueryNextImageResponse [Ota Upgrade: 0000/0 -> 0DEC/1, cluster=0019, TID=4A, status=NO_IMAGE_AVAILABLE, manufacturerCode=49887, imageType=3, fileVersion=337135244, imageSize=0]] 2020-05-10 00:57:02.634 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-57, relayList=A4A5] 2020-05-10 00:57:02.714 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=3564, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=1D], messageTag=47, status=EMBER_SUCCESS, messageContents=] 2020-05-10 00:57:02.714 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=47 state=RX_ACK 2020-05-10 00:57:02.714 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=47, state=RX_ACK, outstanding=1 2020-05-10 00:57:02.715 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=5115, state=COMPLETE, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=47, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:57:02.715 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding 2020-05-10 00:57:02.715 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: transactionComplete COMPLETE 0 2020-05-10 00:57:02.715 [DEBUG] [transaction.ZigBeeTransactionManager] - 0DEC/1: Sending ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=4068, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, commandIdentifier=4, statusCode=SUCCESS]] 2020-05-10 00:57:02.715 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding 2020-05-10 00:57:02.715 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, commandIdentifier=4, statusCode=SUCCESS] 2020-05-10 00:57:02.715 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=53, commandId=11] 2020-05-10 00:57:02.716 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=0DEC/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=DB, rssi=--, lqi=--, payload=10 35 0B 04 00] 2020-05-10 00:57:02.716 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 47 -> RX_ACK == COMPLETE 2020-05-10 00:57:02.735 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=1E] 2020-05-10 00:57:04.528 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-58, relayList=A4A5] 2020-05-10 00:57:05.342 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-55, relayList=A4A5] 2020-05-10 00:57:05.430 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=6E], lastHopLqi=255, lastHopRssi=-55, sender=0DEC, bindingIndex=255, addressIndex=255, messageContents=08 35 04 00] 2020-05-10 00:57:05.431 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0DEC/1, destinationAddress=0000/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=6E, rssi=-55, lqi=FF, payload=08 35 04 00] 2020-05-10 00:57:05.431 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=53, commandId=4] 2020-05-10 00:57:05.431 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: WriteAttributesResponse [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=35, records=[WriteAttributeStatusRecord [status=SUCCESS, attributeIdentifier=0]]] 2020-05-10 00:57:05.431 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: WriteAttributesResponse [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=35, records=[WriteAttributeStatusRecord [status=SUCCESS, attributeIdentifier=0]]] 2020-05-10 00:57:05.431 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: WriteAttributesResponse [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=35, records=[WriteAttributeStatusRecord [status=SUCCESS, attributeIdentifier=0]]] ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=6784, state=DISPATCHED, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, commandIdentifier=4, statusCode=SUCCESS]] 2020-05-10 00:57:05.431 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=7, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, commandIdentifier=4, statusCode=SUCCESS]] 2020-05-10 00:57:05.443 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:57:05.529 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=6F], lastHopLqi=255, lastHopRssi=-56, sender=0DEC, bindingIndex=255, addressIndex=255, messageContents=08 49 0A 12 00 29 40 08] 2020-05-10 00:57:05.529 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0DEC/1, destinationAddress=0000/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=6F, rssi=-56, lqi=FF, payload=08 49 0A 12 00 29 40 08] 2020-05-10 00:57:05.529 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=73, commandId=10] 2020-05-10 00:57:05.529 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=49, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]] 2020-05-10 00:57:05.529 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=49, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]] 2020-05-10 00:57:05.530 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Thermostat: 0DEC/1 -> 0000/1, cluster=0201, TID=49, reports=[AttributeReport [attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=18, attributeValue=2112]]] ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=6883, state=DISPATCHED, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, commandIdentifier=4, statusCode=SUCCESS]] 2020-05-10 00:57:05.530 [DEBUG] [onverterThermostatOutdoorTemperature] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:05 EDT 2020, implemented=false] 2020-05-10 00:57:05.530 [DEBUG] [ZigBeeConverterThermostatRunningMode] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:05 EDT 2020, implemented=false] 2020-05-10 00:57:05.530 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=8, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=49, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:57:05.530 [DEBUG] [ConverterThermostatUnoccupiedCooling] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:05 EDT 2020, implemented=false] 2020-05-10 00:57:05.530 [DEBUG] [eeConverterThermostatOccupiedCooling] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:05 EDT 2020, implemented=false] 2020-05-10 00:57:05.530 [DEBUG] [ConverterThermostatUnoccupiedHeating] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:05 EDT 2020, implemented=false] 2020-05-10 00:57:05.530 [DEBUG] [eConverterThermostatLocalTemperature] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:05 EDT 2020, implemented=false] 2020-05-10 00:57:05.530 [DEBUG] [eeConverterThermostatOccupiedHeating] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:05 EDT 2020, implemented=false] 2020-05-10 00:57:05.530 [DEBUG] [.ZigBeeConverterThermostatSystemMode] - 000D6F00036B0BA5: ZigBee attribute reports ZclAttribute [cluster=Thermostat, id=18, name=Occupied Heating Setpoint, dataType=SIGNED_16_BIT_INTEGER, lastValue=2112, lastReportTime=Sun May 10 00:57:05 EDT 2020, implemented=false] 2020-05-10 00:57:05.530 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 000D6F00036B0BA5: Channel zigbee:device:5e4256a6:000d6f00036b0ba5:000D6F00036B0BA5_1_thermostatoccupiedheating updated to 21.12 °C 2020-05-10 00:57:05.531 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000D6F00036B0BA5: Updating ZigBee channel state zigbee:device:5e4256a6:000d6f00036b0ba5:000D6F00036B0BA5_1_thermostatoccupiedheating to 21.12 °C 2020-05-10 00:57:05.531 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 2020-05-10 00:57:05.531 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Canceling timeout task for thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 2020-05-10 00:57:05.531 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Scheduling timeout task for thingUID=zigbee:device:5e4256a6:000d6f00036b0ba5 in 14430 seconds 2020-05-10 00:57:05.533 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:57:05.632 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0019, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=70], lastHopLqi=255, lastHopRssi=-56, sender=0DEC, bindingIndex=255, addressIndex=255, messageContents=01 4A 01 00 DF C2 03 00 8C 46 18 14] 2020-05-10 00:57:05.632 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0DEC/1, destinationAddress=0000/1, profile=0104, cluster=0019, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=70, rssi=-56, lqi=FF, payload=01 4A 01 00 DF C2 03 00 8C 46 18 14] 2020-05-10 00:57:05.632 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=74, commandId=1] 2020-05-10 00:57:05.632 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: QueryNextImageCommand [Ota Upgrade: 0DEC/1 -> 0000/1, cluster=0019, TID=4A, fieldControl=0, manufacturerCode=49887, imageType=3, fileVersion=337135244, hardwareVersion=null] 2020-05-10 00:57:05.632 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: QueryNextImageCommand [Ota Upgrade: 0DEC/1 -> 0000/1, cluster=0019, TID=4A, fieldControl=0, manufacturerCode=49887, imageType=3, fileVersion=337135244, hardwareVersion=null] 2020-05-10 00:57:05.633 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: QueryNextImageCommand [Ota Upgrade: 0DEC/1 -> 0000/1, cluster=0019, TID=4A, fieldControl=0, manufacturerCode=49887, imageType=3, fileVersion=337135244, hardwareVersion=null] ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=6985, state=DISPATCHED, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, commandIdentifier=4, statusCode=SUCCESS]] 2020-05-10 00:57:05.633 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=9, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=QueryNextImageResponse [Ota Upgrade: 0000/0 -> 0DEC/1, cluster=0019, TID=4A, status=NO_IMAGE_AVAILABLE, manufacturerCode=49887, imageType=3, fileVersion=337135244, imageSize=0]] 2020-05-10 00:57:07.418 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=3564, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=1E], messageTag=35, status=EMBER_DELIVERY_FAILED, messageContents=] 2020-05-10 00:57:07.418 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=35 state=RX_NAK 2020-05-10 00:57:07.418 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=35, state=RX_NAK, outstanding=1 2020-05-10 00:57:07.418 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=8771, state=FAILED, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, commandIdentifier=4, statusCode=SUCCESS]] 2020-05-10 00:57:07.419 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding 2020-05-10 00:57:07.419 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: transactionComplete FAILED 0 2020-05-10 00:57:07.419 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=10, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=8772, state=WAITING, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, commandIdentifier=4, statusCode=SUCCESS]] 2020-05-10 00:57:07.419 [DEBUG] [transaction.ZigBeeTransactionManager] - 0DEC/1: Sending ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=8772, state=WAITING, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, commandIdentifier=4, statusCode=SUCCESS]] 2020-05-10 00:57:07.419 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding 2020-05-10 00:57:07.419 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, commandIdentifier=4, statusCode=SUCCESS] 2020-05-10 00:57:07.419 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=53, commandId=11] 2020-05-10 00:57:07.419 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=0DEC/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=DC, rssi=--, lqi=--, payload=10 35 0B 04 00] 2020-05-10 00:57:07.419 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 35 -> RX_NAK == DISPATCHED 2020-05-10 00:57:07.430 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=1F] 2020-05-10 00:57:07.529 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:57:09.533 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:57:12.119 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=3564, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=1F], messageTag=35, status=EMBER_DELIVERY_FAILED, messageContents=] 2020-05-10 00:57:12.119 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=35 state=RX_NAK 2020-05-10 00:57:12.119 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=35, state=RX_NAK, outstanding=1 2020-05-10 00:57:12.119 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=13472, state=FAILED, sendCnt=2, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, commandIdentifier=4, statusCode=SUCCESS]] 2020-05-10 00:57:12.120 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding 2020-05-10 00:57:12.120 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: transactionComplete FAILED 0 2020-05-10 00:57:12.120 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: transactionComplete exceeded retries 2 2020-05-10 00:57:12.120 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction terminated: ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=13473, state=FAILED, sendCnt=2, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, commandIdentifier=4, statusCode=SUCCESS]] 2020-05-10 00:57:12.120 [DEBUG] [transaction.ZigBeeTransactionManager] - 0DEC/1: Sending ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=12891, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=48, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:57:12.120 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding 2020-05-10 00:57:12.120 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=48, commandIdentifier=10, statusCode=SUCCESS] 2020-05-10 00:57:12.120 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=72, commandId=11] 2020-05-10 00:57:12.120 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=0DEC/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=DD, rssi=--, lqi=--, payload=10 48 0B 0A 00] 2020-05-10 00:57:12.120 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 35 -> RX_NAK == FAILED 2020-05-10 00:57:12.131 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=20] 2020-05-10 00:57:12.537 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:57:12.618 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=000A, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=71], lastHopLqi=255, lastHopRssi=-59, sender=0DEC, bindingIndex=255, addressIndex=255, messageContents=00 4B 00 07 00] 2020-05-10 00:57:12.618 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0DEC/1, destinationAddress=0000/1, profile=0104, cluster=000A, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=71, rssi=-59, lqi=FF, payload=00 4B 00 07 00] 2020-05-10 00:57:12.618 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=75, commandId=0] 2020-05-10 00:57:12.618 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Unsupported local server cluster 000A 2020-05-10 00:57:12.618 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=9, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Time: 0000/0 -> 0DEC/1, cluster=000A, TID=4B, commandIdentifier=0, statusCode=FAILURE]] 2020-05-10 00:57:12.619 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Incoming message from node 0DEC did not translate to command 2020-05-10 00:57:12.623 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:57:13.539 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-59, relayList=A4A5] 2020-05-10 00:57:14.541 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:57:14.632 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0019, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=70], lastHopLqi=255, lastHopRssi=-56, sender=0DEC, bindingIndex=255, addressIndex=255, messageContents=01 4A 01 00 DF C2 03 00 8C 46 18 14] 2020-05-10 00:57:14.632 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0DEC/1, destinationAddress=0000/1, profile=0104, cluster=0019, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=70, rssi=-56, lqi=FF, payload=01 4A 01 00 DF C2 03 00 8C 46 18 14] 2020-05-10 00:57:14.632 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=74, commandId=1] 2020-05-10 00:57:14.632 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: QueryNextImageCommand [Ota Upgrade: 0DEC/1 -> 0000/1, cluster=0019, TID=4A, fieldControl=0, manufacturerCode=49887, imageType=3, fileVersion=337135244, hardwareVersion=null] 2020-05-10 00:57:14.632 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: QueryNextImageCommand [Ota Upgrade: 0DEC/1 -> 0000/1, cluster=0019, TID=4A, fieldControl=0, manufacturerCode=49887, imageType=3, fileVersion=337135244, hardwareVersion=null] 2020-05-10 00:57:14.633 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: QueryNextImageCommand [Ota Upgrade: 0DEC/1 -> 0000/1, cluster=0019, TID=4A, fieldControl=0, manufacturerCode=49887, imageType=3, fileVersion=337135244, hardwareVersion=null] ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=15404, state=DISPATCHED, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=48, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:57:14.633 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: Added transaction to queue, len=10, transaction=ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=0, state=WAITING, sendCnt=0, command=QueryNextImageResponse [Ota Upgrade: 0000/0 -> 0DEC/1, cluster=0019, TID=4A, status=NO_IMAGE_AVAILABLE, manufacturerCode=49887, imageType=3, fileVersion=337135244, imageSize=0]] 2020-05-10 00:57:14.650 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:57:15.542 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5] 2020-05-10 00:57:15.617 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=3564, apsFrame=EmberApsFrame [profileId=0104, clusterId=0201, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=20], messageTag=48, status=EMBER_SUCCESS, messageContents=] 2020-05-10 00:57:15.617 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=48 state=RX_ACK 2020-05-10 00:57:15.617 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=48, state=RX_ACK, outstanding=1 2020-05-10 00:57:15.617 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=16388, state=COMPLETE, sendCnt=1, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=48, commandIdentifier=10, statusCode=SUCCESS]] 2020-05-10 00:57:15.617 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding 2020-05-10 00:57:15.618 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F00036B0BA5: transactionComplete COMPLETE 0 2020-05-10 00:57:15.618 [DEBUG] [transaction.ZigBeeTransactionManager] - 0DEC/1: Sending ZigBeeTransaction [ieeeAddress=000D6F00036B0BA5 queueTime=14960, state=WAITING, sendCnt=0, command=DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, commandIdentifier=4, statusCode=SUCCESS]] 2020-05-10 00:57:15.618 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding 2020-05-10 00:57:15.618 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Thermostat: 0000/0 -> 0DEC/1, cluster=0201, TID=35, commandIdentifier=4, statusCode=SUCCESS] 2020-05-10 00:57:15.618 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=53, commandId=11] 2020-05-10 00:57:15.618 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=0DEC/1, profile=0104, cluster=0201, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=DE, rssi=--, lqi=--, payload=10 35 0B 04 00] 2020-05-10 00:57:15.618 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 48 -> RX_ACK == COMPLETE 2020-05-10 00:57:15.629 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=21] 2020-05-10 00:57:17.542 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=0DEC, sourceEui=000D6F00036B0BA5, lastHopLqi=255, lastHopRssi=-56, relayList=A4A5]