Trouble with battery powered Z-Wave things

Tags: #<Tag:0x00007f6173d636a8>

My setup: RPi 4 4GB, openhabian, openHAB 2.5.4-1, zwave.me usb dongle

I am having trouble with all of my battery operated Z-Wave devices: my Heimann HS1SA-Z Smoke Detectors and Neo Coolcam NAS-DS01Z Door/Window Sensor. I suspect the issue is the same for all of them, so I will focus on the door sensor here. What I did, in baby steps:

  • Take the sensor to the location where it will finally be used
  • Set openhab to inclusion mode via Paper UI > Inbox > Z-Wave Binding > Search
  • Remove the little plastic thingy on the battery so that contact is made, press the button three times
  • The Sensor shows up in the inbox and I can add it as thing, link the two channels I need (sensor_door and battery-level) to the defined items.

Now I think I am done, but there is nothing coming from the sensor. The little LED blinks when opening or closing the door, but it seems openhab does not get a status update. Nothing shows up in the log either. Now I go looking in the forum for a solution.

  • The first thread I find that fits to my problem suggests the battery those sensors come with are faulty and need to be replaced. I order a new one, wait for it to arrive, install it: no change.
  • The next thread says I need to put “Controller” in the “Association Group 1: Lifeline”. I try that, with Paper UI and HABmin, with waking the sensor up directly after or directly before I try to set the value. Always with the same result: it does not stick, the field is always empty when I open it again.
  • Then I think it is maybe because the sensor is not in range of the controller, but has to communicate through a mains powered node. So instead of the controller I enter the nearest node in the association group. Same result as above.
  • Then I find a thread where it is stated that maybe the sensor is not initialized fully. So I exclude it, include it again. Same thing as before. Maybe I messed up that last step a bit, as I was not 100% sure what I had to do, so I ran back and forth between my PC and the sensor and clicked wildly on its button, unlinked the items, tried again.Here is what is in the log for that time (Door sensor is node22. Node 9, 15-21 are the smoke sensor I am also having trouble with.):
2020-05-29 11:49:40.275 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:98f7ce14:node22' has been updated.

2020-05-29 11:49:40.277 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]]

2020-05-29 12:01:53.005 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:98f7ce14:node22' has been updated.

2020-05-29 12:01:53.007 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]]

==> /var/log/openhab2/openhab.log <==

2020-05-29 12:04:23.382 [ERROR] [message.RemoveFailedNodeMessageClass] - NODE 22: Remove failed node failed as node not found

==> /var/log/openhab2/events.log <==

2020-05-29 12:04:23.387 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:98f7ce14:node22' has been updated.

2020-05-29 12:04:23.390 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]]

==> /var/log/openhab2/openhab.log <==

2020-05-29 12:05:24.110 [ERROR] [message.RemoveFailedNodeMessageClass] - NODE 22: Remove failed node failed as node not found

==> /var/log/openhab2/events.log <==

2020-05-29 12:05:24.089 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:98f7ce14:node22' has been updated.

2020-05-29 12:05:24.094 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]]

2020-05-29 12:05:43.621 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:98f7ce14:node22' has been updated.

2020-05-29 12:05:43.626 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]]

==> /var/log/openhab2/openhab.log <==

2020-05-29 12:06:41.181 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'our_home.items'

==> /var/log/openhab2/events.log <==

2020-05-29 12:06:41.236 [temChannelLinkRemovedEvent] - Link 'GF_LivingDining_Door => zwave:device:98f7ce14:node22:sensor_door' has been removed.

2020-05-29 12:06:41.238 [temChannelLinkRemovedEvent] - Link 'GF_LivingDining_Door_Battery => zwave:device:98f7ce14:node22:battery-level' has been removed.

==> /var/log/openhab2/openhab.log <==

2020-05-29 12:08:13.052 [ERROR] [message.RemoveFailedNodeMessageClass] - NODE 22: Remove failed node failed as node not found

==> /var/log/openhab2/events.log <==

2020-05-29 12:08:13.058 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:98f7ce14:node22' has been updated.

2020-05-29 12:08:13.060 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]]

2020-05-29 12:09:06.320 [hingStatusInfoChangedEvent] - 'zwave:device:98f7ce14:node22' changed from ONLINE to REMOVING

2020-05-29 12:09:06.326 [hingStatusInfoChangedEvent] - 'zwave:device:98f7ce14:node22' changed from REMOVING to REMOVED

2020-05-29 12:09:06.341 [hingStatusInfoChangedEvent] - 'zwave:device:98f7ce14:node22' changed from REMOVED to UNINITIALIZED

2020-05-29 12:09:06.478 [hingStatusInfoChangedEvent] - 'zwave:device:98f7ce14:node22' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

==> /var/log/openhab2/openhab.log <==

2020-05-29 12:09:20.781 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 16: Device discovery could not resolve to a thingType! Manufacturer data not known.

