[SOLVED] OH3: zwave binding Z-Wave Serial Controller Aeotec Z-Stick Gen5 remains offline

brononius · July 21, 2021, 8:56pm

I had following ports in the paperUI:

rfc2217://127.0.0.1:3001
rfc2217://127.0.0.1:3002

These correspond with the ports in the yaml file, and that were listening (netstat).

No local firewall in place.
I trust only on my central firewall. Much easier to maintain it all.

Current status: I just booted my old virtual server (I took a clone before upgrading). And after restarting that one machine 3 times, clearing the cache 2 times, and perform a soft reset of the sticks, 1 stick is now up and running?
Configuration is 99,99% identical for stick 1 and 2. Very weird.

7 hours of chasing down this issue. Will have another try tomorrow… With a fresh head, new motiviation…

apella12 · July 21, 2021, 10:14pm

Not an expert, never ran two z-stacks. From the partial log it looks like two different UIDs on the Zsticks. Deactivate zwave:serial_zstick:2f4ef5d0;Active zwave:serial_zstick:30038385 What UID do the nodes have? Are there two separate networks? Anyway if it was I, I might just try to get one working first and make sure the node UIDs have the same as the Zstick. Just thoughts.

brononius · July 22, 2021, 5:49am

Indeed, 2 different UID’s, different wireless networks… Reason is that I’ve got a house, and a studio, about 30m from each other, with very bad bricks for wireless signals. But for several years, this is working fine.

Stick 1: 30038385
Stick 2: 2f4ef5d0

After restarting/cleaning/… my setup from before (same hardware, just different virtual machine), 1 stick came online. I just now restarted openhab on this machine, and both sticks are back offline. grrrr, getting crazy about this, very unreliably…

Trying the ser2net workaround:
cat /etc/ser2net.yaml

connection: &con0096  
  accepter: tcp,3001
  enable: on
  options:
    kickolduser: true
  connector: serialdev,/dev/ttyACM0,115200n81,local

connection: &con1096
  accepter: tcp,3002
  enable: on
  options:
    kickolduser: true
  connector: serialdev,/dev/ttyACM1,115200n81,local

systemctl status ser2net

● ser2net.service - Serial port to network proxy
     Loaded: loaded (/lib/systemd/system/ser2net.service; disabled; vendor preset: enabled)
     Active: active (running) since Thu 2021-07-22 08:11:05 CEST; 3s ago
       Docs: man:ser2net(8)
   Main PID: 6202 (ser2net)
      Tasks: 1 (limit: 19105)
     Memory: 1.0M
     CGroup: /system.slice/ser2net.service
             └─6202 /usr/sbin/ser2net -n -c /etc/ser2net.yaml -P /run/ser2net.pid

Jul 22 08:11:05 doornroosje systemd[1]: Starting Serial port to network proxy...
Jul 22 08:11:05 doornroosje systemd[1]: Started Serial port to network proxy.

netstat -apn | grep ser2net

tcp6       0      0 :::3001                 :::*                    LISTEN      6202/ser2net        
tcp6       0      0 :::3002                 :::*                    LISTEN      6202/ser2net        
unix  3      [ ]         STREAM     CONNECTED     1137419  6202/ser2net         
unix  3      [ ]         STREAM     CONNECTED     1137417  6202/ser2net

telnet 127.0.0.1 3001

Trying 127.0.0.1...
Connected to 127.0.0.1.
Escape character is '^]'.

 1"�
   1"�
               1"�
                      1"�

Configuration in paperUI for the serial port on stick 1:

rfc2217://127.0.0.1:3001

Configuration in paperUI for the serial port on stick 2:

rfc2217://127.0.0.1:3002

And the output of some logs:

2021-07-22 08:28:14.651 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Disposing receive thread
2021-07-22 08:28:14.652 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Receive thread dispose
2021-07-22 08:28:14.653 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Disposing serial connection
2021-07-22 08:28:14.656 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial connection disposed
2021-07-22 08:28:14.657 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler
2021-07-22 08:28:14.660 [DEBUG] [ve.internal.protocol.ZWaveController] - Shutting down ZWave controller
2021-07-22 08:28:14.661 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Shutting down transaction manager
2021-07-22 08:28:14.664 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Exiting ZWave Receive Thread
2021-07-22 08:28:14.665 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction manager shutdown
2021-07-22 08:28:14.666 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller shutdown
2021-07-22 08:28:14.667 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.
2021-07-22 08:28:14.668 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:30038385.
2021-07-22 08:28:14.885 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:30038385
2021-07-22 08:28:15.718 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 49 06 31 05 01 22 00 EA 45 
2021-07-22 08:28:15.724 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=73, callback=0, payload=00 49 06 31 05 01 22 00 EA 
2021-07-22 08:28:15.727 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=73, callback=0, payload=00 49 06 31 05 01 22 00 EA 
2021-07-22 08:28:15.728 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2021-07-22 08:28:15.729 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 73: Not initialized (ie node unknown), ignoring message.
2021-07-22 08:28:15.729 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

