Naming Zwave Device in Habmin

ptmuldoon · March 31, 2016, 12:49am

I’m not sure if this helps or not. And I’m still running OH 1.8.2 and only update the zwave binding to 1.9, so not sure if that makes a difference or not as well. But this is part or the log. It could be I still have have the wrong binding?

2016-03-30 20:43:42.187 [INFO ] [rialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller
2016-03-30 20:43:42.187 [INFO ] [rialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------
2016-03-30 20:43:42.187 [INFO ] [rialApiGetInitDataMessageClass] - # Nodes = 14
2016-03-30 20:43:42.188 [INFO ] [rialApiGetInitDataMessageClass] - ----------------------------------------------------------------------------
2016-03-30 20:43:42.789 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 12: Unsupported command class SCENE_ACTUATOR_CONF
2016-03-30 20:43:42.803 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 11: Unsupported command class SCENE_ACTUATOR_CONF
2016-03-30 20:43:42.819 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 3: Unsupported command class SCENE_ACTUATOR_CONF
2016-03-30 20:43:42.835 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 9: Unsupported command class SCENE_ACTUATOR_CONF
2016-03-30 20:43:42.863 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 8: Unsupported command class SCENE_ACTUATOR_CONF
2016-03-30 20:43:42.883 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 10: Unsupported command class SCENE_ACTUATOR_CONF
2016-03-30 20:43:42.911 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 15: Unsupported command class SCENE_ACTUATOR_CONF
2016-03-30 20:43:42.951 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 16: Unsupported command class SCENE_ACTUATOR_CONF
2016-03-30 20:43:42.979 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 17: Unsupported command class SCENE_ACTUATOR_CONF
2016-03-30 20:43:43.003 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 14: Unsupported command class SCENE_ACTUATOR_CONF
2016-03-30 20:43:43.035 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 18: Unsupported command class SCENE_ACTUATOR_CONF
2016-03-30 20:43:43.491 [WARN ] [.b.z.i.c.ZWaveConverterHandler] - No converter found for command class = NODE_NAMING, ignoring event.
2016-03-30 20:43:43.523 [WARN ] [.b.z.i.c.ZWaveConverterHandler] - No converter found for command class = NODE_NAMING, ignoring event.
2016-03-30 20:43:43.555 [WARN ] [.b.z.i.c.ZWaveConverterHandler] - No converter found for command class = NODE_NAMING, ignoring event.
2016-03-30 20:43:43.587 [WARN ] [.b.z.i.c.ZWaveConverterHandler] - No converter found for command class = NODE_NAMING, ignoring event.
2016-03-30 20:43:43.618 [WARN ] [.b.z.i.c.ZWaveConverterHandler] - No converter found for command class = NODE_NAMING, ignoring event.
2016-03-30 20:43:43.649 [WARN ] [.b.z.i.c.ZWaveConverterHandler] - No converter found for command class = NODE_NAMING, ignoring event.
2016-03-30 20:43:43.682 [WARN ] [.b.z.i.c.ZWaveConverterHandler] - No converter found for command class = NODE_NAMING, ignoring event.
2016-03-30 20:43:43.715 [WARN ] [.b.z.i.c.ZWaveConverterHandler] - No converter found for command class = NODE_NAMING, ignoring event.
2016-03-30 20:43:43.748 [WARN ] [.b.z.i.c.ZWaveConverterHandler] - No converter found for command class = NODE_NAMING, ignoring event.
2016-03-30 20:43:43.777 [WARN ] [.b.z.i.c.ZWaveConverterHandler] - No converter found for command class = NODE_NAMING, ignoring event.
2016-03-30 20:43:43.807 [WARN ] [.b.z.i.c.ZWaveConverterHandler] - No converter found for command class = NODE_NAMING, ignoring event.
2016-03-30 20:43:43.851 [WARN ] [.b.z.i.c.ZWaveConverterHandler] - No converter found for command class = NODE_NAMING, ignoring event.
2016-03-30 20:43:43.852 [ERROR] [z.i.p.i.ZWaveNodeStageAdvancer] - NODE 12: Node advancer: Retries exceeded at DYNAMIC_VALUES
2016-03-30 20:43:43.947 [WARN ] [.b.z.i.c.ZWaveConverterHandler] - No converter found for command class = NODE_NAMING, ignoring event.

chris · March 31, 2016, 7:44am

Thanks @ptmuldoon. The versions are fine, but unfortunately the information I need is only printed in when debug logging is enabled.

JohnnyX · March 31, 2016, 8:42am

As promised, I did some tests with the updated v1.9.0 snapshot this morning - unfortunately not with success. At the end the binding throws a NPE
But the OPEN/CLOSED is still send correctly.

Test procedure:

1st wake up of sensative strip

2016-03-31 10:09:16.164 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class ZWAVE_PLUS_INFO
2016-03-31 10:09:16.164 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class DEVICE_RESET_LOCALLY
2016-03-31 10:09:16.164 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class ASSOCIATION_GROUP_INFO
2016-03-31 10:09:16.164 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class POWERLEVEL
2016-03-31 10:09:21.238 [ERROR] [WaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 2 attempts left!

2nd wake up of the sensative strip

2016-03-31 10:09:43.816 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class ZWAVE_PLUS_INFO
2016-03-31 10:09:43.816 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class DEVICE_RESET_LOCALLY
2016-03-31 10:09:43.816 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class ASSOCIATION_GROUP_INFO
2016-03-31 10:09:43.816 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class POWERLEVEL
2016-03-31 10:09:48.822 [ERROR] [WaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 1 attempts left!

3rd wake up of the sensative strip

2016-03-31 10:10:18.127 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class ZWAVE_PLUS_INFO
2016-03-31 10:10:18.127 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class DEVICE_RESET_LOCALLY
2016-03-31 10:10:18.127 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class ASSOCIATION_GROUP_INFO
2016-03-31 10:10:18.127 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class POWERLEVEL
2016-03-31 10:10:23.133 [ERROR] [WaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 0 attempts left!

4th wake up of the sensative strip

2016-03-31 10:10:43.850 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class ZWAVE_PLUS_INFO
2016-03-31 10:10:43.850 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class DEVICE_RESET_LOCALLY
2016-03-31 10:10:43.850 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class ASSOCIATION_GROUP_INFO
2016-03-31 10:10:43.850 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class POWERLEVEL
2016-03-31 10:10:48.859 [WARN ] [WaveController$ZWaveSendThread] - NODE 2: Too many retries. Discarding message: Message: class = SendData (0x13), type = Request (0x00), payload = 02 03 71 04 00

5th wake up of the sensative strip

2016-03-31 10:11:07.250 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class ZWAVE_PLUS_INFO
2016-03-31 10:11:07.250 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class DEVICE_RESET_LOCALLY
2016-03-31 10:11:07.250 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class ASSOCIATION_GROUP_INFO
2016-03-31 10:11:07.250 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 2: Unsupported command class POWERLEVEL

Now I checked in HABmin for any changes, especially in the register network.

no changes, still

Listening: undefined
Routing: undefined
Power: undefined
Neighbors: None

directly related with opening HABmin and my check for changes the following errors in my log where displayed in 1519 lines

2016-03-31 10:12:42.183 [ERROR] [i.h.s.p.PersistenceModelHelper] - Can’t open model file 'caldav’
2016-03-31 10:12:42.183 [ERROR] [i.h.s.p.PersistenceModelHelper] - Can’t open model file 'exec’
2016-03-31 10:12:42.183 [ERROR] [i.h.s.p.PersistenceModelHelper] - Can’t open model file 'caldav’
2016-03-31 10:12:42.183 [ERROR] [i.h.s.p.PersistenceModelHelper] - Can’t open model file 'exec’
It seems to be that every click from opening HABmin until I reached the register “Network” is related with a number of these errors.

Right after these 1519 lines the following exception is thrown:

2016-03-31 10:12:55.551 [ERROR] [.s.container.ContainerResponse] - The RuntimeException could not be mapped to a response, re-throwing to the HTTP container
java.lang.NullPointerException: null
	at org.openhab.binding.zwave.internal.config.ZWaveConfiguration.getConfiguration(ZWaveConfiguration.java:128) ~[bundlefile:na]
	at org.openhab.io.habmin.services.zwave.ZWaveConfigResource.getConfig(ZWaveConfigResource.java:73) ~[na:na]
	at sun.reflect.GeneratedMethodAccessor64.invoke(Unknown Source) ~[na:na]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:1.8.0_77]
	at java.lang.reflect.Method.invoke(Unknown Source) ~[na:1.8.0_77]
	at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$ResponseOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:205) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:302) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1542) [jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1473) [jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1419) [jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1409) [jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:409) [jersey-servlet-1.18.1.jar:1.18.1]
	at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:540) [jersey-servlet-1.18.1.jar:1.18.1]
	at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:715) [jersey-servlet-1.18.1.jar:1.18.1]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:848) [javax.servlet_3.0.0.v201112011016.jar:na]
	at org.atmosphere.util.AtmosphereFilterChain.doFilter(AtmosphereFilterChain.java:135) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.util.AtmosphereFilterChain.invokeFilterChain(AtmosphereFilterChain.java:96) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.handler.ReflectorServletProcessor$FilterChainServletWrapper.service(ReflectorServletProcessor.java:317) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.handler.ReflectorServletProcessor.onRequest(ReflectorServletProcessor.java:160) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.cpr.AsynchronousProcessor.action(AsynchronousProcessor.java:206) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.cpr.AsynchronousProcessor.suspended(AsynchronousProcessor.java:105) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.container.Jetty7CometSupport.service(Jetty7CometSupport.java:57) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.container.JettyAsyncSupportWithWebSocket.service(JettyAsyncSupportWithWebSocket.java:67) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.cpr.AtmosphereFramework.doCometSupport(AtmosphereFramework.java:2076) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.cpr.AtmosphereServlet.doPost(AtmosphereServlet.java:211) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.cpr.AtmosphereServlet.doGet(AtmosphereServlet.java:197) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:735) [javax.servlet_3.0.0.v201112011016.jar:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:848) [javax.servlet_3.0.0.v201112011016.jar:na]
	at org.eclipse.equinox.http.servlet.internal.ServletRegistration.service(ServletRegistration.java:61) [org.eclipse.equinox.http.servlet_1.1.300.v20120522-1841.jar:na]
	at org.eclipse.equinox.http.servlet.internal.ProxyServlet.processAlias(ProxyServlet.java:128) [org.eclipse.equinox.http.servlet_1.1.300.v20120522-1841.jar:na]
	at org.eclipse.equinox.http.servlet.internal.ProxyServlet.service(ProxyServlet.java:68) [org.eclipse.equinox.http.servlet_1.1.300.v20120522-1841.jar:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:848) [javax.servlet_3.0.0.v201112011016.jar:na]
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:598) [org.eclipse.jetty.servlet_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:486) [org.eclipse.jetty.servlet_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1065) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:413) [org.eclipse.jetty.servlet_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:192) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:999) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:250) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:111) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.Server.handle(Server.java:350) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:454) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:890) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:944) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:630) [org.eclipse.jetty.http_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:230) [org.eclipse.jetty.http_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:77) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:606) [org.eclipse.jetty.io_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:46) [org.eclipse.jetty.io_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:603) [org.eclipse.jetty.util_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:538) [org.eclipse.jetty.util_8.1.3.v20120522.jar:8.1.3.v20120522]
	at java.lang.Thread.run(Unknown Source) [na:1.8.0_77]
