Running Openhabian 2.5.9 bundle from github on RaspberryPi 4
Using Gen 5 Z-Wave Stick.
All my Z-Wave nodes are showing OFFLINE
They are receiving commands and switching outputs on and off, but Openhab is not receiving the status back from them.
items file:
Number ms6_temperature “Living Room Temperature [%.1f C]” { channel=“zwave:device:65985128:node7:sensor_temperature” }
Number ms6_humidity “Living Room Humidity [%.0f %%]” { channel=“zwave:device:65985128:node7:sensor_relhumidity” }
Switch hot_water “Hot Water Heater” { channel=“zwave:device:65985128:node3:switch_binary1” }
Switch hot_water_boost “Hot Water Boost” { channel=“zwave:device:65985128:node3:switch_binary2” }
Switch EV_Charger “EV Charger” { channel=“zwave:device:65985128:node5:switch_binary1” }
Switch power_point “Living Room Power Outlet” { channel=“zwave:device:65985128:node6:switch_binary” }
Debug log pasted below:
[08:25:45] openhabian@openhab:~$ tail -f /var/log/openhab2/openhab.log
2020-10-08 08:16:13.971 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=36, payload=24 01 01 9B
2020-10-08 08:16:13.973 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: SendData Request. CallBack ID = 36, Status = Transmission complete, no ACK received(1)
2020-10-08 08:16:13.975 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 403: Transaction CANCELLED
2020-10-08 08:16:13.976 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: Retry count exceeded. Discarding message: TID 403: [CANCELLED] priority=Poll, requiresResponse=true, callback: 36
2020-10-08 08:16:13.978 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: TID 403: Transaction completed
2020-10-08 08:16:13.979 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: notifyTransactionResponse TID:403 CANCELLED
2020-10-08 08:16:13.981 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-10-08 08:16:13.982 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-10-08 08:16:13.984 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 403: Transaction event listener: DONE: CANCELLED ->
2020-10-08 08:16:13.986 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@81069a
2020-10-08 08:28:01.914 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: ZWaveCommandClassTransactionPayload - send to node
2020-10-08 08:28:01.916 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY not supported
2020-10-08 08:28:01.918 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Command Class COMMAND_CLASS_NO_OPERATION is NOT required to be secured
2020-10-08 08:28:01.919 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@1a31866
2020-10-08 08:28:01.922 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Adding to device queue
2020-10-08 08:28:01.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Added 404 to queue - size 1
2020-10-08 08:28:01.925 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-10-08 08:28:01.929 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 05 01 00 25 25 E0
2020-10-08 08:28:01.933 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 08 00 13 05 01 00 25 25 E0
2020-10-08 08:28:01.935 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-10-08 08:28:01.936 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-10-08 08:28:01.937 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 404: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 37
2020-10-08 08:28:01.938 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-10-08 08:28:01.941 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-10-08 08:28:01.942 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 404: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 37
2020-10-08 08:28:01.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-10-08 08:28:01.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-10-08 08:28:01.954 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-10-08 08:28:01.948 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2020-10-08 08:28:01.958 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2020-10-08 08:28:01.960 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2020-10-08 08:28:01.962 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 404: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 37
2020-10-08 08:28:01.963 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-10-08 08:28:01.965 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 404: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 37
2020-10-08 08:28:01.966 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2020-10-08 08:28:01.968 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: sentData successfully placed on stack.
2020-10-08 08:28:01.969 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 404: Advanced to WAIT_REQUEST
2020-10-08 08:28:01.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 404: Transaction not completed
2020-10-08 08:28:01.971 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-10-08 08:28:01.973 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-10-08 08:28:06.049 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 25 01 01 9B 55
2020-10-08 08:28:06.055 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=37, payload=25 01 01 9B
2020-10-08 08:28:06.057 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=37, payload=25 01 01 9B
2020-10-08 08:28:06.059 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 404: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 37
2020-10-08 08:28:06.060 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-10-08 08:28:06.061 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 404: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 37
2020-10-08 08:28:06.063 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 404: (Callback 37)
2020-10-08 08:28:06.064 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-10-08 08:28:06.066 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 404: callback 37
2020-10-08 08:28:06.068 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=37, payload=25 01 01 9B
2020-10-08 08:28:06.069 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: SendData Request. CallBack ID = 37, Status = Transmission complete, no ACK received(1)
2020-10-08 08:28:06.071 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 404: Transaction CANCELLED
2020-10-08 08:28:06.072 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2020-10-08 08:28:06.073 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: CANCEL while sending message. Requeueing - 2 attempts left!
2020-10-08 08:28:06.075 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 404: Transaction RESET with 2 retries remaining.
2020-10-08 08:28:06.076 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Adding to device queue
2020-10-08 08:28:06.078 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Added 404 to queue - size 1
2020-10-08 08:28:06.079 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-10-08 08:28:06.082 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 05 01 00 25 26 E3
2020-10-08 08:28:06.085 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 08 00 13 05 01 00 25 26 E3
2020-10-08 08:28:06.088 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-10-08 08:28:06.087 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-10-08 08:28:06.090 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-10-08 08:28:06.090 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 404: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 38
2020-10-08 08:28:06.093 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 404: Transaction not completed
2020-10-08 08:28:06.095 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-10-08 08:28:06.096 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 404: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 38
2020-10-08 08:28:06.099 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-10-08 08:28:06.099 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2020-10-08 08:28:06.100 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-10-08 08:28:06.102 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-10-08 08:28:06.102 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2020-10-08 08:28:06.104 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2020-10-08 08:28:06.106 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 404: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 38
2020-10-08 08:28:06.107 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-10-08 08:28:06.109 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 404: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 38
2020-10-08 08:28:06.111 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2020-10-08 08:28:06.112 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: sentData successfully placed on stack.
2020-10-08 08:28:06.114 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 404: Advanced to WAIT_REQUEST
2020-10-08 08:28:06.116 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 404: Transaction not completed
2020-10-08 08:28:06.118 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-10-08 08:28:06.119 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-10-08 08:28:10.232 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 26 01 01 9E 53
2020-10-08 08:28:10.236 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=38, payload=26 01 01 9E
2020-10-08 08:28:10.239 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=38, payload=26 01 01 9E
2020-10-08 08:28:10.240 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 404: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 38
2020-10-08 08:28:10.242 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-10-08 08:28:10.243 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 404: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 38
2020-10-08 08:28:10.245 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 404: (Callback 38)
2020-10-08 08:28:10.247 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-10-08 08:28:10.249 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 404: callback 38
2020-10-08 08:28:10.251 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=38, payload=26 01 01 9E
2020-10-08 08:28:10.253 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: SendData Request. CallBack ID = 38, Status = Transmission complete, no ACK received(1)
2020-10-08 08:28:10.254 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 404: Transaction CANCELLED
2020-10-08 08:28:10.256 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2020-10-08 08:28:10.257 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: CANCEL while sending message. Requeueing - 1 attempts left!
2020-10-08 08:28:10.259 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 404: Transaction RESET with 1 retries remaining.
2020-10-08 08:28:10.260 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Adding to device queue
2020-10-08 08:28:10.262 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Added 404 to queue - size 1
2020-10-08 08:28:10.263 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-10-08 08:28:10.266 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 05 01 00 25 27 E2
2020-10-08 08:28:10.269 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 08 00 13 05 01 00 25 27 E2
2020-10-08 08:28:10.272 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-10-08 08:28:10.270 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-10-08 08:28:10.274 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-10-08 08:28:10.274 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 404: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 39
2020-10-08 08:28:10.276 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 404: Transaction not completed
2020-10-08 08:28:10.278 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-10-08 08:28:10.280 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 404: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 39
2020-10-08 08:28:10.281 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-10-08 08:28:10.283 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2020-10-08 08:28:10.283 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-10-08 08:28:10.284 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-10-08 08:28:10.286 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2020-10-08 08:28:10.288 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2020-10-08 08:28:10.289 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 404: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 39
2020-10-08 08:28:10.290 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-10-08 08:28:10.291 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 404: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 39
2020-10-08 08:28:10.293 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2020-10-08 08:28:10.295 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: sentData successfully placed on stack.
2020-10-08 08:28:10.296 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 404: Advanced to WAIT_REQUEST
2020-10-08 08:28:10.297 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 404: Transaction not completed
2020-10-08 08:28:10.298 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-10-08 08:28:10.300 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-10-08 08:28:14.386 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 27 01 01 9B 57
2020-10-08 08:28:14.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=39, payload=27 01 01 9B
2020-10-08 08:28:14.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=39, payload=27 01 01 9B
2020-10-08 08:28:14.394 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 404: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 39
2020-10-08 08:28:14.395 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-10-08 08:28:14.397 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 404: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 39
2020-10-08 08:28:14.398 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 404: (Callback 39)
2020-10-08 08:28:14.400 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-10-08 08:28:14.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 404: callback 39
2020-10-08 08:28:14.403 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=39, payload=27 01 01 9B
2020-10-08 08:28:14.405 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: SendData Request. CallBack ID = 39, Status = Transmission complete, no ACK received(1)
2020-10-08 08:28:14.406 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 404: Transaction CANCELLED
2020-10-08 08:28:14.408 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2020-10-08 08:28:14.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Retry count exceeded. Discarding message: TID 404: [CANCELLED] priority=Poll, requiresResponse=true, callback: 39
2020-10-08 08:28:14.411 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 404: Transaction completed
2020-10-08 08:28:14.412 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: notifyTransactionResponse TID:404 CANCELLED
2020-10-08 08:28:14.414 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2020-10-08 08:28:14.414 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 404: Transaction event listener: DONE: CANCELLED ->
2020-10-08 08:28:14.415 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-10-08 08:28:14.419 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@b1ed12
2020-10-08 08:28:14.419 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-10-08 08:28:19.196 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Command received zwave:device:65985128:node3:switch_binary1 --> ON [OnOffType]
2020-10-08 08:28:19.198 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 3: Creating new message for application command SWITCH_BINARY_SET
2020-10-08 08:28:19.199 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Encapsulating message, instance / endpoint 1
2020-10-08 08:28:19.201 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 3: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1
2020-10-08 08:28:19.203 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY not supported
2020-10-08 08:28:19.204 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2020-10-08 08:28:19.206 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue
2020-10-08 08:28:19.207 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 405 to queue - size 1
2020-10-08 08:28:19.209 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-10-08 08:28:19.213 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 13 03 07 60 0D 01 01 25 01 FF 25 28 5D
2020-10-08 08:28:19.217 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0E 00 13 03 07 60 0D 01 01 25 01 FF 25 28 5D
2020-10-08 08:28:19.219 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-10-08 08:28:19.221 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-10-08 08:28:19.221 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 405: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 40
2020-10-08 08:28:19.223 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-10-08 08:28:19.223 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling initialised at 86400 seconds - start in 1500 milliseconds.
2020-10-08 08:28:19.224 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-10-08 08:28:19.226 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 405: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 40
2020-10-08 08:28:19.227 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-10-08 08:28:19.228 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-10-08 08:28:19.229 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-10-08 08:28:19.232 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2020-10-08 08:28:19.236 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2020-10-08 08:28:19.238 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2020-10-08 08:28:19.239 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 405: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 40
2020-10-08 08:28:19.241 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-10-08 08:28:19.243 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 405: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 40
2020-10-08 08:28:19.245 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2020-10-08 08:28:19.247 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack.
2020-10-08 08:28:19.249 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 405: Advanced to WAIT_REQUEST
2020-10-08 08:28:19.250 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 405: Transaction not completed
2020-10-08 08:28:19.252 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-10-08 08:28:19.253 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-10-08 08:28:20.723 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling...
2020-10-08 08:28:20.725 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling deferred until initialisation complete
2020-10-08 08:28:23.362 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 28 01 01 9E 5D
2020-10-08 08:28:23.366 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=40, payload=28 01 01 9E
2020-10-08 08:28:23.368 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=40, payload=28 01 01 9E
2020-10-08 08:28:23.369 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 405: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 40
2020-10-08 08:28:23.371 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-10-08 08:28:23.372 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 405: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 40
2020-10-08 08:28:23.373 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 405: (Callback 40)
2020-10-08 08:28:23.374 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-10-08 08:28:23.375 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 405: callback 40
2020-10-08 08:28:23.377 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=40, payload=28 01 01 9E
2020-10-08 08:28:23.378 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 40, Status = Transmission complete, no ACK received(1)
2020-10-08 08:28:23.382 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 405: Transaction CANCELLED
2020-10-08 08:28:23.385 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2020-10-08 08:28:23.387 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: CANCEL while sending message. Requeueing - 2 attempts left!
2020-10-08 08:28:23.388 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 405: Transaction RESET with 2 retries remaining.
2020-10-08 08:28:23.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue
2020-10-08 08:28:23.392 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 405 to queue - size 1
2020-10-08 08:28:23.394 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-10-08 08:28:23.409 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 13 03 07 60 0D 01 01 25 01 FF 25 29 5C
2020-10-08 08:28:23.417 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0E 00 13 03 07 60 0D 01 01 25 01 FF 25 29 5C
2020-10-08 08:28:23.419 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-10-08 08:28:23.421 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-10-08 08:28:23.421 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 405: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 41
2020-10-08 08:28:23.422 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-10-08 08:28:23.423 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 405: Transaction not completed
2020-10-08 08:28:23.425 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-10-08 08:28:23.429 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 405: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 41
2020-10-08 08:28:23.432 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2020-10-08 08:28:23.435 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-10-08 08:28:23.435 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2020-10-08 08:28:23.437 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2020-10-08 08:28:23.438 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 405: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 41
2020-10-08 08:28:23.439 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-10-08 08:28:23.440 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 405: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 41
2020-10-08 08:28:23.442 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2020-10-08 08:28:23.443 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack.
2020-10-08 08:28:23.444 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 405: Advanced to WAIT_REQUEST
2020-10-08 08:28:23.445 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 405: Transaction not completed
2020-10-08 08:28:23.447 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-10-08 08:28:23.448 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.