Zwave binding seems to work, but No bridgeUID found

pilatus · October 15, 2023, 10:27pm

Platform information:
Release = Raspbian GNU/Linux 11 (bullseye)
Kernel = Linux 6.1.21-v8+
Platform = Raspberry Pi 4 Model B Rev 1.1
OpenHAB 4.0.3 - Release Build
Issue of the topic: After some issues with upgrading I decided to go for a clean install of OH4 and step-by-step add devices and functionality. I had no issues adding mutiple mqtt devices.
But as soon as I started to try and integrate my Aeotec Z Stick Gen 5 (which worked ok with OH2 and 3) I ran into issues. Though the stick seemed to be added as a Thing and even showed up online, it never showed the nodes in the discovery (I had one node connected).
So I went back, removed the binding, hard reset the stick, did reboots, I tried everything. Also search all the topics, but nothing really helped.
The Thing for the controller is installed and even online, but this debug message keeps coming every time I open the Thing in MainUI:
[DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:zstick

The code seems ok (I read something about the controller_sisnode)

UID: zwave:serial_zstick:zstick
label: Z-Wave Serial Controller
thingTypeUID: zwave:serial_zstick
configuration:
  controller_softreset: false
  security_networkkey: F7 9F 10 6B 45 0C 42 2D 4C 6D 03 E8 24 05 E9 7C
  security_inclusionmode: 0
  controller_sisnode: 1
  controller_maxawakeperiod: 10
  controller_sync: false
  controller_master: true
  inclusion_mode: 2
  port: /dev/ttyACM0
  controller_wakeupperiod: 3600
  controller_exclude: false
  heal_time: 2
  controller_inclusiontimeout: 30
  controller_hardreset: false

I have added the stick and it is online:

But whenever I open the Thing:

[DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:zstick

Below the install log (after removal and hard reset):

tail -f /var/log/openhab/openhab.log /var/log/openhab/events.log
Filter
==> /var/log/openhab/openhab.log <==
2023-10-15 14:01:40.795 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Stopping ZWave network
2023-10-15 14:01:40.797 [DEBUG] [ve.internal.protocol.ZWaveController] - Shutting down ZWave controller
2023-10-15 14:01:40.798 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Shutting down transaction manager
2023-10-15 14:01:40.799 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Exiting ZWave Receive Thread
2023-10-15 14:01:40.800 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction manager shutdown
2023-10-15 14:01:40.801 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller shutdown
2023-10-15 14:01:40.801 [DEBUG] [zwave.handler.ZWaveControllerHandler] - ZWave network stopped
2023-10-15 14:01:40.802 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Disposing receive thread
2023-10-15 14:01:40.803 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Stopped ZWave thread: Receive
2023-10-15 14:01:40.803 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Receive thread dispose
2023-10-15 14:01:40.804 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Disposing serial connection
2023-10-15 14:01:40.806 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial connection disposed
==> /var/log/openhab/events.log <==
==> /var/log/openhab/openhab.log <==
2023-10-15 14:01:45.821 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'
2023-10-15 14:01:45.830 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Starting receive thread
2023-10-15 14:01:45.831 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2023-10-15 14:01:45.831 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive
2023-10-15 14:01:45.832 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller
2023-10-15 14:01:45.834 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2023-10-15 14:01:45.834 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-15 14:01:45.834 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0A 00 0A 05 00 01 02 01 01 21 D8 
2023-10-15 14:01:45.835 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
2023-10-15 14:01:45.835 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-15 14:01:45.836 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2023-10-15 14:01:45.837 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2023-10-15 14:01:45.837 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 12 hours time.
==> /var/log/openhab/events.log <==
==> /var/log/openhab/openhab.log <==
2023-10-15 14:01:48.836 [DEBUG] [.ZWaveController$InitializeDelayTask] - Initialising network
2023-10-15 14:01:48.837 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 8 to queue - size 1
2023-10-15 14:01:48.837 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-15 14:01:48.838 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9 
2023-10-15 14:01:48.839 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9 
2023-10-15 14:01:48.839 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-15 14:01:48.840 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 8: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.840 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-15 14:01:48.841 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 9 to queue - size 1
2023-10-15 14:01:48.841 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-15 14:01:48.841 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-15 14:01:48.841 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-15 14:01:48.842 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 8: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.842 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-15 14:01:48.842 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 01 15 5A 2D 57 61 76 65 20 36 2E 30 37 00 01 97 
2023-10-15 14:01:48.843 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-15 14:01:48.843 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 10 to queue - size 2
2023-10-15 14:01:48.844 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-15 14:01:48.844 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 36 2E 30 37 00 01 
2023-10-15 14:01:48.844 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-15 14:01:48.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 11 to queue - size 3
2023-10-15 14:01:48.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 36 2E 30 37 00 01 
2023-10-15 14:01:48.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-15 14:01:48.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 8: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.846 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID
2023-10-15 14:01:48.846 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-15 14:01:48.847 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 8: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.847 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 12 to queue - size 4
2023-10-15 14:01:48.847 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 36 2E 30 37 00 01 
2023-10-15 14:01:48.848 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-15 14:01:48.848 [DEBUG] [serialmessage.GetVersionMessageClass] - Got MessageGetVersion response. Version=Z-Wave 6.07, Library Type=1
2023-10-15 14:01:48.849 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 8: Transaction COMPLETED
2023-10-15 14:01:48.849 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 9ms
2023-10-15 14:01:48.849 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 8: Transaction completed
2023-10-15 14:01:48.850 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:8 DONE
2023-10-15 14:01:48.850 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-15 14:01:48.851 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-15 14:01:48.851 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC 
2023-10-15 14:01:48.852 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC 
2023-10-15 14:01:48.853 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-15 14:01:48.853 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 9: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.854 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-15 14:01:48.855 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-15 14:01:48.855 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-15 14:01:48.856 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 9: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.856 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-15 14:01:48.857 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-15 14:01:48.857 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 01 20 FD E8 11 AA 01 79 
2023-10-15 14:01:48.857 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-15 14:01:48.858 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=FD E8 11 AA 01 
2023-10-15 14:01:48.859 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=FD E8 11 AA 01 
2023-10-15 14:01:48.859 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 9: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.859 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-15 14:01:48.860 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 9: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.860 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=FD E8 11 AA 01 
2023-10-15 14:01:48.861 [DEBUG] [erialmessage.MemoryGetIdMessageClass] - Got MessageMemoryGetId response. Home id = 0xfde811aa, Controller Node id = 1
2023-10-15 14:01:48.861 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 9: Transaction COMPLETED
2023-10-15 14:01:48.862 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 9ms
2023-10-15 14:01:48.862 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 9: Transaction completed
2023-10-15 14:01:48.862 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:9 DONE
2023-10-15 14:01:48.863 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-15 14:01:48.863 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-15 14:01:48.864 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 07 FB 
2023-10-15 14:01:48.865 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 07 FB 
2023-10-15 14:01:48.865 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-15 14:01:48.866 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 10: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.866 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-15 14:01:48.868 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-15 14:01:48.869 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-15 14:01:48.869 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 10: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-15 14:01:48.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-15 14:01:48.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-15 14:01:48.871 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 2B 01 07 01 02 00 86 00 01 00 5A FE 87 7F 88 CF 7F C0 4F FB DF FD E0 67 00 80 80 00 80 86 00 01 00 E8 73 00 80 0F 00 00 60 00 00 90 
2023-10-15 14:01:48.874 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=01 02 00 86 00 01 00 5A FE 87 7F 88 CF 7F C0 4F FB DF FD E0 67 00 80 80 00 80 86 00 01 00 E8 73 00 80 0F 00 00 60 00 00 
2023-10-15 14:01:48.876 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=01 02 00 86 00 01 00 5A FE 87 7F 88 CF 7F C0 4F FB DF FD E0 67 00 80 80 00 80 86 00 01 00 E8 73 00 80 0F 00 00 60 00 00 
2023-10-15 14:01:48.876 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 10: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.877 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-15 14:01:48.877 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 10: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.878 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=01 02 00 86 00 01 00 5A FE 87 7F 88 CF 7F C0 4F FB DF FD E0 67 00 80 80 00 80 86 00 01 00 E8 73 00 80 0F 00 00 60 00 00 
2023-10-15 14:01:48.879 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - API Version    = 1.2
2023-10-15 14:01:48.879 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Manufacture ID = 0x86
2023-10-15 14:01:48.879 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Device Type    = 0x1
2023-10-15 14:01:48.880 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Device ID      = 0x5a
2023-10-15 14:01:48.880 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 10: Transaction COMPLETED
2023-10-15 14:01:48.881 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 13 to queue - size 3
2023-10-15 14:01:48.881 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-15 14:01:48.881 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 15ms
2023-10-15 14:01:48.882 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 10: Transaction completed
2023-10-15 14:01:48.882 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:10 DONE
2023-10-15 14:01:48.883 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-15 14:01:48.883 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-15 14:01:48.884 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 06 96 0F 65 
2023-10-15 14:01:48.884 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 06 96 0F 65 
2023-10-15 14:01:48.885 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-15 14:01:48.885 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 11: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.886 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-15 14:01:48.887 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-15 14:01:48.887 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-15 14:01:48.888 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 11: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.888 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 01 06 96 0F 64 
2023-10-15 14:01:48.888 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-15 14:01:48.889 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-15 14:01:48.889 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-15 14:01:48.889 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 
2023-10-15 14:01:48.890 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 
2023-10-15 14:01:48.890 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 11: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.890 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-15 14:01:48.891 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 11: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.891 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 
2023-10-15 14:01:48.891 [DEBUG] [age.SerialApiSetTimeoutsMessageClass] - Got SerialApiSetTimeouts response. ACK=150, BYTE=15
2023-10-15 14:01:48.892 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 11: Transaction COMPLETED
2023-10-15 14:01:48.892 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 7ms
2023-10-15 14:01:48.892 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 11: Transaction completed
2023-10-15 14:01:48.893 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:11 DONE
2023-10-15 14:01:48.893 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-15 14:01:48.894 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-15 14:01:48.894 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 56 AA 
2023-10-15 14:01:48.895 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 56 AA 
2023-10-15 14:01:48.895 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-15 14:01:48.896 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 12: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.896 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-15 14:01:48.897 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-15 14:01:48.897 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-15 14:01:48.898 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 12: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.898 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 56 01 AD 
2023-10-15 14:01:48.898 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-15 14:01:48.898 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-15 14:01:48.899 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 
2023-10-15 14:01:48.899 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-15 14:01:48.899 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 
2023-10-15 14:01:48.900 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 12: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.900 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-15 14:01:48.900 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 12: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.901 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 
2023-10-15 14:01:48.901 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Got SUC NodeID response.
2023-10-15 14:01:48.901 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - NODE 1: Node is SUC.
2023-10-15 14:01:48.902 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 12: Transaction COMPLETED
2023-10-15 14:01:48.902 [DEBUG] [etControllerCapabilitiesMessageClass] - Creating GET_CONTROLLER_CAPABILITIES message
2023-10-15 14:01:48.902 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 14 to queue - size 2
2023-10-15 14:01:48.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-15 14:01:48.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 7ms
2023-10-15 14:01:48.904 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 12: Transaction completed
2023-10-15 14:01:48.904 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:12 DONE
2023-10-15 14:01:48.904 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-15 14:01:48.905 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-15 14:01:48.905 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 02 FE 
2023-10-15 14:01:48.906 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 02 FE 
2023-10-15 14:01:48.906 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-15 14:01:48.907 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 13: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.907 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-15 14:01:48.908 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-15 14:01:48.909 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-15 14:01:48.910 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 13: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:48.910 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-15 14:01:48.911 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-15 14:01:48.912 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-15 14:01:49.010 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 25 01 02 08 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 C0 
2023-10-15 14:01:49.013 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=08 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 
2023-10-15 14:01:49.015 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=08 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 
2023-10-15 14:01:49.016 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 13: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:49.016 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-15 14:01:49.017 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 13: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:49.018 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=08 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 
2023-10-15 14:01:49.018 [DEBUG] [age.SerialApiGetInitDataMessageClass] - Got MessageSerialApiGetInitData response.
2023-10-15 14:01:49.019 [DEBUG] [age.SerialApiGetInitDataMessageClass] - NODE 1: Node found
2023-10-15 14:01:49.025 [DEBUG] [age.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API
2023-10-15 14:01:49.026 [DEBUG] [age.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller
2023-10-15 14:01:49.026 [DEBUG] [age.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------
2023-10-15 14:01:49.027 [DEBUG] [age.SerialApiGetInitDataMessageClass] - # Nodes = 1
2023-10-15 14:01:49.027 [DEBUG] [age.SerialApiGetInitDataMessageClass] - ----------------------------------------------------------------------------
2023-10-15 14:01:49.028 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 13: Transaction COMPLETED
2023-10-15 14:01:49.029 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 1: Init node thread start
2023-10-15 14:01:49.029 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 122ms
2023-10-15 14:01:49.029 [DEBUG] [ve.internal.protocol.ZWaveController] - Starting waiting for init threads
2023-10-15 14:01:49.030 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 13: Transaction completed
2023-10-15 14:01:49.031 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:13 DONE
2023-10-15 14:01:49.031 [DEBUG] [ve.internal.protocol.ZWaveController] - Waiting for init thread Node_1_init
2023-10-15 14:01:49.032 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-15 14:01:49.032 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-15 14:01:49.033 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 05 F9 
2023-10-15 14:01:49.034 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 05 F9 
2023-10-15 14:01:49.035 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-15 14:01:49.036 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-15 14:01:49.036 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 14: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:49.037 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-15 14:01:49.037 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-15 14:01:49.038 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 05 3C C3 
2023-10-15 14:01:49.038 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 14: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:49.039 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-15 14:01:49.039 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=3C 
2023-10-15 14:01:49.040 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-15 14:01:49.041 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-15 14:01:49.041 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=3C 
2023-10-15 14:01:49.042 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 14: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:49.043 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-15 14:01:49.044 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 14: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:49.045 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=3C 
2023-10-15 14:01:49.046 [DEBUG] [etControllerCapabilitiesMessageClass] - Controller is secondary = false
2023-10-15 14:01:49.046 [DEBUG] [etControllerCapabilitiesMessageClass] - Controller is on other network = false
2023-10-15 14:01:49.047 [DEBUG] [etControllerCapabilitiesMessageClass] - Node ID Server is present = false
2023-10-15 14:01:49.048 [DEBUG] [etControllerCapabilitiesMessageClass] - Controller is real primary = true
2023-10-15 14:01:49.049 [DEBUG] [etControllerCapabilitiesMessageClass] - Controller is SUC = true
2023-10-15 14:01:49.049 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 14: Transaction COMPLETED
2023-10-15 14:01:49.050 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 14ms
2023-10-15 14:01:49.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 14: Transaction completed
2023-10-15 14:01:49.052 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:14 DONE
2023-10-15 14:01:49.053 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-15 14:01:49.054 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-15 14:01:49.099 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 1: Serializing from file /var/lib/openhab/zwave/network_fde811aa__node_1.xml
2023-10-15 14:01:49.111 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 1: Restore from config: Ok.
2023-10-15 14:01:49.112 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
2023-10-15 14:01:49.113 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_BASIC, endpoint 0 created
2023-10-15 14:01:49.114 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Starting initialisation from EMPTYNODE
2023-10-15 14:01:49.115 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 1: Init node thread finished
2023-10-15 14:01:49.115 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to IDENTIFY_NODE
2023-10-15 14:01:49.115 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: Initialisation starting
2023-10-15 14:01:49.115 [DEBUG] [ve.internal.protocol.ZWaveController] - Init thread Node_1_init complete
2023-10-15 14:01:49.116 [DEBUG] [ve.internal.protocol.ZWaveController] - All init threads complete
2023-10-15 14:01:49.116 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@b021cc
2023-10-15 14:01:49.116 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller: Incoming Network State Event true
2023-10-15 14:01:49.117 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 15 to queue - size 1
2023-10-15 14:01:49.118 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-15 14:01:49.119 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 01 BB 
2023-10-15 14:01:49.120 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 01 BB 
2023-10-15 14:01:49.121 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-15 14:01:49.122 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-15 14:01:49.122 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 15: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:49.122 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-15 14:01:49.123 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-15 14:01:49.123 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:49.123 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 D3 16 01 02 02 01 73 
2023-10-15 14:01:49.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-15 14:01:49.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-15 14:01:49.125 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 
2023-10-15 14:01:49.125 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-15 14:01:49.126 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 
2023-10-15 14:01:49.126 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 15: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:49.126 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-15 14:01:49.127 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 15: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-15 14:01:49.127 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 
2023-10-15 14:01:49.128 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: ProtocolInfo
2023-10-15 14:01:49.129 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Listening = true
2023-10-15 14:01:49.129 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Routing   = true
2023-10-15 14:01:49.130 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Beaming   = true
2023-10-15 14:01:49.130 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Version   = 4
2023-10-15 14:01:49.130 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: FLIRS     = false
2023-10-15 14:01:49.131 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Security  = false
2023-10-15 14:01:49.131 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Max Baud  = 40000
2023-10-15 14:01:49.132 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Basic    = BASIC_TYPE_STATIC_CONTROLLER
2023-10-15 14:01:49.132 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Generic  = GENERIC_TYPE_STATIC_CONTROLLER
2023-10-15 14:01:49.132 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Specific = SPECIFIC_TYPE_PC_CONTROLLER
2023-10-15 14:01:49.133 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class COMMAND_CLASS_NO_OPERATION
2023-10-15 14:01:49.133 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
2023-10-15 14:01:49.134 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Version = 1, version set. Enabling extra functionality.
2023-10-15 14:01:49.134 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 1: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes.
2023-10-15 14:01:49.135 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class COMMAND_CLASS_BASIC
2023-10-15 14:01:49.136 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_BASIC, endpoint 0 created
2023-10-15 14:01:49.136 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 1: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes.
2023-10-15 14:01:49.137 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 15: Transaction COMPLETED
2023-10-15 14:01:49.137 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 15ms
2023-10-15 14:01:49.138 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 15: Transaction completed
2023-10-15 14:01:49.138 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:15 DONE
2023-10-15 14:01:49.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-15 14:01:49.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 15: Transaction event listener: DONE: DONE -> UNINTIALIZED
2023-10-15 14:01:49.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-15 14:01:49.140 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@484abc
2023-10-15 14:01:49.140 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node Init transaction completed with response COMPLETE
2023-10-15 14:01:49.141 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: FAILED_CHECK - Controller - terminating initialisation
2023-10-15 14:01:49.141 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to DONE
2023-10-15 14:01:49.142 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 1: Serializing to file /var/lib/openhab/zwave/network_fde811aa__node_1.xml
2023-10-15 14:01:49.407 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:zstick

I have to admit that I am a bit desperate at the moment I think I tried everything and did everything right. I am no Linux wizard, so I would really need some guidance here.

apella12 · October 16, 2023, 12:24am

I’m not sure that is a problem. I’m not at my desk, but the controller is the bridge, so it doesn’t have a bridge uid. Have you tried to scan for your device?

pilatus · October 16, 2023, 4:51am

Ok, I did scan for my devices before I did the hard reset, and nothing was found. But just to exclude it, I will add one device and scan for it once again.

pilatus · October 16, 2023, 9:30am

So I have added one device (motion sensor) and did the scan (I just found out that the ‘Scan’ button first appears after some waiting time).

Openhab indeed seems to find the second node, though it is not completely initialized, a behaviour that I recognise from previous versions. Below the log:

==> /var/log/openhab/openhab.log <==
2023-10-16 11:12:14.546 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Stopping ZWave network
2023-10-16 11:12:14.548 [DEBUG] [ve.internal.protocol.ZWaveController] - Shutting down ZWave controller
2023-10-16 11:12:14.549 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Shutting down transaction manager
2023-10-16 11:12:14.551 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Exiting ZWave Receive Thread
2023-10-16 11:12:14.552 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction manager shutdown
2023-10-16 11:12:14.555 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node Init transaction completed with response TIMEOUT_WAITING_FOR_RESPONSE
2023-10-16 11:12:14.556 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to DONE
2023-10-16 11:12:14.558 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 1: Serializing to file /var/lib/openhab/zwave/network_fde811aa__node_1.xml
2023-10-16 11:12:14.568 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller shutdown
2023-10-16 11:12:14.569 [DEBUG] [zwave.handler.ZWaveControllerHandler] - ZWave network stopped
2023-10-16 11:12:14.571 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Disposing receive thread
2023-10-16 11:12:14.576 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Stopped ZWave thread: Receive
2023-10-16 11:12:14.578 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Receive thread dispose
2023-10-16 11:12:14.579 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Disposing serial connection
2023-10-16 11:12:14.584 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial connection disposed
==> /var/log/openhab/events.log <==
2023-10-16 11:12:14.548 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zwave:serial_zstick:zstick' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Serial Error: Port /dev/ttyACM0 does not exist

--

==> /var/log/openhab/openhab.log <==
2023-10-16 11:16:19.621 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'
2023-10-16 11:16:19.634 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Starting receive thread
2023-10-16 11:16:19.636 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2023-10-16 11:16:19.637 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive
2023-10-16 11:16:19.638 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller
2023-10-16 11:16:19.641 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2023-10-16 11:16:19.641 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:16:19.642 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-16 11:16:19.643 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
2023-10-16 11:16:19.646 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2023-10-16 11:16:19.647 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2023-10-16 11:16:19.648 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 15 hours time.

--

==> /var/log/openhab/openhab.log <==
2023-10-16 11:16:22.646 [DEBUG] [.ZWaveController$InitializeDelayTask] - Initialising network
2023-10-16 11:16:22.648 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 52 to queue - size 1
2023-10-16 11:16:22.649 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-16 11:16:22.650 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9 
2023-10-16 11:16:22.651 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9 
2023-10-16 11:16:22.652 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-16 11:16:22.653 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-16 11:16:22.654 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 52: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.655 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.655 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 53 to queue - size 1
2023-10-16 11:16:22.656 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.656 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-16 11:16:22.657 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 52: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.657 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 54 to queue - size 2
2023-10-16 11:16:22.658 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-16 11:16:22.658 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-16 11:16:22.658 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 01 15 5A 2D 57 61 76 65 20 36 2E 30 37 00 01 97 
2023-10-16 11:16:22.658 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:16:22.659 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 55 to queue - size 3
2023-10-16 11:16:22.660 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-16 11:16:22.660 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 36 2E 30 37 00 01 
2023-10-16 11:16:22.661 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-16 11:16:22.661 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID
2023-10-16 11:16:22.662 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 56 to queue - size 4
2023-10-16 11:16:22.662 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 36 2E 30 37 00 01 
2023-10-16 11:16:22.663 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-16 11:16:22.663 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 52: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.664 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-16 11:16:22.665 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 52: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.666 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 36 2E 30 37 00 01 
2023-10-16 11:16:22.667 [DEBUG] [serialmessage.GetVersionMessageClass] - Got MessageGetVersion response. Version=Z-Wave 6.07, Library Type=1
2023-10-16 11:16:22.667 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 52: Transaction COMPLETED
2023-10-16 11:16:22.668 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 15ms
2023-10-16 11:16:22.669 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 52: Transaction completed
2023-10-16 11:16:22.670 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:52 DONE
2023-10-16 11:16:22.671 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:16:22.672 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-16 11:16:22.673 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC 
2023-10-16 11:16:22.674 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC 
2023-10-16 11:16:22.674 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-16 11:16:22.675 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-16 11:16:22.675 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 53: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.676 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.677 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.678 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 53: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.678 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 01 20 FD E8 11 AA 01 79 
2023-10-16 11:16:22.679 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-16 11:16:22.680 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:16:22.680 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=FD E8 11 AA 01 
2023-10-16 11:16:22.680 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-16 11:16:22.681 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=FD E8 11 AA 01 
2023-10-16 11:16:22.682 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 53: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.683 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-16 11:16:22.683 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 53: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.684 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=FD E8 11 AA 01 
2023-10-16 11:16:22.685 [DEBUG] [erialmessage.MemoryGetIdMessageClass] - Got MessageMemoryGetId response. Home id = 0xfde811aa, Controller Node id = 1
2023-10-16 11:16:22.686 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 53: Transaction COMPLETED
2023-10-16 11:16:22.687 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 12ms
2023-10-16 11:16:22.687 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 53: Transaction completed
2023-10-16 11:16:22.688 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:53 DONE
2023-10-16 11:16:22.689 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:16:22.690 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-16 11:16:22.691 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 07 FB 
2023-10-16 11:16:22.692 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 07 FB 
2023-10-16 11:16:22.693 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-16 11:16:22.694 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 54: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.694 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-16 11:16:22.696 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.697 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.698 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 54: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.699 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-16 11:16:22.700 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:16:22.700 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 2B 01 07 01 02 00 86 00 01 00 5A FE 87 7F 88 CF 7F C0 4F FB DF FD E0 67 00 80 80 00 80 86 00 01 00 E8 73 00 80 0F 00 00 60 00 00 90 
2023-10-16 11:16:22.700 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-16 11:16:22.703 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=01 02 00 86 00 01 00 5A FE 87 7F 88 CF 7F C0 4F FB DF FD E0 67 00 80 80 00 80 86 00 01 00 E8 73 00 80 0F 00 00 60 00 00 
2023-10-16 11:16:22.705 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=01 02 00 86 00 01 00 5A FE 87 7F 88 CF 7F C0 4F FB DF FD E0 67 00 80 80 00 80 86 00 01 00 E8 73 00 80 0F 00 00 60 00 00 
2023-10-16 11:16:22.706 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 54: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.706 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-16 11:16:22.707 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 54: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.708 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=01 02 00 86 00 01 00 5A FE 87 7F 88 CF 7F C0 4F FB DF FD E0 67 00 80 80 00 80 86 00 01 00 E8 73 00 80 0F 00 00 60 00 00 
2023-10-16 11:16:22.710 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - API Version    = 1.2
2023-10-16 11:16:22.710 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Manufacture ID = 0x86
2023-10-16 11:16:22.711 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Device Type    = 0x1
2023-10-16 11:16:22.712 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Device ID      = 0x5a
2023-10-16 11:16:22.713 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 54: Transaction COMPLETED
2023-10-16 11:16:22.714 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 57 to queue - size 3
2023-10-16 11:16:22.715 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-16 11:16:22.716 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 22ms
2023-10-16 11:16:22.717 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 54: Transaction completed
2023-10-16 11:16:22.718 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:54 DONE
2023-10-16 11:16:22.719 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:16:22.720 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-16 11:16:22.722 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 06 96 0F 65 
2023-10-16 11:16:22.722 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 06 96 0F 65 
2023-10-16 11:16:22.724 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-16 11:16:22.724 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 55: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.725 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-16 11:16:22.726 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.726 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.727 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 01 06 96 0F 64 
2023-10-16 11:16:22.728 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 55: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.728 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-16 11:16:22.729 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 
2023-10-16 11:16:22.729 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:16:22.730 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-16 11:16:22.731 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 
2023-10-16 11:16:22.732 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 55: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.733 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-16 11:16:22.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 55: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.735 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 
2023-10-16 11:16:22.736 [DEBUG] [age.SerialApiSetTimeoutsMessageClass] - Got SerialApiSetTimeouts response. ACK=150, BYTE=15
2023-10-16 11:16:22.737 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 55: Transaction COMPLETED
2023-10-16 11:16:22.737 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 13ms
2023-10-16 11:16:22.737 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 55: Transaction completed
2023-10-16 11:16:22.738 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:55 DONE
2023-10-16 11:16:22.738 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:16:22.739 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-16 11:16:22.739 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 56 AA 
2023-10-16 11:16:22.740 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 56 AA 
2023-10-16 11:16:22.740 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-16 11:16:22.741 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 56: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.741 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-16 11:16:22.741 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.742 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.742 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 56 01 AD 
2023-10-16 11:16:22.742 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 56: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.743 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-16 11:16:22.743 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 
2023-10-16 11:16:22.743 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 
2023-10-16 11:16:22.744 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 56: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.744 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-16 11:16:22.744 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 56: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.745 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 
2023-10-16 11:16:22.745 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Got SUC NodeID response.
2023-10-16 11:16:22.746 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - NODE 1: Node is SUC.
2023-10-16 11:16:22.746 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 56: Transaction COMPLETED
2023-10-16 11:16:22.746 [DEBUG] [etControllerCapabilitiesMessageClass] - Creating GET_CONTROLLER_CAPABILITIES message
2023-10-16 11:16:22.747 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 58 to queue - size 2
2023-10-16 11:16:22.747 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-16 11:16:22.748 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 7ms
2023-10-16 11:16:22.748 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 56: Transaction completed
2023-10-16 11:16:22.748 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:56 DONE
2023-10-16 11:16:22.749 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:16:22.749 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-16 11:16:22.750 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 02 FE 
2023-10-16 11:16:22.750 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 02 FE 
2023-10-16 11:16:22.751 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-16 11:16:22.751 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 57: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.752 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-16 11:16:22.752 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.753 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.753 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 57: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.753 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-16 11:16:22.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:16:22.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-16 11:16:22.851 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 25 01 02 08 08 1D 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 C2 
2023-10-16 11:16:22.853 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=08 08 1D 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 
2023-10-16 11:16:22.853 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=08 08 1D 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 
2023-10-16 11:16:22.854 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 57: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.854 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-16 11:16:22.855 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 57: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.855 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=08 08 1D 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 
2023-10-16 11:16:22.856 [DEBUG] [age.SerialApiGetInitDataMessageClass] - Got MessageSerialApiGetInitData response.
2023-10-16 11:16:22.856 [DEBUG] [age.SerialApiGetInitDataMessageClass] - NODE 1: Node found
2023-10-16 11:16:22.857 [DEBUG] [age.SerialApiGetInitDataMessageClass] - NODE 2: Node found
2023-10-16 11:16:22.860 [DEBUG] [age.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API
2023-10-16 11:16:22.860 [DEBUG] [age.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller
2023-10-16 11:16:22.861 [DEBUG] [age.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------
2023-10-16 11:16:22.861 [DEBUG] [age.SerialApiGetInitDataMessageClass] - # Nodes = 2
2023-10-16 11:16:22.861 [DEBUG] [age.SerialApiGetInitDataMessageClass] - ----------------------------------------------------------------------------
2023-10-16 11:16:22.862 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 57: Transaction COMPLETED
2023-10-16 11:16:22.863 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 1: Init node thread start
2023-10-16 11:16:22.863 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 2: Init node thread start
2023-10-16 11:16:22.863 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 112ms
2023-10-16 11:16:22.863 [DEBUG] [ve.internal.protocol.ZWaveController] - Starting waiting for init threads
2023-10-16 11:16:22.863 [DEBUG] [ve.internal.protocol.ZWaveController] - Waiting for init thread Node_1_init
2023-10-16 11:16:22.864 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 57: Transaction completed
2023-10-16 11:16:22.864 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:57 DONE
2023-10-16 11:16:22.865 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:16:22.866 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-16 11:16:22.866 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 05 F9 
2023-10-16 11:16:22.867 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 05 F9 
2023-10-16 11:16:22.868 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-16 11:16:22.868 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-16 11:16:22.868 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 58: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.869 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.870 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 05 1C E3 
2023-10-16 11:16:22.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 58: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.871 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=1C 
2023-10-16 11:16:22.871 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-16 11:16:22.871 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=1C 
2023-10-16 11:16:22.872 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 58: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.872 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-16 11:16:22.873 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 58: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.874 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=1C 
2023-10-16 11:16:22.874 [DEBUG] [etControllerCapabilitiesMessageClass] - Controller is secondary = false
2023-10-16 11:16:22.875 [DEBUG] [etControllerCapabilitiesMessageClass] - Controller is on other network = false
2023-10-16 11:16:22.875 [DEBUG] [etControllerCapabilitiesMessageClass] - Node ID Server is present = false
2023-10-16 11:16:22.876 [DEBUG] [etControllerCapabilitiesMessageClass] - Controller is real primary = true
2023-10-16 11:16:22.876 [DEBUG] [etControllerCapabilitiesMessageClass] - Controller is SUC = true
2023-10-16 11:16:22.877 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 58: Transaction COMPLETED
2023-10-16 11:16:22.877 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 9ms
2023-10-16 11:16:22.878 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 58: Transaction completed
2023-10-16 11:16:22.879 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:58 DONE
2023-10-16 11:16:22.880 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:16:22.880 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-16 11:16:22.908 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 1: Serializing from file /var/lib/openhab/zwave/network_fde811aa__node_1.xml
2023-10-16 11:16:22.908 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 2: Serializing from file /var/lib/openhab/zwave/network_fde811aa__node_2.xml
2023-10-16 11:16:22.909 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 2: Error serializing from file: file does not exist.
2023-10-16 11:16:22.910 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Starting initialisation from EMPTYNODE
2023-10-16 11:16:22.911 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 2: Init node thread finished
2023-10-16 11:16:22.911 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - advancing to IDENTIFY_NODE
2023-10-16 11:16:22.912 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: Initialisation starting
2023-10-16 11:16:22.913 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1dded20
2023-10-16 11:16:22.915 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 59 to queue - size 1
2023-10-16 11:16:22.915 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-16 11:16:22.916 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 02 B8 
2023-10-16 11:16:22.917 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 02 B8 
2023-10-16 11:16:22.917 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-16 11:16:22.918 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-16 11:16:22.919 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.919 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 59: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.920 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 1: Restore from config: Ok.
2023-10-16 11:16:22.920 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.920 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 53 9C 01 04 07 01 7A 
2023-10-16 11:16:22.920 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 59: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.921 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-16 11:16:22.921 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
2023-10-16 11:16:22.921 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:16:22.921 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 07 01 
2023-10-16 11:16:22.922 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-16 11:16:22.922 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_BASIC, endpoint 0 created
2023-10-16 11:16:22.922 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 07 01 
2023-10-16 11:16:22.922 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 59: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.922 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Starting initialisation from EMPTYNODE
2023-10-16 11:16:22.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-16 11:16:22.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 59: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.924 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 1: Init node thread finished
2023-10-16 11:16:22.924 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 07 01 
2023-10-16 11:16:22.924 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to IDENTIFY_NODE
2023-10-16 11:16:22.924 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: Initialisation starting
2023-10-16 11:16:22.924 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: ProtocolInfo
2023-10-16 11:16:22.924 [DEBUG] [ve.internal.protocol.ZWaveController] - Init thread Node_1_init complete
2023-10-16 11:16:22.925 [DEBUG] [ve.internal.protocol.ZWaveController] - Waiting for init thread Node_2_init
2023-10-16 11:16:22.925 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Listening = false
2023-10-16 11:16:22.925 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1601c74
2023-10-16 11:16:22.925 [DEBUG] [ve.internal.protocol.ZWaveController] - Init thread Node_2_init complete
2023-10-16 11:16:22.925 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Routing   = true
2023-10-16 11:16:22.925 [DEBUG] [ve.internal.protocol.ZWaveController] - All init threads complete
2023-10-16 11:16:22.926 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Beaming   = true
2023-10-16 11:16:22.926 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 60 to queue - size 1
2023-10-16 11:16:22.926 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller: Incoming Network State Event true
2023-10-16 11:16:22.926 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Version   = 4
2023-10-16 11:16:22.926 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-16 11:16:22.926 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: FLIRS     = false
2023-10-16 11:16:22.927 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Security  = false
2023-10-16 11:16:22.927 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Max Baud  = 40000
2023-10-16 11:16:22.928 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Basic    = BASIC_TYPE_ROUTING_SLAVE
2023-10-16 11:16:22.929 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Generic  = GENERIC_TYPE_SENSOR_NOTIFICATION
2023-10-16 11:16:22.929 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Specific = SPECIFIC_TYPE_NOTIFICATION_SENSOR
2023-10-16 11:16:22.930 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class COMMAND_CLASS_NO_OPERATION
2023-10-16 11:16:22.931 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
2023-10-16 11:16:22.931 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Version = 1, version set. Enabling extra functionality.
2023-10-16 11:16:22.932 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes.
2023-10-16 11:16:22.933 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class COMMAND_CLASS_BASIC
2023-10-16 11:16:22.934 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_BASIC, endpoint 0 created
2023-10-16 11:16:22.934 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes.
2023-10-16 11:16:22.935 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 59: Transaction COMPLETED
2023-10-16 11:16:22.936 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 17ms
2023-10-16 11:16:22.937 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 59: Transaction completed
2023-10-16 11:16:22.937 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:59 DONE
2023-10-16 11:16:22.938 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:16:22.938 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 59: Transaction event listener: DONE: DONE -> UNINTIALIZED
2023-10-16 11:16:22.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-16 11:16:22.940 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1258650
2023-10-16 11:16:22.940 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init transaction completed with response COMPLETE
2023-10-16 11:16:22.941 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - advancing to REQUEST_NIF
2023-10-16 11:16:22.941 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 01 BB 
2023-10-16 11:16:22.942 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 01 BB 
2023-10-16 11:16:22.942 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@16d40b6
2023-10-16 11:16:22.943 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Bump transaction 61 priority from Controller to Immediate
2023-10-16 11:16:22.943 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-16 11:16:22.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 60: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.945 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2023-10-16 11:16:22.945 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 61 to queue - size 1
2023-10-16 11:16:22.946 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-16 11:16:22.960 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-16 11:16:22.961 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.961 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:16:22.962 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 D3 16 01 02 02 01 73 
2023-10-16 11:16:22.962 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 60: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.962 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-16 11:16:22.963 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 
2023-10-16 11:16:22.963 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:16:22.963 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-16 11:16:22.964 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 
2023-10-16 11:16:22.964 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 60: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.965 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-16 11:16:22.965 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 60: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2023-10-16 11:16:22.965 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 
2023-10-16 11:16:22.966 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: ProtocolInfo
2023-10-16 11:16:22.966 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Listening = true
2023-10-16 11:16:22.967 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Routing   = true
2023-10-16 11:16:22.967 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Beaming   = true
2023-10-16 11:16:22.967 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Version   = 4
2023-10-16 11:16:22.968 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: FLIRS     = false
2023-10-16 11:16:22.968 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Security  = false
2023-10-16 11:16:22.968 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Max Baud  = 40000
2023-10-16 11:16:22.969 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Basic    = BASIC_TYPE_STATIC_CONTROLLER
2023-10-16 11:16:22.969 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Generic  = GENERIC_TYPE_STATIC_CONTROLLER
2023-10-16 11:16:22.969 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Specific = SPECIFIC_TYPE_PC_CONTROLLER
2023-10-16 11:16:22.970 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class COMMAND_CLASS_NO_OPERATION
2023-10-16 11:16:22.970 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
2023-10-16 11:16:22.971 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Version = 1, version set. Enabling extra functionality.
2023-10-16 11:16:22.971 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 1: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes.
2023-10-16 11:16:22.971 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class COMMAND_CLASS_BASIC
2023-10-16 11:16:22.972 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_BASIC, endpoint 0 created
2023-10-16 11:16:22.972 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 1: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes.
2023-10-16 11:16:22.973 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 60: Transaction COMPLETED
2023-10-16 11:16:22.973 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 29ms
2023-10-16 11:16:22.973 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 60: Transaction completed
2023-10-16 11:16:22.974 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:60 DONE
2023-10-16 11:16:22.974 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:16:22.975 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 60: Transaction event listener: DONE: DONE -> UNINTIALIZED
2023-10-16 11:16:22.975 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-16 11:16:22.975 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1987704
2023-10-16 11:16:22.976 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node Init transaction completed with response COMPLETE
2023-10-16 11:16:22.976 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: FAILED_CHECK - Controller - terminating initialisation
2023-10-16 11:16:22.976 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to DONE
2023-10-16 11:16:22.977 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 1: Serializing to file /var/lib/openhab/zwave/network_fde811aa__node_1.xml
==> /var/log/openhab/events.log <==
2023-10-16 11:16:22.934 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'zwave:serial_zstick:zstick' changed from OFFLINE (COMMUNICATION_ERROR): Serial Error: Port /dev/ttyACM0 does not exist to ONLINE

---

==> /var/log/openhab/openhab.log <==
2023-10-16 11:18:27.274 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:zstick


==> /var/log/openhab/openhab.log <==
2023-10-16 11:19:36.644 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - ZWave product zwave:serial_zstick has no references!
2023-10-16 11:19:36.648 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - ZWave product zwave:device has no references!
==> /var/log/openhab/events.log <==

---

==> /var/log/openhab/openhab.log <==
2023-10-16 11:19:38.638 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:zstick
2023-10-16 11:19:38.639 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do
2023-10-16 11:19:38.640 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:zstick
2023-10-16 11:19:38.641 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
2023-10-16 11:19:38.642 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2023-10-16 11:19:38.643 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion
2023-10-16 11:19:38.645 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true.
2023-10-16 11:19:38.646 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 62 to queue - size 1
2023-10-16 11:19:38.646 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-10-16 11:19:38.647 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 85 F4 
2023-10-16 11:19:38.648 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 85 F4 
2023-10-16 11:19:38.648 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-10-16 11:19:38.649 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 62: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 133
2023-10-16 11:19:38.649 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-10-16 11:19:38.650 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:19:38.650 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-10-16 11:19:38.651 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 62: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 133
2023-10-16 11:19:38.652 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-10-16 11:19:38.652 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 85 01 00 00 36 
2023-10-16 11:19:38.652 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:19:38.652 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=133, payload=85 01 00 00 
2023-10-16 11:19:38.653 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-10-16 11:19:38.653 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=133, payload=85 01 00 00 
2023-10-16 11:19:38.654 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 62: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 133
2023-10-16 11:19:38.654 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-10-16 11:19:38.655 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 62: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 133
2023-10-16 11:19:38.655 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 62: (Callback 133)
2023-10-16 11:19:38.656 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2023-10-16 11:19:38.656 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 62: callback 133
2023-10-16 11:19:38.656 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=133, payload=85 01 00 00 
2023-10-16 11:19:38.657 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready.
2023-10-16 11:19:38.657 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart
2023-10-16 11:19:38.658 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 62: Transaction COMPLETED
2023-10-16 11:19:38.658 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 9ms
2023-10-16 11:19:38.659 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 62: Transaction completed
2023-10-16 11:19:38.659 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:62 DONE
2023-10-16 11:19:38.660 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-10-16 11:19:38.660 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
==> /var/log/openhab/events.log <==

---

==> /var/log/openhab/openhab.log <==
2023-10-16 11:19:40.651 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery completed
2023-10-16 11:19:40.669 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery could not resolve to a thingType! Manufacturer data not known.
2023-10-16 11:19:40.677 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:zstick:node2' to inbox.

So it seems that I was mislead by the log message, I will try to get the discovery completed and add some more nodes. For now thanks for the quick hint!