Z-Wave: Members in group of rollershutter items often reacting with delay

[openB (Bernd)]

Hi,

I’ve a Z-Wave network in my house with about 25 Fibaro rollershutter items. They are grouped like north, east, south, west or ground floor, first floor etc.

When I send commands like UP or DOWN to these groups I notice some of them sometimes reacting later - ms or even seconds. I wonder why and if there is something I can do to improve on this. It seems that it’s most of the time the same which are reacting late, but there’s for sure quite of a variability in their behaviour.

A few minutes ago I was able to create an events.log with a good example with the zwave binding in debug mode and a group of three rollershutter items. I sent UP, one reacted immediately, but the two others started several seconds later (but then together, so there was a large delay between the first one and the others, but not within the group of the others - note: in general this group is not the one causing the most annoying lags, but I was happy that the problem just showed with this small group; other groups have more members).

Is there someone who can have a look at my log and maybe is able to tell me what’s causing this delay?

Thank you.

Best,
Bernd

#
# There are 3 rollershutter in a group.
# When I send UP to the group, one starts going up (NODE 10)
# but two others don't (NODE 8, NODE 9) - they start several seconds later
#

2024-08-01 21:11:45.580 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 10: TID 42911: Timeout at state WAIT_REQUEST. 3 retries remaining.
2024-08-01 21:11:45.582 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction!
2024-08-01 21:11:45.583 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 42911: Transaction ABORTED
2024-08-01 21:11:45.586 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 
2024-08-01 21:11:45.587 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2024-08-01 21:11:45.588 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

