Z-wave problems... again...again

Add-ons Bindings
1
  • Platform information:
    • OS: Debian 9.4 64-bit
    • Java Runtime Environment: openjdk version “1.8.0_181” OpenJDK Runtime Environment (build 1.8.0_181-8u181-b13-1~deb9u1-b13)
    • openHAB version: 2.3.0
    • z-wave version: 2.4.0.201809081506
    • z-wave controller: aeotec gen5

HI all,

Some time has passed and I have been happy with my OH install. Z-wave started working after installing the 2.4 version. Thanks Chris and everyone who works with this!
But since then I’ve extended the network with a multisensor (MH9-CO2-WD CO2 Monitor Air quality detector) and everything worked nicely until the sensor stoped reporting values. I cant understand by the logs what the problem is. Can someone point me in the right direction? The sensor is Node 6.
It all goes south after the healing of the network. The log starts with the last value update from the sensor. After this its all “NODE 6: Polling deferred until initialisation complete”
Thanks!

Log;

13-Nov-2018 23:59:15.839 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
13-Nov-2018 23:59:15.839 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
14-Nov-2018 00:01:11.682 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 06 06 31 05 11 02 03 36 E5 
14-Nov-2018 00:01:11.683 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=6, callback=0, payload=00 06 06 31 05 11 02 03 36 
14-Nov-2018 00:01:11.684 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=ApplicationCommandHandler[4], type=Request[0], dest=6, callback=0, payload=00 06 06 31 05 11 02 03 36 
14-Nov-2018 00:01:11.685 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=6, callback=0, payload=00 06 06 31 05 11 02 03 36 
14-Nov-2018 00:01:11.685 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction null
14-Nov-2018 00:01:11.685 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 6: Application Command Request (ALIVE:DONE)
14-Nov-2018 00:01:11.685 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 6: resetResendCount initComplete=true isDead=false
14-Nov-2018 00:01:11.685 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 6: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
14-Nov-2018 00:01:11.685 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 6: SECURITY not supported
14-Nov-2018 00:01:11.685 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 6: Received COMMAND_CLASS_SENSOR_MULTILEVEL V5 SENSOR_MULTILEVEL_REPORT
14-Nov-2018 00:01:11.686 [DEBUG] [col.commandclass.ZWaveMultiLevelSensorCommandClass] - NODE 6: Sensor Type = CO2(17), Scale = 0
14-Nov-2018 00:01:11.686 [DEBUG] [col.commandclass.ZWaveMultiLevelSensorCommandClass] - NODE 6: Sensor Value = 822
14-Nov-2018 00:01:11.686 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
14-Nov-2018 00:01:11.686 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 6: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_SENSOR_MULTILEVEL, value = 822
14-Nov-2018 00:01:11.686 [DEBUG] [.internal.converter.ZWaveMultiLevelSensorConverter] - NODE 6: Sensor conversion not performed for CO2.
14-Nov-2018 00:01:11.686 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 6: Updating channel state zwave:device:dd005807:node6:sensor_co2 to 822 [DecimalType]
14-Nov-2018 00:01:11.689 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 6: Commands processed 1.
14-Nov-2018 00:01:11.689 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 6: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@7503f96c.
14-Nov-2018 00:01:11.690 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
14-Nov-2018 00:01:11.690 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
14-Nov-2018 00:01:11.691 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
14-Nov-2018 00:01:11.691 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
14-Nov-2018 00:27:01.928 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling...
14-Nov-2018 00:27:01.928 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling zwave:device:dd005807:node2:switch_binary
14-Nov-2018 00:27:01.928 [DEBUG] [wave.internal.converter.ZWaveBinarySwitchConverter] - NODE 2: Generating poll message for COMMAND_CLASS_SWITCH_BINARY, endpoint 0
14-Nov-2018 00:27:01.928 [DEBUG] [rotocol.commandclass.ZWaveBinarySwitchCommandClass] - NODE 2: Creating new message for application command SWITCH_BINARY_GET
14-Nov-2018 00:27:01.929 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
14-Nov-2018 00:27:01.929 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_SWITCH_BINARY is NOT required to be secured
14-Nov-2018 00:27:01.929 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling skipped for zwave:device:dd005807:node2:switch_binary on COMMAND_CLASS_BASIC
14-Nov-2018 00:27:01.929 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
14-Nov-2018 00:27:01.929 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
14-Nov-2018 00:27:01.930 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 02 02 25 02 25 BF 58 
14-Nov-2018 00:27:01.930 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 09 00 13 02 02 25 02 25 BF 58 
14-Nov-2018 00:27:01.930 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 4: Polling...
14-Nov-2018 00:27:01.930 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 4: Polling zwave:device:dd005807:node4:switch_binary
14-Nov-2018 00:27:01.930 [DEBUG] [wave.internal.converter.ZWaveBinarySwitchConverter] - NODE 4: Generating poll message for COMMAND_CLASS_SWITCH_BINARY, endpoint 0
14-Nov-2018 00:27:01.931 [DEBUG] [rotocol.commandclass.ZWaveBinarySwitchCommandClass] - NODE 4: Creating new message for application command SWITCH_BINARY_GET
14-Nov-2018 00:27:01.931 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 4: SECURITY not supported
14-Nov-2018 00:27:01.931 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 4: Command Class COMMAND_CLASS_SWITCH_BINARY is NOT required to be secured
14-Nov-2018 00:27:01.931 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 4: Polling skipped for zwave:device:dd005807:node4:switch_binary on COMMAND_CLASS_BASIC
14-Nov-2018 00:27:02.392 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
14-Nov-2018 00:27:02.392 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 206: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 191
14-Nov-2018 00:27:02.393 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 4: Adding to device queue
14-Nov-2018 00:27:02.393 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
14-Nov-2018 00:27:04.394 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 2: TID 206: Timeout at state WAIT_RESPONSE. 3 retries remaining.
14-Nov-2018 00:27:04.394 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - Aborting Transaction!
14-Nov-2018 00:27:04.394 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 206: Transaction ABORTED
14-Nov-2018 00:27:04.394 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 
14-Nov-2018 00:27:04.394 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 
14-Nov-2018 00:27:04.398 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
14-Nov-2018 00:27:04.398 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
14-Nov-2018 00:27:16.394 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 2: TID 206: Timeout at state ABORTED. 3 retries remaining.
14-Nov-2018 00:27:16.394 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - TID 206: Transaction is current transaction, so clearing!!!!!
14-Nov-2018 00:27:16.394 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 206: Transaction CANCELLED
14-Nov-2018 00:27:16.394 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
14-Nov-2018 00:27:16.394 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:206 CANCELLED
14-Nov-2018 00:27:16.395 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
14-Nov-2018 00:27:16.395 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 04 02 25 02 25 C0 21 
14-Nov-2018 00:27:16.396 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 4: Sending REQUEST Message = 01 09 00 13 04 02 25 02 25 C0 21 
14-Nov-2018 00:27:16.455 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
14-Nov-2018 00:27:16.455 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 207: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 192
14-Nov-2018 00:27:18.455 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 4: TID 207: Timeout at state WAIT_RESPONSE. 3 retries remaining.
14-Nov-2018 00:27:18.456 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - Aborting Transaction!
14-Nov-2018 00:27:18.457 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 207: Transaction ABORTED
14-Nov-2018 00:27:18.457 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 
14-Nov-2018 00:27:18.458 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 
14-Nov-2018 00:27:18.463 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
14-Nov-2018 00:27:18.464 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
14-Nov-2018 00:27:27.040 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling...
14-Nov-2018 00:27:27.040 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling zwave:device:dd005807:node6:sensor_temperature
14-Nov-2018 00:27:27.040 [DEBUG] [.internal.converter.ZWaveMultiLevelSensorConverter] - NODE 6: Generating poll message for COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
14-Nov-2018 00:27:27.040 [DEBUG] [col.commandclass.ZWaveMultiLevelSensorCommandClass] - NODE 6: Creating new message for command SENSOR_MULTILEVEL_GET
14-Nov-2018 00:27:27.041 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 6: SECURITY not supported
14-Nov-2018 00:27:27.041 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 6: Command Class COMMAND_CLASS_SENSOR_MULTILEVEL is NOT required to be secured
14-Nov-2018 00:27:27.041 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling zwave:device:dd005807:node6:sensor_relhumidity
14-Nov-2018 00:27:27.041 [DEBUG] [.internal.converter.ZWaveMultiLevelSensorConverter] - NODE 6: Generating poll message for COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
14-Nov-2018 00:27:27.041 [DEBUG] [col.commandclass.ZWaveMultiLevelSensorCommandClass] - NODE 6: Creating new message for command SENSOR_MULTILEVEL_GET
14-Nov-2018 00:27:27.041 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 6: SECURITY not supported
14-Nov-2018 00:27:27.041 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 6: Command Class COMMAND_CLASS_SENSOR_MULTILEVEL is NOT required to be secured
14-Nov-2018 00:27:27.041 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling zwave:device:dd005807:node6:sensor_co2
14-Nov-2018 00:27:27.041 [DEBUG] [.internal.converter.ZWaveMultiLevelSensorConverter] - NODE 6: Generating poll message for COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
14-Nov-2018 00:27:27.042 [DEBUG] [col.commandclass.ZWaveMultiLevelSensorCommandClass] - NODE 6: Creating new message for command SENSOR_MULTILEVEL_GET
14-Nov-2018 00:27:27.042 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 6: SECURITY not supported
14-Nov-2018 00:27:27.042 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 6: Command Class COMMAND_CLASS_SENSOR_MULTILEVEL is NOT required to be secured
14-Nov-2018 00:27:27.042 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 6: Adding to device queue
14-Nov-2018 00:27:27.042 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
14-Nov-2018 00:27:27.042 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 6: Adding to device queue
14-Nov-2018 00:27:27.042 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
14-Nov-2018 00:27:27.042 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 6: Adding to device queue
14-Nov-2018 00:27:27.043 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
14-Nov-2018 00:27:30.457 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 4: TID 207: Timeout at state ABORTED. 3 retries remaining.
14-Nov-2018 00:27:30.457 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - TID 207: Transaction is current transaction, so clearing!!!!!
14-Nov-2018 00:27:30.458 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 207: Transaction CANCELLED
14-Nov-2018 00:27:30.458 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 4: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
14-Nov-2018 00:27:30.458 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 4: notifyTransactionResponse TID:207 CANCELLED
14-Nov-2018 00:27:30.458 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
14-Nov-2018 00:27:30.459 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 13 06 04 31 04 01 00 25 C1 35 
14-Nov-2018 00:27:30.459 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 0B 00 13 06 04 31 04 01 00 25 C1 35 
14-Nov-2018 00:27:30.515 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
14-Nov-2018 00:27:30.516 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 208: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 193
14-Nov-2018 00:27:32.516 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 6: TID 208: Timeout at state WAIT_RESPONSE. 3 retries remaining.
14-Nov-2018 00:27:32.517 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - Aborting Transaction!
14-Nov-2018 00:27:32.518 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 208: Transaction ABORTED
14-Nov-2018 00:27:32.518 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 
14-Nov-2018 00:27:32.519 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 
14-Nov-2018 00:27:32.520 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
14-Nov-2018 00:27:32.520 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
14-Nov-2018 00:27:44.518 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 6: TID 208: Timeout at state ABORTED. 3 retries remaining.
14-Nov-2018 00:27:44.518 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - TID 208: Transaction is current transaction, so clearing!!!!!
14-Nov-2018 00:27:44.519 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 208: Transaction CANCELLED
14-Nov-2018 00:27:44.519 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
14-Nov-2018 00:27:44.519 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 6: notifyTransactionResponse TID:208 CANCELLED
14-Nov-2018 00:27:44.519 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
14-Nov-2018 00:27:44.520 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 13 06 04 31 04 05 00 25 C2 32 
14-Nov-2018 00:27:44.520 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 0B 00 13 06 04 31 04 05 00 25 C2 32 
14-Nov-2018 00:27:44.571 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
14-Nov-2018 00:27:44.572 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 209: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 194
14-Nov-2018 00:27:46.572 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 6: TID 209: Timeout at state WAIT_RESPONSE. 3 retries remaining.
14-Nov-2018 00:27:46.572 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - Aborting Transaction!
14-Nov-2018 00:27:46.572 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 209: Transaction ABORTED
14-Nov-2018 00:27:46.573 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 
14-Nov-2018 00:27:46.573 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 
14-Nov-2018 00:27:46.576 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
14-Nov-2018 00:27:46.577 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
14-Nov-2018 00:27:58.572 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 6: TID 209: Timeout at state ABORTED. 3 retries remaining.
14-Nov-2018 00:27:58.572 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - TID 209: Transaction is current transaction, so clearing!!!!!
14-Nov-2018 00:27:58.572 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 209: Transaction CANCELLED
14-Nov-2018 00:27:58.572 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
14-Nov-2018 00:27:58.572 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 6: notifyTransactionResponse TID:209 CANCELLED
14-Nov-2018 00:27:58.573 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
14-Nov-2018 00:27:58.573 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 13 06 04 31 04 11 00 25 C3 27 
14-Nov-2018 00:27:58.574 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 0B 00 13 06 04 31 04 11 00 25 C3 27 
14-Nov-2018 00:27:58.626 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
14-Nov-2018 00:27:58.626 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 210: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 195
14-Nov-2018 00:28:00.626 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 6: TID 210: Timeout at state WAIT_RESPONSE. 3 retries remaining.
14-Nov-2018 00:28:00.626 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - Aborting Transaction!
14-Nov-2018 00:28:00.626 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 210: Transaction ABORTED
14-Nov-2018 00:28:00.626 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 
14-Nov-2018 00:28:00.626 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 
14-Nov-2018 00:28:00.628 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
14-Nov-2018 00:28:00.628 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
14-Nov-2018 00:28:12.626 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 6: TID 210: Timeout at state ABORTED. 3 retries remaining.
14-Nov-2018 00:28:12.627 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - TID 210: Transaction is current transaction, so clearing!!!!!
14-Nov-2018 00:28:12.627 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 210: Transaction CANCELLED
14-Nov-2018 00:28:12.627 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
14-Nov-2018 00:28:12.627 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 6: notifyTransactionResponse TID:210 CANCELLED
14-Nov-2018 00:28:12.628 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
14-Nov-2018 00:29:15.252 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Polling...
14-Nov-2018 00:29:15.252 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Polling zwave:device:dd005807:node5:switch_dimmer
14-Nov-2018 00:29:15.252 [DEBUG] [.internal.converter.ZWaveMultiLevelSwitchConverter] - NODE 5: Generating poll message for COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0
14-Nov-2018 00:29:15.253 [DEBUG] [col.commandclass.ZWaveMultiLevelSwitchCommandClass] - NODE 5: Creating new message for command SWITCH_MULTILEVEL_GET
14-Nov-2018 00:29:15.253 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY NOT required on COMMAND_CLASS_SWITCH_MULTILEVEL
14-Nov-2018 00:29:15.253 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 5: Command Class COMMAND_CLASS_SWITCH_MULTILEVEL is NOT required to be secured
14-Nov-2018 00:29:15.253 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Polling skipped for zwave:device:dd005807:node5:switch_dimmer on COMMAND_CLASS_BASIC
14-Nov-2018 00:29:15.253 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 5: Adding to device queue
14-Nov-2018 00:29:15.253 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
14-Nov-2018 00:29:15.253 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 05 02 26 02 25 C4 27 
14-Nov-2018 00:29:15.254 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 09 00 13 05 02 26 02 25 C4 27 
14-Nov-2018 00:29:15.796 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
14-Nov-2018 00:29:15.797 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 211: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 196
14-Nov-2018 00:29:17.797 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 5: TID 211: Timeout at state WAIT_RESPONSE. 3 retries remaining.
14-Nov-2018 00:29:17.797 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - Aborting Transaction!
14-Nov-2018 00:29:17.798 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 211: Transaction ABORTED
14-Nov-2018 00:29:17.798 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 
14-Nov-2018 00:29:17.798 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 
14-Nov-2018 00:29:17.801 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
14-Nov-2018 00:29:17.802 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
14-Nov-2018 00:29:29.798 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 5: TID 211: Timeout at state ABORTED. 3 retries remaining.
14-Nov-2018 00:29:29.799 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - TID 211: Transaction is current transaction, so clearing!!!!!
14-Nov-2018 00:29:29.799 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 211: Transaction CANCELLED
2

