Aeon Labs Multisensor 6, suddenly no longer detected, and not in database

I pressed the button on it, it flashed green. and I tried again, it comes up the same. not sure where the properties are… I apologies for my speed here… it’s over 1 year since I played with this stuff…

For the console password, look near the bottom of the Connect via SSH section.

I checked the manual, and I followed the instructions to wake it up. I get the same result. :frowning:

openhab-cli console

Logging in as openhab
habopPassword:

                      __  _____    ____      

____ ____ ___ ____ / / / / | / __ )
/ __ / __ / _ / __ / // / /| | / __ |
/ /
/ / // / __/ / / / __ / ___ |/ // /
_/ ./_// /// /// |/_____/
/_/ 2.3.0
Release Build

Hit ‘’ for a list of available commands
and ‘[cmd] --help’ for help on a specific command.
Hit ‘’ or type ‘system:shutdown’ or ‘logout’ to shutdown openHAB.

I also accidentally removed a dimmer switch in the process, and now this also shows up unknown… :frowning:

I suspect you were running 2.2.0 before you upgraded. I haven’t run 2.3.0 for many months now, but as a first step I would definitely recommend (from an SSH session on your RPi):

sudo systemctl stop openhab2
sudo rm -rf /var/lib/openhab2/{cache,tmp}/*
sudo systemctl start openhab2

Be aware that there are many reports of problems with Aeotec Multisensor 6 discovery, particularly when the device is battery powered. It may take many tries before you succeed. It has also been reported here that you can increase your likelihood of success by bringing your multisensor as close to your z-wave controller as possible.

thanks for that, I’ll give it a go…

I can only really suggest to get a debug log so that you can see what is happening. Without that, we can only speculate.

Personally, I would also suggest to update to the latest binding, although that in itself is unlikely to make any real difference, and you might be better off sticking with the current one to avoid changing multiple things at once.

Enable logging, restart the binding, and let’s see what the log shows…

good idea, you’ll have to remind me how to enable the debug loging

When you are in the console, write

 log:set DEBUG org.openhab.binding.zwave

and when you are done capturing some logs, replace DEBUG with INFO.

Hi guys,

So I followed all your advice, I enabled debugging. I ran the commands from Scott.

After restarting, the first thing I noticed is that now all my devices were in OFFLINE state. I also noticed that they all appeared in my inbox, but ALL were now showing as unknown. However, this time, when adding them (despite being unknown) most of them actually appear to come up in the things list correctly.

There are a few exceptions. My Vemmio dual switch comes up OFFLINE. I tried to exclude this. But oddly, after exclusion, it still appears in my inbox when I Search for Z-Wave devices. Somehow OpenHab is remembering this device incorrectly even when it’s excluded. I was expecting it not to be found. My plan was to exclude it, and then re-include it. When including it again, it still comes up OFFLINE. Even if I power the Vemmio off, and then try to scan, OpenHab still finds it! Isn’t this a bit odd?

The good news is that I recovered my multiSensors, and nano dimmer. If I can fix the Vemmio, then we’ll be back on track.

Here are the logs:
Event:
2018-12-13 09:00:49.957 [hingStatusInfoChangedEvent] - ‘zwave:device:0abe5fdb:node12’ changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to REMOVING
2018-12-13 09:00:49.962 [hingStatusInfoChangedEvent] - ‘zwave:device:0abe5fdb:node12’ changed from REMOVING to REMOVED
2018-12-13 09:00:50.204 [hingStatusInfoChangedEvent] - ‘zwave:device:0abe5fdb:node12’ changed from REMOVED to UNINITIALIZED
2018-12-13 09:00:50.296 [hingStatusInfoChangedEvent] - ‘zwave:device:0abe5fdb:node12’ changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2018-12-13 09:01:07.521 [home.event.InboxAddedEvent] - Discovery Result with UID ‘zwave:device:0abe5fdb:node12’ has been added.
2018-12-13 09:02:57.923 [me.event.InboxRemovedEvent] - Discovery Result with UID ‘zwave:device:0abe5fdb:node12’ has been removed.
2018-12-13 09:02:57.963 [hingStatusInfoChangedEvent] - ‘zwave:device:0abe5fdb:node12’ changed from UNINITIALIZED to INITIALIZING
2018-12-13 09:02:57.976 [hingStatusInfoChangedEvent] - ‘zwave:device:0abe5fdb:node12’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2018-12-13 09:02:57.987 [hingStatusInfoChangedEvent] - ‘zwave:device:0abe5fdb:node12’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to UNINITIALIZED
2018-12-13 09:02:58.010 [hingStatusInfoChangedEvent] - ‘zwave:device:0abe5fdb:node12’ changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2018-12-13 09:02:58.154 [hingStatusInfoChangedEvent] - ‘zwave:device:0abe5fdb:node12’ changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
2018-12-13 09:02:58.159 [hingStatusInfoChangedEvent] - ‘zwave:device:0abe5fdb:node12’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2018-12-13 09:02:58.174 [hingStatusInfoChangedEvent] - ‘zwave:device:0abe5fdb:node12’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller
2018-12-13 09:02:58.267 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:0abe5fdb:node12’ has been updated.
2018-12-13 09:02:58.361 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:0abe5fdb:node12’ has been updated.
2018-12-13 09:02:58.453 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:0abe5fdb:node12’ has been updated.
2018-12-13 09:02:58.689 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:0abe5fdb:node12’ has been updated.
2018-12-13 09:05:53.341 [hingStatusInfoChangedEvent] - ‘zwave:device:0abe5fdb:node12’ changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to REMOVING
2018-12-13 09:05:53.353 [hingStatusInfoChangedEvent] - ‘zwave:device:0abe5fdb:node12’ changed from REMOVING to REMOVED
2018-12-13 09:05:53.566 [hingStatusInfoChangedEvent] - ‘zwave:device:0abe5fdb:node12’ changed from REMOVED to UNINITIALIZED
2018-12-13 09:05:53.668 [hingStatusInfoChangedEvent] - ‘zwave:device:0abe5fdb:node12’ changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2018-12-13 09:07:51.668 [home.event.InboxAddedEvent] - Discovery Result with UID ‘zwave:device:0abe5fdb:node12’ has been added.
2018-12-13 09:08:07.988 [me.event.InboxRemovedEvent] - Discovery Result with UID ‘zwave:device:0abe5fdb:node12’ has been removed.
2018-12-13 09:08:20.906 [home.event.InboxAddedEvent] - Discovery Result with UID ‘zwave:device:0abe5fdb:node12’ has been added.
2018-12-13 09:10:01.654 [me.event.InboxRemovedEvent] - Discovery Result with UID ‘zwave:device:0abe5fdb:node12’ has been removed.
2018-12-13 09:10:49.938 [home.event.InboxAddedEvent] - Discovery Result with UID ‘zwave:device:0abe5fdb:node12’ has been added.
2018-12-13 09:21:07.271 [me.event.InboxRemovedEvent] - Discovery Result with UID ‘zwave:device:0abe5fdb:node12’ has been removed.
2018-12-13 09:21:21.495 [home.event.InboxAddedEvent] - Discovery Result with UID ‘zwave:device:0abe5fdb:node12’ has been added.

2018-12-13 09:21:21.484 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 12: Checking zwave:vemmio_ds100_00_000
2018-12-13 09:21:21.487 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 12: Device discovery resolved to thingType zwave:vemmio_ds100_00_000

OpenHAb:
2018-12-13 09:02:58.548 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:0abe5fdb:node12:meter_powerfactor1
2018-12-13 09:02:58.550 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:0abe5fdb:node12:meter_powerfactor1
2018-12-13 09:02:58.552 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:meter_powerfactor1
2018-12-13 09:02:58.554 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:0abe5fdb:node12:meter_voltage1
2018-12-13 09:02:58.556 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:0abe5fdb:node12:meter_voltage1
2018-12-13 09:02:58.558 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:0abe5fdb:node12:meter_voltage1
2018-12-13 09:02:58.560 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:meter_voltage1
2018-12-13 09:02:58.562 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:0abe5fdb:node12:meter_current1
2018-12-13 09:02:58.564 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:0abe5fdb:node12:meter_current1
2018-12-13 09:02:58.565 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:0abe5fdb:node12:meter_current1
2018-12-13 09:02:58.567 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:meter_current1
2018-12-13 09:02:58.569 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:0abe5fdb:node12:meter_watts1
2018-12-13 09:02:58.571 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:0abe5fdb:node12:meter_watts1
2018-12-13 09:02:58.573 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:0abe5fdb:node12:meter_watts1
2018-12-13 09:02:58.575 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:meter_watts1
2018-12-13 09:02:58.577 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:0abe5fdb:node12:meter_kwh1
2018-12-13 09:02:58.579 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:0abe5fdb:node12:meter_kwh1
2018-12-13 09:02:58.581 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:0abe5fdb:node12:meter_kwh1
2018-12-13 09:02:58.583 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:meter_kwh1
2018-12-13 09:02:58.585 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:0abe5fdb:node12:switch_binary2
2018-12-13 09:02:58.587 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:0abe5fdb:node12:switch_binary2
2018-12-13 09:02:58.589 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:0abe5fdb:node12:switch_binary2
2018-12-13 09:02:58.591 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:switch_binary2
2018-12-13 09:02:58.593 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:switch_binary2
2018-12-13 09:02:58.595 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:0abe5fdb:node12:meter_powerfactor2
2018-12-13 09:02:58.597 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:0abe5fdb:node12:meter_powerfactor2
2018-12-13 09:02:58.599 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:0abe5fdb:node12:meter_powerfactor2
2018-12-13 09:02:58.601 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:meter_powerfactor2
2018-12-13 09:02:58.603 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:0abe5fdb:node12:meter_voltage2
2018-12-13 09:02:58.605 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:0abe5fdb:node12:meter_voltage2
2018-12-13 09:02:58.607 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:0abe5fdb:node12:meter_voltage2
2018-12-13 09:02:58.609 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:meter_voltage2
2018-12-13 09:02:58.611 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:0abe5fdb:node12:meter_current2
2018-12-13 09:02:58.613 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:0abe5fdb:node12:meter_current2
2018-12-13 09:02:58.615 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:0abe5fdb:node12:meter_current2
2018-12-13 09:02:58.617 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:meter_current2
2018-12-13 09:02:58.618 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:0abe5fdb:node12:meter_watts2
2018-12-13 09:02:58.620 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:0abe5fdb:node12:meter_watts2
2018-12-13 09:02:58.622 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:0abe5fdb:node12:meter_watts2
2018-12-13 09:02:58.624 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:meter_watts2
2018-12-13 09:02:58.626 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:0abe5fdb:node12:meter_kwh2
2018-12-13 09:02:58.628 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:0abe5fdb:node12:meter_kwh2
2018-12-13 09:02:58.630 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:0abe5fdb:node12:meter_kwh2
2018-12-13 09:02:58.632 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:meter_kwh2
2018-12-13 09:02:58.634 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:0abe5fdb:node12:switch_binary3
2018-12-13 09:02:58.636 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:0abe5fdb:node12:switch_binary3
2018-12-13 09:02:58.638 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:0abe5fdb:node12:switch_binary3
2018-12-13 09:02:58.639 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:switch_binary3
2018-12-13 09:02:58.641 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:switch_binary3
2018-12-13 09:02:58.643 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:0abe5fdb:node12:meter_powerfactor3
2018-12-13 09:02:58.645 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:0abe5fdb:node12:meter_powerfactor3
2018-12-13 09:02:58.647 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:0abe5fdb:node12:meter_powerfactor3
2018-12-13 09:02:58.649 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:meter_powerfactor3
2018-12-13 09:02:58.651 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:0abe5fdb:node12:meter_voltage3
2018-12-13 09:02:58.653 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:0abe5fdb:node12:meter_voltage3
2018-12-13 09:02:58.655 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:0abe5fdb:node12:meter_voltage3
2018-12-13 09:02:58.657 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:meter_voltage3
2018-12-13 09:02:58.659 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:0abe5fdb:node12:meter_current3
2018-12-13 09:02:58.661 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:0abe5fdb:node12:meter_current3
2018-12-13 09:02:58.663 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:0abe5fdb:node12:meter_current3
2018-12-13 09:02:58.665 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:meter_current3
2018-12-13 09:02:58.666 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:0abe5fdb:node12:meter_watts3
2018-12-13 09:02:58.668 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:0abe5fdb:node12:meter_watts3
2018-12-13 09:02:58.670 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:0abe5fdb:node12:meter_watts3
2018-12-13 09:02:58.672 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:meter_watts3
2018-12-13 09:02:58.674 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:0abe5fdb:node12:meter_kwh3
2018-12-13 09:02:58.676 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:0abe5fdb:node12:meter_kwh3
2018-12-13 09:02:58.678 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:0abe5fdb:node12:meter_kwh3
2018-12-13 09:02:58.680 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:0abe5fdb:node12:meter_kwh3
2018-12-13 09:07:51.667 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘zwave:device:0abe5fdb:node12’ to inbox.
2018-12-13 09:08:20.905 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘zwave:device:0abe5fdb:node12’ to inbox.
2018-12-13 09:10:49.938 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘zwave:device:0abe5fdb:node12’ to inbox.
2018-12-13 09:21:21.494 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘zwave:device:0abe5fdb:node12’ to inbox.

Some more information. In attempting to recover the Vemmio, I restarted openhab. After restarting, All the things that I recently added and were working, are now showing up uninitialised. :(. I waited quite a long time too. Oddly also, they now show up again in the inbox, even though I already added them.

I’m still getting nowhere. Every time I reboot, or power cycle the RaspberryPi, All my devices come up offline. They all appear in the inbox again, as unknown. this time I noticed the following warning in the log after a clean power on.
2018-12-14 09:55:23.004 [WARN ] [org.apache.felix.fileinstall ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.zwave-2.2.0-SNAPSHOT.jar
org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.zwave [187]
Another singleton bundle selected: osgi.identity; type=“osgi.bundle”; version:Version=“2.3.0”; osgi.identity=“org.openhab.binding.zwave”; singleton:=“true”

    at org.eclipse.osgi.container.Module.start(Module.java:444) [?:?]
    at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) [?:?]
    at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1260) [9:org.apache.felix.fileinstall:3.6.4]
    at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1233) [9:org.apache.felix.fileinstall:3.6.4]
    at org.apache.felix.fileinstall.internal.DirectoryWatcher.startAllBundles(DirectoryWatcher.java:1221) [9:org.apache.felix.fileinstall:3.6.4]
    at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:515) [9:org.apache.felix.fileinstall:3.6.4]
    at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365) [9:org.apache.felix.fileinstall:3.6.4]
    at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316) [9:org.apache.felix.fileinstall:3.6.4]

(END)

This means you have two zwave bindings installed. You can prove this with list -s|grep zwave in the Karaf console. Delete any zwave jars in /addons, if you’ve also installed through Paper UI or addons.cfg. If you are using a manual binding install, uninstall from the other places I just mentioned, and remove any extra zwave jars from /addons/.

Hi Scott,

Thanks for your input. I"m trying to get my head around what you said.

I tried the command:

list -s|grep zwave
187 â Installed â 80 â 2.2.0.201709102120 â org.openhab.binding.zwave
208 â Active â 80 â 2.3.0 â org.openhab.binding.zwave

indeed, there are two. So now the question is, how do I know which is the right one, and then how do I remove the unwanted one?

I checked in the addons/ folder:

sudo ls /srv/openhab2-sys/addons/
old org.openhab.binding.velux-2.2.0-SNAPSHOT.jar org.openhab.binding.zwave-2.2.0-SNAPSHOT.jar README

there is a single jar there. do you think I should remove this 2.2.0 wave binding? do you know why the 2.3.0 z-wave binding was added when I upgraded?

do you think this will fix the mess? or will I have to completely remove all things and start a fresh? If I have to do that, is there a simple way to clean up totally all hidden files of the things so that they are not being recognised, even when they are not part of the network…

thanks for your help.

Jonathan

If you’re using OH 2.3, then yes, remove the 2.2 zwave binding. Just delete the jar file from /addons. You may need to restart OH (I don’t remember how 2.3 behaved). Try that and see if it helps. If not there is more that can be done.

Hi,

Ok, I have done that now, and restarted the server. I deleted all the things and started from scratch. I added the first three switches and nano dimmer (Aeon Labs), immediately after adding them, they appear to work. I then added the Vemmio…

Z-Wave Node 20: DS100 Double Switch in a dual relay in-wall module - VMC OFFLINE
DS100 Double Switch in a dual relay in-wall module.
zwave:device:98d8c8f7:node20

It still comes up immediately offline as before, although it was working fine under 2.2.0.
I noticed that there is a log message saying that the node is dead, but how can this node be detected at all, if it’s dead, it doesn’t make any sense. Also I don’t understand why it gets detected if I exclude it from the z-wave network. Something a bit fishy…

The log:

2018-12-15 14:11:20.420 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 12: Checking zwave:vemmio_ds100_00_000

2018-12-15 14:11:20.425 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 12: Device already known - properties will be updated.

2018-12-15 14:11:20.431 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 12: Device discovery resolved to thingType zwave:vemmio_ds100_00_000

2018-12-15 14:11:20.446 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Starting initialisation from EMPTYNODE

2018-12-15 14:11:20.452 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - EMPTYNODE: queue length(1), free to send(false)

2018-12-15 14:11:20.453 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Initialisation retry timer started 5000

2018-12-15 14:11:20.461 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - queued packet. Queue length is 1

2018-12-15 14:11:20.464 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 12: Init node thread finished

2018-12-15 14:11:25.454 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Stage EMPTYNODE. Initialisation retry timer triggered. Increased to 10000

2018-12-15 14:11:25.456 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - EMPTYNODE: queue length(0), free to send(false)

2018-12-15 14:11:25.457 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Initialisation retry timer started 10000

2018-12-15 14:11:25.458 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: loop - EMPTYNODE try 1: stageAdvanced(false)

2018-12-15 14:11:25.459 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: Initialisation starting

2018-12-15 14:11:25.459 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - advancing to PROTOINFO

2018-12-15 14:11:25.461 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: loop - PROTOINFO try 0: stageAdvanced(true)

2018-12-15 14:11:25.461 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: PROTOINFO - send IdentifyNode

2018-12-15 14:11:25.462 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - queued packet. Queue length is 1

2018-12-15 14:11:28.411 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: ProtocolInfo

2018-12-15 14:11:28.413 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Listening = true

2018-12-15 14:11:28.414 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Routing = true

2018-12-15 14:11:28.415 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Beaming = true

2018-12-15 14:11:28.416 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Version = 4

2018-12-15 14:11:28.417 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: FLIRS = false

2018-12-15 14:11:28.418 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Security = false

2018-12-15 14:11:28.432 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Max Baud = 40000

2018-12-15 14:11:28.434 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Basic = Routing Slave

2018-12-15 14:11:28.435 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Generic = Binary Switch

2018-12-15 14:11:28.437 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Specific = Binary Power Switch

2018-12-15 14:11:28.438 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Creating new instance of command class NO_OPERATION

2018-12-15 14:11:28.440 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class NO_OPERATION, endpoint null created

2018-12-15 14:11:28.441 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Version = 1, version set. Enabling extra functionality.

2018-12-15 14:11:28.443 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Creating new instance of command class BASIC

2018-12-15 14:11:28.444 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class BASIC, endpoint null created

2018-12-15 14:11:28.446 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Creating new instance of command class SWITCH_BINARY

2018-12-15 14:11:28.448 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class SWITCH_BINARY, endpoint null created

2018-12-15 14:11:28.456 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - PROTOINFO: Transaction complete (IdentifyNode:Request) success(true)

2018-12-15 14:11:28.458 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - checking initialisation queue. Queue size 1.

2018-12-15 14:11:28.460 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - message removed from queue. Queue size 0.

2018-12-15 14:11:28.462 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - PROTOINFO: queue length(0), free to send(true)

2018-12-15 14:11:28.463 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Initialisation retry timer started 5000

2018-12-15 14:11:28.465 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: loop - PROTOINFO try 1: stageAdvanced(false)

2018-12-15 14:11:28.467 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - advancing to INIT_NEIGHBORS

2018-12-15 14:11:28.469 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: loop - INIT_NEIGHBORS try 0: stageAdvanced(true)

2018-12-15 14:11:28.471 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: INIT_NEIGHBORS - send RoutingInfo

2018-12-15 14:11:28.472 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 12: Request routing info

2018-12-15 14:11:28.473 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - queued packet. Queue length is 1

2018-12-15 14:11:28.901 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 12: Got NodeRoutingInfo request.

2018-12-15 14:11:28.902 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 12: Neighbor nodes: 1 7 8 9 10 15 16

2018-12-15 14:11:28.910 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - INIT_NEIGHBORS: Transaction complete (GetRoutingInfo:Request) success(true)

2018-12-15 14:11:28.911 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - checking initialisation queue. Queue size 1.

2018-12-15 14:11:28.913 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - message removed from queue. Queue size 0.

2018-12-15 14:11:28.914 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - INIT_NEIGHBORS: queue length(0), free to send(true)

2018-12-15 14:11:28.915 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Initialisation retry timer started 5000

2018-12-15 14:11:28.916 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: loop - INIT_NEIGHBORS try 1: stageAdvanced(false)

2018-12-15 14:11:28.918 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - advancing to FAILED_CHECK

2018-12-15 14:11:28.920 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: loop - FAILED_CHECK try 0: stageAdvanced(true)

2018-12-15 14:11:28.922 [DEBUG] [rialmessage.IsFailedNodeMessageClass] - NODE 12: Requesting IsFailedNode status from controller.

2018-12-15 14:11:28.923 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - queued packet. Queue length is 1

2018-12-15 14:11:29.238 [WARN ] [rialmessage.IsFailedNodeMessageClass] - NODE 12: Is currently marked as failed by the controller!

2018-12-15 14:11:29.243 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - FAILED_CHECK: Transaction complete (IsFailedNodeID:Request) success(true)

2018-12-15 14:11:29.243 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - checking initialisation queue. Queue size 1.

2018-12-15 14:11:29.244 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - message removed from queue. Queue size 0.

2018-12-15 14:11:29.245 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - FAILED_CHECK: queue length(0), free to send(true)

2018-12-15 14:11:29.246 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Initialisation retry timer started 5000

2018-12-15 14:11:29.247 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: loop - FAILED_CHECK try 1: stageAdvanced(false)

2018-12-15 14:11:29.247 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - advancing to WAIT

2018-12-15 14:11:29.249 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: loop - WAIT try 0: stageAdvanced(true)

2018-12-15 14:11:29.250 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: WAIT - Listening=true, FrequentlyListening=false

2018-12-15 14:11:29.251 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: WAIT - Advancing

2018-12-15 14:11:29.252 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - advancing to PING

2018-12-15 14:11:29.253 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: loop - PING try 0: stageAdvanced(true)

2018-12-15 14:11:29.254 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: PING - send NoOperation

2018-12-15 14:11:29.255 [DEBUG] [ndclass.ZWaveNoOperationCommandClass] - NODE 12: Creating new message for command No Operation

2018-12-15 14:11:29.256 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - queued packet. Queue length is 1

2018-12-15 14:11:34.292 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Stage PING. Initialisation retry timer triggered. Increased to 10000

2018-12-15 14:11:34.294 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - PING: queue length(0), free to send(false)

2018-12-15 14:11:34.297 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Initialisation retry timer started 10000

2018-12-15 14:11:34.298 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: loop - PING try 1: stageAdvanced(false)

2018-12-15 14:11:34.299 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: PING - send NoOperation

2018-12-15 14:11:34.300 [DEBUG] [ndclass.ZWaveNoOperationCommandClass] - NODE 12: Creating new message for command No Operation

2018-12-15 14:11:34.302 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - queued packet. Queue length is 1

2018-12-15 14:11:44.296 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Stage PING. Initialisation retry timer triggered. Increased to 20000

2018-12-15 14:11:44.297 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - PING: queue length(0), free to send(false)

2018-12-15 14:11:44.298 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Initialisation retry timer started 20000

2018-12-15 14:11:44.300 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: loop - PING try 2: stageAdvanced(false)

2018-12-15 14:11:44.301 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: PING - send NoOperation

2018-12-15 14:11:44.302 [DEBUG] [ndclass.ZWaveNoOperationCommandClass] - NODE 12: Creating new message for command No Operation

2018-12-15 14:11:44.304 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - queued packet. Queue length is 1

2018-12-15 14:12:04.298 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Stage PING. Initialisation retry timer triggered. Increased to 40000

2018-12-15 14:12:04.299 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - PING: queue length(0), free to send(false)

2018-12-15 14:12:04.301 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Initialisation retry timer started 40000

2018-12-15 14:12:04.302 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: loop - PING try 3: stageAdvanced(false)

2018-12-15 14:12:04.303 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: PING - send NoOperation

2018-12-15 14:12:04.305 [DEBUG] [ndclass.ZWaveNoOperationCommandClass] - NODE 12: Creating new message for command No Operation

2018-12-15 14:12:04.307 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - queued packet. Queue length is 1

2018-12-15 14:12:25.372 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Controller status changed to ONLINE.

2018-12-15 14:12:25.374 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Controller is ONLINE. Starting device initialisation.

2018-12-15 14:12:25.425 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Updating node properties.

2018-12-15 14:12:25.426 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Updating node properties. MAN=783

2018-12-15 14:12:25.428 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Updating node properties. MAN=783. SET. Was 783

2018-12-15 14:12:25.429 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Properties synchronised

2018-12-15 14:12:25.469 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Property to update: config_10_1, 1, 1

2018-12-15 14:12:25.470 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Property to update: group_1, [], null

2018-12-15 14:12:25.471 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Properties synchronised

2018-12-15 14:12:25.508 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising Thing Node…

2018-12-15 14:12:25.510 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:switch_binary

2018-12-15 14:12:25.511 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:switch_binary

2018-12-15 14:12:25.512 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:switch_binary

2018-12-15 14:12:25.514 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:switch_binary

2018-12-15 14:12:25.515 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:switch_binary

2018-12-15 14:12:25.517 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:scene_number

2018-12-15 14:12:25.518 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:scene_number

2018-12-15 14:12:25.520 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:scene_number

2018-12-15 14:12:25.521 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:scene_number

2018-12-15 14:12:25.522 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_powerfactor

2018-12-15 14:12:25.524 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_powerfactor

2018-12-15 14:12:25.525 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_powerfactor

2018-12-15 14:12:25.526 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_powerfactor

2018-12-15 14:12:25.527 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_voltage

2018-12-15 14:12:25.528 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_voltage

2018-12-15 14:12:25.529 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_voltage

2018-12-15 14:12:25.530 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_voltage

2018-12-15 14:12:25.531 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_current

2018-12-15 14:12:25.533 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_current

2018-12-15 14:12:25.534 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_current

2018-12-15 14:12:25.535 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_current

2018-12-15 14:12:25.536 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_watts

2018-12-15 14:12:25.538 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_watts

2018-12-15 14:12:25.540 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_watts

2018-12-15 14:12:25.541 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_watts

2018-12-15 14:12:25.543 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_kwh

2018-12-15 14:12:25.544 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_kwh

2018-12-15 14:12:25.546 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_kwh

2018-12-15 14:12:25.547 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_kwh

2018-12-15 14:12:25.549 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:alarm_general

2018-12-15 14:12:25.550 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:alarm_general

2018-12-15 14:12:25.552 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:alarm_general

2018-12-15 14:12:25.553 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:alarm_general

2018-12-15 14:12:25.555 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:switch_binary1

2018-12-15 14:12:25.556 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:switch_binary1

2018-12-15 14:12:25.558 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:switch_binary1

2018-12-15 14:12:25.559 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:switch_binary1

2018-12-15 14:12:25.561 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:switch_binary1

2018-12-15 14:12:25.562 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_powerfactor1

2018-12-15 14:12:25.564 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_powerfactor1

2018-12-15 14:12:25.565 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_powerfactor1

2018-12-15 14:12:25.567 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_powerfactor1

2018-12-15 14:12:25.569 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_voltage1

2018-12-15 14:12:25.570 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_voltage1

2018-12-15 14:12:25.572 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_voltage1

2018-12-15 14:12:25.573 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_voltage1

2018-12-15 14:12:25.574 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_current1

2018-12-15 14:12:25.576 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_current1

2018-12-15 14:12:25.578 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_current1

2018-12-15 14:12:25.579 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_current1

2018-12-15 14:12:25.581 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_watts1

2018-12-15 14:12:25.582 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_watts1

2018-12-15 14:12:25.584 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_watts1

2018-12-15 14:12:25.585 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_watts1

2018-12-15 14:12:25.586 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_kwh1

2018-12-15 14:12:25.588 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_kwh1

2018-12-15 14:12:25.589 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_kwh1

2018-12-15 14:12:25.591 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_kwh1

2018-12-15 14:12:25.592 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:switch_binary2

2018-12-15 14:12:25.594 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:switch_binary2

2018-12-15 14:12:25.595 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:switch_binary2

2018-12-15 14:12:25.597 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:switch_binary2

2018-12-15 14:12:25.598 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:switch_binary2

2018-12-15 14:12:25.600 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_powerfactor2

2018-12-15 14:12:25.601 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_powerfactor2

2018-12-15 14:12:25.603 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_powerfactor2

2018-12-15 14:12:25.604 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_powerfactor2

2018-12-15 14:12:25.605 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_voltage2

2018-12-15 14:12:25.607 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_voltage2

2018-12-15 14:12:25.608 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_voltage2

2018-12-15 14:12:25.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_voltage2

2018-12-15 14:12:25.611 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_current2

2018-12-15 14:12:25.613 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_current2

2018-12-15 14:12:25.621 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_current2

2018-12-15 14:12:25.622 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_current2

2018-12-15 14:12:25.623 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_watts2

2018-12-15 14:12:25.625 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_watts2

2018-12-15 14:12:25.626 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_watts2

2018-12-15 14:12:25.627 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_watts2

2018-12-15 14:12:25.628 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_kwh2

2018-12-15 14:12:25.629 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_kwh2

2018-12-15 14:12:25.630 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_kwh2

2018-12-15 14:12:25.631 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_kwh2

2018-12-15 14:12:25.632 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:switch_binary3

2018-12-15 14:12:25.633 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:switch_binary3

2018-12-15 14:12:25.635 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:switch_binary3

2018-12-15 14:12:25.636 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:switch_binary3

2018-12-15 14:12:25.637 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:switch_binary3

2018-12-15 14:12:25.638 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_powerfactor3

2018-12-15 14:12:25.641 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_powerfactor3

2018-12-15 14:12:25.642 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_powerfactor3

2018-12-15 14:12:25.643 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_powerfactor3

2018-12-15 14:12:25.644 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_voltage3

2018-12-15 14:12:25.646 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_voltage3

2018-12-15 14:12:25.647 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_voltage3

2018-12-15 14:12:25.648 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_voltage3

2018-12-15 14:12:25.649 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_current3

2018-12-15 14:12:25.651 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_current3

2018-12-15 14:12:25.652 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_current3

2018-12-15 14:12:25.653 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_current3

2018-12-15 14:12:25.654 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_watts3

2018-12-15 14:12:25.655 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_watts3

2018-12-15 14:12:25.656 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_watts3

2018-12-15 14:12:25.657 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_watts3

2018-12-15 14:12:25.658 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising channel zwave:device:ebfa1e9d:node12:meter_kwh3

2018-12-15 14:12:25.660 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:ebfa1e9d:node12:meter_kwh3

2018-12-15 14:12:25.661 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising poll channel zwave:device:ebfa1e9d:node12:meter_kwh3

2018-12-15 14:12:25.662 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:ebfa1e9d:node12:meter_kwh3

2018-12-15 14:12:25.663 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Polling intialised at 1800 seconds - start in 1800000 milliseconds.

2018-12-15 14:12:44.301 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Stage PING. Initialisation retry timer triggered. Increased to 80000

2018-12-15 14:12:44.303 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - PING: queue length(0), free to send(false)

2018-12-15 14:12:44.304 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Initialisation retry timer started 80000

2018-12-15 14:12:44.305 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: loop - PING try 4: stageAdvanced(false)

2018-12-15 14:12:44.306 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: PING - send NoOperation

2018-12-15 14:12:44.307 [DEBUG] [ndclass.ZWaveNoOperationCommandClass] - NODE 12: Creating new message for command No Operation

2018-12-15 14:12:44.308 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - queued packet. Queue length is 1

2018-12-15 14:13:13.085 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 12: Sending REQUEST Message = 01 08 00 13 0C 01 00 25 13 DF

2018-12-15 14:13:13.107 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: Sent Data successfully placed on stack.

2018-12-15 14:13:18.087 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 12: Timeout while sending message. Requeueing - 0 attempts left!

2018-12-15 14:13:18.090 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: Node is DEAD. Dropping message.

2018-12-15 14:13:18.100 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 12: Sending REQUEST Message = 01 08 00 13 0C 01 00 25 13 DF

2018-12-15 14:13:18.887 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: Sent Data was not placed on stack due to error 0.

2018-12-15 14:13:20.297 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: SendData Request. CallBack ID = 19, Status = Transmission complete, no ACK received(1)

2018-12-15 14:13:20.301 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: Node is DEAD. Dropping message.

2018-12-15 14:13:20.307 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - PING: Transaction complete (SendData:Request) success(false)

2018-12-15 14:13:20.311 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent

2018-12-15 14:13:20.314 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 12: Response processed after 2212ms/2687ms.

2018-12-15 14:14:04.304 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Stage PING. Initialisation retry timer triggered. Increased to 160000

2018-12-15 14:14:04.306 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - PING: queue length(0), free to send(false)

2018-12-15 14:14:04.307 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Initialisation retry timer started 160000

2018-12-15 14:14:04.309 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: loop - PING try 5: stageAdvanced(false)

2018-12-15 14:14:04.310 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: PING - send NoOperation

2018-12-15 14:14:04.312 [DEBUG] [ndclass.ZWaveNoOperationCommandClass] - NODE 12: Creating new message for command No Operation

2018-12-15 14:14:04.314 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - queued packet. Queue length is 1

The Vemmio z-wave device refuses to work and refuses to be removed. In the search it shows up with 3 different node ids! trying to exclude it makes no difference, it always shows up, but none of the three nodes work when I add them. They all show Offline, and in the log it says they are dead. I tried to use HabMin to remove them from the controller, but they still show up in the search. Any ideas?

V

Z-Wave Node 12: DS100 Double Switch in a dual relay in-wall module. OFFLINE

DS100 Double Switch in a dual relay in-wall module.

zwave:device:ebfa1e9d:node12

edit delete

V

Z-Wave Node 19: DS100 Double Switch in a dual relay in-wall module. OFFLINE

DS100 Double Switch in a dual relay in-wall module.

zwave:device:ebfa1e9d:node19

edit delete

V

Z-Wave Node 20: DS100 Double Switch in a dual relay in-wall module. OFFLINE

DS100 Double Switch in a dual relay in-wall module.

zwave:device:ebfa1e9d:node20

Log messages:

2018-12-15 14:28:02.981 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node20’ changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to UNINITIALIZED
2018-12-15 14:28:03.067 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node20’ changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2018-12-15 14:28:05.850 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node19’ changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to UNINITIALIZED
2018-12-15 14:28:05.949 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node19’ changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2018-12-15 14:28:43.435 [home.event.InboxAddedEvent] - Discovery Result with UID ‘zwave:device:ebfa1e9d:node12’ has been added.
2018-12-15 14:28:48.180 [home.event.InboxAddedEvent] - Discovery Result with UID ‘zwave:device:ebfa1e9d:node19’ has been added.
2018-12-15 14:28:49.249 [home.event.InboxAddedEvent] - Discovery Result with UID ‘zwave:device:ebfa1e9d:node20’ has been added.
2018-12-15 14:28:49.275 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@1627fa3
2018-12-15 14:28:49.475 [me.event.InboxRemovedEvent] - Discovery Result with UID ‘zwave:device:ebfa1e9d:node12’ has been removed.
2018-12-15 14:28:49.507 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node12’ changed from UNINITIALIZED to INITIALIZING
2018-12-15 14:28:49.512 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node12’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2018-12-15 14:28:49.523 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node12’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to UNINITIALIZED
2018-12-15 14:28:49.544 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node12’ changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2018-12-15 14:28:49.717 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node12’ changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
2018-12-15 14:28:49.727 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node12’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2018-12-15 14:28:49.739 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node12’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller
2018-12-15 14:28:49.761 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:ebfa1e9d:node12’ has been updated.
2018-12-15 14:28:49.795 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:ebfa1e9d:node12’ has been updated.
2018-12-15 14:28:49.828 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:ebfa1e9d:node12’ has been updated.
2018-12-15 14:28:49.830 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]]
2018-12-15 14:28:49.938 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:ebfa1e9d:node12’ has been updated.
2018-12-15 14:29:07.876 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@17ee2d3
2018-12-15 14:29:22.129 [vent.ItemStateChangedEvent] - SnookerTableHeater_Switch changed from NULL to ON
2018-12-15 14:29:22.188 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node8’ changed from ONLINE: Node initialising: GET_CONFIGURATION to ONLINE: Node initialising: DYNAMIC_END
2018-12-15 14:29:22.234 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node8’ changed from ONLINE: Node initialising: DYNAMIC_END to ONLINE: Node initialising: HEAL_START
2018-12-15 14:29:22.246 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node8’ changed from ONLINE: Node initialising: HEAL_START to ONLINE: Node initialising: DELETE_ROUTES
2018-12-15 14:29:22.265 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node8’ changed from ONLINE: Node initialising: DELETE_ROUTES to ONLINE: Node initialising: RETURN_ROUTES
2018-12-15 14:29:22.282 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node8’ changed from ONLINE: Node initialising: RETURN_ROUTES to ONLINE: Node initialising: NEIGHBORS
2018-12-15 14:29:22.333 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:ebfa1e9d:node8’ has been updated.
2018-12-15 14:29:25.662 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node8’ changed from ONLINE: Node initialising: NEIGHBORS to ONLINE
2018-12-15 14:33:12.649 [me.event.InboxRemovedEvent] - Discovery Result with UID ‘zwave:device:ebfa1e9d:node19’ has been removed.
2018-12-15 14:33:12.690 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node19’ changed from UNINITIALIZED to INITIALIZING
2018-12-15 14:33:12.702 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node19’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2018-12-15 14:33:12.715 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node19’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to UNINITIALIZED
2018-12-15 14:33:12.751 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node19’ changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2018-12-15 14:33:12.908 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node19’ changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
2018-12-15 14:33:12.915 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node19’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2018-12-15 14:33:12.918 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node19’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller
2018-12-15 14:33:12.952 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:ebfa1e9d:node19’ has been updated.
2018-12-15 14:33:13.014 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:ebfa1e9d:node19’ has been updated.
2018-12-15 14:33:13.063 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:ebfa1e9d:node19’ has been updated.
2018-12-15 14:33:13.069 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]]
2018-12-15 14:33:13.231 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:ebfa1e9d:node19’ has been updated.
2018-12-15 14:33:15.073 [me.event.InboxRemovedEvent] - Discovery Result with UID ‘zwave:device:ebfa1e9d:node20’ has been removed.
2018-12-15 14:33:15.109 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node20’ changed from UNINITIALIZED to INITIALIZING
2018-12-15 14:33:15.112 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node20’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2018-12-15 14:33:15.130 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node20’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to UNINITIALIZED
2018-12-15 14:33:15.151 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node20’ changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2018-12-15 14:33:15.263 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node20’ changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
2018-12-15 14:33:15.271 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node20’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2018-12-15 14:33:15.281 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node20’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller
2018-12-15 14:33:15.329 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:ebfa1e9d:node20’ has been updated.
2018-12-15 14:33:15.380 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:ebfa1e9d:node20’ has been updated.
2018-12-15 14:33:15.505 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:ebfa1e9d:node20’ has been updated.
2018-12-15 14:33:15.507 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]]
2018-12-15 14:33:15.735 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:ebfa1e9d:node20’ has been updated.
2018-12-15 14:33:20.283 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@179492e
2018-12-15 14:33:20.400 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@10c33d7
2018-12-15 14:33:33.795 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@7bc3e5
2018-12-15 14:33:50.455 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@4e8e66

Notice the error:
2018-12-15 14:28:05.949 [hingStatusInfoChangedEvent] - ‘zwave:device:ebfa1e9d:node19’ changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

Does anyone know what this means?

Hi,

quick update, I followed the advice on this thread: Remove a ghost Z-Wave Node from HABmin

in order to remove the defunked things. I then included it again, and now it appears to work.

Thank you all for your help!

Jonathan