2016-03-31 10:12:55.554 [ERROR] [.a.h.ReflectorServletProcessor] - onRequest()
java.lang.NullPointerException: null
	at org.openhab.binding.zwave.internal.config.ZWaveConfiguration.getConfiguration(ZWaveConfiguration.java:128) ~[bundlefile:na]
	at org.openhab.io.habmin.services.zwave.ZWaveConfigResource.getConfig(ZWaveConfigResource.java:73) ~[na:na]
	at sun.reflect.GeneratedMethodAccessor64.invoke(Unknown Source) ~[na:na]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:1.8.0_77]
	at java.lang.reflect.Method.invoke(Unknown Source) ~[na:1.8.0_77]
	at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$ResponseOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:205) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:302) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1542) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1473) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1419) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1409) ~[jersey-server-1.18.1.jar:1.18.1]
	at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:409) ~[jersey-servlet-1.18.1.jar:1.18.1]
	at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:540) ~[jersey-servlet-1.18.1.jar:1.18.1]
	at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:715) ~[jersey-servlet-1.18.1.jar:1.18.1]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:848) [javax.servlet_3.0.0.v201112011016.jar:na]
	at org.atmosphere.util.AtmosphereFilterChain.doFilter(AtmosphereFilterChain.java:135) ~[atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.util.AtmosphereFilterChain.invokeFilterChain(AtmosphereFilterChain.java:96) ~[atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.handler.ReflectorServletProcessor$FilterChainServletWrapper.service(ReflectorServletProcessor.java:317) ~[atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.handler.ReflectorServletProcessor.onRequest(ReflectorServletProcessor.java:160) ~[atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.cpr.AsynchronousProcessor.action(AsynchronousProcessor.java:206) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.cpr.AsynchronousProcessor.suspended(AsynchronousProcessor.java:105) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.container.Jetty7CometSupport.service(Jetty7CometSupport.java:57) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.container.JettyAsyncSupportWithWebSocket.service(JettyAsyncSupportWithWebSocket.java:67) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.cpr.AtmosphereFramework.doCometSupport(AtmosphereFramework.java:2076) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.cpr.AtmosphereServlet.doPost(AtmosphereServlet.java:211) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at org.atmosphere.cpr.AtmosphereServlet.doGet(AtmosphereServlet.java:197) [atmosphere-runtime-2.2.5.jar:2.2.5]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:735) [javax.servlet_3.0.0.v201112011016.jar:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:848) [javax.servlet_3.0.0.v201112011016.jar:na]
	at org.eclipse.equinox.http.servlet.internal.ServletRegistration.service(ServletRegistration.java:61) [org.eclipse.equinox.http.servlet_1.1.300.v20120522-1841.jar:na]
	at org.eclipse.equinox.http.servlet.internal.ProxyServlet.processAlias(ProxyServlet.java:128) [org.eclipse.equinox.http.servlet_1.1.300.v20120522-1841.jar:na]
	at org.eclipse.equinox.http.servlet.internal.ProxyServlet.service(ProxyServlet.java:68) [org.eclipse.equinox.http.servlet_1.1.300.v20120522-1841.jar:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:848) [javax.servlet_3.0.0.v201112011016.jar:na]
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:598) [org.eclipse.jetty.servlet_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:486) [org.eclipse.jetty.servlet_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1065) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:413) [org.eclipse.jetty.servlet_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:192) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:999) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:250) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:111) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.Server.handle(Server.java:350) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:454) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:890) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:944) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:630) [org.eclipse.jetty.http_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:230) [org.eclipse.jetty.http_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:77) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:606) [org.eclipse.jetty.io_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:46) [org.eclipse.jetty.io_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:603) [org.eclipse.jetty.util_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:538) [org.eclipse.jetty.util_8.1.3.v20120522.jar:8.1.3.v20120522]
	at java.lang.Thread.run(Unknown Source) [na:1.8.0_77]
