[SOLVED] Very frustrated with ZWave binding and OpenHAB UI

I have to say, after a few weeks of experience, that I’m quite frustrated with ZWave binding. I’m not sure if the issues I’m experiencing are because I started to used OpenHAB with v 3.0, which I guess is still not stable enough, but it is quite frustrating.

In another thread, Trane XR524 ZWave not updating / OH3 - #7 by flpaoli I detailed my attempts to get 2 Thermostats to report temperature regularly. I concluded it was a problem of the Thermostat operating in Fahrenheit. I conclude that was not true (the decimal precision I believe was, but not the lack of updates).

Well, a few days later both Thermostats stopped updating. Nothing changed, just it all stopped working. The Thermostats could receive commands, but OpenHAB didn’t register temperature sensor updates.

Then I hard reset the controller, removed the Things, re-added the nodes through using the controller on a PC, added the Things in again, this time with everything operating in Celsius including OpenHAB, and, no game. The temperatures don’t update in OpenHAB. So this is a problem in OpenHAB somehow.

Then I go to the Thing UI, update Device Configuration, Polling Period, set it to 3600, Save, exit the Thing and open the Thing again, what do I see? Poling Period is 86400. No update. Every time I try to Save the Thermostat there are 3 parameter which it says are invalid, I fix them, Save, and then next time I enter in they’re at the invalid value. So the UI doesn’t seem to be updating anything.

I want to see all of this work, permanently. I would appreciate suggestions. Should I restart from the sdcard image, re-install from scratch and do everything through config files?

Thanks

My understanding is the Zwave binding hasn’t changed much between OH 2.5.11 and OH 3.0 so I doubt that is the problem.

If I understand what you are saying correctly then I agree. I suspect that the device has a set precision such that the temp reading needs to change by a certain amount before it reports and that threshold is larger for F than for C, causing it to report less frequently. Often (but not always) there will be a parameter one can set on the device (it’ll be a property on the Thing) to control stuff like that.

Are these mains powered (or powered from the HVAC system) or battery powered?

You’ll need to gather some trace level logs from the binding but I don’t think your conclusion is correct. As I understand it, most of that communication is handled by the controller itself, not the binding. If the device is reporting there will at least be some evidence of that coming from the devices in the logs. If there is no such evidence the logs it means the root source of the problem is the thermostat itself. If there is evidence in the logs then those logs need to be analyzed by someone more knowledgable than me to figure out what is wrong.

If the device is no longer communicating with the controller, changing any configurations won’t take and will end up reverting. Again, debug or trace logs will be required.

It would be informative to know which parameters they are and what you are doing to fix them.

Put the binging into debug or trace level logging. Capture the startup as well as some info from trying to update the properties on the devices. It might be worth while deleting the Things and rediscovering them. Did you do that when you reset the controller and readded the devices?

If after rediscovery the Thing for the thermostats indicate they are unknown devices that would be an indication that the problem is the thermostats themselves are not communicating.

Thank you rlkoshak for the pointers.

Yes, all my zwave devices are powered from mains, not on battery.

They are
21: Cooling Delta Stage 2 OFF
21
Please select a value that is no more than 8.

24: H/C Delta
24
Please select a value that is no more than 15.

76: Fan OFF Time
0
Please select a value that is no less than 10.

Yes, I had the log files in DEBUG for zwave binding when I plugged the controller back into the Pi’s USB after adding the devices to it, and then started openhab.

Looking at the raw log file I see openhab understands they are new, and starts the process of discovering them:

2021-02-13 16:44:37.528 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 1: Init node thread start
2021-02-13 16:44:37.529 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 2: Init node thread start
2021-02-13 16:44:37.530 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 3: Init node thread start
2021-02-13 16:44:37.534 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 4: Init node thread start
(...)
2021-02-13 16:44:37.933 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 4: Serializing from file /var/lib/openhab/zwave/network_c6ea4f8d__node_4.xml
2021-02-13 16:44:37.933 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 1: Serializing from file /var/lib/openhab/zwave/network_c6ea4f8d__node_1.xml
2021-02-13 16:44:37.933 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 3: Serializing from file /var/lib/openhab/zwave/network_c6ea4f8d__node_3.xml
2021-02-13 16:44:37.934 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 2: Serializing from file /var/lib/openhab/zwave/network_c6ea4f8d__node_2.xml
2021-02-13 16:44:37.937 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 2: Error serializing from file: file does not exist.
2021-02-13 16:44:37.937 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 4: Error serializing from file: file does not exist.
2021-02-13 16:44:37.938 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 3: Error serializing from file: file does not exist.
2021-02-13 16:44:37.972 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 4: Starting initialisation from EMPTYNODE
2021-02-13 16:44:37.972 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Starting initialisation from EMPTYNODE
2021-02-13 16:44:37.973 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Starting initialisation from EMPTYNODE
(...)
2021-02-13 16:44:37.981 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 4: Node advancer - advancing to IDENTIFY_NODE
2021-02-13 16:44:37.982 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - advancing to IDENTIFY_NODE
2021-02-13 16:44:37.983 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 4: Node advancer: Initialisation starting
(...)
2021-02-13 16:44:37.990 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer - advancing to IDENTIFY_NODE
2021-02-13 16:44:37.996 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: Initialisation starting
2021-02-13 16:44:37.986 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: Initialisation starting

Nodes 3 and 4 are the XR524 zwave Thermostats.

Looking at the logs at Z-Wave Log Viewer and filtering one zwave Thermostat at a time, it all looks very normal.

I see it moving between Stages, from IDENTIFY_NODE to PING to a bunch of others until DYNAMIC_END and then DONE. That takes about 4 mins in total.

Right now one of my thermostats says it is 22 C, but in Openhab it is still at 24 C, which was the temperature back in Feb 14th. It is like no updates are being retrieved, hence my intention to force some polling every 10 minutes. Look:

openhabian@openHABianDevice:/tmp $ date
Sat 20 Feb 2021 09:15:24 AM EST
openhabian@openHABianDevice:/tmp $ grep -i "MULTILEVEL, value=" /var/log/openhab/openhab.log | grep -i "node 3"
2021-02-14 23:54:04.324 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=24

It does seem the zwave binding is trying to poll, but there is no info on what (isn’t) happening after the poll:

openhabian@openHABianDevice:/tmp $ grep -i "Polling" /var/log/openhab/openhab.log | grep -i "node 3" | tail -2
2021-02-20 08:35:02.389 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling...
2021-02-20 09:05:02.389 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling...
openhabian@openHABianDevice:/tmp $ cat /var/log/openhab/openhab.log | grep -i "node 3" | tail -2
2021-02-20 08:35:02.389 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling...
2021-02-20 09:05:02.389 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling...

Any suggestions based on the topics above?

I used Zensys tool on a Windows PC try to poll, and it seems to have worked. I get packets sent, packets received, to both thermostats. Even when I set the polling to extremely quick polling, like every 60s or 45s. So it does seem all OK with my hardware and for some reason my OH3 isn’t taking poll responses in.

I don’t understand what the raw data in the packets send from Thermostat into ZWave hub mean, so I can’t check from the raw data if the report from the Thermostat is accurate.

Does anyone have a spec, or can point me to a page with a spec, of what the raw data in a polling response from a Trane XR524 mean, so I can check? Or point me to where in the source code does this translation from raw data to items happens?

Thanks

In general, zwave isn’t about polling and you might instead be looking at the autonomous reporting arrangements of the devices.

That’s a UI bug, see here, with apparent workaround

It’s possible this affects other parameters which you had trouble with.

Well, there’s a chain of stuff to look at; Item details, link details, channel details, Thing details. A mess-up or change in any of those is enough to stop the apparent show.

OK. lets start from the beginning…
Did I miss it, what is the zwave stick or controller?
What is the operating system and platform?
This is a new set-up? and OH version please

1 Like

Hi Andrew,

Setup is relatively new, installed in early Jan. I used to get updates from these Thermostats, then didn’t. The thread I linked to in my original post shows Grafana charts where the Thermostats were reporting.

