Updating a Z-Wave 'Thing' produces NPE

Tags: #<Tag:0x00007efec94a1b58> #<Tag:0x00007efec94a1a40>

I’m using a Raspberry PI in combination with the Razberry Z-Wave Controller.

While trying to update a Z-Wave thing, the PaperUI reports successively:
'Item updated", immediately followed by a ‘404 NOT FOUND’.

I am also experience a very slow update rate from devices as a Fibaro Wall Plug which should be updated a bit faster than once per 25 minutes. At least, it does update a lot faster under the less extensible environment Z-wave Me.

I’d really appreciate the help :slight_smile:

Trying to update a device’s settings produced the following log (info):

2017-03-30 17:18:21.846 [INFO ] [ome.io.rest.core.thing.ThingResource] - Received HTTP PUT request for update config at 'things/zwave:device:5992148b:node4/config' for the unknown thing 'zwave:device:5992148b:node4'.

==> /opt/openhab2/userdata/logs/events.log <==
2017-03-30 17:18:21.915 [hingStatusInfoChangedEvent] - 'zwave:device:5992148b:node4' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2017-03-30 17:18:21.923 [hingStatusInfoChangedEvent] - 'zwave:device:5992148b:node4' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

==> /opt/openhab2/userdata/logs/openhab.log <==
2017-03-30 17:18:21.977 [ERROR] [ome.core.thing.internal.ThingManager] - Exception occured while calling thing updated at ThingHandler 'org.openhab.binding.zwave.handler.ZWaveThingHandler@114ab83': java.lang.NullPointerException
java.util.concurrent.ExecutionException: java.lang.NullPointerException
	at java.util.concurrent.FutureTask.report(FutureTask.java:122)[:1.8.0_65]
	at java.util.concurrent.FutureTask.get(FutureTask.java:206)[:1.8.0_65]
	at org.eclipse.smarthome.core.common.SafeMethodCaller.callAsynchronous(SafeMethodCaller.java:194)
	at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:83)
	at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:67)
	at org.eclipse.smarthome.core.thing.internal.ThingManager.thingUpdated(ThingManager.java:506)
	at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyTrackers(ThingRegistryImpl.java:227)
	at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyListenersAboutUpdatedElement(ThingRegistryImpl.java:150)
	at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyListenersAboutUpdatedElement(ThingRegistryImpl.java:1)
	at org.eclipse.smarthome.core.common.registry.AbstractRegistry.updated(AbstractRegistry.java:167)
	at org.eclipse.smarthome.core.common.registry.AbstractProvider.notifyListeners(AbstractProvider.java:57)
	at org.eclipse.smarthome.core.common.registry.AbstractProvider.notifyListenersAboutUpdatedElement(AbstractProvider.java:82)
	at org.eclipse.smarthome.core.common.registry.AbstractManagedProvider.update(AbstractManagedProvider.java:134)
	at org.eclipse.smarthome.io.rest.core.thing.ThingResource.update(ThingResource.java:422)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.8.0_65]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_65]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_65]
	at java.lang.reflect.Method.invoke(Method.java:497)[:1.8.0_65]
	at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)[158:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)[158:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:315)[158:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:297)[158:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:267)[158:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)[158:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76)[10:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:812)[82:org.eclipse.jetty.servlet:9.2.19.v20160908]
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:587)[82:org.eclipse.jetty.servlet:9.2.19.v20160908]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71)[173:org.ops4j.pax.web.pax-web-jetty:4.3.0]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577)[80:org.eclipse.jetty.security:9.2.19.v20160908]
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:287)[173:org.ops4j.pax.web.pax-web-jetty:4.3.0]
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)[82:org.eclipse.jetty.servlet:9.2.19.v20160908]
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80)[173:org.ops4j.pax.web.pax-web-jetty:4.3.0]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.eclipse.jetty.server.Server.handle(Server.java:499)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:311)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:544)[72:org.eclipse.jetty.io:9.2.19.v20160908]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)[84:org.eclipse.jetty.util:9.2.19.v20160908]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)[84:org.eclipse.jetty.util:9.2.19.v20160908]
	at java.lang.Thread.run(Thread.java:745)[:1.8.0_65]
Caused by: java.lang.NullPointerException
	at org.openhab.binding.zwave.handler.ZWaveThingHandler.updateNodeProperties(ZWaveThingHandler.java:1401)[190:org.openhab.binding.zwave:2.1.0.201703240758]
	at org.openhab.binding.zwave.handler.ZWaveThingHandler.bridgeStatusChanged(ZWaveThingHandler.java:457)[190:org.openhab.binding.zwave:2.1.0.201703240758]
	at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialize(ZWaveThingHandler.java:150)[190:org.openhab.binding.zwave:2.1.0.201703240758]
	at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.thingUpdated(BaseThingHandler.java:192)[106:org.eclipse.smarthome.core.thing:0.9.0.201703201701]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$7.call(ThingManager.java:510)[106:org.eclipse.smarthome.core.thing:0.9.0.201703201701]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$7.call(ThingManager.java:1)[106:org.eclipse.smarthome.core.thing:0.9.0.201703201701]
	at org.eclipse.smarthome.core.common.SafeMethodCaller$CallableWrapper.call(SafeMethodCaller.java:181)[99:org.eclipse.smarthome.core:0.9.0.201703201701]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_65]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_65]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_65]
	... 1 more

