No battery nodes…
1 Like
Please get a debug log file so you can see what is happening.
In the end, i solved it by starting anew. Thanks for the help!
Hi Allison, same thing here. I just want to be sure, to fix your issue, you restart what the openhab daemon or the machine ?
I just reinstalled openhabian and started from scratch.
hi all,
i have exactly the same behavior…
it comes with upgrade of version 2.4!
the old installation i have used a z-stick z2
secound i have used a fresh installation of habian also with the z-stich z2
in the mean time i installed openhab 2.4 on a fresh debian stretch apt based using the z-stick z2
and than i switch to aeon z-stick gen5 with a fresh debian stretch apt-based
and finalky i installed habian
all installations show the same behavior after a reboot some devices - in my case all battery powered - gone
so i thing ether there are some problems with aeon z-sticks or general issues with usb driven zwave controller or with the changes to version 2.4
in my eyes someone should have a very closer look to thst issue again which is coming up with version 2.4
thanks for helping and excuse my not so correct english 
regads
stef
I have same problems since one of the last updates. It’s a aeotec gen5 stick too.
After restart 45 devices, Ca 18 batterie) it takes two hours initialing ping is gone.
The 18 batterie devices (ca 10 wakeup 5-10 Minutes, Rest 1day to 7 days) are different.
Every time different of those 10 went online within 4 hours, ca. Got stuck in request_nif or went offline. But still working. If I send command to them: all working, but some left in request nif forever.
Those other 8 with longer wakeup interval start working after 2-4 hours, but stuck in request_nif forever.
So no zwave map in habmin anymore, because never all healed. Very strange.
Actually using 2.5.3 because 2.5.4 made big problems here
This sounds perfectly ok. The device will not progress through the stages until it wakes. This has always been the case since the very first version of the binding in (if I remember correctly) OH 1.2 or 1.3.
Again, this is correct - just because the device is in a startup state doesn’t mean it doesn’t work. It will still respond to messages the device sends, but the binding cannot communicate with battery devices until they send a wakeup message.
But they wakeup within every 5 minutes and still request_nif after 10 days
Ok, I’m not sure then. have you checked the logs and it does it show what is happening? I guess maybe the device isn’t responding to the NIF or something, but I’m just guessing as I don’t really have any information to go on - sorry.
I already looked in logs, but didn’t find something special. Sometimes a heal and manually wake up same time works. But only as a part of devices.
I think about mesh problem. Devices stuck are all done far away of controller. But have got always on devices between act as router
Just updated today last version 2.5.5
Will watch and inform. Maybe problems with dead devices ? I had 3 with a node on controller not included anymore. OpenHAB doesn’t support to delete them cause shown as online
I am not sure, but I think my problem is related to this.
I just started from scratch a few months ago (re-importing my things from jsondb) and used to have no issues with zwave in the past.
Platform information:
Hardware: RPi 4 8 GB and 32 GB micro SD + zwave: Aeotec Z-Stick Gen5 (ZW090) - UZB
OS: Raspian which comes with openhabian 1.6 beta
Java Runtime Environment: Zulu 8 (standard openhabian)
openHAB version: 2.5.9 (standard openhabian)
Recently I recognized that my Sensative Strip claims to have 0% Battery, which seems to be wrong (it’s just 4 years old).
This device (among other battery driven devices were stalled in REQUEST_NIF
So I removed / deleted the Strip and included it again.
After that there is some communication (so the battery is not empty yet), but the Battery level is still not reported properly.
events.log:
2020-10-16 11:19:45.366 [hingStatusInfoChangedEvent] - 'zwave:device:12345678-9012-3456-7890-123456789012:node8' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2020-10-16 11:19:45.407 [hingStatusInfoChangedEvent] - 'zwave:device:12345678-9012-3456-7890-123456789012:node8' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2020-10-16 11:19:45.672 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:12345678-9012-3456-7890-123456789012:node8' has been updated.
2020-10-16 11:19:45.673 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:12345678-9012-3456-7890-123456789012:node8' has been updated.
2020-10-16 11:19:45.685 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[ConfigStatusMessage [parameterName=group_1, type=PENDING, messageKey=null, arguments=null, message=null, statusCode=null]]]
2020-10-16 11:19:45.696 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[ConfigStatusMessage [parameterName=group_1, type=PENDING, messageKey=null, arguments=null, message=null, statusCode=null]]]
2020-10-16 11:19:45.704 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:12345678-9012-3456-7890-123456789012:node8' has been updated.
Although he “null” in the message is irritating
openhab.log:
2020-10-16 11:18:43.361 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-10-16 11:18:43.363 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-10-16 11:19:45.254 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Configuration update received
2020-10-16 11:19:45.270 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Configuration update set action_heal to false (Boolean)
2020-10-16 11:19:45.272 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Configuration update ignored config_1_1 to 1 (BigDecimal)
2020-10-16 11:19:45.274 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Handler disposed. Unregistering listener.
2020-10-16 11:19:45.274 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Configuration update set binding_cmdrepollperiod to 1500 (BigDecimal)
2020-10-16 11:19:45.276 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Configuration update ignored config_2_1 to 1 (BigDecimal)
2020-10-16 11:19:45.278 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Configuration update ignored wakeup_node to 1 (BigDecimal)
2020-10-16 11:19:45.281 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Configuration update set action_failed to false (Boolean)
2020-10-16 11:19:45.283 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Configuration update ignored wakeup_interval to 86400 (BigDecimal)
2020-10-16 11:19:45.285 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Configuration update set group_1 to [controller] (String)
2020-10-16 11:19:45.287 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Association 1 consolidated to []
2020-10-16 11:19:45.289 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Current members before update ZWaveAssociationGroup [index=1, name=null, profile1=null, profile2=null, associations=[node_1]]
2020-10-16 11:19:45.291 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Members after config update ZWaveAssociationGroup [index=1, name=null, profile1=null, profile2=null, associations=[]]
2020-10-16 11:19:45.293 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Controller is master - forcing associations
2020-10-16 11:19:45.313 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Group is controller - forcing association
2020-10-16 11:19:45.316 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Members after controller update ZWaveAssociationGroup [index=1, name=null, profile1=null, profile2=null, associations=[node_1_1]]
2020-10-16 11:19:45.318 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Removing node_1 from association group 1
2020-10-16 11:19:45.321 [DEBUG] [ndclass.ZWaveAssociationCommandClass] - NODE 8: Creating new message for application command ASSOCIATIONCMD_REMOVE group=1, node=1
2020-10-16 11:19:45.323 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
2020-10-16 11:19:45.326 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Command Class COMMAND_CLASS_ASSOCIATION is NOT required to be secured
2020-10-16 11:19:45.328 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Bump transaction 371 priority from Config to Immediate
2020-10-16 11:19:45.331 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Adding to device queue
2020-10-16 11:19:45.343 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Added 371 to queue - size 5
2020-10-16 11:19:45.344 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-10-16 11:19:45.346 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Adding node_1_1 to association group 1
2020-10-16 11:19:45.348 [DEBUG] [ndclass.ZWaveAssociationCommandClass] - NODE 8: Creating new message for application command ASSOCIATIONCMD_SET, group=1, node=1
2020-10-16 11:19:45.350 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
2020-10-16 11:19:45.351 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Command Class COMMAND_CLASS_ASSOCIATION is NOT required to be secured
2020-10-16 11:19:45.353 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Bump transaction 372 priority from Config to Immediate
2020-10-16 11:19:45.355 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Adding to device queue
2020-10-16 11:19:45.357 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Added 372 to queue - size 6
2020-10-16 11:19:45.359 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-10-16 11:19:45.341 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 8: Serialise aborted as static stages not complete
2020-10-16 11:19:45.362 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:12345678-9012-3456-7890-123456789012:node8.
2020-10-16 11:19:45.364 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Controller status changed to ONLINE.
2020-10-16 11:19:45.366 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Controller is ONLINE. Starting device initialisation.
2020-10-16 11:19:45.374 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating node properties.
2020-10-16 11:19:45.375 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating node properties. MAN=410
2020-10-16 11:19:45.377 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating node properties. MAN=410. SET. Was 410
2020-10-16 11:19:45.379 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Properties synchronised
2020-10-16 11:19:45.361 [DEBUG] [ndclass.ZWaveAssociationCommandClass] - NODE 8: Creating new message for application command ASSOCIATIONCMD_GET group 1
2020-10-16 11:19:45.410 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Update ASSOCIATION group_ZWaveAssociationGroup [index=1, name=null, profile1=null, profile2=null, associations=[node_1]]: Adding Controller (node_1)
2020-10-16 11:19:45.410 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
2020-10-16 11:19:45.412 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Configuration synchronised
2020-10-16 11:19:45.412 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Command Class COMMAND_CLASS_ASSOCIATION is NOT required to be secured
2020-10-16 11:19:45.415 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Bump transaction 373 priority from Config to Immediate
2020-10-16 11:19:45.417 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Adding to device queue
2020-10-16 11:19:45.419 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Added 373 to queue - size 7
2020-10-16 11:19:45.421 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-10-16 11:19:45.427 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Configuration update set action_remove to false (Boolean)
2020-10-16 11:19:45.429 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Configuration update set binding_pollperiod to 86400 (BigDecimal)
2020-10-16 11:19:45.430 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Polling initialised at 86400 seconds - start in 8640000 milliseconds.
2020-10-16 11:19:45.432 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Configuration update ignored node_id to 8 (BigDecimal)
2020-10-16 11:19:45.681 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2020-10-16 11:19:45.683 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Initialising Thing Node...
2020-10-16 11:19:45.685 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Initialising cmd channel zwave:device:12345678-9012-3456-7890-123456789012:node8:sensor_door for OpenClosedType
2020-10-16 11:19:45.687 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Initialising state channel zwave:device:12345678-9012-3456-7890-123456789012:node8:sensor_door for OpenClosedType
2020-10-16 11:19:45.689 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Initialising cmd channel zwave:device:12345678-9012-3456-7890-123456789012:node8:alarm_tamper for OnOffType
2020-10-16 11:19:45.691 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Initialising state channel zwave:device:12345678-9012-3456-7890-123456789012:node8:alarm_tamper for OnOffType
2020-10-16 11:19:45.693 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Initialising cmd channel zwave:device:12345678-9012-3456-7890-123456789012:node8:battery-level for PercentType
2020-10-16 11:19:45.695 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Initialising state channel zwave:device:12345678-9012-3456-7890-123456789012:node8:battery-level for PercentType
2020-10-16 11:19:45.697 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Polling initialised at 86400 seconds - start in 41731200 milliseconds.
2020-10-16 11:19:45.699 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Device initialisation complete.
The wakeup time of 60 days seems to be long, but used to work in the past.
In Habmin the “Association Groups” (Lifeline) the config shows: “pending…”
I will move the controller closer to the strip to check (although it worked in the past with the same distance perfectly)
Any suggestion would be greatly appreciated.
If the wakeup is 60 days, then you can expect the state to be REQUEST_NIF most of the time. This should not be a problem - if the device initialised once in the past (which presumably is the case or it would not be identified) then it will still work fine.
When the binding starts, it always goes through some level of reinitialisation phases to see if it can communicate with the device - if your device only wakes up every 2 months, then the binding cannot communicate with it, however it doesn’t stop the device communicating with the binding.
I’d be surprised if the binding read the wrong battery level. I expect these devices are meant to last longer than 4 years, but as they have not been on the market so long (maybe 4 or 5 years?) I doubt it’s actually been tested much longer - it was probably derived from analyses. Did it just drop from (say) 80% to 0, or was this a linear drop?
If you provide a log with the battery report, I can also check if it’s right.
1 Like
Thanks for your lightning fast response!
The point with the battery is true (life time might be lower, than advertised).
However, if it’s empty, would it then report back any status?
If the power is still sufficient, wouldn’t rhe battery be reported 1% or 0%?
So this should be somewhere in the logs then.
I just have one historic value of battery 50% mid of september.
To check older data (before starting from scratch) I need to check the old influxdb.
(I don’t know how to open the old db yet)
No - that’s not correct. At some point (defined by the device) the device will report low battery, and at that point the binding will report 0%. With ZWave - it’s not possible to report 20% and also low battery (they are exclusive - percentage - or low battery) so it’s quite possible that the device still has 10 or 20 % battery left.
Edit: Re-reading my response - I’m wrong to say that this quote is incorrect - you’re right - if it’s empty, then it won’t report status 
. However my post is still otherwise correct - it can still send reports to say that it’s empty - so it’s not really empty 
Alright - thanks.
But then the state (OPEN / CLOSED) should be reported as well - and that’s not the case.
(it worked obviously until yesterday)
If it’s not reporting, that’s a different issue… However I’m not sure what can change - if the device only wakes up ever 2 months, then it’s unlikely (although not impossible I guess) that the binding has altered any configuration. If it’s stuck in REQUEST_NIF, this means the binding has not communicated to the device.
Would it make sense to (at least temporarily) reducte the wake up time?
The device is back in the REQUEST_NIF stage after a restart.
(bringing the controller closer to the strip did not change anything)
This will not do anything. The wakeup time is set on the device, so the time cannot be set until the device wakes up (some time in the next 60 days).
This is normal - it will ALWAYS do this - every time. It is not a problem - the device should be online, and it should work if the device sends any reports. The REQUEST_NIF is just part of the startup routine that the binding goes through - it is not an error in any way.
Again, this is normal. The device is not listening. Moving it will not change anything - it still won’t be listening no matter where you put it. The only time it will listen is for a few seconds every 60 days when it wakes up.