Aeotec Multisensor 6 (zwave)- Internal Server Error on update via paper UI

Hi guys,

I use the zwave controller with the Aeotec Multisensor 6 (USB powered) on the latest stable of openhab2.
If I try to edit the thing settings for this sensor I get the following exception when I try to save the settings via PaperUI:

20:15:35.356 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:4b8b5b14:node2' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE): Controller is offline
20:15:35.362 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:4b8b5b14:node2' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
20:15:35.368 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4b8b5b14_serial_sof changed from 353 to 354
20:15:35.373 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4b8b5b14_serial_ack changed from 150 to 151
20:15:35.379 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4b8b5b14_serial_sof changed from 354 to 355
20:15:35.391 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4b8b5b14_serial_sof changed from 355 to 356
20:15:35.402 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4b8b5b14_serial_sof changed from 356 to 357
20:15:35.409 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4b8b5b14_serial_ack changed from 151 to 152
20:15:35.414 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4b8b5b14_serial_sof changed from 357 to 358
20:15:35.430 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4b8b5b14_serial_sof changed from 358 to 359
20:15:35.435 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4b8b5b14_serial_ack changed from 152 to 153
20:15:35.443 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_4b8b5b14_serial_sof changed from 359 to 360
20:15:35.374 [ERROR] [ome.core.thing.internal.ThingManager] - Exception occurred while calling thing updated at ThingHandler 'org.openhab.binding.zwave.handler.ZWaveThingHandler@117ad9e': java.lang.NullPointerException
java.util.concurrent.ExecutionException: java.lang.NullPointerException
        at java.util.concurrent.FutureTask.report(FutureTask.java:122)[:1.8.0_144]
        at java.util.concurrent.FutureTask.get(FutureTask.java:206)[:1.8.0_144]
        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:524)
        at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyTrackers(ThingRegistryImpl.java:221)
        at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyListenersAboutUpdatedElement(ThingRegistryImpl.java:144)
        at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyListenersAboutUpdatedElement(ThingRegistryImpl.java:1)
        at org.eclipse.smarthome.core.common.registry.AbstractRegistry.updated(AbstractRegistry.java:177)
        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:133)
        at org.eclipse.smarthome.io.rest.core.thing.ThingResource.update(ThingResource.java:437)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.8.0_144]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_144]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_144]
        at java.lang.reflect.Method.invoke(Method.java:498)[:1.8.0_144]
        at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)[158:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144)[158:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161)[158:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160)[158:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99)[158:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389)[158:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347)[158:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102)[158:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326)[158:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)[157:org.glassfish.jersey.core.jersey-common:2.22.2]
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)[157:org.glassfish.jersey.core.jersey-common:2.22.2]
        at org.glassfish.jersey.internal.Errors.process(Errors.java:315)[157:org.glassfish.jersey.core.jersey-common:2.22.2]
        at org.glassfish.jersey.internal.Errors.process(Errors.java:297)[157:org.glassfish.jersey.core.jersey-common:2.22.2]
        at org.glassfish.jersey.internal.Errors.process(Errors.java:267)[157:org.glassfish.jersey.core.jersey-common:2.22.2]
        at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)[157:org.glassfish.jersey.core.jersey-common:2.22.2]
        at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)[158:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)[158:org.glassfish.jersey.core.jersey-server:2.22.2]
        at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473)[155:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
        at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427)[155:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388)[155:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341)[155:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228)[155:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
        at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76)[9:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:812)[81:org.eclipse.jetty.servlet:9.2.19.v20160908]
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:587)[81:org.eclipse.jetty.servlet:9.2.19.v20160908]
        at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71)[172:org.ops4j.pax.web.pax-web-jetty:4.3.0]
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)[80:org.eclipse.jetty.server:9.2.19.v20160908]
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577)[79:org.eclipse.jetty.security:9.2.19.v20160908]
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)[80:org.eclipse.jetty.server:9.2.19.v20160908]
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)[80:org.eclipse.jetty.server:9.2.19.v20160908]
        at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:287)[172:org.ops4j.pax.web.pax-web-jetty:4.3.0]
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)[81:org.eclipse.jetty.servlet:9.2.19.v20160908]
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)[80:org.eclipse.jetty.server:9.2.19.v20160908]
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)[80:org.eclipse.jetty.server:9.2.19.v20160908]
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)[80:org.eclipse.jetty.server:9.2.19.v20160908]
        at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80)[172:org.ops4j.pax.web.pax-web-jetty:4.3.0]
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)[80:org.eclipse.jetty.server:9.2.19.v20160908]
        at org.eclipse.jetty.server.Server.handle(Server.java:499)[80:org.eclipse.jetty.server:9.2.19.v20160908]
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:311)[80:org.eclipse.jetty.server:9.2.19.v20160908]
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)[80:org.eclipse.jetty.server:9.2.19.v20160908]
        at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:544)[71:org.eclipse.jetty.io:9.2.19.v20160908]
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)[83:org.eclipse.jetty.util:9.2.19.v20160908]
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)[83:org.eclipse.jetty.util:9.2.19.v20160908]
        at java.lang.Thread.run(Thread.java:748)[:1.8.0_144]
