Z-Wave Controller doesn't send commands but receives

Knightshift · December 1, 2018, 4:36pm

Hi there,

I have a lot of z-wave sensors an actors and nearly every time I restart openhab I encounter a problem. After the restart, openhab seems not to send send commands to my actors (e.g. wall plugs). If I switch them on or off with openhab, nothing happens. Interestingly, openhab receives messages as from motion sensors or power meter information from the plugs.
I use openhab 2.4, my controller is a aeotec z-stick gen.5 usb stick.

To solve the problem, I restart openhab several times, unplug und plug the controller back in several times until everything works fine again.

This issue occurs since moths and over different versions of OP (I believe since 2.0) and versions of the z-wave binding.

Does anybody have an idea what could be the reason for this behavior or how to trace the problem?

Thanks

H102 · December 1, 2018, 4:45pm

Have you set the log to DEBUG or TRACE?

Knightshift · December 1, 2018, 4:49pm

I did try debug but actually didn’t see any kind of warning or error or something I could interpret as a cause. But honestly I don’t understand every line of the debugged log.

H102 · December 1, 2018, 4:53pm

Can’t say I understand all of it either, but posting it here, maybe someone else will.

The problem only happens when you restart OH, correct?

Knightshift · December 1, 2018, 4:56pm

Luckily the binding is running flawlessly and I don’t want to stop it at the moment.

Yes, it only happens after a restart, but not every time. The controller an all things are displayed as online.

H102 · December 1, 2018, 5:22pm

Do you have the USB port set to persist in startup? If not a restart may be causing the serial setting to reset.

Knightshift · December 1, 2018, 5:30pm

at first i thought of a problem with the usb-port, too. I have openhab running on a Mac and the USB port generally doesn’t change after a restart, only if I plug the switch it in another USB-port.

And since the controller is online and I receive messages from sensors, I don’t think that it has something to do with the port. If the port would have changed, I believe then none of the z-wave devices should work and the controller would be displayed as offline.

H102 · December 1, 2018, 5:42pm

Forgot that detail, I’m trying to multi-task,

You did mention setting the log to DEBUG, if it’s still in the log file you can post without having to restart.

lagging · December 1, 2018, 5:58pm

stabbing in the dark here, but what about disconnecting and reconnecting the command / actions channel, (however it is called in the z-wave binding things panel) ?

chris · December 1, 2018, 5:59pm

It’s very unlikely to make a difference.

If you have a debug log, please post it so that we can see what is going on…

Knightshift · December 2, 2018, 10:18am

Good morning,

this is a small extract of my log (there is a lot going on). I can’t post the whole log because it has way too much characters. If you need more, I somehow try to post the rest.

I hope this helps.

Tanks