2016-03-31 10:12:55.558 [WARN ] [e.jetty.servlet.ServletHandler] - /services/habmin/zwave/products/
java.lang.RuntimeException: java.lang.NullPointerException
	at org.atmosphere.handler.ReflectorServletProcessor.onRequest(ReflectorServletProcessor.java:163) ~[na:na]
	at org.atmosphere.cpr.AsynchronousProcessor.action(AsynchronousProcessor.java:206) ~[na:na]
	at org.atmosphere.cpr.AsynchronousProcessor.suspended(AsynchronousProcessor.java:105) ~[na:na]
	at org.atmosphere.container.Jetty7CometSupport.service(Jetty7CometSupport.java:57) ~[na:na]
	at org.atmosphere.container.JettyAsyncSupportWithWebSocket.service(JettyAsyncSupportWithWebSocket.java:67) ~[na:na]
	at org.atmosphere.cpr.AtmosphereFramework.doCometSupport(AtmosphereFramework.java:2076) ~[na:na]
	at org.atmosphere.cpr.AtmosphereServlet.doPost(AtmosphereServlet.java:211) ~[na:na]
	at org.atmosphere.cpr.AtmosphereServlet.doGet(AtmosphereServlet.java:197) ~[na:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:735) ~[javax.servlet_3.0.0.v201112011016.jar:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:848) ~[javax.servlet_3.0.0.v201112011016.jar:na]
	at org.eclipse.equinox.http.servlet.internal.ServletRegistration.service(ServletRegistration.java:61) ~[na:na]
	at org.eclipse.equinox.http.servlet.internal.ProxyServlet.processAlias(ProxyServlet.java:128) ~[na:na]
	at org.eclipse.equinox.http.servlet.internal.ProxyServlet.service(ProxyServlet.java:68) ~[na:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:848) ~[javax.servlet_3.0.0.v201112011016.jar:na]
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:598) ~[org.eclipse.jetty.servlet_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:486) [org.eclipse.jetty.servlet_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1065) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:413) [org.eclipse.jetty.servlet_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:192) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:999) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:250) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:111) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.Server.handle(Server.java:350) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:454) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:890) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:944) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:630) [org.eclipse.jetty.http_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:230) [org.eclipse.jetty.http_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:77) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:606) [org.eclipse.jetty.io_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:46) [org.eclipse.jetty.io_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:603) [org.eclipse.jetty.util_8.1.3.v20120522.jar:8.1.3.v20120522]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:538) [org.eclipse.jetty.util_8.1.3.v20120522.jar:8.1.3.v20120522]
	at java.lang.Thread.run(Unknown Source) [na:1.8.0_77]
