2019-05-11 18:20:09.308 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2019-05-11 18:20:09.314 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-05-11 18:20:09.317 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-05-11 18:20:09.320 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2595: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 160

2019-05-11 18:20:09.322 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2019-05-11 18:20:09.322 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 13 A0 00 00 01 00 B8 7F 7F 7F 7F 00 00 03 00 00 00 00 03 01 00 00 EC 

2019-05-11 18:20:09.325 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 2595: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 160

2019-05-11 18:20:09.327 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-05-11 18:20:09.330 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 4: sentData successfully placed on stack.

2019-05-11 18:20:09.333 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 2595: Advanced to WAIT_REQUEST

2019-05-11 18:20:09.335 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 2595: Transaction not completed

2019-05-11 18:20:09.338 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-05-11 18:20:09.340 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2019-05-11 18:20:09.356 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=160, payload=A0 00 00 01 00 B8 7F 7F 7F 7F 00 00 03 00 00 00 00 03 01 00 00 

2019-05-11 18:20:09.362 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=160, payload=A0 00 00 01 00 B8 7F 7F 7F 7F 00 00 03 00 00 00 00 03 01 00 00 

2019-05-11 18:20:09.364 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2595: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 160

2019-05-11 18:20:09.366 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2019-05-11 18:20:09.368 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 2595: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 160

2019-05-11 18:20:09.371 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 2595: (Callback 160)

2019-05-11 18:20:09.373 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!

2019-05-11 18:20:09.376 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 2595: callback 160

2019-05-11 18:20:09.380 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=160, payload=A0 00 00 01 00 B8 7F 7F 7F 7F 00 00 03 00 00 00 00 03 01 00 00 

2019-05-11 18:20:09.383 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 4: SendData Request. CallBack ID = 160, Status = Transmission complete and ACK received(0)

2019-05-11 18:20:09.385 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 2595: Transaction COMPLETED

2019-05-11 18:20:09.388 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Response processed after 101ms

2019-05-11 18:20:09.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 2595: Transaction completed

2019-05-11 18:20:09.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: notifyTransactionResponse TID:2595 DONE

