[zwave] openHAB 2.5.0 Build #1723 exception during startup

Add-ons Bindings
1

Before I open an issue I wanted to see if there are others seeing this error and gather more information others may have.

I’m running OH in a Docker container and just upgraded this morning. When OH comes up I see the following exception in the logs:

2019-10-14 07:58:16.519 [ERROR] [ig.xml.osgi.XmlDocumentBundleTracker] - Could not send adding finished event for the module 'org.openhab.binding.zwave'!
java.lang.IllegalArgumentException: UID must have at least 2 segments.
        at org.eclipse.smarthome.core.common.AbstractUID.<init>(AbstractUID.java:70) ~[133:org.openhab.core:2.5.0.201910140525]
        at org.eclipse.smarthome.core.common.AbstractUID.<init>(AbstractUID.java:49) ~[133:org.openhab.core:2.5.0.201910140525]
        at org.eclipse.smarthome.core.thing.UID.<init>(UID.java:48) ~[?:?]
        at org.eclipse.smarthome.core.thing.type.ChannelTypeUID.<init>(ChannelTypeUID.java:40) ~[?:?]
        at org.eclipse.smarthome.core.thing.xml.internal.ChannelXmlResult.toChannelDefinition(ChannelXmlResult.java:135) ~[?:?]
        at org.eclipse.smarthome.core.thing.xml.internal.ThingTypeXmlResult.toChannelDefinitions(ThingTypeXmlResult.java:94) ~[?:?]
        at org.eclipse.smarthome.core.thing.xml.internal.ThingTypeXmlResult.getBuilder(ThingTypeXmlResult.java:145) ~[?:?]
        at org.eclipse.smarthome.core.thing.xml.internal.ThingTypeXmlResult.toThingType(ThingTypeXmlResult.java:153) ~[?:?]
        at org.eclipse.smarthome.core.thing.xml.internal.ThingTypeXmlProvider.addingFinished(ThingTypeXmlProvider.java:147) ~[?:?]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.addingFinished(XmlDocumentBundleTracker.java:265) [142:org.openhab.core.config.xml:2.5.0.201910140543]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.parseDocuments(XmlDocumentBundleTracker.java:424) [142:org.openhab.core.config.xml:2.5.0.201910140543]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.processBundle(XmlDocumentBundleTracker.java:398) [142:org.openhab.core.config.xml:2.5.0.201910140543]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.access$6(XmlDocumentBundleTracker.java:393) [142:org.openhab.core.config.xml:2.5.0.201910140543]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker$2.run(XmlDocumentBundleTracker.java:363) [142:org.openhab.core.config.xml:2.5.0.201910140543]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
...
2019-10-14 07:58:21.502 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery could not resolve to a thingType! 0138:0001:0002::0.5
2019-10-14 07:58:21.507 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 10: Device discovery could not resolve to a thingType! 0138:0001:0002::0.5
2019-10-14 07:58:21.517 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 13: Device discovery could not resolve to a thingType! 0090:0001:0001::3.37
2019-10-14 07:58:21.524 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 12: Device discovery could not resolve to a thingType! 0090:0001:0001::3.37
2019-10-14 07:58:21.607 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 9: Device discovery could not resolve to a thingType! 0138:0001:0002::0.5

All the Things show as online in PaperUI.

I put the binding into trace logging and immediately before the warnings above I see for each of those nodes

14-Oct-2019 08:13:53.019 [TRACE] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 5: Checking zwave:thermofloor_019b_00_000
14-Oct-2019 08:13:53.052 [TRACE] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 5: Checking zwave:trane_xr524_00_000
14-Oct-2019 08:13:53.052 [TRACE] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 5: Checking zwave:ebv_heatappfloor_00_000
14-Oct-2019 08:13:53.052 [TRACE] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 5: Checking zwave:zwaveme_zmeft_00_000
14-Oct-2019 08:13:53.052 [WARN ] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery could not resolve to a thingType! 0138:0001:0002::0.5

Looking more closely at the nodes that are reporting these warnings, they are all battery powered devices. Nodes 5, 10, and 9 are ZCombo smoke/CO alarms and nodes 12 and 13 are Kwikset 910 deadbolts. None of the mains powered devices are reporting errors and all the mains powered devices are working. These five Nodes appear not to work though (e.g. the Items are not update when I manually manipulate the deadbolts.

I have full trace logs from the startup if they will prove useful. They are pretty big so I’ll wait for them to be asked for before posting.

Here is an extract for NODE 5:

14-Oct-2019 08:13:46.297 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Channel zwave:device:dongle:node5:alarm_general linked - polling started.
14-Oct-2019 08:13:46.297 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Channel zwave:device:dongle:node5:alarm_smoke linked - polling started.
14-Oct-2019 08:13:46.297 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Channel zwave:device:dongle:node5:battery-level linked - polling started.
14-Oct-2019 08:13:49.983 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - NODE 5: Node found
14-Oct-2019 08:13:50.083 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 5: Init node thread start
14-Oct-2019 08:13:50.517 [DEBUG] [ternal.protocol.initialization.ZWaveNodeSerializer] - NODE 5: Serializing from file /openhab/userdata/zwave/network_c639cf57__node_5.xml
14-Oct-2019 08:13:50.566 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 5: Restore from config: Ok.
14-Oct-2019 08:13:50.643 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 5: Command class COMMAND_CLASS_ASSOCIATION, endpoint 0 created
14-Oct-2019 08:13:50.647 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 5: Command class COMMAND_CLASS_VERSION, endpoint 0 created
14-Oct-2019 08:13:50.650 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 5: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
14-Oct-2019 08:13:50.661 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 5: Command class COMMAND_CLASS_BASIC, endpoint 0 created
14-Oct-2019 08:13:50.668 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 5: Command class COMMAND_CLASS_BATTERY, endpoint 0 created
14-Oct-2019 08:13:50.672 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 5: Command class COMMAND_CLASS_CONFIGURATION, endpoint 0 created
14-Oct-2019 08:13:50.694 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 5: Command class COMMAND_CLASS_ALARM, endpoint 0 created
14-Oct-2019 08:13:50.746 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 5: Command class COMMAND_CLASS_MANUFACTURER_SPECIFIC, endpoint 0 created
14-Oct-2019 08:13:50.767 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery completed
14-Oct-2019 08:13:51.683 [TRACE] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 5: Checking zwave:telldus_tzwp100_00_000
14-Oct-2019 08:13:51.684 [TRACE] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 5: Checking zwave:telldus_tzwp100_00_000
14-Oct-2019 08:13:51.684 [TRACE] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 
// Repeats for what appears to be every device in the Zwave database
14-Oct-2019 08:13:53.052 [WARN ] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery could not resolve to a thingType! 0138:0001:0002::0.5
14-Oct-2019 08:13:53.057 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 5: Starting initialisation from EMPTYNODE
14-Oct-2019 08:13:53.105 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 5: Init node thread finished
14-Oct-2019 08:13:53.105 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer - advancing to IDENTIFY_NODE
14-Oct-2019 08:13:53.224 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: Initialisation starting
14-Oct-2019 08:13:53.425 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 5: ProtocolInfo
14-Oct-2019 08:13:53.425 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 5: Listening = false
14-Oct-2019 08:13:53.428 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 5: Routing   = true
14-Oct-2019 08:13:53.429 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 5: Beaming   = true
14-Oct-2019 08:13:53.429 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 5: Version   = 4
14-Oct-2019 08:13:53.429 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 5: FLIRS     = false
14-Oct-2019 08:13:53.429 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 5: Security  = false
14-Oct-2019 08:13:53.430 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 5: Max Baud  = 40000
14-Oct-2019 08:13:53.430 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 5: Basic    = BASIC_TYPE_ROUTING_SLAVE
14-Oct-2019 08:13:53.430 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 5: Generic  = GENERIC_TYPE_SENSOR_ALARM
14-Oct-2019 08:13:53.430 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 5: Specific = SPECIFIC_TYPE_NOT_USED
14-Oct-2019 08:13:53.430 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 5: Creating new instance of command class COMMAND_CLASS_NO_OPERATION
14-Oct-2019 08:13:53.431 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 5: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
14-Oct-2019 08:13:53.431 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 5: Version = 1, version set. Enabling extra functionality.
14-Oct-2019 08:13:53.431 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 5: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes.
14-Oct-2019 08:13:53.431 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 5: Creating new instance of command class COMMAND_CLASS_BASIC
14-Oct-2019 08:13:53.431 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 5: Command class COMMAND_CLASS_BASIC, endpoint 0 created
14-Oct-2019 08:13:53.431 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 5: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes.
14-Oct-2019 08:13:53.820 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 5: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@42587780
14-Oct-2019 08:13:53.855 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 5: Node Init transaction completed with response COMPLETE
14-Oct-2019 08:13:53.861 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer - advancing to REQUEST_NIF
14-Oct-2019 08:13:53.861 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 5: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@75af1af
14-Oct-2019 08:13:53.884 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 5: Bump transaction 20 priority from Controller to Immediate
14-Oct-2019 08:13:53.885 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 5: Adding to device queue
14-Oct-2019 08:13:53.885 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 5: Added 20 to queue - size 2
14-Oct-2019 08:13:54.456 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Controller status changed to ONLINE.
14-Oct-2019 08:13:54.456 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Controller is ONLINE. Starting device initialisation.
14-Oct-2019 08:13:54.456 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating node properties.
14-Oct-2019 08:13:54.456 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating node properties. MAN=312
14-Oct-2019 08:13:54.456 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating node properties. MAN=312. SET. Was 312
14-Oct-2019 08:13:54.456 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Properties synchronised
14-Oct-2019 08:13:54.457 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Update ASSOCIATION group_ZWaveAssociationGroup [index=1, name=null, profile1=null, profile2=null, associations=[node_1]]: Adding Controller (node_1)
14-Oct-2019 08:13:54.457 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Initialising Thing Node...
14-Oct-2019 08:13:54.457 [TRACE] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Processing channel: zwave:device:dongle:node5:alarm_general == zwave:alarm_general
14-Oct-2019 08:13:54.457 [TRACE] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Processing channel: binding:*:OnOffType == COMMAND_CLASS_ALARM,COMMAND_CLASS_BASIC;type=HOME_HEALTH
14-Oct-2019 08:13:54.457 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Initialising cmd channel zwave:device:dongle:node5:alarm_general for OnOffType
14-Oct-2019 08:13:54.457 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Initialising state channel zwave:device:dongle:node5:alarm_general for OnOffType
14-Oct-2019 08:13:54.457 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Initialising state channel zwave:device:dongle:node5:alarm_general for OnOffType
14-Oct-2019 08:13:54.457 [TRACE] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Processing channel: zwave:device:dongle:node5:alarm_smoke == zwave:alarm_smoke
14-Oct-2019 08:13:54.457 [TRACE] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Processing channel: binding:*:OnOffType == COMMAND_CLASS_ALARM,COMMAND_CLASS_BASIC;type=APPLIANCE
14-Oct-2019 08:13:54.457 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Initialising cmd channel zwave:device:dongle:node5:alarm_smoke for OnOffType
14-Oct-2019 08:13:54.457 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Initialising state channel zwave:device:dongle:node5:alarm_smoke for OnOffType
14-Oct-2019 08:13:54.457 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Initialising state channel zwave:device:dongle:node5:alarm_smoke for OnOffType
14-Oct-2019 08:13:54.458 [TRACE] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Processing channel: zwave:device:dongle:node5:battery-level == system:battery-level
14-Oct-2019 08:13:54.458 [TRACE] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Processing channel: binding:*:PercentType == COMMAND_CLASS_BATTERY
14-Oct-2019 08:13:54.458 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Initialising cmd channel zwave:device:dongle:node5:battery-level for PercentType
14-Oct-2019 08:13:54.458 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Initialising state channel zwave:device:dongle:node5:battery-level for PercentType
14-Oct-2019 08:13:54.458 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Polling initialised at 86400 seconds - start in 20217600 milliseconds.
14-Oct-2019 08:13:54.458 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 5: Device initialisation complete.
14-Oct-2019 08:13:55.022 [TRACE] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 5: listening == false, frequentlyListening == false, awake == false
14-Oct-2019 08:13:55.023 [TRACE] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 5: Node not awake!
2

Is that a snapshot build?
The log viewer may help point out the flow better.

https://www.cd-jackson.com/index.php/openhab/zwave-log-viewer

3

Yes, yesterday’s snapshot. I used the log viewer but it doesn’t show anything different than the above. Before I updated from a snapshot from some time last week to the most recent snapshot everything worked fine. With yesterday’s snapshot I get the above errors and warnings and my batter powered devices appear not to work.

4

I’m seeing this at startup in the latest snapshot, too. The system where it’s installed loads the zwave binding, but currently has no zwave things defined (including the serial controller).

1 Like
5

Did update today from 1721 to 1725 and can confirm the startup error. But my battery powered door sensor from Aeotec does still work. It’s the only zwave sensor I have in my system…

6

I just updated to S1725. I get the exception…

2019-10-15 13:22:00.560 [ERROR] [org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker] - Could not send adding finished event for the module 'org.openhab.binding.zwave'!
java.lang.IllegalArgumentException: UID must have at least 2 segments.
        at org.eclipse.smarthome.core.common.AbstractUID.<init>(AbstractUID.java:70) ~[133:org.openhab.core:2.5.0.201910150342]
        at org.eclipse.smarthome.core.common.AbstractUID.<init>(AbstractUID.java:49) ~[133:org.openhab.core:2.5.0.201910150342]
        at org.eclipse.smarthome.core.thing.UID.<init>(UID.java:48) ~[?:?]
        at org.eclipse.smarthome.core.thing.type.ChannelTypeUID.<init>(ChannelTypeUID.java:40) ~[?:?]
        at org.eclipse.smarthome.core.thing.xml.internal.ChannelXmlResult.toChannelDefinition(ChannelXmlResult.java:135) ~[?:?]
        at org.eclipse.smarthome.core.thing.xml.internal.ThingTypeXmlResult.toChannelDefinitions(ThingTypeXmlResult.java:94) ~[?:?]
        at org.eclipse.smarthome.core.thing.xml.internal.ThingTypeXmlResult.getBuilder(ThingTypeXmlResult.java:145) ~[?:?]
        at org.eclipse.smarthome.core.thing.xml.internal.ThingTypeXmlResult.toThingType(ThingTypeXmlResult.java:153) ~[?:?]
        at org.eclipse.smarthome.core.thing.xml.internal.ThingTypeXmlProvider.addingFinished(ThingTypeXmlProvider.java:147) ~[?:?]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.addingFinished(XmlDocumentBundleTracker.java:265) [142:org.openhab.core.config.xml:2.5.0.201910150357]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.parseDocuments(XmlDocumentBundleTracker.java:424) [142:org.openhab.core.config.xml:2.5.0.201910150357]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.processBundle(XmlDocumentBundleTracker.java:398) [142:org.openhab.core.config.xml:2.5.0.201910150357]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.access$6(XmlDocumentBundleTracker.java:393) [142:org.openhab.core.config.xml:2.5.0.201910150357]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker$2.run(XmlDocumentBundleTracker.java:363) [142:org.openhab.core.config.xml:2.5.0.201910150357]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]

… at startup and a LOT of ThingTypes cannot be identified. These are not just battery powered.

2019-10-15 13:46:28.192 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 88: Device discovery could not resolve to a thingType! 014F:2005:0503::1.65
2019-10-15 13:46:28.212 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 223: Device discovery could not resolve to a thingType! 0109:201A:1AA4::15.10
2019-10-15 13:46:28.200 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 133: Device discovery could not resolve to a thingType! 003B:6341:5044::113.22
2019-10-15 13:46:28.211 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 122: Device discovery could not resolve to a thingType! 011A:0601:0901::5.10
2019-10-15 13:46:28.217 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 87: Device discovery could not resolve to a thingType! 014F:2005:0503::1.65
2019-10-15 13:46:28.211 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 18: Device discovery could not resolve to a thingType! 001D:1B03:0334::0.7
2019-10-15 13:46:28.186 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery could not resolve to a thingType! 001D:1C02:0334::0.7
2019-10-15 13:46:28.210 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 225: Device discovery could not resolve to a thingType! 0086:0003:0006::1.43
2019-10-15 13:46:28.210 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 226: Device discovery could not resolve to a thingType! 0086:0003:0006::1.43
2019-10-15 13:46:28.202 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 6: Device discovery could not resolve to a thingType! 001D:1B03:0334::0.7
2019-10-15 13:46:28.201 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 19: Device discovery could not resolve to a thingType! 001D:1B03:0334::0.7
2019-10-15 13:46:28.205 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 140: Device discovery could not resolve to a thingType! 014F:2005:0503::1.65
2019-10-15 13:46:28.154 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 120: Device discovery could not resolve to a thingType! 0109:201A:1AA4::15.10
2019-10-15 13:46:28.210 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 224: Device discovery could not resolve to a thingType! 0086:0003:0006::1.43
2019-10-15 13:46:28.229 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 14: Device discovery could not resolve to a thingType! 001D:1C02:0334::0.7
2019-10-15 13:46:28.272 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 230: Device discovery could not resolve to a thingType! 0086:0002:0009::3.64
2019-10-15 13:46:28.287 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 216: Device discovery could not resolve to a thingType! 0109:201A:1AA4::15.10
2019-10-15 13:46:28.292 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 142: Device discovery could not resolve to a thingType! 003B:6341:5044::113.22
2019-10-15 13:46:28.302 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 231: Device discovery could not resolve to a thingType! 0086:0002:0009::3.64
2019-10-15 13:46:28.228 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 218: Device discovery could not resolve to a thingType! 0109:201A:1AA4::15.10
2019-10-15 13:46:28.219 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 227: Device discovery could not resolve to a thingType! 0086:0003:0006::1.43
2019-10-15 13:46:28.218 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 228: Device discovery could not resolve to a thingType! 0086:0003:0006::1.43
2019-10-15 13:46:28.215 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 137: Device discovery could not resolve to a thingType! 001D:1C02:0334::0.7
2019-10-15 13:46:28.284 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 229: Device discovery could not resolve to a thingType! 0086:0002:0009::3.64
2019-10-15 13:46:28.288 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 232: Device discovery could not resolve to a thingType! 0086:0002:0009::3.64
2019-10-15 13:46:28.236 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 221: Device discovery could not resolve to a thingType! 0109:201A:1AA4::15.10
2019-10-15 13:46:28.207 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 183: Device discovery could not resolve to a thingType! 003B:6341:5044::113.22
2019-10-15 13:46:28.209 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 121: Device discovery could not resolve to a thingType! 011A:0601:0901::5.10
2019-10-15 13:46:28.204 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 13: Device discovery could not resolve to a thingType! 001D:1C02:0334::0.7
2019-10-15 13:46:28.207 [WARN ] [org.openhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE 17: Device discovery could not resolve to a thingType! 001D:1B03:0334::0.

This is odd, since I had the same issue after the resync for some devices, but I got them fixed up. After @chris exported and did a build, the devices worked again. The same devices are affected now, plus many other types.

From a quick look, the Thing XMLs for these devices all appear to have multiple manufacturerRef. There have been two recent commits to the zwave binding. Has anyone tried an older version of the binding and gotten the same results? The exception does not occur after downgrading to 2.5.0.201910040432 and all the Thing XMLs could be read, so this is likely due to a recent zwave PR.

1 Like
7

Me too: posted my symptoms in this post (before reading this thread - lesson learnt :wink:):

8

@Bruce_Osborne, if you are running 2.5M3, could you try running the script to get the latest snapshot version of the binding? This would further confirm this is a binding issue and not something in core.

9

I have a test build with a new controller & 1 device iun a VM rhat I set up last night. Is that sufficient or do I need more devices?

10

You shouldn’t need any devices. I get the exception with just the binding installed and no devices (including no controller thing).

2 Likes
11

I went ahead and created the issue.

12

I got the 2 minute uninstall error.
I will uninstall te binding manually now.

13

Hold up…

14

Too late. The files seemed to get copied but the script timed out. Restarting OH.

15

The cause is known, Chris did a db update, and the current build has the fix and is ready for download. I’ve tested and everything ran without exceptions. I’ve also pushed a fix for the install script, so it should be working now :wink:!

16

I need to download a new install script?
It would be helpful for those of us with short memories to link to the location we are supposed to install the script to. It took me some digging.
I did not realize your script worked with M3.

UPDATE:
Downloaded the script, selected snapshot & the binding appears to be working.

17

The script checks for updates when you run it and will prompt you if you’d like to update when the version of your script is out of date.

1 Like
18

So, the fix made it into the latest snapshot?
GitHub says it was updated 2 hours ago & the snapshot binding was built 2 hr 6 minutes ago.

19

Yes. The fix…

2 Likes
20

Thanks @chris that’s fixed my issues. Appreciate the speedy fix.