2020-11-05 19:58:14.745 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 40: Command received zwave:device:8bb688ce:node40:switch_dimmer --> 92 [PercentType] 2020-11-05 19:58:14.746 [TRACE] [.internal.converter.ZWaveMultiLevelSwitchConverter] - NODE 40: Converted command '92' to value 92 for channel = zwave:device:8bb688ce:node40:switch_dimmer, endpoint = 0. 2020-11-05 19:58:14.748 [DEBUG] [col.commandclass.ZWaveMultiLevelSwitchCommandClass] - NODE 40: Creating new message for command SWITCH_MULTILEVEL_SET 2020-11-05 19:58:14.750 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 40: Encapsulating message, endpoint 0 2020-11-05 19:58:14.755 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 40: SECURITY not supported 2020-11-05 19:58:14.756 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 40: Command Class COMMAND_CLASS_SWITCH_MULTILEVEL is NOT required to be secured 2020-11-05 19:58:14.757 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 40: Adding to device queue 2020-11-05 19:58:14.758 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 40: Added 129221 to queue - size 3 2020-11-05 19:58:14.759 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-11-05 19:58:14.760 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 36: listening == false, frequentlyListening == false, awake == false 2020-11-05 19:58:14.761 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 36: Node not awake! 2020-11-05 19:58:14.762 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 30: listening == false, frequentlyListening == false, awake == false 2020-11-05 19:58:14.763 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 30: Node not awake! 2020-11-05 19:58:14.764 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 40: listening == true, frequentlyListening == false, awake == false 2020-11-05 19:58:14.765 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction from sendQueue 2020-11-05 19:58:14.766 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - getTransactionToSend 6 2020-11-05 19:58:14.767 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 40: Creating empty message of class = SendData (0x13), type = Request 2020-11-05 19:58:14.769 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = -55 2020-11-05 19:58:14.770 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 28 03 26 01 5C 25 5A C9 2020-11-05 19:58:14.772 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 40: Sending REQUEST Message = 01 0A 00 13 28 03 26 01 5C 25 5A C9 2020-11-05 19:58:14.773 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-11-05 19:58:14.774 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129221: Transaction Start type SendData 2020-11-05 19:58:14.775 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-11-05 19:58:14.776 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 129221: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 90 2020-11-05 19:58:14.777 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 06 2020-11-05 19:58:14.777 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null 2020-11-05 19:58:14.778 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: 0 2020-11-05 19:58:14.778 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-05 19:58:14.779 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-05 19:58:14.780 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction null 2020-11-05 19:58:14.780 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1 2020-11-05 19:58:14.781 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF 2020-11-05 19:58:14.781 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:16 PST 2020 - 2000ms 2020-11-05 19:58:14.781 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-11-05 19:58:14.782 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 129221: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 90 2020-11-05 19:58:14.782 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-05 19:58:14.783 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-05 19:58:14.784 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding... 2020-11-05 19:58:14.785 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:14.785 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2020-11-05 19:58:14.786 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:16 PST 2020 - 1995ms 2020-11-05 19:58:14.787 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 04 01 13 01 E8 2020-11-05 19:58:14.787 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:14.788 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = -24 2020-11-05 19:58:14.788 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:16 PST 2020 - 1993ms 2020-11-05 19:58:14.789 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched 2020-11-05 19:58:14.789 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 40: Polling initialised at 86400 seconds - start in 1500 milliseconds. 2020-11-05 19:58:14.791 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Message payload = 01 2020-11-05 19:58:14.792 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK 2020-11-05 19:58:14.793 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT 6 2020-11-05 19:58:14.797 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:14.798 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:14.799 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 129221: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 90 2020-11-05 19:58:14.800 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-05 19:58:14.801 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 129221: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 90 2020-11-05 19:58:14.802 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:14.803 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE 2020-11-05 19:58:14.804 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Response 2020-11-05 19:58:14.805 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 40: sentData successfully placed on stack. 2020-11-05 19:58:14.806 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129221: TransactionAdvance ST: WAIT_RESPONSE 2020-11-05 19:58:14.807 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129221: TransactionAdvance WT: null {} 2020-11-05 19:58:14.808 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129221: TransactionAdvance RX: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:14.809 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129221: TransactionAdvance TO: WAIT_REQUEST 2020-11-05 19:58:14.810 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 129221: Advanced to WAIT_REQUEST 2020-11-05 19:58:14.811 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 40: TID 129221: Transaction not completed 2020-11-05 19:58:14.812 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-05 19:58:14.813 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-05 19:58:14.813 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding... 2020-11-05 19:58:14.814 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:14.815 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:19 PST 2020 - 4997ms 2020-11-05 19:58:14.822 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF 2020-11-05 19:58:14.824 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 5A 00 00 05 B4 2020-11-05 19:58:14.825 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 07 00 13 5A 00 00 05 B4 2020-11-05 19:58:14.826 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = -76 2020-11-05 19:58:14.827 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched 2020-11-05 19:58:14.829 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 0: Message payload = 5A 00 00 05 2020-11-05 19:58:14.829 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK 2020-11-05 19:58:14.831 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT 6 2020-11-05 19:58:14.832 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=90, payload=5A 00 00 05 2020-11-05 19:58:14.833 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=90, payload=5A 00 00 05 2020-11-05 19:58:14.834 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 129221: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 90 2020-11-05 19:58:14.835 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-05 19:58:14.835 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 129221: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 90 2020-11-05 19:58:14.836 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking TID 129221: (Callback 90) 2020-11-05 19:58:14.837 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-11-05 19:58:14.838 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Correlated to TID 129221: callback 90 2020-11-05 19:58:14.839 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=90, payload=5A 00 00 05 2020-11-05 19:58:14.840 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = REQUEST 2020-11-05 19:58:14.840 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Request 2020-11-05 19:58:14.841 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 40: SendData Request. CallBack ID = 90, Status = Transmission complete and ACK received(0) 2020-11-05 19:58:14.842 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 40: resetResendCount initComplete=true isDead=false 2020-11-05 19:58:14.843 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129221: Transaction COMPLETED 2020-11-05 19:58:14.844 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129221: TransactionAdvance ST: DONE 2020-11-05 19:58:14.844 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129221: TransactionAdvance WT: null {} 2020-11-05 19:58:14.845 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129221: TransactionAdvance RX: Message: class=SendData[19], type=Request[0], dest=0, callback=90, payload=5A 00 00 05 2020-11-05 19:58:14.846 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129221: TransactionAdvance TO: DONE 2020-11-05 19:58:14.847 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 40: Response processed after 73ms 2020-11-05 19:58:14.848 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 40: TID 129221: Transaction completed 2020-11-05 19:58:14.849 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 40: notifyTransactionResponse TID:129221 DONE 2020-11-05 19:58:14.850 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent 2020-11-05 19:58:14.851 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 40: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2020-11-05 19:58:14.851 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-05 19:58:14.852 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-11-05 19:58:14.853 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 36: listening == false, frequentlyListening == false, awake == false 2020-11-05 19:58:14.854 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 36: Node not awake! 2020-11-05 19:58:14.854 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 30: listening == false, frequentlyListening == false, awake == false 2020-11-05 19:58:14.855 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 30: Node not awake! 2020-11-05 19:58:14.856 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing 2020-11-05 19:58:14.857 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:16.289 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 40: Polling... 2020-11-05 19:58:16.290 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 40: Polling zwave:device:8bb688ce:node40:switch_dimmer 2020-11-05 19:58:16.291 [DEBUG] [.internal.converter.ZWaveMultiLevelSwitchConverter] - NODE 40: Generating poll message for COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0 2020-11-05 19:58:16.292 [DEBUG] [col.commandclass.ZWaveMultiLevelSwitchCommandClass] - NODE 40: Creating new message for command SWITCH_MULTILEVEL_GET 2020-11-05 19:58:16.292 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 40: Encapsulating message, endpoint 0 2020-11-05 19:58:16.293 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 40: SECURITY not supported 2020-11-05 19:58:16.294 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 40: Command Class COMMAND_CLASS_SWITCH_MULTILEVEL is NOT required to be secured 2020-11-05 19:58:16.294 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 40: Polling skipped for zwave:device:8bb688ce:node40:switch_dimmer on COMMAND_CLASS_BASIC 2020-11-05 19:58:16.295 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 40: Adding to device queue 2020-11-05 19:58:16.296 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 40: Added 129222 to queue - size 3 2020-11-05 19:58:16.296 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-11-05 19:58:16.297 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 36: listening == false, frequentlyListening == false, awake == false 2020-11-05 19:58:16.298 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 36: Node not awake! 2020-11-05 19:58:16.299 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 30: listening == false, frequentlyListening == false, awake == false 2020-11-05 19:58:16.299 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 30: Node not awake! 2020-11-05 19:58:16.300 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 40: listening == true, frequentlyListening == false, awake == false 2020-11-05 19:58:16.301 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction from sendQueue 2020-11-05 19:58:16.301 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - getTransactionToSend 6 2020-11-05 19:58:16.302 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 40: Creating empty message of class = SendData (0x13), type = Request 2020-11-05 19:58:16.303 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = -107 2020-11-05 19:58:16.304 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 28 02 26 02 25 5B 95 2020-11-05 19:58:16.305 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 40: Sending REQUEST Message = 01 09 00 13 28 02 26 02 25 5B 95 2020-11-05 19:58:16.306 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-11-05 19:58:16.307 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129222: Transaction Start type SendData 2020-11-05 19:58:16.308 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 129222: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 91 2020-11-05 19:58:16.308 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-11-05 19:58:16.308 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: COMMAND_CLASS_SWITCH_MULTILEVEL 2020-11-05 19:58:16.308 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 06 2020-11-05 19:58:16.309 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-05 19:58:16.309 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: 3 2020-11-05 19:58:16.309 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-05 19:58:16.310 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction null 2020-11-05 19:58:16.311 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1 2020-11-05 19:58:16.312 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-11-05 19:58:16.312 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:18 PST 2020 - 2000ms 2020-11-05 19:58:16.313 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 129222: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 91 2020-11-05 19:58:16.313 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-05 19:58:16.313 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-05 19:58:16.314 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF 2020-11-05 19:58:16.315 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding... 2020-11-05 19:58:16.315 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2020-11-05 19:58:16.315 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:16.316 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 04 01 13 01 E8 2020-11-05 19:58:16.317 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = -24 2020-11-05 19:58:16.317 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:18 PST 2020 - 1995ms 2020-11-05 19:58:16.318 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched 2020-11-05 19:58:16.318 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:16.318 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Message payload = 01 2020-11-05 19:58:16.319 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK 2020-11-05 19:58:16.319 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:18 PST 2020 - 1992ms 2020-11-05 19:58:16.320 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT 6 2020-11-05 19:58:16.321 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:16.321 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:16.322 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 129222: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 91 2020-11-05 19:58:16.323 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-05 19:58:16.324 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 129222: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 91 2020-11-05 19:58:16.325 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:16.326 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE 2020-11-05 19:58:16.327 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Response 2020-11-05 19:58:16.327 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 40: sentData successfully placed on stack. 2020-11-05 19:58:16.328 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129222: TransactionAdvance ST: WAIT_RESPONSE 2020-11-05 19:58:16.329 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129222: TransactionAdvance WT: ApplicationCommandHandler {} 2020-11-05 19:58:16.330 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129222: TransactionAdvance RX: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:16.331 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129222: TransactionAdvance TO: WAIT_REQUEST 2020-11-05 19:58:16.332 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 129222: Advanced to WAIT_REQUEST 2020-11-05 19:58:16.333 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 40: TID 129222: Transaction not completed 2020-11-05 19:58:16.333 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-05 19:58:16.334 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-05 19:58:16.335 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding... 2020-11-05 19:58:16.336 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:16.337 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:21 PST 2020 - 4997ms 2020-11-05 19:58:16.355 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF 2020-11-05 19:58:16.357 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 5B 00 00 04 B4 2020-11-05 19:58:16.358 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 07 00 13 5B 00 00 04 B4 2020-11-05 19:58:16.358 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = -76 2020-11-05 19:58:16.359 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched 2020-11-05 19:58:16.360 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 0: Message payload = 5B 00 00 04 2020-11-05 19:58:16.360 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK 2020-11-05 19:58:16.361 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT 6 2020-11-05 19:58:16.362 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=91, payload=5B 00 00 04 2020-11-05 19:58:16.363 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=91, payload=5B 00 00 04 2020-11-05 19:58:16.365 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 129222: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 91 2020-11-05 19:58:16.365 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-05 19:58:16.367 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 129222: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 91 2020-11-05 19:58:16.368 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking TID 129222: (Callback 91) 2020-11-05 19:58:16.369 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-11-05 19:58:16.370 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Correlated to TID 129222: callback 91 2020-11-05 19:58:16.371 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=91, payload=5B 00 00 04 2020-11-05 19:58:16.372 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = REQUEST 2020-11-05 19:58:16.374 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Request 2020-11-05 19:58:16.374 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 40: SendData Request. CallBack ID = 91, Status = Transmission complete and ACK received(0) 2020-11-05 19:58:16.376 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 40: resetResendCount initComplete=true isDead=false 2020-11-05 19:58:16.377 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129222: TransactionAdvance ST: WAIT_REQUEST 2020-11-05 19:58:16.378 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129222: TransactionAdvance WT: ApplicationCommandHandler {} 2020-11-05 19:58:16.379 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129222: TransactionAdvance RX: Message: class=SendData[19], type=Request[0], dest=0, callback=91, payload=5B 00 00 04 2020-11-05 19:58:16.380 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129222: TransactionAdvance RQ: RREQ=true, RCLS=ApplicationCommandHandler 2020-11-05 19:58:16.381 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129222: TransactionAdvance TO: WAIT_DATA 2020-11-05 19:58:16.382 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 129222: Advanced to WAIT_DATA 2020-11-05 19:58:16.383 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 40: TID 129222: Transaction not completed 2020-11-05 19:58:16.384 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-05 19:58:16.385 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-05 19:58:16.386 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing 2020-11-05 19:58:16.387 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:16.389 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:21 PST 2020 - 4995ms 2020-11-05 19:58:20.210 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 39: ZWaveCommandClassTransactionPayload - send to node 2020-11-05 19:58:20.211 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 39: Encapsulating message, endpoint 0 2020-11-05 19:58:20.212 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 39: SECURITY not supported 2020-11-05 19:58:20.213 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 39: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured 2020-11-05 19:58:20.214 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 39: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@3fea35 2020-11-05 19:58:20.215 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 39: Adding to device queue 2020-11-05 19:58:20.216 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 39: Added 129223 to queue - size 3 2020-11-05 19:58:20.217 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-05 19:58:20.217 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing 2020-11-05 19:58:20.218 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:20.219 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:21 PST 2020 - 1164ms 2020-11-05 19:58:21.384 [TRACE] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - Transaction Timeout.......... 1 outstanding transactions 2020-11-05 19:58:21.385 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 40: TID 129222: Timeout at state WAIT_DATA. 3 retries remaining. 2020-11-05 19:58:21.386 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129222: Transaction CANCELLED 2020-11-05 19:58:21.386 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent 2020-11-05 19:58:21.387 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 40: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2020-11-05 19:58:21.388 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 40: notifyTransactionResponse TID:129222 CANCELLED 2020-11-05 19:58:21.389 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-11-05 19:58:21.390 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 36: listening == false, frequentlyListening == false, awake == false 2020-11-05 19:58:21.390 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 36: Node not awake! 2020-11-05 19:58:21.391 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 30: listening == false, frequentlyListening == false, awake == false 2020-11-05 19:58:21.391 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 30: Node not awake! 2020-11-05 19:58:21.392 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 39: listening == true, frequentlyListening == false, awake == false 2020-11-05 19:58:21.392 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction from sendQueue 2020-11-05 19:58:21.393 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - getTransactionToSend 6 2020-11-05 19:58:21.393 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 39: Creating empty message of class = SendData (0x13), type = Request 2020-11-05 19:58:21.394 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = -34 2020-11-05 19:58:21.395 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 27 02 60 07 25 5C DE 2020-11-05 19:58:21.396 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 39: Sending REQUEST Message = 01 09 00 13 27 02 60 07 25 5C DE 2020-11-05 19:58:21.397 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-11-05 19:58:21.397 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129223: Transaction Start type SendData 2020-11-05 19:58:21.398 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 129223: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 92 2020-11-05 19:58:21.399 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: COMMAND_CLASS_MULTI_CHANNEL 2020-11-05 19:58:21.399 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-11-05 19:58:21.399 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: 8 2020-11-05 19:58:21.400 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 06 2020-11-05 19:58:21.400 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1 2020-11-05 19:58:21.401 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-05 19:58:21.401 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:21.402 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:23 PST 2020 - 1999ms 2020-11-05 19:58:21.402 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-05 19:58:21.403 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction null 2020-11-05 19:58:21.403 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 129223: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 92 2020-11-05 19:58:21.403 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-11-05 19:58:21.404 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-05 19:58:21.405 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:21.405 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF 2020-11-05 19:58:21.406 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:23 PST 2020 - 1995ms 2020-11-05 19:58:21.407 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2020-11-05 19:58:21.408 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 04 01 13 01 E8 2020-11-05 19:58:21.409 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = -24 2020-11-05 19:58:21.409 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-05 19:58:21.409 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched 2020-11-05 19:58:21.409 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding... 2020-11-05 19:58:21.410 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Message payload = 01 2020-11-05 19:58:21.410 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:21.411 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK 2020-11-05 19:58:21.411 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:23 PST 2020 - 1990ms 2020-11-05 19:58:21.412 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT 6 2020-11-05 19:58:21.413 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:21.414 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:21.415 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 129223: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 92 2020-11-05 19:58:21.415 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-05 19:58:21.416 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 129223: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 92 2020-11-05 19:58:21.418 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:21.419 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE 2020-11-05 19:58:21.420 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Response 2020-11-05 19:58:21.421 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 39: sentData successfully placed on stack. 2020-11-05 19:58:21.421 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129223: TransactionAdvance ST: WAIT_RESPONSE 2020-11-05 19:58:21.422 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129223: TransactionAdvance WT: ApplicationCommandHandler {} 2020-11-05 19:58:21.423 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129223: TransactionAdvance RX: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:21.424 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129223: TransactionAdvance TO: WAIT_REQUEST 2020-11-05 19:58:21.425 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 129223: Advanced to WAIT_REQUEST 2020-11-05 19:58:21.426 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF 2020-11-05 19:58:21.426 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 39: TID 129223: Transaction not completed 2020-11-05 19:58:21.427 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-05 19:58:21.427 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 5C 00 00 02 B5 2020-11-05 19:58:21.428 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 07 00 13 5C 00 00 02 B5 2020-11-05 19:58:21.428 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-05 19:58:21.429 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = -75 2020-11-05 19:58:21.429 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding... 2020-11-05 19:58:21.429 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched 2020-11-05 19:58:21.429 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:21.430 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 0: Message payload = 5C 00 00 02 2020-11-05 19:58:21.430 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:26 PST 2020 - 4996ms 2020-11-05 19:58:21.431 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK 2020-11-05 19:58:21.432 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT 6 2020-11-05 19:58:21.432 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=92, payload=5C 00 00 02 2020-11-05 19:58:21.433 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=92, payload=5C 00 00 02 2020-11-05 19:58:21.434 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 129223: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 92 2020-11-05 19:58:21.435 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-05 19:58:21.436 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 129223: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 92 2020-11-05 19:58:21.437 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking TID 129223: (Callback 92) 2020-11-05 19:58:21.438 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-11-05 19:58:21.439 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Correlated to TID 129223: callback 92 2020-11-05 19:58:21.440 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=92, payload=5C 00 00 02 2020-11-05 19:58:21.441 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = REQUEST 2020-11-05 19:58:21.442 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Request 2020-11-05 19:58:21.444 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 39: SendData Request. CallBack ID = 92, Status = Transmission complete and ACK received(0) 2020-11-05 19:58:21.445 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129223: TransactionAdvance ST: WAIT_REQUEST 2020-11-05 19:58:21.446 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129223: TransactionAdvance WT: ApplicationCommandHandler {} 2020-11-05 19:58:21.447 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129223: TransactionAdvance RX: Message: class=SendData[19], type=Request[0], dest=0, callback=92, payload=5C 00 00 02 2020-11-05 19:58:21.448 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129223: TransactionAdvance RQ: RREQ=true, RCLS=ApplicationCommandHandler 2020-11-05 19:58:21.449 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129223: TransactionAdvance TO: WAIT_DATA 2020-11-05 19:58:21.449 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 129223: Advanced to WAIT_DATA 2020-11-05 19:58:21.450 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 39: TID 129223: Transaction not completed 2020-11-05 19:58:21.451 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-05 19:58:21.452 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-05 19:58:21.453 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing 2020-11-05 19:58:21.454 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:21.454 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:26 PST 2020 - 4996ms 2020-11-05 19:58:23.927 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF 2020-11-05 19:58:23.931 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 25 02 98 40 0C 2020-11-05 19:58:23.932 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 08 00 04 00 25 02 98 40 0C 2020-11-05 19:58:23.933 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 12 2020-11-05 19:58:23.934 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched 2020-11-05 19:58:23.935 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 37: Message payload = 00 25 02 98 40 2020-11-05 19:58:23.936 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK 2020-11-05 19:58:23.937 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT 6 2020-11-05 19:58:23.938 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=37, callback=0, payload=00 25 02 98 40 2020-11-05 19:58:23.940 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=37, callback=0, payload=00 25 02 98 40 2020-11-05 19:58:23.941 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction null 2020-11-05 19:58:23.942 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Application Command Request (ALIVE:DONE) 2020-11-05 19:58:23.943 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 37: resetResendCount initComplete=true isDead=false 2020-11-05 19:58:23.944 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 37: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2020-11-05 19:58:23.945 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 37: SECURITY check internal 2020-11-05 19:58:23.946 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 37: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2020-11-05 19:58:23.947 [DEBUG] [.protocol.commandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_REPORT version 1 2020-11-05 19:58:23.948 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Added to secure queue - size 1 2020-11-05 19:58:23.949 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Commands processed 1. 2020-11-05 19:58:23.950 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@8499d5. 2020-11-05 19:58:23.952 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Checking transaction 129223 ApplicationCommandHandler. 2020-11-05 19:58:23.952 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Checking transaction : state >> WAIT_DATA 2020-11-05 19:58:23.954 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Checking transaction : node >> 39 2020-11-05 19:58:23.954 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Checking transaction : class >> 152 == 96. 2020-11-05 19:58:23.955 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Checking transaction : commd >> 64 == 8. 2020-11-05 19:58:23.956 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Command NOT verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@8499d5. 2020-11-05 19:58:23.957 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 2020-11-05 19:58:23.958 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 2020-11-05 19:58:23.959 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-05 19:58:23.960 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-05 19:58:23.962 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction from secureQueue 2020-11-05 19:58:23.962 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - getTransactionToSend 6 2020-11-05 19:58:23.963 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 37: Creating empty message of class = SendData (0x13), type = Request 2020-11-05 19:58:23.964 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 78 2020-11-05 19:58:23.966 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 25 0A 98 80 E1 36 E3 BE EE 59 F0 31 25 5D 4E 2020-11-05 19:58:23.968 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 37: Sending REQUEST Message = 01 11 00 13 25 0A 98 80 E1 36 E3 BE EE 59 F0 31 25 5D 4E 2020-11-05 19:58:23.970 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-11-05 19:58:23.970 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129224: Transaction Start type SendData 2020-11-05 19:58:23.972 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 129224: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 93 2020-11-05 19:58:23.972 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null 2020-11-05 19:58:23.974 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: 0 2020-11-05 19:58:23.974 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-11-05 19:58:23.975 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 06 2020-11-05 19:58:23.975 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-05 19:58:23.975 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 2 2020-11-05 19:58:23.977 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:23.978 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:25 PST 2020 - 1999ms 2020-11-05 19:58:23.978 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF 2020-11-05 19:58:23.979 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 129224: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 93 2020-11-05 19:58:23.980 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:23.981 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2020-11-05 19:58:23.982 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:25 PST 2020 - 1996ms 2020-11-05 19:58:23.982 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 04 01 13 01 E8 2020-11-05 19:58:23.983 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-05 19:58:23.982 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = -24 2020-11-05 19:58:23.983 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 129224: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 93 2020-11-05 19:58:23.985 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched 2020-11-05 19:58:23.985 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-11-05 19:58:23.986 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-05 19:58:23.986 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 2 out at start. Holdoff false. 2020-11-05 19:58:23.987 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Message payload = 01 2020-11-05 19:58:23.987 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding... 2020-11-05 19:58:23.988 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK 2020-11-05 19:58:23.988 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:23.989 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:25 PST 2020 - 1988ms 2020-11-05 19:58:23.989 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT 6 2020-11-05 19:58:23.991 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:23.993 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:23.994 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 129224: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 93 2020-11-05 19:58:23.995 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 2 2020-11-05 19:58:23.995 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 129224: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 93 2020-11-05 19:58:23.996 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:23.997 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE 2020-11-05 19:58:23.998 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Response 2020-11-05 19:58:23.999 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 37: sentData successfully placed on stack. 2020-11-05 19:58:24.000 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129224: TransactionAdvance ST: WAIT_RESPONSE 2020-11-05 19:58:24.001 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129224: TransactionAdvance WT: null {} 2020-11-05 19:58:24.002 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129224: TransactionAdvance RX: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:24.002 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129224: TransactionAdvance TO: WAIT_REQUEST 2020-11-05 19:58:24.003 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 129224: Advanced to WAIT_REQUEST 2020-11-05 19:58:24.004 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: TID 129224: Transaction not completed 2020-11-05 19:58:24.005 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-05 19:58:24.006 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 2 out at start. Holdoff false. 2020-11-05 19:58:24.007 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding... 2020-11-05 19:58:24.007 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:24.008 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:26 PST 2020 - 2442ms 2020-11-05 19:58:24.094 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF 2020-11-05 19:58:24.096 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 5D 00 00 0C BA 2020-11-05 19:58:24.098 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 07 00 13 5D 00 00 0C BA 2020-11-05 19:58:24.099 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = -70 2020-11-05 19:58:24.101 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched 2020-11-05 19:58:24.102 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 0: Message payload = 5D 00 00 0C 2020-11-05 19:58:24.103 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK 2020-11-05 19:58:24.104 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT 6 2020-11-05 19:58:24.106 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=93, payload=5D 00 00 0C 2020-11-05 19:58:24.107 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=93, payload=5D 00 00 0C 2020-11-05 19:58:24.108 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 129224: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 93 2020-11-05 19:58:24.108 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 2 2020-11-05 19:58:24.109 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 129224: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 93 2020-11-05 19:58:24.110 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking TID 129223: (Callback 92) 2020-11-05 19:58:24.111 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - NO callback match! (92 <> 93) 2020-11-05 19:58:24.111 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking TID 129224: (Callback 93) 2020-11-05 19:58:24.112 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-11-05 19:58:24.113 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Correlated to TID 129224: callback 93 2020-11-05 19:58:24.113 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=93, payload=5D 00 00 0C 2020-11-05 19:58:24.114 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = REQUEST 2020-11-05 19:58:24.115 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Request 2020-11-05 19:58:24.115 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 37: SendData Request. CallBack ID = 93, Status = Transmission complete and ACK received(0) 2020-11-05 19:58:24.116 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 37: resetResendCount initComplete=true isDead=false 2020-11-05 19:58:24.117 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129224: Transaction COMPLETED 2020-11-05 19:58:24.118 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129224: TransactionAdvance ST: DONE 2020-11-05 19:58:24.118 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129224: TransactionAdvance WT: null {} 2020-11-05 19:58:24.119 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129224: TransactionAdvance RX: Message: class=SendData[19], type=Request[0], dest=0, callback=93, payload=5D 00 00 0C 2020-11-05 19:58:24.120 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129224: TransactionAdvance TO: DONE 2020-11-05 19:58:24.121 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Response processed after 151ms 2020-11-05 19:58:24.121 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: TID 129224: Transaction completed 2020-11-05 19:58:24.122 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: notifyTransactionResponse TID:129224 DONE 2020-11-05 19:58:24.123 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent 2020-11-05 19:58:24.124 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2020-11-05 19:58:24.125 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-05 19:58:24.125 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-05 19:58:24.126 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing 2020-11-05 19:58:24.126 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:24.127 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:26 PST 2020 - 2323ms 2020-11-05 19:58:24.186 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF 2020-11-05 19:58:24.189 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1C 00 04 00 25 16 98 81 BB 5B 36 23 30 4C FA CC 45 94 32 E1 85 B9 A8 FB AA CF CC 80 36 2020-11-05 19:58:24.191 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 1C 00 04 00 25 16 98 81 BB 5B 36 23 30 4C FA CC 45 94 32 E1 85 B9 A8 FB AA CF CC 80 36 2020-11-05 19:58:24.192 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = 54 2020-11-05 19:58:24.193 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched 2020-11-05 19:58:24.195 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 37: Message payload = 00 25 16 98 81 BB 5B 36 23 30 4C FA CC 45 94 32 E1 85 B9 A8 FB AA CF CC 80 2020-11-05 19:58:24.196 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK 2020-11-05 19:58:24.197 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT 6 2020-11-05 19:58:24.199 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=37, callback=0, payload=00 25 16 98 81 BB 5B 36 23 30 4C FA CC 45 94 32 E1 85 B9 A8 FB AA CF CC 80 2020-11-05 19:58:24.200 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=37, callback=0, payload=00 25 16 98 81 BB 5B 36 23 30 4C FA CC 45 94 32 E1 85 B9 A8 FB AA CF CC 80 2020-11-05 19:58:24.201 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction null 2020-11-05 19:58:24.202 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Application Command Request (ALIVE:DONE) 2020-11-05 19:58:24.203 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 37: resetResendCount initComplete=true isDead=false 2020-11-05 19:58:24.203 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 37: Decapsulating COMMAND_CLASS_SECURITY 2020-11-05 19:58:24.206 [DEBUG] [al.protocol.commandclass.ZWaveSecurityCommandClass] - NODE 37: SECURITY_RXD 84 07 2020-11-05 19:58:24.207 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Commands processed 1. 2020-11-05 19:58:24.207 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@104dfb6. 2020-11-05 19:58:24.208 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Checking transaction 129223 ApplicationCommandHandler. 2020-11-05 19:58:24.208 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Checking transaction : state >> WAIT_DATA 2020-11-05 19:58:24.209 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Checking transaction : node >> 39 2020-11-05 19:58:24.210 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Checking transaction : class >> 132 == 96. 2020-11-05 19:58:24.210 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Checking transaction : commd >> 7 == 8. 2020-11-05 19:58:24.211 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 37: Command NOT verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@104dfb6. 2020-11-05 19:58:24.212 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 2020-11-05 19:58:24.212 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 2020-11-05 19:58:24.213 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-05 19:58:24.213 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-05 19:58:24.214 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing 2020-11-05 19:58:24.214 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:24.215 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:26 PST 2020 - 2236ms 2020-11-05 19:58:26.451 [TRACE] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - Transaction Timeout.......... 1 outstanding transactions 2020-11-05 19:58:26.452 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 39: TID 129223: Timeout at state WAIT_DATA. 3 retries remaining. 2020-11-05 19:58:26.453 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129223: Transaction CANCELLED 2020-11-05 19:58:26.453 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent 2020-11-05 19:58:26.454 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 39: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2020-11-05 19:58:26.454 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 39: notifyTransactionResponse TID:129223 CANCELLED 2020-11-05 19:58:26.455 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-11-05 19:58:26.455 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 129223: Transaction event listener: DONE: CANCELLED -> 2020-11-05 19:58:26.456 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 36: listening == false, frequentlyListening == false, awake == false 2020-11-05 19:58:26.456 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 36: Node not awake! 2020-11-05 19:58:26.457 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ********* Transaction Response Complete -- 129223 -- 2020-11-05 19:58:26.457 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 30: listening == false, frequentlyListening == false, awake == false 2020-11-05 19:58:26.458 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 30: Node not awake! 2020-11-05 19:58:26.458 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 39: Node Init response (4) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@18380e9 2020-11-05 19:58:26.458 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing 2020-11-05 19:58:26.458 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 39: No data from device, but it was ACK'd. Possibly not supported? (Try 4) 2020-11-05 19:58:26.458 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:26.459 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 39: Node Init transaction retries exceeded 2020-11-05 19:58:26.459 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 39: MultiInstance init first=false 2020-11-05 19:58:26.459 [DEBUG] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 39: Initialising endpoints - version 2 2020-11-05 19:58:26.460 [DEBUG] [otocol.commandclass.ZWaveMultiInstanceCommandClass] - NODE 39: Creating new message for command MULTI_CHANNEL_ENDPOINT_GET 2020-11-05 19:58:26.461 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 39: MultiInstance init returned 1 2020-11-05 19:58:26.461 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 39: ZWaveCommandClassTransactionPayload - send to node 2020-11-05 19:58:26.462 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 39: Encapsulating message, endpoint 0 2020-11-05 19:58:26.462 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 39: SECURITY not supported 2020-11-05 19:58:26.463 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 39: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured 2020-11-05 19:58:26.464 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 39: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@1ac3f94 2020-11-05 19:58:26.465 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 39: Adding to device queue 2020-11-05 19:58:26.465 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 39: Added 129225 to queue - size 3 2020-11-05 19:58:26.466 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-11-05 19:58:26.467 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 36: listening == false, frequentlyListening == false, awake == false 2020-11-05 19:58:26.467 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 36: Node not awake! 2020-11-05 19:58:26.468 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 30: listening == false, frequentlyListening == false, awake == false 2020-11-05 19:58:26.469 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 30: Node not awake! 2020-11-05 19:58:26.470 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 39: listening == true, frequentlyListening == false, awake == false 2020-11-05 19:58:26.470 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction from sendQueue 2020-11-05 19:58:26.471 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - getTransactionToSend 6 2020-11-05 19:58:26.471 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 39: Creating empty message of class = SendData (0x13), type = Request 2020-11-05 19:58:26.472 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = -36 2020-11-05 19:58:26.473 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 27 02 60 07 25 5E DC 2020-11-05 19:58:26.474 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 39: Sending REQUEST Message = 01 09 00 13 27 02 60 07 25 5E DC 2020-11-05 19:58:26.475 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-11-05 19:58:26.475 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129225: Transaction Start type SendData 2020-11-05 19:58:26.476 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 129225: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 94 2020-11-05 19:58:26.477 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-11-05 19:58:26.478 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 06 2020-11-05 19:58:26.479 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-05 19:58:26.479 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: COMMAND_CLASS_MULTI_CHANNEL 2020-11-05 19:58:26.480 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: 8 2020-11-05 19:58:26.480 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1 2020-11-05 19:58:26.481 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-05 19:58:26.481 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:28 PST 2020 - 2000ms 2020-11-05 19:58:26.481 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction null 2020-11-05 19:58:26.482 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 129225: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 94 2020-11-05 19:58:26.482 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:26.482 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-11-05 19:58:26.483 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-05 19:58:26.483 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF 2020-11-05 19:58:26.484 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:28 PST 2020 - 1998ms 2020-11-05 19:58:26.485 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-05 19:58:26.485 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2020-11-05 19:58:26.485 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding... 2020-11-05 19:58:26.486 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 04 01 13 01 E8 2020-11-05 19:58:26.486 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:26.486 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = -24 2020-11-05 19:58:26.486 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:28 PST 2020 - 1995ms 2020-11-05 19:58:26.487 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched 2020-11-05 19:58:26.487 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Message payload = 01 2020-11-05 19:58:26.488 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK 2020-11-05 19:58:26.489 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT 6 2020-11-05 19:58:26.489 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:26.490 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:26.491 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 129225: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 94 2020-11-05 19:58:26.492 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-05 19:58:26.496 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 129225: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 94 2020-11-05 19:58:26.501 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:26.503 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Received SOF 2020-11-05 19:58:26.504 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 5E 00 00 03 B6 2020-11-05 19:58:26.505 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 07 00 13 5E 00 00 03 B6 2020-11-05 19:58:26.506 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE 2020-11-05 19:58:26.507 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Response 2020-11-05 19:58:26.507 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - Calculated checksum = -74 2020-11-05 19:58:26.507 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 39: sentData successfully placed on stack. 2020-11-05 19:58:26.508 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 255: Checksum matched 2020-11-05 19:58:26.508 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129225: TransactionAdvance ST: WAIT_RESPONSE 2020-11-05 19:58:26.508 [TRACE] [nhab.binding.zwave.internal.protocol.SerialMessage] - NODE 0: Message payload = 5E 00 00 03 2020-11-05 19:58:26.508 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129225: TransactionAdvance WT: ApplicationCommandHandler {} 2020-11-05 19:58:26.509 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK 2020-11-05 19:58:26.509 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129225: TransactionAdvance RX: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-05 19:58:26.509 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129225: TransactionAdvance TO: WAIT_REQUEST 2020-11-05 19:58:26.510 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 129225: Advanced to WAIT_REQUEST 2020-11-05 19:58:26.510 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 39: TID 129225: Transaction not completed 2020-11-05 19:58:26.510 [TRACE] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Response SENT 6 2020-11-05 19:58:26.511 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-05 19:58:26.512 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-05 19:58:26.512 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding... 2020-11-05 19:58:26.512 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=94, payload=5E 00 00 03 2020-11-05 19:58:26.513 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:26.515 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:31 PST 2020 - 4995ms 2020-11-05 19:58:26.516 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=94, payload=5E 00 00 03 2020-11-05 19:58:26.517 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 129225: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 94 2020-11-05 19:58:26.517 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-05 19:58:26.518 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 129225: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 94 2020-11-05 19:58:26.518 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking TID 129225: (Callback 94) 2020-11-05 19:58:26.519 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-11-05 19:58:26.520 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Correlated to TID 129225: callback 94 2020-11-05 19:58:26.520 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=94, payload=5E 00 00 03 2020-11-05 19:58:26.521 [TRACE] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message type = REQUEST 2020-11-05 19:58:26.521 [TRACE] [ternal.protocol.serialmessage.SendDataMessageClass] - Handle Message Send Data Request 2020-11-05 19:58:26.522 [DEBUG] [ternal.protocol.serialmessage.SendDataMessageClass] - NODE 39: SendData Request. CallBack ID = 94, Status = Transmission complete and ACK received(0) 2020-11-05 19:58:26.523 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129225: TransactionAdvance ST: WAIT_REQUEST 2020-11-05 19:58:26.523 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129225: TransactionAdvance WT: ApplicationCommandHandler {} 2020-11-05 19:58:26.524 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129225: TransactionAdvance RX: Message: class=SendData[19], type=Request[0], dest=0, callback=94, payload=5E 00 00 03 2020-11-05 19:58:26.524 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129225: TransactionAdvance RQ: RREQ=true, RCLS=ApplicationCommandHandler 2020-11-05 19:58:26.525 [TRACE] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 129225: TransactionAdvance TO: WAIT_DATA 2020-11-05 19:58:26.525 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 129225: Advanced to WAIT_DATA 2020-11-05 19:58:26.526 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 39: TID 129225: Transaction not completed 2020-11-05 19:58:26.526 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-05 19:58:26.527 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-05 19:58:26.527 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing 2020-11-05 19:58:26.528 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - STOP transaction timer 2020-11-05 19:58:26.528 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Nov 05 19:58:31 PST 2020 - 4998ms