Z-wave network gets useless after a couple of hours

Ralph_Hees · December 28, 2019, 7:13am

I have my home automation running with the openhab 2.5.0-SNAPSHOT version created on 2019-12-15.
After I updated from a version that has been installed in November.
First everything worked, even the Nibe binding that had some bugs.

After a couple of hours z-wave stopped working. This is a part of the error log:

2019-12-27 22:07:15.906 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 0: Polling aborted due to exception
java.lang.NullPointerException: null
	at org.openhab.binding.zwave.handler.ZWaveThingHandler$1.run(ZWaveThingHandler.java:381) [bundleFile:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_222]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_222]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_222]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_222]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
2019-12-27 22:10:29.432 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@5c3f13' takes more than 5000ms.
2019-12-27 22:11:16.906 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.io.monitor.internal.EventLogger@b9971' takes more than 5000ms.
2019-12-27 22:12:22.208 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.events.internal.EventBridge@300f1e' takes more than 5000ms.
2019-12-27 22:12:27.724 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.events.internal.EventBridge@300f1e' takes more than 5000ms.
2019-12-27 22:12:32.898 [WARN ] [WaveSerialHandler$ZWaveReceiveThread] - Exception during ZWave thread. 
java.lang.IllegalStateException: Queue full
	at java.util.AbstractQueue.add(AbstractQueue.java:98) ~[?:1.8.0_222]
	at java.util.concurrent.ArrayBlockingQueue.add(ArrayBlockingQueue.java:312) ~[?:1.8.0_222]
	at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager.processReceiveMessage(ZWaveTransactionManager.java:417) ~[bundleFile:?]
	at org.openhab.binding.zwave.internal.protocol.ZWaveController.incomingPacket(ZWaveController.java:1072) ~[bundleFile:?]
	at org.openhab.binding.zwave.handler.ZWaveControllerHandler.incomingMessage(ZWaveControllerHandler.java:411) ~[bundleFile:?]
	at org.openhab.binding.zwave.handler.ZWaveSerialHandler$ZWaveReceiveThread.run(ZWaveSerialHandler.java:331) [bundleFile:?]
2019-12-27 22:12:48.044 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.CommunicationManager@c65d5c' takes more than 5000ms.
2019-12-27 22:13:51.344 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.CommunicationManager@c65d5c' takes more than 5000ms.
2019-12-27 22:14:19.177 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.OutOfMemoryError: unable to create new native thread
	at java.lang.Thread.start0(Native Method) ~[?:1.8.0_222]
	at java.lang.Thread.start(Thread.java:717) ~[?:1.8.0_222]
	at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:957) ~[?:1.8.0_222]
	at java.util.concurrent.ThreadPoolExecutor.ensurePrestart(ThreadPoolExecutor.java:1603) ~[?:1.8.0_222]
	at java.util.concurrent.ScheduledThreadPoolExecutor.reExecutePeriodic(ScheduledThreadPoolExecutor.java:350) ~[?:1.8.0_222]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:296) ~[?:1.8.0_222]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
2019-12-27 22:14:29.075 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@5c3f13' takes more than 5000ms.
2019-12-27 22:14:50.265 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler
2019-12-27 22:15:15.681 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.events.internal.EventBridge@300f1e' takes more than 5000ms.

And in the end it is like this:

2019-12-27 23:30:55.393 [INFO ] [arthome.model.script.slaapkamerGroot] - Triggered PAUSE
2019-12-27 23:31:03.495 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@5c3f13' takes more than 5000ms.
2019-12-27 23:31:12.112 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.CommunicationManager@c65d5c' takes more than 5000ms.
2019-12-27 23:32:22.444 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@5c3f13' takes more than 5000ms.
2019-12-27 23:32:52.080 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.io.monitor.internal.EventLogger@b9971' takes more than 5000ms.
2019-12-27 23:32:58.927 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.CommunicationManager@c65d5c' takes more than 5000ms.
2019-12-27 23:33:41.490 [WARN ] [su.litvak.chromecast.api.v2.Channel ] - Error while sending 'PING', caused by java.net.SocketException: Broken pipe (Write failed)
2019-12-27 23:35:11.114 [WARN ] [su.litvak.chromecast.api.v2.Channel ] - Error while sending 'PING', caused by javax.net.ssl.SSLException: Connection has been shutdown: javax.net.ssl.SSLException: java.net.SocketException: Broken pipe (Write failed)
2019-12-27 23:38:18.610 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 0: Polling aborted due to exception
java.lang.NullPointerException: null
	at org.openhab.binding.zwave.handler.ZWaveThingHandler$1.run(ZWaveThingHandler.java:381) [bundleFile:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_222]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_222]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_222]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_222]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
