Upgraded to 2.2 SnapShot - ZWAVE Errors commence

Tags: #<Tag:0x00007f4342441f10> #<Tag:0x00007f4342441e48>

So after upgrading to 2.2 I’m seeing quite a bit of ZWAVE errors in the Karaf console.

Any thoughts??

        at java.lang.Thread.run(Unknown Source) [?:?]
10:32:30.326 [ZWaveInputThread] ERROR org.openhab.binding.zwave.internal.protoco
l.ZWaveController - Exception during ZWave thread: Input 2. {}
java.lang.NullPointerException: null
        at org.eclipse.smarthome.config.xml.AbstractXmlBasedProvider.get(Abstrac
tXmlBasedProvider.java:146) [97:org.eclipse.smarthome.config.xml:0.9.0.201710240
931]
        at org.eclipse.smarthome.config.xml.AbstractXmlConfigDescriptionProvider
.getConfigDescription(AbstractXmlConfigDescriptionProvider.java:45) [97:org.ecli
pse.smarthome.config.xml:0.9.0.201710240931]
        at org.eclipse.smarthome.config.core.ConfigDescriptionRegistry.getConfig
Description(ConfigDescriptionRegistry.java:147) [94:org.eclipse.smarthome.config
.core:0.9.0.201710240931]
        at org.eclipse.smarthome.config.core.ConfigDescriptionRegistry.getConfig
Description(ConfigDescriptionRegistry.java:183) [94:org.eclipse.smarthome.config
.core:0.9.0.201710240931]
        at org.openhab.binding.zwave.internal.ZWaveConfigProvider.getThingTypeCo
nfig(ZWaveConfigProvider.java:396) [210:org.openhab.binding.zwave:2.2.0.20171029
2329]
        at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeI
nitStageAdvancer.advanceNodeStage(ZWaveNodeInitStageAdvancer.java:974) [210:org.
openhab.binding.zwave:2.2.0.201710292329]
        at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeI
nitStageAdvancer.handleNodeQueue(ZWaveNodeInitStageAdvancer.java:230) [210:org.o
penhab.binding.zwave:2.2.0.201710292329]
        at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeI
nitStageAdvancer.ZWaveIncomingEvent(ZWaveNodeInitStageAdvancer.java:1306) [210:o
rg.openhab.binding.zwave:2.2.0.201710292329]
        at org.openhab.binding.zwave.internal.protocol.ZWaveController.notifyEve
ntListeners(ZWaveController.java:567) [210:org.openhab.binding.zwave:2.2.0.20171
0292329]
        at org.openhab.binding.zwave.internal.protocol.ZWaveController.handleInc
omingRequestMessage(ZWaveController.java:250) [210:org.openhab.binding.zwave:2.2
.0.201710292329]
        at org.openhab.binding.zwave.internal.protocol.ZWaveController.handleInc
omingMessage(ZWaveController.java:214) [210:org.openhab.binding.zwave:2.2.0.2017
10292329]
        at org.openhab.binding.zwave.internal.protocol.ZWaveController.access$7(
ZWaveController.java:208) [210:org.openhab.binding.zwave:2.2.0.201710292329]
        at org.openhab.binding.zwave.internal.protocol.ZWaveController$ZWaveInpu
tThread.run(ZWaveController.java:1324) [210:org.openhab.binding.zwave:2.2.0.2017
10292329]
10:32:32.725 [upnp-main-36] ERROR org.jupnp.protocol.sync.ReceivingEvent - Inval
id subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY
 /upnpcallback/dev/RINCON_000E5823AE2001400/svc/upnp-org/AudioIn/event/cb SEQUEN
CE: 0
10:32:37.760 [upnp-main-35] ERROR org.jupnp.protocol.sync.ReceivingEvent - Inval
id subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY
 /upnpcallback/dev/RINCON_000E5823AE2001400/svc/upnp-org/AudioIn/event/cb SEQUEN
CE: 0
10:32:47.783 [upnp-main-41] ERROR org.jupnp.protocol.sync.ReceivingEvent - Inval
id subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY
 /upnpcallback/dev/RINCON_000E5823AE2001400/svc/upnp-org/AudioIn/event/cb SEQUEN
CE: 0
10:33:07.805 [upnp-main-42] ERROR org.jupnp.protocol.sync.ReceivingEvent - Inval
id subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY
 /upnpcallback/dev/RINCON_000E5823AE2001400/svc/upnp-org/AudioIn/event/cb SEQUEN
CE: 0
Exception in thread "Timer-29" java.lang.NullPointerException
``

Please provide a debug log showing the messages before the error.