# New command begins:
2024-08-01 21:11:45.874 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Command received zwave:device:zwave_controller_1:node10:blinds_control1 --> UP [UpDownType]
2024-08-01 21:11:45.876 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 10: Creating new message for command SWITCH_MULTILEVEL_START_LEVEL_CHANGE
2024-08-01 21:11:45.877 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Encapsulating message, instance / endpoint 1
2024-08-01 21:11:45.879 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 10: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1
2024-08-01 21:11:45.880 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:11:45.881 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2024-08-01 21:11:45.883 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Adding to device queue
2024-08-01 21:11:45.884 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Added 42914 to queue - size 3
2024-08-01 21:11:45.885 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:11:45.887 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling initialised at 86400 seconds - start in 1500 milliseconds.
2024-08-01 21:11:45.887 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Command received zwave:device:zwave_controller_1:node8:blinds_control1 --> UP [UpDownType]
2024-08-01 21:11:45.891 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 8: Creating new message for command SWITCH_MULTILEVEL_START_LEVEL_CHANGE
2024-08-01 21:11:45.894 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Command received zwave:device:zwave_controller_1:node9:blinds_control1 --> UP [UpDownType]
2024-08-01 21:11:45.900 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 9: Creating new message for command SWITCH_MULTILEVEL_START_LEVEL_CHANGE
2024-08-01 21:11:45.900 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Encapsulating message, instance / endpoint 1
2024-08-01 21:11:45.907 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 8: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1
2024-08-01 21:11:45.913 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:11:45.916 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2024-08-01 21:11:45.917 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Adding to device queue
2024-08-01 21:11:45.919 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Added 42915 to queue - size 4
2024-08-01 21:11:45.921 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:11:45.923 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Encapsulating message, instance / endpoint 1
2024-08-01 21:11:45.924 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Polling initialised at 86400 seconds - start in 1500 milliseconds.
2024-08-01 21:11:45.934 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 9: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1
2024-08-01 21:11:45.935 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:11:45.936 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2024-08-01 21:11:45.938 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Adding to device queue
2024-08-01 21:11:45.938 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Added 42916 to queue - size 5
2024-08-01 21:11:45.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:11:45.940 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Polling initialised at 86400 seconds - start in 1500 milliseconds.
2024-08-01 21:11:47.387 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling...
2024-08-01 21:11:47.388 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:zwave_controller_1:node10:meter_kwh
2024-08-01 21:11:47.388 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 10: Generating poll message for COMMAND_CLASS_METER, endpoint 0
2024-08-01 21:11:47.389 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 10: Generating poll message for COMMAND_CLASS_METER, endpoint 0
2024-08-01 21:11:47.390 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 10: Creating new message for application command METER_GET
2024-08-01 21:11:47.391 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_METER
2024-08-01 21:11:47.392 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Command Class COMMAND_CLASS_METER is NOT required to be secured
2024-08-01 21:11:47.392 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:zwave_controller_1:node10:meter_watts
2024-08-01 21:11:47.393 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 10: Generating poll message for COMMAND_CLASS_METER, endpoint 0
2024-08-01 21:11:47.394 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 10: Generating poll message for COMMAND_CLASS_METER, endpoint 0
2024-08-01 21:11:47.395 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 10: Creating new message for application command METER_GET
2024-08-01 21:11:47.395 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_METER
2024-08-01 21:11:47.396 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Command Class COMMAND_CLASS_METER is NOT required to be secured
2024-08-01 21:11:47.397 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:zwave_controller_1:node10:blinds_control1
2024-08-01 21:11:47.398 [DEBUG] [erter.ZWaveMultiLevelSwitchConverter] - NODE 10: Generating poll message for COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 1
2024-08-01 21:11:47.398 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 10: Creating new message for command SWITCH_MULTILEVEL_GET
2024-08-01 21:11:47.399 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Encapsulating message, instance / endpoint 1
2024-08-01 21:11:47.400 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 10: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1
2024-08-01 21:11:47.401 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:11:47.402 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2024-08-01 21:11:47.402 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Adding to device queue
2024-08-01 21:11:47.403 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Added 42917 to queue - size 6
2024-08-01 21:11:47.404 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:11:47.405 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Adding to device queue
2024-08-01 21:11:47.406 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Transaction already in queue - removed original
2024-08-01 21:11:47.406 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Added 42918 to queue - size 6
2024-08-01 21:11:47.407 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:11:47.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Adding to device queue
2024-08-01 21:11:47.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Transaction already in queue - removed original
2024-08-01 21:11:47.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Added 42919 to queue - size 6
2024-08-01 21:11:47.410 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:11:47.424 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Polling...
2024-08-01 21:11:47.424 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Polling deferred until initialisation complete
2024-08-01 21:11:47.441 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Polling...
2024-08-01 21:11:47.441 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Polling deferred until initialisation complete
2024-08-01 21:11:49.804 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2024-08-01 21:11:49.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:11:49.807 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:11:49.808 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42911: [ABORTED] priority=Get, requiresResponse=true, callback: 126
2024-08-01 21:11:49.809 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2024-08-01 21:11:49.810 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:11:49.811 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:11:49.823 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 16 00 04 00 0A 0E 60 0D 01 01 32 02 21 32 00 00 00 00 00 00 CA 00 6D 
2024-08-01 21:11:49.825 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 60 0D 01 01 32 02 21 32 00 00 00 00 00 00 CA 00 
2024-08-01 21:11:49.826 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 60 0D 01 01 32 02 21 32 00 00 00 00 00 00 CA 00 
2024-08-01 21:11:49.827 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42911: [ABORTED] priority=Get, requiresResponse=true, callback: 126
2024-08-01 21:11:49.827 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Application Command Request (ALIVE:DONE)
2024-08-01 21:11:49.828 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: resetResendCount initComplete=true isDead=false
2024-08-01 21:11:49.829 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:11:49.830 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Incoming command class COMMAND_CLASS_METER, endpoint 1
2024-08-01 21:11:49.831 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_METER
2024-08-01 21:11:49.832 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Received COMMAND_CLASS_METER V3 METER_REPORT
2024-08-01 21:11:49.833 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 10: Meter: Type=Electric(1), Scale=W(2), Value=0E+1
2024-08-01 21:11:49.834 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveMeterValueEvent
2024-08-01 21:11:49.834 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_METER, value=0E+1
2024-08-01 21:11:49.835 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating channel state zwave:device:zwave_controller_1:node10:meter_watts1 to 0 [DecimalType]
2024-08-01 21:11:49.836 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Commands processed 1.
2024-08-01 21:11:49.837 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@15f0b46.
2024-08-01 21:11:49.837 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2024-08-01 21:11:49.838 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2024-08-01 21:11:49.839 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:11:49.839 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:11:50.059 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 13 7E 01 03 B5 00 7F 7F 7F 7F 7F 00 01 06 00 00 00 00 02 0D 0D 0A 4D 
2024-08-01 21:11:50.061 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=126, payload=7E 01 03 B5 00 7F 7F 7F 7F 7F 00 01 06 00 00 00 00 02 0D 0D 0A 
2024-08-01 21:11:50.063 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=126, payload=7E 01 03 B5 00 7F 7F 7F 7F 7F 00 01 06 00 00 00 00 02 0D 0D 0A 
2024-08-01 21:11:50.065 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42911: [ABORTED] priority=Get, requiresResponse=true, callback: 126
2024-08-01 21:11:50.069 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2024-08-01 21:11:50.071 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 42911: [ABORTED] priority=Get, requiresResponse=true, callback: 126
2024-08-01 21:11:50.072 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 42911: (Callback 126)
2024-08-01 21:11:50.073 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2024-08-01 21:11:50.075 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 42911: callback 126
2024-08-01 21:11:50.077 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=126, payload=7E 01 03 B5 00 7F 7F 7F 7F 7F 00 01 06 00 00 00 00 02 0D 0D 0A 
2024-08-01 21:11:50.080 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 42911: Transaction CANCELLED
2024-08-01 21:11:50.081 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2024-08-01 21:11:50.082 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: CANCEL while sending message. Requeueing - 2 attempts left!
2024-08-01 21:11:50.083 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 42911: Transaction RESET with 2 retries remaining.
2024-08-01 21:11:50.085 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Adding to device queue
2024-08-01 21:11:50.087 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Transaction already in queue - removed original
2024-08-01 21:11:50.089 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Added 42911 to queue - size 6
2024-08-01 21:11:50.089 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:11:50.091 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 10: Sending REQUEST Message = 01 10 00 13 0A 09 60 0D 01 01 26 04 20 00 FF 25 7F 35 
2024-08-01 21:11:50.092 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2024-08-01 21:11:50.093 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 42914: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 127
2024-08-01 21:11:50.094 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: TID 42911: Transaction not completed
2024-08-01 21:11:50.094 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2024-08-01 21:11:50.095 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:11:50.095 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:11:50.097 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:11:50.098 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:11:50.099 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42914: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 127
2024-08-01 21:11:50.100 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2024-08-01 21:11:50.101 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2024-08-01 21:11:50.102 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:11:50.102 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:11:50.103 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:11:50.104 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:11:50.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42914: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 127
2024-08-01 21:11:50.106 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2024-08-01 21:11:50.108 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 42914: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 127
2024-08-01 21:11:50.109 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:11:50.110 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 42914: Advanced to WAIT_REQUEST
2024-08-01 21:11:50.111 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: TID 42914: Transaction not completed
2024-08-01 21:11:50.112 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:11:50.112 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:11:52.619 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 16 00 04 00 0A 0E 32 02 21 44 00 00 00 50 00 00 00 00 00 00 CA 00 26 
2024-08-01 21:11:52.621 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 32 02 21 44 00 00 00 50 00 00 00 00 00 00 CA 00 
2024-08-01 21:11:52.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 32 02 21 44 00 00 00 50 00 00 00 00 00 00 CA 00 
2024-08-01 21:11:52.624 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42914: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 127
2024-08-01 21:11:52.624 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Application Command Request (ALIVE:DONE)
2024-08-01 21:11:52.626 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: resetResendCount initComplete=true isDead=false
2024-08-01 21:11:52.627 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Incoming command class COMMAND_CLASS_METER, endpoint 0
2024-08-01 21:11:52.628 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_METER
2024-08-01 21:11:52.629 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Received COMMAND_CLASS_METER V3 METER_REPORT
2024-08-01 21:11:52.630 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 10: Meter: Type=Electric(1), Scale=kWh(0), Value=0.8
2024-08-01 21:11:52.631 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveMeterValueEvent
2024-08-01 21:11:52.632 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=0.8
2024-08-01 21:11:52.633 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating channel state zwave:device:zwave_controller_1:node10:meter_kwh to 0.8 [DecimalType]
2024-08-01 21:11:52.634 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Commands processed 1.
2024-08-01 21:11:52.636 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@b94952.
2024-08-01 21:11:52.639 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2024-08-01 21:11:52.641 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2024-08-01 21:11:52.643 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:11:52.644 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:11:52.848 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 16 00 04 00 0A 0E 32 02 21 44 00 00 00 50 00 00 00 00 00 00 CA 00 26 
2024-08-01 21:11:52.851 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 32 02 21 44 00 00 00 50 00 00 00 00 00 00 CA 00 
2024-08-01 21:11:52.853 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 32 02 21 44 00 00 00 50 00 00 00 00 00 00 CA 00 
2024-08-01 21:11:52.855 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42914: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 127
2024-08-01 21:11:52.856 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Application Command Request (ALIVE:DONE)
2024-08-01 21:11:52.858 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: resetResendCount initComplete=true isDead=false
2024-08-01 21:11:52.859 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Incoming command class COMMAND_CLASS_METER, endpoint 0
2024-08-01 21:11:52.861 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_METER
2024-08-01 21:11:52.862 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Received COMMAND_CLASS_METER V3 METER_REPORT
2024-08-01 21:11:52.864 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 10: Meter: Type=Electric(1), Scale=kWh(0), Value=0.8
2024-08-01 21:11:52.866 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveMeterValueEvent
2024-08-01 21:11:52.868 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=0.8
2024-08-01 21:11:52.870 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating channel state zwave:device:zwave_controller_1:node10:meter_kwh to 0.8 [DecimalType]
2024-08-01 21:11:52.872 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Commands processed 1.
2024-08-01 21:11:52.873 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@10fc60f.
2024-08-01 21:11:52.875 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2024-08-01 21:11:52.876 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2024-08-01 21:11:52.878 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:11:52.879 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:11:53.223 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 16 00 04 00 0A 0E 32 02 21 44 00 00 00 50 00 00 00 00 00 00 CA 00 26 
2024-08-01 21:11:53.226 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 32 02 21 44 00 00 00 50 00 00 00 00 00 00 CA 00 
2024-08-01 21:11:53.227 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 32 02 21 44 00 00 00 50 00 00 00 00 00 00 CA 00 
2024-08-01 21:11:53.228 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42914: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 127
2024-08-01 21:11:53.229 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Application Command Request (ALIVE:DONE)
2024-08-01 21:11:53.230 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: resetResendCount initComplete=true isDead=false
2024-08-01 21:11:53.231 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Incoming command class COMMAND_CLASS_METER, endpoint 0
2024-08-01 21:11:53.232 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_METER
2024-08-01 21:11:53.233 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Received COMMAND_CLASS_METER V3 METER_REPORT
2024-08-01 21:11:53.234 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 10: Meter: Type=Electric(1), Scale=kWh(0), Value=0.8
2024-08-01 21:11:53.235 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveMeterValueEvent
2024-08-01 21:11:53.236 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=0.8
2024-08-01 21:11:53.237 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating channel state zwave:device:zwave_controller_1:node10:meter_kwh to 0.8 [DecimalType]
2024-08-01 21:11:53.239 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Commands processed 1.
2024-08-01 21:11:53.240 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@14b5442.
2024-08-01 21:11:53.241 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2024-08-01 21:11:53.242 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2024-08-01 21:11:53.243 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:11:53.244 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:11:55.111 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 10: TID 42914: Timeout at state WAIT_REQUEST. 3 retries remaining.
2024-08-01 21:11:55.113 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction!
2024-08-01 21:11:55.114 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 42914: Transaction ABORTED
2024-08-01 21:11:55.117 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 
2024-08-01 21:11:55.120 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2024-08-01 21:11:55.122 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:11:58.071 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2024-08-01 21:11:58.073 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:11:58.076 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:11:58.077 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42914: [ABORTED] priority=Set, requiresResponse=true, callback: 127
2024-08-01 21:11:58.078 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2024-08-01 21:11:58.079 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:11:58.080 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:11:58.179 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 13 7F 01 03 28 00 7F 7F 7F 7F 7F 00 01 06 00 00 00 00 02 0B 0D 0A D7 
2024-08-01 21:11:58.184 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=127, payload=7F 01 03 28 00 7F 7F 7F 7F 7F 00 01 06 00 00 00 00 02 0B 0D 0A 
2024-08-01 21:11:58.186 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=127, payload=7F 01 03 28 00 7F 7F 7F 7F 7F 00 01 06 00 00 00 00 02 0B 0D 0A 
2024-08-01 21:11:58.187 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42914: [ABORTED] priority=Set, requiresResponse=true, callback: 127
2024-08-01 21:11:58.188 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2024-08-01 21:11:58.189 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 42914: [ABORTED] priority=Set, requiresResponse=true, callback: 127
2024-08-01 21:11:58.190 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 42914: (Callback 127)
2024-08-01 21:11:58.191 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2024-08-01 21:11:58.192 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 42914: callback 127
2024-08-01 21:11:58.193 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=127, payload=7F 01 03 28 00 7F 7F 7F 7F 7F 00 01 06 00 00 00 00 02 0B 0D 0A 
2024-08-01 21:11:58.195 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 42914: Transaction CANCELLED
2024-08-01 21:11:58.196 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2024-08-01 21:11:58.197 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: CANCEL while sending message. Requeueing - 2 attempts left!
2024-08-01 21:11:58.198 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 42914: Transaction RESET with 2 retries remaining.
2024-08-01 21:11:58.199 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Adding to device queue
2024-08-01 21:11:58.200 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Added 42914 to queue - size 6
2024-08-01 21:11:58.201 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:11:58.204 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 10: Sending REQUEST Message = 01 10 00 13 0A 09 60 0D 01 01 26 04 20 00 FF 25 81 CB 
2024-08-01 21:11:58.205 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2024-08-01 21:11:58.206 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 42914: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 129
2024-08-01 21:11:58.207 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2024-08-01 21:11:58.208 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:11:58.208 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: TID 42914: Transaction not completed
2024-08-01 21:11:58.210 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:11:58.211 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42914: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 129
2024-08-01 21:11:58.212 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2024-08-01 21:11:58.213 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2024-08-01 21:11:58.214 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:11:58.214 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:11:58.216 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:11:58.217 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:11:58.218 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42914: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 129
2024-08-01 21:11:58.219 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2024-08-01 21:11:58.221 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 42914: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 129
2024-08-01 21:11:58.222 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:11:58.224 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 42914: Advanced to WAIT_REQUEST
2024-08-01 21:11:58.225 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: TID 42914: Transaction not completed
2024-08-01 21:11:58.226 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:11:58.228 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