2019-12-28 04:09:59.991 [WARN ] [.util.thread.strategy.EatWhatYouKill] - 
java.lang.OutOfMemoryError: Java heap space
2019-12-28 07:13:12.140 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 0: Polling aborted due to exception
java.lang.NullPointerException: null
	at org.openhab.binding.zwave.handler.ZWaveThingHandler$1.run(ZWaveThingHandler.java:381) [bundleFile:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_222]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_222]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_222]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_222]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]

I now added -Xmx2048 as an extra java parameter. I hope this solves the most of my issues.
Looks like the memory usage is exceeding.

Ralph_Hees · December 28, 2019, 7:55am

Xmx was not a fix.
I see this behaviour happening a lot of times after each other:

2019-12-28 08:48:54.138 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node10' changed from ONLINE: Node initialising: PING to ONLINE: Node initialising: REQUEST_NIF

2019-12-28 08:48:54.140 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 64 to 65

2019-12-28 08:48:54.142 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 107 to 108

2019-12-28 08:48:54.473 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 108 to 109

2019-12-28 08:48:54.546 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 109 to 110

2019-12-28 08:48:54.627 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 110 to 111

2019-12-28 08:48:54.847 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 111 to 112

2019-12-28 08:48:55.004 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 112 to 113

2019-12-28 08:48:55.007 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 113 to 114

2019-12-28 08:48:55.514 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 114 to 115

2019-12-28 08:48:55.536 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 65 to 66

2019-12-28 08:48:55.542 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 115 to 116

2019-12-28 08:48:55.964 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 116 to 117

2019-12-28 08:48:55.982 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 66 to 67

2019-12-28 08:48:55.989 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 117 to 118

2019-12-28 08:48:56.312 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 118 to 119

2019-12-28 08:49:00.787 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node12' changed from ONLINE: Node initialising: PING to UNINITIALIZED

2019-12-28 08:49:00.850 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node12' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:00.851 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node10' changed from ONLINE: Node initialising: REQUEST_NIF to UNINITIALIZED

2019-12-28 08:49:00.934 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node10' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:00.939 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node11' changed from ONLINE: Node initialising: PING to UNINITIALIZED

2019-12-28 08:49:00.969 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node11' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:00.975 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node21' changed from ONLINE: Node initialising: PING to UNINITIALIZED

2019-12-28 08:49:01.004 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node21' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.009 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node14' changed from ONLINE: Node initialising: PING to UNINITIALIZED

2019-12-28 08:49:01.052 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node14' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.056 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node9' changed from ONLINE: Node initialising: PING to UNINITIALIZED

2019-12-28 08:49:01.100 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node9' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.104 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node26' changed from ONLINE: Node initialising: REQUEST_NIF to UNINITIALIZED

2019-12-28 08:49:01.207 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node26' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.210 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node23' changed from ONLINE: Node initialising: PING to UNINITIALIZED

2019-12-28 08:49:01.255 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node23' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.259 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node4' changed from ONLINE: Node initialising: PING to UNINITIALIZED

2019-12-28 08:49:01.307 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node4' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.311 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node3' changed from ONLINE: Node initialising: REQUEST_NIF to UNINITIALIZED

2019-12-28 08:49:01.333 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 67 to 68

2019-12-28 08:49:01.337 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 119 to 120

2019-12-28 08:49:01.389 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node3' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.393 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node18' changed from ONLINE to UNINITIALIZED

2019-12-28 08:49:01.455 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node18' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.460 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node2' changed from ONLINE: Node initialising: REQUEST_NIF to UNINITIALIZED

2019-12-28 08:49:01.487 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node2' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.490 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node6' changed from ONLINE: Node initialising: PING to UNINITIALIZED

2019-12-28 08:49:01.524 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node6' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.525 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node24' changed from ONLINE: Node initialising: PING to UNINITIALIZED

2019-12-28 08:49:01.569 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node24' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.574 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node20' changed from ONLINE: Node initialising: PING to UNINITIALIZED

2019-12-28 08:49:01.603 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node20' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.606 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node8' changed from ONLINE: Node initialising: PING to UNINITIALIZED

2019-12-28 08:49:01.628 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 120 to 121

2019-12-28 08:49:01.647 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node8' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.653 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node16' changed from ONLINE: Node initialising: REQUEST_NIF to UNINITIALIZED

