[SOLVED] No access to USB zwave stick

[jan_r]

Hi all,
I need your help: since days I am trying to get an Aeotec Zwave stick running and keep failing: I am migrating from a rasberry to a head-less amd64 and therefor copied all conf and user files to the new server. The usb stick runs w/o flaws on the raspi, but not on the new system. Things I tried so far:

• the Zwave stick seems to be recognized

  dmesg output

[    3.182443] usb 1-2: New USB device found, idVendor=0658, idProduct=0200, bcdDevice= 0.00
[    3.182451] usb 1-2: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    5.870531] usbcore: registered new interface driver cdc_acm

ls -l /dev/tty

[...]
crw--w---- 1 root tty       4,  8 Apr 23 23:22 /dev/tty8
crw--w---- 1 root tty       4,  9 Apr 23 23:22 /dev/tty9
crw-rw---- 1 root dialout 166,  0 Apr 23 23:22 /dev/ttyACM0
crw-rw---- 1 root dialout   4, 64 Apr 23 23:22 /dev/ttyS0
crw-rw---- 1 root dialout   4, 65 Apr 23 23:22 /dev/ttyS1

• the user rights for openhab are set (id openhab)

uid=115(openhab) gid=120(openhab) Gruppen=120(openhab),5(tty),20(dialout),100(users)

• the JAVA_OPTS are set to…

EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/ttyACM0"

• I tried different Java versions (Oracle, Zulu8 in 32 and 64 bit)

Nothing works so far. The only hint might be the systemd output in the end (“Could not initialize class gnu.io.RXTXCommDriver”). I tried to fix this with installing rxtx-java jar ( apt-get install librxtx-java), but that didn’t help. No matter how I try to add the path, the jar isn’t found.

Does anybody have an idea? Thanks!

root@server:/usr# systemctl status openhab2
● openhab2.service - openHAB 2 - empowering the smart home
   Loaded: loaded (/usr/lib/systemd/system/openhab2.service; enabled; vendor preset: enabled)
   Active: active (running) since Wed 2019-04-24 00:02:51 CEST; 59s ago
     Docs: https://www.openhab.org/docs/
           https://community.openhab.org
  Process: 31775 ExecStop=/usr/share/openhab2/runtime/bin/karaf stop (code=exited, status=0/SUCCESS)
 Main PID: 31987 (java)
    Tasks: 196 (limit: 4915)
   Memory: 805.6M
      CPU: 2min 3.338s
   CGroup: /system.slice/openhab2.service
           └─31987 /usr/bin/java -Dopenhab.home=/usr/share/openhab2 -Dopenhab.conf=/etc/openhab2 -Dopenhab.runtime=/usr/share/openhab2/runtime -Dopenh
ab.userdata=/var/lib/openhab2 -Dopenhab.logdir=/var/log/openhab2 -Dfelix.cm.dir=/var/lib/openhab2/config -Djava.library.path=/var/lib/openhab2/tmp/lib
 -Djetty.host=0.0.0.0 -Djetty.http.compliance=RFC2616 -Dorg.ops4j.pax.web.listening.addresses=0.0.0.0 -Dorg.osgi.service.http.port=8080 -Dorg.osgi.ser
vice.http.port.secure=8443 -Djava.awt.headless=true -XX:+UseG1GC -Dgnu.io.rxtx.SerialPorts=/dev/ttyACM0 -Djava.library.path=/usr/share/java/ -Djava.en
dorsed.dirs=/usr/lib/jvm/zulu-8-amd64/jre/jre/lib/endorsed:/usr/lib/jvm/zulu-8-amd64/jre/lib/endorsed:/usr/share/openhab2/runtime/lib/endorsed -Djava.
ext.dirs=/usr/lib/jvm/zulu-8-amd64/jre/jre/lib/ext:/usr/lib/jvm/zulu-8-amd64/jre/lib/ext:/usr/share/openhab2/runtime/lib/ext -Dkaraf.instances=/var/li
b/openhab2/tmp/instances -Dkaraf.home=/usr/share/openhab2/runtime -Dkaraf.base=/var/lib/openhab2 -Dkaraf.data=/var/lib/openhab2 -Dkaraf.etc=/var/lib/o
penhab2/etc -Dkaraf.logs=/var/log/openhab2 -Dkaraf.restart.jvm.supported=true -Djava.io.tmpdir=/var/lib/openhab2/tmp -Djava.util.logging.config.file=/
var/lib/openhab2/etc/java.util.logging.properties -Dkaraf.startLocalConsole=false -Dkaraf.startRemoteShell=true -classpath /usr/share/openhab2/runtime
/lib/boot/activation-1.1.1.jar:/usr/share/openhab2/runtime/lib/boot/jaxb-api-2.3.0.jar:/usr/share/openhab2/runtime/lib/boot/jaxb-core-2.2.11.jar:/usr/
share/openhab2/runtime/lib/boot/jaxb-impl-2.2.11.jar:/usr/share/openhab2/runtime/lib/boot/org.apache.karaf.diagnostic.boot-4.2.1.jar:/usr/share/openha
b2/runtime/lib/boot/org.apache.karaf.jaas.boot-4.2.1.jar:/usr/share/openhab2/runtime/lib/boot/org.apache.karaf.main-4.2.1.jar:/usr/share/openhab2/runt
ime/lib/boot/org.osgi.core-6.0.0.jar org.apache.karaf.main.Main

Apr 24 00:03:23 server karaf[31987]:         at org.apache.karaf.features.internal.service.Deployer.deploy(Deployer.java:997)
Apr 24 00:03:23 server karaf[31987]:         at org.apache.karaf.features.internal.service.FeaturesServiceImpl.doProvision(FeaturesServiceImpl.java:1
025)
Apr 24 00:03:23 server karaf[31987]:         at org.apache.karaf.features.internal.service.FeaturesServiceImpl.lambda$doProvisionInThread$13(Features
ServiceImpl.java:964)
Apr 24 00:03:23 server karaf[31987]:         at java.util.concurrent.FutureTask.run(FutureTask.java:266)
Apr 24 00:03:23 server karaf[31987]:         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
Apr 24 00:03:23 server karaf[31987]:         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
Apr 24 00:03:23 server karaf[31987]:         at java.lang.Thread.run(Thread.java:748)
Apr 24 00:03:23 server karaf[31987]: java.lang.ExceptionInInitializerError thrown while loading gnu.io.RXTXCommDriver
Apr 24 00:03:23 server karaf[31987]: java.lang.NoClassDefFoundError: Could not initialize class gnu.io.RXTXCommDriver thrown while loading gnu.io.RXT
XCommDriver
Apr 24 00:03:23 server karaf[31987]: java.lang.NoClassDefFoundError: Could not initialize class gnu.io.RXTXCommDriver thrown while loading gnu.io.RXT
XCommDriver

• Platform information:
  • Hardware: amd64
  • OS: debian stretch
  • Java Runtime Environment: zulu8 in 32 and 64 bit
  • openHAB version: 2.4.

[5iver (Scott Rushworth)]

What is the actual hardware that you are trying to use? Do you see anything in the openhab.log? Could your issue be related to this?

Issue: nrjavaserial 3.12.0 requires glibc > 2.13

[jan_r]

The hardware is a self-assembled NAS following the recommendations from Technikaffe. Its in principle a head-less MiniATX with a IntelCeleron processor. I installed debian on it and other software works out fine (OpenMediaVault as NAS software, CUPs as printer server incl. a printer on the USB interface).

Concerning ophenhab.log - this is what I find there…:

2019-04-24 09:49:54.876 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:4bd824b3
2019-04-24 09:49:58.906 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:4bd824b3
2019-04-24 09:49:58.911 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update received
2019-04-24 09:49:58.944 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_softreset to false
2019-04-24 09:49:58.951 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Trying to send controller command, but controller is not initialised
2019-04-24 09:49:58.952 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update security_networkkey to DC 1E 83 BD 66 9C E0 07 24 60 C9 D0 0E 9D 30 1B
2019-04-24 09:49:58.953 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update security_inclusionmode to 0
2019-04-24 09:49:58.954 [WARN ] [rm.AbstractFileTransformationService] - Could not transform 'NULL' with the file 'switch.map' : Target value not found in map for 'NULL'
2019-04-24 09:49:58.959 [WARN ] [rm.AbstractFileTransformationService] - Could not transform 'NULL' with the file 'switch.map' : Target value not found in map for 'NULL'
2019-04-24 09:49:58.961 [WARN ] [rm.AbstractFileTransformationService] - Could not transform 'NULL' with the file 'switch.map' : Target value not found in map for 'NULL'
2019-04-24 09:49:58.961 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_suc to false
2019-04-24 09:49:58.971 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Trying to send controller command, but controller is not initialised
2019-04-24 09:49:58.972 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_sisnode to 1
2019-04-24 09:49:58.972 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Trying to send controller command, but controller is not initialised
2019-04-24 09:49:58.973 [WARN ] [rm.AbstractFileTransformationService] - Could not transform 'NULL' with the file 'switch.map' : Target value not found in map for 'NULL'
2019-04-24 09:49:58.973 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_sync to false
2019-04-24 09:49:58.974 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Trying to send controller command, but controller is not initialised
2019-04-24 09:49:58.975 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update port to /dev/ttyACM0
2019-04-24 09:49:58.974 [WARN ] [rm.AbstractFileTransformationService] - Could not transform 'NULL' with the file 'switch.map' : Target value not found in map for 'NULL'
2019-04-24 09:49:58.976 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_master to true
2019-04-24 09:49:58.977 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Trying to send controller command, but controller is not initialised
2019-04-24 09:49:58.979 [WARN ] [rm.AbstractFileTransformationService] - Could not transform 'NULL' with the file 'switch.map' : Target value not found in map for 'NULL'
2019-04-24 09:49:58.979 [WARN ] [rm.AbstractFileTransformationService] - Could not transform 'NULL' with the file 'switch.map' : Target value not found in map for 'NULL'
2019-04-24 09:49:58.982 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update inclusion_mode to 2
2019-04-24 09:49:58.984 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_wakeupperiod to 3600
2019-04-24 09:49:58.985 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Trying to send controller command, but controller is not initialised
2019-04-24 09:49:58.986 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update heal_time to 2
2019-04-24 09:49:58.987 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 17 hours time.
2019-04-24 09:49:58.988 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_exclude to false
2019-04-24 09:49:58.989 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Trying to send controller command, but controller is not initialised
2019-04-24 09:49:58.990 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_inclusiontimeout to 30
2019-04-24 09:49:58.995 [WARN ] [rm.AbstractFileTransformationService] - Could not transform 'NULL' with the file 'switch.map' : Target value not found in map for 'NULL'
2019-04-24 09:49:58.998 [WARN ] [rm.AbstractFileTransformationService] - Could not transform 'NULL' with the file 'switch.map' : Target value not found in map for 'NULL'
2019-04-24 09:49:58.991 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Trying to send controller command, but controller is not initialised
2019-04-24 09:49:58.999 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_hardreset to false
2019-04-24 09:49:59.002 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Trying to send controller command, but controller is not initialised
2019-04-24 09:49:59.016 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler
2019-04-24 09:49:59.018 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.
2019-04-24 09:49:59.021 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:4bd824b3.
2019-04-24 09:49:59.022 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 17 hours time.
2019-04-24 09:49:59.035 [WARN ] [rm.AbstractFileTransformationService] - Could not transform 'OPEN' with the file 'presence.map' : Target value not found in map for 'OPEN'
2019-04-24 09:49:59.038 [WARN ] [rm.AbstractFileTransformationService] - Could not transform 'CLOSED' with the file 'presence.map' : Target value not found in map for 'CLOSED'
2019-04-24 09:49:59.039 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Controller status changed to OFFLINE.
2019-04-24 09:49:59.041 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Controller is not online.
2019-04-24 09:49:59.042 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Controller status changed to OFFLINE.
2019-04-24 09:49:59.044 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Controller is not online.
2019-04-24 09:49:59.052 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Controller status changed to OFFLINE.
2019-04-24 09:49:59.054 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Controller is not online.
2019-04-24 09:49:59.055 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Controller status changed to OFFLINE.
2019-04-24 09:49:59.056 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Controller status changed to OFFLINE.
2019-04-24 09:49:59.057 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Controller is not online.
2019-04-24 09:49:59.058 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Controller status changed to OFFLINE.
2019-04-24 09:49:59.057 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Controller is not online.
2019-04-24 09:49:59.059 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Controller status changed to OFFLINE.
2019-04-24 09:49:59.060 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Controller is not online.
2019-04-24 09:49:59.062 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Controller status changed to OFFLINE.
2019-04-24 09:49:59.064 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Controller is not online.
2019-04-24 09:49:59.065 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Controller status changed to OFFLINE.
2019-04-24 09:49:59.061 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Controller status changed to OFFLINE.
2019-04-24 09:49:59.058 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'
2019-04-24 09:49:59.059 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Controller is not online.
2019-04-24 09:49:59.068 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Controller status changed to OFFLINE.
2019-04-24 09:49:59.066 [WARN ] [rm.AbstractFileTransformationService] - Could not transform 'NULL' with the file 'weather_de.map' : Target value not found in map for 'NULL'
2019-04-24 09:49:59.069 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Controller is not online.
2019-04-24 09:49:59.081 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Controller status changed to OFFLINE.
2019-04-24 09:49:59.082 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Controller is not online.
2019-04-24 09:49:59.083 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Controller status changed to OFFLINE.
2019-04-24 09:49:59.084 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Controller is not online.
2019-04-24 09:49:59.085 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Controller status changed to OFFLINE.
2019-04-24 09:49:59.086 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Controller is not online.
2019-04-24 09:49:59.087 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Controller status changed to OFFLINE.
2019-04-24 09:49:59.074 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Controller status changed to OFFLINE.
2019-04-24 09:49:59.089 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Controller is not online.
2019-04-24 09:49:59.089 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Controller status changed to OFFLINE.
2019-04-24 09:49:59.071 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Controller is not online.
2019-04-24 09:49:59.091 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Controller status changed to OFFLINE.
2019-04-24 09:49:59.092 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Controller is not online.
2019-04-24 09:49:59.092 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Controller status changed to OFFLINE.
2019-04-24 09:49:59.093 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Controller is not online.
2019-04-24 09:49:59.072 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Controller is not online.
2019-04-24 09:49:59.095 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Controller status changed to OFFLINE.
2019-04-24 09:49:59.095 [WARN ] [rm.AbstractFileTransformationService] - Could not transform 'NULL' with the file 'door.map' : Target value not found in map for 'NULL'
2019-04-24 09:49:59.075 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Controller status changed to OFFLINE.
2019-04-24 09:49:59.099 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Controller is not online.
[...]

[5iver (Scott Rushworth)]

Connecting to serial port ‘/dev/ttyACM0’

What have you got after this, especially errors? Are you using Thing files?

[jan_r]

The ZWave serial controller wasn’t setup in a thing file, but some of the zwave sensors are. I can’t see anything jumping into my eye in terms of errors. I just restarted the openhab service and get basically the same - it seems to me like the controller isn’t initialized:

2019-04-24 11:35:59.060 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.
2019-04-24 11:35:59.061 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:4bd824b3.
2019-04-24 11:35:59.064 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 15 hours time.
2019-04-24 11:35:59.110 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'
2019-04-24 11:35:59.132 [DEBUG] [org.openhab.binding.zwave           ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=392, service.bundleid=273, service.scope=singleton} - org.openhab.binding.zwave
2019-04-24 11:35:59.132 [DEBUG] [org.openhab.binding.zwave           ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=390, service.bundleid=273, service.scope=singleton} - org.openhab.binding.zwave
2019-04-24 11:35:59.139 [DEBUG] [org.openhab.binding.zwave           ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=389, service.bundleid=273, service.scope=singleton} - org.openhab.binding.zwave
2019-04-24 11:35:59.139 [DEBUG] [org.openhab.binding.zwave           ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=391, service.bundleid=273, service.scope=singleton} - org.openhab.binding.zwave
2019-04-24 11:35:59.133 [DEBUG] [org.openhab.binding.zwave           ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=388, service.bundleid=273, service.scope=singleton} - org.openhab.binding.zwave
2019-04-24 11:35:59.158 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:4bd824b3:node9.
2019-04-24 11:35:59.189 [DEBUG] [org.openhab.binding.zwave           ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=393, service.bundleid=273, service.scope=singleton} - org.openhab.binding.zwave
2019-04-24 11:35:59.190 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:4bd824b3:node6.
2019-04-24 11:35:59.195 [DEBUG] [org.openhab.binding.zwave           ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=394, service.bundleid=273, service.scope=singleton} - org.openhab.binding.zwave
2019-04-24 11:35:59.332 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:4bd824b3:node8.
2019-04-24 11:35:59.340 [DEBUG] [org.openhab.binding.zwave           ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=395, service.bundleid=273, service.scope=singleton} - org.openhab.binding.zwave
2019-04-24 11:35:59.340 [DEBUG] [org.openhab.binding.zwave           ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=396, service.bundleid=273, service.scope=singleton} - org.openhab.binding.zwave
2019-04-24 11:35:59.342 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Channel zwave:device:4bd824b3:node6:scene_number linked - polling started.
2019-04-24 11:35:59.342 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Channel zwave:device:4bd824b3:node9:switch_dimmer linked - polling started.
2019-04-24 11:35:59.344 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Channel zwave:device:4bd824b3:node8:sensor_luminance linked - polling started.

[jan_r]

And in Paper UI the zwave controller states “Serial Error: Port {0} does not exist” - regardless of deleting and setting it up again.

[5iver (Scott Rushworth)]

MiniATX with a IntelCeleron processor

So definitely not amd64 . Are you sure you’re running OH 2.4? There is a recent issue with the latest snapshot versions of the zwave binding that would have the same symptoms. Or maybe you’ve upgraded just the zwave binding?

And in Paper UI the zwave controller states “ Serial Error: Port {0} does not exist ”

There should be an error in the log then… open the file and search for one. Others have also reported issues when other devices are plugged into USB, so you might want to try powering down, unplugging everything, and starting back up.

Is there possibly power management on the USB port that could be powering it off? Are the LEDs flashing?

[jan_r]

Sorry for the confusion - I was referring to x64 instruction set. OH is the newest stable version 2.4.0-1 according to apt-get and in the paper UI the zwave binding is 2.4 as well. Is it worthwhile to downgrade to 2.3?

In openhab.log I can’t fin the error - even if I try it with “less openhab.log | grep error”. The LEDs on the USB keep on flashing all the time and the very same stick keeps on running in the raspi openhab setup.

I am still wondering if OH is able to access USB at all. The message “java.lang.NoClassDefFoundError: Could not initialize class gnu.io.RXTXCommDriver thrown” during systemd start-up - does it mean I can’t access serial interfaces?

[5iver (Scott Rushworth)]

Is it worthwhile to downgrade to 2.3?

Goodness no! If anything, I’d suggest to upgrade at least the binding… lots of fixes have gone in since 2.4.

does it mean I can’t access serial interfaces?

I honestly do not know what that log message is saying. Triple check you’ve done everything in the installation documentation. But from what you’ve said, it looks like you’ve done everything needed to setup Java and the openhab account to access the port. If the controller never comes online, the log should have details as to why it isn’t working. If the controller is working in your Pi, then you could take a look at what a normal zwave startup log looks like and compare it to the log from your new setup. If you post the log file from startup, I’d be happy to take a look. It may be too big to post in the forum, so put it up in a shared storage and post a link.

Try removing your Thing files, in case they are somehow contributing to the issue. Also search the forum for the error… I found a few.

[sihui]

Could not initialize class gnu.io.RXTXCommDriver thrown ”

Install the serial driver through karaf.
The error is different but maybe it helps.

OH2 Z-Wave refactoring and testing... and SECURITY

On a completely clean installation of OH2 Snapshot (#771), you will get the following error when you try to start the new Z-Wave binding: openhab> bundle:start org.openhab.binding.zwave Error executing command: Error executing command on bundles: Error starting bundle 208: Could not resolve module: org.openhab.binding.zwave [208] Unresolved requirement: Import-Package: gnu.io To fix this: feature:install openhab-transport-serial and then Z-Wave will start

[jan_r]

thanks for the hint, unfortunatly it didn’t help… I still get that message.

[jan_r]

Yes - I solved it finally!

It was in deed the RXTX driver - in case somebody runs into the same issue, here is my solution:

1. In case you don’t have RXTX, install it with

   sudo apt-get install librxtx-java
   

2. edit /etc/default/openhab2 and add to the EXTRA_JAVA_OPTS the path - in my case:

   EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/ttyACM0 -Djava.library.path=/usr/lib/jni -cp /usr/share/java/RXTXcomm.jar"
   
   

Thanks a lot @5iver and @sihui sihui for the help! Your support is really appreciated.

[DanielMalmgren]

@jan_r

in case somebody runs into the same issue, here is my solution

I don’t know if this is a common problem, but I’d just like to notice that this exact solution (three years after it was written) saved my skin after upgrading from 3.3.0 to latest 3.4.0 milestone. Thanks a lot!

[HFM (Henning F. Mettge)]

Hi Daniel,

maybe I have the same problem. Could you please describe a little bit in detail what you have done? I use the Docker image on a Synology.

Thanks in advance!
HFM

[DanielMalmgren]

@HFM

Could you please describe a little bit in detail what you have done?

I just did exactly what @jan_r described in the post above…

[HFM (Henning F. Mettge)]

Hi Daniel,

thanks for your answer. I forgot to put in the device in docker run. So everything is fine.

Bye
HFM