ZWave devices cannot communicate with controller

Sorry, I wasn’t clear there. I meant that I restarted because it was unresponsive.

So here’s where I am. My zwave network continued to be unresponsive after allowing for “settle” for about an hour after the last reboot. So I stopped OH and installed the latest snapshot along with the xstream jar, restarted. After an hour or so, the network appears stable and devices are responsive. The looks “normal”, but if there is anything in them that might point to a potential problem, I’d like to hear it. If things go bad again, I’ll post another log.

2019-09-01 11:43:10.264 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 11:43:10.267 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 85: Application Command Request (ALIVE:REQUEST_NIF)
2019-09-01 11:43:10.270 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 85: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2019-09-01 11:43:10.273 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 85: SECURITY not supported
2019-09-01 11:43:10.276 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 85: Received COMMAND_CLASS_SENSOR_MULTILEVEL V7 SENSOR_MULTILEVEL_REPORT
2019-09-01 11:43:10.279 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 85: Sensor Type = Luminance(3), Scale = 1
2019-09-01 11:43:10.282 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 85: Sensor Value = 357
2019-09-01 11:43:10.285 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 85: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2019-09-01 11:43:10.288 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 85: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=357
2019-09-01 11:43:10.291 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 85: Updating channel state zwave:device:f21cd9de:node85:sensor_luminance to 357 % [QuantityType]
2019-09-01 11:43:10.296 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 85: Commands processed 1.
2019-09-01 11:43:10.317 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 85: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@18ab86c.
2019-09-01 11:43:10.320 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:10.324 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:10.327 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 11:43:10.331 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:43:14.240 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 39 06 31 05 01 2A 02 AE 7B 
2019-09-01 11:43:14.246 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=57, callback=0, payload=00 39 06 31 05 01 2A 02 AE 
2019-09-01 11:43:14.251 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=57, callback=0, payload=00 39 06 31 05 01 2A 02 AE 
2019-09-01 11:43:14.254 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 11:43:14.257 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Application Command Request (ALIVE:DONE)
2019-09-01 11:43:14.260 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: resetResendCount initComplete=true isDead=false
2019-09-01 11:43:14.262 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2019-09-01 11:43:14.266 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: SECURITY not supported
2019-09-01 11:43:14.268 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 57: Received COMMAND_CLASS_SENSOR_MULTILEVEL V5 SENSOR_MULTILEVEL_REPORT
2019-09-01 11:43:14.271 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 57: Sensor Type = Temperature(1), Scale = 1
2019-09-01 11:43:14.274 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 57: Sensor Value = 68.6
2019-09-01 11:43:14.277 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2019-09-01 11:43:14.279 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=68.6
2019-09-01 11:43:14.283 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Updating channel state zwave:device:f21cd9de:node57:sensor_temperature to 68.6 °F [QuantityType]
2019-09-01 11:43:14.293 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Commands processed 1.
2019-09-01 11:43:14.300 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@c142a.
2019-09-01 11:43:14.302 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:14.305 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:14.307 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 11:43:14.310 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:43:14.723 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 39 05 31 05 05 01 45 B9 
2019-09-01 11:43:14.726 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=57, callback=0, payload=00 39 05 31 05 05 01 45 
2019-09-01 11:43:14.747 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=57, callback=0, payload=00 39 05 31 05 05 01 45 
2019-09-01 11:43:14.748 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 11:43:14.751 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Application Command Request (ALIVE:DONE)
2019-09-01 11:43:14.752 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: resetResendCount initComplete=true isDead=false
2019-09-01 11:43:14.755 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2019-09-01 11:43:14.756 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: SECURITY not supported
2019-09-01 11:43:14.759 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 57: Received COMMAND_CLASS_SENSOR_MULTILEVEL V5 SENSOR_MULTILEVEL_REPORT
2019-09-01 11:43:14.760 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 57: Sensor Type = RelativeHumidity(5), Scale = 0
2019-09-01 11:43:14.763 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 57: Sensor Value = 69
2019-09-01 11:43:14.765 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2019-09-01 11:43:14.767 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=69
2019-09-01 11:43:14.769 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 57: Sensor conversion not performed for RELATIVE_HUMIDITY.
2019-09-01 11:43:14.771 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Updating channel state zwave:device:f21cd9de:node57:sensor_relhumidity to 69 [DecimalType]
2019-09-01 11:43:14.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Commands processed 1.
2019-09-01 11:43:14.777 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@10acd96.
2019-09-01 11:43:14.779 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:14.781 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:14.783 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 11:43:14.785 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:43:16.539 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 39 03 80 03 32 79 
2019-09-01 11:43:16.546 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=57, callback=0, payload=00 39 03 80 03 32 
2019-09-01 11:43:16.549 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=57, callback=0, payload=00 39 03 80 03 32 
2019-09-01 11:43:16.552 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 11:43:16.555 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Application Command Request (ALIVE:DONE)
2019-09-01 11:43:16.559 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: resetResendCount initComplete=true isDead=false
2019-09-01 11:43:16.562 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: Incoming command class COMMAND_CLASS_BATTERY, endpoint 0
2019-09-01 11:43:16.566 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: SECURITY not supported
2019-09-01 11:43:16.569 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 57: Received COMMAND_CLASS_BATTERY V1 BATTERY_REPORT
2019-09-01 11:43:16.573 [DEBUG] [ommandclass.ZWaveBatteryCommandClass] - NODE 57: Battery report value = 50
2019-09-01 11:43:16.577 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2019-09-01 11:43:16.580 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_BATTERY, value=50
2019-09-01 11:43:16.584 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Updating channel state zwave:device:f21cd9de:node57:battery-level to 50 [DecimalType]
2019-09-01 11:43:16.590 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Commands processed 1.
2019-09-01 11:43:16.593 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1915bd6.
2019-09-01 11:43:16.596 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:16.598 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:16.602 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 11:43:16.605 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:43:20.398 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 39 06 31 05 03 0A 00 00 F5 
2019-09-01 11:43:20.403 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=57, callback=0, payload=00 39 06 31 05 03 0A 00 00 
2019-09-01 11:43:20.406 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=57, callback=0, payload=00 39 06 31 05 03 0A 00 00 
2019-09-01 11:43:20.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 11:43:20.410 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Application Command Request (ALIVE:DONE)
2019-09-01 11:43:20.413 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: resetResendCount initComplete=true isDead=false
2019-09-01 11:43:20.415 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2019-09-01 11:43:20.418 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: SECURITY not supported
2019-09-01 11:43:20.420 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 57: Received COMMAND_CLASS_SENSOR_MULTILEVEL V5 SENSOR_MULTILEVEL_REPORT
2019-09-01 11:43:20.423 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 57: Sensor Type = Luminance(3), Scale = 1
2019-09-01 11:43:20.426 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 57: Sensor Value = 0E+1
2019-09-01 11:43:20.428 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2019-09-01 11:43:20.430 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=0E+1
2019-09-01 11:43:20.433 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Updating channel state zwave:device:f21cd9de:node57:sensor_luminance to 0E+1 % [QuantityType]
2019-09-01 11:43:20.436 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Commands processed 1.
2019-09-01 11:43:20.438 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@112d410.
2019-09-01 11:43:20.441 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:20.443 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:20.445 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 11:43:20.447 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:43:20.498 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 39 05 31 05 1B 01 00 E2 
2019-09-01 11:43:20.502 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=57, callback=0, payload=00 39 05 31 05 1B 01 00 
2019-09-01 11:43:20.505 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=57, callback=0, payload=00 39 05 31 05 1B 01 00 
2019-09-01 11:43:20.507 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 11:43:20.509 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Application Command Request (ALIVE:DONE)
2019-09-01 11:43:20.512 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: resetResendCount initComplete=true isDead=false
2019-09-01 11:43:20.515 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2019-09-01 11:43:20.517 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 39 02 84 07 4B 
2019-09-01 11:43:20.517 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: SECURITY not supported
2019-09-01 11:43:20.521 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 57: Received COMMAND_CLASS_SENSOR_MULTILEVEL V5 SENSOR_MULTILEVEL_REPORT
2019-09-01 11:43:20.522 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=57, callback=0, payload=00 39 02 84 07 
2019-09-01 11:43:20.525 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 57: Sensor Type = Ultraviolet(27), Scale = 0
2019-09-01 11:43:20.528 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 57: Sensor Value = 0E+1
2019-09-01 11:43:20.531 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2019-09-01 11:43:20.533 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=0E+1
2019-09-01 11:43:20.536 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 57: Sensor conversion not performed for ULTRAVIOLET.
2019-09-01 11:43:20.539 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Updating channel state zwave:device:f21cd9de:node57:sensor_ultraviolet to 0 [DecimalType]
2019-09-01 11:43:20.542 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Commands processed 1.
2019-09-01 11:43:20.545 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1773a5c.
2019-09-01 11:43:20.547 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:20.550 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:20.552 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=57, callback=0, payload=00 39 02 84 07 
2019-09-01 11:43:20.555 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 11:43:20.557 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Application Command Request (ALIVE:DONE)
2019-09-01 11:43:20.560 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: resetResendCount initComplete=true isDead=false
2019-09-01 11:43:20.563 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: Is awake with 0 messages in the queue
2019-09-01 11:43:20.566 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: Start sleep timer at 1000ms
2019-09-01 11:43:20.568 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2019-09-01 11:43:20.596 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 57: Node Status event - Node is AWAKE
2019-09-01 11:43:20.599 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Commands processed 1.
2019-09-01 11:43:20.601 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@483f99.
2019-09-01 11:43:20.607 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:20.610 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:20.613 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 11:43:20.616 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:43:21.069 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: WakeupTimerTask 0 Messages waiting, state DONE
2019-09-01 11:43:21.569 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: WakeupTimerTask 0 Messages waiting, state DONE
2019-09-01 11:43:21.571 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: No more messages, go back to sleep
2019-09-01 11:43:21.572 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 57: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
2019-09-01 11:43:21.575 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: SECURITY not supported
2019-09-01 11:43:21.576 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: Command Class COMMAND_CLASS_WAKE_UP is NOT required to be secured
2019-09-01 11:43:21.578 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@10c9894
2019-09-01 11:43:21.581 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Bump transaction 614 priority from Immediate to Immediate
2019-09-01 11:43:21.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Adding to device queue
2019-09-01 11:43:21.586 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Added 614 to queue - size 35
2019-09-01 11:43:21.588 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:43:21.592 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 39 02 84 08 25 0B 7C 
2019-09-01 11:43:21.595 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 57: Sending REQUEST Message = 01 09 00 13 39 02 84 08 25 0B 7C 
2019-09-01 11:43:21.598 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-01 11:43:21.600 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 614: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 11
2019-09-01 11:43:21.600 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-09-01 11:43:21.604 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-01 11:43:21.608 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-01 11:43:21.610 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 614: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 11
2019-09-01 11:43:21.611 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2019-09-01 11:43:21.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-09-01 11:43:21.617 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-09-01 11:43:21.616 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 11:43:21.619 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-01 11:43:21.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-09-01 11:43:21.623 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 0B 00 00 02 E2 
2019-09-01 11:43:21.625 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 614: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 11
2019-09-01 11:43:21.627 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-01 11:43:21.629 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 614: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 11
2019-09-01 11:43:21.631 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-09-01 11:43:21.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=11, payload=0B 00 00 02 
2019-09-01 11:43:21.633 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 57: sentData successfully placed on stack.
2019-09-01 11:43:21.636 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 614: Advanced to WAIT_REQUEST
2019-09-01 11:43:21.638 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: TID 614: Transaction not completed
2019-09-01 11:43:21.640 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=11, payload=0B 00 00 02 
2019-09-01 11:43:21.642 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 614: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 11
2019-09-01 11:43:21.644 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-01 11:43:21.646 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 614: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 11
2019-09-01 11:43:21.648 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 614: (Callback 11)
2019-09-01 11:43:21.651 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-09-01 11:43:21.652 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 614: callback 11
2019-09-01 11:43:21.655 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=11, payload=0B 00 00 02 
2019-09-01 11:43:21.657 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 57: SendData Request. CallBack ID = 11, Status = Transmission complete and ACK received(0)
2019-09-01 11:43:21.659 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: resetResendCount initComplete=true isDead=false
2019-09-01 11:43:21.670 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 614: Transaction COMPLETED
2019-09-01 11:43:21.672 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: Response processed after 73ms
2019-09-01 11:43:21.674 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: TID 614: Transaction completed
2019-09-01 11:43:21.676 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 57: notifyTransactionResponse TID:614 DONE
2019-09-01 11:43:21.679 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 57: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-09-01 11:43:21.679 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 614: Transaction event listener: DONE: DONE -> 
2019-09-01 11:43:21.681 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 11:43:21.682 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 57: Went to sleep COMPLETE
2019-09-01 11:43:21.684 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:43:27.347 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 3C 02 84 07 4E 
2019-09-01 11:43:27.350 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=60, callback=0, payload=00 3C 02 84 07 
2019-09-01 11:43:27.352 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=60, callback=0, payload=00 3C 02 84 07 
2019-09-01 11:43:27.354 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 11:43:27.355 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 60: Application Command Request (ALIVE:DONE)
2019-09-01 11:43:27.357 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 60: resetResendCount initComplete=true isDead=false
2019-09-01 11:43:27.358 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 60: Commands processed 1.
2019-09-01 11:43:27.360 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 60: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@17e8ead.
2019-09-01 11:43:27.361 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:27.362 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:27.364 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 11:43:27.365 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:43:50.841 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 02 02 84 07 70 
2019-09-01 11:43:50.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 02 84 07 
2019-09-01 11:43:50.846 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 02 84 07 
2019-09-01 11:43:50.848 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 11:43:50.850 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:DONE)
2019-09-01 11:43:50.851 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2019-09-01 11:43:50.856 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1.
2019-09-01 11:43:50.860 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@6372c6.
2019-09-01 11:43:50.861 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:50.863 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:50.864 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 11:43:50.866 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:43:54.235 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 41 05 31 05 05 01 3F BB 
2019-09-01 11:43:54.238 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=65, callback=0, payload=00 41 05 31 05 05 01 3F 
2019-09-01 11:43:54.240 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=65, callback=0, payload=00 41 05 31 05 05 01 3F 
2019-09-01 11:43:54.241 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 11:43:54.242 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 65: Application Command Request (ALIVE:DONE)
2019-09-01 11:43:54.244 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 65: resetResendCount initComplete=true isDead=false
2019-09-01 11:43:54.245 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 65: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2019-09-01 11:43:54.246 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 65: SECURITY not supported
2019-09-01 11:43:54.248 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 65: Received COMMAND_CLASS_SENSOR_MULTILEVEL V5 SENSOR_MULTILEVEL_REPORT
2019-09-01 11:43:54.250 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 65: Sensor Type = RelativeHumidity(5), Scale = 0
2019-09-01 11:43:54.252 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 65: Sensor Value = 63
2019-09-01 11:43:54.254 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 65: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2019-09-01 11:43:54.258 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 65: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=63
2019-09-01 11:43:54.261 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 65: Sensor conversion not performed for RELATIVE_HUMIDITY.
2019-09-01 11:43:54.262 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 65: Updating channel state zwave:device:f21cd9de:node65:sensor_relhumidity to 63 [DecimalType]
2019-09-01 11:43:54.383 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 65: Commands processed 1.
2019-09-01 11:43:54.386 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 65: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@8e028c.
2019-09-01 11:43:54.387 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:54.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:43:54.391 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 11:43:54.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:43:56.373 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1afcacf
2019-09-01 11:43:56.378 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2019-09-01 11:43:56.381 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 417 to queue - size 29
2019-09-01 11:43:56.385 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:43:56.390 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 60 02 99 
2019-09-01 11:43:56.394 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Port closed sending REQUEST Message = 01 04 00 60 02 99 
2019-09-01 11:43:56.397 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 417: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-09-01 11:43:58.400 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 2: TID 417: Timeout at state WAIT_RESPONSE. 3 retries remaining.
2019-09-01 11:43:58.404 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 417: Transaction is current transaction, so clearing!!!!!
2019-09-01 11:43:58.407 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 417: Transaction CANCELLED
2019-09-01 11:43:58.410 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:417 CANCELLED
2019-09-01 11:43:58.413 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:43:58.413 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 417: Transaction event listener: DONE: CANCELLED -> 
2019-09-01 11:43:58.416 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@5e25b6
2019-09-01 11:44:04.274 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 41 05 31 05 05 01 3E BA 
2019-09-01 11:44:04.279 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=65, callback=0, payload=00 41 05 31 05 05 01 3E 
2019-09-01 11:44:04.282 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=65, callback=0, payload=00 41 05 31 05 05 01 3E 
2019-09-01 11:44:04.283 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 11:44:04.286 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 65: Application Command Request (ALIVE:DONE)
2019-09-01 11:44:04.288 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 65: resetResendCount initComplete=true isDead=false
2019-09-01 11:44:04.291 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 65: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2019-09-01 11:44:04.292 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 65: SECURITY not supported
2019-09-01 11:44:04.293 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 65: Received COMMAND_CLASS_SENSOR_MULTILEVEL V5 SENSOR_MULTILEVEL_REPORT
2019-09-01 11:44:04.295 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 65: Sensor Type = RelativeHumidity(5), Scale = 0
2019-09-01 11:44:04.299 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 65: Sensor Value = 62
2019-09-01 11:44:04.303 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 65: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2019-09-01 11:44:04.307 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 65: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=62
2019-09-01 11:44:04.311 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 65: Sensor conversion not performed for RELATIVE_HUMIDITY.
2019-09-01 11:44:04.312 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 65: Updating channel state zwave:device:f21cd9de:node65:sensor_relhumidity to 62 [DecimalType]
2019-09-01 11:44:04.315 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 65: Commands processed 1.
2019-09-01 11:44:04.324 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 65: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1d34733.
2019-09-01 11:44:04.325 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:44:04.330 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:44:04.331 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 11:44:04.333 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:44:43.427 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@5776c0
2019-09-01 11:44:43.430 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Adding to device queue
2019-09-01 11:44:43.431 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Added 418 to queue - size 29
2019-09-01 11:44:43.432 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:44:43.435 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 60 18 83 
2019-09-01 11:44:43.438 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Port closed sending REQUEST Message = 01 04 00 60 18 83 
2019-09-01 11:44:43.439 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 418: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-09-01 11:44:44.336 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 41 05 31 05 05 01 3F BB 
2019-09-01 11:44:44.342 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=65, callback=0, payload=00 41 05 31 05 05 01 3F 
2019-09-01 11:44:44.346 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=65, callback=0, payload=00 41 05 31 05 05 01 3F 
2019-09-01 11:44:44.348 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 11:44:44.351 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 65: Application Command Request (ALIVE:DONE)
2019-09-01 11:44:44.353 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 65: resetResendCount initComplete=true isDead=false
2019-09-01 11:44:44.356 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 65: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2019-09-01 11:44:44.359 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 65: SECURITY not supported
2019-09-01 11:44:44.361 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 65: Received COMMAND_CLASS_SENSOR_MULTILEVEL V5 SENSOR_MULTILEVEL_REPORT
2019-09-01 11:44:44.364 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 65: Sensor Type = RelativeHumidity(5), Scale = 0
2019-09-01 11:44:44.367 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 65: Sensor Value = 63
2019-09-01 11:44:44.370 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 65: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2019-09-01 11:44:44.373 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 65: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=63
2019-09-01 11:44:44.377 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 65: Sensor conversion not performed for RELATIVE_HUMIDITY.
2019-09-01 11:44:44.380 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 65: Updating channel state zwave:device:f21cd9de:node65:sensor_relhumidity to 63 [DecimalType]
2019-09-01 11:44:44.385 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 65: Commands processed 1.
2019-09-01 11:44:44.388 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 65: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@fdb182.
2019-09-01 11:44:44.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:44:44.397 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:44:44.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 11:44:44.403 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:44:45.442 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 24: TID 418: Timeout at state WAIT_RESPONSE. 3 retries remaining.
2019-09-01 11:44:45.445 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 418: Transaction is current transaction, so clearing!!!!!
2019-09-01 11:44:45.447 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 418: Transaction CANCELLED
2019-09-01 11:44:45.449 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: notifyTransactionResponse TID:418 CANCELLED
2019-09-01 11:44:45.460 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:44:45.460 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 418: Transaction event listener: DONE: CANCELLED -> 
2019-09-01 11:44:45.466 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@b4a940
2019-09-01 11:44:54.357 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 41 05 31 05 05 01 3E BA 
2019-09-01 11:44:54.361 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=65, callback=0, payload=00 41 05 31 05 05 01 3E 
2019-09-01 11:44:54.363 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=65, callback=0, payload=00 41 05 31 05 05 01 3E 
2019-09-01 11:44:54.365 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 11:44:54.366 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 65: Application Command Request (ALIVE:DONE)
2019-09-01 11:44:54.368 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 65: resetResendCount initComplete=true isDead=false
2019-09-01 11:44:54.369 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 65: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2019-09-01 11:44:54.371 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 65: SECURITY not supported
2019-09-01 11:44:54.372 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 65: Received COMMAND_CLASS_SENSOR_MULTILEVEL V5 SENSOR_MULTILEVEL_REPORT
2019-09-01 11:44:54.374 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 65: Sensor Type = RelativeHumidity(5), Scale = 0
2019-09-01 11:44:54.375 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 65: Sensor Value = 62
2019-09-01 11:44:54.377 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 65: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2019-09-01 11:44:54.379 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 65: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=62
2019-09-01 11:44:54.381 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 65: Sensor conversion not performed for RELATIVE_HUMIDITY.
2019-09-01 11:44:54.383 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 65: Updating channel state zwave:device:f21cd9de:node65:sensor_relhumidity to 62 [DecimalType]
2019-09-01 11:44:54.386 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 65: Commands processed 1.
2019-09-01 11:44:54.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 65: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@16d1959.
2019-09-01 11:44:54.396 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:44:54.398 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 11:44:54.404 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 11:44:54.406 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:46:27.534 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 59: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@d2c5a8
2019-09-01 11:46:27.537 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 59: Adding to device queue
2019-09-01 11:46:27.539 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 59: Added 419 to queue - size 29
2019-09-01 11:46:27.541 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:46:27.544 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 60 3B A0 
2019-09-01 11:46:27.547 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Port closed sending REQUEST Message = 01 04 00 60 3B A0 
2019-09-01 11:46:27.548 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 419: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-09-01 11:46:29.550 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 59: TID 419: Timeout at state WAIT_RESPONSE. 3 retries remaining.
2019-09-01 11:46:29.552 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 419: Transaction is current transaction, so clearing!!!!!
2019-09-01 11:46:29.555 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 419: Transaction CANCELLED
2019-09-01 11:46:29.557 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 59: notifyTransactionResponse TID:419 CANCELLED
2019-09-01 11:46:29.560 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 11:46:29.563 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 419: Transaction event listener: DONE: CANCELLED -> 
2019-09-01 11:46:29.603 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 59: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1ad8882
1 Like