2019-12-28 08:49:01.713 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node16' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.717 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node15' changed from ONLINE: Node initialising: PING to UNINITIALIZED

2019-12-28 08:49:01.763 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node15' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.766 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node27' changed from ONLINE: Node initialising: REQUEST_NIF to UNINITIALIZED

2019-12-28 08:49:01.810 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node27' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.814 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node5' changed from ONLINE: Node initialising: PING to UNINITIALIZED

2019-12-28 08:49:01.853 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node5' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.856 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node25' changed from ONLINE to UNINITIALIZED

2019-12-28 08:49:01.912 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node25' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.918 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node19' changed from ONLINE: Node initialising: PING to UNINITIALIZED

2019-12-28 08:49:01.969 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node19' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-12-28 08:49:01.972 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:b3d87b46' changed from ONLINE to UNINITIALIZED

2019-12-28 08:49:02.124 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 121 to 122

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

2019-12-28 08:49:05.122 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler

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

2019-12-28 08:49:05.165 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:b3d87b46' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

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

2019-12-28 08:49:11.060 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-action-mail'

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

2019-12-28 08:49:20.415 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node14' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2019-12-28 08:49:20.418 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node15' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2019-12-28 08:49:20.419 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node16' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2019-12-28 08:49:20.420 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node10' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2019-12-28 08:49:20.421 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node11' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2019-12-28 08:49:20.422 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node12' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2019-12-28 08:49:20.423 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node18' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2019-12-28 08:49:20.424 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node19' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2019-12-28 08:49:20.426 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node24' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2019-12-28 08:49:20.438 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node25' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2019-12-28 08:49:20.439 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node26' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2019-12-28 08:49:20.440 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node27' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2019-12-28 08:49:20.441 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node20' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

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

2019-12-28 08:49:20.455 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null

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

2019-12-28 08:49:20.774 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:b3d87b46' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-12-28 08:49:20.807 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:b3d87b46' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

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

2019-12-28 08:49:20.810 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'

2019-12-28 08:49:20.968 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized

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

2019-12-28 08:49:21.050 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node2' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-12-28 08:49:21.057 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node4' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-12-28 08:49:21.071 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 122 to 0

2019-12-28 08:49:21.073 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 68 to 0

2019-12-28 08:49:21.074 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 0 to 1

2019-12-28 08:49:21.086 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node2' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.100 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node4' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.138 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node19' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2019-12-28 08:49:21.139 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node16' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2019-12-28 08:49:21.143 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node14' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2019-12-28 08:49:21.145 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node15' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2019-12-28 08:49:21.149 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node3' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-12-28 08:49:21.182 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node19' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.219 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node15' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.247 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node16' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.248 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node9' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-12-28 08:49:21.259 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node3' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.262 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node6' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-12-28 08:49:21.267 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node5' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-12-28 08:49:21.272 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node8' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

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

2019-12-28 08:49:21.275 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller

2019-12-28 08:49:21.277 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.

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

2019-12-28 08:49:21.295 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node14' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.354 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node9' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.363 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node5' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.365 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node12' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2019-12-28 08:49:21.366 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node8' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.368 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node21' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-12-28 08:49:21.374 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node11' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2019-12-28 08:49:21.384 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node6' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.388 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node25' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2019-12-28 08:49:21.391 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node10' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2019-12-28 08:49:21.406 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node12' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.419 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node26' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2019-12-28 08:49:21.422 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node10' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.439 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node27' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2019-12-28 08:49:21.447 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node23' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-12-28 08:49:21.453 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node25' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.474 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node11' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.476 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node21' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.479 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node24' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2019-12-28 08:49:21.498 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node27' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.506 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node26' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.511 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node20' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2019-12-28 08:49:21.519 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node23' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.527 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node24' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.558 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node20' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:21.566 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node18' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2019-12-28 08:49:21.580 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node18' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2019-12-28 08:49:24.348 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 0 to 1

2019-12-28 08:49:24.352 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 1 to 2

2019-12-28 08:49:24.378 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 2 to 3

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

2019-12-28 08:49:24.408 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 4: Not initialized (ie node unknown), ignoring message.

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

2019-12-28 08:49:24.418 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 1 to 2

2019-12-28 08:49:24.421 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 3 to 4

2019-12-28 08:49:24.472 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 2 to 3

2019-12-28 08:49:24.474 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 4 to 5

2019-12-28 08:49:24.476 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 3 to 4

2019-12-28 08:49:24.478 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 5 to 6

2019-12-28 08:49:24.490 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 4 to 5

2019-12-28 08:49:24.519 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 6 to 7

