Snapshot version of zwave cannot find serial port after OH restart

[ffr (F.)]

since about two weeks, I have the following problem on my Openhab raspi system (2.4 stable):
after starting openhab, the zwave controller does not work.

2019-05-02 19:45:43.586 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'

2019-05-02 19:45:43.603 [WARN ] [erial.internal.SerialPortManagerImpl] - No SerialPortProvider found for: /dev/ttyACM0

the following workaround helps out:

1. in paperui change the port for the zwave controller
2. restart openhab service
3. in paperui change the port back to the original

Chris Jackson suggested that the issue might be related to the start-up sequence of openhab.
Who can help out?

If the topic should be tagged differently, please help me out. thanks.

[Kim_Andersen]

I have the exact same problem using openhabian 2.5M1 build #1575.
I have even specified symlinks, but they´re not available through PaperUI. So I moved the controller to a thing file insted. But the same symptoms happens. When ever I restart openhab, it fails to read the port. And I have to do the very same trick to get it online.

I have no idea what this happend… But there has been a few reports the last few weeks about zwave dongle behaving like this. I did not have this issue using openhab 2.4.
The 2.5 I´m using now is a new build using the same configuration files. Atm I just try to live with it, avoiding to restart, untill I get enough time to dig deeper into it. But i fear there are some fatal problems somewhere in openhab.

[JensH]

Got same with openhab 2.50 build #1680 and searched a lot. If I understood the discussion on github, new distributions of Linux changed something, so a new serial handler is needed. OH 2.4 has got old serial handlers.

@ffr : Could you give some more information which distribution, version and kernel is installed at your rapi-system? If Linux or kernel update stops openhab working, this bug is a lot more important to be solved.

[5iver (Scott Rushworth)]

@JensH

If I understood the discussion on github, new distributions of Linux changed something, so a new serial handler is needed. OH 2.4 has got old serial handlers.

Could you please provide a link to that discussion?

This issue affects more than just openHABian and zwave. It appears to be an issue with USB discovery after the ESH reintegration in openhab-core. Those changes were first included in S1566.

I am affected on OH startup where zwave is not running due to port{0} not found. Zigbee is functioning. The port dropdowns have all available ports. After restarting the zwave binding (I just change the name of the controller), zwave comes online but the serial port dropdowns only display the port used by the zwave controller. Zigbee stays online, but loses the port 24 hours later and requires an OH restart to get it back online. And the cycle repeats.

I’ll open an issue.

[JensH]

No SerialPort Provider error with Ubuntu 18.04 and Zwave 2.5.x snapshot

Ok, thanks for the clarification. Unfortunately, I need some stuff that is not in the 2.4 release device database. Any pointers to where the discussion was happening about the 2.5 issue?

[Zwave] Serial port opening fails on 2.5 Snapshot

Hi, sometimes i’ve got the following error with the 2.5 snapshot (currently 1572). 2019-04-18 12:08:09.610 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyAMA0' 2019-04-18 12:08:09.618 [WARN ] [erial.internal.SerialPortManagerImpl] - No SerialPortProvider found for: /dev/ttyAMA0 2019-04-18 12:08:09.622 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.zwave.handler.Z…