log:set debug org.openhab.binding.zwave
openhab> log:tail
10:54:44.321 [INFO ] [smarthome.event.ItemCommandEvent     ] - Item 'TV' received command ON
10:54:44.322 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 6: Command received zwave:device:271e0fac:node6:switch_binary --> ON [OnOffType]
10:54:44.322 [INFO ] [arthome.event.ItemStatePredictedEvent] - TV predicted to become ON
10:54:44.324 [DEBUG] [ndclass.ZWaveBinarySwitchCommandClass] - NODE 6: Creating new message for application command SWITCH_BINARY_SET
10:54:44.325 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 6: SECURITY not supported
10:54:44.325 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 6: Command Class COMMAND_CLASS_SWITCH_BINARY is NOT required to be secured
10:54:44.325 [INFO ] [home.event.GroupItemStateChangedEvent] - geraete changed from OFF to ON through TV
10:54:44.325 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: Adding to device queue
10:54:44.326 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: Added 2055 to queue - size 19
10:54:44.326 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
10:54:44.326 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 06 03 25 01 FF 25 CB D6 
10:54:44.326 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 0A 00 13 06 03 25 01 FF 25 CB D6 
10:54:44.326 [INFO ] [smarthome.event.ItemStateChangedEvent] - TV changed from OFF to ON
10:54:44.327 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
10:54:44.328 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 2055: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 203
10:54:44.329 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
10:54:44.329 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling intialised at 86400 seconds - start in 1500 milliseconds.
10:54:44.329 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
10:54:44.330 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
10:54:44.330 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 2055: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 203
10:54:44.330 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK
10:54:44.330 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 00 E9 
10:54:44.330 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:54:44.331 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=00 
10:54:44.331 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
10:54:44.331 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=00 
10:54:44.332 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 2055: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 203
10:54:44.332 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
10:54:44.332 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 2055: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 203
10:54:44.332 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=00 
10:54:44.332 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 6: sentData was not placed on stack.
10:54:44.332 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 2055: Transaction CANCELLED
10:54:44.333 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Holdoff Timer started...
10:54:44.333 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
10:54:44.333 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: CANCEL while sending message. Requeueing - 2 attempts left!
10:54:44.333 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 2055: Transaction RESET with 2 retries remaining.
10:54:44.333 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: Adding to device queue
10:54:44.333 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: Added 2055 to queue - size 19
10:54:44.334 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
10:54:44.334 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: TID 2055: Transaction not completed
10:54:44.334 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:54:44.334 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
10:54:44.337 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 15 00 04 00 26 0F 32 02 21 64 00 05 33 6C F2 8E 00 00 00 00 00 94 
10:54:44.338 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=38, callback=0, payload=00 26 0F 32 02 21 64 00 05 33 6C F2 8E 00 00 00 00 00 
10:54:44.338 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=38, callback=0, payload=00 26 0F 32 02 21 64 00 05 33 6C F2 8E 00 00 00 00 00 
10:54:44.339 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
10:54:44.339 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Application Command Request (ALIVE:DONE)
10:54:44.339 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: resetResendCount initComplete=true isDead=false
10:54:44.339 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: Incoming command class COMMAND_CLASS_METER, endpoint 0
10:54:44.339 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: SECURITY not supported
10:54:44.339 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 38: Received COMMAND_CLASS_METER V3 METER_REPORT
10:54:44.340 [DEBUG] [l.commandclass.ZWaveMeterCommandClass] - NODE 38: Meter: Type=Electric(1), Scale=kWh(0), Value=340.844
10:54:44.340 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Got an event from Z-Wave network: ZWaveMeterValueEvent
10:54:44.340 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 340.844
10:54:44.340 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Updating channel state zwave:device:271e0fac:node38:meter_kwh to 340.844 [DecimalType]
10:54:44.341 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Commands processed 1.
10:54:44.341 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@3706810c.
10:54:44.342 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:44.342 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:44.343 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:54:44.344 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
10:54:44.497 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 15 00 04 00 36 0F 32 02 21 64 00 00 AC 85 C9 CB 00 00 00 00 00 89 
10:54:44.497 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=54, callback=0, payload=00 36 0F 32 02 21 64 00 00 AC 85 C9 CB 00 00 00 00 00 
10:54:44.498 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=54, callback=0, payload=00 36 0F 32 02 21 64 00 00 AC 85 C9 CB 00 00 00 00 00 
10:54:44.499 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
10:54:44.499 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 54: Application Command Request (ALIVE:DONE)
10:54:44.499 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 54: resetResendCount initComplete=true isDead=false
10:54:44.499 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 54: Incoming command class COMMAND_CLASS_METER, endpoint 0
10:54:44.499 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 54: SECURITY not supported
10:54:44.500 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 54: Received COMMAND_CLASS_METER V3 METER_REPORT
10:54:44.500 [DEBUG] [l.commandclass.ZWaveMeterCommandClass] - NODE 54: Meter: Type=Electric(1), Scale=kWh(0), Value=44.165
10:54:44.500 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 54: Got an event from Z-Wave network: ZWaveMeterValueEvent
10:54:44.500 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 54: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 44.165
10:54:44.501 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 54: Updating channel state zwave:device:271e0fac:node54:meter_kwh to 44.165 [DecimalType]
10:54:44.501 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 54: Commands processed 1.
10:54:44.502 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 54: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@30bc0845.
10:54:44.502 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:44.503 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:44.503 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:54:44.503 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
10:54:44.560 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 15 00 04 00 26 0F 32 02 21 64 00 05 33 6C F2 8E 00 00 00 00 00 94 
10:54:44.562 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=38, callback=0, payload=00 26 0F 32 02 21 64 00 05 33 6C F2 8E 00 00 00 00 00 
10:54:44.563 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=38, callback=0, payload=00 26 0F 32 02 21 64 00 05 33 6C F2 8E 00 00 00 00 00 
10:54:44.563 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
10:54:44.563 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Application Command Request (ALIVE:DONE)
10:54:44.563 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: resetResendCount initComplete=true isDead=false
10:54:44.563 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: Incoming command class COMMAND_CLASS_METER, endpoint 0
10:54:44.564 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: SECURITY not supported
10:54:44.564 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 38: Received COMMAND_CLASS_METER V3 METER_REPORT
10:54:44.564 [DEBUG] [l.commandclass.ZWaveMeterCommandClass] - NODE 38: Meter: Type=Electric(1), Scale=kWh(0), Value=340.844
10:54:44.564 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Got an event from Z-Wave network: ZWaveMeterValueEvent
10:54:44.564 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 340.844
10:54:44.565 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Updating channel state zwave:device:271e0fac:node38:meter_kwh to 340.844 [DecimalType]
10:54:44.565 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Commands processed 1.
10:54:44.565 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@4f07c55d.
10:54:44.566 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:44.567 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:44.567 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:54:44.567 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
10:54:44.588 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
10:54:44.589 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 06 03 25 01 FF 25 CC D1 
10:54:44.589 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 0A 00 13 06 03 25 01 FF 25 CC D1 
10:54:44.590 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
10:54:44.590 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 2055: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 204
10:54:44.591 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
10:54:44.592 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
10:54:44.592 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
10:54:44.593 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 2055: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 204
10:54:44.592 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 00 E9 
10:54:44.593 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK
10:54:44.593 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=00 
10:54:44.593 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:54:44.594 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
10:54:44.594 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=00 
10:54:44.594 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 2055: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 204
10:54:44.594 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
10:54:44.596 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 2055: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 204
10:54:44.597 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=00 
10:54:44.607 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 6: sentData was not placed on stack.
10:54:44.607 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 2055: Transaction CANCELLED
10:54:44.613 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Holdoff Timer started...
10:54:44.613 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
10:54:44.613 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: CANCEL while sending message. Requeueing - 1 attempts left!
10:54:44.613 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 2055: Transaction RESET with 1 retries remaining.
10:54:44.613 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: Adding to device queue
10:54:44.614 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: Added 2055 to queue - size 19
10:54:44.614 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
10:54:44.614 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: TID 2055: Transaction not completed
10:54:44.614 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:54:44.614 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
10:54:44.619 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 15 00 04 00 26 0F 32 02 21 64 00 05 33 6C F2 8F 00 00 00 00 00 95 
10:54:44.619 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=38, callback=0, payload=00 26 0F 32 02 21 64 00 05 33 6C F2 8F 00 00 00 00 00 
10:54:44.619 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=38, callback=0, payload=00 26 0F 32 02 21 64 00 05 33 6C F2 8F 00 00 00 00 00 
10:54:44.620 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
10:54:44.620 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Application Command Request (ALIVE:DONE)
10:54:44.620 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: resetResendCount initComplete=true isDead=false
10:54:44.620 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: Incoming command class COMMAND_CLASS_METER, endpoint 0
10:54:44.620 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: SECURITY not supported
10:54:44.620 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 38: Received COMMAND_CLASS_METER V3 METER_REPORT
10:54:44.621 [DEBUG] [l.commandclass.ZWaveMeterCommandClass] - NODE 38: Meter: Type=Electric(1), Scale=kWh(0), Value=340.844
10:54:44.621 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Got an event from Z-Wave network: ZWaveMeterValueEvent
10:54:44.621 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 340.844
10:54:44.621 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Updating channel state zwave:device:271e0fac:node38:meter_kwh to 340.844 [DecimalType]
10:54:44.622 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Commands processed 1.
10:54:44.622 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@16746b9.
10:54:44.623 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:44.623 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:44.623 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:54:44.624 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
10:54:44.811 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 15 00 04 00 36 0F 32 02 21 64 00 00 AC 85 C9 CB 00 00 00 00 00 89 
10:54:44.812 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=54, callback=0, payload=00 36 0F 32 02 21 64 00 00 AC 85 C9 CB 00 00 00 00 00 
10:54:44.812 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=54, callback=0, payload=00 36 0F 32 02 21 64 00 00 AC 85 C9 CB 00 00 00 00 00 
10:54:44.812 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
10:54:44.813 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 54: Application Command Request (ALIVE:DONE)
10:54:44.813 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 54: resetResendCount initComplete=true isDead=false
10:54:44.813 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 54: Incoming command class COMMAND_CLASS_METER, endpoint 0
10:54:44.813 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 54: SECURITY not supported
10:54:44.813 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 54: Received COMMAND_CLASS_METER V3 METER_REPORT
10:54:44.813 [DEBUG] [l.commandclass.ZWaveMeterCommandClass] - NODE 54: Meter: Type=Electric(1), Scale=kWh(0), Value=44.165
10:54:44.814 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 54: Got an event from Z-Wave network: ZWaveMeterValueEvent
10:54:44.814 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 54: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 44.165
10:54:44.814 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 54: Updating channel state zwave:device:271e0fac:node54:meter_kwh to 44.165 [DecimalType]
10:54:44.815 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 54: Commands processed 1.
10:54:44.815 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 54: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@2eaa978.
10:54:44.816 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:44.816 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:44.816 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:54:44.816 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
10:54:44.865 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
10:54:44.866 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 06 03 25 01 FF 25 CD D0 
10:54:44.866 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 0A 00 13 06 03 25 01 FF 25 CD D0 
10:54:44.867 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
10:54:44.867 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 2055: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 205
10:54:44.870 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 15 00 04 00 26 0F 32 02 21 64 00 05 33 6C F2 8F 00 00 00 00 00 95 
10:54:44.871 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=38, callback=0, payload=00 26 0F 32 02 21 64 00 05 33 6C F2 8F 00 00 00 00 00 
10:54:44.872 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 18
10:54:44.872 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=38, callback=0, payload=00 26 0F 32 02 21 64 00 05 33 6C F2 8F 00 00 00 00 00 
10:54:44.872 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 2055: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 205
10:54:44.872 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Application Command Request (ALIVE:DONE)
10:54:44.872 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=
10:54:44.873 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: resetResendCount initComplete=true isDead=false
10:54:44.873 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: Incoming command class COMMAND_CLASS_METER, endpoint 0
10:54:44.873 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: SECURITY not supported
10:54:44.873 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 38: Received COMMAND_CLASS_METER V3 METER_REPORT
10:54:44.873 [DEBUG] [l.commandclass.ZWaveMeterCommandClass] - NODE 38: Meter: Type=Electric(1), Scale=kWh(0), Value=340.844
10:54:44.874 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Got an event from Z-Wave network: ZWaveMeterValueEvent
10:54:44.874 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 340.844
10:54:44.874 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Updating channel state zwave:device:271e0fac:node38:meter_kwh to 340.844 [DecimalType]
10:54:44.875 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Commands processed 1.
10:54:44.875 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@52446740.
10:54:44.876 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
10:54:44.877 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
10:54:44.877 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=
10:54:44.878 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 2055: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 205
10:54:44.878 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Holdoff Timer started...
10:54:44.878 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 2055: Resetting transaction
10:54:44.879 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: notifyTransactionResponse TID:2055 WAIT_RESPONSE
10:54:44.879 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: Adding to device queue
10:54:44.879 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: Added 2055 to queue - size 19
10:54:44.879 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
10:54:44.880 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:54:44.880 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
10:54:44.997 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 15 00 04 00 36 0F 32 02 21 64 00 00 AC 85 C9 CB 00 00 00 00 00 89 
10:54:44.997 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=54, callback=0, payload=00 36 0F 32 02 21 64 00 00 AC 85 C9 CB 00 00 00 00 00 
10:54:44.998 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=54, callback=0, payload=00 36 0F 32 02 21 64 00 00 AC 85 C9 CB 00 00 00 00 00 
10:54:44.998 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
10:54:44.998 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 54: Application Command Request (ALIVE:DONE)
10:54:44.999 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 54: resetResendCount initComplete=true isDead=false
10:54:44.999 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 54: Incoming command class COMMAND_CLASS_METER, endpoint 0
10:54:44.999 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 54: SECURITY not supported
10:54:44.999 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 54: Received COMMAND_CLASS_METER V3 METER_REPORT
10:54:44.999 [DEBUG] [l.commandclass.ZWaveMeterCommandClass] - NODE 54: Meter: Type=Electric(1), Scale=kWh(0), Value=44.165
10:54:44.999 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 54: Got an event from Z-Wave network: ZWaveMeterValueEvent
10:54:45.000 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 54: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 44.165
10:54:45.000 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 54: Updating channel state zwave:device:271e0fac:node54:meter_kwh to 44.165 [DecimalType]
10:54:45.000 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 54: Commands processed 1.
10:54:45.001 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 54: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@23187d78.
10:54:45.002 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:45.002 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:45.002 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:54:45.002 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
10:54:45.121 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 15 00 04 00 26 0F 32 02 21 64 00 05 33 6C F2 8F 00 00 00 00 00 95 
10:54:45.121 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=38, callback=0, payload=00 26 0F 32 02 21 64 00 05 33 6C F2 8F 00 00 00 00 00 
10:54:45.122 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=38, callback=0, payload=00 26 0F 32 02 21 64 00 05 33 6C F2 8F 00 00 00 00 00 
10:54:45.122 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
10:54:45.122 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Application Command Request (ALIVE:DONE)
10:54:45.123 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: resetResendCount initComplete=true isDead=false
10:54:45.123 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: Incoming command class COMMAND_CLASS_METER, endpoint 0
10:54:45.123 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: SECURITY not supported
10:54:45.123 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 38: Received COMMAND_CLASS_METER V3 METER_REPORT
10:54:45.123 [DEBUG] [l.commandclass.ZWaveMeterCommandClass] - NODE 38: Meter: Type=Electric(1), Scale=kWh(0), Value=340.844
10:54:45.124 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Got an event from Z-Wave network: ZWaveMeterValueEvent
10:54:45.124 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 340.844
10:54:45.124 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Updating channel state zwave:device:271e0fac:node38:meter_kwh to 340.844 [DecimalType]
10:54:45.125 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Commands processed 1.
10:54:45.125 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1871b52c.
10:54:45.126 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:45.126 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:45.126 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:54:45.126 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
10:54:45.132 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
10:54:45.133 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 06 03 25 01 FF 25 CD D0 
10:54:45.133 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 0A 00 13 06 03 25 01 FF 25 CD D0 
10:54:45.134 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
10:54:45.134 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 2055: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 205
10:54:45.136 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
10:54:45.136 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
10:54:45.138 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 00 E9 
10:54:45.138 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
10:54:45.139 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 2055: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 205
10:54:45.139 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK
10:54:45.139 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:54:45.139 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
10:54:45.138 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=00 
10:54:45.140 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=00 
10:54:45.140 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 2055: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 205
10:54:45.140 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
10:54:45.140 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 2055: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 205
10:54:45.141 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=00 
10:54:45.141 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 6: sentData was not placed on stack.
10:54:45.141 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 2055: Transaction CANCELLED
10:54:45.141 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Holdoff Timer started...
10:54:45.142 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
10:54:45.142 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: Retry count exceeded. Discarding message: TID 2055: [CANCELLED] priority=Set, requiresResponse=true, callback: 205
10:54:45.142 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: TID 2055: Transaction completed
10:54:45.142 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: notifyTransactionResponse TID:2055 CANCELLED
10:54:45.142 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
10:54:45.143 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:54:45.143 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
10:54:45.247 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 15 00 04 00 36 0F 32 02 21 64 00 00 AC 85 C9 CC 00 00 00 00 00 8E 
10:54:45.247 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=54, callback=0, payload=00 36 0F 32 02 21 64 00 00 AC 85 C9 CC 00 00 00 00 00 
10:54:45.248 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=54, callback=0, payload=00 36 0F 32 02 21 64 00 00 AC 85 C9 CC 00 00 00 00 00 
10:54:45.248 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
10:54:45.248 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 54: Application Command Request (ALIVE:DONE)
10:54:45.249 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 54: resetResendCount initComplete=true isDead=false
10:54:45.249 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 54: Incoming command class COMMAND_CLASS_METER, endpoint 0
10:54:45.249 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 54: SECURITY not supported
10:54:45.249 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 54: Received COMMAND_CLASS_METER V3 METER_REPORT
10:54:45.249 [DEBUG] [l.commandclass.ZWaveMeterCommandClass] - NODE 54: Meter: Type=Electric(1), Scale=kWh(0), Value=44.165
10:54:45.250 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 54: Got an event from Z-Wave network: ZWaveMeterValueEvent
10:54:45.250 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 54: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 44.165
10:54:45.250 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 54: Updating channel state zwave:device:271e0fac:node54:meter_kwh to 44.165 [DecimalType]
10:54:45.251 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 54: Commands processed 1.
10:54:45.251 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 54: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@4f076e33.
10:54:45.252 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:45.252 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:45.252 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:54:45.252 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
10:54:45.371 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 15 00 04 00 26 0F 32 02 21 64 00 05 33 6C F2 8F 00 00 00 00 00 95 
10:54:45.371 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=38, callback=0, payload=00 26 0F 32 02 21 64 00 05 33 6C F2 8F 00 00 00 00 00 
10:54:45.372 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=38, callback=0, payload=00 26 0F 32 02 21 64 00 05 33 6C F2 8F 00 00 00 00 00 
10:54:45.372 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
10:54:45.373 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Application Command Request (ALIVE:DONE)
10:54:45.373 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: resetResendCount initComplete=true isDead=false
10:54:45.373 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: Incoming command class COMMAND_CLASS_METER, endpoint 0
10:54:45.373 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: SECURITY not supported
10:54:45.373 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 38: Received COMMAND_CLASS_METER V3 METER_REPORT
10:54:45.373 [DEBUG] [l.commandclass.ZWaveMeterCommandClass] - NODE 38: Meter: Type=Electric(1), Scale=kWh(0), Value=340.844
10:54:45.374 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Got an event from Z-Wave network: ZWaveMeterValueEvent
10:54:45.374 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 340.844
10:54:45.374 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Updating channel state zwave:device:271e0fac:node38:meter_kwh to 340.844 [DecimalType]
10:54:45.375 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Commands processed 1.
10:54:45.375 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@3e887ef4.
10:54:45.376 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:45.376 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:45.376 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:54:45.377 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
10:54:45.394 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
10:54:45.494 [INFO ] [smarthome.event.ItemStateChangedEvent] - iPhone_Tim_ResponseTime changed from 5013.0 to 5018.0
10:54:45.495 [INFO ] [smarthome.event.ItemStateChangedEvent] - iPhone_BeckyesponseTime changed from 5013.0 to 5018.0
10:54:45.496 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 15 00 04 00 36 0F 32 02 21 64 00 00 AC 85 C9 CC 00 00 00 00 00 8E 
10:54:45.497 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=54, callback=0, payload=00 36 0F 32 02 21 64 00 00 AC 85 C9 CC 00 00 00 00 00 
10:54:45.498 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=54, callback=0, payload=00 36 0F 32 02 21 64 00 00 AC 85 C9 CC 00 00 00 00 00 
10:54:45.498 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
10:54:45.498 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 54: Application Command Request (ALIVE:DONE)
10:54:45.498 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 54: resetResendCount initComplete=true isDead=false
10:54:45.498 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 54: Incoming command class COMMAND_CLASS_METER, endpoint 0
10:54:45.499 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 54: SECURITY not supported
10:54:45.499 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 54: Received COMMAND_CLASS_METER V3 METER_REPORT
10:54:45.499 [DEBUG] [l.commandclass.ZWaveMeterCommandClass] - NODE 54: Meter: Type=Electric(1), Scale=kWh(0), Value=44.165
10:54:45.499 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 54: Got an event from Z-Wave network: ZWaveMeterValueEvent
10:54:45.499 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 54: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 44.165
10:54:45.500 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 54: Updating channel state zwave:device:271e0fac:node54:meter_kwh to 44.165 [DecimalType]
10:54:45.500 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 54: Commands processed 1.
10:54:45.500 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 54: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@5e1b27e0.
10:54:45.502 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:45.502 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:45.502 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:54:45.502 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
10:54:45.621 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 15 00 04 00 25 0F 32 02 21 64 00 00 4D 5A C9 D0 00 00 00 00 00 BF 
10:54:45.622 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=37, callback=0, payload=00 25 0F 32 02 21 64 00 00 4D 5A C9 D0 00 00 00 00 00 
10:54:45.631 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 15 00 04 00 26 0F 32 02 21 64 00 05 33 6C F2 90 00 00 00 00 00 8A 
10:54:45.631 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=37, callback=0, payload=00 25 0F 32 02 21 64 00 00 4D 5A C9 D0 00 00 00 00 00 
10:54:45.632 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
10:54:45.632 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 37: Application Command Request (ALIVE:DONE)
10:54:45.632 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 37: resetResendCount initComplete=true isDead=false
10:54:45.632 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 37: Incoming command class COMMAND_CLASS_METER, endpoint 0
10:54:45.632 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 37: SECURITY not supported
10:54:45.633 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 37: Received COMMAND_CLASS_METER V3 METER_REPORT
10:54:45.633 [DEBUG] [l.commandclass.ZWaveMeterCommandClass] - NODE 37: Meter: Type=Electric(1), Scale=kWh(0), Value=19.802
10:54:45.633 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveMeterValueEvent
10:54:45.633 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 37: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 19.802
10:54:45.631 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=38, callback=0, payload=00 26 0F 32 02 21 64 00 05 33 6C F2 90 00 00 00 00 00 
10:54:45.633 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 37: Updating channel state zwave:device:271e0fac:node37:meter_kwh to 19.802 [DecimalType]
10:54:45.634 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 37: Commands processed 1.
10:54:45.634 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 37: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@4bd631da.
10:54:45.635 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:45.636 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
10:54:45.636 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=38, callback=0, payload=00 26 0F 32 02 21 64 00 05 33 6C F2 90 00 00 00 00 00 
10:54:45.636 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
10:54:45.636 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Application Command Request (ALIVE:DONE)
10:54:45.636 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: resetResendCount initComplete=true isDead=false
10:54:45.637 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: Incoming command class COMMAND_CLASS_METER, endpoint 0
10:54:45.637 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 38: SECURITY not supported
10:54:45.637 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 38: Received COMMAND_CLASS_METER V3 METER_REPORT
10:54:45.637 [DEBUG] [l.commandclass.ZWaveMeterCommandClass] - NODE 38: Meter: Type=Electric(1), Scale=kWh(0), Value=340.844
10:54:45.637 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Got an event from Z-Wave network: ZWaveMeterValueEvent
10:54:45.637 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 340.844
10:54:45.638 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 38: Updating channel state zwave:device:271e0fac:node38:meter_kwh to 340.844 [DecimalType]
10:54:45.638 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Commands processed 1.
10:54:45.639 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 38: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@3fd4a865.