[openB (Bernd)]

Log continued:

2024-08-01 21:12:00.302 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 16 00 04 00 0A 0E 60 0D 01 01 32 02 21 32 05 3A 00 00 00 00 CA 00 52 
2024-08-01 21:12:00.304 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 60 0D 01 01 32 02 21 32 05 3A 00 00 00 00 CA 00 
2024-08-01 21:12:00.305 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 60 0D 01 01 32 02 21 32 05 3A 00 00 00 00 CA 00 
2024-08-01 21:12:00.306 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42914: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 129
2024-08-01 21:12:00.307 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Application Command Request (ALIVE:DONE)
2024-08-01 21:12:00.307 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: resetResendCount initComplete=true isDead=false
2024-08-01 21:12:00.308 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:12:00.309 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Incoming command class COMMAND_CLASS_METER, endpoint 1
2024-08-01 21:12:00.310 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_METER
2024-08-01 21:12:00.311 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Received COMMAND_CLASS_METER V3 METER_REPORT
2024-08-01 21:12:00.311 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 10: Meter: Type=Electric(1), Scale=W(2), Value=133.8
2024-08-01 21:12:00.312 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveMeterValueEvent
2024-08-01 21:12:00.313 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_METER, value=133.8
2024-08-01 21:12:00.314 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating channel state zwave:device:zwave_controller_1:node10:meter_watts1 to 133.8 [DecimalType]
2024-08-01 21:12:00.315 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Commands processed 1.
2024-08-01 21:12:00.316 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@f760d6.
2024-08-01 21:12:00.317 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2024-08-01 21:12:00.317 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2024-08-01 21:12:00.318 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:00.319 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:00.665 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 16 00 04 00 0A 0E 60 0D 01 01 32 02 21 32 05 3A 00 00 00 00 CA 00 52 
2024-08-01 21:12:00.666 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 60 0D 01 01 32 02 21 32 05 3A 00 00 00 00 CA 00 
2024-08-01 21:12:00.667 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 60 0D 01 01 32 02 21 32 05 3A 00 00 00 00 CA 00 
2024-08-01 21:12:00.668 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42914: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 129
2024-08-01 21:12:00.669 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Application Command Request (ALIVE:DONE)
2024-08-01 21:12:00.670 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: resetResendCount initComplete=true isDead=false
2024-08-01 21:12:00.671 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:12:00.671 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Incoming command class COMMAND_CLASS_METER, endpoint 1
2024-08-01 21:12:00.672 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_METER
2024-08-01 21:12:00.673 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Received COMMAND_CLASS_METER V3 METER_REPORT
2024-08-01 21:12:00.674 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 10: Meter: Type=Electric(1), Scale=W(2), Value=133.8
2024-08-01 21:12:00.675 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveMeterValueEvent
2024-08-01 21:12:00.676 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_METER, value=133.8
2024-08-01 21:12:00.677 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating channel state zwave:device:zwave_controller_1:node10:meter_watts1 to 133.8 [DecimalType]
2024-08-01 21:12:00.677 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Commands processed 1.
2024-08-01 21:12:00.678 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@e05783.
2024-08-01 21:12:00.679 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2024-08-01 21:12:00.680 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2024-08-01 21:12:00.681 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:00.682 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:01.034 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 16 00 04 00 0A 0E 60 0D 01 01 32 02 21 32 05 3A 00 00 00 00 CA 00 52 
2024-08-01 21:12:01.037 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 60 0D 01 01 32 02 21 32 05 3A 00 00 00 00 CA 00 
2024-08-01 21:12:01.038 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 60 0D 01 01 32 02 21 32 05 3A 00 00 00 00 CA 00 
2024-08-01 21:12:01.039 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42914: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 129
2024-08-01 21:12:01.040 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Application Command Request (ALIVE:DONE)
2024-08-01 21:12:01.041 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: resetResendCount initComplete=true isDead=false
2024-08-01 21:12:01.042 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:12:01.042 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Incoming command class COMMAND_CLASS_METER, endpoint 1
2024-08-01 21:12:01.043 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_METER
2024-08-01 21:12:01.044 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Received COMMAND_CLASS_METER V3 METER_REPORT
2024-08-01 21:12:01.045 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 10: Meter: Type=Electric(1), Scale=W(2), Value=133.8
2024-08-01 21:12:01.045 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveMeterValueEvent
2024-08-01 21:12:01.046 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_METER, value=133.8
2024-08-01 21:12:01.047 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating channel state zwave:device:zwave_controller_1:node10:meter_watts1 to 133.8 [DecimalType]
2024-08-01 21:12:01.048 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Commands processed 1.
2024-08-01 21:12:01.048 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1d2d76e.
2024-08-01 21:12:01.049 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2024-08-01 21:12:01.050 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2024-08-01 21:12:01.050 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:01.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:03.226 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 10: TID 42914: Timeout at state WAIT_REQUEST. 2 retries remaining.
2024-08-01 21:12:03.227 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction!
2024-08-01 21:12:03.228 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 42914: Transaction ABORTED
2024-08-01 21:12:03.233 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 
2024-08-01 21:12:03.235 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2024-08-01 21:12:03.236 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:06.313 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2024-08-01 21:12:06.314 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:12:06.315 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:12:06.316 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42914: [ABORTED] priority=Set, requiresResponse=true, callback: 129
2024-08-01 21:12:06.316 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2024-08-01 21:12:06.317 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:06.317 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:06.452 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 13 81 01 03 38 00 7F 7F 7F 7F 7F 00 01 06 00 00 00 00 02 0E 0D 0A 3C 
2024-08-01 21:12:06.454 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=129, payload=81 01 03 38 00 7F 7F 7F 7F 7F 00 01 06 00 00 00 00 02 0E 0D 0A 
2024-08-01 21:12:06.455 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=129, payload=81 01 03 38 00 7F 7F 7F 7F 7F 00 01 06 00 00 00 00 02 0E 0D 0A 
2024-08-01 21:12:06.456 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42914: [ABORTED] priority=Set, requiresResponse=true, callback: 129
2024-08-01 21:12:06.456 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2024-08-01 21:12:06.457 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 42914: [ABORTED] priority=Set, requiresResponse=true, callback: 129
2024-08-01 21:12:06.457 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 42914: (Callback 129)
2024-08-01 21:12:06.458 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2024-08-01 21:12:06.459 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 42914: callback 129
2024-08-01 21:12:06.460 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=129, payload=81 01 03 38 00 7F 7F 7F 7F 7F 00 01 06 00 00 00 00 02 0E 0D 0A 
2024-08-01 21:12:06.461 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 42914: Transaction CANCELLED
2024-08-01 21:12:06.462 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2024-08-01 21:12:06.462 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: CANCEL while sending message. Requeueing - 1 attempts left!
2024-08-01 21:12:06.463 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 42914: Transaction RESET with 1 retries remaining.
2024-08-01 21:12:06.472 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Adding to device queue
2024-08-01 21:12:06.473 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Added 42914 to queue - size 6
2024-08-01 21:12:06.473 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:06.476 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 10: Sending REQUEST Message = 01 10 00 13 0A 09 60 0D 01 01 26 04 20 00 FF 25 82 C8 
2024-08-01 21:12:06.477 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2024-08-01 21:12:06.477 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 42914: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 130
2024-08-01 21:12:06.478 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: TID 42914: Transaction not completed
2024-08-01 21:12:06.478 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2024-08-01 21:12:06.478 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:06.479 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:06.479 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:12:06.479 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:12:06.480 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42914: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 130
2024-08-01 21:12:06.480 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2024-08-01 21:12:06.481 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:06.482 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:06.485 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2024-08-01 21:12:06.486 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:06.487 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:06.487 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42914: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 130
2024-08-01 21:12:06.488 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2024-08-01 21:12:06.489 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 42914: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 130
2024-08-01 21:12:06.489 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:06.491 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 42914: Advanced to WAIT_REQUEST
2024-08-01 21:12:06.491 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: TID 42914: Transaction not completed
2024-08-01 21:12:06.492 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:06.492 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:06.751 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 13 82 00 00 1B 01 CA CA 7F 7F 7F 01 01 04 1A 00 00 00 01 01 00 00 0D 
2024-08-01 21:12:06.753 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=130, payload=82 00 00 1B 01 CA CA 7F 7F 7F 01 01 04 1A 00 00 00 01 01 00 00 
2024-08-01 21:12:06.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=130, payload=82 00 00 1B 01 CA CA 7F 7F 7F 01 01 04 1A 00 00 00 01 01 00 00 
2024-08-01 21:12:06.755 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42914: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 130
2024-08-01 21:12:06.756 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2024-08-01 21:12:06.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 42914: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 130
2024-08-01 21:12:06.759 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 42914: (Callback 130)
2024-08-01 21:12:06.759 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2024-08-01 21:12:06.760 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 42914: callback 130
2024-08-01 21:12:06.762 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=130, payload=82 00 00 1B 01 CA CA 7F 7F 7F 01 01 04 1A 00 00 00 01 01 00 00 
2024-08-01 21:12:06.764 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: resetResendCount initComplete=true isDead=false
2024-08-01 21:12:06.764 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 42914: Transaction COMPLETED
2024-08-01 21:12:06.765 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Response processed after 288ms
2024-08-01 21:12:06.766 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: TID 42914: Transaction completed
2024-08-01 21:12:06.766 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: notifyTransactionResponse TID:42914 DONE
2024-08-01 21:12:06.768 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2024-08-01 21:12:06.769 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:06.769 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:06.772 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 8: Sending REQUEST Message = 01 10 00 13 08 09 60 0D 01 01 26 04 20 00 FF 25 83 CB 
2024-08-01 21:12:06.773 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2024-08-01 21:12:06.774 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 42915: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 131
2024-08-01 21:12:06.774 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2024-08-01 21:12:06.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:12:06.776 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:12:06.777 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42915: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 131
2024-08-01 21:12:06.778 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2024-08-01 21:12:06.779 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:06.780 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:06.782 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2024-08-01 21:12:06.783 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:06.784 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:06.790 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42915: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 131
2024-08-01 21:12:06.792 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2024-08-01 21:12:06.793 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 42915: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 131
2024-08-01 21:12:06.794 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:06.797 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 42915: Advanced to WAIT_REQUEST
2024-08-01 21:12:06.798 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: TID 42915: Transaction not completed
2024-08-01 21:12:06.798 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:06.799 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:06.949 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 13 83 00 00 11 01 B5 BB 7F 7F 7F 01 01 03 13 00 00 00 01 01 00 00 06 
2024-08-01 21:12:06.950 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=131, payload=83 00 00 11 01 B5 BB 7F 7F 7F 01 01 03 13 00 00 00 01 01 00 00 
2024-08-01 21:12:06.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=131, payload=83 00 00 11 01 B5 BB 7F 7F 7F 01 01 03 13 00 00 00 01 01 00 00 
2024-08-01 21:12:06.952 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42915: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 131
2024-08-01 21:12:06.953 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2024-08-01 21:12:06.954 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 42915: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 131
2024-08-01 21:12:06.954 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 42915: (Callback 131)
2024-08-01 21:12:06.955 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2024-08-01 21:12:06.956 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 42915: callback 131
2024-08-01 21:12:06.956 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=131, payload=83 00 00 11 01 B5 BB 7F 7F 7F 01 01 03 13 00 00 00 01 01 00 00 
2024-08-01 21:12:06.958 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 42915: Transaction COMPLETED
2024-08-01 21:12:06.958 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Response processed after 185ms
2024-08-01 21:12:06.959 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: TID 42915: Transaction completed
2024-08-01 21:12:06.959 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: notifyTransactionResponse TID:42915 DONE
2024-08-01 21:12:06.960 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2024-08-01 21:12:06.961 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:06.962 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:06.963 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 9: Sending REQUEST Message = 01 10 00 13 09 09 60 0D 01 01 26 04 20 00 FF 25 84 CD 
2024-08-01 21:12:06.964 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2024-08-01 21:12:06.964 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 42916: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 132
2024-08-01 21:12:06.966 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2024-08-01 21:12:06.967 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:12:06.968 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:12:06.968 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42916: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 132
2024-08-01 21:12:06.969 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2024-08-01 21:12:06.969 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:06.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:06.972 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2024-08-01 21:12:06.973 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:06.974 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:06.974 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42916: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 132
2024-08-01 21:12:06.975 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2024-08-01 21:12:06.976 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 42916: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 132
2024-08-01 21:12:06.976 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:06.978 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 42916: Advanced to WAIT_REQUEST
2024-08-01 21:12:06.978 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: TID 42916: Transaction not completed
2024-08-01 21:12:06.978 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:06.979 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:07.044 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 13 84 00 00 07 02 CA BE BC 7F 7F 00 00 03 1A 1C 00 00 03 01 00 00 BA 
2024-08-01 21:12:07.046 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=132, payload=84 00 00 07 02 CA BE BC 7F 7F 00 00 03 1A 1C 00 00 03 01 00 00 
2024-08-01 21:12:07.048 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=132, payload=84 00 00 07 02 CA BE BC 7F 7F 00 00 03 1A 1C 00 00 03 01 00 00 
2024-08-01 21:12:07.049 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42916: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 132
2024-08-01 21:12:07.050 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2024-08-01 21:12:07.050 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 42916: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 132
2024-08-01 21:12:07.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 42916: (Callback 132)
2024-08-01 21:12:07.052 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2024-08-01 21:12:07.052 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 42916: callback 132
2024-08-01 21:12:07.053 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=132, payload=84 00 00 07 02 CA BE BC 7F 7F 00 00 03 1A 1C 00 00 03 01 00 00 
2024-08-01 21:12:07.054 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 42916: Transaction COMPLETED
2024-08-01 21:12:07.055 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Response processed after 91ms
2024-08-01 21:12:07.056 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: TID 42916: Transaction completed
2024-08-01 21:12:07.056 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: notifyTransactionResponse TID:42916 DONE
2024-08-01 21:12:07.058 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2024-08-01 21:12:07.059 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:07.060 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:07.061 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 10: Sending REQUEST Message = 01 0A 00 13 0A 03 32 01 00 25 80 79 
2024-08-01 21:12:07.063 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2024-08-01 21:12:07.064 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2024-08-01 21:12:07.064 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 42911: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 128
2024-08-01 21:12:07.064 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:12:07.066 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:12:07.066 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42911: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 128
2024-08-01 21:12:07.067 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2024-08-01 21:12:07.068 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:07.068 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:07.069 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2024-08-01 21:12:07.071 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:07.072 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:07.073 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42911: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 128
2024-08-01 21:12:07.073 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2024-08-01 21:12:07.074 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 42911: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 128
2024-08-01 21:12:07.075 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:07.076 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 42911: Advanced to WAIT_REQUEST
2024-08-01 21:12:07.077 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: TID 42911: Transaction not completed
2024-08-01 21:12:07.078 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:07.079 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:07.605 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 13 80 00 00 35 01 CA CA 7F 7F 7F 01 01 03 1A 00 00 00 01 02 00 00 25 
2024-08-01 21:12:07.608 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=128, payload=80 00 00 35 01 CA CA 7F 7F 7F 01 01 03 1A 00 00 00 01 02 00 00 
2024-08-01 21:12:07.610 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=128, payload=80 00 00 35 01 CA CA 7F 7F 7F 01 01 03 1A 00 00 00 01 02 00 00 
2024-08-01 21:12:07.611 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42911: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 128
2024-08-01 21:12:07.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2024-08-01 21:12:07.613 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 42911: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 128
2024-08-01 21:12:07.614 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 42911: (Callback 128)
2024-08-01 21:12:07.615 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2024-08-01 21:12:07.616 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 42911: callback 128
2024-08-01 21:12:07.617 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=128, payload=80 00 00 35 01 CA CA 7F 7F 7F 01 01 03 1A 00 00 00 01 02 00 00 
2024-08-01 21:12:07.619 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: resetResendCount initComplete=true isDead=false
2024-08-01 21:12:07.620 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 42911: Advanced to WAIT_DATA
2024-08-01 21:12:07.621 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: TID 42911: Transaction not completed
2024-08-01 21:12:07.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:07.623 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:07.754 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 16 00 04 00 0A 0E 32 02 21 44 00 00 00 50 00 00 00 00 00 00 CA 00 26 
2024-08-01 21:12:07.756 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 32 02 21 44 00 00 00 50 00 00 00 00 00 00 CA 00 
2024-08-01 21:12:07.758 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 32 02 21 44 00 00 00 50 00 00 00 00 00 00 CA 00 
2024-08-01 21:12:07.758 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:07.759 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Application Command Request (ALIVE:DONE)
2024-08-01 21:12:07.760 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: resetResendCount initComplete=true isDead=false
2024-08-01 21:12:07.761 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Incoming command class COMMAND_CLASS_METER, endpoint 0
2024-08-01 21:12:07.762 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_METER
2024-08-01 21:12:07.763 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Received COMMAND_CLASS_METER V3 METER_REPORT
2024-08-01 21:12:07.764 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 10: Meter: Type=Electric(1), Scale=kWh(0), Value=0.8
2024-08-01 21:12:07.765 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveMeterValueEvent
2024-08-01 21:12:07.766 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=0.8
2024-08-01 21:12:07.767 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating channel state zwave:device:zwave_controller_1:node10:meter_kwh to 0.8 [DecimalType]
2024-08-01 21:12:07.768 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Commands processed 1.
2024-08-01 21:12:07.769 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@367a92.
2024-08-01 21:12:07.770 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@367a92.
2024-08-01 21:12:07.770 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: notifyTransactionResponse TID:42911 DONE
2024-08-01 21:12:07.772 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2024-08-01 21:12:07.773 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2024-08-01 21:12:07.773 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:07.774 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:07.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:07.777 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 10: Sending REQUEST Message = 01 0A 00 13 0A 03 32 01 10 25 85 6C 
2024-08-01 21:12:07.778 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2024-08-01 21:12:07.779 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 42918: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 133
2024-08-01 21:12:07.780 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2024-08-01 21:12:07.781 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:12:07.782 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:12:07.782 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42918: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 133
2024-08-01 21:12:07.783 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2024-08-01 21:12:07.783 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:07.784 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:07.785 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2024-08-01 21:12:07.786 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:07.787 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:07.788 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42918: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 133
2024-08-01 21:12:07.789 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2024-08-01 21:12:07.789 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 42918: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 133
2024-08-01 21:12:07.790 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:07.792 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 42918: Advanced to WAIT_REQUEST
2024-08-01 21:12:07.792 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: TID 42918: Transaction not completed
2024-08-01 21:12:07.793 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:07.794 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:08.040 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 13 85 00 00 1A 01 CA CA 7F 7F 7F 01 01 03 1A 00 00 00 01 01 00 00 0C 
2024-08-01 21:12:08.042 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=133, payload=85 00 00 1A 01 CA CA 7F 7F 7F 01 01 03 1A 00 00 00 01 01 00 00 
2024-08-01 21:12:08.044 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=133, payload=85 00 00 1A 01 CA CA 7F 7F 7F 01 01 03 1A 00 00 00 01 01 00 00 
2024-08-01 21:12:08.045 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42918: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 133
2024-08-01 21:12:08.046 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2024-08-01 21:12:08.046 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 42918: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 133
2024-08-01 21:12:08.047 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 42918: (Callback 133)
2024-08-01 21:12:08.048 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2024-08-01 21:12:08.049 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 42918: callback 133
2024-08-01 21:12:08.050 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=133, payload=85 00 00 1A 01 CA CA 7F 7F 7F 01 01 03 1A 00 00 00 01 01 00 00 
2024-08-01 21:12:08.052 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: resetResendCount initComplete=true isDead=false
2024-08-01 21:12:08.052 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 42918: Advanced to WAIT_DATA
2024-08-01 21:12:08.053 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: TID 42918: Transaction not completed
2024-08-01 21:12:08.054 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:08.055 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:08.177 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 12 00 04 00 0A 0A 32 02 21 32 05 35 00 00 00 00 CA 00 30 
2024-08-01 21:12:08.179 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0A 32 02 21 32 05 35 00 00 00 00 CA 00 
2024-08-01 21:12:08.180 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0A 32 02 21 32 05 35 00 00 00 00 CA 00 
2024-08-01 21:12:08.181 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:08.182 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Application Command Request (ALIVE:DONE)
2024-08-01 21:12:08.183 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: resetResendCount initComplete=true isDead=false
2024-08-01 21:12:08.184 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Incoming command class COMMAND_CLASS_METER, endpoint 0
2024-08-01 21:12:08.186 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_METER
2024-08-01 21:12:08.187 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Received COMMAND_CLASS_METER V3 METER_REPORT
2024-08-01 21:12:08.188 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 10: Meter: Type=Electric(1), Scale=W(2), Value=133.3
2024-08-01 21:12:08.189 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveMeterValueEvent
2024-08-01 21:12:08.190 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=133.3
2024-08-01 21:12:08.191 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating channel state zwave:device:zwave_controller_1:node10:meter_watts to 133.3 [DecimalType]
2024-08-01 21:12:08.192 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Commands processed 1.
2024-08-01 21:12:08.193 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1925ad2.
2024-08-01 21:12:08.194 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1925ad2.
2024-08-01 21:12:08.195 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: notifyTransactionResponse TID:42918 DONE
2024-08-01 21:12:08.197 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2024-08-01 21:12:08.198 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2024-08-01 21:12:08.199 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:08.200 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:08.201 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:08.204 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 10: Sending REQUEST Message = 01 0D 00 13 0A 06 60 0D 01 01 26 02 25 86 07 
2024-08-01 21:12:08.205 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2024-08-01 21:12:08.206 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 42919: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 134
2024-08-01 21:12:08.207 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2024-08-01 21:12:08.208 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:12:08.210 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:12:08.211 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42919: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 134
2024-08-01 21:12:08.212 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2024-08-01 21:12:08.213 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2024-08-01 21:12:08.213 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:08.214 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:08.215 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:08.217 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:08.218 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42919: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 134
2024-08-01 21:12:08.219 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2024-08-01 21:12:08.220 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 42919: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 134
2024-08-01 21:12:08.221 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:08.223 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 42919: Advanced to WAIT_REQUEST
2024-08-01 21:12:08.224 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: TID 42919: Transaction not completed
2024-08-01 21:12:08.225 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:08.226 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:08.466 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 13 86 00 00 19 01 CA CA 7F 7F 7F 01 01 03 1A 00 00 00 01 01 00 00 0C 
2024-08-01 21:12:08.468 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=134, payload=86 00 00 19 01 CA CA 7F 7F 7F 01 01 03 1A 00 00 00 01 01 00 00 
2024-08-01 21:12:08.470 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=134, payload=86 00 00 19 01 CA CA 7F 7F 7F 01 01 03 1A 00 00 00 01 01 00 00 
2024-08-01 21:12:08.471 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 42919: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 134
2024-08-01 21:12:08.472 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2024-08-01 21:12:08.473 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 42919: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 134
2024-08-01 21:12:08.474 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 42919: (Callback 134)
2024-08-01 21:12:08.475 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2024-08-01 21:12:08.476 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 42919: callback 134
2024-08-01 21:12:08.477 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=134, payload=86 00 00 19 01 CA CA 7F 7F 7F 01 01 03 1A 00 00 00 01 01 00 00 
2024-08-01 21:12:08.480 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: resetResendCount initComplete=true isDead=false
2024-08-01 21:12:08.481 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 42919: Advanced to WAIT_DATA
2024-08-01 21:12:08.482 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: TID 42919: Transaction not completed
2024-08-01 21:12:08.482 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:08.483 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:08.605 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 11 00 04 00 0A 09 60 0D 01 01 26 03 FE FE FE CA 00 95 
2024-08-01 21:12:08.607 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 09 60 0D 01 01 26 03 FE FE FE CA 00 
2024-08-01 21:12:08.608 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 09 60 0D 01 01 26 03 FE FE FE CA 00 
2024-08-01 21:12:08.609 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:08.610 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Application Command Request (ALIVE:DONE)
2024-08-01 21:12:08.611 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: resetResendCount initComplete=true isDead=false
2024-08-01 21:12:08.612 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:12:08.612 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 1
2024-08-01 21:12:08.613 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_SWITCH_MULTILEVEL
2024-08-01 21:12:08.614 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Received COMMAND_CLASS_SWITCH_MULTILEVEL V3 SWITCH_MULTILEVEL_REPORT
2024-08-01 21:12:08.615 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 10: Switch Multi Level report, value = 254
2024-08-01 21:12:08.616 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2024-08-01 21:12:08.617 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=254
2024-08-01 21:12:08.618 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating channel state zwave:device:zwave_controller_1:node10:blinds_control1 to UNDEF [UnDefType]
2024-08-01 21:12:08.619 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Commands processed 1.
2024-08-01 21:12:08.620 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1c642ec.
2024-08-01 21:12:08.621 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1c642ec.
2024-08-01 21:12:08.621 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: notifyTransactionResponse TID:42919 DONE
2024-08-01 21:12:08.623 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2024-08-01 21:12:08.624 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2024-08-01 21:12:08.624 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:08.625 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:08.626 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:09.400 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 16 00 04 00 0A 0E 60 0D 01 01 32 02 21 32 05 2C 00 00 00 00 CA 00 44 
2024-08-01 21:12:09.403 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 60 0D 01 01 32 02 21 32 05 2C 00 00 00 00 CA 00 
2024-08-01 21:12:09.405 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 60 0D 01 01 32 02 21 32 05 2C 00 00 00 00 CA 00 
2024-08-01 21:12:09.406 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:09.407 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Application Command Request (ALIVE:DONE)
2024-08-01 21:12:09.408 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: resetResendCount initComplete=true isDead=false
2024-08-01 21:12:09.409 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:12:09.410 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Incoming command class COMMAND_CLASS_METER, endpoint 1
2024-08-01 21:12:09.411 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_METER
2024-08-01 21:12:09.412 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Received COMMAND_CLASS_METER V3 METER_REPORT
2024-08-01 21:12:09.413 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 10: Meter: Type=Electric(1), Scale=W(2), Value=132.4
2024-08-01 21:12:09.414 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveMeterValueEvent
2024-08-01 21:12:09.415 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_METER, value=132.4
2024-08-01 21:12:09.416 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating channel state zwave:device:zwave_controller_1:node10:meter_watts1 to 132.4 [DecimalType]
2024-08-01 21:12:09.417 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Commands processed 1.
2024-08-01 21:12:09.418 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@3e86dd.
2024-08-01 21:12:09.419 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:09.420 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:09.421 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:09.422 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:09.604 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 16 00 04 00 08 0E 60 0D 01 01 32 02 21 32 05 30 00 00 00 00 B3 00 23 
2024-08-01 21:12:09.607 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 60 0D 01 01 32 02 21 32 05 30 00 00 00 00 B3 00 
2024-08-01 21:12:09.608 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 60 0D 01 01 32 02 21 32 05 30 00 00 00 00 B3 00 
2024-08-01 21:12:09.609 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:09.610 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:SUC_ROUTE)
2024-08-01 21:12:09.611 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:12:09.612 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_METER, endpoint 1
2024-08-01 21:12:09.613 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY NOT required on COMMAND_CLASS_METER
2024-08-01 21:12:09.614 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_METER V3 METER_REPORT
2024-08-01 21:12:09.616 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 8: Meter: Type=Electric(1), Scale=W(2), Value=132.8
2024-08-01 21:12:09.617 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveMeterValueEvent
2024-08-01 21:12:09.618 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_METER, value=132.8
2024-08-01 21:12:09.619 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating channel state zwave:device:zwave_controller_1:node8:meter_watts1 to 132.8 [DecimalType]
2024-08-01 21:12:09.620 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2024-08-01 21:12:09.621 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1659662.
2024-08-01 21:12:09.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:09.623 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:09.624 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:09.625 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:09.896 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 16 00 04 00 09 0E 60 0D 01 01 32 02 21 32 03 3E 00 00 00 00 CA 00 53 
2024-08-01 21:12:09.899 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 0E 60 0D 01 01 32 02 21 32 03 3E 00 00 00 00 CA 00 
2024-08-01 21:12:09.900 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 0E 60 0D 01 01 32 02 21 32 03 3E 00 00 00 00 CA 00 
2024-08-01 21:12:09.902 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:09.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Application Command Request (ALIVE:RETURN_ROUTES)
2024-08-01 21:12:09.904 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:12:09.905 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Incoming command class COMMAND_CLASS_METER, endpoint 1
2024-08-01 21:12:09.906 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: SECURITY NOT required on COMMAND_CLASS_METER
2024-08-01 21:12:09.907 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 9: Received COMMAND_CLASS_METER V3 METER_REPORT
2024-08-01 21:12:09.908 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 9: Meter: Type=Electric(1), Scale=W(2), Value=83
2024-08-01 21:12:09.909 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveMeterValueEvent
2024-08-01 21:12:09.909 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_METER, value=83
2024-08-01 21:12:09.910 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Updating channel state zwave:device:zwave_controller_1:node9:meter_watts1 to 83 [DecimalType]
2024-08-01 21:12:09.911 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Commands processed 1.
2024-08-01 21:12:09.912 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@ec1796.
2024-08-01 21:12:09.913 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:09.914 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:09.915 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:09.916 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:14.627 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 11 00 04 00 0A 09 60 0D 01 01 26 03 63 FE FE CA 00 08 
2024-08-01 21:12:14.629 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 09 60 0D 01 01 26 03 63 FE FE CA 00 
2024-08-01 21:12:14.631 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 09 60 0D 01 01 26 03 63 FE FE CA 00 
2024-08-01 21:12:14.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:14.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Application Command Request (ALIVE:DONE)
2024-08-01 21:12:14.634 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: resetResendCount initComplete=true isDead=false
2024-08-01 21:12:14.635 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:12:14.636 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 1
2024-08-01 21:12:14.638 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_SWITCH_MULTILEVEL
2024-08-01 21:12:14.639 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Received COMMAND_CLASS_SWITCH_MULTILEVEL V3 SWITCH_MULTILEVEL_REPORT
2024-08-01 21:12:14.640 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 10: Switch Multi Level report, value = 99
2024-08-01 21:12:14.641 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2024-08-01 21:12:14.643 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=99
2024-08-01 21:12:14.644 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating channel state zwave:device:zwave_controller_1:node10:blinds_control1 to 100 [PercentType]
2024-08-01 21:12:14.645 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Commands processed 1.
2024-08-01 21:12:14.646 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@158f205.
2024-08-01 21:12:14.647 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:14.648 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:14.649 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:14.650 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:16.843 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 16 00 04 00 0A 0E 60 0D 01 01 32 02 21 32 00 00 00 00 00 00 CA 00 6D 
2024-08-01 21:12:16.846 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 60 0D 01 01 32 02 21 32 00 00 00 00 00 00 CA 00 
2024-08-01 21:12:16.872 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0E 60 0D 01 01 32 02 21 32 00 00 00 00 00 00 CA 00 
2024-08-01 21:12:16.879 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:16.880 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Application Command Request (ALIVE:DONE)
2024-08-01 21:12:16.882 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: resetResendCount initComplete=true isDead=false
2024-08-01 21:12:16.905 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:12:16.906 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Incoming command class COMMAND_CLASS_METER, endpoint 1
2024-08-01 21:12:16.907 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_METER
2024-08-01 21:12:16.915 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Received COMMAND_CLASS_METER V3 METER_REPORT
2024-08-01 21:12:16.920 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 10: Meter: Type=Electric(1), Scale=W(2), Value=0E+1
2024-08-01 21:12:16.924 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveMeterValueEvent
2024-08-01 21:12:16.926 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_METER, value=0E+1
2024-08-01 21:12:16.927 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating channel state zwave:device:zwave_controller_1:node10:meter_watts1 to 0 [DecimalType]
2024-08-01 21:12:16.928 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Commands processed 1.
2024-08-01 21:12:16.928 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1628e5d.
2024-08-01 21:12:16.929 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:16.930 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:16.931 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:16.932 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:29.685 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 25: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@9ec615
2024-08-01 21:12:29.688 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 25: Adding to device queue
2024-08-01 21:12:29.691 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 25: Added 42920 to queue - size 1
2024-08-01 21:12:29.693 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:29.697 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 51 19 87 35 
2024-08-01 21:12:29.700 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2024-08-01 21:12:29.700 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2024-08-01 21:12:29.702 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:12:29.704 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 42920: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 135
2024-08-01 21:12:29.704 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2024-08-01 21:12:29.706 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:29.707 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2024-08-01 21:12:29.708 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:29.709 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2024-08-01 21:12:31.707 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 25: TID 42920: Timeout at state WAIT_RESPONSE. 3 retries remaining.
2024-08-01 21:12:31.708 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 42920: Transaction is current transaction, so clearing!!!!!
2024-08-01 21:12:31.709 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 42920: Transaction CANCELLED
2024-08-01 21:12:31.710 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 25: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2024-08-01 21:12:31.710 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 25: notifyTransactionResponse TID:42920 CANCELLED
2024-08-01 21:12:31.711 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:31.711 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 42920: Transaction event listener: DONE: CANCELLED -> WAIT_RESPONSE
2024-08-01 21:12:31.712 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 25: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@abeb91
2024-08-01 21:12:32.816 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 51 01 AA 
2024-08-01 21:12:32.818 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AssignSucReturnRoute[81], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:32.819 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AssignSucReturnRoute[81], type=Response[1], dest=255, callback=0, payload=01 
2024-08-01 21:12:32.820 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:32.821 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
2024-08-01 21:12:32.822 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null
2024-08-01 21:12:32.823 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:32.824 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:32.826 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 51 87 04 28 
2024-08-01 21:12:32.828 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AssignSucReturnRoute[81], type=Request[0], dest=4, callback=135, payload=87 04 
2024-08-01 21:12:32.829 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AssignSucReturnRoute[81], type=Request[0], dest=4, callback=135, payload=87 04 
2024-08-01 21:12:32.830 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 11 00 04 00 09 09 60 0D 01 01 26 03 63 FE FE CA 00 0B 
2024-08-01 21:12:32.831 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:32.832 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
2024-08-01 21:12:32.833 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 09 60 0D 01 01 26 03 63 FE FE CA 00 
2024-08-01 21:12:32.834 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null
2024-08-01 21:12:32.835 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AssignSucReturnRoute[81], type=Request[0], dest=4, callback=135, payload=87 04 
2024-08-01 21:12:32.838 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 09 60 0D 01 01 26 03 63 FE FE CA 00 
2024-08-01 21:12:32.839 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:32.840 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Application Command Request (ALIVE:RETURN_ROUTES)
2024-08-01 21:12:32.842 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:12:32.843 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 1
2024-08-01 21:12:32.843 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: SECURITY NOT required on COMMAND_CLASS_SWITCH_MULTILEVEL
2024-08-01 21:12:32.844 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 9: Received COMMAND_CLASS_SWITCH_MULTILEVEL V3 SWITCH_MULTILEVEL_REPORT
2024-08-01 21:12:32.845 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 9: Switch Multi Level report, value = 99
2024-08-01 21:12:32.846 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2024-08-01 21:12:32.847 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=99
2024-08-01 21:12:32.848 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Updating channel state zwave:device:zwave_controller_1:node9:blinds_control1 to 100 [PercentType]
2024-08-01 21:12:32.849 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Commands processed 1.
2024-08-01 21:12:32.850 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@e7c215.
2024-08-01 21:12:32.851 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:32.852 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:32.853 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:32.854 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:32.893 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 11 00 04 00 09 09 60 0D 01 01 26 03 63 FE FE CA 00 0B 
2024-08-01 21:12:32.895 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 09 60 0D 01 01 26 03 63 FE FE CA 00 
2024-08-01 21:12:32.896 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 09 60 0D 01 01 26 03 63 FE FE CA 00 
2024-08-01 21:12:32.897 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:32.897 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Application Command Request (ALIVE:RETURN_ROUTES)
2024-08-01 21:12:32.898 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:12:32.899 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 1
2024-08-01 21:12:32.900 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: SECURITY NOT required on COMMAND_CLASS_SWITCH_MULTILEVEL
2024-08-01 21:12:32.901 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 9: Received COMMAND_CLASS_SWITCH_MULTILEVEL V3 SWITCH_MULTILEVEL_REPORT
2024-08-01 21:12:32.902 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 9: Switch Multi Level report, value = 99
2024-08-01 21:12:32.903 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2024-08-01 21:12:32.903 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=99
2024-08-01 21:12:32.904 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Updating channel state zwave:device:zwave_controller_1:node9:blinds_control1 to 100 [PercentType]
2024-08-01 21:12:32.906 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Commands processed 1.
2024-08-01 21:12:32.906 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@6523f8.
2024-08-01 21:12:32.907 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:32.908 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:32.909 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:32.910 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:32.923 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 11 00 04 00 09 09 60 0D 01 01 26 03 63 FE FE CA 00 0B 
2024-08-01 21:12:32.925 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 09 60 0D 01 01 26 03 63 FE FE CA 00 
2024-08-01 21:12:32.926 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 09 60 0D 01 01 26 03 63 FE FE CA 00 
2024-08-01 21:12:32.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:32.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Application Command Request (ALIVE:RETURN_ROUTES)
2024-08-01 21:12:32.928 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:12:32.929 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 1
2024-08-01 21:12:32.930 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: SECURITY NOT required on COMMAND_CLASS_SWITCH_MULTILEVEL
2024-08-01 21:12:32.931 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 9: Received COMMAND_CLASS_SWITCH_MULTILEVEL V3 SWITCH_MULTILEVEL_REPORT
2024-08-01 21:12:32.932 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 9: Switch Multi Level report, value = 99
2024-08-01 21:12:32.933 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2024-08-01 21:12:32.933 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=99
2024-08-01 21:12:32.934 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Updating channel state zwave:device:zwave_controller_1:node9:blinds_control1 to 100 [PercentType]
2024-08-01 21:12:32.936 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Commands processed 1.
2024-08-01 21:12:32.936 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@bd3dab.
2024-08-01 21:12:32.937 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:32.938 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:32.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:32.940 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:33.242 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 11 00 04 00 09 09 60 0D 01 01 26 03 63 FE FE CA 00 0B 
2024-08-01 21:12:33.244 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 09 60 0D 01 01 26 03 63 FE FE CA 00 
2024-08-01 21:12:33.256 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 09 60 0D 01 01 26 03 63 FE FE CA 00 
2024-08-01 21:12:33.257 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:33.258 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Application Command Request (ALIVE:RETURN_ROUTES)
2024-08-01 21:12:33.260 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:12:33.263 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 1
2024-08-01 21:12:33.265 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: SECURITY NOT required on COMMAND_CLASS_SWITCH_MULTILEVEL
2024-08-01 21:12:33.267 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 9: Received COMMAND_CLASS_SWITCH_MULTILEVEL V3 SWITCH_MULTILEVEL_REPORT
2024-08-01 21:12:33.268 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 9: Switch Multi Level report, value = 99
2024-08-01 21:12:33.269 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2024-08-01 21:12:33.270 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=99
2024-08-01 21:12:33.271 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Updating channel state zwave:device:zwave_controller_1:node9:blinds_control1 to 100 [PercentType]
2024-08-01 21:12:33.272 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Commands processed 1.
2024-08-01 21:12:33.273 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@15c4507.
2024-08-01 21:12:33.274 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:33.275 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:33.276 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:33.277 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:33.747 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 16 00 04 00 09 0E 60 0D 01 01 32 02 21 32 00 00 00 00 00 00 CA 00 6E 
2024-08-01 21:12:33.749 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 0E 60 0D 01 01 32 02 21 32 00 00 00 00 00 00 CA 00 
2024-08-01 21:12:33.750 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 0E 60 0D 01 01 32 02 21 32 00 00 00 00 00 00 CA 00 
2024-08-01 21:12:33.751 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:33.752 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Application Command Request (ALIVE:RETURN_ROUTES)
2024-08-01 21:12:33.753 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:12:33.754 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Incoming command class COMMAND_CLASS_METER, endpoint 1
2024-08-01 21:12:33.755 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: SECURITY NOT required on COMMAND_CLASS_METER
2024-08-01 21:12:33.756 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 9: Received COMMAND_CLASS_METER V3 METER_REPORT
2024-08-01 21:12:33.757 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 9: Meter: Type=Electric(1), Scale=W(2), Value=0E+1
2024-08-01 21:12:33.758 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveMeterValueEvent
2024-08-01 21:12:33.759 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_METER, value=0E+1
2024-08-01 21:12:33.760 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Updating channel state zwave:device:zwave_controller_1:node9:meter_watts1 to 0 [DecimalType]
2024-08-01 21:12:33.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Commands processed 1.
2024-08-01 21:12:33.762 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@123c8d3.
2024-08-01 21:12:33.763 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:33.764 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:33.765 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:33.767 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:34.878 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 11 00 04 00 08 09 60 0D 01 01 26 03 63 FE FE B3 00 73 
2024-08-01 21:12:34.881 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 09 60 0D 01 01 26 03 63 FE FE B3 00 
2024-08-01 21:12:34.882 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 09 60 0D 01 01 26 03 63 FE FE B3 00 
2024-08-01 21:12:34.883 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:34.884 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:SUC_ROUTE)
2024-08-01 21:12:34.885 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:12:34.886 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 1
2024-08-01 21:12:34.887 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY NOT required on COMMAND_CLASS_SWITCH_MULTILEVEL
2024-08-01 21:12:34.888 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_SWITCH_MULTILEVEL V3 SWITCH_MULTILEVEL_REPORT
2024-08-01 21:12:34.889 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 8: Switch Multi Level report, value = 99
2024-08-01 21:12:34.890 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2024-08-01 21:12:34.891 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=99
2024-08-01 21:12:34.892 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating channel state zwave:device:zwave_controller_1:node8:blinds_control1 to 100 [PercentType]
2024-08-01 21:12:34.893 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2024-08-01 21:12:34.894 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@14506c.
2024-08-01 21:12:34.895 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:34.896 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:34.897 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:34.898 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2024-08-01 21:12:35.135 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 16 00 04 00 08 0E 60 0D 01 01 32 02 21 32 00 00 00 00 00 00 B1 00 14 
2024-08-01 21:12:35.137 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 60 0D 01 01 32 02 21 32 00 00 00 00 00 00 B1 00 
2024-08-01 21:12:35.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 60 0D 01 01 32 02 21 32 00 00 00 00 00 00 B1 00 
2024-08-01 21:12:35.140 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2024-08-01 21:12:35.141 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:SUC_ROUTE)
2024-08-01 21:12:35.142 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2024-08-01 21:12:35.143 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_METER, endpoint 1
2024-08-01 21:12:35.144 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY NOT required on COMMAND_CLASS_METER
2024-08-01 21:12:35.145 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_METER V3 METER_REPORT
2024-08-01 21:12:35.146 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 8: Meter: Type=Electric(1), Scale=W(2), Value=0E+1
2024-08-01 21:12:35.147 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveMeterValueEvent
2024-08-01 21:12:35.148 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_METER, value=0E+1
2024-08-01 21:12:35.149 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating channel state zwave:device:zwave_controller_1:node8:meter_watts1 to 0 [DecimalType]
2024-08-01 21:12:35.150 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2024-08-01 21:12:35.151 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1d96da0.
2024-08-01 21:12:35.152 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:35.153 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2024-08-01 21:12:35.154 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2024-08-01 21:12:35.155 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