2020-05-29 12:09:20.807 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 17: Device discovery could not resolve to a thingType! Manufacturer data not known.

2020-05-29 12:09:20.817 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 18: Device discovery could not resolve to a thingType! Manufacturer data not known.

2020-05-29 12:09:20.835 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 19: Device discovery could not resolve to a thingType! Manufacturer data not known.

2020-05-29 12:09:20.842 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 20: Device discovery could not resolve to a thingType! Manufacturer data not known.

2020-05-29 12:09:20.852 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 21: Device discovery could not resolve to a thingType! Manufacturer data not known.

2020-05-29 12:09:20.874 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:98f7ce14:node22' to inbox.

2020-05-29 12:09:20.885 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 9: Device discovery could not resolve to a thingType! Manufacturer data not known.

2020-05-29 12:09:20.904 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 15: Device discovery could not resolve to a thingType! Manufacturer data not known.

==> /var/log/openhab2/events.log <==

2020-05-29 12:09:20.870 [home.event.InboxAddedEvent] - Discovery Result with UID 'zwave:device:98f7ce14:node22' has been added.

2020-05-29 12:09:50.782 [me.event.InboxRemovedEvent] - Discovery Result with UID 'zwave:device:98f7ce14:node22' has been removed.

2020-05-29 12:09:50.804 [hingStatusInfoChangedEvent] - 'zwave:device:98f7ce14:node22' changed from UNINITIALIZED to INITIALIZING

2020-05-29 12:09:50.824 [hingStatusInfoChangedEvent] - 'zwave:device:98f7ce14:node22' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-05-29 12:09:50.829 [hingStatusInfoChangedEvent] - 'zwave:device:98f7ce14:node22' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2020-05-29 12:09:50.837 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:98f7ce14:node22' has been updated.

2020-05-29 12:09:50.839 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:98f7ce14:node22' has been updated.

2020-05-29 12:09:50.842 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:98f7ce14:node22' has been updated.

2020-05-29 12:09:50.870 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:98f7ce14:node22' has been updated.

2020-05-29 12:09:50.872 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]]

2020-05-29 12:10:47.123 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:98f7ce14:node22' has been updated.

2020-05-29 12:10:47.124 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]]

2020-05-29 12:11:07.607 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:98f7ce14:node22' has been updated.

2020-05-29 12:11:07.616 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]]

At this point I stopped, but did not get any clever ideas what more to do in the last 3 hours. Can anyone help me?

Provided your controller works and is online (I assume that is the case as the inclusion and exclusions seem to work):
The thing with battery operated devices is, you need to either give them time to become fully integrated or you need to wake them up manually a couple of times so that all the information exchange between the controller and the devices can be finished. As for “give them time”, we are talking not only minutes or a few hours, it can take a lot longer, depending on the wakeup period the device comes with initially. It may even take a day or two.
Hence my advise is to let the system settle its communication for a while after your devices were included into the network.

Actually you need to wake them up MANY times, especially for initial discovery. In my experience waiting for initial discovery usually does not work because the OH thread gets orphaned from the binding.

Is there any way I can see if and when the device is fully discovered?

I usually use HABmin.
It tends to show a status, especially of the binding is waiting for the NIF (Node Informaiton Frame) from the device.

Could you tell me where in HABmin? I can’t find anything…

Here is an example I have now.

image

Ok, thank you. That looks like this on my end:
image
So that does not tell me anything.

But it seems that I am not even able to exclude the sensor successfully. I go in exclusion mode (Paper UI or HABmin, does not matter), press the button on the sensor three times. LED flashes two or three times. Log looks like this:

2020-05-29 19:04:00.055 [ERROR] [message.RemoveFailedNodeMessageClass] - NODE 22: Remove failed node failed as node not found

==> /var/log/openhab2/events.log <==

2020-05-29 19:04:00.058 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:98f7ce14:node22' has been updated.

2020-05-29 19:04:00.087 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]]

2020-05-29 19:04:41.974 [hingStatusInfoChangedEvent] - 'zwave:device:98f7ce14:node22' changed from ONLINE to REMOVING

2020-05-29 19:04:41.977 [hingStatusInfoChangedEvent] - 'zwave:device:98f7ce14:node22' changed from REMOVING to REMOVED

2020-05-29 19:04:41.988 [hingStatusInfoChangedEvent] - 'zwave:device:98f7ce14:node22' changed from REMOVED to UNINITIALIZED

2020-05-29 19:04:42.081 [hingStatusInfoChangedEvent] - 'zwave:device:98f7ce14:node22' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

So the last reported status is “UNINITIALIZED (HANDLER_MISSING_ERROR)”
If I delete the thing and then go back to the Inbox in Paper UI the bloody thing is again “discovered”.

Not even a factory reset (pressing the button on the sensor for 15 seconds, according to the paper manual that came in the box) does anything.

It seems that there is really no communication between sensor and openhab, in any way I can tell.
It is glued to the doorframe already. I think I will take it off and get it in range of the controller and see if that changes anything.

