00:53:23.922 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 49 84 14 08 04 07 01 5E 98 9F 55 6C 42 00:53:23.925 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=20, callback=132, payload=84 14 08 04 07 01 5E 98 9F 55 6C 00:53:23.928 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=20, callback=132, payload=84 14 08 04 07 01 5E 98 9F 55 6C 00:53:23.930 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 00:53:23.931 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0 00:53:23.932 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: null 00:53:23.933 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=20, callback=132, payload=84 14 08 04 07 01 5E 98 9F 55 6C 00:53:23.936 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 20: Application update request. Node information received. Transaction null 00:53:23.937 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveNodeStatusEvent 00:53:23.938 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Setting ONLINE 00:53:23.939 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 20: Node Status event - Node is ALIVE 00:53:23.940 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: Node is ALIVE. Init stage is VERSION. 00:53:23.941 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveNodeStatusEvent 00:53:23.942 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Setting ONLINE 00:53:23.942 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zwave:device:16c934373e7:node20' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE 00:53:23.945 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 20: Node Status event - Node is ALIVE 00:53:23.945 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 20: Unsupported command class COMMAND_CLASS_SECURITY_2 00:53:23.946 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 20: Unsupported command class COMMAND_CLASS_TRANSPORT_SERVICE 00:53:23.946 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 20: Unsupported command class COMMAND_CLASS_SUPERVISION 00:53:23.946 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 20: Application update - no transaction. 00:53:23.947 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:23.947 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 00:53:24.198 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: Is awake with 0 messages in the queue 00:53:24.200 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: Start sleep timer at 5000ms 00:53:24.203 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveNodeStatusEvent 00:53:24.206 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 20: Node Status event - Node is AWAKE 00:53:24.206 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'zwave:device:16c934373e7:node20' has been updated. 00:53:26.704 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: WakeupTimerTask 0 Messages waiting, state VERSION 00:53:27.355 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 49 84 14 08 04 07 01 5E 98 9F 55 6C 42 00:53:27.357 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=20, callback=132, payload=84 14 08 04 07 01 5E 98 9F 55 6C 00:53:27.359 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=20, callback=132, payload=84 14 08 04 07 01 5E 98 9F 55 6C 00:53:27.359 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 00:53:27.360 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0 00:53:27.360 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: null 00:53:27.360 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=20, callback=132, payload=84 14 08 04 07 01 5E 98 9F 55 6C 00:53:27.360 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 20: Application update request. Node information received. Transaction null 00:53:27.361 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 20: Unsupported command class COMMAND_CLASS_SECURITY_2 00:53:27.361 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 20: Unsupported command class COMMAND_CLASS_TRANSPORT_SERVICE 00:53:27.361 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 20: Unsupported command class COMMAND_CLASS_SUPERVISION 00:53:27.361 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 20: Application update - no transaction. 00:53:27.362 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:27.362 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 00:53:29.233 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: WakeupTimerTask 0 Messages waiting, state VERSION 00:53:29.235 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: No more messages, go back to sleep 00:53:29.239 [DEBUG] [.commandclass.ZWaveWakeUpCommandClass] - NODE 20: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION 00:53:29.242 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: SECURITY required on COMMAND_CLASS_WAKE_UP 00:53:29.242 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: Command Class COMMAND_CLASS_WAKE_UP is required to be secured 00:53:29.243 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@36878d83 00:53:29.244 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Bump transaction 59 priority from Immediate to Immediate 00:53:29.244 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Adding to device queue 00:53:29.245 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Added 59 to queue - size 2 00:53:29.245 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 00:53:29.246 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 20: isNonceAvailable = null 00:53:29.246 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_GET version 1 00:53:29.247 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 14 02 98 40 25 2A 24 00:53:29.247 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 20: Sending REQUEST Message = 01 09 00 13 14 02 98 40 25 2A 24 00:53:29.248 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 00:53:29.248 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 60: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 42 00:53:29.250 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 00:53:29.250 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:53:29.251 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:53:29.252 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 60: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 42 00:53:29.252 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 00:53:29.253 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:29.253 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:29.293 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 00:53:29.293 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:53:29.294 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:53:29.294 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 60: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 42 00:53:29.295 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 00:53:29.295 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 60: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 42 00:53:29.296 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:53:29.296 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 20: sentData successfully placed on stack. 00:53:29.297 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 60: Advanced to WAIT_REQUEST 00:53:29.297 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: TID 60: Transaction not completed 00:53:29.298 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:29.298 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:29.337 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 2A 00 00 03 C2 00:53:29.337 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=42, payload=2A 00 00 03 00:53:29.339 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=42, payload=2A 00 00 03 00:53:29.339 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 60: [WAIT_REQUEST] priority=High, requiresResponse=true, callback: 42 00:53:29.340 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 00:53:29.341 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 60: [WAIT_REQUEST] priority=High, requiresResponse=true, callback: 42 00:53:29.341 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 60: (Callback 42) 00:53:29.342 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 00:53:29.342 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 60: callback 42 00:53:29.343 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=42, payload=2A 00 00 03 00:53:29.344 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 20: SendData Request. CallBack ID = 42, Status = Transmission complete and ACK received(0) 00:53:29.344 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 60: Advanced to WAIT_DATA 00:53:29.345 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: TID 60: Transaction not completed 00:53:29.346 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:29.346 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:29.381 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 14 0A 98 80 D0 97 42 3A DE 32 11 DF F0 00:53:29.382 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=20, callback=0, payload=00 14 0A 98 80 D0 97 42 3A DE 32 11 DF 00:53:29.383 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=20, callback=0, payload=00 14 0A 98 80 D0 97 42 3A DE 32 11 DF 00:53:29.385 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 00:53:29.386 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Application Command Request (ALIVE:VERSION) 00:53:29.387 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 00:53:29.388 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: SECURITY check internal 00:53:29.389 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 20: Received COMMAND_CLASS_SECURITY V0 SECURITY_NONCE_REPORT 00:53:29.390 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 20: NONCE Received start... 00:53:29.391 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 20: NONCE Received start null 00:53:29.392 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 20: NONCE Received ZWaveNonce [nonceBytes=(D0 97 42 3A DE 32 11 DF ), timer=85628, valid=true] 00:53:29.393 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Commands processed 1. 00:53:29.393 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@7081f8ff. 00:53:29.394 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@7081f8ff. 00:53:29.396 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: notifyTransactionResponse TID:60 DONE 00:53:29.397 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 00:53:29.397 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 00:53:29.398 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 00:53:29.398 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:29.399 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 00:53:29.399 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_MESSAGE_ENCAPSULATION version 1 00:53:29.403 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 20: SECURITY_TXD 84 08 00:53:29.404 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 1D 00 13 14 16 98 81 70 6B 7E D2 D4 C5 91 D7 85 31 2A D0 5B DC 63 7D FF EE 4E 3E 25 2B B2 00:53:29.404 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 20: Sending REQUEST Message = 01 1D 00 13 14 16 98 81 70 6B 7E D2 D4 C5 91 D7 85 31 2A D0 5B DC 63 7D FF EE 4E 3E 25 2B B2 00:53:29.405 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 00:53:29.405 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 59: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 43 00:53:29.437 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 00:53:29.438 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:53:29.438 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:53:29.438 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 59: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 43 00:53:29.439 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 00:53:29.440 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:29.440 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:29.481 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 00:53:29.481 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:53:29.482 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:53:29.482 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 59: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 43 00:53:29.483 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 00:53:29.484 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 59: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 43 00:53:29.484 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:53:29.485 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 20: sentData successfully placed on stack. 00:53:29.485 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 59: Advanced to WAIT_REQUEST 00:53:29.486 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: TID 59: Transaction not completed 00:53:29.486 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:29.486 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:29.525 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 2B 00 00 03 C3 00:53:29.526 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=43, payload=2B 00 00 03 00:53:29.527 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=43, payload=2B 00 00 03 00:53:29.528 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 59: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 43 00:53:29.529 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 00:53:29.529 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 59: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 43 00:53:29.530 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 59: (Callback 43) 00:53:29.531 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 00:53:29.532 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 59: callback 43 00:53:29.533 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=43, payload=2B 00 00 03 00:53:29.534 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 20: SendData Request. CallBack ID = 43, Status = Transmission complete and ACK received(0) 00:53:29.534 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 59: Transaction COMPLETED 00:53:29.535 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Response processed after 130ms 00:53:29.536 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: TID 59: Transaction completed 00:53:29.537 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: notifyTransactionResponse TID:59 DONE 00:53:29.537 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 00:53:29.538 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:29.538 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 00:53:29.539 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 59: Transaction event listener: DONE: DONE -> 00:53:29.540 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: Went to sleep COMPLETE 00:53:34.668 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 49 84 14 08 04 07 01 5E 98 9F 55 6C 42 00:53:34.672 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=20, callback=132, payload=84 14 08 04 07 01 5E 98 9F 55 6C 00:53:34.673 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=20, callback=132, payload=84 14 08 04 07 01 5E 98 9F 55 6C 00:53:34.673 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 00:53:34.673 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0 00:53:34.673 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: null 00:53:34.674 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=20, callback=132, payload=84 14 08 04 07 01 5E 98 9F 55 6C 00:53:34.674 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 20: Application update request. Node information received. Transaction null 00:53:34.675 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 20: Unsupported command class COMMAND_CLASS_SECURITY_2 00:53:34.675 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 20: Unsupported command class COMMAND_CLASS_TRANSPORT_SERVICE 00:53:34.675 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 20: Unsupported command class COMMAND_CLASS_SUPERVISION 00:53:34.675 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 20: Application update - no transaction. 00:53:34.675 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:34.676 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 00:53:34.926 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: Is awake with 0 messages in the queue 00:53:34.928 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: Start sleep timer at 5000ms 00:53:34.930 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveNodeStatusEvent 00:53:34.937 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 20: Node Status event - Node is AWAKE 00:53:34.942 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'zwave:device:16c934373e7:node20' has been updated. 00:53:37.430 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: WakeupTimerTask 0 Messages waiting, state VERSION 00:53:39.960 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: WakeupTimerTask 0 Messages waiting, state VERSION 00:53:39.961 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: No more messages, go back to sleep 00:53:39.963 [DEBUG] [.commandclass.ZWaveWakeUpCommandClass] - NODE 20: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION 00:53:39.965 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: SECURITY required on COMMAND_CLASS_WAKE_UP 00:53:39.967 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: Command Class COMMAND_CLASS_WAKE_UP is required to be secured 00:53:39.968 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@99ceaaa 00:53:39.970 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Bump transaction 61 priority from Immediate to Immediate 00:53:39.972 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Adding to device queue 00:53:39.973 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Added 61 to queue - size 2 00:53:39.974 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 00:53:39.975 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 20: isNonceAvailable = null 00:53:39.976 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_GET version 1 00:53:39.978 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 14 02 98 40 25 2C 22 00:53:39.979 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 20: Sending REQUEST Message = 01 09 00 13 14 02 98 40 25 2C 22 00:53:39.980 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 00:53:39.981 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 62: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 44 00:53:39.985 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 00:53:39.986 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:53:39.987 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:53:39.987 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 62: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 44 00:53:39.988 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 00:53:39.988 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:39.988 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:40.028 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 00:53:40.028 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:53:40.029 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:53:40.029 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 62: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 44 00:53:40.029 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 00:53:40.029 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 62: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 44 00:53:40.029 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:53:40.030 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 20: sentData successfully placed on stack. 00:53:40.030 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 62: Advanced to WAIT_REQUEST 00:53:40.030 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: TID 62: Transaction not completed 00:53:40.030 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:40.031 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:45.061 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 20: TID 62: Timeout at state WAIT_REQUEST. 3 retries remaining. 00:53:45.063 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - Aborting Transaction! 00:53:45.067 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 62: Transaction ABORTED 00:53:45.070 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 00:53:45.073 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 00:53:45.074 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 00:53:45.076 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:45.078 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 00:53:45.078 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:53:45.079 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:53:45.080 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 62: [ABORTED] priority=High, requiresResponse=true, callback: 44 00:53:45.080 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 00:53:45.080 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:45.081 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:45.395 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 2C 01 02 1C D8 00:53:45.399 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=44, payload=2C 01 02 1C 00:53:45.402 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=44, payload=2C 01 02 1C 00:53:45.404 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 62: [ABORTED] priority=High, requiresResponse=true, callback: 44 00:53:45.405 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 00:53:45.406 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 62: [ABORTED] priority=High, requiresResponse=true, callback: 44 00:53:45.407 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 62: (Callback 44) 00:53:45.408 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 00:53:45.408 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 62: callback 44 00:53:45.410 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=44, payload=2C 01 02 1C 00:53:45.411 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 20: SendData Request. CallBack ID = 44, Status = Transmission complete, no ACK received(1) 00:53:45.412 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 62: Transaction CANCELLED 00:53:45.412 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 00:53:45.413 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: CANCEL while sending message. Requeueing - 2 attempts left! 00:53:45.414 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 62: Transaction RESET with 2 retries remaining. 00:53:45.414 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Adding to device queue 00:53:45.415 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Added 62 to queue - size 2 00:53:45.416 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 00:53:45.417 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 14 02 98 40 25 2D 23 00:53:45.418 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 20: Sending REQUEST Message = 01 09 00 13 14 02 98 40 25 2D 23 00:53:45.418 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 00:53:45.419 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 62: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 45 00:53:45.419 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: TID 62: Transaction not completed 00:53:45.420 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:45.420 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:45.450 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 00:53:45.450 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:53:45.451 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:53:45.452 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 62: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 45 00:53:45.452 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 00:53:45.453 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:45.453 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:45.493 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 00:53:45.493 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:53:45.494 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:53:45.494 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 62: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 45 00:53:45.495 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 00:53:45.495 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 62: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 45 00:53:45.495 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:53:45.496 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 20: sentData successfully placed on stack. 00:53:45.497 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 62: Advanced to WAIT_REQUEST 00:53:45.498 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: TID 62: Transaction not completed 00:53:45.499 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:45.500 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:50.542 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 20: TID 62: Timeout at state WAIT_REQUEST. 2 retries remaining. 00:53:50.544 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - Aborting Transaction! 00:53:50.546 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 62: Transaction ABORTED 00:53:50.547 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 00:53:50.547 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 00:53:50.548 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 00:53:50.549 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:50.549 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 00:53:50.550 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:53:50.550 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:53:50.550 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 62: [ABORTED] priority=High, requiresResponse=true, callback: 45 00:53:50.550 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 00:53:50.551 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:50.551 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:50.602 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 2D 01 02 03 C6 00:53:50.602 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=45, payload=2D 01 02 03 00:53:50.604 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=45, payload=2D 01 02 03 00:53:50.604 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 62: [ABORTED] priority=High, requiresResponse=true, callback: 45 00:53:50.605 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 00:53:50.606 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 62: [ABORTED] priority=High, requiresResponse=true, callback: 45 00:53:50.606 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 62: (Callback 45) 00:53:50.607 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 00:53:50.607 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 62: callback 45 00:53:50.607 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=45, payload=2D 01 02 03 00:53:50.608 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 20: SendData Request. CallBack ID = 45, Status = Transmission complete, no ACK received(1) 00:53:50.608 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 62: Transaction CANCELLED 00:53:50.609 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 00:53:50.609 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: CANCEL while sending message. Requeueing - 1 attempts left! 00:53:50.609 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 62: Transaction RESET with 1 retries remaining. 00:53:50.610 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Adding to device queue 00:53:50.610 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Added 62 to queue - size 2 00:53:50.610 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 00:53:50.611 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 14 02 98 40 25 2E 20 00:53:50.611 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 20: Sending REQUEST Message = 01 09 00 13 14 02 98 40 25 2E 20 00:53:50.611 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 00:53:50.612 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 62: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 46 00:53:50.612 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: TID 62: Transaction not completed 00:53:50.612 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:50.613 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:50.655 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 00:53:50.655 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:53:50.656 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:53:50.656 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 62: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 46 00:53:50.657 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 00:53:50.657 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:50.657 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:50.699 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 00:53:50.700 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:53:50.701 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:53:50.703 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 62: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 46 00:53:50.703 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 00:53:50.704 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 62: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 46 00:53:50.705 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:53:50.706 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 20: sentData successfully placed on stack. 00:53:50.707 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 62: Advanced to WAIT_REQUEST 00:53:50.708 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: TID 62: Transaction not completed 00:53:50.709 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:50.710 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:55.741 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 20: TID 62: Timeout at state WAIT_REQUEST. 1 retries remaining. 00:53:55.744 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - Aborting Transaction! 00:53:55.747 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 62: Transaction ABORTED 00:53:55.751 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 00:53:55.753 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 00:53:55.753 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 00:53:55.754 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:55.754 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 00:53:55.755 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:53:55.755 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:53:55.755 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 62: [ABORTED] priority=High, requiresResponse=true, callback: 46 00:53:55.756 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 00:53:55.756 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:55.756 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:53:55.807 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 2E 01 02 03 C5 00:53:55.808 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=46, payload=2E 01 02 03 00:53:55.808 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=46, payload=2E 01 02 03 00:53:55.809 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 62: [ABORTED] priority=High, requiresResponse=true, callback: 46 00:53:55.809 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 00:53:55.809 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 62: [ABORTED] priority=High, requiresResponse=true, callback: 46 00:53:55.809 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 62: (Callback 46) 00:53:55.810 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 00:53:55.810 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 62: callback 46 00:53:55.811 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=46, payload=2E 01 02 03 00:53:55.811 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 20: SendData Request. CallBack ID = 46, Status = Transmission complete, no ACK received(1) 00:53:55.812 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 62: Transaction CANCELLED 00:53:55.812 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 00:53:55.813 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Retry count exceeded. Discarding message: TID 62: [CANCELLED] priority=High, requiresResponse=true, callback: 46 00:53:55.813 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveNodeStatusEvent 00:53:55.814 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Setting OFFLINE 00:53:55.816 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 20: Node Status event - Node is DEAD 00:53:55.816 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zwave:device:16c934373e7:node20' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller 00:53:55.819 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: Node is DEAD. 00:53:55.820 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveNodeStatusEvent 00:53:55.820 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Setting OFFLINE 00:53:55.824 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 20: Node Status event - Node is DEAD 00:53:55.825 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: TID 62: Transaction completed 00:53:55.825 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: notifyTransactionResponse TID:62 CANCELLED 00:53:55.826 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: processing secure transaction -- TID:61 00:53:55.827 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 61: Transaction event listener: DONE: UNINTIALIZED -> 00:53:55.827 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Completing UNINTIALIZED transaction 61!!! How?!? 00:53:55.827 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 00:53:55.827 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:53:55.827 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 00:53:55.828 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: Went to sleep CANCELLED 00:54:03.057 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 49 84 14 08 04 07 01 5E 98 9F 55 6C 42 00:54:03.058 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=20, callback=132, payload=84 14 08 04 07 01 5E 98 9F 55 6C 00:54:03.059 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=20, callback=132, payload=84 14 08 04 07 01 5E 98 9F 55 6C 00:54:03.060 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 00:54:03.060 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0 00:54:03.060 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: null 00:54:03.060 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=20, callback=132, payload=84 14 08 04 07 01 5E 98 9F 55 6C 00:54:03.061 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 20: Application update request. Node information received. Transaction null 00:54:03.061 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveNodeStatusEvent 00:54:03.061 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Setting ONLINE 00:54:03.062 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 20: Node Status event - Node is ALIVE 00:54:03.062 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: Node is ALIVE. Init stage is VERSION. 00:54:03.062 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zwave:device:16c934373e7:node20' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE 00:54:03.062 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveNodeStatusEvent 00:54:03.063 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Setting ONLINE 00:54:03.063 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 20: Node Status event - Node is ALIVE 00:54:03.064 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 20: Unsupported command class COMMAND_CLASS_SECURITY_2 00:54:03.064 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 20: Unsupported command class COMMAND_CLASS_TRANSPORT_SERVICE 00:54:03.064 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 20: Unsupported command class COMMAND_CLASS_SUPERVISION 00:54:03.065 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 20: Application update - no transaction. 00:54:03.065 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:54:03.065 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 00:54:03.317 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: Is awake with 0 messages in the queue 00:54:03.320 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: Start sleep timer at 5000ms 00:54:03.322 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveNodeStatusEvent 00:54:03.325 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 20: Node Status event - Node is AWAKE 00:54:03.326 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'zwave:device:16c934373e7:node20' has been updated. 00:54:05.823 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: WakeupTimerTask 0 Messages waiting, state VERSION 00:54:08.368 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: WakeupTimerTask 0 Messages waiting, state VERSION 00:54:08.372 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: No more messages, go back to sleep 00:54:08.373 [DEBUG] [.commandclass.ZWaveWakeUpCommandClass] - NODE 20: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION 00:54:08.373 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: SECURITY required on COMMAND_CLASS_WAKE_UP 00:54:08.374 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: Command Class COMMAND_CLASS_WAKE_UP is required to be secured 00:54:08.375 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@27e27a5d 00:54:08.376 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Bump transaction 63 priority from Immediate to Immediate 00:54:08.376 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Adding to device queue 00:54:08.376 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Added 63 to queue - size 2 00:54:08.377 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 00:54:08.377 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 20: isNonceAvailable = null 00:54:08.377 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_GET version 1 00:54:08.378 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 14 02 98 40 25 2F 21 00:54:08.378 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 20: Sending REQUEST Message = 01 09 00 13 14 02 98 40 25 2F 21 00:54:08.378 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 00:54:08.379 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 64: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 47 00:54:08.381 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 00:54:08.381 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:54:08.382 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:54:08.382 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 64: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 47 00:54:08.383 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 00:54:08.383 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:54:08.383 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:54:08.423 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 00:54:08.424 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:54:08.424 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:54:08.425 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 64: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 47 00:54:08.425 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 00:54:08.425 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 64: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 47 00:54:08.425 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:54:08.425 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 20: sentData successfully placed on stack. 00:54:08.426 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 64: Advanced to WAIT_REQUEST 00:54:08.426 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: TID 64: Transaction not completed 00:54:08.426 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:54:08.426 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:54:11.090 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 49 84 14 08 04 07 01 5E 98 9F 55 6C 42 00:54:11.091 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=20, callback=132, payload=84 14 08 04 07 01 5E 98 9F 55 6C 00:54:11.092 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=20, callback=132, payload=84 14 08 04 07 01 5E 98 9F 55 6C 00:54:11.092 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 64: [WAIT_REQUEST] priority=High, requiresResponse=true, callback: 47 00:54:11.093 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 00:54:11.093 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 64: [WAIT_REQUEST] priority=High, requiresResponse=true, callback: 47 00:54:11.093 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 64: (Callback 47) 00:54:11.094 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=20, callback=132, payload=84 14 08 04 07 01 5E 98 9F 55 6C 00:54:11.094 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 20: Application update request. Node information received. Transaction null 00:54:11.095 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 20: Unsupported command class COMMAND_CLASS_SECURITY_2 00:54:11.095 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 20: Unsupported command class COMMAND_CLASS_TRANSPORT_SERVICE 00:54:11.095 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 20: Unsupported command class COMMAND_CLASS_SUPERVISION 00:54:11.104 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 20: Application update - no transaction. 00:54:11.104 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:54:11.105 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:54:13.457 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 20: TID 64: Timeout at state WAIT_REQUEST. 3 retries remaining. 00:54:13.459 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - Aborting Transaction! 00:54:13.464 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 64: Transaction ABORTED 00:54:13.464 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 00:54:13.465 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 00:54:13.465 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 00:54:13.466 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:54:13.466 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 00:54:13.467 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:54:13.467 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:54:13.468 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 64: [ABORTED] priority=High, requiresResponse=true, callback: 47 00:54:13.468 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 00:54:13.468 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:54:13.468 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:54:13.554 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 2F 01 02 05 C2 00:54:13.558 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=47, payload=2F 01 02 05 00:54:13.562 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=47, payload=2F 01 02 05 00:54:13.564 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 64: [ABORTED] priority=High, requiresResponse=true, callback: 47 00:54:13.566 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 00:54:13.568 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 64: [ABORTED] priority=High, requiresResponse=true, callback: 47 00:54:13.569 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 64: (Callback 47) 00:54:13.570 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 00:54:13.571 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 64: callback 47 00:54:13.572 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=47, payload=2F 01 02 05 00:54:13.573 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 20: SendData Request. CallBack ID = 47, Status = Transmission complete, no ACK received(1) 00:54:13.573 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 64: Transaction CANCELLED 00:54:13.574 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 00:54:13.575 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: CANCEL while sending message. Requeueing - 2 attempts left! 00:54:13.576 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 64: Transaction RESET with 2 retries remaining. 00:54:13.576 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Adding to device queue 00:54:13.577 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Added 64 to queue - size 2 00:54:13.577 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 00:54:13.578 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 14 02 98 40 25 30 3E 00:54:13.578 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 20: Sending REQUEST Message = 01 09 00 13 14 02 98 40 25 30 3E 00:54:13.579 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 00:54:13.580 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 64: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 48 00:54:13.580 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: TID 64: Transaction not completed 00:54:13.581 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:54:13.581 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:54:13.609 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 00:54:13.610 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:54:13.610 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:54:13.610 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 64: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 48 00:54:13.611 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 00:54:13.611 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:54:13.611 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:54:13.653 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 00:54:13.653 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:54:13.654 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:54:13.655 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 64: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 48 00:54:13.655 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 00:54:13.655 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 64: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 48 00:54:13.656 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:54:13.656 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 20: sentData successfully placed on stack. 00:54:13.656 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 64: Advanced to WAIT_REQUEST 00:54:13.657 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: TID 64: Transaction not completed 00:54:13.657 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:54:13.657 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:54:18.687 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 20: TID 64: Timeout at state WAIT_REQUEST. 2 retries remaining. 00:54:18.689 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - Aborting Transaction! 00:54:18.692 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 64: Transaction ABORTED 00:54:18.694 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 00:54:18.698 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 00:54:18.700 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 00:54:18.700 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:54:18.700 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 00:54:18.701 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:54:18.701 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:54:18.702 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 64: [ABORTED] priority=High, requiresResponse=true, callback: 48 00:54:18.702 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 00:54:18.702 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:54:18.702 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:54:18.783 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 30 01 02 05 DD 00:54:18.787 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=48, payload=30 01 02 05 00:54:18.789 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=48, payload=30 01 02 05 00:54:18.791 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 64: [ABORTED] priority=High, requiresResponse=true, callback: 48 00:54:18.792 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 00:54:18.794 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 64: [ABORTED] priority=High, requiresResponse=true, callback: 48 00:54:18.796 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 64: (Callback 48) 00:54:18.798 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 00:54:18.799 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 64: callback 48 00:54:18.801 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=48, payload=30 01 02 05 00:54:18.802 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 20: SendData Request. CallBack ID = 48, Status = Transmission complete, no ACK received(1) 00:54:18.803 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 64: Transaction CANCELLED 00:54:18.804 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 00:54:18.805 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: CANCEL while sending message. Requeueing - 1 attempts left! 00:54:18.805 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 64: Transaction RESET with 1 retries remaining. 00:54:18.806 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Adding to device queue 00:54:18.806 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Added 64 to queue - size 2 00:54:18.807 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 00:54:18.807 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 14 02 98 40 25 31 3F 00:54:18.808 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 20: Sending REQUEST Message = 01 09 00 13 14 02 98 40 25 31 3F 00:54:18.808 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 00:54:18.809 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 64: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 49 00:54:18.809 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: TID 64: Transaction not completed 00:54:18.810 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:54:18.810 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:54:18.832 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 00:54:18.832 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:54:18.833 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:54:18.834 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 64: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 49 00:54:18.834 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 00:54:18.835 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:54:18.835 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:54:18.874 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 00:54:18.875 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:54:18.875 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:54:18.877 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 64: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 49 00:54:18.878 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 00:54:18.878 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 64: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 49 00:54:18.878 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 00:54:18.879 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 20: sentData successfully placed on stack. 00:54:18.879 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 64: Advanced to WAIT_REQUEST 00:54:18.879 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: TID 64: Transaction not completed 00:54:18.880 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:54:18.880 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:54:23.909 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 20: TID 64: Timeout at state WAIT_REQUEST. 1 retries remaining. 00:54:23.913 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - Aborting Transaction! 00:54:23.915 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 64: Transaction ABORTED 00:54:23.915 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 00:54:23.916 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 00:54:23.916 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 00:54:23.916 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:54:23.917 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 00:54:23.918 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:54:23.918 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 00:54:23.919 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 64: [ABORTED] priority=High, requiresResponse=true, callback: 49 00:54:23.919 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 00:54:23.919 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:54:23.920 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 00:54:24.005 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 31 01 02 05 DC 00:54:24.008 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=49, payload=31 01 02 05 00:54:24.010 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=49, payload=31 01 02 05 00:54:24.012 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 64: [ABORTED] priority=High, requiresResponse=true, callback: 49 00:54:24.014 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 00:54:24.016 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 64: [ABORTED] priority=High, requiresResponse=true, callback: 49 00:54:24.017 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 64: (Callback 49) 00:54:24.018 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 00:54:24.018 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 64: callback 49 00:54:24.020 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=49, payload=31 01 02 05 00:54:24.021 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 20: SendData Request. CallBack ID = 49, Status = Transmission complete, no ACK received(1) 00:54:24.022 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 64: Transaction CANCELLED 00:54:24.023 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 00:54:24.024 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: Retry count exceeded. Discarding message: TID 64: [CANCELLED] priority=High, requiresResponse=true, callback: 49 00:54:24.024 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveNodeStatusEvent 00:54:24.025 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Setting OFFLINE 00:54:24.030 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zwave:device:16c934373e7:node20' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller 00:54:24.029 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 20: Node Status event - Node is DEAD 00:54:24.034 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: Node is DEAD. 00:54:24.034 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveNodeStatusEvent 00:54:24.034 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Setting OFFLINE 00:54:24.035 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 20: Node Status event - Node is DEAD 00:54:24.038 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: TID 64: Transaction completed 00:54:24.042 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: notifyTransactionResponse TID:64 CANCELLED 00:54:24.043 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 20: processing secure transaction -- TID:63 00:54:24.044 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 63: Transaction event listener: DONE: UNINTIALIZED -> 00:54:24.044 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Completing UNINTIALIZED transaction 63!!! How?!? 00:54:24.044 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 20: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 00:54:24.044 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 00:54:24.044 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 00:54:24.045 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 20: Went to sleep CANCELLED