Z-node has trouble updating

Setup, Configuration and Use Beginners
1

I have node that continuously logs the following:

18:08:35.559 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_43f84cf2_serial_sof changed from 415181 to 415182
18:08:35.579 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_43f84cf2_serial_sof changed from 415182 to 415183
18:08:35.590 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zwave:device:43f84cf2:node19’ has been updated.
18:08:36.416 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_43f84cf2_serial_sof changed from 415183 to 415184
18:08:36.475 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zwave:device:43f84cf2:node19’ has been updated.
18:08:37.414 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_43f84cf2_serial_sof changed from 415184 to 415185
18:08:37.429 [WARN ] [org.jline ] - Failed to save history
java.nio.file.AccessDeniedException: /home/openhab
at sun.nio.fs.UnixException.translateToIOException(UnixException.java:84) [?:?]
at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102) [?:?]
at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107) [?:?]
at sun.nio.fs.UnixFileSystemProvider.createDirectory(UnixFileSystemProvider.java:384) [?:?]
at java.nio.file.Files.createDirectory(Files.java:674) [?:?]
at java.nio.file.Files.createAndCheckIsDirectory(Files.java:781) [?:?]
at java.nio.file.Files.createDirectories(Files.java:767) [?:?]
at org.jline.reader.impl.history.DefaultHistory.save(DefaultHistory.java:124) [14:org.jline:3.6.0]
at org.jline.reader.impl.history.DefaultHistory.add(DefaultHistory.java:253) [14:org.jline:3.6.0]
at org.jline.reader.impl.LineReaderImpl.finishBuffer(LineReaderImpl.java:887) [14:org.jline:3.6.0]
at org.jline.reader.impl.LineReaderImpl.readLine(LineReaderImpl.java:566) [14:org.jline:3.6.0]
at org.apache.karaf.shell.impl.console.ConsoleSessionImpl.run(ConsoleSessionImpl.java:343) [12:org.apache.karaf.shell.core:4.1.5]
at java.lang.Thread.run(Thread.java:748) [?:?]
18:08:37.431 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zwave:device:43f84cf2:node19’ has been updated.
18:08:38.421 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_43f84cf2_serial_sof changed from 415185 to 415186
18:08:38.450 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_43f84cf2_serial_ack changed from 98314 to 98315
18:08:38.483 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zwave:device:43f84cf2:node19’ has been updated.
18:08:38.509 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_43f84cf2_serial_sof changed from 415186 to 415187
18:08:38.536 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_43f84cf2_serial_sof changed from 415187 to 415188
18:08:39.417 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_43f84cf2_serial_sof changed from 415188 to 415189
18:08:39.463 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing ‘zwave:device:43f84cf2:node19’ has been updated.
18:08:40.411 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_43f84cf2_serial_sof changed from 415189 to 415190

The battery eventually runs out because it never gets updated?

Any ideas where to start troubleshooting?

2

That looks like a serial “packet counter” for which you have an item defined (zwave_serial_zstick_43f84cf2_serial_sof) - do you need to read the value of the counter every time? You could comment out the item, so the Zstick doesn’t update/poll the node so frequently (though, I’m not sure if the node wouldn’t still be sending those packets anyway - seems like a bad idea for a battery-powered Zwave node). What is the device, anyway? Is there a configuration option you can choose in Habmin to disable the packet counter from updating?

3

The device is a dry contact sensor I’m using to indicate when my HVAC is on. When I first installed it several months ago it worked OK but more recently when I changed the battery it got into the “chatty” mode that just won’t stop.
Consequently it will eat batteries in a couple of days.
Those “serial_sof” messages occur whenever my system is getting updates from the z-wave devices but normally they are only occasional. I don’t know how to run debug logging to understand them better.
I have about 25 z-wave devices

4

ZW097 Dry Contact Sensor to be specific.

zwave_class_basic ROUTING_SLAVE
zwave_class_generic SENSOR_NOTIFICATION
zwave_frequent false
zwave_neighbours 1,2,3,7,8,15,17
modelId ZW097
zwave_version 1.5
zwave_listening false
zwave_plus_devicetype ACCESS_CONTROL_SENSOR
manufacturerId 0086
manufacturerRef 0002:0061,0102:0061,0202:0061
dbReference 267
zwave_deviceid 97
zwave_nodeid 19
vendor AEON Labs
defaultAssociations 1
zwave_routing true
zwave_wakeup_time 2018-07-31T03:01:51Z
zwave_beaming true
zwave_class_specific NOTIFICATION_SENSOR
zwave_manufacturer 134
zwave_devicetype 258
5

Check out this description of possible modes for battery operated Zwave devices and the entry in @chris 's database. Your battery-operated sensor should not be routing as far as I know, and it’s possible that it’s mis-configured. Specifically, look at setting “111” (Battery report interval), since it appears that your messages in the log from the devices are coming in at 1-second intervals. You might want to set that (using Habmin) to a much higher value.

6

You should get a debug logfile. Most of what you have logged above is not related to the device, but to find out what is happening, you need to get the debug log.

The SOF messages mean that the binding has received a frame from the controller - we don’t know what without the log. It is a good guess that node 19 sent the frame as there is an update message shortly after, but it doesn’t look like the binding has sent anything based on this log.

The exception doesn’t appear to be related to ZWave.