The initialisation seems to be spreading…

14-Nov-2018 20:55:22.430 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 581: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 58
14-Nov-2018 20:55:27.430 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 4: TID 581: Timeout at state WAIT_REQUEST. 3 retries remaining.
14-Nov-2018 20:55:27.430 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - TID 581: Transaction is current transaction, so clearing!!!!!
14-Nov-2018 20:55:27.430 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 581: Transaction CANCELLED
14-Nov-2018 20:55:27.431 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 4: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
14-Nov-2018 20:55:27.431 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 4: notifyTransactionResponse TID:581 CANCELLED
14-Nov-2018 20:55:27.431 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
14-Nov-2018 20:55:27.431 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 581: Transaction event listener: DONE: CANCELLED ->
14-Nov-2018 20:55:27.432 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 4: -- To notify -- TIMEOUT_WAITING_FOR_RESPONSE
14-Nov-2018 20:55:27.432 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ********* Transaction Response Complete -- 581 --
14-Nov-2018 20:55:27.432 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 4: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1e39c88
14-Nov-2018 20:55:30.713 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 6: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@6d32422e
14-Nov-2018 20:55:30.713 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 6: Adding to device queue
14-Nov-2018 20:55:30.713 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
14-Nov-2018 20:55:30.713 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 48 06 3B 8F
14-Nov-2018 20:55:30.713 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 48 06 3B 8F
14-Nov-2018 20:55:31.475 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
14-Nov-2018 20:55:31.476 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 582: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 59
14-Nov-2018 20:55:36.476 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 6: TID 582: Timeout at state WAIT_REQUEST. 3 retries remaining.
14-Nov-2018 20:55:36.476 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - TID 582: Transaction is current transaction, so clearing!!!!!
14-Nov-2018 20:55:36.476 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 582: Transaction CANCELLED
14-Nov-2018 20:55:36.477 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
14-Nov-2018 20:55:36.477 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 6: notifyTransactionResponse TID:582 CANCELLED
14-Nov-2018 20:55:36.477 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
14-Nov-2018 20:55:36.477 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 582: Transaction event listener: DONE: CANCELLED ->
14-Nov-2018 20:55:36.478 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 6: -- To notify -- TIMEOUT_WAITING_FOR_RESPONSE
14-Nov-2018 20:55:36.478 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ********* Transaction Response Complete -- 582 --
14-Nov-2018 20:55:36.478 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 6: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@a767b4b
14-Nov-2018 20:57:27.040 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling...
14-Nov-2018 20:57:27.040 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling deferred until initialisation complete
14-Nov-2018 20:59:28.542 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Polling...
14-Nov-2018 20:59:28.542 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Polling deferred until initialisation complete
3

There are no messages being received from the dongle, so something has happened with the port or dongle it seems.

4

Thanks for your response.
But the networks seems to be alive and working. I have some light switches that is still doing its thing correctly.
Its only the sensor that stoped reporting values…

5

Have you filtered the log at all? The log shows only one message received at the beginning of the log from the dongle - after that there is nothing - not even acks to messages that it sends.

6

I’m embarrassed to say that I don’t really know. I’ve used this to log to a separate file:

log4j2.logger.zwave.name = org.openhab.binding.zwave
log4j2.logger.zwave.level = DEBUG
log4j2.logger.zwave.additivity = false
log4j2.logger.zwave.appenderRefs = zwave
log4j2.logger.zwave.appenderRef.zwave.ref = zwave
log4j2.appender.zwave.name = zwave
log4j2.appender.zwave.type = RollingRandomAccessFile
log4j2.appender.zwave.fileName = /var/log/openhab2/zwave.log
log4j2.appender.zwave.filePattern = /var/log/openhab2/zwave.log.%i
log4j2.appender.zwave.immediateFlush = true
log4j2.appender.zwave.append = true
log4j2.appender.zwave.layout.type = PatternLayout
log4j2.appender.zwave.layout.pattern = %d{dd-MMM-yyyy HH:mm:ss.SSS} [%-5.5p] [%-50.50c] - %m%n
log4j2.appender.zwave.policies.type = Policies
log4j2.appender.zwave.policies.size.type = SizeBasedTriggeringPolicy
log4j2.appender.zwave.policies.size.size = 1000MB
log4j2.appender.zwave.strategy.type = DefaultRolloverStrategy

