ZWave via ser2net Offline

[mr_eskildsen (Martin Eskildsen)]

I am trying to use ser2net / socat for my ZWave controller. I have setup ser2net / socat using this guide:

Forwarding of serial and USB ports over the network to openHAB

As promised, here comes the tutorial on forwarding serial or USB ports to openHAB. This tutorial is the result of my efforts to use Vlad Kolotov’s Bluetooth binding (kudos to @vkolotov ) for my MiFlora plant sensors. Problem description Services such as Zwave or Bluetooth are limited in their transmission range for technical reasons. To improve the range, the corresponding adapters can be connected with extension cables. However, if the cable length is limited or the installation of cables is …

That part seems to work, since i can see that a connection is established when openhab is started.
When I add a zwave Serial controller, the thing new comes online. It just stays offline Offline - Bridge offline (Controller Offline)
When looking in the Zwave log it seems that there is some kind of connection although I am uncertain if it simply just gives upyour code goes here?
your code goes here

11-Oct-2019 21:12:21.868 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - Creating ZWave discovery service for zwave:serial_zstick:31bad3d2 with scan time of 60
11-Oct-2019 21:12:21.868 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Active zwave:serial_zstick:31bad3d2
11-Oct-2019 21:12:21.868 [INFO ] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null
11-Oct-2019 21:12:21.869 [DEBUG] [org.openhab.binding.zwave                         ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=548, service.bundleid=241, service.scope=singleton} - org.openhab.binding.zwave
11-Oct-2019 21:12:21.879 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.
11-Oct-2019 21:12:21.879 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:31bad3d2.
11-Oct-2019 21:12:21.879 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - No network key set by user - using random value.
11-Oct-2019 21:12:21.882 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 5 hours time.
11-Oct-2019 21:12:21.883 [INFO ] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyNET0'
11-Oct-2019 21:12:21.893 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Starting receive thread
11-Oct-2019 21:12:21.894 [INFO ] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
11-Oct-2019 21:12:21.894 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive
11-Oct-2019 21:12:21.894 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller
11-Oct-2019 21:12:21.899 [INFO ] [ab.binding.zwave.internal.protocol.ZWaveController] - Starting ZWave controller
11-Oct-2019 21:12:21.900 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
11-Oct-2019 21:12:21.900 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
11-Oct-2019 21:12:21.900 [INFO ] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
11-Oct-2019 21:12:21.900 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event listener added.
11-Oct-2019 21:12:21.901 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event listener added.
11-Oct-2019 21:12:24.900 [DEBUG] [ernal.protocol.ZWaveController$InitializeDelayTask] - Initialising network
11-Oct-2019 21:12:24.903 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 5 to queue - size 1
11-Oct-2019 21:12:24.903 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
11-Oct-2019 21:12:24.903 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9 
11-Oct-2019 21:12:24.903 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9 
11-Oct-2019 21:12:24.904 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
11-Oct-2019 21:12:24.904 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
11-Oct-2019 21:12:24.904 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 6 to queue - size 1
11-Oct-2019 21:12:24.905 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
11-Oct-2019 21:12:24.905 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 7 to queue - size 2
11-Oct-2019 21:12:24.905 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
11-Oct-2019 21:12:24.905 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 8 to queue - size 3
11-Oct-2019 21:12:24.905 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
11-Oct-2019 21:12:24.905 [DEBUG] [al.protocol.serialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID
11-Oct-2019 21:12:24.905 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 9 to queue - size 4
11-Oct-2019 21:12:24.905 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
11-Oct-2019 21:12:26.905 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 255: TID 5: Timeout at state WAIT_RESPONSE. 3 retries remaining.
11-Oct-2019 21:12:26.905 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - TID 5: Transaction is current transaction, so clearing!!!!!
11-Oct-2019 21:12:26.905 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 5: Transaction CANCELLED
11-Oct-2019 21:12:26.905 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:5 CANCELLED
11-Oct-2019 21:12:26.906 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
11-Oct-2019 21:12:26.907 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC 
11-Oct-2019 21:12:26.907 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC 
11-Oct-2019 21:12:26.907 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
11-Oct-2019 21:12:26.907 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
11-Oct-2019 21:12:28.907 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 255: TID 6: Timeout at state WAIT_RESPONSE. 3 retries remaining.
11-Oct-2019 21:12:28.907 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - TID 6: Transaction is current transaction, so clearing!!!!!
11-Oct-2019 21:12:28.908 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 6: Transaction CANCELLED
11-Oct-2019 21:12:28.908 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:6 CANCELLED
11-Oct-2019 21:12:28.908 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
11-Oct-2019 21:12:28.909 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 07 FB 
11-Oct-2019 21:12:28.909 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 07 FB 
11-Oct-2019 21:12:28.909 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
11-Oct-2019 21:12:28.909 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
11-Oct-2019 21:12:30.909 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 255: TID 7: Timeout at state WAIT_RESPONSE. 3 retries remaining.
11-Oct-2019 21:12:30.909 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - TID 7: Transaction is current transaction, so clearing!!!!!
11-Oct-2019 21:12:30.910 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 7: Transaction CANCELLED
11-Oct-2019 21:12:30.910 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:7 CANCELLED
11-Oct-2019 21:12:30.910 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
11-Oct-2019 21:12:30.911 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 06 96 0F 65 
11-Oct-2019 21:12:30.911 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 06 96 0F 65 
11-Oct-2019 21:12:30.911 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
11-Oct-2019 21:12:30.911 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 8: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
11-Oct-2019 21:12:32.911 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 255: TID 8: Timeout at state WAIT_RESPONSE. 3 retries remaining.
11-Oct-2019 21:12:32.912 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - TID 8: Transaction is current transaction, so clearing!!!!!
11-Oct-2019 21:12:32.912 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 8: Transaction CANCELLED
11-Oct-2019 21:12:32.912 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:8 CANCELLED
11-Oct-2019 21:12:32.912 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
11-Oct-2019 21:12:32.913 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 56 AA 
11-Oct-2019 21:12:32.913 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 56 AA 
11-Oct-2019 21:12:32.913 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT
11-Oct-2019 21:12:32.913 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 9: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
11-Oct-2019 21:12:34.913 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 255: TID 9: Timeout at state WAIT_RESPONSE. 3 retries remaining.
11-Oct-2019 21:12:34.913 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - TID 9: Transaction is current transaction, so clearing!!!!!
11-Oct-2019 21:12:34.913 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 9: Transaction CANCELLED
11-Oct-2019 21:12:34.913 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:9 CANCELLED
11-Oct-2019 21:12:34.913 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

I am running openHAB 2.5.0M3 on Ubuntu 18.04.
I am quite sure that it is some kind of permission since I would expect a little more in the ZWave log (allthough there is only 1 node in the network on that zstick)

Any ideas?

[Bruce_Osborne]

@mr_eskildsen

Any ideas?

You can save the zwave log to a file and use the log viewer.

https://www.cd-jackson.com/index.php/openhab/zwave-log-viewer

[mr_eskildsen (Martin Eskildsen)]

@Dibbler42

You should replace IP address and port with the IP of the server and the corresponding port and enable and start it after saving for system startup.

Thanks for the tip but I don’t suspect the zwave binding to be the problem. I think I have a config error somewhere in ser2net. So I am starting from beginning

[mr_eskildsen (Martin Eskildsen)]

It turns out that the Raspberry Pi hosting the ZStick was in some strange state. I just noticed that the 1-Wire service wasn’t responding, so I tried restarting, the RPI and it came onlie again.