[SOLVED] Very frustrated with ZWave binding and OpenHAB UI

[flpaoli (FLP)]

Thank you rlkoshak for the pointers.

@rlkoshak

@flpaoli

Well, a few days later both Thermostats stopped updating. Nothing changed, just it all stopped working.

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

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

@rlkoshak

@flpaoli

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.

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

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.

@rlkoshak

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.

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?