I’ve just recently bought a Gen5 Z-Stick and installed Openhab2 from the nightly build on the 14 July 2016.
I’ve paired one Z-Wave device with the stick, a Aeon multi-sensor.
I’m running openhab on a Gentoo box with amd64 architecture and kernel 4.4.8-hardened-r1.
The Z-Stick is mount as /dev/ttyACM0 and permissions seems to be correct.
I’ve also tried both Icedtea and Oracle 1.8 JVMs. The same issue is with both.
Unfortunately when I start openhab, I get loads of communication issues, such as:
2016-07-15 13:13:21.076 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2016-07-15 13:13:21.345 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app
2016-07-15 13:13:21.466 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui
2016-07-15 13:13:21.515 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start
2016-07-15 13:13:21.681 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
2016-07-15 13:13:22.262 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0’
2016-07-15 13:13:22.291 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2016-07-15 13:13:22.294 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - Update networkKey
2016-07-15 13:13:22.301 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2016-07-15 13:13:22.302 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
2016-07-15 13:13:25.449 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 1: Node found
2016-07-15 13:13:25.450 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 2: Node found
2016-07-15 13:13:25.450 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API
2016-07-15 13:13:25.451 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller
2016-07-15 13:13:25.451 [INFO ] [age.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------
2016-07-15 13:13:25.451 [INFO ] [age.SerialApiGetInitDataMessageClass] - # Nodes = 2
2016-07-15 13:13:25.451 [INFO ] [age.SerialApiGetInitDataMessageClass] - ---------------------------------------------------------------------------
2016-07-15 13:13:25.474 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising Thing Node…
2016-07-15 13:13:25.746 [WARN ] [l.serialmessage.SendDataMessageClass] - NODE 2: Already processed another send data request for this callback Id, ignoring.
2016-07-15 13:13:30.699 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 0 attempts left!
2016-07-15 13:13:30.700 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
2016-07-15 13:13:35.787 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 2 attempts left!
2016-07-15 13:13:35.787 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
2016-07-15 13:13:40.788 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 1 attempts left!
2016-07-15 13:13:40.789 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
2016-07-15 13:13:45.790 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 0 attempts left!
2016-07-15 13:13:45.790 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
2016-07-15 13:13:50.791 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=2, callback=11, payload=02 03 70 05 08
From the log it looks like the device (node 2) simply isn’t responding. It might not be properly included into the network, or there may be a communication problem (eg distance) or it may be a database problem - it’s hard to tell from this log.
I would suggest enabling debug logging - this will help establish what is being sent, and if other commands are being processed correctly.
To enable debug, use the command log:set debug org.openhab.binding.zwave
It’s a bit hard to say conclusively from a short log, but this looks ok to me…
Retries and timeouts will occur occasionally - it’s part of life with radio communications. If the issue is “occasional” then just live with it, but if it is quite often, then you will need to resolve the network difficulties by adding more devices.
If it’s always the same request that times out, then we can look to see if there’s a bug in the database, but I think the ZW100 is quite common so I suspect it is ok.