PaperUI
I’ve also removed the sticks from paperUI, and recreated them with the same UID, but no luck.

Any suggestion is welcome.

apella12 · July 22, 2021, 3:00pm

First suggestion is to open a new thread since the solution in this thread is not working for you. You might be missing the input of some of the forum and Zwave heavy hitters (not me) by posting on a SOLVED thread. Also I think the two stick set-up might be contributing, but I don’t really know.

Two, for clarification, both sticks are in the same location? If yes, I don’t see how that helps wireless connectivity, but it is not related to your issue because the zsticks are not staying online. I use a zniffer to monitor radio traffic. I still might suggest try getting just one to work. From the logs 30038385 seemed to work

Three, although painful in unwieldly size you will need to provide a longer and more complete Debug of a full cycle. I have recently finished an analysis of battery device initialization and the Debug file runs runs about 500 KB for about 30 seconds.

Fourth although not a java programmer, the approach I took was to download the zwave code, go to file referenced in the Debug and look at the comments around the Debug statement for clues. That may not work in this case because from the snippets you posted, it does not seem to be the binding itself, but the serial connection. Also that took a lot of time.

Sorry I can’t help more, especially with serial connectivity, I’ve never explored that area of the OH core.

Bob

brononius · July 22, 2021, 7:13pm

I disagree.
It works!

After moving the sticks to another machine, I could link them over my internal network. The only difference was the OS (linux mint instead of ubuntu) and the hardware. I’m not sure where the yaml config file came from, but this was the problem. Maybe I had a missing option. But after purging ser2net, and reinstalling it, I’m now having following working config:

cat /etc/ser2net.conf

3001:telnet:0:/dev/ttyACM0:115200 8DATABITS NONE 1STOPBIT remctl
3002:telnet:0:/dev/ttyACM1:115200 8DATABITS NONE 1STOPBIT remctl

Both my zwave sticks are now online, and the 72 nodes behind it.

This is all done on the virtual machine. I just pass the usb ports from the hypervisor towards the virtual machine. Now I’m thinking about it, Maybe I should run ser2net on the hypervisor? No need then to push the usb ports.

Same ‘location’, but 2 seperate buildings. Distance about 30m. And the bricks are very wireless unfriendly. So I decided to have 2 different zwave networks, to avoid to much latency.

Andrew_Rowe · July 22, 2021, 7:21pm

You guys might want to check out this issue on github about the library OH3 uses for the serial connection

github.com/openhab/openhab-core

Serial ports getting blocked after some re-connecting

opened 08:11PM - 22 Nov 20 UTC

fwolter

external bug

When using the Modbus binding with OH3, the serial port with the Modbus RS485 tr…ansciever cannot be opened anymore after some time. When the error appears, the following is printed on stdout: `initialise_event_info_struct: initialise failed!` This is a known bug NeuronRobotics/nrjavaserial#111. After compiling the native libs with `DISABLE_LOCKFILES` as suggested in above issue, the error is gone. This has been discussed in https://community.openhab.org/t/modbus-binding-loses-its-serial-connection-every-few-days-without-a-reason-after-updating-to-2-5-0-release-build/89550/14 Maybe locking should be disabled in OH nrjavaserial again?

and also this issue on the nrjavaserial github about a bug which is causing some of these issues

github.com/NeuronRobotics/nrjavaserial

initialise_event_info_struct: initialise failed!

opened 02:37PM - 26 Sep 17 UTC

closed 01:53PM - 07 May 21 UTC

roxkamx