==> /opt/openhab2/userdata/logs/events.log <==
2017-03-30 17:18:22.073 [ThingUpdatedEvent         ] - Thing 'zwave:device:5992148b:node4' has been updated.

Which branch of OH are you using (snapshot or release)?

Please ensure you use the latest snapshot (ie from today) and then provide a debug log. I’ve added some additional debug to make sure we understand the issue.

Using the Snapshot release from today gave me pretty much the same thing (despite the fact that my Z-Wave light switches now work - yeey :thumbsup:)

==> /opt/openhab2/userdata/logs/openhab.log <==
2017-03-31 13:49:36.258 [INFO ] [ome.io.rest.core.thing.ThingResource] - Received HTTP PUT request for update config at 'things/zwave:device:5992148b:node3/config' for the unknown thing 'zwave:device:5992148b:node3'.

==> /opt/openhab2/userdata/logs/events.log <==
2017-03-31 13:49:36.317 [hingStatusInfoChangedEvent] - 'zwave:device:5992148b:node3' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2017-03-31 13:49:36.320 [hingStatusInfoChangedEvent] - 'zwave:device:5992148b:node3' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

==> /opt/openhab2/userdata/logs/openhab.log <==
2017-03-31 13:49:36.329 [ERROR] [ome.core.thing.internal.ThingManager] - Exception occured while calling thing updated at ThingHandler 'org.openhab.binding.zwave.handler.ZWaveThingHandler@14d677a': java.lang.NullPointerException
java.util.concurrent.ExecutionException: java.lang.NullPointerException
	at java.util.concurrent.FutureTask.report(FutureTask.java:122)[:1.8.0_65]
	at java.util.concurrent.FutureTask.get(FutureTask.java:206)[:1.8.0_65]
	at org.eclipse.smarthome.core.common.SafeMethodCaller.callAsynchronous(SafeMethodCaller.java:194)
	at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:83)
	at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:67)
	at org.eclipse.smarthome.core.thing.internal.ThingManager.thingUpdated(ThingManager.java:506)
	at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyTrackers(ThingRegistryImpl.java:227)
	at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyListenersAboutUpdatedElement(ThingRegistryImpl.java:150)
	at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyListenersAboutUpdatedElement(ThingRegistryImpl.java:1)
	at org.eclipse.smarthome.core.common.registry.AbstractRegistry.updated(AbstractRegistry.java:167)
	at org.eclipse.smarthome.core.common.registry.AbstractProvider.notifyListeners(AbstractProvider.java:57)
	at org.eclipse.smarthome.core.common.registry.AbstractProvider.notifyListenersAboutUpdatedElement(AbstractProvider.java:82)
	at org.eclipse.smarthome.core.common.registry.AbstractManagedProvider.update(AbstractManagedProvider.java:134)
	at org.eclipse.smarthome.io.rest.core.thing.ThingResource.update(ThingResource.java:422)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.8.0_65]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_65]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_65]
	at java.lang.reflect.Method.invoke(Method.java:497)[:1.8.0_65]
	at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)[158:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)[158:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:315)[158:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:297)[158:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:267)[158:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)[158:org.glassfish.jersey.core.jersey-common:2.22.2]
	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)[159:org.glassfish.jersey.core.jersey-server:2.22.2]
	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
	at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76)[10:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:812)[82:org.eclipse.jetty.servlet:9.2.19.v20160908]
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:587)[82:org.eclipse.jetty.servlet:9.2.19.v20160908]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71)[173:org.ops4j.pax.web.pax-web-jetty:4.3.0]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577)[80:org.eclipse.jetty.security:9.2.19.v20160908]
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:287)[173:org.ops4j.pax.web.pax-web-jetty:4.3.0]
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)[82:org.eclipse.jetty.servlet:9.2.19.v20160908]
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80)[173:org.ops4j.pax.web.pax-web-jetty:4.3.0]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.eclipse.jetty.server.Server.handle(Server.java:499)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:311)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)[81:org.eclipse.jetty.server:9.2.19.v20160908]
	at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:544)[72:org.eclipse.jetty.io:9.2.19.v20160908]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)[84:org.eclipse.jetty.util:9.2.19.v20160908]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)[84:org.eclipse.jetty.util:9.2.19.v20160908]
	at java.lang.Thread.run(Thread.java:745)[:1.8.0_65]