OS version:

##   Release = Raspbian GNU/Linux 10 (buster)
##    Kernel = Linux 5.4.83-v7l+

OH version:

3.0.0 - Release Build  

ZWave Stick/controller: Aeotec Z-Stick Gen5+ (Z-Wave USB stick & antenna • Z-Stick Gen5+ • Aeotec)

ZWave binding version (I updated at the start because I was getting no result from the Thermostats, kind of like now): Whoa… this is strange… I was expecting to see 3.1.0 here…

openhab> bundle:list org.openhab.binding.zwave
START LEVEL 100 , List Threshold: 50
 ID │ State  │ Lvl │ Version │ Name
────┼────────┼─────┼─────────┼───────────────────────────────────────────────────────────────────────────────
231 │ Active │  80 │ 3.0.0   │ openHAB Add-ons :: Bundles :: ZWave Binding

I did not update nor rollback to 3.0.0… is there any way where this might have happened automatically?

Thanks

Did you install the zwave binding when you installed 3.0.0? Did you then install a snapshot version by dropping a jar file into the addons folder? Did you uninstall the 3.0 version before adding the jar? Just trying to figure out what you have done, seems like you expected this

to be a newer version… correct?

It is currently recommended to use a snapshot binding on OH3. We fixed a database error after 3.0.1 was released.
The script usually helps.
Zigbee and Z-Wave manual install script - Tutorials & Examples - openHAB Community

2 Likes

Yes, I followed what anonymous.one posted at [SOLVED] Zwave devices not updating item states after upgrade to OH 3 - #8 by anonymous.one and updated to 3.1.0 . I can’t recall now but I think I wasn’t able to do the Karaf thing but searched and found another way to update. I am sure I had the 3.1.0 version because I did execute bundle:list -s | grep zwave and saw 3.1.0 there.

So somehow my OH3 brought back to 3.0.0 … strange.

I will try the script linked by Bruce_Osborne to get it back to 3.1.0 again.

Thanks guys

OK, now I have 3.1.0 again:

openhab> list -s | grep zwave                                                                                                
233 │ Active │  80 │ 3.1.0.202103070338      │ org.openhab.binding.zwave

Let’s see how this behaves now, if I get thermostat updates into OH3. I’m hopeful.

Yep, my OH3 is good now. I’m getting updates from the thermostats now.

So my problem was that ZWave binding went back to 3.0.0 . I don’t have a clue how that happened.

Thank you for the questions which led me to discover 3.1.0 was gone and my OH3 was back to 3.0.0.

2 Likes

Somehow my OpenHAB again returned to ZWave binding 3.0.0 … when I restarted OpenHAB two days ago.

openhab> bundle:list org.openhab.binding.zwave                                                                                                                                                          
START LEVEL 100 , List Threshold: 50
 ID │ State  │ Lvl │ Version            │ Name
────┼────────┼─────┼────────────────────┼──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
208 │ Active │  80 │ 3.1.0.202103070338 │ openHAB Add-ons :: Bundles :: ZWave Binding
219 │ Active │  80 │ 3.0.1              │ openHAB Add-ons :: Bundles :: ZWave Binding
openhab>

Can anyone help me understand why is this happening? I got 3.1.0 installed with the script @Bruce_Osborne posted, and all was fine until this restart.

Yeah, this is getting strange or frustrating again. The manual script doesn’t complete. So I followed the manual steps at openHAB-utils/README.md at master · 5iver/openHAB-utils · GitHub and that resulted in both versions installed.

So I removed them both with bundle:uninstall org.openhab.binding.zwave then ran openhabian-config and updated to main. After that I went to console and listed the bindings.

At first it lists 3.1.0 only, then, magically, about a minute later I run list again and I see both versions again !?!?:

openhab> list -s | grep zwave                                                                                                                                                                                                                 
209 │ Installed │  80 │ 3.1.0.202104210336      │ org.openhab.binding.zwave
openhab> list -s | grep zwave                                                                                                                                                                                                                 
209 │ Installed │  80 │ 3.1.0.202104210336      │ org.openhab.binding.zwave
222 │ Active    │  80 │ 3.0.2                   │ org.openhab.binding.zwave
openhab>  

How do I get rid of this zombie 3.0 version which keeps reappearing? Where does this thing come from?

Anyway, I seemed to have resolved my problem by uninstalling 3.0.2, removing 3.1.0.2021042110336 because it resulted in errors, and then taking the backup of 3.1.0.202103070338 which the zzManualInstaller.sh script created and putting it back into addons.

Copies of my chores below in case someone is facing similar issues with their ZWave in OH3:

openhab> list -s | grep zwave                                                                                                                                                                                                                 
209 │ Installed │  80 │ 3.1.0.202104210336      │ org.openhab.binding.zwave
222 │ Active    │  80 │ 3.0.2                   │ org.openhab.binding.zwave
openhab> bundle:stop 222
openhab> list -s | grep zwave
209 │ Installed │  80 │ 3.1.0.202104210336      │ org.openhab.binding.zwave
222 │ Resolved  │  80 │ 3.0.2                   │ org.openhab.binding.zwave
openhab> bundle:uninstall 222
openhab> list -s | grep zwave                                                                                                                                                                                                                 
209 │ Installed │  80 │ 3.1.0.202104210336      │ org.openhab.binding.zwave
openhab> bundle:start 209
Error executing command: Error executing command on bundles:
	Error starting bundle 209: Could not resolve module: org.openhab.binding.zwave [209]
  Unresolved requirement: Import-Package: org.osgi.framework; version="[1.9.0,2.0.0)"

OK, that recently downloaded version didn’t work, so I tried the snapshot I had before, recovered the file, or swapped 202104210336 for 202103070338:

openhabian@openHABianDevice:/usr/share/openhab/addons $ ll
total 208M
drwxrwxr-x 3 openhab    openhab 4.0K Apr 22 22:14 ./
drwxrwxr-x 4 openhab    openhab 4.0K Apr  4 21:09 ../
drwxr-xr-x 3 openhab    openhab 4.0K Apr 22 21:37 archive/
-rw-r--r-- 1 openhab    openhab 204M Jan 27 15:21 openhab-addons-3.0.1.kar
-rw-rw-r-- 1 openhabian openhab 1.1M Apr 22 22:14 org.apache.servicemix.bundles.xstream-1.4.16_1.jar
-rw-rw-r-- 1 openhabian openhab  67K Apr 20 22:22 org.openhab.binding.wizlighting-3.0.0-SNAPSHOT.jar
-rw-rw-r-- 1 openhabian openhab 3.5M Apr 22 22:10 org.openhab.binding.zwave-3.1.0-20210421.034706-14.jar
-rw-r--r-- 1 openhab    openhab   70 Jan 27 15:42 README
-rwxr-xr-- 1 openhabian openhab  46K Mar 11 22:18 zzManualInstaller.sh*
openhabian@openHABianDevice:/usr/share/openhab/addons $ sudo mv org.openhab.binding.zwave-3.1.0-20210421.034706-14.jar archive/zwave/
[sudo] password for openhabian: 
openhabian@openHABianDevice:/usr/share/openhab/addons $ ll
total 205M
drwxrwxr-x 3 openhab    openhab 4.0K Apr 22 22:37 ./
drwxrwxr-x 4 openhab    openhab 4.0K Apr 22 22:22 ../
drwxr-xr-x 3 openhab    openhab 4.0K Apr 22 21:37 archive/
-rw-r--r-- 1 openhab    openhab 204M Apr 21 15:48 openhab-addons-3.0.2.kar
-rw-rw-r-- 1 openhabian openhab 1.1M Apr 22 22:14 org.apache.servicemix.bundles.xstream-1.4.16_1.jar
-rw-rw-r-- 1 openhabian openhab  67K Apr 20 22:22 org.openhab.binding.wizlighting-3.0.0-SNAPSHOT.jar
-rw-r--r-- 1 openhab    openhab   70 Apr 21 15:49 README
-rwxr-xr-- 1 openhabian openhab  46K Mar 11 22:18 zzManualInstaller.sh*
openhabian@openHABianDevice:/usr/share/openhab/addons $ cd archive/zwave/
openhabian@openHABianDevice:/usr/share/openhab/addons/archive/zwave $ ll
total 6.9M
drwxr-xr-x 2 openhab    openhab 4.0K Apr 22 22:37 ./
drwxr-xr-x 3 openhab    openhab 4.0K Apr 22 21:37 ../
-rw-rw-r-- 1 openhab    openhab 3.4M Mar 11 22:29 org.openhab.binding.zwave-3.1.0-20210307.034709-24.20210422213733.old
-rw-rw-r-- 1 openhabian openhab 3.5M Apr 22 22:10 org.openhab.binding.zwave-3.1.0-20210421.034706-14.jar
openhabian@openHABianDevice:/usr/share/openhab/addons/archive/zwave $ sudo chown openhab:openhab org.openhab.binding.zwave-3.1.0-20210421.034706-14.jar 
openhabian@openHABianDevice:/usr/share/openhab/addons/archive/zwave $ sudo -u openhab cp org.openhab.binding.zwave-3.1.0-20210307.034709-24.20210422213733.old ../../org.openhab.binding.zwave-3.1.0-20210307.034709-24.jar 
openhabian@openHABianDevice:/usr/share/openhab/addons/archive/zwave $ cd ..
openhabian@openHABianDevice:/usr/share/openhab/addons/archive $ cd ..
openhabian@openHABianDevice:/usr/share/openhab/addons $ ll
total 208M
drwxrwxr-x 3 openhab    openhab 4.0K Apr 22 22:39 ./
drwxrwxr-x 4 openhab    openhab 4.0K Apr 22 22:22 ../
drwxr-xr-x 3 openhab    openhab 4.0K Apr 22 21:37 archive/
-rw-r--r-- 1 openhab    openhab 204M Apr 21 15:48 openhab-addons-3.0.2.kar
-rw-rw-r-- 1 openhabian openhab 1.1M Apr 22 22:14 org.apache.servicemix.bundles.xstream-1.4.16_1.jar
-rw-rw-r-- 1 openhabian openhab  67K Apr 20 22:22 org.openhab.binding.wizlighting-3.0.0-SNAPSHOT.jar
-rw-r--r-- 1 openhab    openhab 3.4M Apr 22 22:39 org.openhab.binding.zwave-3.1.0-20210307.034709-24.jar
-rw-r--r-- 1 openhab    openhab   70 Apr 21 15:49 README
-rwxr-xr-- 1 openhabian openhab  46K Mar 11 22:18 zzManualInstaller.sh*
openhabian@openHABianDevice:/usr/share/openhab/addons $ 

Then in the console it is automagically there and Active:

openhab> list -s | grep zwave                                                                                         235 │ Active │  80 │ 3.1.0.202103070338      │ org.openhab.binding.zwave                                              openhab> list -s | grep zwave                                                                                         
235 │ Active │  80 │ 3.1.0.202103070338      │ org.openhab.binding.zwave

But my question remains, because I know that zombie 3.0.x version is hiding somewhere ready to pounce for my brain… where is it hiding and how do I shoot it in the head for good please?

Apparently the script did not remove the 3.0.1 binding. I see you know how to het into the Karaf console. Once in there try this

bundle:stop 219
bundle:uninstall 219

That should stop & remove the old binding. The script was supposed to do that.

This looks like the work of addons.cfg

That added a jar to the addons folder and the old binding was not uninstalled first. There was a script that worked quite well for a while doing that.

Sure. But if there should happen to be bindings= entry in addons.cfg text file then it will fetch and load the “standard” binding as well as any jar it finds. I suppose it’s not worth looking, though.

I assumed uninstalling did more than remove the file entry.

The file is a list for openHAB’s use of “things to install”. I don’t think uninstalling a package from karaf affects the file at contents at all.