"Port /dev/ttyUSB0 does not exist" and "Zwave Network Isn't Ready" errors

[g.wol...@gmail.com]

Hello,

does someone is experiencing issues with latest OpenHab 1.6 builds (from some time now - I didn't had time to investigate) and z-wave binding? Zwave log:

2014-10-12 17:26:32.819 DEBUG o.o.b.z.i.ZWaveActivator[:36]- Z-Wave binding has been started.
2014-10-12 17:26:36.404 INFO  o.o.b.z.i.ZWaveActiveBinding[:306]- Update config, port = /dev/ttyUSB0
2014-10-12 17:26:36.408 INFO  o.o.b.z.i.ZWaveActiveBinding[:311]- Update config, healtime = 2
2014-10-12 17:26:36.409 INFO  o.o.b.z.i.ZWaveActiveBinding[:347]- Update config, setSUC = false
2014-10-12 17:26:36.411 INFO  o.o.b.z.i.ZWaveActiveBinding[:356]- Update config, softReset = true
2014-10-12 17:26:36.415 DEBUG o.o.b.z.i.ZWaveActiveBinding[:99]- Zwave Network isn't ready yet!
2014-10-12 17:26:36.440 INFO  o.o.b.z.i.p.ZWaveController[:139]- Starting Z-Wave controller
2014-10-12 17:26:36.441 INFO  o.o.b.z.i.p.ZWaveController[:144]- Z-Wave timeout is set to 5000ms.
2014-10-12 17:26:36.443 INFO  o.o.b.z.i.p.ZWaveController[:302]- Connecting to serial port /dev/ttyUSB0
2014-10-12 17:26:36.446 ERROR o.o.b.z.i.p.ZWaveController[:317]- Port /dev/ttyUSB0 does not exist
2014-10-12 17:28:00.077 DEBUG o.o.b.z.i.ZWaveActiveBinding[:209]- internalReceiveCommand Called, But Not Properly Configure yet or Zwave Network Isn't Ready, returning.

but as you can see mentioned USB port does exists:

ls /dev/ttyUSB*
/dev/ttyUSB0  /dev/ttyUSB1

USB port exists. I'm using Aeon Labs USB stick. When I'm trying to configure it with Domoticz software (http://www.domoticz.com/ - I was testing it before and I leaved it just to have other testing environment) I have not problem to configure USB stick and find my zwave devices. When I unplugged USB stick and plugged it again it appeared as "/dev/ttyUSB2" and again I had no problem with using it with Domoticz and OpenHab returns:

2014-10-12 17:41:26.422 DEBUG o.o.b.z.i.ZWaveActivator[:36]- Z-Wave binding has been started.
2014-10-12 17:41:31.735 INFO  o.o.b.z.i.ZWaveActiveBinding[:306]- Update config, port = /dev/ttyUSB2
2014-10-12 17:41:31.745 INFO  o.o.b.z.i.ZWaveActiveBinding[:311]- Update config, healtime = 2
2014-10-12 17:41:31.747 INFO  o.o.b.z.i.ZWaveActiveBinding[:347]- Update config, setSUC = false
2014-10-12 17:41:31.748 INFO  o.o.b.z.i.ZWaveActiveBinding[:356]- Update config, softReset = true
2014-10-12 17:41:31.753 DEBUG o.o.b.z.i.ZWaveActiveBinding[:99]- Zwave Network isn't ready yet!
2014-10-12 17:41:31.782 INFO  o.o.b.z.i.p.ZWaveController[:139]- Starting Z-Wave controller
2014-10-12 17:41:31.783 INFO  o.o.b.z.i.p.ZWaveController[:144]- Z-Wave timeout is set to 5000ms.
2014-10-12 17:41:31.784 INFO  o.o.b.z.i.p.ZWaveController[:302]- Connecting to serial port /dev/ttyUSB2
2014-10-12 17:41:31.788 ERROR o.o.b.z.i.p.ZWaveController[:317]- Port /dev/ttyUSB2 does not exist
2014-10-12 17:43:00.042 DEBUG o.o.b.z.i.ZWaveActiveBinding[:209]- internalReceiveCommand Called, But Not Properly Configure yet or Zwave Network Isn't Ready, returning.

I'm using latest build of OpenHab 1.6 (build 744 from https://openhab.ci.cloudbees.com/job/openHAB/).

Any ideas? I'm running OpenHab on normal Atom CPU based PC (headless) with Ubuntu installed with latest habmin.

When I finally manage to "catch" USB stick this is all I'm getting in logs:

2014-10-12 18:05:47.845 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1066]- Starting Z-Wave receive thread
2014-10-12 18:05:47.846 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:923]- Starting Z-Wave send thread
2014-10-12 18:05:47.845 INFO  o.o.b.z.i.p.ZWaveController[:315]- Serial port is initialized
2014-10-12 18:05:47.922 DEBUG o.o.b.z.i.ZWaveActiveBinding[:99]- Zwave Network isn't ready yet!
2014-10-12 18:05:52.422 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1113]- Receive Message = 01 01 01
2014-10-12 18:05:52.424 ERROR o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1054]- Message is not valid, discarding
2014-10-12 18:05:52.923 DEBUG o.o.b.z.i.ZWaveActiveBinding[:99]- Zwave Network isn't ready yet!
2014-10-12 18:05:57.818 WARN  o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1180]- Threads not alive, respawning
2014-10-12 18:05:57.819 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1010]- Stopped Z-Wave send thread
2014-10-12 18:05:57.839 INFO  o.o.b.z.i.p.ZWaveController[:384]- Disconnected from serial port
2014-10-12 18:05:57.839 INFO  o.o.b.z.i.p.ZWaveController[:302]- Connecting to serial port /dev/zwave
2014-10-12 18:05:57.852 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1066]- Starting Z-Wave receive thread
2014-10-12 18:05:57.852 INFO  o.o.b.z.i.p.ZWaveController[:315]- Serial port is initialized
2014-10-12 18:05:57.853 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:923]- Starting Z-Wave send thread
2014-10-12 18:05:57.923 DEBUG o.o.b.z.i.ZWaveActiveBinding[:99]- Zwave Network isn't ready yet!
2014-10-12 18:06:02.924 DEBUG o.o.b.z.i.ZWaveActiveBinding[:99]- Zwave Network isn't ready yet!
2014-10-12 18:06:04.455 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1113]- Receive Message = 01 09 00 04 00 0F 03 25 03 00 D8
2014-10-12 18:06:04.465 DEBUG o.o.b.z.i.p.ZWaveController[:161]- Message: class = ApplicationCommandHandler (0x04), type = Request (0x00), payload = 00 0F             03 25 03 00
2014-10-12 18:06:04.468 WARN  o.o.b.z.i.p.s.ApplicationCommandMessageClass[:34]- NODE 15: Not initialized yet, ignoring message.
2014-10-12 18:06:07.925 DEBUG o.o.b.z.i.ZWaveActiveBinding[:99]- Zwave Network isn't ready yet!
2014-10-12 18:06:12.926 DEBUG o.o.b.z.i.ZWaveActiveBinding[:99]- Zwave Network isn't ready yet!
2014-10-12 18:06:17.819 WARN  o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1180]- Threads not alive, respawning
2014-10-12 18:06:17.820 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1010]- Stopped Z-Wave send thread
2014-10-12 18:06:17.842 INFO  o.o.b.z.i.p.ZWaveController[:384]- Disconnected from serial port
2014-10-12 18:06:17.843 INFO  o.o.b.z.i.p.ZWaveController[:302]- Connecting to serial port /dev/zwave
2014-10-12 18:06:17.859 INFO  o.o.b.z.i.p.ZWaveController[:315]- Serial port is initialized

