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

Setup, Configuration and Use Beginners
1

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

2

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

3

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?

4

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}
5

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.

6

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ā€

7

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

8

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?

9

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?

10

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.

11

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ā€¦

12

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?

13

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ā€¦

14

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.

15

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

1 Like