[SOLVED] Some Z-Wave battery devices are not updating battery level

zwave
Tags: #<Tag:0x00007f014c2070c0>

(Nico) #1

I know that there are other threads regarding that topic, but since they are mostly older and they do not contain a solution for my problem and due to the fact that the z-wave binding was recently updated to v2.5.0, I decided to start this new thread.

I am using the two z-wave battery devices:

  • FGK101 Door Opening Sensor (as the “smartification”-device of my analogue doorbell - including a temperature sensor)
  • WALLC-S Wall Controller (as a wall controller for my rollershutters)

and they are working fine … that means, they are both sending the information I need (in case if somebody rings the bell or pushes a button on the wall controller).

Unfortunately they both are not updating the battery level!

The door sensor (which I am using as a binary sensor for my door bell with included temperature sensor) is sending a command when somebody rings the bell or when the temperature is changing. But even if I wake the device up manually (by pressing the B-button three times) it is not providing its battery state. The wall controller is also not sending information about its battery level when pushing one of its buttons.

My MT02650 Devolo Thermostat (09356) (which is also a z-wave battery device) is providing its battery level with every temperature update. So there everything is fine.

The items are configured as follows:

Number   klingelsensor_temperature         "Klingelsensor/Temperatur [%.1f °C]"  <temperature>  { channel="zwave:device:71a23be9:node14:sensor_temperature" }
Number   klingelsensor_batterylevel        "Klingelsensor/Batterie [%s %%]"      <battery>      { channel="zwave:device:71a23be9:node14:battery-level" }
Contact  doorbell                          "Klingel betätigt"                    <contact>      { channel="zwave:device:71a23be9:node14:sensor_door" }

Number   wallcs_og_batterie          "WallC-S-Schalter Batterie: [%s %%]" <battery>  { channel="zwave:device:71a23be9:node18:battery-level" }
Number   wallcs_og_scene_number      "WallC-S-Schalter Scene-Number"                 { channel="zwave:device:71a23be9:node18:scene_number" }

Number schlafzimmer_temp_ist                "Ist-Temperatur"   <temperature>  { channel="zwave:device:71a23be9:node30:sensor_temperature" }
Number schlafzimmer_thermostat_batterylevel "Batterie-Level"   <battery>   { channel="zwave:device:71a23be9:node30:battery-level" }

The Wake Up Interval of the door sensor is set to 21600 but (due to a note of Chris Jackson here in the forum) it should provide its battery state at least once an hour.

The Z-Wave controller is set as recipient of the 1st association group (“Lifeline”) for all devices.

