ZWave controller / nodes stuck at INITIALIZING

Setup:

  • Raspberry Pi 3 Model B Rev 1.2
  • OS: Raspbian 8 (jessie)
  • Kernel: Linux THANATOS 4.9.35-v7+ #1014 SMP Fri Jun 30 14:47:43 BST 2017 armv7l GNU/Linux
  • java version “1.8.0_161” Java™ SE Runtime Environment (build 1.8.0_161-b12)
  • Openhab: openHAB 2.5.4 Release Build
  • ZWave Binding: 2.5.4
  • ZWave Controller: Aeon Labs Aeotec ZStick

Problem:
After upgrading from 2.3 to 2.5 and then rebooting, ZWave bindings don’t work as expected. My ZWave nodes all show “UNINITIALIZED - BRIDGE_UNINITIALIZED” and the controller shows “INITIALIZING”.

At best, I can get the controller to “ONLINE” and all nodes as “INITIALIZING” by changing the serial device to something and then back.

Attempted Solutions:
I went to PaperUI and Edited the controller Thing to verify the serial output, which does show up as /dev/ttyACM0. If I change this to /dev/ttyAMA0 and back (as recommended elsewhere on these forums to do this to make sure the setting is set correct), then sometimes the Things all go ONLINE, but changing their state in habpanel, paperui, etc. don’t actually trigger any changes (real or logged attempts). Or other times, the controller goes “ONLINE” but all nodes are stuck at “INITIALIZING”. Yet others, the controller goes to “OFFLINE - BRIDGE_OFFLINE” with all the nodes as “INITIALIZING”.

I followed instructions in the “ZWave Binding Updates” post to upgrade the Things for ZWave.

Additional Info:
I have other bindings that are in a broken state, but I believe those are different issues. For example, Nest is broken due to migrating my account to Google (ugh, mistake), Hue is offline because I haven’t yet done the Hue bridge fix, and Chromecasts are all stuck at “INITIALIZING”. Additionally, stopping Openhab as a service takes a while and eventually times out and there are messages on startup that starting handlers takes more than 5000ms.

This was working (ZWave binding and all Things on ZWave) on 2.5 when I first did the upgrade, but when I rebooted the device it broke. I found out this was likely due to the cache reinstalling an old snapshot, and it’s at this point that I cleaned the cache. Specifically, when I rebooted, there were 2 ZWave bindings installed according to the karaf console with list -s | grep zwave – a 2.5 version from PaperUI and a 2.3 version from a .jar snapshot install. Despite removing the 2.3 version with bundle:uninstall <id> and confirming it was gone with list -s | grep zwave, it kept re-appearing after each reboot of Openhab as a service or reboot of the Pi. This is even with the 2.5 PaperUI version removed. Clearing the cache with openhab-cli --clean-cache after stopping OpenHAB with sudo systemctl stop openhab2.service resolved this. Then I added the binding back with PaperUI, confirmed there was only one, and am hitting this issue.

Here are the serial interfaces showing they should be configured correctly for my Aeon Labs Aeotec ZStick:

$ ls -alph /dev | grep ttyA
lrwxrwxrwx  1 root root           7 Apr 28 19:30 serial1 -> ttyAMA0
crw-rw----  1 root dialout 166,   0 Apr 28 19:37 ttyACM0
crw-rw----  1 root dialout 204,  64 Apr 28 19:30 ttyAMA0
$ groups openhab
openhab : openhab tty dialout audio bluetooth
$ lsusb
Bus 001 Device 004: ID 0658:0200 Sigma Designs, Inc. 
Bus 001 Device 003: ID 0424:ec00 Standard Microsystems Corp. SMSC9512/9514 Fast Ethernet Adapter
Bus 001 Device 002: ID 0424:9514 Standard Microsystems Corp. 
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

I’ve let the nodes sit at “INITIALIZING” for over 30 minutes, and enabled DEBUG loglevel for the zwave binding. They don’t finish initializing.

Attached is a log from a fresh boot into openhab running (controller at “INITIALIZING” and all nodes “UNINITIALIZED - BRIDGE_UNINITIALIZED” the whole time), then after 5 minutes changing the serial port from /dev/ttyACM0 to /dev/ttyAMA0 and back at 7:58:30 PM, then 5 more minutes waiting (controller and nodes all still the same state as before).

/var/log/openhab2/events.log: https://drive.google.com/open?id=1cxOA_3VCZJV-FDIFUU2jTU6VTcVfQyDi
/var/log/openhab2/openhab.log: (DEBUG mode): https://drive.google.com/open?id=1JgDtRruHsByS2GIQ-8qlLjWp1hb5yZx2

You likely have some invalid addons defined causing them to all reload every minute trying to load the invalid ones. Restdocs is a common culprit since its location moved in 2.5.
Are there any errors in the logs about being unable to load an addon?

Thanks for the response and suggestion! I did have to deal with restdocs earlier (before this issue) – I removed it manually, then re-added with PaperUI. I believe that should be set now.

As far as I can tell from the logs, there are no errors loading addons. There are a few exceptions coming from org.eclipse.jetty.io.EofException: null on channel endpoint flushing, but I don’t think those are related. There are also a couple exceptions on connecting to Openhab Cloud, but that seems to fail a couple times and then succeed. There’s also the seemingly known " switch dimmer" key error on the Thing database, but since I’m not using that device it shouldn’t be a problem.