[apella12 (Bob Eckhoff)]

On the self-help side I would suggest running your logs through the Zwave debug viewer here.

I took a quick look and the command to Node 10 was sent three times before the device responded with an Ack(nowledgement) so that took about 16 seconds. There can only be 1 command outstanding until that is Ack’ed, so nodes 8 and 9 had to wait.
The first command to Node 10 was 11:50 and wasn’t acked until 12:06.7. The UP command to Node 8 and Node 9 were acked at 12:06.95 and 12:07.044, so no problems there.

What looks a little odd, is that Node 10 kept sending meter information while it wasn’t responding to the “UP”. Perhaps you can look at the meter parameters and space them out. In this group of three node 10 is the problem.

EDIT: reread your post. My guess is Node 10 started to act on the command, but did not Ack it, so it held up 8 and 9 (the one command rule)

[openB (Bernd)]

Great, thank you so much Bob. What I found out analyzing larger logs with the debug viewer: there have been time outs of 10% - 32% for most nodes in my network, which might be the result of putting the Raspi with the network controller in the heating room (cellar).

I moved it to a probably better place and rebooted; and then I found with this great debug viewer that there is a node 2 which is not responding at all. In openHAB there is no thing with this node id, and I’m not missing any zwave item
IIRC there have been issues with one of the rollershutter controller and it might be that I re-added it. Maybe without correctly excluding it before. But that’s only a guess.