2019-05-11 18:20:09.396 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-05-11 18:20:09.398 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2019-05-11 18:20:09.400 [DEBUG] [andclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_MESSAGE_ENCAPSULATION version 1

2019-05-11 18:20:09.405 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 4: SECURITY_TXD 98 02 

2019-05-11 18:20:09.412 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 1D 00 13 04 16 98 81 90 C3 C5 93 24 ED 33 E6 C9 88 90 17 33 0D 44 B7 EE AC 26 AA 25 A1 A2 

2019-05-11 18:20:09.407 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 2595: Transaction event listener: DONE: DONE -> 

2019-05-11 18:20:09.418 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: Went to sleep COMPLETE

2019-05-11 18:20:09.429 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 4: Sending REQUEST Message = 01 1D 00 13 04 16 98 81 90 C3 C5 93 24 ED 33 E6 C9 88 90 17 33 0D 44 B7 EE AC 26 AA 25 A1 A2 

2019-05-11 18:20:09.435 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06

2019-05-11 18:20:09.437 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2019-05-11 18:20:09.441 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 

2019-05-11 18:20:09.454 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2019-05-11 18:20:09.456 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 2596: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 161

2019-05-11 18:20:09.459 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2019-05-11 18:20:09.461 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2596: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 161

2019-05-11 18:20:09.463 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK

2019-05-11 18:20:09.465 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-05-11 18:20:09.468 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2019-05-11 18:20:09.504 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-05-11 18:20:09.507 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-05-11 18:20:09.509 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2596: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 161

2019-05-11 18:20:09.511 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 13 A1 00 00 02 00 B8 7F 7F 7F 7F 00 00 03 00 00 00 00 03 01 00 00 EE 

2019-05-11 18:20:09.512 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2019-05-11 18:20:09.514 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 2596: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 161

2019-05-11 18:20:09.516 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-05-11 18:20:09.519 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 4: sentData successfully placed on stack.

2019-05-11 18:20:09.521 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 2596: Advanced to WAIT_REQUEST

2019-05-11 18:20:09.524 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 2596: Transaction not completed

2019-05-11 18:20:09.526 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-05-11 18:20:09.529 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2019-05-11 18:20:09.546 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=161, payload=A1 00 00 02 00 B8 7F 7F 7F 7F 00 00 03 00 00 00 00 03 01 00 00 

2019-05-11 18:20:09.551 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=161, payload=A1 00 00 02 00 B8 7F 7F 7F 7F 00 00 03 00 00 00 00 03 01 00 00 

2019-05-11 18:20:09.552 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2596: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 161

2019-05-11 18:20:09.554 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2019-05-11 18:20:09.557 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 2596: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 161

2019-05-11 18:20:09.559 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 2596: (Callback 161)

2019-05-11 18:20:09.562 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!

2019-05-11 18:20:09.564 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 2596: callback 161

2019-05-11 18:20:09.575 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=161, payload=A1 00 00 02 00 B8 7F 7F 7F 7F 00 00 03 00 00 00 00 03 01 00 00 

2019-05-11 18:20:09.578 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 4: SendData Request. CallBack ID = 161, Status = Transmission complete and ACK received(0)

2019-05-11 18:20:09.580 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 2596: Advanced to WAIT_DATA

2019-05-11 18:20:09.582 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 2596: Transaction not completed

2019-05-11 18:20:09.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-05-11 18:20:09.586 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2019-05-11 18:20:09.614 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0A 00 04 00 04 02 98 40 B8 00 97 

2019-05-11 18:20:09.645 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=4, callback=0, payload=00 04 02 98 40 B8 00 

2019-05-11 18:20:09.647 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=4, callback=0, payload=00 04 02 98 40 B8 00 

2019-05-11 18:20:09.649 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2019-05-11 18:20:09.651 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Application Command Request (ALIVE:SECURITY_REPORT)

2019-05-11 18:20:09.654 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0

2019-05-11 18:20:09.664 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: SECURITY check internal

2019-05-11 18:20:09.667 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 4: Received COMMAND_CLASS_SECURITY V0 SECURITY_NONCE_GET

2019-05-11 18:20:09.669 [DEBUG] [andclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_REPORT version 1

2019-05-11 18:20:09.671 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Added to secure queue - size 1

2019-05-11 18:20:09.674 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Commands processed 1.

2019-05-11 18:20:09.676 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@102b5b2.

2019-05-11 18:20:09.678 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Command NOT verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@102b5b2.

2019-05-11 18:20:09.680 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1

2019-05-11 18:20:09.682 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1

2019-05-11 18:20:09.685 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-05-11 18:20:09.687 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2019-05-11 18:20:09.689 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 04 0A 98 80 B4 3F 17 E9 E2 20 07 41 25 A2 9D 

2019-05-11 18:20:09.692 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 4: Sending REQUEST Message = 01 11 00 13 04 0A 98 80 B4 3F 17 E9 E2 20 07 41 25 A2 9D 

2019-05-11 18:20:09.698 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06

2019-05-11 18:20:09.700 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2019-05-11 18:20:09.703 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 

2019-05-11 18:20:09.724 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2019-05-11 18:20:09.726 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 2597: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 162

2019-05-11 18:20:09.729 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2019-05-11 18:20:09.731 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2597: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 162

2019-05-11 18:20:09.732 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK

2019-05-11 18:20:09.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-05-11 18:20:09.735 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 2 out at start. Holdoff false.

2019-05-11 18:20:09.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-05-11 18:20:09.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-05-11 18:20:09.759 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2597: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 162

2019-05-11 18:20:09.760 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 2

2019-05-11 18:20:09.762 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 13 A2 00 00 02 00 B8 7F 7F 7F 7F 00 00 03 00 00 00 00 03 01 00 00 ED 

2019-05-11 18:20:09.762 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 2597: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 162

2019-05-11 18:20:09.767 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-05-11 18:20:09.770 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 4: sentData successfully placed on stack.

2019-05-11 18:20:09.772 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 2597: Advanced to WAIT_REQUEST

2019-05-11 18:20:09.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 2597: Transaction not completed

2019-05-11 18:20:09.777 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-05-11 18:20:09.779 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 2 out at start. Holdoff false.

2019-05-11 18:20:09.795 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=162, payload=A2 00 00 02 00 B8 7F 7F 7F 7F 00 00 03 00 00 00 00 03 01 00 00 

2019-05-11 18:20:09.798 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=162, payload=A2 00 00 02 00 B8 7F 7F 7F 7F 00 00 03 00 00 00 00 03 01 00 00 

2019-05-11 18:20:09.801 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2597: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 162

2019-05-11 18:20:09.803 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 2

2019-05-11 18:20:09.805 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 2597: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 162

2019-05-11 18:20:09.808 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 2596: (Callback 161)

2019-05-11 18:20:09.810 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - NO callback match! (161 <> 162)

2019-05-11 18:20:09.812 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 2597: (Callback 162)

2019-05-11 18:20:09.815 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!

2019-05-11 18:20:09.817 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 2597: callback 162

2019-05-11 18:20:09.820 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=162, payload=A2 00 00 02 00 B8 7F 7F 7F 7F 00 00 03 00 00 00 00 03 01 00 00 

2019-05-11 18:20:09.823 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 4: SendData Request. CallBack ID = 162, Status = Transmission complete and ACK received(0)

2019-05-11 18:20:09.825 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 2597: Transaction COMPLETED

2019-05-11 18:20:09.828 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Response processed after 102ms

2019-05-11 18:20:09.830 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 2597: Transaction completed

2019-05-11 18:20:09.832 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: notifyTransactionResponse TID:2597 DONE

2019-05-11 18:20:09.835 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-05-11 18:20:09.838 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2019-05-11 18:20:09.877 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 30 00 04 00 04 28 98 81 86 84 A7 68 4C B6 F4 55 DD C7 28 5E 65 28 2C DE 4F A0 CB D2 A4 15 7B CB 77 67 DC 7D E3 B4 0D 74 CD C3 A1 15 E1 72 B8 00 42 

2019-05-11 18:20:09.906 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=4, callback=0, payload=00 04 28 98 81 86 84 A7 68 4C B6 F4 55 DD C7 28 5E 65 28 2C DE 4F A0 CB D2 A4 15 7B CB 77 67 DC 7D E3 B4 0D 74 CD C3 A1 15 E1 72 B8 00 

2019-05-11 18:20:09.910 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=4, callback=0, payload=00 04 28 98 81 86 84 A7 68 4C B6 F4 55 DD C7 28 5E 65 28 2C DE 4F A0 CB D2 A4 15 7B CB 77 67 DC 7D E3 B4 0D 74 CD C3 A1 15 E1 72 B8 00 

2019-05-11 18:20:09.912 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2019-05-11 18:20:09.914 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Application Command Request (ALIVE:SECURITY_REPORT)

2019-05-11 18:20:09.917 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: Decapsulating COMMAND_CLASS_SECURITY

2019-05-11 18:20:09.922 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 4: SECURITY_RXD 98 03 00 86 85 59 8E 60 72 5A 84 5B 71 70 80 7A EF 25 26 EF 

2019-05-11 18:20:09.924 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0

2019-05-11 18:20:09.927 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 4: Received COMMAND_CLASS_SECURITY V0 SECURITY_COMMANDS_SUPPORTED_REPORT

2019-05-11 18:20:09.929 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Commands processed 1.

2019-05-11 18:20:09.932 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@126fc05.

2019-05-11 18:20:09.934 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@126fc05.

2019-05-11 18:20:09.936 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: notifyTransactionResponse TID:2596 DONE

2019-05-11 18:20:09.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1

2019-05-11 18:20:09.941 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0

2019-05-11 18:20:09.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-05-11 18:20:09.946 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2019-05-11 18:20:09.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 2596: Transaction event listener: DONE: DONE -> 

2019-05-11 18:20:09.955 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 4: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@15d7ab3

2019-05-11 18:20:09.957 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 4: Node Init transaction completed with response COMPLETE

2019-05-11 18:20:09.960 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 4: Node advancer - advancing to MANUFACTURER

2019-05-11 18:20:09.962 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 4: Node advancer: MANUFACTURER - send ManufacturerSpecific

2019-05-11 18:20:09.965 [DEBUG] [WaveManufacturerSpecificCommandClass] - NODE 4: Creating new message for command MANUFACTURER_SPECIFIC_GET

2019-05-11 18:20:09.967 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 4: ZWaveCommandClassTransactionPayload - send to node

2019-05-11 18:20:09.970 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: SECURITY required on COMMAND_CLASS_MANUFACTURER_SPECIFIC

2019-05-11 18:20:09.972 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: Command Class COMMAND_CLASS_MANUFACTURER_SPECIFIC is required to be secured

2019-05-11 18:20:09.975 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@11c1602

2019-05-11 18:20:09.977 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Bump transaction 2598 priority from Config to Immediate

2019-05-11 18:20:09.979 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Adding to device queue

2019-05-11 18:20:09.980 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Added 2598 to queue - size 1

2019-05-11 18:20:09.982 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2019-05-11 18:20:25.358 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:16aa3413767

2019-05-11 18:20:25.362 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do

2019-05-11 18:21:29.059 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave inclusion controller finalised

2019-05-11 18:21:29.164 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave inclusion controller finalised

==> /var/log/openhab2/events.log <==

2019-05-11 18:21:33.367 [me.event.InboxRemovedEvent] - Discovery Result with UID 'zwave:device:16aa3413767:node4' has been removed.

==> /var/log/openhab2/openhab.log <==

2019-05-11 18:21:33.434 [DEBUG] [org.openhab.binding.zwave           ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=645, service.bundleid=263, service.scope=singleton} - org.openhab.binding.zwave

==> /var/log/openhab2/events.log <==

2019-05-11 18:21:33.529 [hingStatusInfoChangedEvent] - 'zwave:device:16aa3413767:node4' changed from UNINITIALIZED to INITIALIZING

==> /var/log/openhab2/openhab.log <==

2019-05-11 18:21:33.532 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:16aa3413767:node4.

==> /var/log/openhab2/events.log <==

2019-05-11 18:21:33.560 [hingStatusInfoChangedEvent] - 'zwave:device:16aa3413767:node4' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2019-05-11 18:21:33.623 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: MANUFACTURER not set

2019-05-11 18:21:33.625 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Controller status changed to ONLINE.

2019-05-11 18:21:33.628 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Controller is ONLINE. Starting device initialisation.

==> /var/log/openhab2/events.log <==

2019-05-11 18:21:33.637 [hingStatusInfoChangedEvent] - 'zwave:device:16aa3413767:node4' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

==> /var/log/openhab2/openhab.log <==

2019-05-11 18:21:33.690 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Updating node properties.

==> /var/log/openhab2/events.log <==

2019-05-11 18:21:33.692 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:16aa3413767:node4' has been updated.

==> /var/log/openhab2/openhab.log <==

2019-05-11 18:21:33.724 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Updating node properties. MAN=2147483647

2019-05-11 18:21:33.726 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Properties synchronised

2019-05-11 18:21:33.796 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Configuration synchronised

==> /var/log/openhab2/events.log <==

2019-05-11 18:21:33.799 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:16aa3413767:node4' has been updated.

2019-05-11 18:21:33.858 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:16aa3413767:node4' has been updated.

==> /var/log/openhab2/openhab.log <==

2019-05-11 18:21:33.864 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.

2019-05-11 18:21:33.867 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Initialising Thing Node...

==> /var/log/openhab2/events.log <==

2019-05-11 18:21:33.877 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]]

