Several Z-Wave devices no longer reachable after upgrade from OH3.1 to OH3.2

BG56 · February 21, 2022, 5:37pm

After the upgrade from OH3.1 to OH3.2 several Z-Wave devices are no longer reachable. Does anybody have a similar issue or can help with further analysis or problem solving?

Z-Wave entries in the log file:

2022-02-21 18:07:07.882 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2022-02-21 18:07:07.883 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
2022-02-21 18:07:14.794 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:serial_zstick:88190bb8’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2022-02-21 18:07:14.796 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node23’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.803 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node22’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.810 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node25’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2022-02-21 18:07:14.812 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node21’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.813 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node24’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.850 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node25’ changed from ONLINE to ONLINE: Node initialising: PING
2022-02-21 18:07:14.886 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node20’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.887 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node29’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.889 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node26’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.891 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node27’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.893 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node28’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.919 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node4’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.921 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node5’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.923 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node3’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.926 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node8’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.940 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node9’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2022-02-21 18:07:14.942 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node34’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.944 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node33’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.951 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node36’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.969 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node35’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.979 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node30’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.981 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node32’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.983 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node31’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.989 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node38’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.991 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node37’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.993 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node39’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.997 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node45’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:14.999 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node49’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:15.001 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node12’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:15.003 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node11’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:15.007 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node14’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2022-02-21 18:07:15.009 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node13’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2022-02-21 18:07:15.012 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node10’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:15.016 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node19’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2022-02-21 18:07:15.018 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node16’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:15.022 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node15’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:15.024 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node18’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:15.027 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node17’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2022-02-21 18:07:15.029 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node41’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:15.032 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node40’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:15.034 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node42’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:15.036 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node44’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:15.038 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node50’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:15.040 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node51’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:15.041 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node52’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2022-02-21 18:07:15.107 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node17’ changed from ONLINE to ONLINE: Node initialising: REQUEST_NIF
2022-02-21 18:07:15.196 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node13’ changed from ONLINE to ONLINE: Node initialising: REQUEST_NIF
2022-02-21 18:07:17.149 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node17’ changed from ONLINE: Node initialising: REQUEST_NIF to ONLINE
2022-02-21 18:07:17.390 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node19’ changed from ONLINE to ONLINE: Node initialising: REQUEST_NIF
2022-02-21 18:07:19.379 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node13’ changed from ONLINE: Node initialising: REQUEST_NIF to ONLINE
2022-02-21 18:07:19.762 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node14’ changed from ONLINE to ONLINE: Node initialising: REQUEST_NIF
2022-02-21 18:07:21.295 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node19’ changed from ONLINE: Node initialising: REQUEST_NIF to ONLINE
2022-02-21 18:07:21.714 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node9’ changed from ONLINE to ONLINE: Node initialising: REQUEST_NIF
2022-02-21 18:07:28.670 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node14’ changed from ONLINE: Node initialising: REQUEST_NIF to ONLINE
2022-02-21 18:07:28.963 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node25’ changed from ONLINE: Node initialising: PING to ONLINE: Node initialising: REQUEST_NIF
2022-02-21 18:07:30.007 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node9’ changed from ONLINE: Node initialising: REQUEST_NIF to ONLINE
2022-02-21 18:07:30.619 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing ‘zwave:device:88190bb8:node25’ changed from ONLINE: Node initialising: REQUEST_NIF to ONLINE

Z-Wave network after the upgrade:

Z-Wave stick configuration:

UID: zwave:serial_zstick:88190bb8
label: Z-Wave Serial Controller
thingTypeUID: zwave:serial_zstick
configuration:
controller_softreset: false
security_networkkey: …
security_inclusionmode: 0
controller_suc: false
controller_sisnode: 1
controller_sync: false
controller_master: true
inclusion_mode: 2
port: /dev/ttyACM0
controller_wakeupperiod: 3600
controller_exclude: false
heal_time: 2
controller_inclusiontimeout: 60
controller_hardreset: false
location: HWR

It would be great if anybody could help to solve the issue

robmac · February 21, 2022, 6:54pm

It looks like the devices are no longer in the controller node table.

A hard reset would change the home id and remove all nodes so this has not happened.

Other than that openHAB only ever removes nodes from the controller when the controller is set to exclusion and each node requests to be excluded which is initiated on the slave device.

I assume you have restarted just in case this was some odd controller start-up error.

There are other ways nodes can be removed for example by request of the slave if it malfunctions so that is possible but it is surprising so many would do this so it looks more likely your controller encountered a failure.

Have you got a backup of your controller that you can go back to on this controller or possibly a new one if this one is faulty? If the nodes are not on the controller that would be the only way to recover and only then if the slave devices are still included in their memory.

BG56 · February 22, 2022, 7:42am

Thank you @robmac for your hint. I didn’t expect a failure in the Aeotec Z-Wave stick while doing a OH upgrade. Anyway I did a backup of the stick some month ago and did a restore to the stick. Now most of the devices in the Z-Wave network can be reached again. To include the missing 3 devices is not a big deal.

I still can’t understand how this data loss on the stick can happen during a OH upgrade. What seems to be new to me after the OH upgrade is that the Z-Wave stick is quickly blinking yellow during the startup of the Raspberry PI 4 with OH3.2. I can’t remember that I have seen this behavior of the stick in the past. Is it possible that the quick yellow blinking of the stick indicates an undefined status of the stick during the startup of the PI 4 with the new PI-OS (Bullseye) … which may cause data loss on the stick during startup? Thank you again helping to solve my problem!

robmac · February 22, 2022, 8:42am

The behaviour of the serial port may have been tweaked in the OS but it could also just be that the stick is failing.

If the stick had gone into exclusion mode then the slaves would also have forgotten that they were part of the network. It seams more probable that the issue was within the controller but the flashing light does happen when you successfully exclude a device so worth watching and keeping a good backup .

There are several versions of that stick is it the latest PI 4 compatible version?

BG56 · February 22, 2022, 9:24am

I use the Aeotec AEOEZW090-C Z-Wave Stick since Jan 2018 without any problems. Since I switched from PI3 to PI4 I had to use a USB-hub between the stick and the PI4 USB port. Is this what you mean with not PI4 compatible version?
The stick has a build in batterie to be able to remove the stick from the PI and go with the stick (without the PI) to the device which you want to include. The batterie may be old but the data is stored in the EEPROM and does not need the batterie to hold the data.
In the future I’ll do a backup of the stick whenever I have added (included) a Z-Wave device

cidi · February 22, 2022, 11:51am

Hello.
How do you backup your Z-Wave-Stick-Data?
Thanks in Advance.

BG56 · February 22, 2022, 1:09pm

system · April 5, 2022, 5:09am

This topic was automatically closed 41 days after the last reply. New replies are no longer allowed.