Was this a fresh 2.5.4 install or an upgrade? If an upgrade, from what version?

The upgrade from 2.4 & earlier to 2.5 was not seamless for many people.

That was a complete fresh install, with brand new hardware. Just started this whole thing.

Well, and getting the sensor into the range of the controller did not do anything. (Other than ripping the self adhesive pad to pieces of course. Thankfully they delivered the sensor with a bunch of them. Oh, wait. Mhm.)

I still think that it is a general issue with my installation, since the smoke detectors show a very similar behavior: They are shown as online, but I do not get any status updates. With smoke I can understand, but at least the battery level should work.

image

The mains powered devices work like expected though.

That handler missing error looked strange to me.

While waiting for more help you might want to follow the binding documentation for when things do not go as expected and enable debug logging.

To be clear, what exactly are you doing? I think that you’re not going into exclusion mode - I think you’re trying to remove the device, and this is failing.

This message indicates that you are trying to remove a failed device - not put the controller into exclusion mode.

1 Like

:hot_face: This is embarrassing, but you are right. (The correct way to exclude of course is: go to Configuration > Things > Z-Wave Serial Controller, click edit, show more, and then there is the switch to go into exclusion mode).

I did that, pressed the button on the sensor three times. The LED flashed two times.

It seems that did not work though, as the sensor still shows up in the thing list. But something else happened: now almost all the battery powered devices are in REQUEST_NIF

image

Did you also delete the thing? I know - this seems a bit strange - you just excluded it right, so you’d expect it to go away… Unfortunately the binding used to do this but openHAB designers decides that bindings can’t remove their things and now you will need to do this manually.

If you’ve done this, then does it come back when you do a search?

I’m guessing slightly here, but possibly the binding has restarted which would do this - you can probably just ignore this and it will sort itself out as devices wake.

I removed the thing. I went to the Inbox and and the sensor is discovered without me pressing anything on the sensor, but as unknown device.

image

That result stays the same if I repeat this process but additionally press the button three times.

Can you provide a debug log showing the exclusion process please?

1 Like

Was away for a while, but started on this again late last night. I enabled debug logging and tried to solve it that way. But when you put the controller in exclude mode the log is flooded with messages and, well, it was a bit too much for me. I could not tell that pressing the button on the sensor did anything that showed up in the log. But what I now did is: reset the door sensor to factory setting (by pressing the button 15 seconds). It then gets discovered with a new node number in Paper UI. (The old node number will be a “ghost” in the controller, right?).
I then pressed the button on the sensor wildly and repeatedly and without really knowing what I did. (The documentation that came with the device was not helpful either.) The LED flashed sometimes one time, sometimes two times, but only when it flashed five times it was shown in the log that the device woke up. And you could see in the log that the status of initialization changed. After waking it up many times that way it was eventually fully initialized. I set the Lifeline to “controller”, woke the sensor up again and then the sensor was operational.

image

Am I correct in assuming that the setting for this Lifeline only “takes” (actually is saved and does not disappear when you reload the configuration page) when the device is fully initialized? That would be a way for me to determine if the many smoke detectors I still have trouble with are now initialized or not.

That should be no longer needed. The binding figures it out if not set in the database entry.

Ok, I have continued with my smoke detectors. One of them to be precise. I have woken it up every 10 to 20 seconds or so for the last hour and looked at the many lines flying by in the log in debugging mode. In between it stopped responding, which I solved by hitting the “heal the device” button in Paper UI > Configuration > Things > Edit > Node xy : show more.
Eventually I could see in the log that the battery status for this node was updated for the first time (to 10%, yay). So I assume that the device is now fully initialized? How can I tell?
The display in HABmin is not a reliable source of information. There is definetely only one device already operational, but only about half of the rest is showing the REQUEST_NIF

image

What I found though is that in Paper UI the configuration page now looks different:

As an example another smoke detector that is not yet initialized:

So, now I only have 7 more to go.

There is one question I still have: in between I thought to be clever and wanted to set the wakeup interval to 1 (second) so that it would wake up by itself or rather not go to sleep in the first place. Pressing the button started to get annoying. But that did not seem to work. Can it be that I can only set this parameter after the device is initialized?

And another rather important question came up.
I was toiling away to initialize more of my smoke detectors. When including them I took care to do that at the place that they will finally be located, and they were all discovered ok. But now I have found two (with the possibility of there being more) that seem to not be in the range of the controller, and have to rely on the mesh for communication. When trying to wake them up I can see no action in the log, even though the light is flashing when I press the button, and no matter how often I repeat that. Only when I move physically closer to the controller (presumably so that I am in range to directly communicate with it) things start to move. The big question I have now:

Will smoke detectors (or any battery powered device) that have been initialized somewhere else than they will finally be located still be able to communicate? Or does initialization also determine their place in the mesh, and which node they have to talk to?

I have, as I said, included them at their final location, just as the manual demands. Is that enough?