2021-06-11 00:30:15.922 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 05 02 98 40 2C 2021-06-11 00:30:15.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 02 98 40 2021-06-11 00:30:15.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 02 98 40 2021-06-11 00:30:15.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-11 00:30:15.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE) 2021-06-11 00:30:15.924 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:15.924 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2021-06-11 00:30:15.924 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY check internal 2021-06-11 00:30:15.924 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2021-06-11 00:30:15.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Added to secure queue - size 1 2021-06-11 00:30:15.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1. 2021-06-11 00:30:15.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@5f2ad418. 2021-06-11 00:30:15.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:15.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:15.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:15.925 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:15.925 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 11 00 13 05 0A 98 80 53 22 91 A8 15 F3 76 59 25 9E D0 2021-06-11 00:30:15.925 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2021-06-11 00:30:15.925 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 31184: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 158 2021-06-11 00:30:15.927 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2021-06-11 00:30:15.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-11 00:30:15.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-11 00:30:15.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31184: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 158 2021-06-11 00:30:15.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2021-06-11 00:30:15.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:15.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-11 00:30:15.939 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2021-06-11 00:30:15.942 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:15.942 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:15.942 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31184: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 158 2021-06-11 00:30:15.942 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-11 00:30:15.942 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 31184: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 158 2021-06-11 00:30:15.942 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:15.942 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 31184: Advanced to WAIT_REQUEST 2021-06-11 00:30:15.942 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 31184: Transaction not completed 2021-06-11 00:30:15.943 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:15.943 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-11 00:30:16.102 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 9E 00 00 11 64 2021-06-11 00:30:16.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=158, payload=9E 00 00 11 2021-06-11 00:30:16.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=158, payload=9E 00 00 11 2021-06-11 00:30:16.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31184: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 158 2021-06-11 00:30:16.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-11 00:30:16.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 31184: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 158 2021-06-11 00:30:16.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 31184: (Callback 158) 2021-06-11 00:30:16.105 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2021-06-11 00:30:16.106 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 31184: callback 158 2021-06-11 00:30:16.106 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=158, payload=9E 00 00 11 2021-06-11 00:30:16.106 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:16.106 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 31184: Transaction COMPLETED 2021-06-11 00:30:16.106 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Response processed after 181ms 2021-06-11 00:30:16.106 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 31184: Transaction completed 2021-06-11 00:30:16.106 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: notifyTransactionResponse TID:31184 DONE 2021-06-11 00:30:16.106 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2021-06-11 00:30:16.107 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:16.107 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:16.187 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 21 00 04 00 05 1B 98 81 54 27 A8 38 38 67 62 43 C8 71 A8 DB 06 46 78 A3 53 9F 9C D2 15 69 4E 9B EF D5 2021-06-11 00:30:16.189 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 1B 98 81 54 27 A8 38 38 67 62 43 C8 71 A8 DB 06 46 78 A3 53 9F 9C D2 15 69 4E 9B EF 2021-06-11 00:30:16.189 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 1B 98 81 54 27 A8 38 38 67 62 43 C8 71 A8 DB 06 46 78 A3 53 9F 9C D2 15 69 4E 9B EF 2021-06-11 00:30:16.189 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-11 00:30:16.189 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE) 2021-06-11 00:30:16.189 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:16.189 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Decapsulating COMMAND_CLASS_SECURITY 2021-06-11 00:30:16.189 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 5: SECURITY_RXD 60 0D 00 01 20 01 FF 2021-06-11 00:30:16.190 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2021-06-11 00:30:16.190 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_BASIC, endpoint 0 2021-06-11 00:30:16.190 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_BASIC V1 BASIC_SET 2021-06-11 00:30:16.190 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 5: Basic report, value = 255 2021-06-11 00:30:16.190 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveCommandClassValueEvent 2021-06-11 00:30:16.190 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_BASIC, value=255 2021-06-11 00:30:16.190 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1. 2021-06-11 00:30:16.190 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@18d5692d. 2021-06-11 00:30:16.190 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:16.190 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:16.191 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:16.191 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:17.240 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 05 02 98 40 2C 2021-06-11 00:30:17.242 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 02 98 40 2021-06-11 00:30:17.242 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 02 98 40 2021-06-11 00:30:17.242 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-11 00:30:17.242 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE) 2021-06-11 00:30:17.242 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:17.242 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2021-06-11 00:30:17.242 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY check internal 2021-06-11 00:30:17.243 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2021-06-11 00:30:17.243 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Added to secure queue - size 1 2021-06-11 00:30:17.243 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1. 2021-06-11 00:30:17.243 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@705495ff. 2021-06-11 00:30:17.243 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:17.243 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:17.243 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:17.243 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:17.244 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 11 00 13 05 0A 98 80 E3 B0 C2 B9 69 90 62 32 25 9F D1 2021-06-11 00:30:17.246 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2021-06-11 00:30:17.246 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 31185: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 159 2021-06-11 00:30:17.248 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2021-06-11 00:30:17.248 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-11 00:30:17.248 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-11 00:30:17.248 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31185: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 159 2021-06-11 00:30:17.248 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2021-06-11 00:30:17.248 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:17.248 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-11 00:30:17.258 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2021-06-11 00:30:17.259 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:17.259 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:17.259 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31185: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 159 2021-06-11 00:30:17.259 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-11 00:30:17.259 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 31185: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 159 2021-06-11 00:30:17.260 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:17.260 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 31185: Advanced to WAIT_REQUEST 2021-06-11 00:30:17.260 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 31185: Transaction not completed 2021-06-11 00:30:17.260 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:17.260 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-11 00:30:17.478 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 9F 00 00 16 62 2021-06-11 00:30:17.480 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=159, payload=9F 00 00 16 2021-06-11 00:30:17.480 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=159, payload=9F 00 00 16 2021-06-11 00:30:17.480 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31185: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 159 2021-06-11 00:30:17.480 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-11 00:30:17.480 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 31185: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 159 2021-06-11 00:30:17.480 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 31185: (Callback 159) 2021-06-11 00:30:17.480 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2021-06-11 00:30:17.481 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 31185: callback 159 2021-06-11 00:30:17.481 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=159, payload=9F 00 00 16 2021-06-11 00:30:17.481 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:17.481 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 31185: Transaction COMPLETED 2021-06-11 00:30:17.481 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Response processed after 235ms 2021-06-11 00:30:17.481 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 31185: Transaction completed 2021-06-11 00:30:17.481 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: notifyTransactionResponse TID:31185 DONE 2021-06-11 00:30:17.481 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2021-06-11 00:30:17.482 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:17.482 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:17.564 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 21 00 04 00 05 1B 98 81 83 A0 63 19 6D 9D 1C 87 6A EA AB 9F FD 08 75 F9 E3 2F 3C 78 0B 62 CD 91 F9 66 2021-06-11 00:30:17.567 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 1B 98 81 83 A0 63 19 6D 9D 1C 87 6A EA AB 9F FD 08 75 F9 E3 2F 3C 78 0B 62 CD 91 F9 2021-06-11 00:30:17.568 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 1B 98 81 83 A0 63 19 6D 9D 1C 87 6A EA AB 9F FD 08 75 F9 E3 2F 3C 78 0B 62 CD 91 F9 2021-06-11 00:30:17.568 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-11 00:30:17.568 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE) 2021-06-11 00:30:17.568 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:17.568 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Decapsulating COMMAND_CLASS_SECURITY 2021-06-11 00:30:17.568 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 5: SECURITY_RXD 60 0D 01 01 25 03 FF 2021-06-11 00:30:17.568 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2021-06-11 00:30:17.568 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_SWITCH_BINARY, endpoint 1 2021-06-11 00:30:17.568 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_SWITCH_BINARY V0 SWITCH_BINARY_REPORT 2021-06-11 00:30:17.569 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 5: Switch Binary report, value = 255 2021-06-11 00:30:17.569 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveCommandClassValueEvent 2021-06-11 00:30:17.569 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_SWITCH_BINARY, value=255 2021-06-11 00:30:17.569 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:8f57dbad:node5:switch_binary1 to ON [OnOffType] 2021-06-11 00:30:17.571 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1. 2021-06-11 00:30:17.571 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@3cfae0b3. 2021-06-11 00:30:17.571 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:17.571 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:17.571 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:17.571 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:19.845 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 05 02 98 40 2C 2021-06-11 00:30:19.848 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 02 98 40 2021-06-11 00:30:19.848 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 02 98 40 2021-06-11 00:30:19.848 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-11 00:30:19.848 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE) 2021-06-11 00:30:19.848 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:19.848 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2021-06-11 00:30:19.848 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY check internal 2021-06-11 00:30:19.848 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2021-06-11 00:30:19.849 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Added to secure queue - size 1 2021-06-11 00:30:19.849 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1. 2021-06-11 00:30:19.849 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@35797920. 2021-06-11 00:30:19.850 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:19.850 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:19.850 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:19.850 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:19.850 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 11 00 13 05 0A 98 80 8F 81 D4 8A F3 8D B1 A2 25 A0 52 2021-06-11 00:30:19.854 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2021-06-11 00:30:19.854 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 31186: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 160 2021-06-11 00:30:19.856 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2021-06-11 00:30:19.856 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-11 00:30:19.856 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-11 00:30:19.856 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31186: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 160 2021-06-11 00:30:19.856 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2021-06-11 00:30:19.856 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:19.857 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-11 00:30:19.867 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2021-06-11 00:30:19.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:19.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:19.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31186: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 160 2021-06-11 00:30:19.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-11 00:30:19.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 31186: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 160 2021-06-11 00:30:19.870 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:19.871 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 31186: Advanced to WAIT_REQUEST 2021-06-11 00:30:19.871 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 31186: Transaction not completed 2021-06-11 00:30:19.871 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:19.871 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-11 00:30:19.966 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 A0 00 00 0A 41 2021-06-11 00:30:19.969 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=160, payload=A0 00 00 0A 2021-06-11 00:30:19.969 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=160, payload=A0 00 00 0A 2021-06-11 00:30:19.969 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31186: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 160 2021-06-11 00:30:19.969 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-11 00:30:19.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 31186: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 160 2021-06-11 00:30:19.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 31186: (Callback 160) 2021-06-11 00:30:19.970 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2021-06-11 00:30:19.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 31186: callback 160 2021-06-11 00:30:19.970 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=160, payload=A0 00 00 0A 2021-06-11 00:30:19.970 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:19.970 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 31186: Transaction COMPLETED 2021-06-11 00:30:19.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Response processed after 116ms 2021-06-11 00:30:19.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 31186: Transaction completed 2021-06-11 00:30:19.971 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: notifyTransactionResponse TID:31186 DONE 2021-06-11 00:30:19.971 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2021-06-11 00:30:19.971 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:19.971 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:20.049 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 21 00 04 00 05 1B 98 81 39 2E 77 59 00 AA C2 70 FB F4 2C F9 FE 54 EF FC E3 EE 55 FB 6A 65 0F 2A 16 00 2021-06-11 00:30:20.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 1B 98 81 39 2E 77 59 00 AA C2 70 FB F4 2C F9 FE 54 EF FC E3 EE 55 FB 6A 65 0F 2A 16 2021-06-11 00:30:20.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 1B 98 81 39 2E 77 59 00 AA C2 70 FB F4 2C F9 FE 54 EF FC E3 EE 55 FB 6A 65 0F 2A 16 2021-06-11 00:30:20.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-11 00:30:20.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE) 2021-06-11 00:30:20.051 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:20.051 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Decapsulating COMMAND_CLASS_SECURITY 2021-06-11 00:30:20.052 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 5: SECURITY_ERR NONCE ID invalid! 227<>143 2021-06-11 00:30:20.052 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:20.052 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:20.391 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 05 02 98 40 2C 2021-06-11 00:30:20.394 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 02 98 40 2021-06-11 00:30:20.394 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 02 98 40 2021-06-11 00:30:20.394 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-11 00:30:20.394 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE) 2021-06-11 00:30:20.394 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:20.394 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2021-06-11 00:30:20.394 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY check internal 2021-06-11 00:30:20.394 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2021-06-11 00:30:20.395 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Added to secure queue - size 1 2021-06-11 00:30:20.406 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1. 2021-06-11 00:30:20.406 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@656e2a3. 2021-06-11 00:30:20.406 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:20.406 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:20.406 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:20.407 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:20.407 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 11 00 13 05 0A 98 80 3B E7 62 52 8A AB 00 58 25 A1 FB 2021-06-11 00:30:20.408 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2021-06-11 00:30:20.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 31187: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 161 2021-06-11 00:30:20.409 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2021-06-11 00:30:20.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-11 00:30:20.410 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-11 00:30:20.410 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31187: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 161 2021-06-11 00:30:20.410 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2021-06-11 00:30:20.410 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:20.410 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-11 00:30:20.420 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2021-06-11 00:30:20.423 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:20.423 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:20.423 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31187: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 161 2021-06-11 00:30:20.423 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-11 00:30:20.424 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 31187: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 161 2021-06-11 00:30:20.424 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:20.424 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 31187: Advanced to WAIT_REQUEST 2021-06-11 00:30:20.424 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 31187: Transaction not completed 2021-06-11 00:30:20.424 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:20.424 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-11 00:30:20.515 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 A1 00 00 09 43 2021-06-11 00:30:20.517 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=161, payload=A1 00 00 09 2021-06-11 00:30:20.517 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=161, payload=A1 00 00 09 2021-06-11 00:30:20.517 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31187: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 161 2021-06-11 00:30:20.517 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-11 00:30:20.517 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 31187: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 161 2021-06-11 00:30:20.517 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 31187: (Callback 161) 2021-06-11 00:30:20.517 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2021-06-11 00:30:20.517 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 31187: callback 161 2021-06-11 00:30:20.518 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=161, payload=A1 00 00 09 2021-06-11 00:30:20.518 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:20.518 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 31187: Transaction COMPLETED 2021-06-11 00:30:20.518 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Response processed after 110ms 2021-06-11 00:30:20.518 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 31187: Transaction completed 2021-06-11 00:30:20.518 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: notifyTransactionResponse TID:31187 DONE 2021-06-11 00:30:20.518 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2021-06-11 00:30:20.518 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:20.519 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:20.592 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 21 00 04 00 05 1B 98 81 1A 0A E0 B8 DE E8 5C BE B0 67 51 7B D3 50 D0 0D 3B 91 02 6D AA 5B ED 69 60 32 2021-06-11 00:30:20.597 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 1B 98 81 1A 0A E0 B8 DE E8 5C BE B0 67 51 7B D3 50 D0 0D 3B 91 02 6D AA 5B ED 69 60 2021-06-11 00:30:20.597 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 1B 98 81 1A 0A E0 B8 DE E8 5C BE B0 67 51 7B D3 50 D0 0D 3B 91 02 6D AA 5B ED 69 60 2021-06-11 00:30:20.597 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-11 00:30:20.597 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE) 2021-06-11 00:30:20.597 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:20.597 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Decapsulating COMMAND_CLASS_SECURITY 2021-06-11 00:30:20.597 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 5: SECURITY_RXD 60 0D 01 01 25 03 00 2021-06-11 00:30:20.597 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2021-06-11 00:30:20.597 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_SWITCH_BINARY, endpoint 1 2021-06-11 00:30:20.598 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_SWITCH_BINARY V0 SWITCH_BINARY_REPORT 2021-06-11 00:30:20.598 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 5: Switch Binary report, value = 0 2021-06-11 00:30:20.598 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveCommandClassValueEvent 2021-06-11 00:30:20.598 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_SWITCH_BINARY, value=0 2021-06-11 00:30:20.598 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:8f57dbad:node5:switch_binary1 to OFF [OnOffType] 2021-06-11 00:30:20.601 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1. 2021-06-11 00:30:20.601 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@52f964fb. 2021-06-11 00:30:20.601 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:20.601 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:20.601 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:20.601 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:22.507 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 05 02 98 40 2C 2021-06-11 00:30:22.511 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 02 98 40 2021-06-11 00:30:22.511 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 02 98 40 2021-06-11 00:30:22.511 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-11 00:30:22.511 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE) 2021-06-11 00:30:22.511 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:22.512 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2021-06-11 00:30:22.512 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY check internal 2021-06-11 00:30:22.512 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2021-06-11 00:30:22.512 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Added to secure queue - size 1 2021-06-11 00:30:22.512 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1. 2021-06-11 00:30:22.512 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@39edf96f. 2021-06-11 00:30:22.512 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:22.512 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:22.512 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:22.513 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:22.513 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 11 00 13 05 0A 98 80 EC 42 A3 B2 89 79 E8 A6 25 A2 6C 2021-06-11 00:30:22.516 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2021-06-11 00:30:22.516 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 31188: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 162 2021-06-11 00:30:22.519 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2021-06-11 00:30:22.519 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-11 00:30:22.519 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-11 00:30:22.519 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31188: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 162 2021-06-11 00:30:22.519 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2021-06-11 00:30:22.519 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:22.520 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-11 00:30:22.530 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2021-06-11 00:30:22.531 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:22.531 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:22.531 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31188: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 162 2021-06-11 00:30:22.531 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-11 00:30:22.531 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 31188: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 162 2021-06-11 00:30:22.531 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:22.532 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 31188: Advanced to WAIT_REQUEST 2021-06-11 00:30:22.532 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 31188: Transaction not completed 2021-06-11 00:30:22.532 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:22.532 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-11 00:30:22.731 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 A2 00 00 14 5D 2021-06-11 00:30:22.732 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=162, payload=A2 00 00 14 2021-06-11 00:30:22.733 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=162, payload=A2 00 00 14 2021-06-11 00:30:22.733 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31188: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 162 2021-06-11 00:30:22.733 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-11 00:30:22.733 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 31188: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 162 2021-06-11 00:30:22.733 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 31188: (Callback 162) 2021-06-11 00:30:22.733 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2021-06-11 00:30:22.733 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 31188: callback 162 2021-06-11 00:30:22.733 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=162, payload=A2 00 00 14 2021-06-11 00:30:22.733 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:22.734 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 31188: Transaction COMPLETED 2021-06-11 00:30:22.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Response processed after 218ms 2021-06-11 00:30:22.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 31188: Transaction completed 2021-06-11 00:30:22.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: notifyTransactionResponse TID:31188 DONE 2021-06-11 00:30:22.734 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2021-06-11 00:30:22.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:22.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:22.923 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 21 00 04 00 05 1B 98 81 BE 6A 03 EC B7 8F CE 69 68 C8 41 F0 12 31 81 7C EC 1E 39 93 B3 07 D6 88 B1 B5 2021-06-11 00:30:22.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 1B 98 81 BE 6A 03 EC B7 8F CE 69 68 C8 41 F0 12 31 81 7C EC 1E 39 93 B3 07 D6 88 B1 2021-06-11 00:30:22.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 1B 98 81 BE 6A 03 EC B7 8F CE 69 68 C8 41 F0 12 31 81 7C EC 1E 39 93 B3 07 D6 88 B1 2021-06-11 00:30:22.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-11 00:30:22.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE) 2021-06-11 00:30:22.927 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:22.928 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Decapsulating COMMAND_CLASS_SECURITY 2021-06-11 00:30:22.928 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 5: SECURITY_RXD 60 0D 00 01 20 01 FF 2021-06-11 00:30:22.928 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2021-06-11 00:30:22.928 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_BASIC, endpoint 0 2021-06-11 00:30:22.928 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_BASIC V1 BASIC_SET 2021-06-11 00:30:22.928 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 5: Basic report, value = 255 2021-06-11 00:30:22.928 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveCommandClassValueEvent 2021-06-11 00:30:22.928 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_BASIC, value=255 2021-06-11 00:30:22.929 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1. 2021-06-11 00:30:22.929 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@47a3370b. 2021-06-11 00:30:22.929 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:22.929 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:22.929 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:22.929 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:23.559 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 05 02 98 40 2C 2021-06-11 00:30:23.563 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 02 98 40 2021-06-11 00:30:23.563 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 02 98 40 2021-06-11 00:30:23.563 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-11 00:30:23.563 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE) 2021-06-11 00:30:23.563 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:23.564 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2021-06-11 00:30:23.564 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY check internal 2021-06-11 00:30:23.564 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2021-06-11 00:30:23.564 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Added to secure queue - size 1 2021-06-11 00:30:23.564 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1. 2021-06-11 00:30:23.564 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@76d196a6. 2021-06-11 00:30:23.564 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:23.564 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:23.565 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:23.565 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:23.565 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 11 00 13 05 0A 98 80 67 EC 3E 3C 26 D0 7E 40 25 A3 2D 2021-06-11 00:30:23.567 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2021-06-11 00:30:23.567 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 31189: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 163 2021-06-11 00:30:23.570 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2021-06-11 00:30:23.570 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-11 00:30:23.570 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-11 00:30:23.570 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31189: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 163 2021-06-11 00:30:23.570 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2021-06-11 00:30:23.570 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:23.570 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-11 00:30:23.587 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2021-06-11 00:30:23.591 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:23.591 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:23.591 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31189: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 163 2021-06-11 00:30:23.591 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-11 00:30:23.591 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 31189: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 163 2021-06-11 00:30:23.592 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:23.592 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 31189: Advanced to WAIT_REQUEST 2021-06-11 00:30:23.592 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 31189: Transaction not completed 2021-06-11 00:30:23.592 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:23.592 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-11 00:30:23.675 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 A3 00 00 09 41 2021-06-11 00:30:23.679 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=163, payload=A3 00 00 09 2021-06-11 00:30:23.679 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=163, payload=A3 00 00 09 2021-06-11 00:30:23.679 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31189: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 163 2021-06-11 00:30:23.679 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-11 00:30:23.680 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 31189: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 163 2021-06-11 00:30:23.680 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 31189: (Callback 163) 2021-06-11 00:30:23.680 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2021-06-11 00:30:23.680 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 31189: callback 163 2021-06-11 00:30:23.680 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=163, payload=A3 00 00 09 2021-06-11 00:30:23.680 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:23.680 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 31189: Transaction COMPLETED 2021-06-11 00:30:23.680 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Response processed after 113ms 2021-06-11 00:30:23.681 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 31189: Transaction completed 2021-06-11 00:30:23.681 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: notifyTransactionResponse TID:31189 DONE 2021-06-11 00:30:23.681 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2021-06-11 00:30:23.681 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:23.681 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:23.967 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 21 00 04 00 05 1B 98 81 4C B5 F5 B0 C1 CE F0 09 2C 4A 24 AF 18 8C EE 95 EC 8A 6F 9B 44 85 EA 05 0E 27 2021-06-11 00:30:23.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 1B 98 81 4C B5 F5 B0 C1 CE F0 09 2C 4A 24 AF 18 8C EE 95 EC 8A 6F 9B 44 85 EA 05 0E 2021-06-11 00:30:23.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 1B 98 81 4C B5 F5 B0 C1 CE F0 09 2C 4A 24 AF 18 8C EE 95 EC 8A 6F 9B 44 85 EA 05 0E 2021-06-11 00:30:23.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-11 00:30:23.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE) 2021-06-11 00:30:23.970 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:23.971 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Decapsulating COMMAND_CLASS_SECURITY 2021-06-11 00:30:23.971 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 5: SECURITY_ERR NONCE ID invalid! 236<>103 2021-06-11 00:30:23.971 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:23.971 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:26.744 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 05 02 98 40 2C 2021-06-11 00:30:26.746 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 02 98 40 2021-06-11 00:30:26.746 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 02 98 40 2021-06-11 00:30:26.746 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-11 00:30:26.746 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE) 2021-06-11 00:30:26.746 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:26.746 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 2021-06-11 00:30:26.746 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY check internal 2021-06-11 00:30:26.746 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET 2021-06-11 00:30:26.747 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Added to secure queue - size 1 2021-06-11 00:30:26.747 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1. 2021-06-11 00:30:26.747 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@6f16ea3b. 2021-06-11 00:30:26.747 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:26.747 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2021-06-11 00:30:26.747 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:26.747 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:26.748 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 11 00 13 05 0A 98 80 24 5F 05 9B 91 38 48 50 25 A4 3F 2021-06-11 00:30:26.748 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2021-06-11 00:30:26.748 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 31190: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 164 2021-06-11 00:30:26.750 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2021-06-11 00:30:26.750 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-11 00:30:26.750 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2021-06-11 00:30:26.750 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31190: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 164 2021-06-11 00:30:26.750 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2021-06-11 00:30:26.750 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:26.750 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-11 00:30:26.762 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2021-06-11 00:30:26.766 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:26.766 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:26.766 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31190: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 164 2021-06-11 00:30:26.766 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-11 00:30:26.766 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 31190: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 164 2021-06-11 00:30:26.766 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2021-06-11 00:30:26.766 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 31190: Advanced to WAIT_REQUEST 2021-06-11 00:30:26.766 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 31190: Transaction not completed 2021-06-11 00:30:26.767 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:26.767 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2021-06-11 00:30:26.868 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 A4 00 00 0B 44 2021-06-11 00:30:26.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=164, payload=A4 00 00 0B 2021-06-11 00:30:26.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=164, payload=A4 00 00 0B 2021-06-11 00:30:26.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31190: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 164 2021-06-11 00:30:26.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2021-06-11 00:30:26.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 31190: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 164 2021-06-11 00:30:26.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 31190: (Callback 164) 2021-06-11 00:30:26.870 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2021-06-11 00:30:26.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 31190: callback 164 2021-06-11 00:30:26.870 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=164, payload=A4 00 00 0B 2021-06-11 00:30:26.871 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:26.871 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 31190: Transaction COMPLETED 2021-06-11 00:30:26.871 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Response processed after 123ms 2021-06-11 00:30:26.871 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 31190: Transaction completed 2021-06-11 00:30:26.871 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: notifyTransactionResponse TID:31190 DONE 2021-06-11 00:30:26.871 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2021-06-11 00:30:26.871 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2021-06-11 00:30:26.872 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2021-06-11 00:30:26.943 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 28 00 04 00 05 22 98 81 EE 85 44 C8 34 47 73 35 4D 3A 2A BE 40 73 BF 18 17 43 E2 37 B1 8F 83 24 D9 FE 88 98 49 42 55 BF 86 2021-06-11 00:30:26.946 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 22 98 81 EE 85 44 C8 34 47 73 35 4D 3A 2A BE 40 73 BF 18 17 43 E2 37 B1 8F 83 24 D9 FE 88 98 49 42 55 BF 2021-06-11 00:30:26.946 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 22 98 81 EE 85 44 C8 34 47 73 35 4D 3A 2A BE 40 73 BF 18 17 43 E2 37 B1 8F 83 24 D9 FE 88 98 49 42 55 BF 2021-06-11 00:30:26.946 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2021-06-11 00:30:26.946 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE) 2021-06-11 00:30:26.946 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false 2021-06-11 00:30:26.946 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Decapsulating COMMAND_CLASS_SECURITY 2021-06-11 00:30:26.947 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 5: SECURITY_RXD 60 0D 01 01 32 02 21 32 00 00 00 00 00 00 2021-06-11 00:30:26.947 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2021-06-11 00:30:26.947 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_METER, endpoint 1 2021-06-11 00:30:26.947 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_METER V0 METER_REPORT 2021-06-11 00:30:26.947 [DEBUG] [.commandclass.ZWaveMeterCommandClass]