What could / should I do now with this node 2?

Edit - PS: I started with the raspi in a better place and after a few months I moved it to the cellar. To my surprise the network continued working; it might be that the delay problem got worse, but not much because I decided to leave it there. Maybe my delay problems are caused by this node 2?

EDIT2: No, I just rembered that there is a flush relay currently not used. That’s node 2. So nothing wrong here… Or is it a problem having a device “defined” in the controller which is not available at all? Should I power it on and then exclude it? (I used it for testing purposes before we moved into our house and currently don’t have a use case for it.)

[apella12 (Bob Eckhoff)]

@openB

Or is it a problem having a device “defined” in the controller which is not available at all?

Yes there is. I would advise removing it or locating it as a powered-up repeater somewhere

It is best to have the controller as centrally located as possible. IMO the “mesh” is overrated from a response perspective. My objective has been to place the controller to be in direct contact with as many nodes as possible. I use a spare controller reprogrammed as a Zniffer to analyze.

As I have bought Rpi’s I have split my Zwave networks. I have the house OH and upstairs Zwave (34 nodes) on a Rpi5. I have a twenty node Zwave-js Rpi4 in the basement (MQTT to the House OH). Lastly a small 4 node network of most remote nodes on a Rpi3b (OH remote binding to the House OH). Some of all that is to give me something to play with , but you get the idea.