You could also upload to the log viewer to see id anything looks suspicious.

https://www.cd-jackson.com/index.php/openhab/zwave-log-viewer

This log looks pretty normal, but it’s short. The previous log shows a lot of CAN messages as I said earlier. These are often indicative of the controller being overloaded. In the past I’ve seen that these have been caused when a device floods the network.

OK, thanks. I may have to get a sniffer to find out just which devices may be flooding the network.
But since my last report, I ran into the issue again. I tapped a button on my wall mote, it flashed blue a few times, then red. There was no console output when the button was pressed ( I’m running tail -f on the log file). The bulb did not toggle.

Here is the log just before it happened:

2019-09-01 13:55:34.093 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2019-09-01 13:55:34.094 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 
2019-09-01 13:55:34.095 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 242 to queue - size 39
2019-09-01 13:55:34.100 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-01 13:55:34.104 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (1): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-01 13:55:34.108 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 241: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-09-01 13:55:34.112 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-09-01 13:55:34.117 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 
2019-09-01 13:55:34.121 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 241: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-09-01 13:55:34.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-01 13:55:34.126 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 241: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-09-01 13:55:34.128 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 
2019-09-01 13:55:34.130 [DEBUG] [lmessage.RequestNodeInfoMessageClass] - Request node info successfully placed on stack.
2019-09-01 13:55:34.132 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 241: Advanced to WAIT_DATA
2019-09-01 13:55:34.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: TID 241: Transaction not completed
2019-09-01 13:55:34.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 13:55:34.138 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-01 13:55:41.832 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 59: ZWaveCommandClassTransactionPayload - send to node
2019-09-01 13:55:41.835 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 59: SECURITY not supported
2019-09-01 13:55:41.837 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 59: Command Class COMMAND_CLASS_METER is NOT required to be secured
2019-09-01 13:55:41.839 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 59: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@f478e
2019-09-01 13:55:41.841 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 59: Adding to device queue
2019-09-01 13:55:41.844 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 59: Added 243 to queue - size 40
2019-09-01 13:55:41.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-01 13:55:59.134 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 15: TID 241: Timeout at state WAIT_DATA. 3 retries remaining.
2019-09-01 13:55:59.138 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 241: Transaction is current transaction, so clearing!!!!!
2019-09-01 13:55:59.141 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 241: Transaction CANCELLED
2019-09-01 13:55:59.143 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: notifyTransactionResponse TID:241 CANCELLED
2019-09-01 13:55:59.147 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 13:55:59.147 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 241: Transaction event listener: DONE: CANCELLED -> 
2019-09-01 13:55:59.153 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 13 02 26 02 25 57 A2 
2019-09-01 13:55:59.153 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node Init response (4) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@76bec6
2019-09-01 13:55:59.157 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 19: Sending REQUEST Message = 01 09 00 13 13 02 26 02 25 57 A2 
2019-09-01 13:55:59.158 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: No data from device, but it was ACK'd. Possibly not supported? (Try 4)
2019-09-01 13:55:59.161 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-01 13:55:59.163 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node Init transaction retries exceeded
2019-09-01 13:55:59.164 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 240: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 87
2019-09-01 13:55:59.167 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node advancer: Restored from file - skipping static initialisation
2019-09-01 13:55:59.171 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node advancer - advancing to STATIC_END
2019-09-01 13:55:59.174 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 15: Serialise aborted as static stages not complete
2019-09-01 13:55:59.177 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node advancer - advancing to DYNAMIC_VALUES
2019-09-01 13:55:59.180 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_MANUFACTURER_SPECIFIC
2019-09-01 13:55:59.183 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_POWERLEVEL
2019-09-01 13:55:59.185 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Found 1 instances of COMMAND_CLASS_POWERLEVEL for endpoint 0
2019-09-01 13:55:59.190 [DEBUG] [andclass.ZWavePowerLevelCommandClass] - NODE 15: Creating new message for application command POWERLEVEL_GET
2019-09-01 13:55:59.192 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: SECURITY not supported
2019-09-01 13:55:59.196 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Command Class COMMAND_CLASS_POWERLEVEL is NOT required to be secured
2019-09-01 13:55:59.198 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: ZWaveCommandClassTransactionPayload - send to node
2019-09-01 13:55:59.202 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: SECURITY not supported
2019-09-01 13:55:59.204 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Command Class COMMAND_CLASS_POWERLEVEL is NOT required to be secured
2019-09-01 13:55:59.208 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@bfa94
2019-09-01 13:55:59.211 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Adding to device queue
2019-09-01 13:55:59.215 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Added 244 to queue - size 40
2019-09-01 13:55:59.217 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-01 13:56:01.168 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 19: TID 240: Timeout at state WAIT_RESPONSE. 3 retries remaining.
2019-09-01 13:56:01.170 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction!
2019-09-01 13:56:01.172 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 240: Transaction ABORTED
2019-09-01 13:56:01.176 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 
2019-09-01 13:56:01.179 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 
2019-09-01 13:56:01.182 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-01 13:56:01.185 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-01 13:56:13.175 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 19: TID 240: Timeout at state ABORTED. 3 retries remaining.
2019-09-01 13:56:13.177 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 240: Transaction is current transaction, so clearing!!!!!
2019-09-01 13:56:13.179 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 240: Transaction CANCELLED
2019-09-01 13:56:13.180 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-09-01 13:56:13.182 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 19: notifyTransactionResponse TID:240 CANCELLED
2019-09-01 13:56:13.184 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 13:56:13.184 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 240: Transaction event listener: DONE: CANCELLED -> 
2019-09-01 13:56:13.187 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 13 02 04 31 04 03 00 25 58 AA 
2019-09-01 13:56:13.188 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 19: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1b8c976
2019-09-01 13:56:13.192 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 19: Node Init transaction completed with response COMPLETE
2019-09-01 13:56:13.192 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0B 00 13 02 04 31 04 03 00 25 58 AA 
2019-09-01 13:56:13.195 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-01 13:56:13.194 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 19: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_DEVICE_RESET_LOCALLY
2019-09-01 13:56:13.198 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 242: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 88
2019-09-01 13:56:13.198 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 19: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_VERSION
2019-09-01 13:56:13.200 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 19: Node advancer: Initialisation complete!
2019-09-01 13:56:13.202 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 19: Node advancer - advancing to DYNAMIC_END
2019-09-01 13:56:13.204 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2019-09-01 13:56:13.207 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 19: Serializing to file /var/lib/openhab2/zwave/network_ef958966__node_19.xml
2019-09-01 13:56:13.241 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 19: Node advancer - advancing to DONE
2019-09-01 13:56:13.243 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2019-09-01 13:56:13.246 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 19: Serializing to file /var/lib/openhab2/zwave/network_ef958966__node_19.xml
2019-09-01 13:56:15.201 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 2: TID 242: Timeout at state WAIT_RESPONSE. 3 retries remaining.
2019-09-01 13:56:15.204 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction!
2019-09-01 13:56:15.207 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 242: Transaction ABORTED
2019-09-01 13:56:15.212 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 
2019-09-01 13:56:15.215 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 
2019-09-01 13:56:15.220 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-01 13:56:15.222 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-01 13:56:19.687 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 79: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1a182bb
2019-09-01 13:56:19.690 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 79: Adding to device queue
2019-09-01 13:56:19.692 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 79: Added 245 to queue - size 40
2019-09-01 13:56:19.694 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.












2019-09-01 13:56:27.212 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 2: TID 242: Timeout at state ABORTED. 3 retries remaining.
2019-09-01 13:56:27.215 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 242: Transaction is current transaction, so clearing!!!!!
2019-09-01 13:56:27.218 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 242: Transaction CANCELLED
2019-09-01 13:56:27.222 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-09-01 13:56:27.225 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:242 CANCELLED
2019-09-01 13:56:27.229 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 13:56:27.229 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 242: Transaction event listener: DONE: CANCELLED -> 
2019-09-01 13:56:27.234 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1940567
2019-09-01 13:56:27.235 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 60 4F D4 
2019-09-01 13:56:27.238 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init transaction completed with response COMPLETE
2019-09-01 13:56:27.241 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2019-09-01 13:56:27.240 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 60 4F D4 
2019-09-01 13:56:27.244 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_SENSOR_MULTILEVEL is NOT required to be secured
2019-09-01 13:56:27.245 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-01 13:56:27.250 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 245: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-09-01 13:56:27.255 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: ZWaveCommandClassTransactionPayload - send to node
2019-09-01 13:56:27.267 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2019-09-01 13:56:27.271 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_SENSOR_MULTILEVEL is NOT required to be secured
2019-09-01 13:56:27.274 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@d5d956
2019-09-01 13:56:27.277 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2019-09-01 13:56:27.282 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 246 to queue - size 40
2019-09-01 13:56:27.285 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-01 13:56:29.254 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 79: TID 245: Timeout at state WAIT_RESPONSE. 3 retries remaining.
2019-09-01 13:56:29.255 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 245: Transaction is current transaction, so clearing!!!!!
2019-09-01 13:56:29.258 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 245: Transaction CANCELLED
2019-09-01 13:56:29.260 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 79: notifyTransactionResponse TID:245 CANCELLED
2019-09-01 13:56:29.263 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 13:56:29.263 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 245: Transaction event listener: DONE: CANCELLED -> 
2019-09-01 13:56:29.266 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 79: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@101b7d9
2019-09-01 13:56:29.267 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 3B 03 32 01 18 25 59 89 
2019-09-01 13:56:29.270 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 59: Sending REQUEST Message = 01 0A 00 13 3B 03 32 01 18 25 59 89 
2019-09-01 13:56:29.272 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-01 13:56:29.286 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 243: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 89
2019-09-01 13:56:31.288 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 59: TID 243: Timeout at state WAIT_RESPONSE. 3 retries remaining.
2019-09-01 13:56:31.293 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction!
2019-09-01 13:56:31.297 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 243: Transaction ABORTED
2019-09-01 13:56:31.301 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 
2019-09-01 13:56:31.306 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 
2019-09-01 13:56:31.309 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-01 13:56:31.314 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.