Zwave not working with openHAB 2.5.0~S1566-1 (Build #1566)

I installed build 1566 and got following problem: All Zwave offline (no device handler) Aeotec Stick offline to. Doing softreset of usb stick brings him online again, but all Zwave devices are offline and don’t come up. Restart openhab brings both offline again, restart Ubuntu 18.04 Server the same. Went back to earlier build and all works fine. Anybody else same problems, maybe with same stick?

And on github:

[nrjavaserial] Multiple versions

[JensH]

@5iver

I’ll open an issue.

For zwave, I have been changing the location of the controller, which restarts the binding. I also have the problem

As you see, there is allready an open issue. If I understood right, the handler gives openhab the information about the ports causes this error, so it’s like a lottery if USB-Port is found or not.

[Kim_Andersen]

Forgot to mention, it happens to my RS485 USB dongle as well. So this is not restricted to zwave dongles.

[noppes123 (Ron)]

Could this be caused by changed symlinks to the tty devices?
What serial ports and symlinks do you see with ls -l /dev?

[Kim_Andersen]

[23:31:52] openhabian@openHABianPi:~$ ls -l /dev
total 0
crw-r--r-- 1 root root     10, 235 Apr 29 11:12 autofs
drwxr-xr-x 2 root root         580 Apr 29 11:12 block
drwxr-xr-x 2 root root          60 Jan  1  1970 bsg
crw------- 1 root root     10, 234 Apr 29 11:12 btrfs-control
drwxr-xr-x 3 root root          60 Jan  1  1970 bus
crw------- 1 root root     10,  63 Apr 29 11:12 cachefiles
drwxr-xr-x 2 root root        2580 Apr 29 11:12 char
crw------- 1 root root      5,   1 Apr 29 11:12 console
crw------- 1 root root     10,  62 Apr 29 11:12 cpu_dma_latency
crw------- 1 root root     10, 203 Apr 29 11:12 cuse
drwxr-xr-x 7 root root         140 Apr 29 11:12 disk
crw-rw---- 1 root video    29,   0 Apr 29 11:12 fb0
lrwxrwxrwx 1 root root          13 Nov  3  2016 fd -> /proc/self/fd
crw-rw-rw- 1 root root      1,   7 Apr 29 11:12 full
crw-rw-rw- 1 root root     10, 229 Apr 29 11:12 fuse
crw-rw---- 1 root gpio    254,   0 Apr 29 11:12 gpiochip0
crw-rw---- 1 root gpio    254,   1 Apr 29 11:12 gpiochip1
crw-rw---- 1 root gpio    248,   0 Apr 29 11:12 gpiomem
crw------- 1 root root     10, 183 Apr 29 11:12 hwrng
lrwxrwxrwx 1 root root          25 Nov  3  2016 initctl -> /run/systemd/initctl/         fifo
drwxr-xr-x 2 root root          60 Jan  1  1970 input
crw-r--r-- 1 root root      1,  11 Apr 29 11:12 kmsg
lrwxrwxrwx 1 root root          28 Nov  3  2016 log -> /run/systemd/journal/dev-         log
brw-rw---- 1 root disk      7,   0 Apr 29 11:12 loop0
brw-rw---- 1 root disk      7,   1 Apr 29 11:12 loop1
brw-rw---- 1 root disk      7,   2 Apr 29 11:12 loop2
brw-rw---- 1 root disk      7,   3 Apr 29 11:12 loop3
brw-rw---- 1 root disk      7,   4 Apr 29 11:12 loop4
brw-rw---- 1 root disk      7,   5 Apr 29 11:12 loop5
brw-rw---- 1 root disk      7,   6 Apr 29 11:12 loop6
brw-rw---- 1 root disk      7,   7 Apr 29 11:12 loop7
crw-rw---- 1 root disk     10, 237 Apr 29 11:12 loop-control
drwxr-xr-x 2 root root          60 Apr 29 11:12 mapper
crw-r----- 1 root kmem      1,   1 Apr 29 11:12 mem
crw------- 1 root root     10,  59 Apr 29 11:12 memory_bandwidth
drwxrwxrwt 2 root root          40 Jan  1  1970 mqueue
drwxr-xr-x 2 root root          60 Apr 29 11:12 net
crw------- 1 root root     10,  61 Apr 29 11:12 network_latency
crw------- 1 root root     10,  60 Apr 29 11:12 network_throughput
crw-rw-rw- 1 root root      1,   3 Apr 29 11:12 null
crw------- 1 root root    108,   0 Apr 29 11:12 ppp
crw-rw-rw- 1 root tty       5,   2 May  2 23:31 ptmx
drwxr-xr-x 2 root root           0 Nov  3  2016 pts
brw-rw---- 1 root disk      1,   0 Apr 29 11:12 ram0
brw-rw---- 1 root disk      1,   1 Apr 29 11:12 ram1
brw-rw---- 1 root disk      1,  10 Apr 29 11:12 ram10
brw-rw---- 1 root disk      1,  11 Apr 29 11:12 ram11
brw-rw---- 1 root disk      1,  12 Apr 29 11:12 ram12
brw-rw---- 1 root disk      1,  13 Apr 29 11:12 ram13
brw-rw---- 1 root disk      1,  14 Apr 29 11:12 ram14
brw-rw---- 1 root disk      1,  15 Apr 29 11:12 ram15
brw-rw---- 1 root disk      1,   2 Apr 29 11:12 ram2
brw-rw---- 1 root disk      1,   3 Apr 29 11:12 ram3
brw-rw---- 1 root disk      1,   4 Apr 29 11:12 ram4
brw-rw---- 1 root disk      1,   5 Apr 29 11:12 ram5
brw-rw---- 1 root disk      1,   6 Apr 29 11:12 ram6
brw-rw---- 1 root disk      1,   7 Apr 29 11:12 ram7
brw-rw---- 1 root disk      1,   8 Apr 29 11:12 ram8
brw-rw---- 1 root disk      1,   9 Apr 29 11:12 ram9
crw-rw-rw- 1 root root      1,   8 Apr 29 11:12 random
drwxr-xr-x 2 root root          60 Jan  1  1970 raw
crw-rw-r-- 1 root netdev   10,  58 Apr 29 11:12 rfkill
brw-rw---- 1 root disk      8,   0 Apr 29 11:12 sda
brw-rw---- 1 root disk      8,   1 Apr 29 11:12 sda1
brw-rw---- 1 root disk      8,   2 Apr 29 11:12 sda2
drwxr-xr-x 4 root root          80 Apr 29 11:12 serial
lrwxrwxrwx 1 root root           7 Apr 29 11:12 serial0 -> ttyAMA0
lrwxrwxrwx 1 root root           5 Apr 29 11:12 serial1 -> ttyS0
crw-rw---- 1 root disk     21,   0 Apr 29 11:12 sg0
drwxrwxrwt 2 root root          40 Nov  3  2016 shm
drwxr-xr-x 3 root root         160 Apr 29 11:12 snd
lrwxrwxrwx 1 root root          15 Nov  3  2016 stderr -> /proc/self/fd/2
lrwxrwxrwx 1 root root          15 Nov  3  2016 stdin -> /proc/self/fd/0
lrwxrwxrwx 1 root root          15 Nov  3  2016 stdout -> /proc/self/fd/1
crw-rw-rw- 1 root tty       5,   0 Apr 29 11:12 tty
crw--w---- 1 root tty       4,   0 Apr 29 11:12 tty0
crw--w---- 1 root tty       4,   1 Apr 29 11:12 tty1
crw--w---- 1 root tty       4,  10 Apr 29 11:12 tty10
crw--w---- 1 root tty       4,  11 Apr 29 11:12 tty11
crw--w---- 1 root tty       4,  12 Apr 29 11:12 tty12
crw--w---- 1 root tty       4,  13 Apr 29 11:12 tty13
crw--w---- 1 root tty       4,  14 Apr 29 11:12 tty14
crw--w---- 1 root tty       4,  15 Apr 29 11:12 tty15
crw--w---- 1 root tty       4,  16 Apr 29 11:12 tty16
crw--w---- 1 root tty       4,  17 Apr 29 11:12 tty17
crw--w---- 1 root tty       4,  18 Apr 29 11:12 tty18
crw--w---- 1 root tty       4,  19 Apr 29 11:12 tty19
crw--w---- 1 root tty       4,   2 Apr 29 11:12 tty2
crw--w---- 1 root tty       4,  20 Apr 29 11:12 tty20
crw--w---- 1 root tty       4,  21 Apr 29 11:12 tty21
crw--w---- 1 root tty       4,  22 Apr 29 11:12 tty22
crw--w---- 1 root tty       4,  23 Apr 29 11:12 tty23
crw--w---- 1 root tty       4,  24 Apr 29 11:12 tty24
crw--w---- 1 root tty       4,  25 Apr 29 11:12 tty25
crw--w---- 1 root tty       4,  26 Apr 29 11:12 tty26
crw--w---- 1 root tty       4,  27 Apr 29 11:12 tty27
crw--w---- 1 root tty       4,  28 Apr 29 11:12 tty28
crw--w---- 1 root tty       4,  29 Apr 29 11:12 tty29
crw--w---- 1 root tty       4,   3 Apr 29 11:12 tty3
crw--w---- 1 root tty       4,  30 Apr 29 11:12 tty30
crw--w---- 1 root tty       4,  31 Apr 29 11:12 tty31
crw--w---- 1 root tty       4,  32 Apr 29 11:12 tty32
crw--w---- 1 root tty       4,  33 Apr 29 11:12 tty33
crw--w---- 1 root tty       4,  34 Apr 29 11:12 tty34
crw--w---- 1 root tty       4,  35 Apr 29 11:12 tty35
crw--w---- 1 root tty       4,  36 Apr 29 11:12 tty36
crw--w---- 1 root tty       4,  37 Apr 29 11:12 tty37
crw--w---- 1 root tty       4,  38 Apr 29 11:12 tty38
crw--w---- 1 root tty       4,  39 Apr 29 11:12 tty39
crw--w---- 1 root tty       4,   4 Apr 29 11:12 tty4
crw--w---- 1 root tty       4,  40 Apr 29 11:12 tty40
crw--w---- 1 root tty       4,  41 Apr 29 11:12 tty41
crw--w---- 1 root tty       4,  42 Apr 29 11:12 tty42
crw--w---- 1 root tty       4,  43 Apr 29 11:12 tty43
crw--w---- 1 root tty       4,  44 Apr 29 11:12 tty44
crw--w---- 1 root tty       4,  45 Apr 29 11:12 tty45
crw--w---- 1 root tty       4,  46 Apr 29 11:12 tty46
crw--w---- 1 root tty       4,  47 Apr 29 11:12 tty47
crw--w---- 1 root tty       4,  48 Apr 29 11:12 tty48
crw--w---- 1 root tty       4,  49 Apr 29 11:12 tty49
crw--w---- 1 root tty       4,   5 Apr 29 11:12 tty5
crw--w---- 1 root tty       4,  50 Apr 29 11:12 tty50
crw--w---- 1 root tty       4,  51 Apr 29 11:12 tty51
crw--w---- 1 root tty       4,  52 Apr 29 11:12 tty52
crw--w---- 1 root tty       4,  53 Apr 29 11:12 tty53
crw--w---- 1 root tty       4,  54 Apr 29 11:12 tty54
crw--w---- 1 root tty       4,  55 Apr 29 11:12 tty55
crw--w---- 1 root tty       4,  56 Apr 29 11:12 tty56
crw--w---- 1 root tty       4,  57 Apr 29 11:12 tty57
crw--w---- 1 root tty       4,  58 Apr 29 11:12 tty58
crw--w---- 1 root tty       4,  59 Apr 29 11:12 tty59
crw--w---- 1 root tty       4,   6 Apr 29 11:12 tty6
crw--w---- 1 root tty       4,  60 Apr 29 11:12 tty60
crw--w---- 1 root tty       4,  61 Apr 29 11:12 tty61
crw--w---- 1 root tty       4,  62 Apr 29 11:12 tty62
crw--w---- 1 root tty       4,  63 Apr 29 11:12 tty63
crw--w---- 1 root tty       4,   7 Apr 29 11:12 tty7
crw--w---- 1 root tty       4,   8 Apr 29 11:12 tty8
crw--w---- 1 root tty       4,   9 Apr 29 11:12 tty9
crw-rw-rw- 1 root dialout 166,   0 May  2 23:31 ttyACM0
crw-rw---- 1 root dialout 204,  64 May  2 23:31 ttyAMA0
crw------- 1 root root      5,   3 Apr 29 11:12 ttyprintk
crw-rw---- 1 root dialout   4,  64 Apr 29 11:12 ttyS0
crw-rw-rw- 1 root dialout 188,   0 May  2 23:31 ttyUSB0
lrwxrwxrwx 1 root root           7 Apr 29 11:12 ttyUSB_RS485 -> ttyUSB0
lrwxrwxrwx 1 root root           7 Apr 29 11:12 ttyUSB_ZStick -> ttyACM0
crw------- 1 root root     10, 239 Apr 29 11:12 uhid
crw------- 1 root root     10, 223 Apr 29 11:12 uinput
crw-rw-rw- 1 root root      1,   9 Apr 29 11:12 urandom
crw-rw---- 1 root video   246,   0 Apr 29 11:12 vchiq
crw-rw---- 1 root video   249,   0 Apr 29 11:12 vcio
crw------- 1 root root    250,   0 Apr 29 11:12 vc-mem
crw-rw---- 1 root tty       7,   0 Apr 29 11:12 vcs
crw-rw---- 1 root tty       7,   1 Apr 29 11:12 vcs1
crw-rw---- 1 root tty       7,   2 Apr 29 11:12 vcs2
crw-rw---- 1 root tty       7,   3 Apr 29 11:12 vcs3
crw-rw---- 1 root tty       7,   4 Apr 29 11:12 vcs4
crw-rw---- 1 root tty       7,   5 Apr 29 11:12 vcs5
crw-rw---- 1 root tty       7,   6 Apr 29 11:12 vcs6
crw-rw---- 1 root tty       7, 128 Apr 29 11:12 vcsa
crw-rw---- 1 root tty       7, 129 Apr 29 11:12 vcsa1
crw-rw---- 1 root tty       7, 130 Apr 29 11:12 vcsa2
crw-rw---- 1 root tty       7, 131 Apr 29 11:12 vcsa3
crw-rw---- 1 root tty       7, 132 Apr 29 11:12 vcsa4
crw-rw---- 1 root tty       7, 133 Apr 29 11:12 vcsa5
crw-rw---- 1 root tty       7, 134 Apr 29 11:12 vcsa6
crw------- 1 root root     10, 137 Apr 29 11:12 vhci
crw------- 1 root root     10, 130 Apr 29 11:12 watchdog
crw------- 1 root root    252,   0 Apr 29 11:12 watchdog0
crw-rw-rw- 1 root root      1,   5 Apr 29 11:12 zero
[23:31:55] openhabian@openHABianPi:~$

I have no idea what I´m looking at

[noppes123 (Ron)]

@Kim_Andersen

lrwxrwxrwx 1 root root 7 Apr 29 11:12 ttyUSB_RS485 → ttyUSB0 lrwxrwxrwx 1 root root 7 Apr 29 11:12 ttyUSB_ZStick → ttyACM0

Perhaps these also need to have group dialout ownership?

[Kim_Andersen]

Maybe. I just dont know how to. I followed the tutorial for setting up symlinks.
This one:

Raspberry Pi - Make serial USB ports persistent via symlinks

Usually, USB sticks attached to Raspberry Pi will get assigned ports in an increasing manner such as /dev/ttyACM0, /dev/ttyACM1, etc. This may become a problem whenever you reattach your USB devices to a different port, you add new devices, or you simply reboot your RPi. The reason is that one specified device may be recognized earlier than another while booting the RPi. You could make these ports permanent via so called symlinks and give them more telling names in contrast to ttyACM0. SSH i…

[5iver (Scott Rushworth)]

@5iver

If I understood the discussion on github, new distributions of Linux changed something, so a new serial handler is needed. OH 2.4 has got old serial handlers.

Could you please provide a link to that discussion?

Thank you! There was a PR that resolved the multiple versions of nrjavaserial being used, which may have been the cause but it did not resolve this issue. The start of these issues also seemed to coincide with the zwave binding moving to a different serial transport. I’ll test with an older binding to try and isolate the issue.

@noppes123

Could this be caused by changed symlinks to the tty devices?

No… the issue still occurs if you do not use symlinks.

[JensH]

Following the discussion a special serialhandler is allready integrated in core. Some of the next builds should get it. The actual build #1583 still has this issue (just updated and tested)

In my case after start of OH2.5 opening paperUI, delete Serial Z-Wave Handler, add it again works.

Not nice, but it is a workaround until issue is solved.

[Kim_Andersen]

In my case, I edit the .thing file from /ttyUSB_ZStick to /ttyACM0. Then the dongle works fine.
After next restart it will fail again, I change the .thing file back to /ttyUSB_ZStick, and it works fine again…

Really odd and quite annoying.

[5iver (Scott Rushworth)]

@JensH

Following the discussion a special serialhandler is allready integrated in core. Some of the next builds should get it. The actual build #1583 still has this issue (just updated and tested)

There was a PR to resolve the issue of multiple versions of nrjavaserial being used. This is in the snapshots and does not correct this issue. There is a special nrjavaserial that is built for use with OH which removed liblocdev, but those discussions are tangential to this issue and to the one about multiple versions being used.

I just tested with an older version of the zwave binding and everything started up fine after several OH restarts. Also, the serial port dropdowns continued to display all ports. The issue appears to be related to this PR, which modified the serial transport used by the zwave binding.

[chris (Chris Jackson)]

@5iver

The issue appears to be related to this PR, which modified the serial transport used by the zwave binding.

Correct - this is what I said previously, although I can’t find the thread. My guess is that there is a startup issue - given that this only seems to be a problem on startup, I think that possibly the provider isn’t available when the binding starts, and therefore it can’t open the port.

That’s a guess though, but given the ESH startup is not well defined, I think it’s a good possibility.

[5iver (Scott Rushworth)]

In addition, there appears to be some kind of conflict in the USB discovery service after the zwave binding is manually restarted, since the ports listed in the dropdown (for all bindings using serial) disappear except for the one used by zwave (at least that is what I am seeing). Possibly due to using different serial transports? It’s probably time to replace openhab-transport-serial in all bindings with openhab-core-io-transport-serial, since TMK there is no reason for OH to have both.

[apella12 (Bob Eckhoff)]

I’m not an expert. I did have a similar problem on start-up after I delete my tmp and cache directories. I’m on OH 2.4 but am using a zwave 2.5 snapshot, so it might not be the same issue. Anyway I found a suggestion on the forum that worked for me. Go into the console and type; feature:install openhab-transport-serial. Everything came back.

In a separate post I was wondering if there is a OH file I can place this command into because I get a lot of errors until I can get into the console after a start-up and issue the above command.

[5iver (Scott Rushworth)]

@apella12

Go into the console and type; feature:install openhab-transport-serial. Everything came back.

The issue reported here is different. If you are running a recent snapshot version of the binding, you will find that zwave will not find the serial port after OH restarts and you will need to restart the binding to get it working. The easiest way I have found to do this is to open Habmin and change the name of the controller.

What you are describing is due to binding dependencies not being automatically resolved when the binding is manually installed, so the serial transport also needs to be manually installed. You could automate this by running my script in a startup rule.

[5iver (Scott Rushworth)]

@ffr, I change the title of your topic… hopefully this is more accurate. Or are you not using the snapshot version of the zwave binding?