2019-05-31 23:17:37.902 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007 2019-05-31 23:17:37.955 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-misc-restdocs' 2019-05-31 23:18:36.501 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007 2019-05-31 23:18:36.551 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-misc-restdocs' 2019-05-31 23:19:34.438 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007 2019-05-31 23:19:34.484 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-misc-restdocs' 2019-05-31 23:20:34.465 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007 2019-05-31 23:20:34.506 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-misc-restdocs' 2019-05-31 23:21:32.802 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007 2019-05-31 23:21:32.843 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-misc-restdocs' 2019-05-31 23:22:35.570 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007 2019-05-31 23:22:35.625 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-misc-restdocs' 2019-05-31 23:23:04.360 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Command received zwave:device:8f6d8b58:node3:blinds_control --> DOWN [UpDownType] 2019-05-31 23:23:04.366 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 3: Creating new message for command SWITCH_MULTILEVEL_START_LEVEL_CHANGE 2019-05-31 23:23:04.369 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY not supported 2019-05-31 23:23:04.374 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Command Class COMMAND_CLASS_SWITCH_MULTILEVEL is NOT required to be secured 2019-05-31 23:23:04.377 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue 2019-05-31 23:23:04.382 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 82 to queue - size 1 2019-05-31 23:23:04.385 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-05-31 23:23:04.391 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0C 00 13 03 05 26 04 60 00 FF 25 35 4B 2019-05-31 23:23:04.397 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0C 00 13 03 05 26 04 60 00 FF 25 35 4B 2019-05-31 23:23:04.401 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-05-31 23:23:04.405 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 82: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 53 2019-05-31 23:23:04.405 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-05-31 23:23:04.411 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling intialised at 1800 seconds - start in 1500 milliseconds. 2019-05-31 23:23:04.414 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:23:04.418 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:23:04.425 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2019-05-31 23:23:04.431 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 82: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 53 2019-05-31 23:23:04.431 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:23:04.443 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-05-31 23:23:04.448 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:23:04.452 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 82: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 53 2019-05-31 23:23:04.460 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:23:04.462 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 82: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 53 2019-05-31 23:23:04.466 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:23:04.469 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack. 2019-05-31 23:23:04.473 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 82: Advanced to WAIT_REQUEST 2019-05-31 23:23:04.476 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 82: Transaction not completed 2019-05-31 23:23:04.479 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:23:04.482 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:23:05.915 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling... 2019-05-31 23:23:05.919 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling deferred until initialisation complete 2019-05-31 23:23:09.476 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 3: TID 82: Timeout at state WAIT_REQUEST. 3 retries remaining. 2019-05-31 23:23:09.480 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction! 2019-05-31 23:23:09.482 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 82: Transaction ABORTED 2019-05-31 23:23:09.487 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 2019-05-31 23:23:09.490 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 2019-05-31 23:23:09.493 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-05-31 23:23:09.496 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:23:09.496 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-05-31 23:23:09.499 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:23:09.502 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:23:09.510 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 82: [ABORTED] priority=Set, requiresResponse=true, callback: 53 2019-05-31 23:23:09.514 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-05-31 23:23:09.518 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:23:09.521 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:23:10.639 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 13 35 01 02 6F 00 7F 7F 7F 7F 7F 00 01 07 00 00 00 00 02 0F 05 03 DF 2019-05-31 23:23:10.655 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=53, payload=35 01 02 6F 00 7F 7F 7F 7F 7F 00 01 07 00 00 00 00 02 0F 05 03 2019-05-31 23:23:10.664 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=53, payload=35 01 02 6F 00 7F 7F 7F 7F 7F 00 01 07 00 00 00 00 02 0F 05 03 2019-05-31 23:23:10.671 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 82: [ABORTED] priority=Set, requiresResponse=true, callback: 53 2019-05-31 23:23:10.682 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:23:10.689 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 82: [ABORTED] priority=Set, requiresResponse=true, callback: 53 2019-05-31 23:23:10.696 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 82: (Callback 53) 2019-05-31 23:23:10.702 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2019-05-31 23:23:10.707 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 82: callback 53 2019-05-31 23:23:10.717 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=53, payload=35 01 02 6F 00 7F 7F 7F 7F 7F 00 01 07 00 00 00 00 02 0F 05 03 2019-05-31 23:23:10.724 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 53, Status = Transmission complete, no ACK received(1) 2019-05-31 23:23:10.730 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 82: Transaction CANCELLED 2019-05-31 23:23:10.733 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2019-05-31 23:23:10.737 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: CANCEL while sending message. Requeueing - 2 attempts left! 2019-05-31 23:23:10.740 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 82: Transaction RESET with 2 retries remaining. 2019-05-31 23:23:10.745 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue 2019-05-31 23:23:10.749 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 82 to queue - size 1 2019-05-31 23:23:10.755 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-05-31 23:23:10.762 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0C 00 13 03 05 26 04 60 00 FF 25 36 48 2019-05-31 23:23:10.769 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0C 00 13 03 05 26 04 60 00 FF 25 36 48 2019-05-31 23:23:10.772 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-05-31 23:23:10.776 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-05-31 23:23:10.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 82: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 54 2019-05-31 23:23:10.778 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:23:10.781 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 82: Transaction not completed 2019-05-31 23:23:10.786 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:23:10.791 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 82: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 54 2019-05-31 23:23:10.795 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-05-31 23:23:10.793 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2019-05-31 23:23:10.799 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:23:10.802 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:23:10.802 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:23:10.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:23:10.810 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 82: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 54 2019-05-31 23:23:10.813 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:23:10.817 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 82: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 54 2019-05-31 23:23:10.821 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:23:10.825 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack. 2019-05-31 23:23:10.829 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 82: Advanced to WAIT_REQUEST 2019-05-31 23:23:10.832 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 82: Transaction not completed 2019-05-31 23:23:10.835 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:23:10.838 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:23:15.832 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 3: TID 82: Timeout at state WAIT_REQUEST. 2 retries remaining. 2019-05-31 23:23:15.836 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction! 2019-05-31 23:23:15.839 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 82: Transaction ABORTED 2019-05-31 23:23:15.842 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 2019-05-31 23:23:15.845 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 2019-05-31 23:23:15.849 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-05-31 23:23:15.853 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-05-31 23:23:15.854 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:23:15.855 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:23:15.859 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:23:15.862 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 82: [ABORTED] priority=Set, requiresResponse=true, callback: 54 2019-05-31 23:23:15.866 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-05-31 23:23:15.869 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:23:15.873 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:23:17.000 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 13 36 01 02 6E 00 7F 7F 7F 7F 7F 00 01 07 00 00 00 00 02 0F 05 03 DD 2019-05-31 23:23:17.016 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=54, payload=36 01 02 6E 00 7F 7F 7F 7F 7F 00 01 07 00 00 00 00 02 0F 05 03 2019-05-31 23:23:17.025 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=54, payload=36 01 02 6E 00 7F 7F 7F 7F 7F 00 01 07 00 00 00 00 02 0F 05 03 2019-05-31 23:23:17.031 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 82: [ABORTED] priority=Set, requiresResponse=true, callback: 54 2019-05-31 23:23:17.038 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:23:17.044 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 82: [ABORTED] priority=Set, requiresResponse=true, callback: 54 2019-05-31 23:23:17.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 82: (Callback 54) 2019-05-31 23:23:17.053 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2019-05-31 23:23:17.056 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 82: callback 54 2019-05-31 23:23:17.061 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=54, payload=36 01 02 6E 00 7F 7F 7F 7F 7F 00 01 07 00 00 00 00 02 0F 05 03 2019-05-31 23:23:17.065 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 54, Status = Transmission complete, no ACK received(1) 2019-05-31 23:23:17.067 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 82: Transaction CANCELLED 2019-05-31 23:23:17.070 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2019-05-31 23:23:17.073 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: CANCEL while sending message. Requeueing - 1 attempts left! 2019-05-31 23:23:17.076 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 82: Transaction RESET with 1 retries remaining. 2019-05-31 23:23:17.078 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue 2019-05-31 23:23:17.081 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 82 to queue - size 1 2019-05-31 23:23:17.087 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-05-31 23:23:17.092 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0C 00 13 03 05 26 04 60 00 FF 25 37 49 2019-05-31 23:23:17.096 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0C 00 13 03 05 26 04 60 00 FF 25 37 49 2019-05-31 23:23:17.104 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-05-31 23:23:17.119 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:23:17.141 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2019-05-31 23:23:17.100 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-05-31 23:23:17.150 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 82: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 55 2019-05-31 23:23:17.154 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 82: Transaction not completed 2019-05-31 23:23:17.159 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:23:17.157 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:23:17.164 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 82: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 55 2019-05-31 23:23:17.167 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-05-31 23:23:17.172 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:23:17.175 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 82: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 55 2019-05-31 23:23:17.179 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:23:17.185 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 82: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 55 2019-05-31 23:23:17.207 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:23:17.212 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack. 2019-05-31 23:23:17.217 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 82: Advanced to WAIT_REQUEST 2019-05-31 23:23:17.221 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 82: Transaction not completed 2019-05-31 23:23:17.224 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:23:17.227 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:23:22.221 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 3: TID 82: Timeout at state WAIT_REQUEST. 1 retries remaining. 2019-05-31 23:23:22.234 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction! 2019-05-31 23:23:22.237 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 82: Transaction ABORTED 2019-05-31 23:23:22.241 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 2019-05-31 23:23:22.245 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 2019-05-31 23:23:22.253 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-05-31 23:23:22.255 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-05-31 23:23:22.257 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:23:22.260 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:23:22.263 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 82: [ABORTED] priority=Set, requiresResponse=true, callback: 55 2019-05-31 23:23:22.266 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-05-31 23:23:22.273 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:23:22.270 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:23:22.281 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:23:23.281 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 13 37 01 02 69 00 7F 7F 7F 7F 7F 00 01 07 00 00 00 00 02 0F 05 03 DB 2019-05-31 23:23:23.300 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=55, payload=37 01 02 69 00 7F 7F 7F 7F 7F 00 01 07 00 00 00 00 02 0F 05 03 2019-05-31 23:23:23.318 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=55, payload=37 01 02 69 00 7F 7F 7F 7F 7F 00 01 07 00 00 00 00 02 0F 05 03 2019-05-31 23:23:23.321 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 82: [ABORTED] priority=Set, requiresResponse=true, callback: 55 2019-05-31 23:23:23.324 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:23:23.326 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 82: [ABORTED] priority=Set, requiresResponse=true, callback: 55 2019-05-31 23:23:23.329 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 82: (Callback 55) 2019-05-31 23:23:23.331 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2019-05-31 23:23:23.334 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 82: callback 55 2019-05-31 23:23:23.338 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=55, payload=37 01 02 69 00 7F 7F 7F 7F 7F 00 01 07 00 00 00 00 02 0F 05 03 2019-05-31 23:23:23.342 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 55, Status = Transmission complete, no ACK received(1) 2019-05-31 23:23:23.345 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 82: Transaction CANCELLED 2019-05-31 23:23:23.349 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2019-05-31 23:23:23.352 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Retry count exceeded. Discarding message: TID 82: [CANCELLED] priority=Set, requiresResponse=true, callback: 55 2019-05-31 23:23:23.356 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 82: Transaction completed 2019-05-31 23:23:23.359 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: notifyTransactionResponse TID:82 CANCELLED 2019-05-31 23:23:23.364 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2019-05-31 23:23:23.366 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:23:23.370 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-05-31 23:23:34.180 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007 2019-05-31 23:23:34.226 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-misc-restdocs' 2019-05-31 23:24:27.993 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1d8b0c 2019-05-31 23:24:28.003 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Adding to device queue 2019-05-31 23:24:28.007 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Added 83 to queue - size 1 2019-05-31 23:24:28.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-05-31 23:24:28.014 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 60 04 9F 2019-05-31 23:24:28.018 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 60 04 9F 2019-05-31 23:24:28.023 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-05-31 23:24:28.025 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-05-31 23:24:28.025 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 83: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:28.029 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:24:28.031 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:24:28.034 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 83: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:28.036 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-05-31 23:24:28.038 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:24:28.043 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:24:28.048 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 60 01 9B 2019-05-31 23:24:28.054 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:24:28.057 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:24:28.060 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 83: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:28.064 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:24:28.067 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 83: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:28.071 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:24:28.074 [DEBUG] [lmessage.RequestNodeInfoMessageClass] - Request node info successfully placed on stack. 2019-05-31 23:24:28.078 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 83: Advanced to WAIT_DATA 2019-05-31 23:24:28.081 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 83: Transaction not completed 2019-05-31 23:24:28.083 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:24:28.085 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:24:35.464 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 06 00 49 81 00 00 31 2019-05-31 23:24:35.476 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:24:35.479 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:24:35.484 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 83: [WAIT_DATA] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:35.486 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:24:35.490 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 83: [WAIT_DATA] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:35.498 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 83: (Callback 0) 2019-05-31 23:24:35.501 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 83: callback 0 2019-05-31 23:24:35.509 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:24:35.512 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 4: Application update request. Node Info Request Failed. 2019-05-31 23:24:35.514 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 83: Transaction CANCELLED 2019-05-31 23:24:35.520 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: CANCEL while sending message. Requeueing - 2 attempts left! 2019-05-31 23:24:35.527 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 83: Transaction RESET with 2 retries remaining. 2019-05-31 23:24:35.529 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Adding to device queue 2019-05-31 23:24:35.533 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Added 83 to queue - size 1 2019-05-31 23:24:35.535 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-05-31 23:24:35.540 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 60 04 9F 2019-05-31 23:24:35.543 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 60 04 9F 2019-05-31 23:24:35.550 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-05-31 23:24:35.554 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:24:35.547 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-05-31 23:24:35.566 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 83: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:35.569 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 83: Transaction not completed 2019-05-31 23:24:35.572 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:24:35.573 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 60 01 9B 2019-05-31 23:24:35.590 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:24:35.574 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 83: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:35.601 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-05-31 23:24:35.607 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:24:35.609 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 83: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:35.613 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:24:35.616 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 83: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:35.619 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:24:35.622 [DEBUG] [lmessage.RequestNodeInfoMessageClass] - Request node info successfully placed on stack. 2019-05-31 23:24:35.625 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 83: Advanced to WAIT_DATA 2019-05-31 23:24:35.628 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 83: Transaction not completed 2019-05-31 23:24:35.631 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:24:35.634 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:24:37.748 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007 2019-05-31 23:24:37.791 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-misc-restdocs' 2019-05-31 23:24:43.017 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 06 00 49 81 00 00 31 2019-05-31 23:24:43.023 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:24:43.026 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:24:43.030 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 83: [WAIT_DATA] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:43.034 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:24:43.037 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 83: [WAIT_DATA] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:43.039 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 83: (Callback 0) 2019-05-31 23:24:43.042 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 83: callback 0 2019-05-31 23:24:43.046 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:24:43.049 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 4: Application update request. Node Info Request Failed. 2019-05-31 23:24:43.052 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 83: Transaction CANCELLED 2019-05-31 23:24:43.057 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: CANCEL while sending message. Requeueing - 1 attempts left! 2019-05-31 23:24:43.060 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 83: Transaction RESET with 1 retries remaining. 2019-05-31 23:24:43.063 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Adding to device queue 2019-05-31 23:24:43.065 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Added 83 to queue - size 1 2019-05-31 23:24:43.068 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-05-31 23:24:43.072 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 60 04 9F 2019-05-31 23:24:43.076 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 60 04 9F 2019-05-31 23:24:43.080 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-05-31 23:24:43.083 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 83: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:43.083 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-05-31 23:24:43.086 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 83: Transaction not completed 2019-05-31 23:24:43.086 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:24:43.089 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:24:43.091 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:24:43.094 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:24:43.097 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 83: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:43.106 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-05-31 23:24:43.108 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 60 01 9B 2019-05-31 23:24:43.108 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:24:43.111 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:24:43.114 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:24:43.119 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:24:43.123 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 83: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:43.127 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:24:43.131 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 83: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:43.134 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:24:43.137 [DEBUG] [lmessage.RequestNodeInfoMessageClass] - Request node info successfully placed on stack. 2019-05-31 23:24:43.140 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 83: Advanced to WAIT_DATA 2019-05-31 23:24:43.143 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 83: Transaction not completed 2019-05-31 23:24:43.146 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:24:43.149 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:24:50.587 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 06 00 49 81 00 00 31 2019-05-31 23:24:50.592 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:24:50.595 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:24:50.599 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 83: [WAIT_DATA] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:50.602 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:24:50.606 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 83: [WAIT_DATA] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:50.610 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 83: (Callback 0) 2019-05-31 23:24:50.613 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 83: callback 0 2019-05-31 23:24:50.617 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:24:50.620 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 4: Application update request. Node Info Request Failed. 2019-05-31 23:24:50.624 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 83: Transaction CANCELLED 2019-05-31 23:24:50.626 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Retry count exceeded. Discarding message: TID 83: [CANCELLED] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:24:50.630 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 83: Transaction completed 2019-05-31 23:24:50.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: notifyTransactionResponse TID:83 CANCELLED 2019-05-31 23:24:50.651 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:24:50.651 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 83: Transaction event listener: DONE: CANCELLED -> 2019-05-31 23:24:50.653 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-05-31 23:24:50.657 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 4: Node Init response (8) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1208137 2019-05-31 23:24:50.661 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 4: No data from device, but it was ACK'd. Possibly not supported? (Try 8) 2019-05-31 23:25:02.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@596620 2019-05-31 23:25:02.054 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue 2019-05-31 23:25:02.058 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 84 to queue - size 1 2019-05-31 23:25:02.061 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-05-31 23:25:02.064 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 60 02 99 2019-05-31 23:25:02.067 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 60 02 99 2019-05-31 23:25:02.070 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-05-31 23:25:02.072 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-05-31 23:25:02.072 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 84: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:02.075 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:25:02.078 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:25:02.080 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 84: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:02.083 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-05-31 23:25:02.085 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:25:02.088 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:25:02.501 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 60 01 9B 2019-05-31 23:25:02.504 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:25:02.507 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:25:02.509 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 84: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:02.512 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:25:02.514 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 84: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:02.516 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:25:02.519 [DEBUG] [lmessage.RequestNodeInfoMessageClass] - Request node info successfully placed on stack. 2019-05-31 23:25:02.521 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 84: Advanced to WAIT_DATA 2019-05-31 23:25:02.524 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 84: Transaction not completed 2019-05-31 23:25:02.526 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:25:02.528 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:25:11.170 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 06 00 49 81 00 00 31 2019-05-31 23:25:11.178 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:25:11.181 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:25:11.183 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 84: [WAIT_DATA] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:11.186 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:25:11.188 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 84: [WAIT_DATA] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:11.191 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 84: (Callback 0) 2019-05-31 23:25:11.193 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 84: callback 0 2019-05-31 23:25:11.196 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:25:11.200 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update request. Node Info Request Failed. 2019-05-31 23:25:11.202 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 84: Transaction CANCELLED 2019-05-31 23:25:11.206 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: CANCEL while sending message. Requeueing - 2 attempts left! 2019-05-31 23:25:11.208 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 84: Transaction RESET with 2 retries remaining. 2019-05-31 23:25:11.212 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue 2019-05-31 23:25:11.222 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 84 to queue - size 1 2019-05-31 23:25:11.226 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-05-31 23:25:11.229 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 60 02 99 2019-05-31 23:25:11.234 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 60 02 99 2019-05-31 23:25:11.237 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-05-31 23:25:11.240 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-05-31 23:25:11.240 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 84: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:11.242 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:25:11.244 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 84: Transaction not completed 2019-05-31 23:25:11.248 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:25:11.250 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 84: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:11.253 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-05-31 23:25:11.256 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:25:11.259 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:25:11.669 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 60 01 9B 2019-05-31 23:25:11.674 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:25:11.677 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:25:11.680 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 84: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:11.683 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:25:11.686 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 84: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:11.689 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:25:11.692 [DEBUG] [lmessage.RequestNodeInfoMessageClass] - Request node info successfully placed on stack. 2019-05-31 23:25:11.694 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 84: Advanced to WAIT_DATA 2019-05-31 23:25:11.697 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 84: Transaction not completed 2019-05-31 23:25:11.699 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:25:11.711 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:25:20.322 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 06 00 49 81 00 00 31 2019-05-31 23:25:20.326 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:25:20.329 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:25:20.331 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 84: [WAIT_DATA] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:20.333 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:25:20.337 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 84: [WAIT_DATA] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:20.339 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 84: (Callback 0) 2019-05-31 23:25:20.344 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 84: callback 0 2019-05-31 23:25:20.346 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:25:20.350 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update request. Node Info Request Failed. 2019-05-31 23:25:20.353 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 84: Transaction CANCELLED 2019-05-31 23:25:20.356 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: CANCEL while sending message. Requeueing - 1 attempts left! 2019-05-31 23:25:20.359 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 84: Transaction RESET with 1 retries remaining. 2019-05-31 23:25:20.362 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue 2019-05-31 23:25:20.365 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 84 to queue - size 1 2019-05-31 23:25:20.368 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-05-31 23:25:20.372 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 60 02 99 2019-05-31 23:25:20.375 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 60 02 99 2019-05-31 23:25:20.382 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-05-31 23:25:20.386 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:25:20.379 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-05-31 23:25:20.392 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 84: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:20.396 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 84: Transaction not completed 2019-05-31 23:25:20.399 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-05-31 23:25:20.403 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 84: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:20.405 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-05-31 23:25:20.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:25:20.411 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:25:20.810 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 60 01 9B 2019-05-31 23:25:20.815 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:25:20.818 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:25:20.821 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 84: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:20.823 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:25:20.827 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 84: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:20.830 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2019-05-31 23:25:20.833 [DEBUG] [lmessage.RequestNodeInfoMessageClass] - Request node info successfully placed on stack. 2019-05-31 23:25:20.836 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 84: Advanced to WAIT_DATA 2019-05-31 23:25:20.840 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 84: Transaction not completed 2019-05-31 23:25:20.843 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:25:20.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-05-31 23:25:29.448 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 06 00 49 81 00 00 31 2019-05-31 23:25:29.453 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:25:29.456 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:25:29.466 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 84: [WAIT_DATA] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:29.473 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-05-31 23:25:29.479 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 84: [WAIT_DATA] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:29.485 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 84: (Callback 0) 2019-05-31 23:25:29.490 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 84: callback 0 2019-05-31 23:25:29.492 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=0, callback=129, payload=81 00 00 2019-05-31 23:25:29.495 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update request. Node Info Request Failed. 2019-05-31 23:25:29.498 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 84: Transaction CANCELLED 2019-05-31 23:25:29.501 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Retry count exceeded. Discarding message: TID 84: [CANCELLED] priority=Controller, requiresResponse=true, callback: 0 2019-05-31 23:25:29.503 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 84: Transaction completed 2019-05-31 23:25:29.514 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:84 CANCELLED 2019-05-31 23:25:29.524 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-05-31 23:25:29.533 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-05-31 23:25:29.533 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 84: Transaction event listener: DONE: CANCELLED -> 2019-05-31 23:25:29.542 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init response (8) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@66e833 2019-05-31 23:25:29.548 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: No data from device, but it was ACK'd. Possibly not supported? (Try 8) 2019-05-31 23:25:36.671 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007 2019-05-31 23:25:36.709 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-misc-restdocs' 2019-05-31 23:26:35.208 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007 2019-05-31 23:26:35.301 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-misc-restdocs'