Hi, I have a project where I attach 32 devices grouped in 2 physical hubs ( 1…6 each ) to a Centos7 server. With 16 devices my application works just fine. When I start the application with both hubs attached ( i.e. 32 devices attached ) at the 24th device my application stops with the following error: `initialise_event_info_struct: initialise failed! ` This message looks to be from RXTX ( as found on http://rxtx.qbang.org/pub/rxtx/rxtx-2.1-7r2/src/SerialImp.c ) Any suggestions how to overcome this issue? is there any limitation? The same thing happened on 2 other different PCs, so I would exclude for now the USB driver. Thanks

apella12 · July 22, 2021, 10:34pm

Glad you have it running.

Bob

brononius · July 23, 2021, 11:07am

Just for reference: I’ve updated this morning my ubuntu to version 21.04, and the yaml configuration files are back. After some try and errors, this config is working:

cat /etc/ser2net.yaml

connection: &con0192
    accepter: telnet,3001
    enable: on
    connector: serialdev,
              /dev/ttyACM0,
              115200n81,local

connection: &con1192
    accepter: telnet,3002
    enable: on
    connector: serialdev,
              /dev/ttyACM1,
              115200n81,local

Toneus · July 28, 2021, 7:54pm

FYI - I found and issue related to xhci_hcd on Ubuntu 5.4.0 not recognizing the front ports on my NUC. My issue is on OH2, but I think the underlying issue are not OH specific which is why I’m sharing here.

vespaman · August 1, 2021, 12:42pm

Today I restarted my 3.1 installation, and now I just cant get oh to start the zcontroller again. I had issues before, when I restarted, I had to unplug the zstick before starting up oh again.

I see in my log;

14:17:21.097 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Connecting to serial port ‘/dev/ttyACM0’
initialise_event_info_struct: initialise failed!

I see that the LCK…ttyACM0 is created in /run/lock (linked from /var/lock on my box).
I tried to delete the lock file before starting oh, but that did not make any difference.

But; and this may help someone else… After spending hours with this I decided to unplug the zstick while oh was running, and directly plug it again, so it got ACM1 identiy. Then I restarted oh and edited the zstick thing, changing device into ACM1 instead, and instantly I was up and running again.

Not a good solution for sure, but at least I am up again…

Andrew_Rowe · August 1, 2021, 1:19pm

This is the exact problem linked in my post above
nrjavaserial is leaking lock files.

dastrix80 · September 27, 2021, 12:00pm

Have tried this and no luck! Any other suggestions?

JAVA opts updated, copied/edited the legacy.conf file, udev rule setup.

None of it is working. Worked OK on OH 2.5 , still a litle flaky some times.

HaKuNa · September 27, 2021, 7:28pm

hardware? os?

dastrix80 · September 27, 2021, 8:40pm

VM on QNAP virtualisation station, USB3 (has worked on this configuration for years) - Ubuntu 20.x

HaKuNa · September 28, 2021, 3:01am

Then I suggest to open a new thread.
Different HW, different OS and this thread here is marked as solved. There are 2 ways descibed as solution and both are working.

garyfree · October 2, 2021, 2:36pm

Using info from elsewhere I ran after stopping instance
sudo open-cli start
Stopped it
then ran openhab as service as at boot and voila worked fine
I have zigbee - ttyUSB*
and ZWave - ttyACM*
It is only the ACM that is the problem USB works fine

pleky · December 11, 2021, 5:29pm

Hello,

I’ve got the same issue with a basic VM and OH3.1

it looks like openhab is trying to create its lock file in /run/lock
so I’ve just do a chmod 777 /var/lock and it solved the issue.
The unique drawback (except security ) is that it needs to be done every reboot.

Any idea to let openhab put its lock somewhere else ?

Thank

stefan.hoehn · December 11, 2021, 9:16pm

I think one of the reasons that this happens that the lock is created by a different user than the the one that is used when OH is started automatically. This for example can happen when you start OH manually via sudo and then reboot. At least that was once the root cause why this happened to me. Can you check which user has written the lock and compare that with the user that OH runs with?

pleky · December 13, 2021, 8:23pm

yes, easy , the folder is supposed to be writable by root only, and openhab is started as a service via systemctl and run as openhab user

I’ve reread another post and found maybe an entry to change the default mode on the lock folder (need to reboot again to see the result)
But maybe the path could be somewhere else where openhab (or other) user has writing rights.

Or add somekind of self checkup to warm user to change the default OS setup to allow write rights ?

Thanks

RV_84 · February 2, 2022, 3:50pm

Hey

I didn´t manage it to get the Aeotec Stick running on my RPi4 and OH3.2.0
All the configs in the treads failed
My Elero Stick (ttyUSB0) is working fine and showen up, but the ZWave Stick not:

~ $ dmesg | grep tty
[ 0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=0 bcm2708_fb.fbheight=0 bcm2708_fb.fbdepth=16 bcm2708_fb.fbswap=1 smsc95xx.macaddr=DC:A6:32:9E:D2:53 vc_mem.mem_base=0x3f000000 vc_mem.mem_size=0x3f600000 console=ttyS0,115200 console=tty1 root=PARTUUID=4d915286-02 rootfstype=ext4 fsck.repair=yes rootwait
[ 0.001824] printk: console [tty1] enabled
[ 1.461311] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 36, base_baud = 0) is a PL011 rev2
[ 3.142609] systemd[1]: Created slice system-getty.slice.
[ 5.428786] usb 1-1.1: FTDI USB Serial Device converter now attached to ttyUSB0

I want to try it with an hub.
Do I need an active or passive hub in between?

THX René