When I first started several years ago, I moved the Rpi3b (OH + ZW) from the basement (its original location) to main floor after experiencing problems. Might also want to review this post for other ideas if you still have issues. [SOLVED] Unresponsive Z-Wave Network: Tools and Approaches to track down the issues - Tutorials & Examples / Solutions - openHAB Community

[openB (Bernd)]

Thanks again, I’m going to try out a few places for my controller in the coming days. BTW: what happens, when I move my Raspi + controller to another location? I think there is a routing table which is “optimized” by the controller on a regular basis; does this also happen after a reboot? The reason for this question is that I wonder when I really can analyze my network, directly after repositioning and reboot or after “some” time?

[openB (Bernd)]

And with regard to positioning my Raspi + ZWave controller, there are some constraints… I want it to be connected to my home network by LAN, not just WLAN, and it shouldn’t be too visible… the current (new) location is quite well in the middle of the house (middle floor as well as well in between its outer walls.

[apella12 (Bob Eckhoff)]

@openB

I think there is a routing table which is “optimized” by the controller on a regular basis;

You are talking about the network HEAL on the Controller UI page. It goes off on time of day not after a reboot. You can get it started by changing the time to the current hour. It will then run, but things will be slow for awhile. The default is 2am when traffic should be low. You can tell when it i done by the Node timestamps in the userdata/zwave folder. I have the heal disabled because I haven’t moved nodes around for some time and don’t think the new routings are better. Zwave plus devices will adjust the paths on their own.

[openB (Bernd)]

Yes, heal, and interestingly there are several buttons on the controller page in openhab (View Network Map, Soft Reset, Hard Reset, Exclude Devices, Sync Network), but no heal button. So I used setting the heal time to the current hour to force a heal. And I found out that all my devices are Z-Wave Plus already, so this might be the reason why my network re-builds itself after a reboot of the Raspi.

What I’ve found out - and I report it here because it might help others:
The Zwave debug viewer linked earlier combined with OH’s View Network Map give a good overview of the network; and the network might be different to what you expect if you think of your house. In our case, there is a basement (no zwave devices, built of concrete) and three levels on top (timber frame construction) with zwave devices on all sides of the building in the first levels, but not the attic; up there all 11 devices are put into a box in one wall which is placed quite remote (it’s a outer wall in a small storage room).

If I place Raspi + controller on the first level and rather in the middle of the building, I get only one direct connection to a device in the ground floor; the connection to the storage room (one level higher) is also not a direct one.

If I place them in the same room but on an outer wall which has several devices on all levels, these devices are not as well connected as I’d expect: it seems that connections from within the building to devices in outer walls are much better than connections between devices which are placed about each other in outer walls where the connection has to go “within the outer wall”.

If I place it on the ground floor, I get connections to all devices on the same floor and almost all devices on the first floor. So connections downwards seem to be more difficult than upwards. Maybe because the Raspi is placed on something (window sill or cupboard)? There is one very important device (staircase on the middle level) linking the controller to most devices in the storage room. I temporarily put the (unused) flush relay in the bathroom beside which is also approx. in-between and it’s connecting the controller to most of the storage room devices as well.

Summary: I think I should place the raspi + controller on the ground floor because connections upward are better than downward, which results in good connections (short response times according to Z-Wave Log Viewer) to most devices except these in the storage room on the attic level. To connect them best I’ll have to test different placements of the unused flush relay - luckily tomorrow is Sunday

[apella12 (Bob Eckhoff)]

My caution is that the OH network map shows neighbors, not the actual route. It was not designed for diagnostic purposes. To get the actual routes in OH you need a zniffer and the silabs simplicity studio. Edit: the response times from the viewer would be a good way to judge connections. Probably every time under 100ms will be one or two hops. The other thing to note is that if the connection is not good the controller will send at slower speeds. Max is 100kbits a second, but 40 or 9.6kbits are also possible options.

[openB (Bernd)]

The network map doesn’t show actual routes, that’s true, but it gives a good visual impression if certain devices are rather central, with many connections, or not. With my new placement my controller is much better placed: 14 direct connections instead of 9; now I’m trying to optimize the placement of the flush device to get my device cluster better integrated.