Caused by: java.lang.NullPointerException: null
	at org.openhab.binding.zwave.internal.config.ZWaveConfiguration.getConfiguration(ZWaveConfiguration.java:128) ~[na:na]
	at org.openhab.io.habmin.services.zwave.ZWaveConfigResource.getConfig(ZWaveConfigResource.java:73) ~[na:na]
	at sun.reflect.GeneratedMethodAccessor64.invoke(Unknown Source) ~[na:na]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:1.8.0_77]
	at java.lang.reflect.Method.invoke(Unknown Source) ~[na:1.8.0_77]
	at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60) ~[na:na]
	at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$ResponseOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:205) ~[na:na]
	at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75) ~[na:na]
	at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:302) ~[na:na]
	at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147) ~[na:na]
	at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108) ~[na:na]
	at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147) ~[na:na]
	at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84) ~[na:na]
	at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1542) ~[na:na]
	at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1473) ~[na:na]
	at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1419) ~[na:na]
	at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1409) ~[na:na]
	at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:409) ~[na:na]
	at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:540) ~[na:na]
	at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:715) ~[na:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:848) ~[javax.servlet_3.0.0.v201112011016.jar:na]
	at org.atmosphere.util.AtmosphereFilterChain.doFilter(AtmosphereFilterChain.java:135) ~[na:na]
	at org.atmosphere.util.AtmosphereFilterChain.invokeFilterChain(AtmosphereFilterChain.java:96) ~[na:na]
	at org.atmosphere.handler.ReflectorServletProcessor$FilterChainServletWrapper.service(ReflectorServletProcessor.java:317) ~[na:na]
	at org.atmosphere.handler.ReflectorServletProcessor.onRequest(ReflectorServletProcessor.java:160) ~[na:na]
	... 36 common frames omitted