Caused by: java.lang.NullPointerException
	at org.openhab.binding.zwave.handler.ZWaveThingHandler.updateNodeProperties(ZWaveThingHandler.java:1401)[204:org.openhab.binding.zwave:2.1.0.201703310852]
	at org.openhab.binding.zwave.handler.ZWaveThingHandler.bridgeStatusChanged(ZWaveThingHandler.java:457)[204:org.openhab.binding.zwave:2.1.0.201703310852]
	at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialize(ZWaveThingHandler.java:150)[204:org.openhab.binding.zwave:2.1.0.201703310852]
	at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.thingUpdated(BaseThingHandler.java:192)[106:org.eclipse.smarthome.core.thing:0.9.0.201703201701]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$7.call(ThingManager.java:510)[106:org.eclipse.smarthome.core.thing:0.9.0.201703201701]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$7.call(ThingManager.java:1)[106:org.eclipse.smarthome.core.thing:0.9.0.201703201701]
	at org.eclipse.smarthome.core.common.SafeMethodCaller$CallableWrapper.call(SafeMethodCaller.java:181)[99:org.eclipse.smarthome.core:0.9.0.201703201701]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_65]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_65]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_65]
	... 1 more

This is expected as nothing was changed to fix the problem. What I wanted to see is the debug log.

I’m also slightly concerned that the version hasn’t changed as the line 1401 in the original log should now be 1403…

Well, these files give the following:

cat /opt/openhab2/userdata/tmp/mvn/org/openhab/binding/org.openhab.binding.zwave/2.1.0-SNAPSHOT/resolver-status.properties 
#NOTE: This is an Aether internal implementation file, its format can be changed without prior notice.
#Fri Mar 31 13:43:02 CEST 2017
maven-metadata-openhab.xml.lastUpdated=1490960582810
maven-metadata-openhab.xml.error=```

and

cat /opt/openhab2/userdata/tmp/mvn/org/openhab/binding/org.openhab.binding.zwave/2.1.0-SNAPSHOT/org.openhab.binding.zwave-2.1.0-SNAPSHOT.jar.sha1 

1ef3b95ab4e40544c985e941f9a14e1a0837c999

And since I’m now able to use my TZ37 lights, I did get a new version of the binding :confused:
Is there anything else I could do to double check this?

But as this was added a couple of days ago, it doesn’t mean that you got the version I created this morning…

Best is to do a list command in Karaf as that should show the bindings that are running.

However, please provide the log - if it’s got the extra information I added, then it’s updated. If it doesn’t, well, it hasn’t ;).

Is there a way to hook into Karaf when the service is already running? (I adapted the startup’s extra opts to get it to recognise my raspberry tty port)

Edit:
Logs refer to the binding in the following way: org.openhab.binding.zwave:2.1.0.201703310852
Which as far I’d interpret: Means the 31th of March, 08:52 ?

@chris I then mean: How do I get into the Karaf shell when the service is running? Only way I know off is running start.sh manually.

I’m not sure what you mean. You can only log in to Karaf, and send commands set when the service is running :confused:.

Have a read of the docs - you can ssh into Karaf, but this is all detailed in the documentation.

http://docs.openhab.org/administration/console.html

Thanks. Found it when you referred me to the docs. It was under the Advanced section, so hadn’t come across it yet.

Anyway, version is the one I reported earlier:
204 | Active | 80 | 2.1.0.201703310852 | ZWave Binding

Is that the version you deployed this morning?

Nope - that’s not the latest version.

Ok, so I tried bundle:stop 204, bundle:update 204 followed by a bundle:start 204.

Didn’t work as it still reports:
204 | Installed | 80 | 2.1.0.201703310852 | ZWave Binding

So this means that I haven’t done it correctly, or that the version you’re talking about isn’t available through this method.

How do I update it correctly?

Maybe it takes some more time to flow through the system - I’m not sure. If I look at the last build, it’s dated about 30 minutes later than this version…

Still getting build 2.1.0.201703310852.

How can I force this?
How do I give you the logs you want? Adjust the logging level to DEBUG? Is it possible doing that for this specific binding only?

Yes, you need to change the log level to debug, and yes you can do it just for a single bundle - the docs tell you how this is done (sorry - I can’t dig this out right now as I’m sitting on a plane).

This is what I receive after pushing the checkmark when trying to alter a Z-wave ‘thing’s’ configuration:

18:19:16.543 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Configuration update received
18:19:16.585 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Configuration update group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@5b8371 to []
18:19:16.589 [INFO ] [ome.io.rest.core.thing.ThingResource] - Received HTTP PUT request for update config at 'things/zwave:device:5992148b:node3/config' for the unknown thing 'zwave:device:5992148b:node3'.

I removed the maven cache in the userdata/tmp directory and then I tried a bundle:update again, nothing. Tried feature:repo-refresh, feature:install, nothing.
I always get the following version: 217 | Active | 80 | 2.1.0.201703310852 | ZWave Binding again.

Unforunately this isn’t related to the error you had, and if you’re still running the old version, then it still won’t have the debug information.

It looks like there’s a problem somewhere with the build so the system isn’t updating at the moment - that said, I still would have expected the last version I mentioned yesterday to have flowed through as that did build ok.

¯\(ツ)/¯ Guess it can’t be helped for now then? No manual way to do this?

I saw this (unrelated) error as well in the logs passing by btw, but that’s something entirely different https://gist.github.com/daneov/cfceee70b497e6080a5ae91a1b7cfe34

You can download the binding from the last stable link and manually install it, but you need to be careful with dependencies when you manually install bundles - you may also need to add the serial driver.

It’s a bit strange as it looks like the value is ok, but I’d need to see an unfiltered log to check what’s happening.