Knightshift · January 12, 2019, 10:19am

Hi there,

I just updated to 2.5.0-SNAPSHOT but the problem remains. Controller receives signals e.g. from movement sensors or door/window contacts bit doesn’t send ON/OFF messages to any Wall Plug.

Looking into the debug log, I found the following lines

11:11:08.035 [INFO ] [smarthome.event.ItemCommandEvent ] - Item ‘TV’ received command ON
11:11:08.036 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 6: Command received zwave:device:271e0fac:node6:switch_binary → ON [OnOffType]
11:11:08.038 [DEBUG] [ndclass.ZWaveBinarySwitchCommandClass] - NODE 6: Creating new message for application command SWITCH_BINARY_SET
11:11:08.037 [INFO ] [arthome.event.ItemStatePredictedEvent] - TV predicted to become ON
11:11:08.039 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 6: SECURITY not supported
11:11:08.040 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 6: Command Class COMMAND_CLASS_SWITCH_BINARY is NOT required to be secured
11:11:08.041 [INFO ] [home.event.GroupItemStateChangedEvent] - geraete changed from OFF to ON through TV
11:11:08.041 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: Adding to device queue
11:11:08.042 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: Added 776 to queue - size 23
11:11:08.042 [INFO ] [smarthome.event.ItemStateChangedEvent] - TV changed from OFF to ON
11:11:08.042 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
11:11:08.043 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 06 03 25 01 FF 25 52 4F
11:11:08.043 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 0A 00 13 06 03 25 01 FF 25 52 4F
11:11:08.044 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
11:11:08.044 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 776: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 82
11:11:08.045 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling intialised at 86400 seconds - start in 1500 milliseconds.
11:11:08.046 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
11:11:08.047 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
11:11:08.048 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 00 E9
11:11:08.049 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
11:11:08.051 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 776: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 82
11:11:08.053 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK
11:11:08.053 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
11:11:08.053 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
11:11:08.050 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=00
11:11:08.054 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=00
11:11:08.055 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 776: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 82
11:11:08.055 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
11:11:08.055 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 776: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 82
11:11:08.056 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=00
11:11:08.056 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 6: sentData was not placed on stack.
11:11:08.056 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 776: Transaction CANCELLED
11:11:08.057 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Holdoff Timer started…
11:11:08.057 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
11:11:08.057 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: CANCEL while sending message. Requeueing - 2 attempts left!
11:11:08.058 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 776: Transaction RESET with 2 retries remaining.
11:11:08.058 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: Adding to device queue
11:11:08.058 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: Added 776 to queue - size 23
11:11:08.058 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff true.
11:11:08.058 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 6: TID 776: Transaction not completed