chris · March 31, 2016, 8:54am

Thanks. The NPE isn’t directly related to this - it looks like a problem in the database. Unfortunately to really see what’s happening I’d need to see a debug log file. It looks though that the controller is receiving the NIF messages from the device, but the device isn’t responding to the controllers request (hence the timeouts). How far apart are they?

JohnnyX · March 31, 2016, 8:58am

I’ll try to repeat my tests in debug mode

Today: around 10 meters from basement to ground floor (with a lot of steel in the beton).

But: yesterday I already saw the same errors/timeouts (didn’t pay any attention to this since the open/close state was sent) and then the Strip was less than 1 meter away from the controller.

sihui · March 31, 2016, 5:24pm

But that NPE looks like a bug, see this thread:
Continuing the discussion from 1.8.2 and Habmin:
After reverting to an older 1.9.0 snapshot (1.9.0.201602250200) the NPE error is gone.
But I still haven’t found out why and when this error shows up, that’s the reason I did not yet open an issue …

chris · March 31, 2016, 5:49pm

Yes - I’m aware of that issue - I just meant that it’s not directly related to this issue.

I don’t really want to discuss this issue in this thread as it’s not related. We need to resolve the database problem, but clearly we can’t fix 1.8.2 - it will need to be resolved for 1.8.3 (whenever that is).