There does seem to be a “Missing dependency” in karaf, but that’s only logged at INFO level, which is interesting.

Many people look at the addons.config file buried in the userdata tree for information. Stop OpenHAB before modifying though.

Here is my /var/lib/openhab2/config/org/openhab/addons.config, are you suggesting removing everything from this file except zwave while openhab is shut down?

:org.apache.felix.configadmin.revision:=L"11"
binding="network,chromecast,hue,ntp,plex1,amazondashbutton,zwave"
felix.fileinstall.filename="file:/var/lib/openhab2/etc/org.openhab.addons.cfg"
misc="ruleengine,gcal1,openhabcloud"
package="expert"
persistence=""
remote="true"
service.pid="org.openhab.addons"
transformation="map,regex,xslt,exec,javascript,scale,xpath,jsonpath"
ui="classic,basic,paper,habpanel,habmin,restdocs"
voice="marytts"

You say you did an uninstall of the 2.3 snapshot in karaf console but it reappeared after start/stop or a reboot. Did you remove the 2.3 snapshot file from the addon folder?

1 Like

The addons.config looks good to me. You should always remove manually installed bindings before updating. It is very possible the manually installed version is not compatible with 2.5.

@Stefan:

Yeah. I did an uninstall through the karaf console and confirmed the .jar file was removed from the addon folder. But when restarting the openhab2 service, the 2.3 snapshot reappeared. This was reproducible, and is what led to me uninstalling the snapshot through karaf, stopping the openhab2 service, and cleaning the cache. The cache resolved the issue of 2.3 coming back.

@Bruce_Osborne

Yup, I did make the mistake of forgetting that I had manually installed addons before upgrading to 2.5. However, I caught this when following ZWave binding updates to update the ZWave binding, which led to the cache / uninstall issue that I think is resolved. Do you think there may be leftover issues due to that? I’ve verified the 2.3 snapshot is not present now with console bundle:list and by looking in the addon folder.

:slight_smile: Your very detailed description did not mention removal of the snapshot file, therefore I asked about it.

In that case I would uninstall the ZWave binding entirely, making sure nothing is left (check in karaf console, start/stop several times, maybe clear the cache first again) and then follow the upgrade description again after reinstalling the ZWave bundle

1 Like

Apologies about that then! Thank you for checking.

Gotcha, I’ll try that.

The only particular reason I haven’t done a full wipe and reinstall is concern that I’d have to manually re-pair each ZWave device to the controller/openhab (some are quite hard to access). Is this a valid concern, or is the pairing done at the controller level and therefore not affected by openhab configs? Should I just purge and restart?

I have the ZWave devices stored in .items and .things files.

Also, I went to do your steps and found all nodes and the controller “ONLINE” but I was unable to actually change the devices’ states. Toggling them from habpanel/paperui doesn’t actually change lights on/off, for example.

I then uninstalled the ZWave binding through PaperUI along with most other bindings to try to isolate the problem. While uninstalling, I noticed this took a while and the log showed lines of “Disposing handler for thing ‘zwave:device:d2f51293:node11’ took longer than 500ms”. That seemed unusual.

I’m working through the uninstall/reboot/cache process right now, but this will take a bit.

Z-Wave network is stored on the controller. The devices need to bne woken up to be fully discovered by openHAB.
If you set the thing id of the controller the same as the old one, device thing ids will match old item links for channels.

Ok, I did a full purge of openhab2 according to https://www.openhab.org/docs/installation/linux.html. I reinstalled openhab2 and added only the zwave binding (through PaperUI), I added the controller and nodes (through PaperUI) as Things, added the old .items file to /etc/openhab2/items, and still cannot get any switches to change state (with PaperUI “Control”, which lists no items, and with HabPanel, which lets me select elements to toggle but doesn’t do anything when clicked). I’ve restarted openhab several times.

The only error showing up in the log is the IllegalArgumentException: ID segment ' switch_dimmer'... one.

What else can I look at or try? This seems to be the same issue before the wipe and reinstall.

Ah, I think I’ve got it. The Things from PaperUI were not connected to the Items from the filesystem /etc/openhab2/items/zwave.items file.

I fixed this for one by going to PaperUI, opening a Thing, and assigning a Channel to an Item.

I suppose I thought this was handled explicitly by the .items file specifying a Channel in it.

Here’s an example Item definition:

Switch UP_OFFICE_Switch   "Office Light Switch"           <switch> (gLights_Upstairs)                     ["Lighting"] { channel="zwave:device:d2f52b46:node17:switch_binary" }

I compared Thing’s Channel name from PaperUI to the channel field of the Item in the .items file, and they actually don’t match now. The Item has channel as listed above, but the Thing has channel zwave:device:730141c1:node17:switch_binary.

Shouldn’t that Channel from the Thing be device/network specific? Why would that have changed since I added the Items / had this last working?

Also, is this still best practice – add Things in PaperUI and define Items in files for ZWave devices, or should I be doing something different?

Thank you, all!

The ThingID of the controller is randomly generated when you delete and recreate the Thing, but you have the option to specify it and use the one previously used so that the Links created in the .items files are still valid. Otherwise, you need to search/replace to update the new one.

Yes

1 Like

Actually the recommended practice for zwave is to use HABmin but the Paper UI works too.