Regards

[Chris Jackson]

I’m not having any problems here on either of my 2 machines (Mac and Linux). What other bindings are you using?

Chris

[g.wol...@gmail.com]

org.openhab.action.mail-1.6.0-SNAPSHOT.jar        org.openhab.binding.mqttitude-1.6.0-SNAPSHOT.jar      org.openhab.binding.xbmc-1.6.0-SNAPSHOT.jar

org.openhab.action.squeezebox-1.6.0-SNAPSHOT.jar  org.openhab.binding.networkhealth-1.6.0-SNAPSHOT.jar  org.openhab.binding.zwave-1.6.0-SNAPSHOT.jar

org.openhab.action.xbmc-1.6.0-SNAPSHOT.jar        org.openhab.binding.ntp-1.6.0-SNAPSHOT.jar            org.openhab.io.habmin-1.6.0-SNAPSHOT.jar

org.openhab.binding.astro-1.6.0-SNAPSHOT.jar      org.openhab.binding.plugwise-1.6.0-SNAPSHOT.jar       org.openhab.io.squeezeserver-1.6.0-SNAPSHOT.jar

org.openhab.binding.exec-1.6.0-SNAPSHOT.jar       org.openhab.binding.samsungtv-1.6.0-SNAPSHOT.jar      org.openhab.persistence.mysql-1.6.0-SNAPSHOT.jar

org.openhab.binding.http-1.6.0-SNAPSHOT.jar       org.openhab.binding.squeezebox-1.6.0-SNAPSHOT.jar     README

org.openhab.binding.mqtt-1.6.0-SNAPSHOT.jar       org.openhab.binding.tcp-1.6.0-SNAPSHOT.jar

I'm using for plugwise and for zwave persistent USB names described here:

https://www.domotiga.nl/boards/1/topics/1222

[Nolan Garrett]

I have experienced this same behavior, and it started with the 1.6 builds. 

2014-10-12 18:05:57.818 WARN  o.o.<span style="color: #000;" class="sty

...

[g.wol...@gmail.com]

Have you returned to 1.5.x to solve this issue?

[g.wol...@gmail.com]

Hello again,

sorry for asking again but have you managed to solve this issue?

W dniu niedziela, 12 października 2014 22:42:32 UTC+2 użytkownik Nolan Garrett napisał:

[Daniel Schade]

I have the same problem with Ubuntu 14.04.01 and openHAB 1.6 latest build (751) with latest add ons and AEON Labs Z-Stick Series 2.

INFO  o.o.b.z.i.p.ZWaveController[:142]- Starting Z-Wave controller

INFO  o.o.b.z.i.p.ZWaveController[:147]- Z-Wave timeout is set to 5000ms.

INFO  o.o.b.z.i.p.ZWaveController[:305]- Connecting to serial port ttyUSB0

ERROR o.o.b.z.i.p.ZWaveController[:320]- Port ttyUSB0 does not exist

For openhab i used a user openhab with group openhab:
openhab:x:1001:1001:openHAB:/home/openhab:/bin/bash

openhab Runtime:

/opt/openhab/

openHAB Addons:

org.openhab.action.homematic-1.6.0-SNAPSHOT.jar

org.openhab.action.prowl-1.6.0-SNAPSHOT.jar

org.openhab.action.pushover-1.6.0-SNAPSHOT.jar

org.openhab.binding.astro-1.6.0-SNAPSHOT.jar

org.openhab.binding.exec-1.6.0-SNAPSHOT.jar

org.openhab.binding.fritzbox-1.6.0-SNAPSHOT.jar

org.openhab.binding.homematic-1.6.0-SNAPSHOT.jar

org.openhab.binding.http-1.6.0-SNAPSHOT.jar

org.openhab.binding.milight-1.6.0-SNAPSHOT.jar

org.openhab.binding.mpd-1.6.0-SNAPSHOT.jar

org.openhab.binding.mqtt-1.6.0-SNAPSHOT.jar

org.openhab.binding.mqttitude-1.6.0-SNAPSHOT.jar

org.openhab.binding.networkhealth-1.6.0-SNAPSHOT.jar

org.openhab.binding.ntp-1.6.0-SNAPSHOT.jar

org.openhab.binding.tcp-1.6.0-SNAPSHOT.jar

org.openhab.binding.zwave-1.6.0-SNAPSHOT.jar

org.openhab.io.cv-1.6.0-SNAPSHOT.jar

org.openhab.io.habmin-1.6.0-SNAPSHOT.jar

org.openhab.persistence.exec-1.6.0-SNAPSHOT.jar

org.openhab.persistence.logging-1.6.0-SNAPSHOT.jar

org.openhab.persistence.mqtt-1.6.0-SNAPSHOT.jar

org.openhab.persistence.rrd4j-1.6.0-SNAPSHOT.jar

dmesg:

usb 3-2: cp210x converter now attached to ttyUSB0

ls -lah /dev/ttyUSB0

crw-rw---- 1 root dialout 188, 0 Oct 21 21:09 /dev/ttyUSB0

/etc/group

tty:x:5:openhab

uucp:x:10:openhab

dialout:x:20:openhab

java -version

java version "1.8.0_20"

Java(TM) SE Runtime Environment (build 1.8.0_20-b26)

Java HotSpot(TM) 64-Bit Server VM (build 25.20-b23, mixed mode)

uname -a

Linux openhab 3.13.0-37-generic #64-Ubuntu SMP Mon Sep 22 21:28:38 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux

Anyone a solution for this problem ?

[karsten.k...@gmail.com]

Hi,

can you check as per serial binding description:

you might have to adopt start.sh to have the serial port included. the java command line should then include the following parameters:

-Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0

Cheers

Karsten

2014-10-12 18:05:57.818 WARN  o.o.<span style="color: #000;" class="sty

...

[Neil Renaud]

If you have multiple serial devices I'd recommend making these as per tsymlinkshese details:

https://code.google.com/p/openhab-samples/wiki/Tricks#How_to_configure_openHAB_to_connect_to_device_symlinks_(on_Linux

In fact I'd recommend doing that even if you don't as unplugging and replugging the controller can give you a different device name.

Neil

[Daniel Schade]

Hi Karsten,

i have changed and restarted the service under /etc/init.d/openhab:

DAEMON_ARGS="-Dosgi.clean=true -Declipse.ignoreApp=true -Dosgi.noShutdown=true -Djetty.port=$HTTPPORT -Djetty.port.ssl=$HTTPSPORT -Djetty.home=$ECLIPSEHOME -Dlogback.configurationFile=$ECLIPSEHOME/configurations/logback.xml -Dfelix.fileinstall.dir=$ECLIPSEHOME/addons -Djava.library.path=$ECLIPSEHOME/lib -Djava.security.auth.login.config=$ECLIPSEHOME/etc/login.conf -Dorg.quartz.properties=$ECLIPSEHOME/etc/quartz.properties -Djava.awt.headless=true -jar $cp -console ${TELNETPORT} -Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0"

The problem persists.

[karsten.k...@gmail.com]

I read somewhere that there might be an issue putting it to the end of the line. try to put is somewhere more advance in the line. i dont have access to my line so far but i think its just before the -Djetty options. And here it works.

(as a reference: https://groups.google.com/forum/#!searchin/openhab/helios/openhab/R2uGyf0jNjE/wni9OzHkAogJ)

Cheers

Karsten

[Daniel Schade]

I put the -Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0 line before, but same problem.

[Neil Renaud]

Silly question but it is still ttyUSB0? It hasn't moved due to an unplug / replug?

--
You received this message because you are subscribed to a topic in the Google Groups "openhab" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/openhab/epGh6SCqI6w/unsubscribe.
To unsubscribe from this group and all its topics, send an email to openhab+u...@googlegroups.com.
To post to this group, send email to ope...@googlegroups.com.
Visit this group at http://groups.google.com/group/openhab.
For more options, visit https://groups.google.com/d/optout.

[Daniel Schade]

Yes it is silly... i removed the Z-Wave stick and reconnected.. same device /dev/ttyUSB0. And.. same problem.

[g.wol...@gmail.com]

On my end params for OH runtime starts (inside daemon startup script) with:

DAEMON_ARGS="-Dgnu.io.rxtx.SerialPorts=/dev/ttyUSBPlugwise:/dev/ttyUSBZwave .....

Two USB aliases can be found here:

lrwxrwxrwx 1 0  0      7 paź 22 08:23 /dev/ttyUSBPlugwise -> ttyUSB0

lrwxrwxrwx 1 0  0      7 paź 22 09:45 /dev/ttyUSBZwave -> ttyUSB2

(now it has USB2 because I've replugged it). Currently my zwave.log contains only multiple lines like this:

2014-10-22 15:22:01.957 DEBUG o.o.b.z.i.ZWaveActiveBinding[:209]- internalReceiveCommand Called, But Not Properly Configure yet or Zwave Network Isn't Ready, returning.
2014-10-22 15:22:02.055 DEBUG o.o.b.z.i.ZWaveActiveBinding[:209]- internalReceiveCommand Called, But Not Properly Configure yet or Zwave Network Isn't Ready, returning.
2014-10-22 15:22:06.403 DEBUG o.o.b.z.i.ZWaveActiveBinding[:99]- Zwave Network isn't ready yet!
2014-10-22 15:22:11.405 DEBUG o.o.b.z.i.ZWaveActiveBinding[:99]- Zwave Network isn't ready yet!
2014-10-22 15:22:16.406 DEBUG o.o.b.z.i.ZWaveActiveBinding[:99]- Zwave Network isn't ready yet!
2014-10-22 15:22:21.407 DEBUG o.o.b.z.i.ZWaveActiveBinding[:99]- Zwave Network isn't ready yet!
2014-10-22 15:22:26.417 DEBUG o.o.b.z.i.ZWaveActiveBinding[:99]- Zwave Network isn't ready yet!
2014-10-22 15:22:31.417 DEBUG o.o.b.z.i.ZWaveActiveBinding[:99]- Zwave Network isn't ready yet!
2014-10-22 15:22:36.418 DEBUG o.o.b.z.i.ZWaveActiveBinding[:99]- Zwave Network isn't ready yet!

In habmin I don't see any zwave devices. When I'm connecting Aeon Labs stick to my Windows desktop and checking it with zensys tools:

http://www.moonlitzwave.com/zensys-tools.zip

z-wave devices are being loaded without any problems and I have access to most of them. I've noticed that if I finally fetch zwave devices from aeon stick to openhab and try to change state of one device which is probably not accessible I'm loosing connection to z-wave network. I'm using latest builds almost always.

Regards

[g.wol...@gmail.com]

Does placing -Dgnu.io.rxtx.SerialPorts=/dev/ttyUSBPlugwise:/dev/ttyUSBZwave param a little futher in DAEMONA_ARGS line makes any difference? I've moved it after "-Dosgi.noShutdown=true", restarted openhab service and something has started working even without reconnecting aeon labs stick or restarting whole system.

2014-10-12 18:05:47.845 INFO  o.o.b.z.i.p.ZWaveController[:315]- Serial<span st

...

[g.wol...@gmail.com]

It worked maybe for 30 minutes.

Then again total zwave network none connectivity with entries in log:

2014-10-22 19:27:14.028 ERROR o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1032]- NODE 27: Timeout while sending message. Requeueing
2014-10-22 19:28:04.410 DEBUG o.o.b.z.i.p.c.ZWaveBinarySwitchCommandClass[:135]- Creating new message for application command SWITCH_BINARY_SET for node 16
2014-10-22 19:28:04.415 DEBUG o.o.b.z.i.p.SerialMessage[:108]- NODE 16: Creating empty message of class = SendData (0x13), type = Request (0x00)
2014-10-22 19:28:04.418 DEBUG o.o.b.z.i.protocol.ZWaveNode[:582]- NODE 16: Encapsulating message, instance / endpoint 1
2014-10-22 19:28:04.421 DEBUG o.o.b.z.i.p.ZWaveController[:754]- Callback ID = 146
2014-10-22 19:28:04.425 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:971]- Took message from queue for sending. Queue length = 0
2014-10-22 19:28:04.426 DEBUG o.o.b.z.i.p.SerialMessage[:226]- Assembled message buffer = 01 0A 00 13 10 03 25 01 00 25 92 66
2014-10-22 19:28:04.427 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1000]- Sending Message = 01 0A 00 13 10 03 25 01 00 25 92 66
2014-10-22 19:28:04.429 DEBUG o.o.b.z.i.p.ZWaveController[:396]- Enqueueing message. Queue length = 0
2014-10-22 19:28:04.450 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:130]- Creating new message for application command BASIC_SET for node 25
2014-10-22 19:28:04.451 DEBUG o.o.b.z.i.p.SerialMessage[:108]- NODE 25: Creating empty message of class = SendData (0x13), type = Request (0x00)
2014-10-22 19:28:04.452 DEBUG o.o.b.z.i.p.ZWaveController[:754]- Callback ID = 147
2014-10-22 19:28:04.453 DEBUG o.o.b.z.i.p.ZWaveController[:396]- Enqueueing message. Queue length = 1

Reconnecting (usb plug out and plug gin without openhab restarting) Aeon Labs Stick fixes issue right away:

2014-10-22 19:28:04.577 ERROR o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1008]- Got I/O exception Błąd wejścia/wyjścia in writeArray during sending. exiting thread.
2014-10-22 19:28:04.578 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1053]- Stopped Z-Wave send thread
2014-10-22 19:28:12.744 WARN  o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1223]- Threads not alive, respawning
2014-10-22 19:28:12.747 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1189]- Stopped Z-Wave receive thread
2014-10-22 19:28:12.827 INFO  o.o.b.z.i.p.ZWaveController[:387]- Disconnected from serial port
2014-10-22 19:28:12.828 INFO  o.o.b.z.i.p.ZWaveController[:305]- Connecting to serial port /dev/ttyUSBZwave
2014-10-22 19:28:12.900 INFO  o.o.b.z.i.p.ZWaveController[:318]- Serial port is initialized
2014-10-22 19:28:12.900 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1109]- Starting Z-Wave receive thread
2014-10-22 19:28:12.901 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:966]- Starting Z-Wave send thread
2014-10-22 19:28:12.907 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:971]- Took message from queue for sending. Queue length = 0
2014-10-22 19:28:12.908 DEBUG o.o.b.z.i.p.SerialMessage[:226]- Assembled message buffer = 01 0A 00 13 19 03 20 01 00 25 93 6B
2014-10-22 19:28:12.909 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1000]- Sending Message = 01 0A 00 13 19 03 20 01 00 25 93 6B
2014-10-22 19:28:12.914 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1156]- Receive Message = 01 09 00 04 08 1C 03 80 03 64 02
2014-10-22 19:28:12.917 DEBUG o.o.b.z.i.p.ZWaveController[:164]- Message: class = ApplicationCommandHandler (0x04), type = Request (0x00), payload = 08 1C 03 80 03 64
2014-10-22 19:28:12.918 DEBUG o.o.b.z.i.p.s.ApplicationCommandMessageClass[:37]- NODE 28: Application Command Request (Stage Node Dead)
2014-10-22 19:28:12.919 DEBUG o.o.b.z.i.protocol.ZWaveNode[:207]- NODE 28: Node is now ALIVE
2014-10-22 19:28:12.920 DEBUG o.o.b.z.i.p.ZWaveController[:411]- Notifying event listeners
2014-10-22 19:28:12.921 DEBUG o.o.b.z.i.ZWaveActiveBinding[:398]- ZwaveIncomingEvent
2014-10-22 19:28:12.922 DEBUG o.o.b.z.i.ZWaveNetworkMonitor[:611]- NODE 28: Node Status event - Node is Alive
2014-10-22 19:28:12.923 DEBUG o.o.b.z.i.p.s.ApplicationCommandMessageClass[:42]- NODE 28: Node has risen from the DEAD. Set stage to DONE.
2014-10-22 19:28:12.924 DEBUG o.o.b.z.i.p.s.ApplicationCommandMessageClass[:60]- NODE 28: Incoming command class BATTERY (0x80)
2014-10-22 19:28:12.925 DEBUG o.o.b.z.i.p.c.ZWaveBatteryCommandClass[:74]- Node 28: Received Battery Request
2014-10-22 19:28:12.926 DEBUG o.o.b.z.i.p.c.ZWaveBatteryCommandClass[:84]- Node 28: Battery report value = 0x64
2014-10-22 19:28:12.927 DEBUG o.o.b.z.i.p.ZWaveController[:411]- Notifying event listeners
2014-10-22 19:28:12.928 DEBUG o.o.b.z.i.ZWaveActiveBinding[:398]- ZwaveIncomingEvent
2014-10-22 19:28:12.928 DEBUG o.o.b.z.i.ZWaveActiveBinding[:419]- Got a value event from Z-Wave network for nodeId = 28, endpoint = 1, command class = BATTERY, value = 100
2014-10-22 19:28:12.930 ERROR o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1171]- Message cancelled by controller (CAN), resending
2014-10-22 19:28:13.031 DEBUG o.o.b.z.i.p.ZWaveController[:396]- Enqueueing message. Queue length = 1
2014-10-22 19:28:13.032 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1046]- Response processed after 123ms/4602ms.

[g.wol...@gmail.com]

And again it worked for about 2-3 hours. IMHO there is something wrong with z-wave binding because restarting openhab and accessing z-wave binding is not showing any devices at all. When I'm stopping openhab and starting domoticz (www.domoticz.com) all of my devices stored in Aeon Labs stick are being showed and zwave network is starting to work (or at least starts discover).

On Wednesday, October 22, 2014 7:33:34 PM UTC+2, g.wol...@gmail.com wrote:

It worked maybe for 30 minutes.

Then again total zwave network none connectivity with entries in log:

2014-10-22 19:27:14.028 ERROR o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1032]- NODE 27: Timeout while sending message. Requeueing
2014-10-22 19:28:04.410 DEBUG o.o.b.z.i.p.c.ZWaveBinarySwitchCommandClass[:135]- Creating new message for application command SWITCH_BINARY_SET for node 16
2014-10-22 19:28:04.415 DEBUG o.o.b.z.i.p.SerialMessage[:108]- NODE 16: Creating empty message of class = SendData (0x13), type = Request (0x00)
2014-10-22 19:28:04.418 DEBUG o.o.b.z.i.protocol.ZWaveNode[:582]- NODE 16: Encapsulating message, instance / endpoint 1
2014-10-22 19:28:04.421 DEBUG o.o.b.z.i.p.ZWaveController[:754]- Callback ID = 146
2014-10-22 19:28:04.425 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:971]- Took message from queue for sending. Queue length = 0
2014-10-22 19:28:04.426 DEBUG o.o.b.z.i.p.SerialMessage[:226]- Assembled message buffer = 01 0A 00 13 10 03 25 01 00 25 92 66
2014-10-22 19:28:04.427 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1000]- Sending Message = 01 0A 00 13 10 03 25 01 00 25 92 66
2014-10-22 19:28:04.429 DEBUG o.o.b.z.i.p.ZWaveController[:396]- Enqueueing message. Queue length = 0
2014-10-22 19:28:04.450 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:130]- Creating new message for application command BASIC_SET for node 25
2014-10-22 19:28:04.451 DEBUG o.o.b.z.i.p.SerialMessage[:108]- NODE 25: Creating empty message of class = SendData (0x13), type = Request (0x00)
2014-10-22 19:28:04.452 DEBUG o.o.b.z.i.p.ZWaveController[:754]- Callback ID = 147
2014-10-22 19:28:04.453 DEBUG o.o.b.z.i.p.ZWaveController[:396]- Enqueueing message. Queue length = 1

Reconnecting (usb plug out and plug gin without openhab restarting) Aeon Labs Stick fixes issue right away:

2014-10-22 19:28:04.577 ERROR o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1008]- Got I/O exception Błąd wejścia/wyjścia in writeArray during sending. exiting thread.
2014-10-22 19:28<

...

[Chris Jackson]

I don't think there's an issue with the binding, but possibly there are issues with the serial driver and its compatibility with all possible computers. At the end of the day, the zwave binding just tries to open a port - this is implemented by the java serial driver.  I don't know what hardware people are using - maybe there's something common here that we can look at?

Chris

[Nolan Garrett]

At you guys using any extension cables or USB hubs? My issue went away when I switched to a short extension cable.

---

From: Chris Jackson
Sent: ‎10/‎23/‎2014 4:07 AM
To: ope...@googlegroups.com
Cc: g.wol...@gmail.com; g.wol...@gmail.com
Subject: Re: [openhab] Re: "Port /dev/ttyUSB0 does not exist" and "ZwaveNetwork Isn't Ready" errors

I don't think there's an issue with the binding, but possibly there are issues with the serial driver and its compatibility with all possible computers. At the end of the day, the zwave binding just tries to open a port - this is implemented by the java serial driver.  I don't know what hardware people are using - maybe there's something common here that we can look at?

Chris

--

[Chris Jackson]

From my side, I have an extension cable - maybe 1.5m - so that I can sit the stick up higher rather than right behind my PC. It works 100% fine, but this would likely be closely linked to the hardware, and maybe the 'quality' of the cable (not that mine is a quality cable, but I suspect some cheap use lower gauge wire to cut cost, but this will also impact on voltage drop).

Chris

[Daniel Schade]

At my side. 

First: I have switched the Z-Wave stick directly to the usb interface. -> Port /dev/ttyUSB0 does not exist.

Second: Changed java version from 1.8 to 1.7. -> Port /dev/ttyUSB0 does not exist.

[g.wol...@gmail.com]

Hello,

I'm attaching zwave log from moment when zwave devices are becoming unresponsible (about 12:36:07 hour). Maybe someone with better understanding of zwave communication will be able to tell me where I should look for solution.

Thanks

[Chris Jackson]

I thought that the problem was the serial port couldn’t be opened as it was reported as not existing? Clearly there’s no problem with this log - it looks more like the controller (i.e. zstick) might have an issue or something, but all commands are being responded to so the port must be open?

It’s unclear what the problem is since the stick is responding, but clearly unable to communicate with at least some devices (nodes 16 and 17) but the controller is also cancelling a number of frames (for reasons that I can’t tell). I don’t think this is the same problem reported here though!

Chris

[Daniel Schade]

Halleluja!!!!

Amazing..

Old openhab.cfg (with error described before):

zwave:port=ttyUSB0

New openhab.cfg:

zwave:port=/dev/ttyUSB0

20:01:06.535 INFO  o.o.c.s.AbstractActiveService[:169]- ZWave Refresh Service has been started