2019-12-28 08:49:24.538 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 5 to 6

2019-12-28 08:49:24.632 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 7 to 8

2019-12-28 08:49:25.090 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 6 to 7

2019-12-28 08:49:25.111 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 8 to 9

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

2019-12-28 08:49:25.381 [WARN ] [ve.internal.protocol.ZWaveController] - NODE 28: Restore from config: Error. Data invalid, ignoring config.

2019-12-28 08:49:25.389 [WARN ] [ve.internal.protocol.ZWaveController] - NODE 30: Restore from config: Error. Data invalid, ignoring config.

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

2019-12-28 08:49:25.601 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 7 to 8

2019-12-28 08:49:25.605 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 9 to 10

2019-12-28 08:49:25.621 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 8 to 9

2019-12-28 08:49:25.626 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 10 to 11

2019-12-28 08:49:25.667 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 9 to 10

2019-12-28 08:49:25.670 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 11 to 12

2019-12-28 08:49:25.674 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 10 to 11

2019-12-28 08:49:25.697 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 12 to 13

2019-12-28 08:49:28.639 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:b3d87b46' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.674 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node19' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.675 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node2' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.676 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node16' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.678 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node4' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.679 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node3' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.687 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:b3d87b46' has been updated.

2019-12-28 08:49:28.756 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node14' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.762 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node15' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.790 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node9' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.792 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node6' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.794 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node5' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.797 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node8' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.810 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node12' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.811 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node10' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.822 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node11' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.824 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node27' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.834 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node25' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.835 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node26' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.837 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node23' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.839 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node24' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.841 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node21' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.844 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node18' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:28.846 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node20' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2019-12-28 08:49:29.171 [ome.event.ItemCommandEvent] - Item 'MeterProductionActual' received command 0.000

2019-12-28 08:49:29.348 [ome.event.ItemCommandEvent] - Item 'MeterDeliveryT2' received command 527.370

2019-12-28 08:49:29.387 [ome.event.ItemCommandEvent] - Item 'MeterProductionT1' received command 525.818

2019-12-28 08:49:29.419 [ome.event.ItemCommandEvent] - Item 'MeterProductionT2' received command 1193.616

2019-12-28 08:49:29.457 [ome.event.ItemCommandEvent] - Item 'MeterDeliveryT1' received command 894.795

2019-12-28 08:49:29.464 [vent.ItemStateChangedEvent] - MeterDeliveryT1 changed from 894.789 to 894.795

2019-12-28 08:49:29.509 [ome.event.ItemCommandEvent] - Item 'MeterDeliveryActual' received command 1.093

2019-12-28 08:49:29.515 [vent.ItemStateChangedEvent] - MeterDeliveryActual changed from 1.095 to 1.093

2019-12-28 08:49:29.841 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 13 to 14

2019-12-28 08:49:29.862 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 11 to 12

2019-12-28 08:49:29.868 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 14 to 15

2019-12-28 08:49:29.885 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node5' changed from ONLINE to ONLINE: Node initialising: PING

2019-12-28 08:49:29.893 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 12 to 13

2019-12-28 08:49:29.896 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 15 to 16

2019-12-28 08:49:29.904 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node10' changed from ONLINE to ONLINE: Node initialising: PING

2019-12-28 08:49:29.909 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 13 to 14

2019-12-28 08:49:29.916 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 16 to 17

2019-12-28 08:49:29.930 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node20' changed from ONLINE to ONLINE: Node initialising: PING

2019-12-28 08:49:29.933 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 14 to 15

2019-12-28 08:49:29.934 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 17 to 18

2019-12-28 08:49:29.939 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 15 to 16

2019-12-28 08:49:29.945 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 18 to 19

2019-12-28 08:49:29.963 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node11' changed from ONLINE to ONLINE: Node initialising: PING

2019-12-28 08:49:29.972 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node9' changed from ONLINE to ONLINE: Node initialising: PING

2019-12-28 08:49:29.974 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 16 to 17

2019-12-28 08:49:29.993 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 19 to 20

2019-12-28 08:49:29.995 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 17 to 18

2019-12-28 08:49:29.997 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node14' changed from ONLINE to ONLINE: Node initialising: PING

2019-12-28 08:49:30.002 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 20 to 21

2019-12-28 08:49:30.007 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node6' changed from ONLINE to ONLINE: Node initialising: PING

2019-12-28 08:49:30.013 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 18 to 19

2019-12-28 08:49:30.029 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 21 to 22

2019-12-28 08:49:30.031 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 19 to 20

