with firmware 2.3, 2.5 and 3.2
Thank you @HomeAutomation and @mstormi for your support. I just reconfigured it and will give feedback tomorrow.
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).
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
?
No problem 
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.
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!
1 Like
Hi everyone and especially @chris 
i know, this topic is marked as solved, but i am facing mostly the same problem and didn’t find a solution yet.
I’m running some battery powered z-wave door/window sensors Vision ZD-2102 with an Aeon Z-Stick Gen 5 on Raspberry Pi.
Everything working properly for years with OpenHAB 1.8 an Z-Wave Binding 1.9 Snapshot.
Few weeks ago i did a complete fresh install of openhab 2.4 using openhabian and started migrating all my configuration. I also upgraded to the new 2.4 Z-Wave Binding installed through PaperUI.
Z-Wave Things have been added through Habmin, Items are manually configured in items files.
Now none of my ZD-2102 is reporting it’s battery-level.
With 1.8 it’s been reularly updated. I only have one other battery device, POPE009303, which is updating it’s battery-level.
I already tried to exclude an reinclude one of the devices to the Z-Wave network and readded the thing, but nothing changed. I also tried adding the battery item through PaperUI with no success.
This is my zstick thing
"zwave:serial_zstick:7c2d2216": {
"class": "org.eclipse.smarthome.core.thing.internal.BridgeImpl",
"value": {
"label": "Z-Wave Serial Controller",
"channels": [
{
"acceptedItemType": "Number",
"kind": "STATE",
"uid": {
"segments": [
"zwave",
"serial_zstick",
"7c2d2216",
"serial_sof"
]
},
"channelTypeUID": {
"segments": [
"zwave",
"serial_sof"
]
},
"label": "Start Frames",
"description": "Counter tracking the number of SOF bytes received",
"configuration": {
"properties": {}
},
"properties": {},
"defaultTags": []
},
{
"acceptedItemType": "Number",
"kind": "STATE",
"uid": {
"segments": [
"zwave",
"serial_zstick",
"7c2d2216",
"serial_ack"
]
},
"channelTypeUID": {
"segments": [
"zwave",
"serial_ack"
]
},
"label": "Frames Acknowledged",
"description": "Counter tracking the number of frames acknowledged by the controller",
"configuration": {
"properties": {}
},
"properties": {},
"defaultTags": []
},
{
"acceptedItemType": "Number",
"kind": "STATE",
"uid": {
"segments": [
"zwave",
"serial_zstick",
"7c2d2216",
"serial_nak"
]
},
"channelTypeUID": {
"segments": [
"zwave",
"serial_nak"
]
},
"label": "Frames Rejected",
"description": "Counter tracking the number of frames rejected by the controller",
"configuration": {
"properties": {}
},
"properties": {},
"defaultTags": []
},
{
"acceptedItemType": "Number",
"kind": "STATE",
"uid": {
"segments": [
"zwave",
"serial_zstick",
"7c2d2216",
"serial_can"
]
},
"channelTypeUID": {
"segments": [
"zwave",
"serial_can"
]
},
"label": "Frames Cancelled",
"description": "Counter tracking the number of frames cancelled by the controller",
"configuration": {
"properties": {}
},
"properties": {},
"defaultTags": []
},
{
"acceptedItemType": "Number",
"kind": "STATE",
"uid": {
"segments": [
"zwave",
"serial_zstick",
"7c2d2216",
"serial_oof"
]
},
"channelTypeUID": {
"segments": [
"zwave",
"serial_oof"
]
},
"label": "OOF Bytes Received",
"description": "Counter tracking the number of out of flow bytes received",
"configuration": {
"properties": {}
},
"properties": {},
"defaultTags": []
},
{
"acceptedItemType": "Number",
"kind": "STATE",
"uid": {
"segments": [
"zwave",
"serial_zstick",
"7c2d2216",
"serial_cse"
]
},
"channelTypeUID": {
"segments": [
"zwave",
"serial_cse"
]
},
"label": "Received Checksum Errors",
"description": "Counter tracking the number of frames received with checksum errors",
"configuration": {
"properties": {}
},
"properties": {},
"defaultTags": []
}
],
"configuration": {
"properties": {
"controller_softreset": false,
"security_networkkey": "55 17 75 56 3F 2D 18 55 77 1F FD D9 65 2B 9C 93",
"security_inclusionmode": 0,
"controller_sisnode": 1,
"controller_sync": false,
"port": "/dev/ttyACM0",
"controller_master": true,
"inclusion_mode": 2,
"controller_wakeupperiod": 3600,
"heal_time": 2,
"controller_exclude": false,
"controller_inclusiontimeout": 30,
"controller_hardreset": false
}
},
"properties": {
"zwave_neighbours": "2,6,8,9,14,16,17,18,19,20,21,22,23",
"zwave_nodeid": "1"
},
"uid": {
"segments": [
"zwave",
"serial_zstick",
"7c2d2216"
]
},
"thingTypeUID": {
"segments": [
"zwave",
"serial_zstick"
]
}
}
}
This is one of the ZD-2102 things
"zwave:device:7c2d2216:node26": {
"class": "org.eclipse.smarthome.core.thing.internal.ThingImpl",
"value": {
"label": "Z-Wave Door Window Sensor Büro Osten",
"bridgeUID": {
"segments": [
"zwave",
"serial_zstick",
"7c2d2216"
]
},
"channels": [
{
"acceptedItemType": "Contact",
"kind": "STATE",
"uid": {
"segments": [
"zwave",
"device",
"7c2d2216",
"node26",
"sensor_door"
]
},
"channelTypeUID": {
"segments": [
"zwave",
"sensor_door"
]
},
"label": "Sensor (Alarm)",
"description": "Indicates if the door/window is open or closed",
"configuration": {
"properties": {}
},
"properties": {
"binding:*:OpenClosedType": "COMMAND_CLASS_ALARM;type\u003dACCESS_CONTROL, event\u003d23"
},
"defaultTags": []
},
{
"acceptedItemType": "Switch",
"kind": "STATE",
"uid": {
"segments": [
"zwave",
"device",
"7c2d2216",
"node26",
"alarm_tamper"
]
},
"channelTypeUID": {
"segments": [
"zwave",
"alarm_tamper"
]
},
"label": "Tamper Alarm",
"description": "Indicates if the tamper alarm is triggered",
"configuration": {
"properties": {}
},
"properties": {
"binding:*:OnOffType": "COMMAND_CLASS_ALARM;BURGLAR"
},
"defaultTags": []
},
{
"acceptedItemType": "Number",
"kind": "STATE",
"uid": {
"segments": [
"zwave",
"device",
"7c2d2216",
"node26",
"battery-level"
]
},
"channelTypeUID": {
"segments": [
"system",
"battery-level"
]
},
"label": "Batterieladung",
"configuration": {
"properties": {}
},
"properties": {
"binding:*:PercentType": "COMMAND_CLASS_BATTERY"
},
"defaultTags": []
}
],
"configuration": {
"properties": {
"action_heal": false,
"config_1_1": 0,
"binding_cmdrepollperiod": 1500,
"action_reinit": false,
"wakeup_node": 1,
"action_failed": false,
"wakeup_interval": 3600,
"group_1": [
"node_1"
],
"action_remove": false,
"binding_pollperiod": 86400,
"node_id": 26
}
},
"properties": {
"zwave_class_basic": "BASIC_TYPE_ROUTING_SLAVE",
"zwave_class_generic": "GENERIC_TYPE_SENSOR_NOTIFICATION",
"zwave_frequent": "false",
"zwave_neighbours": "",
"modelId": "ZD2102-5",
"zwave_version": "5.1",
"zwave_listening": "false",
"zwave_plus_devicetype": "NODE_TYPE_ZWAVEPLUS_NODE",
"manufacturerId": "0109",
"manufacturerRef": "2001:0105,2001:0106",
"dbReference": "816",
"zwave_deviceid": "262",
"zwave_nodeid": "26",
"vendor": "Vision Security",
"defaultAssociations": "1",
"zwave_routing": "true",
"zwave_plus_roletype": "ROLE_TYPE_SLAVE_SLEEPING_REPORTING",
"zwave_beaming": "true",
"zwave_secure": "false",
"zwave_class_specific": "SPECIFIC_TYPE_NOTIFICATION_SENSOR",
"zwave_manufacturer": "265",
"zwave_devicetype": "8193",
"zwave_lastwakeup": "2019-02-22T10:12:39Z"
},
"uid": {
"segments": [
"zwave",
"device",
"7c2d2216",
"node26"
]
},
"thingTypeUID": {
"segments": [
"zwave",
"vision_zd2102plus_00_000"
]
}
}
}
And finally the corresponding item
Contact ZWAVE_CONTACT_23 {channel="zwave:device:7c2d2216:node26:sensor_door"}
Number ZWAVE_CONTACT_23_BATTERY {channel="zwave:device:7c2d2216:node26:battery-level"}
There are no errors or warnings in the logs, battery-level just never occurs.
Hope somebody can help me to identify the problem.
I realized, i wasn’t 100% honest.
There is one error in openhab.log for every of the ZD-2102 devices. This error is only showing up once on system startup.
2019-02-11 20:57:54.435 [ERROR] [pse.smarthome.core.thing.internal.ThingManagerImpl] - Exception occurred during notification about bridge status change on thing 'zwave:device:7c2d2216:node26': 1
java.lang.ArrayIndexOutOfBoundsException: 1
at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialiseNode(ZWaveThingHandler.java:226) ~[?:?]
at org.openhab.binding.zwave.handler.ZWaveThingHandler.bridgeStatusChanged(ZWaveThingHandler.java:512) ~[?:?]
at org.eclipse.smarthome.core.thing.internal.ThingManagerImpl$4.run(ThingManagerImpl.java:901) [109:org.eclipse.smarthome.core.thing:0.10.0.oh240]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
I had the same problem with the ZD-2102 devices.
There must be a change between 2.3 and 2.4 of the z-wave binding which causes this effect. With 2.3 all went good. Tamper and battery was working. With 2.4 version of the binding, both was gone. I had only three of them and exchanged them with fibaro sensors. Now I’m happe again.
This normally happens if the device sends corrupted data - please can you post the debug messages that appear before this.
2.3 and 2.4 are quite different, but I’m not sure what effect you are talking about? Battery requests should be handled the same.
Please provide debug logs - it’s really pretty much impossible to understand what might be wrong without this.
I had battery issues with snapshots of 2.4, stable 2.4, 2.5 M1 zwave battery %s showed up again for my door sensors which are very similar to yours (purchased mine from monoprice). Not saying to upgrade your zwave binding, just passing along something that worked for me.
I thought you would say that.
I’m not sure which log level to set to DEBUG.
Only the z-wave binding?
# ZWave log appender
log4j2.logger.zwave.name = org.openhab.binding.zwave
log4j2.logger.zwave.level = DEBUG
log4j2.logger.zwave.additivity = false
log4j2.logger.zwave.appenderRefs = zwave
log4j2.logger.zwave.appenderRef.zwave.ref = ZWAVE
seems like there is realy an issue with this version of the binding?
Yes, in Karaf, just type log:set DEBUG org.openhab.binding.zwave.
I think it’s unlikely that there is a general issue or we would have a lot more people talking about this than 2 
The 2.5 binding hasn’t really seen any changes in the battery management from 2.4 either…
Let’s look at the logs to see what is happening - otherwise we can just speculate, and that won’t get anything fixed.
Hi chris,
not to confuse you. The battery issue is only related to this one z-wave device ZD-2102. All other devices work perfect. I do not have this one anymore, so I cannot make a debug log.
Ok, but the binding knows nothing specific about the device, so I’m not sure why it would decide to not work only for the battery here.
Ah - ok, then that will be problematic
think you’re right.
ok, set the level to DEBUG and restartet openhab.
here is the error in openhab.log at 16:18:01.451
2019-02-22 16:18:01.451 [ERROR] [pse.smarthome.core.thing.internal.ThingManagerImpl] - Exception occurred during notification about bridge status change on thing 'zwave:device:7c2d2216:node26': 1
and this is the debug output containing NODE 26
2019-02-22 16:17:45.904 [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 26: Channel zwave:device:7c2d2216:node26:sensor_door linked - polling started.
2019-02-22 16:17:45.933 [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 26: Channel zwave:device:7c2d2216:node26:battery-level linked - polling started.
2019-02-22 16:17:48.870 [col.serialmessage.SerialApiGetInitDataMessageClass] - NODE 26: Node found
2019-02-22 16:17:49.037 [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 26: Init node thread start
2019-02-22 16:17:49.637 [ternal.protocol.initialization.ZWaveNodeSerializer] - NODE 26: Serializing from file /var/lib/openhab2/zwave/network_d7fd06c9__node_26.xml
2019-02-22 16:17:50.227 [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 26: Restore from config: Ok.
2019-02-22 16:17:50.400 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Command class COMMAND_CLASS_ZWAVEPLUS_INFO, endpoint 0 created
2019-02-22 16:17:50.400 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Command class COMMAND_CLASS_WAKE_UP, endpoint 0 created
2019-02-22 16:17:50.427 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Command class COMMAND_CLASS_VERSION, endpoint 0 created
2019-02-22 16:17:50.448 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
2019-02-22 16:17:50.460 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Command class COMMAND_CLASS_ASSOCIATION, endpoint 0 created
2019-02-22 16:17:50.661 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Command class COMMAND_CLASS_FIRMWARE_UPDATE_MD, endpoint 0 created
2019-02-22 16:17:50.672 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Command class COMMAND_CLASS_SECURITY, endpoint 0 created
2019-02-22 16:17:50.673 [al.protocol.commandclass.ZWaveSecurityCommandClass] - NODE 26: Updated networkKey
2019-02-22 16:17:50.674 [al.protocol.commandclass.ZWaveSecurityCommandClass] - NODE 26: setupNetworkKey useSchemeZero=false
2019-02-22 16:17:50.677 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Command class COMMAND_CLASS_BATTERY, endpoint 0 created
2019-02-22 16:17:50.677 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Command class COMMAND_CLASS_DEVICE_RESET_LOCALLY, endpoint 0 created
2019-02-22 16:17:50.711 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Command class COMMAND_CLASS_ALARM, endpoint 0 created
2019-02-22 16:17:50.735 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Command class COMMAND_CLASS_CONFIGURATION, endpoint 0 created
2019-02-22 16:17:50.736 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Command class COMMAND_CLASS_MANUFACTURER_SPECIFIC, endpoint 0 created
2019-02-22 16:17:50.747 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Command class COMMAND_CLASS_BASIC, endpoint 0 created
2019-02-22 16:17:50.748 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Command class COMMAND_CLASS_POWERLEVEL, endpoint 0 created
2019-02-22 16:17:50.753 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Command class COMMAND_CLASS_ASSOCIATION_GRP_INFO, endpoint 0 created
2019-02-22 16:17:50.754 [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 26: Device discovery completed
2019-02-22 16:18:00.664 [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 26: Device discovery resolved to thingType zwave:vision_zd2102plus_00_000
2019-02-22 16:18:00.803 [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 26: Starting initialisation from EMPTYNODE
2019-02-22 16:18:00.868 [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 26: Init node thread finished
2019-02-22 16:18:00.869 [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 26: Node advancer - advancing to IDENTIFY_NODE
2019-02-22 16:18:00.871 [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 26: Node advancer: Initialisation starting
2019-02-22 16:18:01.421 [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 26: Controller status changed to ONLINE.
2019-02-22 16:18:01.421 [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 26: Controller is ONLINE. Starting device initialisation.
2019-02-22 16:18:01.423 [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 26: Updating node properties.
2019-02-22 16:18:01.424 [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 26: Updating node properties. MAN=265
2019-02-22 16:18:01.424 [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 26: Updating node properties. MAN=265. SET. Was 265
2019-02-22 16:18:01.429 [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 26: Properties synchronised
2019-02-22 16:18:01.438 [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 26: Update ASSOCIATION group_ZWaveAssociationGroup [index=1, name=Lifeline, profile1=0, profile2=1, associations=[node_1]]: Adding node_1
2019-02-22 16:18:01.446 [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 26: Initialising Thing Node...
2019-02-22 16:18:01.447 [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 26: Initialising cmd channel zwave:device:7c2d2216:node26:sensor_door for OpenClosedType
2019-02-22 16:18:01.448 [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 26: Initialising state channel zwave:device:7c2d2216:node26:sensor_door for OpenClosedType
2019-02-22 16:18:01.685 [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 26: ProtocolInfo
2019-02-22 16:18:01.686 [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 26: Listening = false
2019-02-22 16:18:01.687 [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 26: Routing = true
2019-02-22 16:18:01.687 [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 26: Beaming = true
2019-02-22 16:18:01.688 [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 26: Version = 4
2019-02-22 16:18:01.689 [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 26: FLIRS = false
2019-02-22 16:18:01.689 [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 26: Security = false
2019-02-22 16:18:01.690 [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 26: Max Baud = 40000
2019-02-22 16:18:01.691 [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 26: Basic = BASIC_TYPE_ROUTING_SLAVE
2019-02-22 16:18:01.691 [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 26: Generic = GENERIC_TYPE_SENSOR_NOTIFICATION
2019-02-22 16:18:01.692 [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 26: Specific = SPECIFIC_TYPE_NOTIFICATION_SENSOR
2019-02-22 16:18:01.692 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Creating new instance of command class COMMAND_CLASS_NO_OPERATION
2019-02-22 16:18:01.693 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
2019-02-22 16:18:01.694 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Version = 1, version set. Enabling extra functionality.
2019-02-22 16:18:01.694 [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 26: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes.
2019-02-22 16:18:01.695 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Creating new instance of command class COMMAND_CLASS_BASIC
2019-02-22 16:18:01.695 [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 26: Command class COMMAND_CLASS_BASIC, endpoint 0 created
2019-02-22 16:18:01.696 [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 26: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes.
2019-02-22 16:18:01.713 [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 26: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@81bf0e
2019-02-22 16:18:01.714 [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 26: Node Init transaction completed with response COMPLETE
2019-02-22 16:18:01.714 [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 26: Node advancer - advancing to REQUEST_NIF
2019-02-22 16:18:01.715 [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 26: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2019-02-22 16:18:01.717 [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 26: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@183373a
2019-02-22 16:18:01.719 [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 26: Bump transaction 40 priority from Controller to Immediate
2019-02-22 16:18:01.720 [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 26: Adding to device queue
2019-02-22 16:18:01.721 [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 26: Added 40 to queue - size 11
i noticed something else. scanning the zwave.log for battery, for all ZD-2102 getting something like this
2019-02-22 16:17:45.933 [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 26: Channel zwave:device:7c2d2216:node26:battery-level linked - polling started.
but the POPE009303 shows me
2019-02-22 16:18:01.086 [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 6: Initialising cmd channel zwave:device:7c2d2216:node6:battery-level for PercentType
2019-02-22 16:18:01.089 [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 6: Initialising state channel zwave:device:7c2d2216:node6:battery-level for PercentType
as i mentioned, POP is my only device that is reporting its battery-level.
Sorry - I missed this. Since you didn’t reply to my message, the system doesn’t notify me…
I’ve no idea what this is, but I doubt it’s related. Is there any more information printed with the exception?
This doesn’t really provide a lot…
Interesting - if you don’t see the same message, then this could explain the problem. Apparently there is a bug in ESH (now OH I guess ) where the bindings aren’t always notified when channels are linked. I’m not familiar with this, but @mhilbush might be able to provide a reference?
I’ve not logged an issue on this, because it happens so infrequently and I can’t see anything that is a direct cause. Sometimes it happens for all channels; sometimes for just a couple channels. When it happens, it usually occurs at startup. I expect it is a timing issue related to the way bundles/services are loaded. Stopping and starting the binding always resolves the issue (i.e. an openHAB restart is not required). I also resolved it once by saving a change to my zwave.items file.
The issue manifests itself by the channel for a fully initialized device never being polled, and with the absence of the “Channel xxxxx linked - polling started” messages in the log.
If I can’t figure out what’s causing it, I might try to convince @chris to consider using the isLinked method when deciding to poll the channels.
There is, but if it’s helpful…
2019-02-22 16:18:01.451 [ERROR] [pse.smarthome.core.thing.internal.ThingManagerImpl] - Exception occurred during notification about bridge status change on thing 'zwave:device:7c2d2216:node26': 1
java.lang.ArrayIndexOutOfBoundsException: 1
at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialiseNode(ZWaveThingHandler.java:226) ~[?:?]
at org.openhab.binding.zwave.handler.ZWaveThingHandler.bridgeStatusChanged(ZWaveThingHandler.java:512) ~[?:?]
at org.eclipse.smarthome.core.thing.internal.ThingManagerImpl$4.run(ThingManagerImpl.java:901) [109:org.eclipse.smarthome.core.thing:0.10.0.oh240]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
When I had a look into Habmin today I recognized all ZD-2102 stuck in “Node initialising: REQUEST_NIF”. Last time some of them were in this status, but now it’s all of them.
After restarting the zwave addon one of the nodes seems to be fully initialised in Habmin. I’ll check this again tomorrow.
Hi Mark, thanks for your input. I tried commenting out some of the Battery items and adding them back later on. Also touched the items file and restarted the zwave addon. But till now nothing changed.
This is the message I receive.
But these are missing
Initialising cmd channel...
Initialising state channel...