OH 2.2.0 Snapshots 1025-1028 / ZWave NPE

rgerrans · August 29, 2017, 8:35pm

The development version. I had the same issue with it yesterday not showing in Habmin (I did not look at the log files to see if it was throwing off the NPE’s).

chris · August 29, 2017, 8:36pm

Ok, sorry - I thought I read from @sihui and others that the dev version didn’t have an issue. I’ll do a rebuild of this later.

Dim · August 29, 2017, 8:38pm

It seems that the 500 errors are related to the framework (you get those both in PaperUI and HABmin… they both use the REST API which spits out the 500s)

I don’t know if these framework errors are caused by the Z-Wave binding (I doubt it). People using both versions of the Z-Wave binding are seeing these framework errors in Snapshot builds greater than 1025.

So: I believe that we have 2 separate issues here:
(a) NPEs for the standard Z-Wave binding due to ThingTypeI18nLocalizationService (logged under: 4152)
(b) Internal Server Error 500 due to REST API being “broken” (not logged anywhere yet)

(maybe the 2 issues are associated… somehow?)

rgerrans · August 29, 2017, 8:38pm

Thanks. I just looked at my log files and I was getting NPE’s but I also was getting all kind of errors with it trying to pull in dependencies as well.

2017-08-28 16:11:06.454 [WARN ] [org.apache.felix.fileinstall        ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.zwave-2.1.0-SNAPSHOT.jar
org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.zwave [10]
  Unresolved requirement: Import-Package: com.google.common.collect

	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:1253) [8:org.apache.felix.fileinstall:3.6.0]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1225) [8:org.apache.felix.fileinstall:3.6.0]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:512) [8:org.apache.felix.fileinstall:3.6.0]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:361) [8:org.apache.felix.fileinstall:3.6.0]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:312) [8:org.apache.felix.fileinstall:3.6.0]

Dim · August 29, 2017, 8:46pm

more specifically… something is wrong with the thing-types and the discovery in snapshots 1025 & 1026

Request URLs failing with NPE, causing http code 500:

http://OH2_IP:8080/rest/thing-types
http://OH2_IP:8080/rest/discovery

marcel_erkel · August 29, 2017, 8:55pm

Build 1025 includes a new ESH stable version. Amongst the changes is a version bump of Xtext. Xtext is used for textual configuration.

In the past I’ve had issues with HTTP 500 Errors when my textual item definitions were incorrect. I’m not saying that the Xtext bump and the 500 errors you are seeing are related, but I would not rule it out either.

rgerrans · August 29, 2017, 8:57pm

I can confirm that I use 100% text files for everything but Things in my system configuration.

Dim · August 30, 2017, 5:54am

1027 has the same NPE on the Z-Wave log:

30-Aug-2017 08:47:41.162 [INFO ] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'
30-Aug-2017 08:47:41.285 [INFO ] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
30-Aug-2017 08:47:41.288 [INFO ] [al.protocol.commandclass.ZWaveSecurityCommandClass] - Update networkKey
30-Aug-2017 08:47:41.295 [INFO ] [ab.binding.zwave.internal.protocol.ZWaveController] - Starting ZWave controller
30-Aug-2017 08:47:41.295 [INFO ] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
30-Aug-2017 08:47:44.443 [INFO ] [col.serialmessage.SerialApiGetInitDataMessageClass] - NODE 1: Node found
30-Aug-2017 08:47:44.443 [INFO ] [col.serialmessage.SerialApiGetInitDataMessageClass] - NODE 2: Node found
30-Aug-2017 08:47:44.443 [INFO ] [col.serialmessage.SerialApiGetInitDataMessageClass] - NODE 3: Node found
30-Aug-2017 08:47:44.444 [INFO ] [col.serialmessage.SerialApiGetInitDataMessageClass] - NODE 4: Node found
30-Aug-2017 08:47:44.444 [INFO ] [col.serialmessage.SerialApiGetInitDataMessageClass] - NODE 6: Node found
30-Aug-2017 08:47:44.444 [INFO ] [col.serialmessage.SerialApiGetInitDataMessageClass] - NODE 8: Node found
30-Aug-2017 08:47:44.444 [INFO ] [col.serialmessage.SerialApiGetInitDataMessageClass] - NODE 9: Node found
30-Aug-2017 08:47:44.444 [INFO ] [col.serialmessage.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API
30-Aug-2017 08:47:44.444 [INFO ] [col.serialmessage.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller
30-Aug-2017 08:47:44.445 [INFO ] [col.serialmessage.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Cont
roller------------
30-Aug-2017 08:47:44.445 [INFO ] [col.serialmessage.SerialApiGetInitDataMessageClass] - # Nodes = 7
30-Aug-2017 08:47:44.446 [INFO ] [col.serialmessage.SerialApiGetInitDataMessageClass] - ----------------------------------------------------------
------------------
30-Aug-2017 08:47:49.911 [ERROR] [ab.binding.zwave.internal.protocol.ZWaveController] - Exception during ZWave thread: Input 2. {}
java.lang.NullPointerException: null
	at org.eclipse.smarthome.core.thing.i18n.ThingTypeI18nLocalizationService.createLocalizedThingType(ThingTypeI18nLocalizationService.java:6
7) [105:org.eclipse.smarthome.core.thing:0.9.0.201708281632]
	at org.eclipse.smarthome.core.thing.xml.internal.XmlThingTypeProvider.localize(XmlThingTypeProvider.java:128) [106:org.eclipse.smarthome.c
ore.thing.xml:0.9.0.201708281632]
	at org.eclipse.smarthome.core.thing.xml.internal.XmlThingTypeProvider.localize(XmlThingTypeProvider.java:1) [106:org.eclipse.smarthome.cor
e.thing.xml:0.9.0.201708281632]
	at org.eclipse.smarthome.config.xml.AbstractXmlBasedProvider.acquireLocalizedObject(AbstractXmlBasedProvider.java:211) [97:org.eclipse.sma
rthome.config.xml:0.9.0.201708281632]
	at org.eclipse.smarthome.config.xml.AbstractXmlBasedProvider.getAll(AbstractXmlBasedProvider.java:165) [97:org.eclipse.smarthome.config.xm
l:0.9.0.201708281632]
	at org.eclipse.smarthome.core.thing.xml.internal.XmlThingTypeProvider.getThingTypes(XmlThingTypeProvider.java:82) [106:org.eclipse.smartho
me.core.thing.xml:0.9.0.201708281632]
	at org.eclipse.smarthome.core.thing.type.ThingTypeRegistry.getThingTypes(ThingTypeRegistry.java:48) [105:org.eclipse.smarthome.core.thing:
0.9.0.201708281632]
	at org.eclipse.smarthome.core.thing.type.ThingTypeRegistry.getThingTypes(ThingTypeRegistry.java:59) [105:org.eclipse.smarthome.core.thing:
0.9.0.201708281632]
	at org.openhab.binding.zwave.internal.ZWaveConfigProvider.initialiseZWaveThings(ZWaveConfigProvider.java:310) [203:org.openhab.binding.zwa
ve:2.2.0.201708292017]
	at org.openhab.binding.zwave.internal.ZWaveConfigProvider.getProductIndex(ZWaveConfigProvider.java:355) [203:org.openhab.binding.zwave:2.2
.0.201708292017]
	at org.openhab.binding.zwave.internal.ZWaveConfigProvider.getThingType(ZWaveConfigProvider.java:382) [203:org.openhab.binding.zwave:2.2.0.
201708292017]
	at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer.advanceNodeStage(ZWaveNodeInitStageAdvancer.java:
968) [203:org.openhab.binding.zwave:2.2.0.201708292017]
	at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer.handleNodeQueue(ZWaveNodeInitStageAdvancer.java:2
30) [203:org.openhab.binding.zwave:2.2.0.201708292017]
	at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer.ZWaveIncomingEvent(ZWaveNodeInitStageAdvancer.jav
a:1306) [203:org.openhab.binding.zwave:2.2.0.201708292017]
	at org.openhab.binding.zwave.internal.protocol.ZWaveController.notifyEventListeners(ZWaveController.java:567) [203:org.openhab.binding.zwa
ve:2.2.0.201708292017]
	at org.openhab.binding.zwave.internal.protocol.ZWaveController.handleIncomingRequestMessage(ZWaveController.java:250) [203:org.openhab.bin
ding.zwave:2.2.0.201708292017]
	at org.openhab.binding.zwave.internal.protocol.ZWaveController.handleIncomingMessage(ZWaveController.java:214) [203:org.openhab.binding.zw
ave:2.2.0.201708292017]
	at org.openhab.binding.zwave.internal.protocol.ZWaveController.access$7(ZWaveController.java:208) [203:org.openhab.binding.zwave:2.2.0.201
708292017]
	at org.openhab.binding.zwave.internal.protocol.ZWaveController$ZWaveInputThread.run(ZWaveController.java:1324) [203:org.openhab.binding.zwave:2.2.0.201708292017]

and both URLs fail with 500:

http://OH2_IP:8080/rest/thing-types
http://OH2_IP:8080/rest/discovery

openhab> list -s |grep -i smarthome.core
 98 │ Active   │  80 │ 0.9.0.201708281632     │ org.eclipse.smarthome.core
openhab> list -s |grep -i Z
203 │ Active   │  80 │ 2.2.0.201708292017     │ org.openhab.binding.zwave

(same situation as above)

chris · August 30, 2017, 6:55am

I don’t think it’s XText that’s causing the ZWave NPE at least. The problem seems to be with localisation and in any case XText reads the files during initialisation and not when the REST interface is read.

I added the additional channel into the binding yesterday and didn’t see any errors. Maybe my development environment doesn’t have all the latest updates in ESH so I’ll do a complete update tonight and see if I can find where this issue is.

sihui · August 30, 2017, 4:09pm

Upgraded to build #1027 with development zwave binding 2.1.0.201708292314

There is still no NPE related to the zwave binding. Also there has not been an NPE with #1025 and zwave development binding from one day earlier before the fix was applied.
It looks like zwave NPE’s only occur with the snapshot zwave binding (can’t test, don’t use it).
With #1027 I am still seeing the 500 internal server error in PaperUI and no things showing up in HABmin.
It looks like those issues are already covered in the issue tracker here: NPE in ThingTypeI18nLocalizationService · Issue #4152 · eclipse-archived/smarthome · GitHub

chris · August 30, 2017, 4:11pm

Thanks.

Dim · August 31, 2017, 4:19am

uped to OH2.2.0 S1028
still seeing the same 2 issues
using the “standard/mainstream” Z-Wave snapshot (not the sec/dev version)

no worries, my system is operational

sihui · August 31, 2017, 4:04pm

Yeah, mine too, but no chance to change any settings or doing the usual tinkering …

mstormi · September 1, 2017, 4:26pm

Just saw that @lolodomo has fixed ESH #4152.

Great, thanks!
Now as this is a ESH fix, how and when will it be forward-propagated into a new OH snapshot build ?
ESH-stable is still on #225 and Cloudbees is still on #1029.
Please pardon my lack of knowledge on the full dependency chain. Has anybody written down how it’s getting processed ?
If not, doing so would probably make sense to keep more people like me from annoying you hard working guys with more questions like this one.

sihui · September 1, 2017, 5:07pm

Looks like we are lucky and get it a little sooner than usually:

https://hudson.eclipse.org/smarthome/job/SmartHomeDistribution-Stable/changes

sihui · September 1, 2017, 5:09pm

A little more info can be found here:

mstormi · September 1, 2017, 11:57pm

Just upgraded to #1030, and things are back in habmin ! Also no NPE so far (I’m running the dev zwave binding, though).
Will check in more detail tomorrow. Thanks a lot @lolodomo and @kai.

EDIT (it’s 12AM CEST): still running fine.

mike_mccaffery · September 2, 2017, 9:41am

Just to add 1030 has fixed for me also, 500’s in paperui (though items tab seems to have disappeared - not sure when that happened) and no items in habmin. i wasnt experiencing the zwave error running standard binding.

thanks for fixing

Mike_Bagdanoff · September 2, 2017, 4:01pm

I thought the items missing in paperUI was part of the bug, is it an intentional change?

That said, I’ve updated to 1031 and it all seems to be running fine

sihui · September 2, 2017, 7:07pm

Don’t think so, items category tab is available in HABmin with #1031 …

But verify if “Simple Mode” is switched off, you won’t have an items category with that switch ON.