2019-09-01 13:56:43.300 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 59: TID 243: Timeout at state ABORTED. 3 retries remaining.
2019-09-01 13:56:43.302 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 243: Transaction is current transaction, so clearing!!!!!
2019-09-01 13:56:43.304 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 243: Transaction CANCELLED
2019-09-01 13:56:43.305 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 59: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-09-01 13:56:43.307 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 59: notifyTransactionResponse TID:243 CANCELLED
2019-09-01 13:56:43.309 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 13:56:43.309 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 243: Transaction event listener: DONE: CANCELLED -> 
2019-09-01 13:56:43.312 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 13 02 04 31 04 04 00 25 5A AF 
2019-09-01 13:56:43.314 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0B 00 13 02 04 31 04 04 00 25 5A AF 
2019-09-01 13:56:43.317 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 59: Node Init response (3) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@670457
2019-09-01 13:56:43.319 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 59: Node Init transaction completed with response COMPLETE
2019-09-01 13:56:43.320 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 59: Node advancer: Initialisation complete!
2019-09-01 13:56:43.322 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 59: Node advancer - advancing to DYNAMIC_END
2019-09-01 13:56:43.324 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 59: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2019-09-01 13:56:43.325 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 59: Serializing to file /var/lib/openhab2/zwave/network_ef958966__node_59.xml
2019-09-01 13:56:43.370 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 59: Node advancer - advancing to DONE
2019-09-01 13:56:43.372 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 59: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2019-09-01 13:56:43.375 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 59: Serializing to file /var/lib/openhab2/zwave/network_ef958966__node_59.xml
2019-09-01 13:57:00.016 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-01 13:57:00.018 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 246: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 90
2019-09-01 13:57:00.018 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-09-01 13:57:00.020 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-01 13:57:00.022 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-01 13:57:00.024 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 246: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 90
2019-09-01 13:57:00.025 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-09-01 13:57:00.026 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 13:57:00.028 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-01 13:57:00.031 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2019-09-01 13:57:00.034 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-09-01 13:57:00.036 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-09-01 13:57:00.036 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 18
2019-09-01 13:57:00.037 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 246: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 90
2019-09-01 13:57:00.039 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-01 13:57:00.039 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=
2019-09-01 13:57:00.040 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 246: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 90
2019-09-01 13:57:00.042 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-09-01 13:57:00.042 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 18
2019-09-01 13:57:00.044 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2019-09-01 13:57:00.045 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=
2019-09-01 13:57:00.046 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 246: Advanced to WAIT_REQUEST
2019-09-01 13:57:00.047 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 246: Transaction not completed
2019-09-01 13:57:00.049 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (1): Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=
2019-09-01 13:57:00.048 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 18
2019-09-01 13:57:00.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=
2019-09-01 13:57:00.050 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 246: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 90
2019-09-01 13:57:00.053 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Holdoff Timer started...
2019-09-01 13:57:00.053 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 18
2019-09-01 13:57:00.054 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 246: Resetting transaction
2019-09-01 13:57:00.056 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:246 WAIT_REQUEST
2019-09-01 13:57:00.055 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 2<>126 : Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=
2019-09-01 13:57:00.058 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2019-09-01 13:57:00.060 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 246 to queue - size 39
2019-09-01 13:57:00.060 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 18
2019-09-01 13:57:00.062 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
2019-09-01 13:57:00.061 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 246: Transaction event listener: DONE: WAIT_REQUEST -> 
2019-09-01 13:57:00.063 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 3<>125 : Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=
2019-09-01 13:57:00.063 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (2): Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=
2019-09-01 13:57:00.066 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 13:57:00.066 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 18
2019-09-01 13:57:00.068 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (2): Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=
2019-09-01 13:57:00.063 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Completing UNINTIALIZED transaction 246!!! How?!?
2019-09-01 13:57:00.072 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 13:57:00.071 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 2<>126 : Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=
2019-09-01 13:57:00.072 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1331a98
2019-09-01 13:57:00.076 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (2): Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=
2019-09-01 13:57:00.075 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 18
2019-09-01 13:57:00.079 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 13:57:00.079 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 2<>126 : Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=
2019-09-01 13:57:00.082 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (2): Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=
2019-09-01 13:57:00.084 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 13:57:00.087 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (1): Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=
2019-09-01 13:57:00.084 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 3F 09 60 0D 00 01 5B 03 7D 00 01 8A 
2019-09-01 13:57:00.089 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 13:57:00.092 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=
2019-09-01 13:57:00.092 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=63, callback=0, payload=00 3F 09 60 0D 00 01 5B 03 7D 00 01 
2019-09-01 13:57:00.094 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 13:57:00.097 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=63, callback=0, payload=00 3F 09 60 0D 00 01 5B 03 7D 00 01 
2019-09-01 13:57:00.099 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 13:57:00.101 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 63: Application Command Request (ALIVE:REQUEST_NIF)
2019-09-01 13:57:00.103 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 63: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2019-09-01 13:57:00.105 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 63: Incoming command class COMMAND_CLASS_CENTRAL_SCENE, endpoint 0
2019-09-01 13:57:00.108 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 63: SECURITY not supported
2019-09-01 13:57:00.109 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 63: Received COMMAND_CLASS_CENTRAL_SCENE V2 CENTRAL_SCENE_NOTIFICATION
2019-09-01 13:57:00.112 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 63: Received scene 1 at key 0 [Single Press]
2019-09-01 13:57:00.115 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 63: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2019-09-01 13:57:00.117 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 63: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_CENTRAL_SCENE, value=1.0
2019-09-01 13:57:00.120 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 63: Updating channel state zwave:device:f21cd9de:node63:scene_number to 1.0 [DecimalType]
2019-09-01 13:57:00.127 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 63: Commands processed 1.
2019-09-01 13:57:00.129 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 63: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@354501.
2019-09-01 13:57:00.132 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 13:57:00.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-01 13:57:00.137 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 13:57:00.140 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
2019-09-01 13:57:00.246 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 57 00 00 16 AA 
2019-09-01 13:57:00.249 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=87, payload=57 00 00 16 
2019-09-01 13:57:00.251 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=87, payload=57 00 00 16 
2019-09-01 13:57:00.253 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-01 13:57:00.255 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
2019-09-01 13:57:00.257 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null
2019-09-01 13:57:00.258 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=87, payload=57 00 00 16 
2019-09-01 13:57:00.261 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 13:57:00.262 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
2019-09-01 13:57:00.306 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-01 13:57:00.309 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 13 02 04 31 04 04 00 25 5A AF 
2019-09-01 13:57:00.312 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0B 00 13 02 04 31 04 04 00 25 5A AF 
2019-09-01 13:57:00.315 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-01 13:57:00.317 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 246: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 90
2019-09-01 13:57:00.317 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-09-01 13:57:00.319 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-01 13:57:00.321 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-01 13:57:00.323 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 246: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 90
2019-09-01 13:57:00.324 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2019-09-01 13:57:00.325 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-09-01 13:57:00.327 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-09-01 13:57:00.328 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 13:57:00.330 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-01 13:57:00.332 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-09-01 13:57:00.336 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 246: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 90
2019-09-01 13:57:00.338 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-01 13:57:00.342 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 246: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 90
2019-09-01 13:57:00.345 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-09-01 13:57:00.349 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2019-09-01 13:57:00.351 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 246: Advanced to WAIT_REQUEST
2019-09-01 13:57:00.355 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 246: Transaction not completed
2019-09-01 13:57:00.358 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 13:57:00.361 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-01 13:57:00.377 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 5A 00 00 06 B7 
2019-09-01 13:57:00.382 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=90, payload=5A 00 00 06 
2019-09-01 13:57:00.385 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=90, payload=5A 00 00 06 
2019-09-01 13:57:00.388 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 246: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 90
2019-09-01 13:57:00.391 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-01 13:57:00.394 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 246: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 90
2019-09-01 13:57:00.397 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 246: (Callback 90)
2019-09-01 13:57:00.401 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-09-01 13:57:00.404 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 246: callback 90
2019-09-01 13:57:00.408 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=90, payload=5A 00 00 06 
2019-09-01 13:57:00.411 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 90, Status = Transmission complete and ACK received(0)
2019-09-01 13:57:00.415 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 246: Advanced to WAIT_DATA
2019-09-01 13:57:00.417 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 246: Transaction not completed
2019-09-01 13:57:00.421 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-01 13:57:00.423 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 13 03 26 03 00 C7 
2019-09-01 13:57:00.423 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-01 13:57:00.428 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=19, callback=0, payload=00 13 03 26 03 00 
2019-09-01 13:57:00.432 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=19, callback=0, payload=00 13 03 26 03 00 
2019-09-01 13:57:00.435 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

Same as before, lot’s of CAN and a 61 seconds delay for node 19:

1 Like