Is there anybody who can tell me what especially “NODE 6: sentData was not placed on stack” and “TID 776: Transaction CANCELLED” means?

chris · January 12, 2019, 10:28am

It means that the controller rejected the command that was sent by the binding.

Knightshift · January 12, 2019, 10:49am

Is there a way to find out why this happens?

chris · January 12, 2019, 11:17am

Unfortunately not. The documentation provides no information about “why” - just that it is rejected.

Have you reset the stick (ie removed it from the computer and put it back - like any computer, the stick needs to be reset occasionally.

tarcus · January 12, 2019, 3:11pm

One thing to watch out for is that sometimes when restarting, either the stick changes device file or OpenHab decides it’s going to use a different one. For example if you unplug the stick and plug it back in, it may appear as /dev/ttyACM1 instead of /dev/ttyACM0 and OpenHab will still be looking at the old location, although this should show the stick as offline completely, not just affecting sending only.

Another thing to check for would be file permissions on the device file to make sure it’s not being changed by something, it would need to permit writes from the OpenHab user.

I’ve got two of these sticks and have never had any problems with them of this nature so it’s not an inherent problem with them so there will be a reason for this. I rarely need to reset them or fiddle with them in any way.

chris · January 12, 2019, 4:37pm

The controller is talking to the binding, so that is not the issue here.

david_vanhuffel1 · March 29, 2021, 12:10pm

Just to let you know that I had this issue too, working with OH 3 and with a UZB Zwave Controller. OH 3 is running in a virtual environment (Ubuntu 20.04 running KVM. VM with OH is running Debian 10). The devices do not respond to the commands, however, turning the devices themselves on and off manually results in the proper changes in OH 3, which means that the hardware is found, yet there is something wrong.
I found that it seems to be related to something deeper than OH itself. I turned the virtual machine off (in which OH is running, so OH was completely shut down), but left the underlying OS and KVM running, unplugged and plugged in the controller, and things were working normally again.
So it seems to be related to the underlaying OS too, and the physical reset probably reinitializes something.
Just a theory: possibly OH Is relying on some hardware based value which has changed because of the reboot, after reboot it changed in the OS but OH still works with “old” value. Forcing the re-initialisation by unplugging the controller seems to fix this.

Judging from multiple other similar messages, rebooting appears to be an issue for all platforms (also Windows). Some people claim that re-initializing the Z-wave binding works too: go to the Karaf console and type bundle:restart org.openhab.binding.zwave

However, I was not able to verify that unfortunately.

Just placing this here in case more people run into the same problem, and you never know this might trigger an idea on developer side, for example: re-initialize the Z-Wave binding completely after each reboot (if that doesn’t happen already).

Kind regards,

David.

chris · March 29, 2021, 8:21pm

This is a very old thread. You would be advised to check the logs to see what is happening. Please refer to the binding docs on how to enable logging.

When the binding starts, it reinitialises, and it starts when the systems starts, so this already happens.

Pascal_S · November 29, 2022, 3:35pm

Hi,

I know this is an old thread but it already describes the behavior I can experience with my Z-Wave network: Reports from Nodes are still being received, but commands are not send out by the Binding.

I noticed that the issue started, when my rules started to send On and Off commands to my christmas decoration lights (8 plugs that are commanded sequentially without any delay in an Openhab rule). In the log linked below that rule was triggered at 16:14:40. After that ZWave was responding for a couple of moments as expected. But the earliest point I can tell for sure no command were honored anymore was 16:16:25.

To be honest I don’t have the knowledge to interpret the log, please find it here:

I uploaded it to we transfer as I am not allowed to attach files bigger than 1 MB.

The only way I found out to recover from that state was to cut power of raspberry pi running ohab inlcuding the razberry controller for several seconds and restart it.
Since this is somehow reproducable (at the latest every 2 days the behavior can be observed), this is rather annoying.

Is anybody able to interpret the log and identify the issue here?

Further information:
I got the controller placed in a central location and a Z-Wave mesh with over 130 nodes of which estimated more than 50 nodes are mains powered and 10 nodes are FLIRS.

Thanks in advance!