2019-12-28 08:49:30.032 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 22 to 23

2019-12-28 08:49:30.048 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 20 to 21

2019-12-28 08:49:30.049 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 23 to 24

2019-12-28 08:49:30.054 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node3' changed from ONLINE to ONLINE: Node initialising: REQUEST_NIF

2019-12-28 08:49:30.073 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node24' changed from ONLINE to ONLINE: Node initialising: PING

2019-12-28 08:49:30.074 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 21 to 22

2019-12-28 08:49:30.076 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 24 to 25

2019-12-28 08:49:30.092 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node4' changed from ONLINE to ONLINE: Node initialising: PING

2019-12-28 08:49:30.102 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node18' changed from ONLINE to ONLINE: Node initialising: REQUEST_NIF

2019-12-28 08:49:30.110 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 22 to 23

2019-12-28 08:49:30.113 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node27' changed from ONLINE to ONLINE: Node initialising: REQUEST_NIF

2019-12-28 08:49:30.115 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 25 to 26

2019-12-28 08:49:30.123 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node2' changed from ONLINE to ONLINE: Node initialising: REQUEST_NIF

2019-12-28 08:49:30.124 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 23 to 24

2019-12-28 08:49:30.126 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 26 to 27

2019-12-28 08:49:30.129 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 24 to 25

2019-12-28 08:49:30.130 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 27 to 28

2019-12-28 08:49:30.131 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 25 to 26

2019-12-28 08:49:30.132 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 28 to 29

2019-12-28 08:49:30.139 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 26 to 27

2019-12-28 08:49:30.140 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 29 to 30

2019-12-28 08:49:30.143 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node19' changed from ONLINE to ONLINE: Node initialising: PING

2019-12-28 08:49:30.156 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 27 to 28

2019-12-28 08:49:30.159 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node26' changed from ONLINE to ONLINE: Node initialising: PING

2019-12-28 08:49:30.160 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 30 to 31

2019-12-28 08:49:30.162 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 28 to 29

2019-12-28 08:49:30.169 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node16' changed from ONLINE to ONLINE: Node initialising: PING

2019-12-28 08:49:30.175 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 31 to 32

2019-12-28 08:49:30.179 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 29 to 30

2019-12-28 08:49:30.181 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node8' changed from ONLINE to ONLINE: Node initialising: PING

2019-12-28 08:49:30.182 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 32 to 33

2019-12-28 08:49:30.187 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 30 to 31

2019-12-28 08:49:30.195 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 33 to 34

2019-12-28 08:49:30.209 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 31 to 32

2019-12-28 08:49:30.219 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 34 to 35

2019-12-28 08:49:30.223 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node21' changed from ONLINE to ONLINE: Node initialising: PING

2019-12-28 08:49:30.236 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 32 to 33

2019-12-28 08:49:30.242 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 35 to 36

2019-12-28 08:49:30.247 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node15' changed from ONLINE to ONLINE: Node initialising: PING

2019-12-28 08:49:30.249 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 33 to 34

2019-12-28 08:49:30.251 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 36 to 37

2019-12-28 08:49:30.254 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node23' changed from ONLINE to ONLINE: Node initialising: PING

2019-12-28 08:49:30.263 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 34 to 35

2019-12-28 08:49:30.266 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 37 to 38

2019-12-28 08:49:30.269 [vent.ItemStateChangedEvent] - ZWaveSerialController_FramesAcknowledged changed from 35 to 36

2019-12-28 08:49:30.272 [hingStatusInfoChangedEvent] - 'zwave:device:b3d87b46:node12' changed from ONLINE to ONLINE: Node initialising: PING

Bruce_Osborne · December 28, 2019, 10:02am

Check addons,cfg and especially addons.config for invalid addons. Restdocs moved from misc to ui. Yahoowesther is no longer valid.
The loader reloads all addons every minute trying to load the invalid one.

Ralph_Hees · December 28, 2019, 10:37am

Removing the mail action from the addons did the trick.
Also my old nodes that I cannot remove correctly anymore, did I add again and marked as failed nodes.

For now it looks fine. Let’s wait a day to see if it all stays working.

Bruce_Osborne · December 28, 2019, 10:53am

If those old zombie nodes are still stored in the controller network they can cause issues as devices try to route through them. That would be the next place to look.

I would also update to the 2.5 stable release.

Ralph_Hees · December 29, 2019, 6:41pm

Thank you for the information. I didn’t know there was a new stable release. I switched back to stable.
2.4 didn’t work well with my devices, so that’s why I switched to 2.5 snapshot version.

It now works fine.