Would love to but running into an issue with 2.2 not logging…trying to get that figured out as nothing is getting written to the log files.

Ok, let me know when you have the logs and I’ll take a look. These sort of errors are normally caused by an incorrectly formatted message from a device so I need to see what that is…

Just to confirm, DEBUG on just the ZWAVE binding?

Yep.

Chris -

Here’s the log…one thing I’ve noticed that is kinda weird is I’m seeing RGB reporting coming back from my range extender. That’s a new device that was added to the database recently. It may be nothing, but I wanted to relay what I noticed when scanning the log.

Let me know what else I can supply.

Thanks,

Squid

What is node 22? The issue seems to be related to finding this nodes thing description, but I’m not really sure what the issue is as the crash is in the XML code. Maybe there’s a database issue with the device or something…

Node 22 is a PS15EMZ51 Appliance Module

I have another one of those same modules as Node 18

Node 20 is the RANGE EXTENDER that is sending back RGB info…

Does node 18 work ok or does it also cause issues? I would suggest to delete this thing and add it back to see if that helps. I don’t see anything obviously wrong in the database and the issue is deep down in ESH code so not really easy to see what’s wrong.

The range extender is probably fine. If it’s an Aeon, then it supports color - is there a problem with it or you just weren’t expecting this?

Both nodes were working fine…this just started when I moved to 2.2 SNAPSHOT from 2.1 Stable/Release.

Node 18 is currently unplugged - my housekeeper thought she was being helpful taking down Halloween decorations and took the appliance module as well. I’ll plug it back in this evening.

The range extender is an Aeon…I just never saw the RGB info in the logs since I upgraded.

Ok. I have removed and added back Node 18 and Node 20 and am still getting messages in the Karaf window.

openhab> Exception in thread "Timer-27" java.lang.NullPointerException
        at org.eclipse.smarthome.config.xml.AbstractXmlBasedProvider.get(Abstrac
tXmlBasedProvider.java:146)
        at org.eclipse.smarthome.config.xml.AbstractXmlConfigDescriptionProvider
.getConfigDescription(AbstractXmlConfigDescriptionProvider.java:45)
        at org.eclipse.smarthome.config.core.ConfigDescriptionRegistry.getConfig
Description(ConfigDescriptionRegistry.java:147)
        at org.eclipse.smarthome.config.core.ConfigDescriptionRegistry.getConfig
Description(ConfigDescriptionRegistry.java:183)
        at org.openhab.binding.zwave.internal.ZWaveConfigProvider.getThingTypeCo
nfig(ZWaveConfigProvider.java:396)
        at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeI
nitStageAdvancer.advanceNodeStage(ZWaveNodeInitStageAdvancer.java:974)
        at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeI
nitStageAdvancer$IdleTimerTask.run(ZWaveNodeInitStageAdvancer.java:1395)
        at java.util.TimerThread.mainLoop(Unknown Source)
        at java.util.TimerThread.run(Unknown Source)
Exception in thread "Timer-25" java.lang.NullPointerException
        at org.eclipse.smarthome.config.xml.AbstractXmlBasedProvider.get(Abstrac
tXmlBasedProvider.java:146)
        at org.eclipse.smarthome.config.xml.AbstractXmlConfigDescriptionProvider
.getConfigDescription(AbstractXmlConfigDescriptionProvider.java:45)
        at org.eclipse.smarthome.config.core.ConfigDescriptionRegistry.getConfig
Description(ConfigDescriptionRegistry.java:147)
        at org.eclipse.smarthome.config.core.ConfigDescriptionRegistry.getConfig
Description(ConfigDescriptionRegistry.java:183)
        at org.openhab.binding.zwave.internal.ZWaveConfigProvider.getThingTypeCo
nfig(ZWaveConfigProvider.java:396)
        at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeI
nitStageAdvancer.advanceNodeStage(ZWaveNodeInitStageAdvancer.java:974)
        at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeI
nitStageAdvancer$IdleTimerTask.run(ZWaveNodeInitStageAdvancer.java:1395)
        at java.util.TimerThread.mainLoop(Unknown Source)
        at java.util.TimerThread.run(Unknown Source)

openhab>

I think this must be a bug in ESH somewhere (possibly triggered by something in the XML for this device). The binding is simply asking the system for the configuration, and since this is many calls down in ESH, I don’t think the issue can be with the binding.

I’ll see if I can set up some sort of test to read the XML.

Ok, I confirm I can reproduce this so I’ll sort out a fix in the next day or so.

Many thanks as always…

Squid

I can just say that I have the same error and its nice to see that it will be fixed. Hope you will come back here and tell us when it is fixed so I can test the fix.

FTR -: