Hi,
I am getting a bit frustrated because very simple things don’t work. But maybe you can help me:
I hab an OH 2 instance a few years ago.
Now I installed the newest OH3 on a raspberry. With a zwave controller dongle. As devices i have a magnetic switch a fibaro socket and a LED ligthbulb.
Yesterday a added the zwave binding, created the Controller dongle as a Bridge:
All three devices appeared in the inbox. But have not been recognized (Noder 002, Node 003, Node 004).
Looking back, i should just have waited longer till inclusin was completed.
I added one of them to see what happens, but deleted the item again.
Today I wanted to try again, but after reading more i think my controller and devices are in a limbo / undefined state.
No new devices apper in my inbox.
The switch i am trying to intergrate gets aparently recognized, when i start the “Scan” in openhab (see logfile domitech_ze27_00_000).
But the item does not apear in the inbox.
As you can see in the logfile the item gets recognizes, but my openhab does not promt it to me in the “Inbox”
Maybee because i added the LED which is working with uid “zwave:device:ZWaveBridge:node2” and now it is double?
2022-05-13 19:17:08.026 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery resolved to thingType zwave:domitech_ze27_00_000
It is all a bit confusing now, so some of my questions are:
If i click “Scan” under “Ad New Thing->zwaveBinding”, does this set my zwave controller to inclusion mode?
How do i get my controller to exclusion mode?
If item appear as NODE 003 in the inbox:
Should i add them as item, or wait until they are recognized correctly?
Any tips on how to reset all the mess and get all of it working again?
==> /var/log/openhab/events.log <==
2022-05-13 19:16:35.080 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'Switch' received command OFF
2022-05-13 19:16:35.083 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'Switch' predicted to become OFF
2022-05-13 19:16:35.092 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Switch' changed from ON to OFF
==> /var/log/openhab/openhab.log <==
2022-05-13 19:16:36.645 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling...
2022-05-13 19:16:36.648 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling zwave:device:ZWaveBridge:node2:switch_dimmer
2022-05-13 19:16:36.650 [DEBUG] [erter.ZWaveMultiLevelSwitchConverter] - NODE 2: Generating poll message for COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0
2022-05-13 19:16:36.652 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 2: Creating new message for command SWITCH_MULTILEVEL_GET
2022-05-13 19:16:36.656 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2022-05-13 19:16:36.658 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_SWITCH_MULTILEVEL is NOT required to be secured
2022-05-13 19:16:36.661 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling skipped for zwave:device:ZWaveBridge:node2:switch_dimmer on COMMAND_CLASS_BASIC
2022-05-13 19:16:36.664 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2022-05-13 19:16:36.666 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 145 to queue - size 1
2022-05-13 19:16:36.669 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2022-05-13 19:16:36.673 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 02 02 26 02 25 81 65
2022-05-13 19:16:36.677 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 09 00 13 02 02 26 02 25 81 65
2022-05-13 19:16:36.680 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2022-05-13 19:16:36.682 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2022-05-13 19:16:36.685 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2022-05-13 19:16:36.686 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 145: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 129
2022-05-13 19:16:36.688 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2022-05-13 19:16:36.689 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2022-05-13 19:16:36.691 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 145: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 129
2022-05-13 19:16:36.693 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2022-05-13 19:16:36.694 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2022-05-13 19:16:36.696 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2022-05-13 19:16:36.699 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 145: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 129
2022-05-13 19:16:36.701 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2022-05-13 19:16:36.704 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 145: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 129
2022-05-13 19:16:36.707 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2022-05-13 19:16:36.709 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2022-05-13 19:16:36.712 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 145: Advanced to WAIT_REQUEST
2022-05-13 19:16:36.715 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 145: Transaction not completed
2022-05-13 19:16:36.717 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 02 03 26 03 30 E6
2022-05-13 19:16:36.717 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2022-05-13 19:16:36.719 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2022-05-13 19:16:36.721 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 03 26 03 30
2022-05-13 19:16:36.725 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 03 26 03 30
2022-05-13 19:16:36.728 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 145: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 129
2022-05-13 19:16:36.730 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:DONE)
2022-05-13 19:16:36.733 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2022-05-13 19:16:36.735 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0
2022-05-13 19:16:36.738 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2022-05-13 19:16:36.741 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_SWITCH_MULTILEVEL V1 SWITCH_MULTILEVEL_REPORT
2022-05-13 19:16:36.744 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 2: Switch Multi Level report, value = 48
2022-05-13 19:16:36.747 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2022-05-13 19:16:36.750 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=48
2022-05-13 19:16:36.754 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:ZWaveBridge:node2:switch_dimmer to 48 [PercentType]
2022-05-13 19:16:36.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1.
2022-05-13 19:16:36.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1437225.
2022-05-13 19:16:36.764 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2022-05-13 19:16:36.767 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2022-05-13 19:16:36.771 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2022-05-13 19:16:36.772 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 81 00 00 08 62
2022-05-13 19:16:36.777 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=129, payload=81 00 00 08
2022-05-13 19:16:36.777 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2022-05-13 19:16:36.782 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=129, payload=81 00 00 08
2022-05-13 19:16:36.783 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 02 03 26 03 2E F8
2022-05-13 19:16:36.785 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 145: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 129
2022-05-13 19:16:36.788 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2022-05-13 19:16:36.788 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 03 26 03 2E
2022-05-13 19:16:36.790 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 145: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 129
2022-05-13 19:16:36.793 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 145: (Callback 129)
2022-05-13 19:16:36.796 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2022-05-13 19:16:36.798 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 145: callback 129
2022-05-13 19:16:36.801 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=129, payload=81 00 00 08
2022-05-13 19:16:36.804 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 129, Status = Transmission complete and ACK received(0)
2022-05-13 19:16:36.807 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2022-05-13 19:16:36.810 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 145: Advanced to WAIT_DATA
2022-05-13 19:16:36.813 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 145: Transaction not completed
2022-05-13 19:16:36.816 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 03 26 03 2E
2022-05-13 19:16:36.818 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2022-05-13 19:16:36.821 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:DONE)
2022-05-13 19:16:36.823 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2022-05-13 19:16:36.826 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0
2022-05-13 19:16:36.829 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2022-05-13 19:16:36.831 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_SWITCH_MULTILEVEL V1 SWITCH_MULTILEVEL_REPORT
2022-05-13 19:16:36.834 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 2: Switch Multi Level report, value = 46
2022-05-13 19:16:36.836 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2022-05-13 19:16:36.839 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=46
2022-05-13 19:16:36.842 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:ZWaveBridge:node2:switch_dimmer to 46 [PercentType]
2022-05-13 19:16:36.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1.
2022-05-13 19:16:36.848 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1ea0bf2.
2022-05-13 19:16:36.850 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1ea0bf2.
2022-05-13 19:16:36.853 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:145 DONE
2022-05-13 19:16:36.859 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2022-05-13 19:16:36.861 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2022-05-13 19:16:36.864 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2022-05-13 19:16:36.866 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2022-05-13 19:16:36.869 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2022-05-13 19:17:05.965 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:ZWaveBridge
2022-05-13 19:17:05.968 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do
2022-05-13 19:17:05.970 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:ZWaveBridge
2022-05-13 19:17:05.973 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
2022-05-13 19:17:05.977 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2022-05-13 19:17:05.980 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion
2022-05-13 19:17:05.983 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true.
2022-05-13 19:17:05.987 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 146 to queue - size 1
2022-05-13 19:17:05.990 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2022-05-13 19:17:05.993 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 82 F3
2022-05-13 19:17:05.997 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 82 F3
2022-05-13 19:17:06.000 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2022-05-13 19:17:06.002 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2022-05-13 19:17:06.004 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 146: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 130
2022-05-13 19:17:06.005 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2022-05-13 19:17:06.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2022-05-13 19:17:06.010 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 82 01 00 00 31
2022-05-13 19:17:06.012 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 146: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 130
2022-05-13 19:17:06.016 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2022-05-13 19:17:06.016 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=130, payload=82 01 00 00
2022-05-13 19:17:06.020 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=130, payload=82 01 00 00
2022-05-13 19:17:06.023 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 146: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 130
2022-05-13 19:17:06.026 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2022-05-13 19:17:06.029 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 146: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 130
2022-05-13 19:17:06.032 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 146: (Callback 130)
2022-05-13 19:17:06.035 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2022-05-13 19:17:06.038 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 146: callback 130
2022-05-13 19:17:06.041 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=130, payload=82 01 00 00
2022-05-13 19:17:06.045 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready.
2022-05-13 19:17:06.048 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart
2022-05-13 19:17:06.051 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 146: Transaction COMPLETED
2022-05-13 19:17:06.054 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 50ms
2022-05-13 19:17:06.057 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 146: Transaction completed
2022-05-13 19:17:06.060 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:146 DONE
2022-05-13 19:17:06.064 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2022-05-13 19:17:06.067 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2022-05-13 19:17:08.008 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery completed
2022-05-13 19:17:08.026 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery resolved to thingType zwave:domitech_ze27_00_000
2022-05-13 19:18:05.971 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:ZWaveBridge
2022-05-13 19:18:05.974 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeStart
2022-05-13 19:18:05.976 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2022-05-13 19:18:05.979 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 147 to queue - size 1
2022-05-13 19:18:05.981 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2022-05-13 19:18:05.985 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 83 36
2022-05-13 19:18:05.988 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 83 36
2022-05-13 19:18:05.991 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2022-05-13 19:18:05.992 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2022-05-13 19:18:05.995 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2022-05-13 19:18:05.998 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 147: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 131
2022-05-13 19:18:05.998 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2022-05-13 19:18:06.000 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2022-05-13 19:18:06.006 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2022-05-13 19:18:06.008 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2022-05-13 19:18:06.011 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2022-05-13 19:18:06.143 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 83 06 02 00 35
2022-05-13 19:18:06.147 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=131, payload=83 06 02 00
2022-05-13 19:18:06.150 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=131, payload=83 06 02 00
2022-05-13 19:18:06.153 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 147: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 131
2022-05-13 19:18:06.155 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2022-05-13 19:18:06.158 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 147: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 131
2022-05-13 19:18:06.160 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 147: (Callback 131)
2022-05-13 19:18:06.163 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2022-05-13 19:18:06.165 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 147: callback 131
2022-05-13 19:18:06.168 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=131, payload=83 06 02 00
2022-05-13 19:18:06.171 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
2022-05-13 19:18:06.174 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovered
2022-05-13 19:18:06.181 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveInclusionEvent
2022-05-13 19:18:06.184 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeDone, new event IncludeDone
2022-05-13 19:18:06.186 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2022-05-13 19:18:06.189 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 148 to queue - size 1
2022-05-13 19:18:06.192 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2022-05-13 19:18:06.194 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
2022-05-13 19:18:06.197 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done
2022-05-13 19:18:06.199 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 147: Advanced to DONE
2022-05-13 19:18:06.202 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 204ms
2022-05-13 19:18:06.204 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 147: Transaction completed
2022-05-13 19:18:06.206 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:147 DONE
2022-05-13 19:18:06.211 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2022-05-13 19:18:06.214 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2022-05-13 19:18:06.217 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5
2022-05-13 19:18:06.220 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5
2022-05-13 19:18:06.223 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2022-05-13 19:18:06.225 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2022-05-13 19:18:06.226 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 148: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2022-05-13 19:18:06.228 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2022-05-13 19:18:06.231 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2022-05-13 19:18:06.233 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 148: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2022-05-13 19:18:06.235 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2022-05-13 19:18:06.238 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2022-05-13 19:18:06.240 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2022-05-13 19:18:11.229 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 148: Timeout at state WAIT_REQUEST. 3 retries remaining.
2022-05-13 19:18:11.233 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 148: Transaction is current transaction, so clearing!!!!!
2022-05-13 19:18:11.235 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 148: Transaction CANCELLED
2022-05-13 19:18:11.238 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:148 CANCELLED
2022-05-13 19:18:11.243 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2022-05-13 19:29:58.065 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:ZWaveBridge
2022-05-13 19:32:19.259 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Command received zwave:device:ZWaveBridge:node2:switch_dimmer --> ON [OnOffType]
2022-05-13 19:32:19.263 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 2: Creating new message for command SWITCH_MULTILEVEL_SET
2022-05-13 19:32:19.266 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2022-05-13 19:32:19.268 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_SWITCH_MULTILEVEL is NOT required to be secured
2022-05-13 19:32:19.271 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2022-05-13 19:32:19.274 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 149 to queue - size 1
2022-05-13 19:32:19.276 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2022-05-13 19:32:19.280 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 02 03 26 01 FF 25 85 9F
2022-05-13 19:32:19.284 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 26 01 FF 25 85 9F
2022-05-13 19:32:19.287 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2022-05-13 19:32:19.289 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2022-05-13 19:32:19.290 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 149: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 133
2022-05-13 19:32:19.291 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2022-05-13 19:32:19.294 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2022-05-13 19:32:19.296 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling initialised at 1800 seconds - start in 1500 milliseconds.
2022-05-13 19:32:19.296 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2022-05-13 19:32:19.297 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 149: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 133
2022-05-13 19:32:19.300 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2022-05-13 19:32:19.300 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2022-05-13 19:32:19.303 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2022-05-13 19:32:19.305 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2022-05-13 19:32:19.308 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2022-05-13 19:32:19.311 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 149: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 133
2022-05-13 19:32:19.313 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 85 00 00 03 6D
2022-05-13 19:32:19.314 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2022-05-13 19:32:19.317 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 149: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 133
2022-05-13 19:32:19.317 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=133, payload=85 00 00 03
2022-05-13 19:32:19.320 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2022-05-13 19:32:19.323 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2022-05-13 19:32:19.325 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 149: Advanced to WAIT_REQUEST
2022-05-13 19:32:19.328 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 149: Transaction not completed
2022-05-13 19:32:19.331 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=133, payload=85 00 00 03
2022-05-13 19:32:19.333 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 149: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 133
2022-05-13 19:32:19.336 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2022-05-13 19:32:19.338 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 149: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 133
2022-05-13 19:32:19.341 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 149: (Callback 133)
2022-05-13 19:32:19.344 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2022-05-13 19:32:19.346 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 149: callback 133
2022-05-13 19:32:19.349 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=133, payload=85 00 00 03
2022-05-13 19:32:19.352 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 133, Status = Transmission complete and ACK received(0)
2022-05-13 19:32:19.355 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2022-05-13 19:32:19.357 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 149: Transaction COMPLETED
2022-05-13 19:32:19.360 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Response processed after 70ms
2022-05-13 19:32:19.363 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 149: Transaction completed
2022-05-13 19:32:19.365 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:149 DONE
2022-05-13 19:32:19.373 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2022-05-13 19:32:19.375 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2022-05-13 19:32:19.378 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
==> /var/log/openhab/events.log <==
2022-05-13 19:32:19.220 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'Switch' received command ON
2022-05-13 19:32:19.226 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'Switch' predicted to become ON
2022-05-13 19:32:19.235 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Switch' changed from OFF to ON
==> /var/log/openhab/openhab.log <==
2022-05-13 19:32:20.794 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling...
2022-05-13 19:32:20.797 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling zwave:device:ZWaveBridge:node2:switch_dimmer
2022-05-13 19:32:20.799 [DEBUG] [erter.ZWaveMultiLevelSwitchConverter] - NODE 2: Generating poll message for COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0
2022-05-13 19:32:20.801 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 2: Creating new message for command SWITCH_MULTILEVEL_GET
2022-05-13 19:32:20.803 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2022-05-13 19:32:20.806 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_SWITCH_MULTILEVEL is NOT required to be secured
2022-05-13 19:32:20.809 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling skipped for zwave:device:ZWaveBridge:node2:switch_dimmer on COMMAND_CLASS_BASIC
2022-05-13 19:32:20.812 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2022-05-13 19:32:20.815 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 150 to queue - size 1
2022-05-13 19:32:20.818 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2022-05-13 19:32:20.822 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 02 02 26 02 25 86 62
2022-05-13 19:32:20.825 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 09 00 13 02 02 26 02 25 86 62
2022-05-13 19:32:20.828 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2022-05-13 19:32:20.830 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2022-05-13 19:32:20.831 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 150: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 134
2022-05-13 19:32:20.833 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2022-05-13 19:32:20.836 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2022-05-13 19:32:20.838 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2022-05-13 19:32:20.839 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 150: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 134
2022-05-13 19:32:20.841 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2022-05-13 19:32:20.841 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2022-05-13 19:32:20.844 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2022-05-13 19:32:20.847 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 150: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 134
2022-05-13 19:32:20.850 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2022-05-13 19:32:20.852 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 150: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 134
2022-05-13 19:32:20.853 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 86 00 00 02 6F
2022-05-13 19:32:20.855 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2022-05-13 19:32:20.857 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=134, payload=86 00 00 02
2022-05-13 19:32:20.859 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2022-05-13 19:32:20.861 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 150: Advanced to WAIT_REQUEST
2022-05-13 19:32:20.864 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 150: Transaction not completed
2022-05-13 19:32:20.865 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 02 03 26 03 34 E2
2022-05-13 19:32:20.867 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=134, payload=86 00 00 02
2022-05-13 19:32:20.869 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 03 26 03 34
2022-05-13 19:32:20.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 150: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 134
2022-05-13 19:32:20.873 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2022-05-13 19:32:20.875 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 150: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 134
2022-05-13 19:32:20.878 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 150: (Callback 134)
2022-05-13 19:32:20.881 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2022-05-13 19:32:20.883 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 150: callback 134
2022-05-13 19:32:20.886 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=134, payload=86 00 00 02
2022-05-13 19:32:20.889 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 134, Status = Transmission complete and ACK received(0)
2022-05-13 19:32:20.892 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2022-05-13 19:32:20.895 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 150: Advanced to WAIT_DATA
2022-05-13 19:32:20.897 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 150: Transaction not completed
2022-05-13 19:32:20.900 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 03 26 03 34
2022-05-13 19:32:20.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2022-05-13 19:32:20.905 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:DONE)
2022-05-13 19:32:20.908 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2022-05-13 19:32:20.911 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0
2022-05-13 19:32:20.914 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2022-05-13 19:32:20.917 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_SWITCH_MULTILEVEL V1 SWITCH_MULTILEVEL_REPORT
2022-05-13 19:32:20.921 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 2: Switch Multi Level report, value = 52
2022-05-13 19:32:20.924 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2022-05-13 19:32:20.928 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=52
2022-05-13 19:32:20.931 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:ZWaveBridge:node2:switch_dimmer to 52 [PercentType]
2022-05-13 19:32:20.935 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1.
2022-05-13 19:32:20.938 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@122928c.
2022-05-13 19:32:20.941 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@122928c.
2022-05-13 19:32:20.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:150 DONE
2022-05-13 19:32:20.949 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2022-05-13 19:32:20.952 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2022-05-13 19:32:20.971 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2022-05-13 19:32:20.974 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2022-05-13 19:32:20.977 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2022-05-13 19:32:21.326 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Command received zwave:device:ZWaveBridge:node2:switch_dimmer --> OFF [OnOffType]
2022-05-13 19:32:21.329 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 2: Creating new message for command SWITCH_MULTILEVEL_SET
2022-05-13 19:32:21.331 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2022-05-13 19:32:21.334 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_SWITCH_MULTILEVEL is NOT required to be secured
2022-05-13 19:32:21.337 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2022-05-13 19:32:21.340 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 151 to queue - size 1
2022-05-13 19:32:21.343 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2022-05-13 19:32:21.347 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 02 03 26 01 00 25 87 62
2022-05-13 19:32:21.350 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 26 01 00 25 87 62
2022-05-13 19:32:21.354 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2022-05-13 19:32:21.356 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2022-05-13 19:32:21.357 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 151: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 135
2022-05-13 19:32:21.359 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2022-05-13 19:32:21.361 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling initialised at 1800 seconds - start in 1500 milliseconds.
2022-05-13 19:32:21.362 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2022-05-13 19:32:21.364 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2022-05-13 19:32:21.365 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 151: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 135
2022-05-13 19:32:21.367 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2022-05-13 19:32:21.368 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2022-05-13 19:32:21.370 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2022-05-13 19:32:21.373 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 151: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 135
2022-05-13 19:32:21.375 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2022-05-13 19:32:21.378 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 151: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 135
2022-05-13 19:32:21.379 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 87 00 00 02 6E
2022-05-13 19:32:21.381 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2022-05-13 19:32:21.383 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=135, payload=87 00 00 02
2022-05-13 19:32:21.384 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2022-05-13 19:32:21.387 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 151: Advanced to WAIT_REQUEST
2022-05-13 19:32:21.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 151: Transaction not completed
2022-05-13 19:32:21.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=135, payload=87 00 00 02
2022-05-13 19:32:21.395 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 151: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 135
2022-05-13 19:32:21.398 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2022-05-13 19:32:21.400 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 151: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 135
2022-05-13 19:32:21.403 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 151: (Callback 135)
2022-05-13 19:32:21.405 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2022-05-13 19:32:21.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 151: callback 135
2022-05-13 19:32:21.411 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=135, payload=87 00 00 02
2022-05-13 19:32:21.414 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 135, Status = Transmission complete and ACK received(0)
2022-05-13 19:32:21.416 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2022-05-13 19:32:21.419 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 151: Transaction COMPLETED
2022-05-13 19:32:21.421 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Response processed after 65ms
2022-05-13 19:32:21.424 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 151: Transaction completed
2022-05-13 19:32:21.426 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:151 DONE
2022-05-13 19:32:21.431 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2022-05-13 19:32:21.434 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2022-05-13 19:32:21.436 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.