And to logs I’ve posted are direct cut outs of this.

7

After some more digging in the logs i found

2018-11-15 13:47:37.419 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-binding-http1, openhab-ui-homebuilder, openhab-persistence-jdbc-mariadb, openhab-ui-habpanel, openhab-binding-zwave, openhab-binding-dscalarm, openhab-ui-basic, openhab-transformation-map, openhab-binding-astro, openhab-binding-tellstick, openhab-ui-habmin, openhab-binding-expire1, openhab-ui-paper': Error restarting bundles:
Could not resolve module: org.openhab.binding.zwave [210]
  Another singleton bundle selected: osgi.identity; osgi.identity="org.openhab.binding.zwave"; type="osgi.bundle"; version:Version="2.4.0.201808271154"; singleton:="true"

and when running

openhab> bundle:list|grep -i zwave
189 │ Active    │  80 │ 2.4.0.201808271154     │ ZWave Binding
210 │ Installed │  80 │ 2.3.0                  │ ZWave Binding

It seems that the 2.3.0 version is still around and maybe creates problems. I’ve removed it and cleaned the cache but it still reoccurs every time I restart. I have to read more into geting rid of this…

8

I had a version of the z-wave 2.4.0 binding in the addon folder, creating problems. Sorry for being such a noob :slight_smile:
It’s gone now and I will resume operations and hopes that this problem is gone. Do i need to remove the whole z-wave folder or can I still use it (/var/lib/openhab2/zwave/)?

9

I stared a new thread as the fault has evolved…