20:01:06.604 INFO  o.o.b.z.i.p.ZWaveController[:142]- Starting Z-Wave controller

20:01:06.605 INFO  o.o.b.z.i.p.ZWaveController[:147]- Z-Wave timeout is set to 5000ms.

20:01:06.607 INFO  o.o.b.z.i.p.ZWaveController[:305]- Connecting to serial port /dev/ttyUSB0

20:01:06.729 INFO  o.o.b.z.i.p.ZWaveController[:318]- Serial port is initialized

20:01:07.193 INFO  o.o.b.z.i.p.s.SerialApiGetInitDataMessageClass[:57]- NODE 1: Node found

20:01:07.194 INFO  o.o.b.z.i.p.s.SerialApiGetInitDataMessageClass[:65]- ZWave Controller using Controller API

20:01:07.195 INFO  o.o.b.z.i.p.s.SerialApiGetInitDataMessageClass[:66]- ZWave Controller is Primary Controller

20:01:07.196 INFO  o.o.b.z.i.p.s.SerialApiGetInitDataMessageClass[:67]- ------------Number of Nodes Found Registered to ZWave Controller------------

20:01:07.197 INFO  o.o.b.z.i.p.s.SerialApiGetInitDataMessageClass[:68]- # Nodes = 1

20:01:07.198 INFO  o.o.b.z.i.p.s.SerialApiGetInitDataMessageClass[:69]- ----------------------------------------------------------------------------

Headnut!!! :D

[Vlad Lyseyko]

Hi guys,

I'm having the same problem with my Z-Stick. I've tried everything suggested in here but I still can't get it working  reliably. Some time I need to restart openhab 3-4 times before it will initializes the ttyUSB  device. Looking that java has some problem with RXTX devices directly, I was wondering if it's possible to use TCP/Telnet port instead in z-wave binding  and redirect your zwave ttyUSB dev using something like ser2net or socat, much like Alarmedecoder binding is working. This could eliminate initialization problem and also could be useful in multi-home/multi-site environment (like having your cottage and your office controlled through one instance of Openhab by just deploring remote Z-Sticks on raspberypi).

Vlad

[Piotr Walczowski]

I was similar problem on rpi - the problem was in permission to /dev/ttyUSB0 - user openhab was not granted for it

[Vlad Lyseyko]

my permissions are 660, but I've have tried running it as root and was still getting the same error...

[Piotr Walczowski]

But if you run openhab from /etc/init.d/openhab script you should remember that it run as openhab user - or other, depending what you have in config file - /etc/default/openhab in my case - you can see what file was used in line:

# Read configuration variable file if it is present

[ -r /etc/default/$NAME ] && . /etc/default/$NAME

So, user openhab should be able to read and write to /dev/ttyUSB0 - I set 666 permission and everything works fine.

Maybe it help you.

[Stefan Peter]

Dear Vlad Lyseyko

Am 26.01.2015 um 05:41 schrieb Vlad Lyseyko:
> my permissions are 660, but I've have tried running it as root and was
> still getting the same error...

You will get the same error if a stale lock file for ttyUSB0 exists.
Please make sure there is no /var/loc/LCK..ttyUSB0 file prior to
starting openhab. And of course, if you delete this file manually, you
are responsible that no other application is trying to access
/dev/ttyUSB0 ;)

Regards

Stefan Peter

[Piotr Walczowski]

A little update.

Because permissions are restore to original when you unplug and plug again usb device, add user openhab to proper group will be better solution.  

[Vlad Lyseyko]

Hi Piotr,

I did try setting my permission to 666 as well and I was not running openhab from the /etc/init.d... I'm lunching it from /opt/openhab/start.sh as root and still get this error... I think I should try to actually running it from the startup script and see if that will fix my problem. But I'm still very interested if it's possible to run ser2net with zwave usb and configure the binding to use tcp/telnet port instead...

Vlad

[Pascal Leynaud]

I also had this issue and eventually get rid of it by modifying my start.sh.

I modifyed -Dgnu.io.rxtx.SerialPorts=/dev/ttyAMA0 (as I'm also using EnOcean) to -Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0:/dev/ttyAMA0 (placed just before the -jar option if it has some importance) after a reboot all was ok.

Pascal

[William Leemans]

For posterity:

this happened to me as well

I resolved it by allowing the user that runs openhab (openhab in my case) to read/write to /var/lock

Disclaimer