My installation is based on:
openHAB 2.5.0~S1479-1 (Build #1479) (openHABian)
binding-zwave - 2.5.0.SNAPSHOT

Does somebody had the same problem and a solution for it or an idea how I can get to the bottom of the problem?

Thank you very much in advance for your support!

Some logs (log level DEBUG for zwave binding):

Waking up the door sensor manually:

2019-01-09 21:08:35.007 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=14, callback=132, payload=84 0E 18 04 07 01 5E 85 59 22 20 80 70 56 5A 7A 72 8E 71 73 98 2B 9C 30 31 86 84 
2019-01-09 21:08:35.010 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 14: Application update request. Node information received. Transaction null
2019-01-09 21:08:35.014 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: resetResendCount initComplete=true isDead=false
2019-01-09 21:08:35.016 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 14: Application update - no transaction.
2019-01-09 21:08:35.020 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-09 21:08:35.023 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-01-09 21:08:35.271 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: Is awake with 0 messages in the queue
2019-01-09 21:08:35.274 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: Start sleep timer at 1000ms
2019-01-09 21:08:35.277 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2019-01-09 21:08:35.315 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 14: Node Status event - Node is AWAKE
2019-01-09 21:08:35.777 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: WakeupTimerTask 0 Messages waiting, state DONE
2019-01-09 21:08:36.278 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: WakeupTimerTask 0 Messages waiting, state DONE
2019-01-09 21:08:36.288 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: No more messages, go back to sleep
2019-01-09 21:08:36.290 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 14: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
2019-01-09 21:08:36.293 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: SECURITY NOT required on COMMAND_CLASS_WAKE_UP
2019-01-09 21:08:36.295 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: Command Class COMMAND_CLASS_WAKE_UP is NOT required to be secured
2019-01-09 21:08:36.298 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@67fee
2019-01-09 21:08:36.300 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Bump transaction 12612 priority from Immediate to Immediate
2019-01-09 21:08:36.304 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Adding to device queue
2019-01-09 21:08:36.307 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Added 12612 to queue - size 5
2019-01-09 21:08:36.311 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-01-09 21:08:36.315 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 0E 02 84 08 25 9B DB 
2019-01-09 21:08:36.320 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 14: Sending REQUEST Message = 01 09 00 13 0E 02 84 08 25 9B DB 
2019-01-09 21:08:36.330 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-01-09 21:08:36.333 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-01-09 21:08:36.334 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 12612: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 155
2019-01-09 21:08:36.337 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-01-09 21:08:36.343 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-01-09 21:08:36.345 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2019-01-09 21:08:36.345 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 12612: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 155
2019-01-09 21:08:36.348 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-01-09 21:08:36.349 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-01-09 21:08:36.351 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-09 21:08:36.355 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-01-09 21:08:36.355 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 9B 00 00 02 72 
2019-01-09 21:08:36.358 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-01-09 21:08:36.361 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=155, payload=9B 00 00 02 
2019-01-09 21:08:36.361 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 12612: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 155
2019-01-09 21:08:36.364 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-01-09 21:08:36.367 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 12612: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 155
2019-01-09 21:08:36.371 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2019-01-09 21:08:36.373 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 14: sentData successfully placed on stack.
2019-01-09 21:08:36.378 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 12612: Advanced to WAIT_REQUEST
2019-01-09 21:08:36.380 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: TID 12612: Transaction not completed
2019-01-09 21:08:36.384 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=155, payload=9B 00 00 02 
2019-01-09 21:08:36.387 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 12612: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 155
2019-01-09 21:08:36.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-01-09 21:08:36.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 12612: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 155
2019-01-09 21:08:36.396 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 12612: (Callback 155)
2019-01-09 21:08:36.399 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-01-09 21:08:36.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 12612: callback 155
2019-01-09 21:08:36.403 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=155, payload=9B 00 00 02 
2019-01-09 21:08:36.405 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 14: SendData Request. CallBack ID = 155, Status = Transmission complete and ACK received(0)
2019-01-09 21:08:36.407 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: resetResendCount initComplete=true isDead=false
2019-01-09 21:08:36.409 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 12612: Transaction COMPLETED
2019-01-09 21:08:36.411 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Response processed after 77ms
2019-01-09 21:08:36.413 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: TID 12612: Transaction completed
2019-01-09 21:08:36.414 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: notifyTransactionResponse TID:12612 DONE
2019-01-09 21:08:36.417 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-01-09 21:08:36.417 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 12612: Transaction event listener: DONE: DONE -> 
2019-01-09 21:08:36.418 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-09 21:08:36.419 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: Went to sleep COMPLETE
2019-01-09 21:08:36.420 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

WallC-S button pressed:

2019-01-09 21:14:12.837 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 12 05 5B 03 03 00 05 B9 
2019-01-09 21:14:12.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=18, callback=0, payload=00 12 05 5B 03 03 00 05 
2019-01-09 21:14:12.851 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=18, callback=0, payload=00 12 05 5B 03 03 00 05 
2019-01-09 21:14:12.855 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-01-09 21:14:12.859 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Application Command Request (ALIVE:UPDATE_NEIGHBORS)
2019-01-09 21:14:12.864 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 18: Incoming command class COMMAND_CLASS_CENTRAL_SCENE, endpoint 0
2019-01-09 21:14:12.868 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 18: SECURITY not supported
2019-01-09 21:14:12.872 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 18: Received COMMAND_CLASS_CENTRAL_SCENE V1 CENTRAL_SCENE_NOTIFICATION
2019-01-09 21:14:12.877 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 18: Received scene 5 at key 0 [Single Press]
2019-01-09 21:14:12.882 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2019-01-09 21:14:12.886 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_CENTRAL_SCENE, value = 5.0
2019-01-09 21:14:12.891 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Updating channel state zwave:device:71a23be9:node18:scene_number to 5.0 [DecimalType]
2019-01-09 21:14:12.897 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Commands processed 1.
2019-01-09 21:14:12.902 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 18: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@73a0f0.
2019-01-09 21:14:12.906 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-01-09 21:14:12.911 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-01-09 21:14:12.915 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-09 21:14:12.920 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

(Markus Storm) #2

I don’t believe that as that sort of would be contradicting all the attempts to save on battery.
Dunno what’s the interval to update on battery. That’s not necessarily the same as the wake up interval.

I’d double check the items definition for battery and all zwave parameters that might be related to it.
Carefully re-read the manuals.
For a start, enable long term logging and see if there’s ANY zwave battery message.


(Nico) #3

I was referring to this post:

… but it was stated in July 2016 so it must not be true for the current version of the binding.


(HomeAutomation) #4

I think it is not correct, that the battery level will be send every hour.

I fixed this by doing this:

  1. change polling periodfrom 1d to 6h
  2. command poll period: disabled
  3. wakeup configuration: 21600

This gives me every 6h a new battery value as an update.

Keep in mind, if the battery level is not changed you see nothing in the eventlog. Only a rule which triggers on update will see the command from the device.


(Nico) #5

Thank you very much for that hint, @HomeAutomation! I am gonna check that out.

May I ask you which device do you use this way?

Notes:

  • I am already using an on update trigger (to store the last update time) but no updates are sent.
  • the battery level item is empty in my case, thus never set.

(Markus Storm) #6

Refresh is something different. It doesn’t mean a message is sent. The device needs to wakeup to do this.


(HomeAutomation) #7

with firmware 2.3, 2.5 and 3.2


(Nico) #8

Thank you @HomeAutomation and @mstormi for your support. I just reconfigured it and will give feedback tomorrow.


(Chris Jackson) #9

Why mustn’t it be true still? It is as far as I know.

It is also governed by the wakeup interval (unless the device is sending battery level unsolicited at a different interval (eg when it sends notifications).


(Nico) #10

Sorry, @chris, my translation was bad (I used german-like words). The meaning of my note was: “it does not have to be true furthermore”.

Do I understand your words (in the old and the current thread) correctly when I say that the binding tries to poll the battery state at least once an hour but receives it more frequently if the device …
a) … is programmed to send the battery state with the wake up message and the wake up is configured with an interval less than an hour
b) … sends the battery level along with notifications and there is at least one before the hour is over
c) … is programmed to publish its battery state unsolicited but does so before the hour is over
?


(Chris Jackson) #11

No problem :slight_smile:

Yes, you understand correctly. When the binding polls, it does it every hour - this will not be sent until the next wakeup of the device (which could be another hour, or day, or…). The device can however also send the battery level on its own for the possible reasons you list. Even if the device does this, the binding will still send the poll to request the battery level.


(Nico) #12

Thank you very much, @chris , for the detailed information! Now I think I got it.

One additional note for others with the same problem:

after reconfiguring my affected devices (like @HomeAutomation suggested) and waking them up to receive the new parameter values, nothing changed in the behaviour which means I got no information about the battery levels of these devices. But as I saw in habmin that the device is now more frequently waking up, I created a second openhab-item for the battery level besides the already existent one … but with the difference that I did it by using the UI instead of defining them in an items-file. From then on, everything worked fine … even with the “old” items. Since then I get the battery state regularly about every six hours. Strange, but it works now!

Thank you very much for your support to all of you!