ptmuldoon · March 31, 2016, 10:21pm

@chris

Chris… I just ran OH1 in debug and have the log for you. Would it better to email/upload the entire thing or is their a specific piece/section I should try and copy here?

chris · March 31, 2016, 10:24pm

If it’s not toooooo big (ie not more than a few MB zipped up) then feel free to email (chris -at- cd-jackson.com). Otherwise, if you can dig out the section where the messages are being transferred for the node naming that would also be find…

ptmuldoon · March 31, 2016, 10:45pm

Because I had deleted the old log prior to running in debug, the file is actually less than 2mb.

I just emailed it to you and hopefully it helps.

chris · April 1, 2016, 12:20am

So, the issue is that the response coming in from the node with the ‘problem’ is reporting it’s using UTF-16. So, these are (probably) valid characters for this character set (I’m no expert on UTF16!). However, the data is actually ASCII (its set to ‘Testing’) so it gets incorrectly translated. Due to the fact that the device is reporting it’s using UTF16, I don’t seem to be able to filter these characters.

So, to get through this current issue I’m treating everything as ASCII - let’s see how that goes. Maybe there’s a middle ground we can find to support a wider character set…

ptmuldoon · April 1, 2016, 3:57pm

Chris,

I just gave the updated binding a try. And while I’m not seeing the strange symbols anymore, it also appears a name change is not ‘sticking’. When I change the name, after a few seconds the name just goes back to being blank. That was happening on occasion before the latest update as well, so could possibly still be related.

But what is also strange is that any node that I was able to name in the past, I can actually update those names. But any node that is currently blank will not take the name change and reverts back to blank?

I can restart OH1 in debug mode again if you would like?

chris · April 1, 2016, 4:10pm

Yes please - if you can get a log where you set and read it back, that would be good (it probably reads back automatically after setting, so just doing a set should get what I need).

I also found a bug in the way the values are set after I made the update last night. The commands are always sent with the UTF-16 encoding bit set, but I suspect they are really UTF-8 and this is probably why things are screwed up in the first place (ie why we have something that looks ASCII, but the node says it’s UTF-16).

ptmuldoon · April 1, 2016, 9:06pm

Chris

I just resent you another debug log. And I as mentioned in the email, it seems the names i entered earlier all of sudden are now showing. But when trying to change them again, it seems its not taking. All very strange, and hopefully the log helps uncover something.

chris · April 1, 2016, 10:55pm

Hmm - strange as I’ve hardcoded it to be ASCII

TheKorn · April 1, 2016, 10:56pm

Ha, I withdrew that message. Looks like it just took a moment to initialize. They’re gone now. (yay!)

chris · April 1, 2016, 10:57pm

Don’t do that to me

Good stuff - there’s still some issues to resolve… Are you able to set the values? I have a log from Paul, but will look at this tomorrow (gotta have a few hours kip!).

TheKorn · April 1, 2016, 11:10pm

Ha, sorry!

I can’t set the names. The names that I set previously are there (and BONUS! – correct), but if I change them to anything else they revert. And devices that don’t have a name I can’t set one. (Reverts to nothing.)

chris · April 2, 2016, 7:42am

Thanks - same as @ptmuldoon is seeing (which is good - I like something that’s reproducible ).

chris · April 2, 2016, 8:03am

I just had a look at Pauls log - it looks ok… I think the only issue is that there’s nothing to read the value back, so, we set the name (which looks ok), but we never read back an update. Since the value in the command class hasn’t changed, HABmin updates 5 seconds later with the old value… This should be fixed by adding a poll after the SET to update the value.

However, this should update when you restart OH, so can you restart and see if it updates? If it does, then I’ll make the change above…

Thanks
Chris