Caused by: java.lang.NullPointerException
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.updateNodeProperties(ZWaveThingHandler.java:1403)[206:org.openhab.binding.zwave:2.1.0]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.bridgeStatusChanged(ZWaveThingHandler.java:457)[206:org.openhab.binding.zwave:2.1.0]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialize(ZWaveThingHandler.java:150)[206:org.openhab.binding.zwave:2.1.0]
        at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.thingUpdated(BaseThingHandler.java:192)[105:org.eclipse.smarthome.core.thing:0.9.0.b5]
        at org.eclipse.smarthome.core.thing.internal.ThingManager$7.call(ThingManager.java:528)[105:org.eclipse.smarthome.core.thing:0.9.0.b5]
        at org.eclipse.smarthome.core.thing.internal.ThingManager$7.call(ThingManager.java:1)[105:org.eclipse.smarthome.core.thing:0.9.0.b5]
        at org.eclipse.smarthome.core.common.SafeMethodCaller$CallableWrapper.call(SafeMethodCaller.java:181)[98:org.eclipse.smarthome.core:0.9.0.b5]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_144]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)[:1.8.0_144]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)[:1.8.0_144]
        ... 1 more

Has anybody a hint for me what´s going wrong here?

Thanks & best

Please get a debug log - it will log more information immediately before this error occurs and will hopefully help work out what’s wrong.

Thanks Chris…
Added the following to my log config:

log:set DEBUG org.openhab.binding.zwave

in /var/lib/openhab2/etc/org.ops4j.pax.logging.cfg.
Then restarted the openhab2.service but I still don´t get more information.

Is this the correct way of changing the debug level?

Ok, made it via Karaf console. Here is the Debug information (only the first lines) when the PUT Request for updating the thing configuration is sent:

2017-08-16 22:23:27.249 [DEBUG] [org.eclipse.jetty.server.Server     ] - REQUEST PUT /rest/things/zwave:device:4b8b5b14:node2/config on HttpChannelOverHttp@9b265b{r=7,c=false,a=DISPATCHED,uri=/rest/things/zwave:device:4b8b5b14:node2/config}
2017-08-16 22:23:27.250 [DEBUG] [ax.web.service.spi.model.ServerModel] - Matching [/rest/things/zwave:device:4b8b5b14:node2/config]...
2017-08-16 22:23:27.251 [DEBUG] [ax.web.service.spi.model.ServerModel] - Path [/rest/things/zwave:device:4b8b5b14:node2/config] matched to {pattern=/rest/.*,model=ServletModel{id=org.ops4j.pax.web.service.spi.model.ServletModel-9,name=org.ops4j.pax.web.service.spi.model.ServletModel-9,urlPatterns=[/rest/*],alias=/rest,servlet=com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge@1fa4382,initParams={},context=ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-8,name=,httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [9], contextID=default],contextParams={},virtualHosts={},connectors={}}}}
2017-08-16 22:23:27.252 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/things/zwave:device:4b8b5b14:node2/config @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [9], contextID=default]}
2017-08-16 22:23:27.252 [DEBUG] [.jetty.server.handler.ContextHandler] - context=||/rest/things/zwave:device:4b8b5b14:node2/config @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [9], contextID=default]}
2017-08-16 22:23:27.253 [DEBUG] [org.eclipse.jetty.server.session    ] - sessionManager=org.ops4j.pax.web.service.jetty.internal.LateInvalidatingHashSessionManager@aefd46
2017-08-16 22:23:27.254 [DEBUG] [org.eclipse.jetty.server.session    ] - session=null
2017-08-16 22:23:27.255 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - servlet |/rest|/things/zwave:device:4b8b5b14:node2/config -> org.ops4j.pax.web.service.spi.model.ServletModel-9@378be101==com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge,-1,true
2017-08-16 22:23:27.255 [DEBUG] [ce.jetty.internal.HttpServiceContext] - Handling request for [/rest/things/zwave:device:4b8b5b14:node2/config] using http context [DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [9], contextID=default]]
2017-08-16 22:23:27.256 [DEBUG] [y.internal.HttpServiceServletHandler] - handling request org.ops4j.pax.web.service.jetty.internal.HttpServiceRequestWrapper@1e4fbca, org.ops4j.pax.web.service.jetty.internal.HttpServiceResponseWrapper@1231686
2017-08-16 22:23:27.257 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - chain=null
2017-08-16 22:23:27.265 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@9b265b{r=7,c=false,a=DISPATCHED,uri=/rest/things/zwave:device:4b8b5b14:node2/config} content java.nio.HeapByteBufferR[pos=478 lim=1468 cap=8192]
2017-08-16 22:23:27.267 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@9b265b{r=7,c=false,a=DISPATCHED,uri=/rest/things/zwave:device:4b8b5b14:node2/config} messageComplete
2017-08-16 22:23:27.268 [DEBUG] [org.eclipse.jetty.server.HttpInput  ] - HttpInputOverHTTP@7924f1 EOF
2017-08-16 22:23:27.269 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 SelectChannelEndPoint@c099b9{/192.168.0.119:56674<->8080,Open,in,out,-,-,23/30000,HttpConnection}{io=0,kio=0,kro=1}
2017-08-16 22:23:27.271 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@141f46e[FILLING,SelectChannelEndPoint@c099b9{/192.168.0.119:56674<->8080,Open,in,out,-,-,25/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=END,990 of 990},g=HttpGenerator{s=START},c=HttpChannelOverHttp@9b265b{r=7,c=false,a=DISPATCHED,uri=/rest/things/zwave:device:4b8b5b14:node2/config}] filled 0
2017-08-16 22:23:27.272 [DEBUG] [org.eclipse.jetty.server.HttpInput  ] - HttpInputOverHTTP@7924f1 eof EOF
2017-08-16 22:23:27.274 [DEBUG] [org.eclipse.jetty.server.HttpInput  ] - HttpInputOverHTTP@7924f1 eof EOF
2017-08-16 22:23:27.276 [DEBUG] [org.eclipse.jetty.server.HttpInput  ] - HttpInputOverHTTP@7924f1 eof EOF
2017-08-16 22:23:27.277 [DEBUG] [e.internal.ReaderInterceptorExecutor] - Message body reader (class org.eclipse.smarthome.io.rest.core.internal.GsonProvider) is trying to close the entity input stream. Not closing.
2017-08-16 22:23:27.283 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop woken up from select, 1/3 selected
2017-08-16 22:23:27.303 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop woken up from select, 1/3 selected
2017-08-16 22:23:27.305 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Key interests updated 1 -> 0 on SelectChannelEndPoint@135bbdf{/192.168.0.119:56675<->8080,Open,in,out,R,-,10070/30000,HttpConnection}{io=1,kio=0,kro=1}
2017-08-16 22:23:27.306 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Local interests updating 1 -> 0 for SelectChannelEndPoint@135bbdf{/192.168.0.119:56675<->8080,Open,in,out,R,-,10071/30000,HttpConnection}{io=0,kio=0,kro=1}
2017-08-16 22:23:27.307 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Queued change org.eclipse.jetty.io.SelectChannelEndPoint$1@1312cbe
2017-08-16 22:23:27.308 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Key interests updated 1 -> 0 on SelectChannelEndPoint@1b77428{/192.168.0.119:56676<->8080,Open,in,out,R,-,27653/30000,HttpConnection}{io=1,kio=0,kro=1}
2017-08-16 22:23:27.308 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILL_INTERESTED-->FILLING HttpConnection@1708144[FILLING,SelectChannelEndPoint@135bbdf{/192.168.0.119:56675<->8080,Open,in,out,-,-,10072/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@a55029{r=9,c=false,a=IDLE,uri=}]
2017-08-16 22:23:27.309 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@1312cbe
2017-08-16 22:23:27.310 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop waiting on select
2017-08-16 22:23:27.310 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@1708144[FILLING,SelectChannelEndPoint@135bbdf{/192.168.0.119:56675<->8080,Open,in,out,-,-,10074/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@a55029{r=9,c=false,a=IDLE,uri=}] onFillable HttpChannelState@1f9dddc{s=IDLE i=true a=null}
2017-08-16 22:23:27.311 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop woken up from select, 1/3 selected
2017-08-16 22:23:27.311 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Local interests updating 1 -> 0 for SelectChannelEndPoint@1b77428{/192.168.0.119:56676<->8080,Open,in,out,R,-,27656/30000,HttpConnection}{io=0,kio=0,kro=1}
2017-08-16 22:23:27.311 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 363 SelectChannelEndPoint@135bbdf{/192.168.0.119:56675<->8080,Open,in,out,-,-,10076/30000,HttpConnection}{io=0,kio=0,kro=1}
2017-08-16 22:23:27.312 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Queued change org.eclipse.jetty.io.SelectChannelEndPoint$1@90b54
2017-08-16 22:23:27.312 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Key interests updated 1 -> 0 on SelectChannelEndPoint@118504d{/192.168.0.119:56677<->8080,Open,in,out,R,-,27508/30000,HttpConnection}{io=1,kio=0,kro=1}
2017-08-16 22:23:27.312 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@a55029{r=10,c=false,a=IDLE,uri=/rest/channel-types} messageComplete
2017-08-16 22:23:27.313 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Local interests updating 1 -> 0 for SelectChannelEndPoint@118504d{/192.168.0.119:56677<->8080,Open,in,out,R,-,27508/30000,HttpConnection}{io=0,kio=0,kro=1}

Looks like we’ve got lots of logging from the REST server, but nothing from ZWave. There should be a log entry that shows the following -:

NODE xx: Property to update:

This should be right before the exception which also isn’t logged here. If I can see this logging it would be useful.

I´m sorry, there is no entry in my log containing “to update” or “NODE”. I´ve tons of log entries but the only interesting I can find are the following entries. The second one is from another zwave sensor when I try to update it via Paper UI:

Update of ZWave multisensor:
18:10:39.106 [ERROR] [ome.io.rest.core.thing.ThingResource] - Exception during HTTP PUT request for update config at ‘things/zwave:device:4b8b5b14:node2/config’ for thing ‘zwave:device:4b8b5b14:node2’: null

Update of ZWave Qubino Flush dimmer:
2017-08-18 18:16:38.851 [ERROR] [ome.io.rest.core.thing.ThingResource] - Exception during HTTP PUT request for update config at ‘things/zwave:device:4b8b5b14:node4/config’ for thing ‘zwave:device:4b8b5b14:node4’: For input string: “org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@16d37a0”

Here is the complete debug log after I click on the “check” icon when editing a the zwave thing - maybe you can see something interesting!?
http://dpaste.com/3M5BY5Y

Are you still getting the exception? I don’t see it in the log at all?

There’s nothing in here from the zwave binding, so it looks like it’s not getting as far as the binding. The only issue I see is this -:

2017-08-18 18:21:56.128 [ERROR] [ome.io.rest.core.thing.ThingResource] - Exception during HTTP PUT request for update config at 'things/zwave:device:4b8b5b14:node4/config' for thing 'zwave:device:4b8b5b14:node4': For input string: "org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@16d37a0"

This looks like a remnant from an old bug that was storing some rubbish in the configuration database. Is this a new setup, or has it been around for a while? Possible the easiest way to remove this might be to remove the thing and add it back and see if that helps?

It´s a complete fresh install (about three weeks old) on a raspberry pi 3… latest os, latest openhab2, all linux libs up-to-date.
The exception also appears on other things like the dimmer.

When I save the thing config in Paper UI I see the following in the bottom right:

  • Thing updated
  • ERROR 500: Internal Server Error

This does NOT happen if I edit the config for the Z-Wave Controller.

Another strange behaviour:
I had an old Genreation 5 Multisensor for Z-Wave. I´ve deleted the thing but it always appears again in the Inbox or is found if I search for new things. The sensor of course is not powered on any more and already back on the way to Amazon.

Is there a way I can edit things config without paper UI as a workaround?

Just have seen that you are the developer behind the zwave binding @chris. Thanks for the great work! :slight_smile:
Another hint I just found out: If I open the thing and try to remove a channel (by clicking on the circle icon next to the channel), the server returns a 404 message at the bottom right…

This only happens with all sensor channels. Adding and removing of the “Moving alarm” channel works without any problems for example.

Well, you can edit the json database, but it won’t help since the real issue I guess is that you haven’t excluded the device from the network. Therefore, it’s still known by the controller, and when the binding asks for a list of nodes, it finds it again.

You can try adding it as a thing, then use advanced mode in HABmin. There’s then two options in the thing menu - “add to failed items list”, and “remove item from controller” - use these two options in that order and it might remove the device.

I’ll have another look at this association issue…

Ok, it seems to be an issue/bug with Paper UI. If I try to change and persist the settings via HABmin it works like a charme… Thanks for the idea of using HABmin. Would you generally suggest to use HABmin instead of PaperUI for device configuration @chris?

I have the same problem with the Aeotec Multisensor. When I try to change a value it also triggers the same exception. When I try to set it with HABmin I get:

2018-12-17 14:25:42.236 [ERROR] [e.internal.WriterInterceptorExecutor] - MessageBodyWriter not found for media type=text/plain, type=class java.util.Collections$UnmodifiableCollection, genericType=class java.util.Collections$UnmodifiableCollection.

Old threat, I know…

This error should have been fixed in later versions of ESH - so if you are running a recent version of 2.4 snapshot, or the 2.4 release, it shouldn’t occur.

Running 2.3.0-1 I have an update to run toninght :slight_smile: Thanks!

1 Like