The reinitialization happened quick.
openhab> log:set debug org.openhab.binding.zigbee
openhab> log:display
16:30:21.198 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C13884A303C0EF: Node 4F89 is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C13884A303C0EF, NWK=----, endpoints=[]]
16:30:21.198 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=6B, commandId=10]
16:30:21.198 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Color Control: 4F89/1 -> 0000/1, cluster=0300, TID=6B, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=1, attributeValue=253]]]
16:30:21.198 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Color Control: 4F89/1 -> 0000/1, cluster=0300, TID=6B, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=1, attributeValue=253]]]
16:30:21.198 [DEBUG] [erter.ZigBeeConverterColorTemperature] - A4C13884A303C0EF: ZigBee attribute reports ZclAttribute [cluster=Color Control, id=1, name=Current Saturation, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=253, lastReportTime=Sun Jun 02 16:30:21 CDT 2024, implemented=true] on endpoint 1
16:30:21.198 [DEBUG] [l.converter.ZigBeeConverterColorColor] - A4C13884A303C0EF: ZigBee attribute reports ZclAttribute [cluster=Color Control, id=1, name=Current Saturation, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=253, lastReportTime=Sun Jun 02 16:30:21 CDT 2024, implemented=true]
16:30:21.198 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - A4C13884A303C0EF: Channel zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color updated to 280.6299,99.6063,51
16:30:21.198 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C13884A303C0EF: Updating ZigBee channel state zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color to 280.6299,99.6063,51
16:30:21.198 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef
16:30:21.198 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef
16:30:21.198 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef in 14430 seconds
16:30:21.199 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=5, ackNum=7, reTx=false, data=4E 90 01 59 00 89 4F EF C0 03 A3 84 38 C1 A4 E8 D6 00]
16:30:21.199 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=6, notRdy=false]
16:30:21.199 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4F89, sourceEui=A4C13884A303C0EF, lastHopLqi=232, lastHopRssi=-42, relayList=]
16:30:21.208 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=6, ackNum=7, reTx=false, data=4E 90 01 45 00 00 04 01 08 00 01 01 40 01 00 00 00 E8 D6 89 4F FF FF 07 18 6C 0A 00 00 20 7F 02]
16:30:21.208 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=7, notRdy=false]
16:30:21.208 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0008, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=00], lastHopLqi=232, lastHopRssi=-42, sender=4F89, bindingIndex=255, addressIndex=255, messageContents=18 6C 0A 00 00 20 7F]
16:30:21.208 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4F89/1, destinationAddress=0000/1, profile=0104, cluster=0008, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=00, rssi=-42, lqi=E8, payload=18 6C 0A 00 00 20 7F]
16:30:21.208 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C13884A303C0EF: Node update. NWK Address=NULL
16:30:21.208 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C13884A303C0EF: Node 4F89 is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C13884A303C0EF, NWK=----, endpoints=[]]
16:30:21.208 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=6C, commandId=10]
16:30:21.208 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Level Control: 4F89/1 -> 0000/1, cluster=0008, TID=6C, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=127]]]
16:30:21.208 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Level Control: 4F89/1 -> 0000/1, cluster=0008, TID=6C, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=127]]]
16:30:21.208 [DEBUG] [l.converter.ZigBeeConverterColorColor] - A4C13884A303C0EF: ZigBee attribute reports ZclAttribute [cluster=Level Control, id=0, name=Current Level, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=127, lastReportTime=Sun Jun 02 16:30:21 CDT 2024, implemented=true]
16:30:21.208 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - A4C13884A303C0EF: Channel zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color updated to 280.6299,99.6063,50
16:30:21.208 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C13884A303C0EF: Updating ZigBee channel state zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color to 280.6299,99.6063,50
16:30:21.208 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef
16:30:21.208 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef
16:30:21.208 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef in 14430 seconds
16:30:21.401 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=7, ackNum=7, reTx=false, data=4E 90 01 59 00 66 40 8B 26 D6 0E 10 38 C1 A4 FF EA 00]
16:30:21.401 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=0, notRdy=false]
16:30:21.401 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4066, sourceEui=A4C138100ED6268B, lastHopLqi=255, lastHopRssi=-22, relayList=]
16:30:21.407 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=0, ackNum=7, reTx=false, data=4E 90 01 45 00 00 04 01 00 03 01 01 40 01 00 00 9A FF EA 66 40 FF FF 07 18 95 0A 00 00 20 C5 02]
16:30:21.407 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=1, notRdy=false]
16:30:21.407 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=9A], lastHopLqi=255, lastHopRssi=-22, sender=4066, bindingIndex=255, addressIndex=255, messageContents=18 95 0A 00 00 20 C5]
16:30:21.407 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4066/1, destinationAddress=0000/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=9A, rssi=-22, lqi=FF, payload=18 95 0A 00 00 20 C5]
16:30:21.407 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C138100ED6268B: Node update. NWK Address=NULL
16:30:21.407 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C138100ED6268B: Node 4066 is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C138100ED6268B, NWK=----, endpoints=[]]
16:30:21.407 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=95, commandId=10]
16:30:21.407 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Color Control: 4066/1 -> 0000/1, cluster=0300, TID=95, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=197]]]
16:30:21.407 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Color Control: 4066/1 -> 0000/1, cluster=0300, TID=95, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=197]]]
16:30:21.407 [DEBUG] [l.converter.ZigBeeConverterColorColor] - A4C138100ED6268B: ZigBee attribute reports ZclAttribute [cluster=Color Control, id=0, name=Current Hue, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=197, lastReportTime=Sun Jun 02 16:30:21 CDT 2024, implemented=true]
16:30:21.407 [DEBUG] [erter.ZigBeeConverterColorTemperature] - A4C138100ED6268B: ZigBee attribute reports ZclAttribute [cluster=Color Control, id=0, name=Current Hue, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=197, lastReportTime=Sun Jun 02 16:30:21 CDT 2024, implemented=true] on endpoint 1
16:30:21.428 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=1, ackNum=7, reTx=false, data=4E 90 01 59 00 66 40 8B 26 D6 0E 10 38 C1 A4 FF EA 00]
16:30:21.428 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=2, notRdy=false]
16:30:21.428 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4066, sourceEui=A4C138100ED6268B, lastHopLqi=255, lastHopRssi=-22, relayList=]
16:30:21.430 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=2, ackNum=7, reTx=false, data=4E 90 01 45 00 00 04 01 00 03 01 01 40 01 00 00 9B FF EA 66 40 FF FF 07 18 96 0A 01 00 20 FD 02]
16:30:21.430 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=3, notRdy=false]
16:30:21.430 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=9B], lastHopLqi=255, lastHopRssi=-22, sender=4066, bindingIndex=255, addressIndex=255, messageContents=18 96 0A 01 00 20 FD]
16:30:21.430 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4066/1, destinationAddress=0000/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=9B, rssi=-22, lqi=FF, payload=18 96 0A 01 00 20 FD]
16:30:21.430 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C138100ED6268B: Node update. NWK Address=NULL
16:30:21.430 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C138100ED6268B: Node 4066 is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C138100ED6268B, NWK=----, endpoints=[]]
16:30:21.430 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=96, commandId=10]
16:30:21.430 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Color Control: 4066/1 -> 0000/1, cluster=0300, TID=96, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=1, attributeValue=253]]]
16:30:21.430 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Color Control: 4066/1 -> 0000/1, cluster=0300, TID=96, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=1, attributeValue=253]]]
16:30:21.430 [DEBUG] [erter.ZigBeeConverterColorTemperature] - A4C138100ED6268B: ZigBee attribute reports ZclAttribute [cluster=Color Control, id=1, name=Current Saturation, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=253, lastReportTime=Sun Jun 02 16:30:21 CDT 2024, implemented=true] on endpoint 1
16:30:21.430 [DEBUG] [l.converter.ZigBeeConverterColorColor] - A4C138100ED6268B: ZigBee attribute reports ZclAttribute [cluster=Color Control, id=1, name=Current Saturation, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=253, lastReportTime=Sun Jun 02 16:30:21 CDT 2024, implemented=true]
16:30:21.430 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - A4C138100ED6268B: Channel zigbee:device:3ea840067f:a4c138100ed6268b:A4C138100ED6268B_1_color updated to 279.2126,99.6063,50
16:30:21.430 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C138100ED6268B: Updating ZigBee channel state zigbee:device:3ea840067f:a4c138100ed6268b:A4C138100ED6268B_1_color to 279.2126,99.6063,50
16:30:21.430 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:3ea840067f:a4c138100ed6268b
16:30:21.430 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:3ea840067f:a4c138100ed6268b
16:30:21.430 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:3ea840067f:a4c138100ed6268b in 14430 seconds
16:30:21.632 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Generic_MQTT_Thing_Color' changed from 280,100,50 to 232,63,64
16:30:21.633 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C138100ED6268B: Command for channel zigbee:device:3ea840067f:a4c138100ed6268b:A4C138100ED6268B_1_color --> 232,63,64 [HSBType]
16:30:21.633 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C13884A303C0EF: Command for channel zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color --> 232,63,64 [HSBType]
16:30:21.633 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C1381B88FD55A7: Command for channel zigbee:device:3ea840067f:a4c1381b88fd55a7:A4C1381B88FD55A7_1_color --> 232,63,64 [HSBType]
16:30:21.633 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C1381B88FD55A7: No handler found for zigbee:device:3ea840067f:a4c1381b88fd55a7:A4C1381B88FD55A7_1_color
16:30:21.633 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - A4C138100ED6268B: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=A4C138100ED6268B queueTime=0, state=WAITING, sendCnt=0, command=MoveToLevelWithOnOffCommand [Level Control: 0000/0 -> 4066/1, cluster=0008, TID=--, level=163, transitionTime=10]]
16:30:21.633 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3
16:30:21.633 [DEBUG] [.transaction.ZigBeeTransactionManager] - 4066/1: Sending ZigBeeTransaction [ieeeAddress=A4C138100ED6268B queueTime=0, state=WAITING, sendCnt=0, command=MoveToLevelWithOnOffCommand [Level Control: 0000/0 -> 4066/1, cluster=0008, TID=E2, level=163, transitionTime=10]]
16:30:21.633 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
16:30:21.633 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: MoveToLevelWithOnOffCommand [Level Control: 0000/0 -> 4066/1, cluster=0008, TID=E2, level=163, transitionTime=10]
16:30:21.633 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=E2, commandId=4]
16:30:21.633 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=4066/1, profile=0104, cluster=0008, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=E7, rssi=--, lqi=--, payload=01 E2 04 A3 0A 00]
16:30:21.633 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspSendUnicastRequest [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=4066, apsFrame=EmberApsFrame [profileId=0104, clusterId=0008, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=E7], messageTag=E2, messageContents=01 E2 04 A3 0A 00]
16:30:21.633 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - A4C13884A303C0EF: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=A4C13884A303C0EF queueTime=0, state=WAITING, sendCnt=0, command=MoveToLevelWithOnOffCommand [Level Control: 0000/0 -> 4F89/1, cluster=0008, TID=--, level=163, transitionTime=10]]
16:30:21.633 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3
16:30:21.633 [DEBUG] [.transaction.ZigBeeTransactionManager] - 4F89/1: Sending ZigBeeTransaction [ieeeAddress=A4C13884A303C0EF queueTime=0, state=WAITING, sendCnt=0, command=MoveToLevelWithOnOffCommand [Level Control: 0000/0 -> 4F89/1, cluster=0008, TID=E3, level=163, transitionTime=10]]
16:30:21.633 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding
16:30:21.633 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=7, ackNum=3, reTx=false, data=4F 00 01 34 00 00 66 40 04 01 08 00 01 01 40 11 00 00 E7 E2 06 01 E2 04 A3 0A 00]
16:30:21.633 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: MoveToLevelWithOnOffCommand [Level Control: 0000/0 -> 4F89/1, cluster=0008, TID=E3, level=163, transitionTime=10]
16:30:21.633 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=E3, commandId=4]
16:30:21.633 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=4F89/1, profile=0104, cluster=0008, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=E8, rssi=--, lqi=--, payload=01 E3 04 A3 0A 00]
16:30:21.633 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - A4C13884A303C0EF: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=A4C13884A303C0EF queueTime=0, state=WAITING, sendCnt=0, command=MoveToHueAndSaturationCommand [Color Control: 0000/0 -> 4F89/1, cluster=0300, TID=--, hue=164, saturation=160, transitionTime=10]]
16:30:21.633 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=2, outstandingQueues=1, sleepy=0/3
16:30:21.633 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - A4C13884A303C0EF: Channel zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color waiting for response to 232,63,64
16:30:21.633 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - A4C138100ED6268B: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=A4C138100ED6268B queueTime=0, state=WAITING, sendCnt=0, command=MoveToHueAndSaturationCommand [Color Control: 0000/0 -> 4066/1, cluster=0300, TID=--, hue=164, saturation=160, transitionTime=10]]
16:30:21.633 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=2, outstandingQueues=2, sleepy=0/3
16:30:21.633 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - A4C138100ED6268B: Channel zigbee:device:3ea840067f:a4c138100ed6268b:A4C138100ED6268B_1_color waiting for response to 232,63,64
16:30:21.642 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=3, ackNum=0, reTx=false, data=4F 80 01 34 00 00 69]
16:30:21.642 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=4, notRdy=false]
16:30:21.642 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=69]
16:30:21.642 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspSendUnicastRequest [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=4F89, apsFrame=EmberApsFrame [profileId=0104, clusterId=0008, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=E8], messageTag=E3, messageContents=01 E3 04 A3 0A 00]
16:30:21.642 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=0, ackNum=4, reTx=false, data=50 00 01 34 00 00 89 4F 04 01 08 00 01 01 40 11 00 00 E8 E3 06 01 E3 04 A3 0A 00]
16:30:21.650 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=4, ackNum=1, reTx=false, data=50 80 01 34 00 00 6A]
16:30:21.650 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=5, notRdy=false]
16:30:21.650 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=6A]
16:30:21.684 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=2, outstandingQueues=2, sleepy=0/3
16:30:21.710 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=5, ackNum=1, reTx=false, data=50 90 01 59 00 66 40 8B 26 D6 0E 10 38 C1 A4 FF EA 00]
16:30:21.710 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=6, notRdy=false]
16:30:21.710 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4066, sourceEui=A4C138100ED6268B, lastHopLqi=255, lastHopRssi=-22, relayList=]
16:30:21.714 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=6, ackNum=1, reTx=false, data=50 90 01 3F 00 00 66 40 04 01 08 00 01 01 40 11 00 00 69 E2 00 00]
16:30:21.714 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=7, notRdy=false]
16:30:21.714 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=4066, apsFrame=EmberApsFrame [profileId=0104, clusterId=0008, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=69], messageTag=E2, status=EMBER_SUCCESS, messageContents=]
16:30:21.714 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=E2 state=RX_ACK
16:30:21.714 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=E2, state=RX_ACK, outstanding=2
16:30:21.714 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=4066, TID=E2, event=RX_ACK, state=ACKED
16:30:21.724 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=7, ackNum=1, reTx=false, data=50 90 01 59 00 89 4F EF C0 03 A3 84 38 C1 A4 EC D7 00]
16:30:21.724 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=0, notRdy=false]
16:30:21.724 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4F89, sourceEui=A4C13884A303C0EF, lastHopLqi=236, lastHopRssi=-41, relayList=]
16:30:21.728 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=0, ackNum=1, reTx=false, data=50 90 01 3F 00 00 89 4F 04 01 08 00 01 01 40 11 00 00 6A E3 00 00]
16:30:21.728 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=1, notRdy=false]
16:30:21.728 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=4F89, apsFrame=EmberApsFrame [profileId=0104, clusterId=0008, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=6A], messageTag=E3, status=EMBER_SUCCESS, messageContents=]
16:30:21.728 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=E3 state=RX_ACK
16:30:21.728 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=E3, state=RX_ACK, outstanding=2
16:30:21.728 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=4F89, TID=E3, event=RX_ACK, state=ACKED
16:30:21.752 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=1, ackNum=1, reTx=false, data=50 90 01 59 00 66 40 8B 26 D6 0E 10 38 C1 A4 FF EA 00]
16:30:21.752 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=2, notRdy=false]
16:30:21.752 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4066, sourceEui=A4C138100ED6268B, lastHopLqi=255, lastHopRssi=-22, relayList=]
16:30:21.758 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=2, ackNum=1, reTx=false, data=50 90 01 45 00 00 04 01 08 00 01 01 40 01 00 00 9C FF EA 66 40 FF FF 05 18 E2 0B 04 00 02]
16:30:21.758 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=3, notRdy=false]
16:30:21.758 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0008, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=9C], lastHopLqi=255, lastHopRssi=-22, sender=4066, bindingIndex=255, addressIndex=255, messageContents=18 E2 0B 04 00]
16:30:21.758 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4066/1, destinationAddress=0000/1, profile=0104, cluster=0008, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=9C, rssi=-22, lqi=FF, payload=18 E2 0B 04 00]
16:30:21.758 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C138100ED6268B: Node update. NWK Address=NULL
16:30:21.758 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C138100ED6268B: Node 4066 is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C138100ED6268B, NWK=----, endpoints=[]]
16:30:21.758 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=E2, commandId=11]
16:30:21.758 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DefaultResponse [Level Control: 4066/1 -> 0000/1, cluster=0008, TID=E2, commandIdentifier=4, statusCode=SUCCESS]
16:30:21.758 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [Level Control: 4066/1 -> 0000/1, cluster=0008, TID=E2, commandIdentifier=4, statusCode=SUCCESS]
16:30:21.758 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=A4C138100ED6268B queueTime=125, state=COMPLETE, sendCnt=1, command=MoveToLevelWithOnOffCommand [Level Control: 0000/0 -> 4066/1, cluster=0008, TID=E2, level=163, transitionTime=10]]
16:30:21.758 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding
16:30:21.758 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - A4C138100ED6268B: transactionComplete, state=COMPLETE, outstanding=0
16:30:21.758 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=2, sleepy=0/3
16:30:21.758 [DEBUG] [.transaction.ZigBeeTransactionManager] - 4066/1: Sending ZigBeeTransaction [ieeeAddress=A4C138100ED6268B queueTime=125, state=WAITING, sendCnt=0, command=MoveToHueAndSaturationCommand [Color Control: 0000/0 -> 4066/1, cluster=0300, TID=E4, hue=164, saturation=160, transitionTime=10]]
16:30:21.758 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding
16:30:21.758 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: MoveToHueAndSaturationCommand [Color Control: 0000/0 -> 4066/1, cluster=0300, TID=E4, hue=164, saturation=160, transitionTime=10]
16:30:21.758 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=E4, commandId=6]
16:30:21.758 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=4066/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=E9, rssi=--, lqi=--, payload=01 E4 06 A4 A0 0A 00]
16:30:21.758 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspSendUnicastRequest [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=4066, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=E9], messageTag=E4, messageContents=01 E4 06 A4 A0 0A 00]
16:30:21.758 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=1, ackNum=3, reTx=false, data=51 00 01 34 00 00 66 40 04 01 00 03 01 01 40 11 00 00 E9 E4 07 01 E4 06 A4 A0 0A 00]
16:30:21.779 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=3, ackNum=1, reTx=false, data=50 90 01 59 00 89 4F EF C0 03 A3 84 38 C1 A4 EC D7 00]
16:30:21.779 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=4, notRdy=false]
16:30:21.779 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4F89, sourceEui=A4C13884A303C0EF, lastHopLqi=236, lastHopRssi=-41, relayList=]
16:30:21.779 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=4, ackNum=2, reTx=false, data=51 84 01 34 00 00 6B]
16:30:21.779 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=5, notRdy=false]
16:30:21.779 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=6B]
16:30:21.779 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=5, ackNum=2, reTx=false, data=50 90 01 45 00 00 04 01 08 00 01 01 40 01 00 00 01 EC D7 89 4F FF FF 05 18 E3 0B 04 00 02]
16:30:21.779 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=6, notRdy=false]
16:30:21.779 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0008, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=01], lastHopLqi=236, lastHopRssi=-41, sender=4F89, bindingIndex=255, addressIndex=255, messageContents=18 E3 0B 04 00]
16:30:21.779 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4F89/1, destinationAddress=0000/1, profile=0104, cluster=0008, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=01, rssi=-41, lqi=EC, payload=18 E3 0B 04 00]
16:30:21.779 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C13884A303C0EF: Node update. NWK Address=NULL
16:30:21.779 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C13884A303C0EF: Node 4F89 is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C13884A303C0EF, NWK=----, endpoints=[]]
16:30:21.779 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=E3, commandId=11]
16:30:21.779 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DefaultResponse [Level Control: 4F89/1 -> 0000/1, cluster=0008, TID=E3, commandIdentifier=4, statusCode=SUCCESS]
16:30:21.779 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [Level Control: 4F89/1 -> 0000/1, cluster=0008, TID=E3, commandIdentifier=4, statusCode=SUCCESS]
16:30:21.779 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=A4C13884A303C0EF queueTime=146, state=COMPLETE, sendCnt=1, command=MoveToLevelWithOnOffCommand [Level Control: 0000/0 -> 4F89/1, cluster=0008, TID=E3, level=163, transitionTime=10]]
16:30:21.779 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding
16:30:21.779 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - A4C13884A303C0EF: transactionComplete, state=COMPLETE, outstanding=0
16:30:21.779 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3
16:30:21.779 [DEBUG] [.transaction.ZigBeeTransactionManager] - 4F89/1: Sending ZigBeeTransaction [ieeeAddress=A4C13884A303C0EF queueTime=146, state=WAITING, sendCnt=0, command=MoveToHueAndSaturationCommand [Color Control: 0000/0 -> 4F89/1, cluster=0300, TID=E5, hue=164, saturation=160, transitionTime=10]]
16:30:21.779 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding
16:30:21.779 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: MoveToHueAndSaturationCommand [Color Control: 0000/0 -> 4F89/1, cluster=0300, TID=E5, hue=164, saturation=160, transitionTime=10]
16:30:21.780 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=E5, commandId=6]
16:30:21.780 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=4F89/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=EA, rssi=--, lqi=--, payload=01 E5 06 A4 A0 0A 00]
16:30:21.780 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspSendUnicastRequest [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=4F89, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=EA], messageTag=E5, messageContents=01 E5 06 A4 A0 0A 00]
16:30:21.780 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=2, ackNum=6, reTx=false, data=52 00 01 34 00 00 89 4F 04 01 00 03 01 01 40 11 00 00 EA E5 07 01 E5 06 A4 A0 0A 00]
16:30:21.789 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=6, ackNum=3, reTx=false, data=52 80 01 34 00 00 6C]
16:30:21.789 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=7, notRdy=false]
16:30:21.789 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=6C]
16:30:21.914 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=7, ackNum=3, reTx=false, data=52 90 01 59 00 66 40 8B 26 D6 0E 10 38 C1 A4 FF EA 00]
16:30:21.914 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=0, notRdy=false]
16:30:21.914 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4066, sourceEui=A4C138100ED6268B, lastHopLqi=255, lastHopRssi=-22, relayList=]
16:30:21.918 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=0, ackNum=3, reTx=false, data=52 90 01 3F 00 00 66 40 04 01 00 03 01 01 40 11 00 00 6B E4 00 00]
16:30:21.918 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=1, notRdy=false]
16:30:21.918 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=4066, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=6B], messageTag=E4, status=EMBER_SUCCESS, messageContents=]
16:30:21.918 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=E4 state=RX_ACK
16:30:21.918 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=E4, state=RX_ACK, outstanding=2
16:30:21.918 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=4066, TID=E4, event=RX_ACK, state=ACKED
16:30:21.926 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=1, ackNum=3, reTx=false, data=52 90 01 59 00 89 4F EF C0 03 A3 84 38 C1 A4 EC D7 00]
16:30:21.926 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=2, notRdy=false]
16:30:21.926 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4F89, sourceEui=A4C13884A303C0EF, lastHopLqi=236, lastHopRssi=-41, relayList=]
16:30:21.930 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=2, ackNum=3, reTx=false, data=52 90 01 3F 00 00 89 4F 04 01 00 03 01 01 40 11 00 00 6C E5 00 00]
16:30:21.930 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=3, notRdy=false]
16:30:21.930 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=4F89, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=6C], messageTag=E5, status=EMBER_SUCCESS, messageContents=]
16:30:21.930 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=E5 state=RX_ACK
16:30:21.930 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=E5, state=RX_ACK, outstanding=2
16:30:21.930 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=4F89, TID=E5, event=RX_ACK, state=ACKED
16:30:21.954 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=3, ackNum=3, reTx=false, data=52 90 01 59 00 66 40 8B 26 D6 0E 10 38 C1 A4 FF EA 00]
16:30:21.954 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=4, notRdy=false]
16:30:21.954 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4066, sourceEui=A4C138100ED6268B, lastHopLqi=255, lastHopRssi=-22, relayList=]
16:30:21.960 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=4, ackNum=3, reTx=false, data=52 90 01 45 00 00 04 01 00 03 01 01 40 01 00 00 9D FF E9 66 40 FF FF 05 18 E4 0B 06 00 02]
16:30:21.960 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=5, notRdy=false]
16:30:21.960 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=9D], lastHopLqi=255, lastHopRssi=-23, sender=4066, bindingIndex=255, addressIndex=255, messageContents=18 E4 0B 06 00]
16:30:21.960 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4066/1, destinationAddress=0000/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=9D, rssi=-23, lqi=FF, payload=18 E4 0B 06 00]
16:30:21.960 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C138100ED6268B: Node update. NWK Address=NULL
16:30:21.960 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C138100ED6268B: Node 4066 is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C138100ED6268B, NWK=----, endpoints=[]]
16:30:21.960 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=E4, commandId=11]
16:30:21.960 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DefaultResponse [Color Control: 4066/1 -> 0000/1, cluster=0300, TID=E4, commandIdentifier=6, statusCode=SUCCESS]
16:30:21.960 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [Color Control: 4066/1 -> 0000/1, cluster=0300, TID=E4, commandIdentifier=6, statusCode=SUCCESS]
16:30:21.960 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=A4C138100ED6268B queueTime=327, state=COMPLETE, sendCnt=1, command=MoveToHueAndSaturationCommand [Color Control: 0000/0 -> 4066/1, cluster=0300, TID=E4, hue=164, saturation=160, transitionTime=10]]
16:30:21.960 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding
16:30:21.960 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - A4C138100ED6268B: Channel zigbee:device:3ea840067f:a4c138100ed6268b:A4C138100ED6268B_1_color received SUCCESS in response to 232,63,64
16:30:21.960 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - A4C138100ED6268B: transactionComplete, state=COMPLETE, outstanding=0
16:30:21.960 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=0, sleepy=0/3
16:30:21.960 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - A4C138100ED6268B: Channel zigbee:device:3ea840067f:a4c138100ed6268b:A4C138100ED6268B_1_color updated to 232,63,64
16:30:21.960 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C138100ED6268B: Updating ZigBee channel state zigbee:device:3ea840067f:a4c138100ed6268b:A4C138100ED6268B_1_color to 232,63,64
16:30:21.960 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:3ea840067f:a4c138100ed6268b
16:30:21.960 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:3ea840067f:a4c138100ed6268b
16:30:21.960 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:3ea840067f:a4c138100ed6268b in 14430 seconds
16:30:21.981 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=5, ackNum=3, reTx=false, data=52 90 01 59 00 89 4F EF C0 03 A3 84 38 C1 A4 EC D7 00]
16:30:21.981 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=6, notRdy=false]
16:30:21.981 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4F89, sourceEui=A4C13884A303C0EF, lastHopLqi=236, lastHopRssi=-41, relayList=]
16:30:21.981 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=6, ackNum=3, reTx=false, data=52 90 01 45 00 00 04 01 00 03 01 01 40 01 00 00 02 EC D7 89 4F FF FF 05 18 E5 0B 06 00 02]
16:30:21.981 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=7, notRdy=false]
16:30:21.981 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=02], lastHopLqi=236, lastHopRssi=-41, sender=4F89, bindingIndex=255, addressIndex=255, messageContents=18 E5 0B 06 00]
16:30:21.981 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4F89/1, destinationAddress=0000/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=02, rssi=-41, lqi=EC, payload=18 E5 0B 06 00]
16:30:21.981 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C13884A303C0EF: Node update. NWK Address=NULL
16:30:21.981 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C13884A303C0EF: Node 4F89 is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C13884A303C0EF, NWK=----, endpoints=[]]
16:30:21.981 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=E5, commandId=11]
16:30:21.981 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DefaultResponse [Color Control: 4F89/1 -> 0000/1, cluster=0300, TID=E5, commandIdentifier=6, statusCode=SUCCESS]
16:30:21.981 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [Color Control: 4F89/1 -> 0000/1, cluster=0300, TID=E5, commandIdentifier=6, statusCode=SUCCESS]
16:30:21.981 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=A4C13884A303C0EF queueTime=348, state=COMPLETE, sendCnt=1, command=MoveToHueAndSaturationCommand [Color Control: 0000/0 -> 4F89/1, cluster=0300, TID=E5, hue=164, saturation=160, transitionTime=10]]
16:30:21.981 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
16:30:21.981 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - A4C13884A303C0EF: Channel zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color received SUCCESS in response to 232,63,64
16:30:21.982 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - A4C13884A303C0EF: transactionComplete, state=COMPLETE, outstanding=0
16:30:21.982 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - A4C13884A303C0EF: Channel zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color updated to 232,63,64
16:30:21.982 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=0, sleepy=0/3
16:30:21.982 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C13884A303C0EF: Updating ZigBee channel state zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color to 232,63,64
16:30:21.982 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef
16:30:21.982 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef
16:30:21.982 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef in 14430 seconds
16:30:22.168 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=7, ackNum=3, reTx=false, data=52 90 01 59 00 89 4F EF C0 03 A3 84 38 C1 A4 EC D7 00]
16:30:22.168 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=0, notRdy=false]
16:30:22.168 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4F89, sourceEui=A4C13884A303C0EF, lastHopLqi=236, lastHopRssi=-41, relayList=]
16:30:22.176 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=0, ackNum=3, reTx=false, data=52 90 01 45 00 00 04 01 00 03 01 01 40 01 00 00 03 F0 D8 89 4F FF FF 07 18 6D 0A 00 00 20 C0 02]
16:30:22.176 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=1, notRdy=false]
16:30:22.176 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=03], lastHopLqi=240, lastHopRssi=-40, sender=4F89, bindingIndex=255, addressIndex=255, messageContents=18 6D 0A 00 00 20 C0]
16:30:22.176 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4F89/1, destinationAddress=0000/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=03, rssi=-40, lqi=F0, payload=18 6D 0A 00 00 20 C0]
16:30:22.176 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C13884A303C0EF: Node update. NWK Address=NULL
16:30:22.176 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C13884A303C0EF: Node 4F89 is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C13884A303C0EF, NWK=----, endpoints=[]]
16:30:22.176 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=6D, commandId=10]
16:30:22.176 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Color Control: 4F89/1 -> 0000/1, cluster=0300, TID=6D, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=192]]]
16:30:22.176 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Color Control: 4F89/1 -> 0000/1, cluster=0300, TID=6D, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=192]]]
16:30:22.176 [DEBUG] [l.converter.ZigBeeConverterColorColor] - A4C13884A303C0EF: ZigBee attribute reports ZclAttribute [cluster=Color Control, id=0, name=Current Hue, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=192, lastReportTime=Sun Jun 02 16:30:22 CDT 2024, implemented=true]
16:30:22.176 [DEBUG] [erter.ZigBeeConverterColorTemperature] - A4C13884A303C0EF: ZigBee attribute reports ZclAttribute [cluster=Color Control, id=0, name=Current Hue, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=192, lastReportTime=Sun Jun 02 16:30:22 CDT 2024, implemented=true] on endpoint 1
16:30:22.192 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=1, ackNum=3, reTx=false, data=52 90 01 59 00 89 4F EF C0 03 A3 84 38 C1 A4 EC D7 00]
16:30:22.192 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=2, notRdy=false]
16:30:22.192 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4F89, sourceEui=A4C13884A303C0EF, lastHopLqi=236, lastHopRssi=-41, relayList=]
16:30:22.198 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=2, ackNum=3, reTx=false, data=52 90 01 45 00 00 04 01 00 03 01 01 40 01 00 00 04 EC D7 89 4F FF FF 07 18 6E 0A 01 00 20 EE 02]
16:30:22.198 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=3, notRdy=false]
16:30:22.198 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=04], lastHopLqi=236, lastHopRssi=-41, sender=4F89, bindingIndex=255, addressIndex=255, messageContents=18 6E 0A 01 00 20 EE]
16:30:22.198 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4F89/1, destinationAddress=0000/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=04, rssi=-41, lqi=EC, payload=18 6E 0A 01 00 20 EE]
16:30:22.198 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C13884A303C0EF: Node update. NWK Address=NULL
16:30:22.198 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C13884A303C0EF: Node 4F89 is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C13884A303C0EF, NWK=----, endpoints=[]]
16:30:22.198 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=6E, commandId=10]
16:30:22.198 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Color Control: 4F89/1 -> 0000/1, cluster=0300, TID=6E, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=1, attributeValue=238]]]
16:30:22.198 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Color Control: 4F89/1 -> 0000/1, cluster=0300, TID=6E, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=1, attributeValue=238]]]
16:30:22.198 [DEBUG] [erter.ZigBeeConverterColorTemperature] - A4C13884A303C0EF: ZigBee attribute reports ZclAttribute [cluster=Color Control, id=1, name=Current Saturation, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=238, lastReportTime=Sun Jun 02 16:30:22 CDT 2024, implemented=true] on endpoint 1
16:30:22.198 [DEBUG] [l.converter.ZigBeeConverterColorColor] - A4C13884A303C0EF: ZigBee attribute reports ZclAttribute [cluster=Color Control, id=1, name=Current Saturation, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=238, lastReportTime=Sun Jun 02 16:30:22 CDT 2024, implemented=true]
16:30:22.198 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - A4C13884A303C0EF: Channel zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color updated to 272.12598,93.70079,50
16:30:22.198 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C13884A303C0EF: Updating ZigBee channel state zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color to 272.12598,93.70079,50
16:30:22.198 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef
16:30:22.198 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef
16:30:22.198 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef in 14430 seconds
16:30:22.217 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=3, ackNum=3, reTx=false, data=52 90 01 59 00 89 4F EF C0 03 A3 84 38 C1 A4 EC D7 00]
16:30:22.217 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=4, notRdy=false]
16:30:22.217 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4F89, sourceEui=A4C13884A303C0EF, lastHopLqi=236, lastHopRssi=-41, relayList=]
16:30:22.223 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=4, ackNum=3, reTx=false, data=52 90 01 45 00 00 04 01 08 00 01 01 40 01 00 00 05 EC D7 89 4F FF FF 07 18 6F 0A 00 00 20 8C 02]
16:30:22.223 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=5, notRdy=false]
16:30:22.223 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0008, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=05], lastHopLqi=236, lastHopRssi=-41, sender=4F89, bindingIndex=255, addressIndex=255, messageContents=18 6F 0A 00 00 20 8C]
16:30:22.223 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4F89/1, destinationAddress=0000/1, profile=0104, cluster=0008, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=05, rssi=-41, lqi=EC, payload=18 6F 0A 00 00 20 8C]
16:30:22.223 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C13884A303C0EF: Node update. NWK Address=NULL
16:30:22.223 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C13884A303C0EF: Node 4F89 is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C13884A303C0EF, NWK=----, endpoints=[]]
16:30:22.223 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=6F, commandId=10]
16:30:22.223 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Level Control: 4F89/1 -> 0000/1, cluster=0008, TID=6F, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=140]]]
16:30:22.223 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Level Control: 4F89/1 -> 0000/1, cluster=0008, TID=6F, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=140]]]
16:30:22.223 [DEBUG] [l.converter.ZigBeeConverterColorColor] - A4C13884A303C0EF: ZigBee attribute reports ZclAttribute [cluster=Level Control, id=0, name=Current Level, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=140, lastReportTime=Sun Jun 02 16:30:22 CDT 2024, implemented=true]
16:30:22.223 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - A4C13884A303C0EF: Channel zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color updated to 272.12598,93.70079,55
16:30:22.223 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C13884A303C0EF: Updating ZigBee channel state zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color to 272.12598,93.70079,55
16:30:22.223 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef
16:30:22.223 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef
16:30:22.223 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef in 14430 seconds
16:30:22.416 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=5, ackNum=3, reTx=false, data=52 90 01 59 00 66 40 8B 26 D6 0E 10 38 C1 A4 FF EA 00]
16:30:22.416 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=6, notRdy=false]
16:30:22.416 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4066, sourceEui=A4C138100ED6268B, lastHopLqi=255, lastHopRssi=-22, relayList=]
16:30:22.422 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=6, ackNum=3, reTx=false, data=52 90 01 45 00 00 04 01 00 03 01 01 40 01 00 00 9E FF EA 66 40 FF FF 07 18 97 0A 00 00 20 B7 02]
16:30:22.422 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=7, notRdy=false]
16:30:22.422 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=9E], lastHopLqi=255, lastHopRssi=-22, sender=4066, bindingIndex=255, addressIndex=255, messageContents=18 97 0A 00 00 20 B7]
16:30:22.422 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4066/1, destinationAddress=0000/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=9E, rssi=-22, lqi=FF, payload=18 97 0A 00 00 20 B7]
16:30:22.422 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C138100ED6268B: Node update. NWK Address=NULL
16:30:22.422 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C138100ED6268B: Node 4066 is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C138100ED6268B, NWK=----, endpoints=[]]
16:30:22.422 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=97, commandId=10]
16:30:22.422 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Color Control: 4066/1 -> 0000/1, cluster=0300, TID=97, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=183]]]
16:30:22.422 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Color Control: 4066/1 -> 0000/1, cluster=0300, TID=97, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=183]]]
16:30:22.422 [DEBUG] [l.converter.ZigBeeConverterColorColor] - A4C138100ED6268B: ZigBee attribute reports ZclAttribute [cluster=Color Control, id=0, name=Current Hue, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=183, lastReportTime=Sun Jun 02 16:30:22 CDT 2024, implemented=true]
16:30:22.422 [DEBUG] [erter.ZigBeeConverterColorTemperature] - A4C138100ED6268B: ZigBee attribute reports ZclAttribute [cluster=Color Control, id=0, name=Current Hue, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=183, lastReportTime=Sun Jun 02 16:30:22 CDT 2024, implemented=true] on endpoint 1
16:30:22.438 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=7, ackNum=3, reTx=false, data=52 90 01 59 00 66 40 8B 26 D6 0E 10 38 C1 A4 FF EA 00]
16:30:22.438 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=0, notRdy=false]
16:30:22.438 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4066, sourceEui=A4C138100ED6268B, lastHopLqi=255, lastHopRssi=-22, relayList=]
16:30:22.446 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=0, ackNum=3, reTx=false, data=52 90 01 45 00 00 04 01 00 03 01 01 40 01 00 00 9F FF EA 66 40 FF FF 07 18 98 0A 01 00 20 D6 02]
16:30:22.446 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=1, notRdy=false]
16:30:22.446 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=9F], lastHopLqi=255, lastHopRssi=-22, sender=4066, bindingIndex=255, addressIndex=255, messageContents=18 98 0A 01 00 20 D6]
16:30:22.446 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4066/1, destinationAddress=0000/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=9F, rssi=-22, lqi=FF, payload=18 98 0A 01 00 20 D6]
16:30:22.446 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C138100ED6268B: Node update. NWK Address=NULL
16:30:22.446 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C138100ED6268B: Node 4066 is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C138100ED6268B, NWK=----, endpoints=[]]
16:30:22.446 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=98, commandId=10]
16:30:22.446 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Color Control: 4066/1 -> 0000/1, cluster=0300, TID=98, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=1, attributeValue=214]]]
16:30:22.446 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Color Control: 4066/1 -> 0000/1, cluster=0300, TID=98, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=1, attributeValue=214]]]
16:30:22.446 [DEBUG] [l.converter.ZigBeeConverterColorColor] - A4C138100ED6268B: ZigBee attribute reports ZclAttribute [cluster=Color Control, id=1, name=Current Saturation, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=214, lastReportTime=Sun Jun 02 16:30:22 CDT 2024, implemented=true]
16:30:22.446 [DEBUG] [erter.ZigBeeConverterColorTemperature] - A4C138100ED6268B: ZigBee attribute reports ZclAttribute [cluster=Color Control, id=1, name=Current Saturation, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=214, lastReportTime=Sun Jun 02 16:30:22 CDT 2024, implemented=true] on endpoint 1
16:30:22.446 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - A4C138100ED6268B: Channel zigbee:device:3ea840067f:a4c138100ed6268b:A4C138100ED6268B_1_color updated to 259.3701,84.25197,50
16:30:22.446 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C138100ED6268B: Updating ZigBee channel state zigbee:device:3ea840067f:a4c138100ed6268b:A4C138100ED6268B_1_color to 259.3701,84.25197,50
16:30:22.446 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:3ea840067f:a4c138100ed6268b
16:30:22.446 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:3ea840067f:a4c138100ed6268b
16:30:22.446 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:3ea840067f:a4c138100ed6268b in 14430 seconds
16:30:22.462 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=1, ackNum=3, reTx=false, data=52 90 01 59 00 66 40 8B 26 D6 0E 10 38 C1 A4 FF EA 00]
16:30:22.462 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=2, notRdy=false]
16:30:22.462 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4066, sourceEui=A4C138100ED6268B, lastHopLqi=255, lastHopRssi=-22, relayList=]
16:30:22.470 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=2, ackNum=3, reTx=false, data=52 90 01 45 00 00 04 01 08 00 01 01 40 01 00 00 A0 FF EB 66 40 FF FF 07 18 99 0A 00 00 20 95 02]
16:30:22.470 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=3, notRdy=false]
16:30:22.470 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0008, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=A0], lastHopLqi=255, lastHopRssi=-21, sender=4066, bindingIndex=255, addressIndex=255, messageContents=18 99 0A 00 00 20 95]
16:30:22.470 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4066/1, destinationAddress=0000/1, profile=0104, cluster=0008, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=A0, rssi=-21, lqi=FF, payload=18 99 0A 00 00 20 95]
16:30:22.470 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C138100ED6268B: Node update. NWK Address=NULL
16:30:22.470 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C138100ED6268B: Node 4066 is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C138100ED6268B, NWK=----, endpoints=[]]
16:30:22.470 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=99, commandId=10]
16:30:22.470 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Level Control: 4066/1 -> 0000/1, cluster=0008, TID=99, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=149]]]
16:30:22.470 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Level Control: 4066/1 -> 0000/1, cluster=0008, TID=99, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=149]]]
16:30:22.470 [DEBUG] [l.converter.ZigBeeConverterColorColor] - A4C138100ED6268B: ZigBee attribute reports ZclAttribute [cluster=Level Control, id=0, name=Current Level, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=149, lastReportTime=Sun Jun 02 16:30:22 CDT 2024, implemented=true]
16:30:22.470 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - A4C138100ED6268B: Channel zigbee:device:3ea840067f:a4c138100ed6268b:A4C138100ED6268B_1_color updated to 259.3701,84.25197,59
16:30:22.470 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C138100ED6268B: Updating ZigBee channel state zigbee:device:3ea840067f:a4c138100ed6268b:A4C138100ED6268B_1_color to 259.3701,84.25197,59
16:30:22.470 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:3ea840067f:a4c138100ed6268b
16:30:22.470 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:3ea840067f:a4c138100ed6268b
16:30:22.470 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:3ea840067f:a4c138100ed6268b in 14430 seconds
16:30:22.633 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Generic_MQTT_Thing_Color' changed from 232,63,64 to 192,86,83
16:30:22.634 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C1381B88FD55A7: Command for channel zigbee:device:3ea840067f:a4c1381b88fd55a7:A4C1381B88FD55A7_1_color --> 192,86,83 [HSBType]
16:30:22.634 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C13884A303C0EF: Command for channel zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color --> 192,86,83 [HSBType]
16:30:22.634 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C138100ED6268B: Command for channel zigbee:device:3ea840067f:a4c138100ed6268b:A4C138100ED6268B_1_color --> 192,86,83 [HSBType]
16:30:22.634 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C1381B88FD55A7: No handler found for zigbee:device:3ea840067f:a4c1381b88fd55a7:A4C1381B88FD55A7_1_color
16:30:22.634 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - A4C13884A303C0EF: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=A4C13884A303C0EF queueTime=0, state=WAITING, sendCnt=0, command=MoveToLevelWithOnOffCommand [Level Control: 0000/0 -> 4F89/1, cluster=0008, TID=--, level=211, transitionTime=10]]
16:30:22.634 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3
16:30:22.634 [DEBUG] [.transaction.ZigBeeTransactionManager] - 4F89/1: Sending ZigBeeTransaction [ieeeAddress=A4C13884A303C0EF queueTime=0, state=WAITING, sendCnt=0, command=MoveToLevelWithOnOffCommand [Level Control: 0000/0 -> 4F89/1, cluster=0008, TID=E6, level=211, transitionTime=10]]
16:30:22.634 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
16:30:22.634 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: MoveToLevelWithOnOffCommand [Level Control: 0000/0 -> 4F89/1, cluster=0008, TID=E6, level=211, transitionTime=10]
16:30:22.634 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=E6, commandId=4]
16:30:22.634 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=4F89/1, profile=0104, cluster=0008, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=EB, rssi=--, lqi=--, payload=01 E6 04 D3 0A 00]
16:30:22.634 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - A4C138100ED6268B: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=A4C138100ED6268B queueTime=0, state=WAITING, sendCnt=0, command=MoveToLevelWithOnOffCommand [Level Control: 0000/0 -> 4066/1, cluster=0008, TID=--, level=211, transitionTime=10]]
16:30:22.634 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspSendUnicastRequest [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=4F89, apsFrame=EmberApsFrame [profileId=0104, clusterId=0008, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=EB], messageTag=E6, messageContents=01 E6 04 D3 0A 00]
16:30:22.634 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3
16:30:22.634 [DEBUG] [.transaction.ZigBeeTransactionManager] - 4066/1: Sending ZigBeeTransaction [ieeeAddress=A4C138100ED6268B queueTime=0, state=WAITING, sendCnt=0, command=MoveToLevelWithOnOffCommand [Level Control: 0000/0 -> 4066/1, cluster=0008, TID=E7, level=211, transitionTime=10]]
16:30:22.634 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding
16:30:22.634 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: MoveToLevelWithOnOffCommand [Level Control: 0000/0 -> 4066/1, cluster=0008, TID=E7, level=211, transitionTime=10]
16:30:22.634 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=3, ackNum=3, reTx=false, data=53 00 01 34 00 00 89 4F 04 01 08 00 01 01 40 11 00 00 EB E6 06 01 E6 04 D3 0A 00]
16:30:22.634 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=E7, commandId=4]
16:30:22.634 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=4066/1, profile=0104, cluster=0008, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=EC, rssi=--, lqi=--, payload=01 E7 04 D3 0A 00]
16:30:22.634 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - A4C13884A303C0EF: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=A4C13884A303C0EF queueTime=0, state=WAITING, sendCnt=0, command=MoveToHueAndSaturationCommand [Color Control: 0000/0 -> 4F89/1, cluster=0300, TID=--, hue=135, saturation=218, transitionTime=10]]
16:30:22.634 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=2, outstandingQueues=1, sleepy=0/3
16:30:22.634 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - A4C13884A303C0EF: Channel zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color waiting for response to 192,86,83
16:30:22.634 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - A4C138100ED6268B: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=A4C138100ED6268B queueTime=0, state=WAITING, sendCnt=0, command=MoveToHueAndSaturationCommand [Color Control: 0000/0 -> 4066/1, cluster=0300, TID=--, hue=135, saturation=218, transitionTime=10]]
16:30:22.634 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=2, outstandingQueues=2, sleepy=0/3
16:30:22.634 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - A4C138100ED6268B: Channel zigbee:device:3ea840067f:a4c138100ed6268b:A4C138100ED6268B_1_color waiting for response to 192,86,83
16:30:22.642 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=3, ackNum=4, reTx=false, data=53 80 01 34 00 00 6D]
16:30:22.642 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=4, notRdy=false]
16:30:22.642 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=6D]
16:30:22.642 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspSendUnicastRequest [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=4066, apsFrame=EmberApsFrame [profileId=0104, clusterId=0008, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=EC], messageTag=E7, messageContents=01 E7 04 D3 0A 00]
16:30:22.642 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=4, ackNum=4, reTx=false, data=54 00 01 34 00 00 66 40 04 01 08 00 01 01 40 11 00 00 EC E7 06 01 E7 04 D3 0A 00]
16:30:22.650 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=4, ackNum=5, reTx=false, data=54 80 01 34 00 00 6E]
16:30:22.650 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=5, notRdy=false]
16:30:22.650 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=6E]
16:30:22.685 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=2, outstandingQueues=2, sleepy=0/3
16:30:22.726 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=5, ackNum=5, reTx=false, data=54 90 01 59 00 89 4F EF C0 03 A3 84 38 C1 A4 EC D7 00]
16:30:22.726 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=6, notRdy=false]
16:30:22.726 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4F89, sourceEui=A4C13884A303C0EF, lastHopLqi=236, lastHopRssi=-41, relayList=]
16:30:22.730 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=6, ackNum=5, reTx=false, data=54 90 01 3F 00 00 89 4F 04 01 08 00 01 01 40 11 00 00 6D E6 00 00]
16:30:22.730 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=7, notRdy=false]
16:30:22.730 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=4F89, apsFrame=EmberApsFrame [profileId=0104, clusterId=0008, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=6D], messageTag=E6, status=EMBER_SUCCESS, messageContents=]
16:30:22.730 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=E6 state=RX_ACK
16:30:22.730 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=E6, state=RX_ACK, outstanding=2
16:30:22.730 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=4F89, TID=E6, event=RX_ACK, state=ACKED
16:30:22.756 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=7, ackNum=5, reTx=false, data=54 90 01 59 00 66 40 8B 26 D6 0E 10 38 C1 A4 FF EA 00]
16:30:22.756 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=0, notRdy=false]
16:30:22.756 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4066, sourceEui=A4C138100ED6268B, lastHopLqi=255, lastHopRssi=-22, relayList=]
16:30:22.760 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=0, ackNum=5, reTx=false, data=54 90 01 3F 00 00 66 40 04 01 08 00 01 01 40 11 00 00 6E E7 00 00]
16:30:22.760 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=1, notRdy=false]
16:30:22.760 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=4066, apsFrame=EmberApsFrame [profileId=0104, clusterId=0008, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=6E], messageTag=E7, status=EMBER_SUCCESS, messageContents=]
16:30:22.760 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=E7 state=RX_ACK
16:30:22.760 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=E7, state=RX_ACK, outstanding=2
16:30:22.760 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=4066, TID=E7, event=RX_ACK, state=ACKED
16:30:22.780 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=1, ackNum=5, reTx=false, data=54 90 01 59 00 89 4F EF C0 03 A3 84 38 C1 A4 EC D7 00]
16:30:22.780 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=2, notRdy=false]
16:30:22.780 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4F89, sourceEui=A4C13884A303C0EF, lastHopLqi=236, lastHopRssi=-41, relayList=]
16:30:22.780 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=2, ackNum=5, reTx=false, data=54 90 01 45 00 00 04 01 08 00 01 01 40 01 00 00 06 EC D7 89 4F FF FF 05 18 E6 0B 04 00 02]
16:30:22.780 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=3, notRdy=false]
16:30:22.780 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0008, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=06], lastHopLqi=236, lastHopRssi=-41, sender=4F89, bindingIndex=255, addressIndex=255, messageContents=18 E6 0B 04 00]
16:30:22.780 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4F89/1, destinationAddress=0000/1, profile=0104, cluster=0008, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=06, rssi=-41, lqi=EC, payload=18 E6 0B 04 00]
16:30:22.780 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C13884A303C0EF: Node update. NWK Address=NULL
16:30:22.780 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C13884A303C0EF: Node 4F89 is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C13884A303C0EF, NWK=----, endpoints=[]]
16:30:22.780 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=E6, commandId=11]
16:30:22.780 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DefaultResponse [Level Control: 4F89/1 -> 0000/1, cluster=0008, TID=E6, commandIdentifier=4, statusCode=SUCCESS]
16:30:22.780 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [Level Control: 4F89/1 -> 0000/1, cluster=0008, TID=E6, commandIdentifier=4, statusCode=SUCCESS]
16:30:22.780 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=A4C13884A303C0EF queueTime=146, state=COMPLETE, sendCnt=1, command=MoveToLevelWithOnOffCommand [Level Control: 0000/0 -> 4F89/1, cluster=0008, TID=E6, level=211, transitionTime=10]]
16:30:22.780 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding
16:30:22.780 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - A4C13884A303C0EF: transactionComplete, state=COMPLETE, outstanding=0
16:30:22.780 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=2, sleepy=0/3
16:30:22.780 [DEBUG] [.transaction.ZigBeeTransactionManager] - 4F89/1: Sending ZigBeeTransaction [ieeeAddress=A4C13884A303C0EF queueTime=146, state=WAITING, sendCnt=0, command=MoveToHueAndSaturationCommand [Color Control: 0000/0 -> 4F89/1, cluster=0300, TID=E8, hue=135, saturation=218, transitionTime=10]]
16:30:22.780 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding
16:30:22.780 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: MoveToHueAndSaturationCommand [Color Control: 0000/0 -> 4F89/1, cluster=0300, TID=E8, hue=135, saturation=218, transitionTime=10]
16:30:22.780 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=E8, commandId=6]
16:30:22.780 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=4F89/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=ED, rssi=--, lqi=--, payload=01 E8 06 87 DA 0A 00]
16:30:22.781 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspSendUnicastRequest [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=4F89, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=ED], messageTag=E8, messageContents=01 E8 06 87 DA 0A 00]
16:30:22.781 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=5, ackNum=3, reTx=false, data=55 00 01 34 00 00 89 4F 04 01 00 03 01 01 40 11 00 00 ED E8 07 01 E8 06 87 DA 0A 00]
16:30:22.790 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=3, ackNum=6, reTx=false, data=55 80 01 34 00 00 6F]
16:30:22.790 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=4, notRdy=false]
16:30:22.790 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=6F]
16:30:22.836 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=4, ackNum=6, reTx=false, data=55 90 01 59 00 66 40 8B 26 D6 0E 10 38 C1 A4 FF EA 00]
16:30:22.836 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=5, notRdy=false]
16:30:22.836 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4066, sourceEui=A4C138100ED6268B, lastHopLqi=255, lastHopRssi=-22, relayList=]
16:30:22.844 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=5, ackNum=6, reTx=false, data=55 90 01 45 00 00 04 01 08 00 01 01 40 01 00 00 A1 FF EA 66 40 FF FF 05 18 E7 0B 04 00 02]
16:30:22.844 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=6, notRdy=false]
16:30:22.844 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0008, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=A1], lastHopLqi=255, lastHopRssi=-22, sender=4066, bindingIndex=255, addressIndex=255, messageContents=18 E7 0B 04 00]
16:30:22.844 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4066/1, destinationAddress=0000/1, profile=0104, cluster=0008, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=A1, rssi=-22, lqi=FF, payload=18 E7 0B 04 00]
16:30:22.844 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C138100ED6268B: Node update. NWK Address=NULL
16:30:22.844 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C138100ED6268B: Node 4066 is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C138100ED6268B, NWK=----, endpoints=[]]
16:30:22.844 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=E7, commandId=11]
16:30:22.844 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DefaultResponse [Level Control: 4066/1 -> 0000/1, cluster=0008, TID=E7, commandIdentifier=4, statusCode=SUCCESS]
16:30:22.844 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [Level Control: 4066/1 -> 0000/1, cluster=0008, TID=E7, commandIdentifier=4, statusCode=SUCCESS]
16:30:22.844 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=A4C138100ED6268B queueTime=210, state=COMPLETE, sendCnt=1, command=MoveToLevelWithOnOffCommand [Level Control: 0000/0 -> 4066/1, cluster=0008, TID=E7, level=211, transitionTime=10]]
16:30:22.844 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding
16:30:22.844 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - A4C138100ED6268B: transactionComplete, state=COMPLETE, outstanding=0
16:30:22.844 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3
16:30:22.844 [DEBUG] [.transaction.ZigBeeTransactionManager] - 4066/1: Sending ZigBeeTransaction [ieeeAddress=A4C138100ED6268B queueTime=210, state=WAITING, sendCnt=0, command=MoveToHueAndSaturationCommand [Color Control: 0000/0 -> 4066/1, cluster=0300, TID=E9, hue=135, saturation=218, transitionTime=10]]
16:30:22.844 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding
16:30:22.844 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: MoveToHueAndSaturationCommand [Color Control: 0000/0 -> 4066/1, cluster=0300, TID=E9, hue=135, saturation=218, transitionTime=10]
16:30:22.844 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=E9, commandId=6]
16:30:22.844 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=4066/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=EE, rssi=--, lqi=--, payload=01 E9 06 87 DA 0A 00]
16:30:22.844 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspSendUnicastRequest [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=4066, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=EE], messageTag=E9, messageContents=01 E9 06 87 DA 0A 00]
16:30:22.844 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=6, ackNum=6, reTx=false, data=56 00 01 34 00 00 66 40 04 01 00 03 01 01 40 11 00 00 EE E9 07 01 E9 06 87 DA 0A 00]
16:30:22.852 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=6, ackNum=7, reTx=false, data=56 80 01 34 00 00 70]
16:30:22.852 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=7, notRdy=false]
16:30:22.852 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=70]
16:30:22.928 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=7, ackNum=7, reTx=false, data=56 90 01 59 00 89 4F EF C0 03 A3 84 38 C1 A4 F0 D8 00]
16:30:22.928 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=0, notRdy=false]
16:30:22.928 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4F89, sourceEui=A4C13884A303C0EF, lastHopLqi=240, lastHopRssi=-40, relayList=]
16:30:22.932 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=0, ackNum=7, reTx=false, data=56 90 01 3F 00 00 89 4F 04 01 00 03 01 01 40 11 00 00 6F E8 00 00]
16:30:22.932 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=1, notRdy=false]
16:30:22.932 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=4F89, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=6F], messageTag=E8, status=EMBER_SUCCESS, messageContents=]
16:30:22.932 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=E8 state=RX_ACK
16:30:22.932 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=E8, state=RX_ACK, outstanding=2
16:30:22.932 [DEBUG] [.zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=4F89, TID=E8, event=RX_ACK, state=ACKED
16:30:22.972 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=1, ackNum=7, reTx=false, data=56 90 01 59 00 89 4F EF C0 03 A3 84 38 C1 A4 F0 D8 00]
16:30:22.972 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=2, notRdy=false]
16:30:22.972 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4F89, sourceEui=A4C13884A303C0EF, lastHopLqi=240, lastHopRssi=-40, relayList=]
16:30:22.978 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=2, ackNum=7, reTx=false, data=56 90 01 45 00 00 04 01 00 03 01 01 40 01 00 00 07 F0 D8 89 4F FF FF 05 18 E8 0B 06 00 02]
16:30:22.978 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=3, notRdy=false]
16:30:22.978 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0300, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=07], lastHopLqi=240, lastHopRssi=-40, sender=4F89, bindingIndex=255, addressIndex=255, messageContents=18 E8 0B 06 00]
16:30:22.978 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=4F89/1, destinationAddress=0000/1, profile=0104, cluster=0300, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=07, rssi=-40, lqi=F0, payload=18 E8 0B 06 00]
16:30:22.978 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C13884A303C0EF: Node update. NWK Address=NULL
16:30:22.978 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - A4C13884A303C0EF: Node 4F89 is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C13884A303C0EF, NWK=----, endpoints=[]]
16:30:22.978 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=E8, commandId=11]
16:30:22.978 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DefaultResponse [Color Control: 4F89/1 -> 0000/1, cluster=0300, TID=E8, commandIdentifier=6, statusCode=SUCCESS]
16:30:22.978 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [Color Control: 4F89/1 -> 0000/1, cluster=0300, TID=E8, commandIdentifier=6, statusCode=SUCCESS]
16:30:22.978 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=A4C13884A303C0EF queueTime=344, state=COMPLETE, sendCnt=1, command=MoveToHueAndSaturationCommand [Color Control: 0000/0 -> 4F89/1, cluster=0300, TID=E8, hue=135, saturation=218, transitionTime=10]]
16:30:22.978 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - A4C13884A303C0EF: Channel zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color received SUCCESS in response to 192,86,83
16:30:22.978 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding
16:30:22.978 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - A4C13884A303C0EF: Channel zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color updated to 192,86,83
16:30:22.978 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - A4C13884A303C0EF: transactionComplete, state=COMPLETE, outstanding=0
16:30:22.978 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - A4C13884A303C0EF: Updating ZigBee channel state zigbee:device:3ea840067f:a4c13884a303c0ef:A4C13884A303C0EF_1_color to 192,86,83
16:30:22.978 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=0, sleepy=0/3
16:30:22.978 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef
16:30:22.978 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef
16:30:22.978 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:3ea840067f:a4c13884a303c0ef in 14430 seconds
16:30:23.010 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=3, ackNum=7, reTx=false, data=56 90 01 59 00 66 40 8B 26 D6 0E 10 38 C1 A4 FF EA 00]
16:30:23.010 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=4, notRdy=false]
16:30:23.010 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=4066, sourceEui=A4C138100ED6268B, lastHopLqi=255, lastHopRssi=-22, relayList=]
16:30:23.031 [DEBUG] [le.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=4, ackNum=7, reTx=false, data=56 90 01 3F 00 00 66 40 04 01 00 03 01 01 40 11 00 00 70 E9 00 00]