anager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@3a3383cf. 2021-06-08 22:59:58.928 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 22:59:58.928 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 22:59:58.928 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:58.928 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 22:59:58.928 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 02 0A 98 80 FA 93 C8 F5 EF 57 62 AF 25 C8 21 2021-06-08 22:59:58.929 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 11 00 13 02 0A 98 80 FA 93 C8 F5 EF 57 62 AF 25 C8 21 2021-06-08 22:59:58.932 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2021-06-08 22:59:58.932 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 15705: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 200 2021-06-08 22:59:58.933 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2021-06-08 22:59:58.933 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 22:59:58.933 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 22:59:58.933 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15705: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 200 2021-06-08 22:59:58.933 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2021-06-08 22:59:58.934 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:58.934 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 22:59:58.942 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2021-06-08 22:59:58.943 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 22:59:58.943 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 22:59:58.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15705: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 200 2021-06-08 22:59:58.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 22:59:58.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15705: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 200 2021-06-08 22:59:58.944 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 22:59:58.944 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack. 2021-06-08 22:59:58.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 15705: Advanced to WAIT_REQUEST 2021-06-08 22:59:58.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 15705: Transaction not completed 2021-06-08 22:59:58.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:58.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 22:59:59.048 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 C8 00 00 0B 28 2021-06-08 22:59:59.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=200, payload=C8 00 00 0B 2021-06-08 22:59:59.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=200, payload=C8 00 00 0B 2021-06-08 22:59:59.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15705: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 200 2021-06-08 22:59:59.052 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 22:59:59.054 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15705: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 200 2021-06-08 22:59:59.055 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 15705: (Callback 200) 2021-06-08 22:59:59.055 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2021-06-08 22:59:59.055 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 15705: callback 200 2021-06-08 22:59:59.055 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=200, payload=C8 00 00 0B 2021-06-08 22:59:59.055 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 200, Status = Transmission complete and ACK received(0) 2021-06-08 22:59:59.055 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 15705: Transaction COMPLETED 2021-06-08 22:59:59.056 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Response processed after 124ms 2021-06-08 22:59:59.056 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 15705: Transaction completed 2021-06-08 22:59:59.056 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:15705 DONE 2021-06-08 22:59:59.056 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2021-06-08 22:59:59.056 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:59.056 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 22:59:59.138 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 2C 00 04 00 02 26 98 81 8A AE 76 13 D4 C2 3A E5 B6 8F C1 DA 70 C7 2B 70 24 79 50 E8 3E 34 A0 0B DA E7 BA FA C7 E1 A2 31 4E DA EC 31 69 2021-06-08 22:59:59.140 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 26 98 81 8A AE 76 13 D4 C2 3A E5 B6 8F C1 DA 70 C7 2B 70 24 79 50 E8 3E 34 A0 0B DA E7 BA FA C7 E1 A2 31 4E DA EC 31 2021-06-08 22:59:59.140 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 26 98 81 8A AE 76 13 D4 C2 3A E5 B6 8F C1 DA 70 C7 2B 70 24 79 50 E8 3E 34 A0 0B DA E7 BA FA C7 E1 A2 31 4E DA EC 31 2021-06-08 22:59:59.140 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 22:59:59.140 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:REQUEST_NIF) 2021-06-08 22:59:59.140 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Decapsulating COMMAND_CLASS_SECURITY 2021-06-08 22:59:59.140 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: SECURITY_RXD 60 0D 04 01 32 02 21 24 00 00 1C 32 00 00 00 00 00 00 2021-06-08 22:59:59.140 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2021-06-08 22:59:59.141 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_METER, endpoint 4 2021-06-08 22:59:59.141 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_METER V0 METER_REPORT 2021-06-08 22:59:59.141 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 2: Meter: Type=Electric(1), Scale=kWh(0), Value=721.8 2021-06-08 22:59:59.141 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveMeterValueEvent 2021-06-08 22:59:59.141 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint=4, command class=COMMAND_CLASS_METER, value=721.8 2021-06-08 22:59:59.141 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:8f57dbad:node2:meter_kwh4 to 721.8 [DecimalType] 2021-06-08 22:59:59.141 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1. 2021-06-08 22:59:59.141 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@21094752. 2021-06-08 22:59:59.141 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 22:59:59.141 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 22:59:59.142 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:59.142 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 22:59:59.182 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 02 02 98 40 2B 2021-06-08 22:59:59.185 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 02 98 40 2021-06-08 22:59:59.185 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 02 98 40 2021-06-08 22:59:59.185 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 22:59:59.186 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:REQUEST_NIF) 2021-06-08 22:59:59.186 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2021-06-08 22:59:59.186 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY check internal 2021-06-08 22:59:59.186 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2021-06-08 22:59:59.186 [DEBUG] [andclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_REPORT version 1 2021-06-08 22:59:59.186 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added to secure queue - size 1 2021-06-08 22:59:59.186 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1. 2021-06-08 22:59:59.186 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@64ad8f9b. 2021-06-08 22:59:59.187 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 22:59:59.187 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 22:59:59.187 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:59.187 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 22:59:59.187 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 02 0A 98 80 D0 FD 33 6B FE 93 60 21 25 C9 58 2021-06-08 22:59:59.187 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 11 00 13 02 0A 98 80 D0 FD 33 6B FE 93 60 21 25 C9 58 2021-06-08 22:59:59.188 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2021-06-08 22:59:59.188 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 15706: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 201 2021-06-08 22:59:59.189 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2021-06-08 22:59:59.189 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 22:59:59.190 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 22:59:59.190 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15706: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 201 2021-06-08 22:59:59.190 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2021-06-08 22:59:59.190 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:59.190 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 22:59:59.201 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2021-06-08 22:59:59.204 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 22:59:59.204 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 22:59:59.204 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15706: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 201 2021-06-08 22:59:59.204 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 22:59:59.204 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15706: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 201 2021-06-08 22:59:59.204 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 22:59:59.204 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack. 2021-06-08 22:59:59.204 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 15706: Advanced to WAIT_REQUEST 2021-06-08 22:59:59.205 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 15706: Transaction not completed 2021-06-08 22:59:59.205 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:59.205 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 22:59:59.239 [INFO ] [openhab.event.ItemStateEvent ] - Item 'Power_kwh' updated to 4562.877 2021-06-08 22:59:59.239 [INFO ] [openhab.event.ItemStateEvent ] - Item 'power_watt' updated to 726.5 2021-06-08 22:59:59.240 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Power_kwh' changed from 4562.874 to 4562.877 2021-06-08 22:59:59.240 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'power_watt' changed from 664.5 to 726.5 2021-06-08 22:59:59.306 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 C9 00 00 0B 29 2021-06-08 22:59:59.309 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=201, payload=C9 00 00 0B 2021-06-08 22:59:59.309 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=201, payload=C9 00 00 0B 2021-06-08 22:59:59.309 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15706: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 201 2021-06-08 22:59:59.309 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 22:59:59.309 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15706: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 201 2021-06-08 22:59:59.309 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 15706: (Callback 201) 2021-06-08 22:59:59.309 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2021-06-08 22:59:59.309 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 15706: callback 201 2021-06-08 22:59:59.310 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=201, payload=C9 00 00 0B 2021-06-08 22:59:59.310 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 201, Status = Transmission complete and ACK received(0) 2021-06-08 22:59:59.310 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 15706: Transaction COMPLETED 2021-06-08 22:59:59.310 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Response processed after 122ms 2021-06-08 22:59:59.310 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 15706: Transaction completed 2021-06-08 22:59:59.310 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:15706 DONE 2021-06-08 22:59:59.311 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2021-06-08 22:59:59.311 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:59.311 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 22:59:59.387 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 2C 00 04 00 02 26 98 81 75 D2 FD 69 21 C9 24 A5 1A 32 21 1F 15 40 CF 71 2E AD 3A 56 02 25 A3 82 CE FA 88 D0 A0 59 A2 44 58 DC 2B 14 6C 2021-06-08 22:59:59.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 26 98 81 75 D2 FD 69 21 C9 24 A5 1A 32 21 1F 15 40 CF 71 2E AD 3A 56 02 25 A3 82 CE FA 88 D0 A0 59 A2 44 58 DC 2B 14 2021-06-08 22:59:59.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 26 98 81 75 D2 FD 69 21 C9 24 A5 1A 32 21 1F 15 40 CF 71 2E AD 3A 56 02 25 A3 82 CE FA 88 D0 A0 59 A2 44 58 DC 2B 14 2021-06-08 22:59:59.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 22:59:59.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:REQUEST_NIF) 2021-06-08 22:59:59.389 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Decapsulating COMMAND_CLASS_SECURITY 2021-06-08 22:59:59.389 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: SECURITY_RXD 60 0D 04 01 32 02 21 54 00 00 00 09 00 00 00 00 00 00 2021-06-08 22:59:59.389 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2021-06-08 22:59:59.389 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_METER, endpoint 4 2021-06-08 22:59:59.389 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_METER V0 METER_REPORT 2021-06-08 22:59:59.390 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 2: Meter: Type=Electric(1), Scale=W(2), Value=0.09 2021-06-08 22:59:59.390 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveMeterValueEvent 2021-06-08 22:59:59.390 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint=4, command class=COMMAND_CLASS_METER, value=0.09 2021-06-08 22:59:59.390 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:8f57dbad:node2:meter_watts4 to 0.09 [DecimalType] 2021-06-08 22:59:59.390 [INFO ] [openhab.event.ItemStateEvent ] - Item 'bathroom_floor_wattsnewnew' updated to 0.09 2021-06-08 22:59:59.391 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'bathroom_floor_wattsnewnew' changed from 0.01 to 0.09 2021-06-08 22:59:59.391 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1. 2021-06-08 22:59:59.391 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@eec21c4. 2021-06-08 22:59:59.392 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 22:59:59.392 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 22:59:59.392 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:59.392 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 22:59:59.431 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 02 02 98 40 2B 2021-06-08 22:59:59.433 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 02 98 40 2021-06-08 22:59:59.433 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 02 98 40 2021-06-08 22:59:59.434 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 22:59:59.434 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:REQUEST_NIF) 2021-06-08 22:59:59.434 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2021-06-08 22:59:59.434 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY check internal 2021-06-08 22:59:59.434 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2021-06-08 22:59:59.434 [DEBUG] [andclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_REPORT version 1 2021-06-08 22:59:59.434 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added to secure queue - size 1 2021-06-08 22:59:59.434 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1. 2021-06-08 22:59:59.434 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@2867e62d. 2021-06-08 22:59:59.434 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 22:59:59.435 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 22:59:59.435 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:59.435 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 22:59:59.435 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 02 0A 98 80 4E B6 6F E8 0D AB 40 B1 25 CA 2A 2021-06-08 22:59:59.435 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 11 00 13 02 0A 98 80 4E B6 6F E8 0D AB 40 B1 25 CA 2A 2021-06-08 22:59:59.435 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2021-06-08 22:59:59.435 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 15707: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 202 2021-06-08 22:59:59.437 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2021-06-08 22:59:59.437 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 22:59:59.437 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 22:59:59.437 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15707: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 202 2021-06-08 22:59:59.437 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2021-06-08 22:59:59.437 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:59.437 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 22:59:59.445 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2021-06-08 22:59:59.446 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 22:59:59.446 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 22:59:59.446 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15707: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 202 2021-06-08 22:59:59.447 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 22:59:59.447 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15707: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 202 2021-06-08 22:59:59.447 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 22:59:59.447 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack. 2021-06-08 22:59:59.447 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 15707: Advanced to WAIT_REQUEST 2021-06-08 22:59:59.447 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 15707: Transaction not completed 2021-06-08 22:59:59.447 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:59.447 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 22:59:59.586 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 CA 00 00 0E 2F 2021-06-08 22:59:59.589 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=202, payload=CA 00 00 0E 2021-06-08 22:59:59.589 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=202, payload=CA 00 00 0E 2021-06-08 22:59:59.589 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15707: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 202 2021-06-08 22:59:59.589 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 22:59:59.589 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15707: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 202 2021-06-08 22:59:59.589 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 15707: (Callback 202) 2021-06-08 22:59:59.590 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2021-06-08 22:59:59.590 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 15707: callback 202 2021-06-08 22:59:59.590 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=202, payload=CA 00 00 0E 2021-06-08 22:59:59.590 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 202, Status = Transmission complete and ACK received(0) 2021-06-08 22:59:59.590 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 15707: Transaction COMPLETED 2021-06-08 22:59:59.590 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Response processed after 155ms 2021-06-08 22:59:59.590 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 15707: Transaction completed 2021-06-08 22:59:59.590 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:15707 DONE 2021-06-08 22:59:59.591 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2021-06-08 22:59:59.591 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:59.591 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 22:59:59.690 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 0F 02 98 40 26 2021-06-08 22:59:59.692 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 02 98 40 2021-06-08 22:59:59.692 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 02 98 40 2021-06-08 22:59:59.692 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 22:59:59.693 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Application Command Request (ALIVE:DONE) 2021-06-08 22:59:59.693 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 22:59:59.693 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2021-06-08 22:59:59.693 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: SECURITY check internal 2021-06-08 22:59:59.693 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2021-06-08 22:59:59.693 [DEBUG] [andclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_REPORT version 1 2021-06-08 22:59:59.693 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Added to secure queue - size 1 2021-06-08 22:59:59.693 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Commands processed 1. 2021-06-08 22:59:59.693 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@433f07a4. 2021-06-08 22:59:59.693 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 22:59:59.694 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 22:59:59.694 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:59.694 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 22:59:59.694 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 0F 0A 98 80 B3 6D 65 76 A3 16 FA 47 25 CB CB 2021-06-08 22:59:59.694 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 15: Sending REQUEST Message = 01 11 00 13 0F 0A 98 80 B3 6D 65 76 A3 16 FA 47 25 CB CB 2021-06-08 22:59:59.696 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2021-06-08 22:59:59.696 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 15708: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 203 2021-06-08 22:59:59.697 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2021-06-08 22:59:59.697 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 22:59:59.698 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 22:59:59.698 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15708: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 203 2021-06-08 22:59:59.698 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2021-06-08 22:59:59.698 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:59.698 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 22:59:59.708 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2021-06-08 22:59:59.711 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 22:59:59.711 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 22:59:59.711 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15708: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 203 2021-06-08 22:59:59.711 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 22:59:59.711 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15708: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 203 2021-06-08 22:59:59.711 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 22:59:59.711 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 15: sentData successfully placed on stack. 2021-06-08 22:59:59.711 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 15708: Advanced to WAIT_REQUEST 2021-06-08 22:59:59.712 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: TID 15708: Transaction not completed 2021-06-08 22:59:59.712 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:59.712 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 22:59:59.875 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 28 00 04 00 02 22 98 81 30 DB 6B 4A AF 81 9A C1 94 4F D0 53 53 4D 8D E8 07 94 1A 45 3C E0 47 4E E0 6E C7 C4 A0 1C 3B 90 F5 2021-06-08 22:59:59.878 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 22 98 81 30 DB 6B 4A AF 81 9A C1 94 4F D0 53 53 4D 8D E8 07 94 1A 45 3C E0 47 4E E0 6E C7 C4 A0 1C 3B 90 2021-06-08 22:59:59.878 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 22 98 81 30 DB 6B 4A AF 81 9A C1 94 4F D0 53 53 4D 8D E8 07 94 1A 45 3C E0 47 4E E0 6E C7 C4 A0 1C 3B 90 2021-06-08 22:59:59.879 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15708: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 203 2021-06-08 22:59:59.879 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:REQUEST_NIF) 2021-06-08 22:59:59.879 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Decapsulating COMMAND_CLASS_SECURITY 2021-06-08 22:59:59.879 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: SECURITY_RXD 60 0D 04 01 32 02 A1 22 09 6A 00 00 00 00 2021-06-08 22:59:59.879 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2021-06-08 22:59:59.879 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_METER, endpoint 4 2021-06-08 22:59:59.879 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_METER V0 METER_REPORT 2021-06-08 22:59:59.879 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 2: Meter: Type=Electric(1), Scale=kWh(0), Value=241 2021-06-08 22:59:59.880 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveMeterValueEvent 2021-06-08 22:59:59.880 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint=4, command class=COMMAND_CLASS_METER, value=241 2021-06-08 22:59:59.880 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:8f57dbad:node2:meter_kwh4 to 241 [DecimalType] 2021-06-08 22:59:59.880 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1. 2021-06-08 22:59:59.880 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@4be6890f. 2021-06-08 22:59:59.880 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 2021-06-08 22:59:59.880 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 2021-06-08 22:59:59.880 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:59.880 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 22:59:59.958 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 02 02 98 40 2B 2021-06-08 22:59:59.960 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 02 98 40 2021-06-08 22:59:59.960 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 02 98 40 2021-06-08 22:59:59.960 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15708: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 203 2021-06-08 22:59:59.961 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:REQUEST_NIF) 2021-06-08 22:59:59.961 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2021-06-08 22:59:59.961 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY check internal 2021-06-08 22:59:59.961 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2021-06-08 22:59:59.961 [DEBUG] [andclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_REPORT version 1 2021-06-08 22:59:59.961 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added to secure queue - size 1 2021-06-08 22:59:59.961 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1. 2021-06-08 22:59:59.961 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@24eb63b6. 2021-06-08 22:59:59.961 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 2021-06-08 22:59:59.962 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 2021-06-08 22:59:59.962 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 22:59:59.962 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 23:00:00.020 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 0F 02 98 40 26 2021-06-08 23:00:00.023 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 02 98 40 2021-06-08 23:00:00.023 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 02 98 40 2021-06-08 23:00:00.023 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15708: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 203 2021-06-08 23:00:00.024 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Application Command Request (ALIVE:DONE) 2021-06-08 23:00:00.024 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 23:00:00.024 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2021-06-08 23:00:00.024 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: SECURITY check internal 2021-06-08 23:00:00.024 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2021-06-08 23:00:00.024 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 15: Ignoring NONCE Request received after 331ms 2021-06-08 23:00:00.024 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Commands processed 1. 2021-06-08 23:00:00.024 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@33aaaf88. 2021-06-08 23:00:00.024 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 2021-06-08 23:00:00.025 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 2021-06-08 23:00:00.025 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:00.025 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 23:00:00.164 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 CB 00 00 2E 0E 2021-06-08 23:00:00.168 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=203, payload=CB 00 00 2E 2021-06-08 23:00:00.168 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=203, payload=CB 00 00 2E 2021-06-08 23:00:00.168 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15708: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 203 2021-06-08 23:00:00.168 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 23:00:00.168 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15708: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 203 2021-06-08 23:00:00.168 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 15708: (Callback 203) 2021-06-08 23:00:00.168 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2021-06-08 23:00:00.169 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 15708: callback 203 2021-06-08 23:00:00.169 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=203, payload=CB 00 00 2E 2021-06-08 23:00:00.169 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 15: SendData Request. CallBack ID = 203, Status = Transmission complete and ACK received(0) 2021-06-08 23:00:00.169 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 23:00:00.169 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 15708: Transaction COMPLETED 2021-06-08 23:00:00.169 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Response processed after 473ms 2021-06-08 23:00:00.169 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: TID 15708: Transaction completed 2021-06-08 23:00:00.169 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: notifyTransactionResponse TID:15708 DONE 2021-06-08 23:00:00.170 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2021-06-08 23:00:00.170 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:00.170 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:00.170 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 02 0A 98 80 84 83 3A 4B 00 37 1C 88 25 CC D1 2021-06-08 23:00:00.170 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 11 00 13 02 0A 98 80 84 83 3A 4B 00 37 1C 88 25 CC D1 2021-06-08 23:00:00.171 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2021-06-08 23:00:00.171 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 15709: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 204 2021-06-08 23:00:00.172 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2021-06-08 23:00:00.172 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 23:00:00.172 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 23:00:00.172 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15709: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 204 2021-06-08 23:00:00.172 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2021-06-08 23:00:00.172 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:00.172 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 23:00:00.182 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2021-06-08 23:00:00.183 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:00.183 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:00.184 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15709: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 204 2021-06-08 23:00:00.184 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 23:00:00.184 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15709: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 204 2021-06-08 23:00:00.184 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:00.184 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack. 2021-06-08 23:00:00.184 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 15709: Advanced to WAIT_REQUEST 2021-06-08 23:00:00.184 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 15709: Transaction not completed 2021-06-08 23:00:00.184 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:00.184 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 23:00:00.218 [INFO ] [openhab.event.RuleStatusInfoEvent ] - cameras-1 updated: RUNNING 2021-06-08 23:00:00.221 [INFO ] [openhab.event.RuleStatusInfoEvent ] - cameras-1 updated: IDLE 2021-06-08 23:00:00.289 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 CC 00 00 0B 2C 2021-06-08 23:00:00.290 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=204, payload=CC 00 00 0B 2021-06-08 23:00:00.291 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=204, payload=CC 00 00 0B 2021-06-08 23:00:00.291 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15709: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 204 2021-06-08 23:00:00.291 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 23:00:00.291 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15709: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 204 2021-06-08 23:00:00.291 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 15709: (Callback 204) 2021-06-08 23:00:00.291 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2021-06-08 23:00:00.291 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 15709: callback 204 2021-06-08 23:00:00.291 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=204, payload=CC 00 00 0B 2021-06-08 23:00:00.291 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 204, Status = Transmission complete and ACK received(0) 2021-06-08 23:00:00.291 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 15709: Transaction COMPLETED 2021-06-08 23:00:00.292 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Response processed after 121ms 2021-06-08 23:00:00.292 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 15709: Transaction completed 2021-06-08 23:00:00.292 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:15709 DONE 2021-06-08 23:00:00.292 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2021-06-08 23:00:00.292 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:00.292 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:00.370 [INFO ] [openhab.event.RuleStatusInfoEvent ] - removeCastSound-1 updated: RUNNING 2021-06-08 23:00:00.372 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 24 00 04 00 02 1E 98 81 24 A6 C5 15 2B A2 7B FD AF ED 2A D7 03 5E 28 E6 2E 0E 51 84 59 35 54 EB AB BC A5 EC D3 2021-06-08 23:00:00.374 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 1E 98 81 24 A6 C5 15 2B A2 7B FD AF ED 2A D7 03 5E 28 E6 2E 0E 51 84 59 35 54 EB AB BC A5 EC 2021-06-08 23:00:00.374 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 1E 98 81 24 A6 C5 15 2B A2 7B FD AF ED 2A D7 03 5E 28 E6 2E 0E 51 84 59 35 54 EB AB BC A5 EC 2021-06-08 23:00:00.374 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 23:00:00.374 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:REQUEST_NIF) 2021-06-08 23:00:00.374 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Decapsulating COMMAND_CLASS_SECURITY 2021-06-08 23:00:00.374 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: SECURITY_RXD 60 0D 02 01 31 05 01 22 00 00 2021-06-08 23:00:00.375 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2021-06-08 23:00:00.375 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 2 2021-06-08 23:00:00.375 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_SENSOR_MULTILEVEL V0 SENSOR_MULTILEVEL_REPORT 2021-06-08 23:00:00.375 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 2: Sensor Type = Temperature(1), Scale = 0 2021-06-08 23:00:00.375 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 2: Sensor Value = 0E+1 2021-06-08 23:00:00.375 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent 2021-06-08 23:00:00.375 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint=2, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=0E+1 2021-06-08 23:00:00.375 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:8f57dbad:node2:sensor_temperature2 to 0E+1 °C [QuantityType] 2021-06-08 23:00:00.376 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1. 2021-06-08 23:00:00.376 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@8139c7e. 2021-06-08 23:00:00.376 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 23:00:00.376 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 23:00:00.376 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:00.376 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:00.431 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 23 00 04 00 0F 1D 98 81 19 26 01 7A D6 57 AE 53 76 78 7B C2 36 D1 1F 28 FD D3 B3 78 AE 52 BE BF 6E 59 92 31 2021-06-08 23:00:00.434 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 1D 98 81 19 26 01 7A D6 57 AE 53 76 78 7B C2 36 D1 1F 28 FD D3 B3 78 AE 52 BE BF 6E 59 92 2021-06-08 23:00:00.434 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 1D 98 81 19 26 01 7A D6 57 AE 53 76 78 7B C2 36 D1 1F 28 FD D3 B3 78 AE 52 BE BF 6E 59 92 2021-06-08 23:00:00.434 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 23:00:00.434 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Application Command Request (ALIVE:DONE) 2021-06-08 23:00:00.434 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 23:00:00.434 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Decapsulating COMMAND_CLASS_SECURITY 2021-06-08 23:00:00.435 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 15: SECURITY_RXD 60 0D 00 01 5B 03 AA 80 01 2021-06-08 23:00:00.435 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2021-06-08 23:00:00.439 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Incoming command class COMMAND_CLASS_CENTRAL_SCENE, endpoint 0 2021-06-08 23:00:00.439 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Received COMMAND_CLASS_CENTRAL_SCENE V3 CENTRAL_SCENE_NOTIFICATION 2021-06-08 23:00:00.439 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 15: Received scene 1 at key 0 [Single Press] 2021-06-08 23:00:00.439 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Got an event from Z-Wave network: ZWaveCommandClassValueEvent 2021-06-08 23:00:00.439 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_CENTRAL_SCENE, value=1.0 2021-06-08 23:00:00.439 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Updating channel state zwave:device:8f57dbad:node15:scene_number to 1.0 [DecimalType] 2021-06-08 23:00:00.439 [INFO ] [openhab.event.ItemStateEvent ] - Item 'switch_bathroom_scene' updated to 1.0 2021-06-08 23:00:00.441 [INFO ] [openhab.event.RuleStatusInfoEvent ] - walli_scenes-1 updated: RUNNING 2021-06-08 23:00:00.441 [INFO ] [openhab.event.RuleStatusInfoEvent ] - walli_scenes-1 updated: IDLE 2021-06-08 23:00:00.441 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Commands processed 1. 2021-06-08 23:00:00.442 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@77c2c282. 2021-06-08 23:00:00.442 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 23:00:00.442 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 23:00:00.442 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:00.443 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:00.499 [INFO ] [openhab.event.ThingStatusInfoEvent ] - Thing 'chromecast:chromecast:1469b08e' updated: ONLINE 2021-06-08 23:00:00.499 [INFO ] [openhab.event.ItemStateEvent ] - Item 'google_home_idling' updated to OFF 2021-06-08 23:00:00.514 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 02 02 98 40 2B 2021-06-08 23:00:00.515 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 02 98 40 2021-06-08 23:00:00.516 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 02 98 40 2021-06-08 23:00:00.516 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 23:00:00.516 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:REQUEST_NIF) 2021-06-08 23:00:00.516 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2021-06-08 23:00:00.516 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY check internal 2021-06-08 23:00:00.516 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2021-06-08 23:00:00.516 [DEBUG] [andclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_REPORT version 1 2021-06-08 23:00:00.516 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added to secure queue - size 1 2021-06-08 23:00:00.516 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1. 2021-06-08 23:00:00.516 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@8cbe91f. 2021-06-08 23:00:00.517 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 23:00:00.517 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 23:00:00.517 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:00.517 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:00.517 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 02 0A 98 80 71 06 3C DB BE E7 41 A9 25 CD 24 2021-06-08 23:00:00.517 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 11 00 13 02 0A 98 80 71 06 3C DB BE E7 41 A9 25 CD 24 2021-06-08 23:00:00.519 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2021-06-08 23:00:00.519 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 15710: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 205 2021-06-08 23:00:00.520 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2021-06-08 23:00:00.520 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 23:00:00.520 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 23:00:00.520 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15710: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 205 2021-06-08 23:00:00.521 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2021-06-08 23:00:00.521 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:00.521 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 23:00:00.531 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2021-06-08 23:00:00.532 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:00.532 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:00.532 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15710: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 205 2021-06-08 23:00:00.533 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 23:00:00.533 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15710: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 205 2021-06-08 23:00:00.533 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:00.533 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack. 2021-06-08 23:00:00.533 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 15710: Advanced to WAIT_REQUEST 2021-06-08 23:00:00.533 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 15710: Transaction not completed 2021-06-08 23:00:00.533 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:00.533 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 23:00:00.591 [INFO ] [openhab.event.ItemStateEvent ] - Item 'google_home_player' updated to PAUSE 2021-06-08 23:00:00.628 [INFO ] [openhab.event.ThingStatusInfoEvent ] - Thing 'chromecast:chromecast:1469b08e' updated: ONLINE 2021-06-08 23:00:00.628 [INFO ] [openhab.event.ItemStateEvent ] - Item 'google_home_idling' updated to OFF 2021-06-08 23:00:00.641 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 CD 00 00 0C 2A 2021-06-08 23:00:00.642 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=205, payload=CD 00 00 0C 2021-06-08 23:00:00.642 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=205, payload=CD 00 00 0C 2021-06-08 23:00:00.642 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15710: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 205 2021-06-08 23:00:00.643 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 23:00:00.643 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15710: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 205 2021-06-08 23:00:00.643 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 15710: (Callback 205) 2021-06-08 23:00:00.643 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2021-06-08 23:00:00.643 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 15710: callback 205 2021-06-08 23:00:00.643 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=205, payload=CD 00 00 0C 2021-06-08 23:00:00.643 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 205, Status = Transmission complete and ACK received(0) 2021-06-08 23:00:00.643 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 15710: Transaction COMPLETED 2021-06-08 23:00:00.643 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Response processed after 124ms 2021-06-08 23:00:00.643 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 15710: Transaction completed 2021-06-08 23:00:00.644 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:15710 DONE 2021-06-08 23:00:00.644 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2021-06-08 23:00:00.644 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:00.644 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:00.690 [INFO ] [openhab.event.ThingStatusInfoEvent ] - Thing 'chromecast:chromecast:795da18a709a40c1900a79d5c55450de' updated: ONLINE 2021-06-08 23:00:00.690 [INFO ] [openhab.event.ItemStateEvent ] - Item 'jbl_cc_app_name' updated to UNDEF 2021-06-08 23:00:00.690 [INFO ] [openhab.event.ItemStateEvent ] - Item 'jbl_cc_appstatus' updated to UNDEF 2021-06-08 23:00:00.691 [INFO ] [openhab.event.ItemStateEvent ] - Item 'jbl_cc_volume' updated to 36 2021-06-08 23:00:00.691 [INFO ] [openhab.event.ItemStateEvent ] - Item 'jbl_cc_mute' updated to OFF 2021-06-08 23:00:00.719 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 24 00 04 00 02 1E 98 81 D3 E1 00 18 CA 7F C0 E1 90 01 4E 9F 4D 89 9C CB BA 26 E9 71 0B AE 9B 7F 2A 0C BF DA B1 2021-06-08 23:00:00.721 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 1E 98 81 D3 E1 00 18 CA 7F C0 E1 90 01 4E 9F 4D 89 9C CB BA 26 E9 71 0B AE 9B 7F 2A 0C BF DA 2021-06-08 23:00:00.721 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 1E 98 81 D3 E1 00 18 CA 7F C0 E1 90 01 4E 9F 4D 89 9C CB BA 26 E9 71 0B AE 9B 7F 2A 0C BF DA 2021-06-08 23:00:00.721 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 23:00:00.721 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:REQUEST_NIF) 2021-06-08 23:00:00.721 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Decapsulating COMMAND_CLASS_SECURITY 2021-06-08 23:00:00.721 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: SECURITY_RXD 60 0D 02 01 31 05 01 22 00 00 2021-06-08 23:00:00.722 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2021-06-08 23:00:00.722 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 2 2021-06-08 23:00:00.722 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_SENSOR_MULTILEVEL V0 SENSOR_MULTILEVEL_REPORT 2021-06-08 23:00:00.722 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 2: Sensor Type = Temperature(1), Scale = 0 2021-06-08 23:00:00.722 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 2: Sensor Value = 0E+1 2021-06-08 23:00:00.722 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent 2021-06-08 23:00:00.722 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint=2, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=0E+1 2021-06-08 23:00:00.722 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:8f57dbad:node2:sensor_temperature2 to 0E+1 °C [QuantityType] 2021-06-08 23:00:00.722 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1. 2021-06-08 23:00:00.722 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@6efbc161. 2021-06-08 23:00:00.723 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 23:00:00.723 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 23:00:00.723 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:00.723 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:00.771 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 02 02 98 40 2B 2021-06-08 23:00:00.774 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 02 98 40 2021-06-08 23:00:00.774 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 02 98 40 2021-06-08 23:00:00.774 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 23:00:00.774 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:REQUEST_NIF) 2021-06-08 23:00:00.775 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2021-06-08 23:00:00.775 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY check internal 2021-06-08 23:00:00.775 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2021-06-08 23:00:00.775 [DEBUG] [andclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_REPORT version 1 2021-06-08 23:00:00.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added to secure queue - size 1 2021-06-08 23:00:00.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1. 2021-06-08 23:00:00.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@7a9f50ac. 2021-06-08 23:00:00.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 23:00:00.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 23:00:00.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:00.776 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:00.776 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 02 0A 98 80 13 AD 9B F5 12 CA 16 4F 25 CE 57 2021-06-08 23:00:00.776 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 11 00 13 02 0A 98 80 13 AD 9B F5 12 CA 16 4F 25 CE 57 2021-06-08 23:00:00.776 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2021-06-08 23:00:00.776 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 15711: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 206 2021-06-08 23:00:00.778 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2021-06-08 23:00:00.778 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 23:00:00.778 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 23:00:00.778 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15711: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 206 2021-06-08 23:00:00.778 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2021-06-08 23:00:00.778 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:00.778 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 23:00:00.790 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2021-06-08 23:00:00.793 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:00.793 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:00.793 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15711: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 206 2021-06-08 23:00:00.793 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 23:00:00.793 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15711: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 206 2021-06-08 23:00:00.793 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:00.793 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack. 2021-06-08 23:00:00.794 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 15711: Advanced to WAIT_REQUEST 2021-06-08 23:00:00.794 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 15711: Transaction not completed 2021-06-08 23:00:00.794 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:00.794 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 23:00:00.839 [INFO ] [openhab.event.ThingStatusInfoEvent ] - Thing 'chromecast:chromecast:1469b08e' updated: ONLINE 2021-06-08 23:00:00.839 [INFO ] [openhab.event.RuleStatusInfoEvent ] - removeCastSound-1 updated: IDLE 2021-06-08 23:00:00.859 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 23 00 04 00 0F 1D 98 81 19 26 01 7A D6 57 AE 53 76 78 7B C2 36 D1 1F 28 FD D3 B3 78 AE 52 BE BF 6E 59 92 31 2021-06-08 23:00:00.861 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 1D 98 81 19 26 01 7A D6 57 AE 53 76 78 7B C2 36 D1 1F 28 FD D3 B3 78 AE 52 BE BF 6E 59 92 2021-06-08 23:00:00.861 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 1D 98 81 19 26 01 7A D6 57 AE 53 76 78 7B C2 36 D1 1F 28 FD D3 B3 78 AE 52 BE BF 6E 59 92 2021-06-08 23:00:00.861 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15711: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 206 2021-06-08 23:00:00.861 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Application Command Request (ALIVE:DONE) 2021-06-08 23:00:00.861 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 23:00:00.861 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Decapsulating COMMAND_CLASS_SECURITY 2021-06-08 23:00:00.861 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 15: SECURITY_ERR No valid NONCE! null 2021-06-08 23:00:00.862 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:00.862 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 23:00:01.092 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 0F 02 98 40 26 2021-06-08 23:00:01.094 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 02 98 40 2021-06-08 23:00:01.095 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 02 98 40 2021-06-08 23:00:01.095 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15711: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 206 2021-06-08 23:00:01.095 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Application Command Request (ALIVE:DONE) 2021-06-08 23:00:01.095 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 23:00:01.095 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2021-06-08 23:00:01.095 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: SECURITY check internal 2021-06-08 23:00:01.095 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2021-06-08 23:00:01.095 [DEBUG] [andclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_REPORT version 1 2021-06-08 23:00:01.096 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Added to secure queue - size 1 2021-06-08 23:00:01.096 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Commands processed 1. 2021-06-08 23:00:01.096 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1b284baf. 2021-06-08 23:00:01.096 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 2021-06-08 23:00:01.096 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 2021-06-08 23:00:01.096 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:01.096 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 23:00:01.118 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 CE 00 00 21 04 2021-06-08 23:00:01.119 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=206, payload=CE 00 00 21 2021-06-08 23:00:01.120 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=206, payload=CE 00 00 21 2021-06-08 23:00:01.120 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15711: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 206 2021-06-08 23:00:01.120 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 23:00:01.120 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15711: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 206 2021-06-08 23:00:01.120 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 15711: (Callback 206) 2021-06-08 23:00:01.120 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2021-06-08 23:00:01.120 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 15711: callback 206 2021-06-08 23:00:01.120 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=206, payload=CE 00 00 21 2021-06-08 23:00:01.120 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 206, Status = Transmission complete and ACK received(0) 2021-06-08 23:00:01.121 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 15711: Transaction COMPLETED 2021-06-08 23:00:01.121 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Response processed after 345ms 2021-06-08 23:00:01.121 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 15711: Transaction completed 2021-06-08 23:00:01.121 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:15711 DONE 2021-06-08 23:00:01.121 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2021-06-08 23:00:01.121 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:01.121 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:01.121 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 0F 0A 98 80 23 EE 62 E8 90 A8 56 22 25 CF 01 2021-06-08 23:00:01.121 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 15: Sending REQUEST Message = 01 11 00 13 0F 0A 98 80 23 EE 62 E8 90 A8 56 22 25 CF 01 2021-06-08 23:00:01.122 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2021-06-08 23:00:01.122 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 15712: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 207 2021-06-08 23:00:01.123 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2021-06-08 23:00:01.123 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 23:00:01.123 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 23:00:01.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15712: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 207 2021-06-08 23:00:01.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2021-06-08 23:00:01.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:01.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 23:00:01.132 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2021-06-08 23:00:01.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:01.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:01.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15712: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 207 2021-06-08 23:00:01.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 23:00:01.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15712: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 207 2021-06-08 23:00:01.135 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:01.135 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 15: sentData successfully placed on stack. 2021-06-08 23:00:01.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 15712: Advanced to WAIT_REQUEST 2021-06-08 23:00:01.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: TID 15712: Transaction not completed 2021-06-08 23:00:01.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:01.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 23:00:01.404 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 CF 00 00 1B 3F 2021-06-08 23:00:01.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=207, payload=CF 00 00 1B 2021-06-08 23:00:01.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=207, payload=CF 00 00 1B 2021-06-08 23:00:01.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15712: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 207 2021-06-08 23:00:01.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 23:00:01.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15712: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 207 2021-06-08 23:00:01.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 15712: (Callback 207) 2021-06-08 23:00:01.408 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2021-06-08 23:00:01.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 15712: callback 207 2021-06-08 23:00:01.408 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=207, payload=CF 00 00 1B 2021-06-08 23:00:01.409 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 15: SendData Request. CallBack ID = 207, Status = Transmission complete and ACK received(0) 2021-06-08 23:00:01.409 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 23:00:01.409 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 15712: Transaction COMPLETED 2021-06-08 23:00:01.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Response processed after 287ms 2021-06-08 23:00:01.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: TID 15712: Transaction completed 2021-06-08 23:00:01.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: notifyTransactionResponse TID:15712 DONE 2021-06-08 23:00:01.409 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2021-06-08 23:00:01.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:01.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:01.558 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 28 00 04 00 0F 22 98 81 BD AE 76 69 3F F9 36 7F AF 98 54 8A AF 89 6A D8 20 1E 78 BD 6D AA 04 23 64 69 58 1A E8 27 C6 27 63 2021-06-08 23:00:01.560 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 22 98 81 BD AE 76 69 3F F9 36 7F AF 98 54 8A AF 89 6A D8 20 1E 78 BD 6D AA 04 23 64 69 58 1A E8 27 C6 27 2021-06-08 23:00:01.560 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 22 98 81 BD AE 76 69 3F F9 36 7F AF 98 54 8A AF 89 6A D8 20 1E 78 BD 6D AA 04 23 64 69 58 1A E8 27 C6 27 2021-06-08 23:00:01.561 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 23:00:01.561 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Application Command Request (ALIVE:DONE) 2021-06-08 23:00:01.561 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 23:00:01.561 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Decapsulating COMMAND_CLASS_SECURITY 2021-06-08 23:00:01.561 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 15: SECURITY_RXD 60 0D 01 01 32 02 21 32 00 00 00 00 00 00 2021-06-08 23:00:01.563 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2021-06-08 23:00:01.563 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Incoming command class COMMAND_CLASS_METER, endpoint 1 2021-06-08 23:00:01.563 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Received COMMAND_CLASS_METER V0 METER_REPORT 2021-06-08 23:00:01.563 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 15: Meter: Type=Electric(1), Scale=W(2), Value=0E+1 2021-06-08 23:00:01.563 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Got an event from Z-Wave network: ZWaveMeterValueEvent 2021-06-08 23:00:01.563 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_METER, value=0E+1 2021-06-08 23:00:01.564 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Updating channel state zwave:device:8f57dbad:node15:meter_watts1 to 0 [DecimalType] 2021-06-08 23:00:01.564 [INFO ] [openhab.event.ItemStateEvent ] - Item 'switch_bathroom1_watts' updated to 0 2021-06-08 23:00:01.564 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'switch_bathroom1_watts' changed from 19.3 to 0 2021-06-08 23:00:01.565 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Updating channel state zwave:device:8f57dbad:node15:meter_kwh1 to 0 [DecimalType] 2021-06-08 23:00:01.565 [INFO ] [openhab.event.ItemStateEvent ] - Item 'switch_bathroom1_kwh' updated to 0 2021-06-08 23:00:01.565 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'switch_bathroom1_kwh' changed from 19.3 to 0 2021-06-08 23:00:01.566 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Commands processed 1. 2021-06-08 23:00:01.566 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@4c7ccac4. 2021-06-08 23:00:01.566 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 23:00:01.566 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 23:00:01.566 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:01.566 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:01.646 [INFO ] [openhab.event.InboxUpdatedEvent ] - Discovery Result with UID 'chromecast:chromecast:a43926f655f926b65d8ed99d140ec7dd' has been updated. 2021-06-08 23:00:01.813 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 28 00 04 00 0F 22 98 81 BD AE 76 69 3F F9 36 7F AF 98 54 8A AF 89 6A D8 20 1E 78 BD 6D AA 04 23 64 69 58 1A E8 27 C6 27 63 2021-06-08 23:00:01.814 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 22 98 81 BD AE 76 69 3F F9 36 7F AF 98 54 8A AF 89 6A D8 20 1E 78 BD 6D AA 04 23 64 69 58 1A E8 27 C6 27 2021-06-08 23:00:01.814 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 22 98 81 BD AE 76 69 3F F9 36 7F AF 98 54 8A AF 89 6A D8 20 1E 78 BD 6D AA 04 23 64 69 58 1A E8 27 C6 27 2021-06-08 23:00:01.814 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 23:00:01.814 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Application Command Request (ALIVE:DONE) 2021-06-08 23:00:01.815 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 23:00:01.815 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Decapsulating COMMAND_CLASS_SECURITY 2021-06-08 23:00:01.815 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 15: SECURITY_ERR No valid NONCE! null 2021-06-08 23:00:01.815 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:01.816 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:01.870 [INFO ] [openhab.event.ItemStateEvent ] - Item 'google_home_player' updated to PLAY 2021-06-08 23:00:01.871 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'google_home_player' changed from PAUSE to PLAY 2021-06-08 23:00:02.048 [INFO ] [openhab.event.ThingStatusInfoEvent ] - Thing 'chromecast:chromecast:0031b4ef30a020aba8a03705af9b0f60' updated: ONLINE 2021-06-08 23:00:02.068 [INFO ] [openhab.event.ThingStatusInfoEvent ] - Thing 'chromecast:chromecast:1469b08e' updated: ONLINE 2021-06-08 23:00:02.068 [INFO ] [openhab.event.ItemStateEvent ] - Item 'google_home_idling' updated to OFF 2021-06-08 23:00:02.197 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 28 00 04 00 0F 22 98 81 BD AE 76 69 3F F9 36 7F AF 98 54 8A AF 89 6A D8 20 1E 78 BD 6D AA 04 23 64 69 58 1A E8 27 C6 27 63 2021-06-08 23:00:02.199 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 22 98 81 BD AE 76 69 3F F9 36 7F AF 98 54 8A AF 89 6A D8 20 1E 78 BD 6D AA 04 23 64 69 58 1A E8 27 C6 27 2021-06-08 23:00:02.199 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 22 98 81 BD AE 76 69 3F F9 36 7F AF 98 54 8A AF 89 6A D8 20 1E 78 BD 6D AA 04 23 64 69 58 1A E8 27 C6 27 2021-06-08 23:00:02.199 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 23:00:02.199 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Application Command Request (ALIVE:DONE) 2021-06-08 23:00:02.199 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 23:00:02.199 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Decapsulating COMMAND_CLASS_SECURITY 2021-06-08 23:00:02.199 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 15: SECURITY_ERR No valid NONCE! null 2021-06-08 23:00:02.199 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:02.200 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:02.368 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 0F 02 98 40 26 2021-06-08 23:00:02.370 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 02 98 40 2021-06-08 23:00:02.370 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 02 98 40 2021-06-08 23:00:02.370 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 23:00:02.371 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Application Command Request (ALIVE:DONE) 2021-06-08 23:00:02.371 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 23:00:02.371 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2021-06-08 23:00:02.371 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: SECURITY check internal 2021-06-08 23:00:02.371 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2021-06-08 23:00:02.371 [DEBUG] [andclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_REPORT version 1 2021-06-08 23:00:02.371 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Added to secure queue - size 1 2021-06-08 23:00:02.371 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Commands processed 1. 2021-06-08 23:00:02.371 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@7c3cfae3. 2021-06-08 23:00:02.371 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 23:00:02.372 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 23:00:02.372 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:02.372 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:02.372 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 0F 0A 98 80 4F 09 EF 4C 6D 20 BD 82 25 D0 82 2021-06-08 23:00:02.372 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 15: Sending REQUEST Message = 01 11 00 13 0F 0A 98 80 4F 09 EF 4C 6D 20 BD 82 25 D0 82 2021-06-08 23:00:02.372 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2021-06-08 23:00:02.373 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 15713: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 208 2021-06-08 23:00:02.374 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2021-06-08 23:00:02.374 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 23:00:02.374 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 23:00:02.374 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15713: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 208 2021-06-08 23:00:02.374 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2021-06-08 23:00:02.374 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:02.375 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 23:00:02.387 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2021-06-08 23:00:02.388 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:02.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:02.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15713: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 208 2021-06-08 23:00:02.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 23:00:02.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15713: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 208 2021-06-08 23:00:02.389 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:02.389 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 15: sentData successfully placed on stack. 2021-06-08 23:00:02.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 15713: Advanced to WAIT_REQUEST 2021-06-08 23:00:02.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: TID 15713: Transaction not completed 2021-06-08 23:00:02.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:02.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 23:00:02.583 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 D0 00 00 14 2F 2021-06-08 23:00:02.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=208, payload=D0 00 00 14 2021-06-08 23:00:02.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=208, payload=D0 00 00 14 2021-06-08 23:00:02.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15713: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 208 2021-06-08 23:00:02.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 23:00:02.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15713: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 208 2021-06-08 23:00:02.585 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 15713: (Callback 208) 2021-06-08 23:00:02.585 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2021-06-08 23:00:02.585 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 15713: callback 208 2021-06-08 23:00:02.585 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=208, payload=D0 00 00 14 2021-06-08 23:00:02.585 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 15: SendData Request. CallBack ID = 208, Status = Transmission complete and ACK received(0) 2021-06-08 23:00:02.585 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 23:00:02.585 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 15713: Transaction COMPLETED 2021-06-08 23:00:02.585 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Response processed after 213ms 2021-06-08 23:00:02.585 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: TID 15713: Transaction completed 2021-06-08 23:00:02.585 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: notifyTransactionResponse TID:15713 DONE 2021-06-08 23:00:02.586 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2021-06-08 23:00:02.586 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:02.586 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:02.608 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 21 00 04 00 0F 1B 98 81 C9 15 42 43 39 65 A5 9C 8F FE 06 AB 51 65 4E 1E 23 AC 90 65 4D 3C 15 C3 33 39 2021-06-08 23:00:02.611 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 1B 98 81 C9 15 42 43 39 65 A5 9C 8F FE 06 AB 51 65 4E 1E 23 AC 90 65 4D 3C 15 C3 33 2021-06-08 23:00:02.611 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 1B 98 81 C9 15 42 43 39 65 A5 9C 8F FE 06 AB 51 65 4E 1E 23 AC 90 65 4D 3C 15 C3 33 2021-06-08 23:00:02.611 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 23:00:02.611 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Application Command Request (ALIVE:DONE) 2021-06-08 23:00:02.611 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 23:00:02.611 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Decapsulating COMMAND_CLASS_SECURITY 2021-06-08 23:00:02.611 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 15: SECURITY_ERR NONCE ID invalid! 35<>79 2021-06-08 23:00:02.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:02.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:02.838 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 21 00 04 00 0F 1B 98 81 C9 15 42 43 39 65 A5 9C 8F FE 06 AB 51 65 4E 1E 23 AC 90 65 4D 3C 15 C3 33 39 2021-06-08 23:00:02.840 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 1B 98 81 C9 15 42 43 39 65 A5 9C 8F FE 06 AB 51 65 4E 1E 23 AC 90 65 4D 3C 15 C3 33 2021-06-08 23:00:02.840 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 1B 98 81 C9 15 42 43 39 65 A5 9C 8F FE 06 AB 51 65 4E 1E 23 AC 90 65 4D 3C 15 C3 33 2021-06-08 23:00:02.840 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 23:00:02.840 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Application Command Request (ALIVE:DONE) 2021-06-08 23:00:02.840 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 23:00:02.840 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Decapsulating COMMAND_CLASS_SECURITY 2021-06-08 23:00:02.841 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 15: SECURITY_ERR NONCE ID invalid! 35<>79 2021-06-08 23:00:02.841 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:02.841 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:02.879 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 21 00 04 00 0F 1B 98 81 C9 15 42 43 39 65 A5 9C 8F FE 06 AB 51 65 4E 1E 23 AC 90 65 4D 3C 15 C3 33 39 2021-06-08 23:00:02.880 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 1B 98 81 C9 15 42 43 39 65 A5 9C 8F FE 06 AB 51 65 4E 1E 23 AC 90 65 4D 3C 15 C3 33 2021-06-08 23:00:02.880 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 1B 98 81 C9 15 42 43 39 65 A5 9C 8F FE 06 AB 51 65 4E 1E 23 AC 90 65 4D 3C 15 C3 33 2021-06-08 23:00:02.880 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 23:00:02.880 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Application Command Request (ALIVE:DONE) 2021-06-08 23:00:02.881 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 23:00:02.881 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Decapsulating COMMAND_CLASS_SECURITY 2021-06-08 23:00:02.881 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 15: SECURITY_ERR NONCE ID invalid! 35<>79 2021-06-08 23:00:02.881 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:02.881 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:03.076 [INFO ] [openhab.event.InboxUpdatedEvent ] - Discovery Result with UID 'chromecast:chromecast:a43926f655f926b65d8ed99d140ec7dd' has been updated. 2021-06-08 23:00:03.120 [INFO ] [openhab.event.ThingStatusInfoEvent ] - Thing 'spotify:player:f7a68189' updated: ONLINE 2021-06-08 23:00:03.278 [INFO ] [openhab.event.ThingStatusInfoEvent ] - Thing 'chromecast:audio:2bcbe0e09e095b6917885f04367df63e' updated: ONLINE 2021-06-08 23:00:03.278 [INFO ] [openhab.event.ItemStateEvent ] - Item 'klipsch_cc_app_name' updated to UNDEF 2021-06-08 23:00:03.279 [INFO ] [openhab.event.ItemStateEvent ] - Item 'klipsch_cc_appstatus' updated to UNDEF 2021-06-08 23:00:03.279 [INFO ] [openhab.event.ItemStateEvent ] - Item 'klipsch_cc_volume' updated to 51 2021-06-08 23:00:03.279 [INFO ] [openhab.event.ItemStateEvent ] - Item 'klipsch_cc_mute' updated to OFF 2021-06-08 23:00:04.097 [INFO ] [openhab.event.InboxUpdatedEvent ] - Discovery Result with UID 'chromecast:chromecast:a43926f655f926b65d8ed99d140ec7dd' has been updated. 2021-06-08 23:00:04.321 [INFO ] [openhab.event.ThingStatusInfoEvent ] - Thing 'chromecast:audiogroup:9951a181-39c5-4824-9f66-49f678bbf9aa' updated: ONLINE 2021-06-08 23:00:04.321 [INFO ] [openhab.event.ItemStateEvent ] - Item 'all_cc_volume' updated to 42 2021-06-08 23:00:04.322 [INFO ] [openhab.event.ItemStateEvent ] - Item 'all_cc_mute' updated to OFF 2021-06-08 23:00:04.387 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 0F 02 98 40 26 2021-06-08 23:00:04.388 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 02 98 40 2021-06-08 23:00:04.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 02 98 40 2021-06-08 23:00:04.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 23:00:04.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Application Command Request (ALIVE:DONE) 2021-06-08 23:00:04.389 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 23:00:04.389 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2021-06-08 23:00:04.389 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: SECURITY check internal 2021-06-08 23:00:04.389 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2021-06-08 23:00:04.389 [DEBUG] [andclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_REPORT version 1 2021-06-08 23:00:04.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Added to secure queue - size 1 2021-06-08 23:00:04.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Commands processed 1. 2021-06-08 23:00:04.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@7c26cff8. 2021-06-08 23:00:04.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 23:00:04.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-08 23:00:04.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:04.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:04.390 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 0F 0A 98 80 EC 2B CE FE A3 BC F8 4F 25 D1 4B 2021-06-08 23:00:04.390 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 15: Sending REQUEST Message = 01 11 00 13 0F 0A 98 80 EC 2B CE FE A3 BC F8 4F 25 D1 4B 2021-06-08 23:00:04.391 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2021-06-08 23:00:04.391 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 15714: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 209 2021-06-08 23:00:04.393 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2021-06-08 23:00:04.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 23:00:04.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-08 23:00:04.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15714: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 209 2021-06-08 23:00:04.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2021-06-08 23:00:04.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:04.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 23:00:04.401 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2021-06-08 23:00:04.403 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:04.403 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:04.403 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15714: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 209 2021-06-08 23:00:04.403 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 23:00:04.404 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15714: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 209 2021-06-08 23:00:04.404 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-08 23:00:04.404 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 15: sentData successfully placed on stack. 2021-06-08 23:00:04.404 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 15714: Advanced to WAIT_REQUEST 2021-06-08 23:00:04.404 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: TID 15714: Transaction not completed 2021-06-08 23:00:04.404 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:04.404 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-08 23:00:04.422 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 D1 00 00 02 38 2021-06-08 23:00:04.425 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=209, payload=D1 00 00 02 2021-06-08 23:00:04.426 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=209, payload=D1 00 00 02 2021-06-08 23:00:04.426 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15714: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 209 2021-06-08 23:00:04.426 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-08 23:00:04.426 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15714: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 209 2021-06-08 23:00:04.426 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 15714: (Callback 209) 2021-06-08 23:00:04.426 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2021-06-08 23:00:04.426 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 15714: callback 209 2021-06-08 23:00:04.426 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=209, payload=D1 00 00 02 2021-06-08 23:00:04.427 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 15: SendData Request. CallBack ID = 209, Status = Transmission complete and ACK received(0) 2021-06-08 23:00:04.427 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 23:00:04.427 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 15714: Transaction COMPLETED 2021-06-08 23:00:04.427 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Response processed after 36ms 2021-06-08 23:00:04.427 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: TID 15714: Transaction completed 2021-06-08 23:00:04.427 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: notifyTransactionResponse TID:15714 DONE 2021-06-08 23:00:04.427 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2021-06-08 23:00:04.427 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:04.428 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-08 23:00:04.451 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 28 00 04 00 0F 22 98 81 C9 AA FB 32 61 3B 3F C6 10 CD 11 64 A8 C9 5C BE 9B 53 2C 4B E1 DE D6 4F 47 7B E3 CB CB 63 A6 77 A1 2021-06-08 23:00:04.452 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 22 98 81 C9 AA FB 32 61 3B 3F C6 10 CD 11 64 A8 C9 5C BE 9B 53 2C 4B E1 DE D6 4F 47 7B E3 CB CB 63 A6 77 2021-06-08 23:00:04.453 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 22 98 81 C9 AA FB 32 61 3B 3F C6 10 CD 11 64 A8 C9 5C BE 9B 53 2C 4B E1 DE D6 4F 47 7B E3 CB CB 63 A6 77 2021-06-08 23:00:04.453 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-08 23:00:04.453 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Application Command Request (ALIVE:DONE) 2021-06-08 23:00:04.453 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2021-06-08 23:00:04.453 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Decapsulating COMMAND_CLASS_SECURITY 2021-06-08 23:00:04.453 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 15: SECURITY_ERR NONCE ID invalid! 79<>236 2021-06-08 23:00:04.453 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-08 23:00:04.453 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.