==> /var/log/openhab2/openhab.log <==

2019-05-11 18:21:33.899 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Polling intialised at 1800 seconds - start in 572400 milliseconds.

2019-05-11 18:21:33.901 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Device initialisation complete.

2019-05-11 18:22:11.004 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@16098ff

2019-05-11 18:22:11.055 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Bump transaction 1860 priority from Controller to Immediate

2019-05-11 18:22:11.058 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Adding to device queue

2019-05-11 18:22:11.061 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Added 1860 to queue - size 15

2019-05-11 18:22:11.063 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2019-05-11 18:22:11.088 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 60 0E 95 

2019-05-11 18:22:11.091 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Port closed sending REQUEST Message = 01 04 00 60 0E 95 

2019-05-11 18:22:11.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1860: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 0

2019-05-11 18:22:13.115 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 14: TID 1860: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2019-05-11 18:22:13.120 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 1860: Transaction is current transaction, so clearing!!!!!

2019-05-11 18:22:13.123 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1860: Transaction CANCELLED

2019-05-11 18:22:13.127 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: notifyTransactionResponse TID:1860 CANCELLED

2019-05-11 18:22:13.144 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2019-05-11 18:22:13.144 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 1860: Transaction event listener: DONE: CANCELLED -> 

2019-05-11 18:22:13.148 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 14: Node Init response (3) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@e85d54