[SOLVED] Z-Wave dongle makes openhab crash

5iver · August 17, 2017, 10:40am

Yes, that was what I was thinking of. They used to provide a download of Zensys Tools too. Cool, it sounds like it’s not hardware!

I thought installing the zwave binding through PaperUI also put down the serial binding… must be wrong on that. But yes, you do need the serial binding! You can find it in PaperUI. Without the serial binding, you should have a bunch of errors in the log too… maybe they were during startup. Anyway, this will hopefully get you going!

ulfwin · August 17, 2017, 2:56pm

Hi again,

I installed the serial binding, but sadly that did not solve the problem. Exact same symptom as before. I tried restarting openhab and reinstalling the z-wave binding without luck…

I see there is also a “z-way” binding. Is that an alternative I could try perhaps?

5iver · August 17, 2017, 3:31pm

I am not familiar with zway, but if you’d like some more help with zwave, it would be very helpful if you would post some logs of the OH startup while the zstick is plugged in and the zwave binding in DEBUG. You may have examples of this in /var/lib/openhab2/logs/openhab.log.

chris · August 17, 2017, 3:36pm

My 2c worth is that this is more likely to be a hardware/driver sort of problem - it shouldn’t really be possible for the binding itself to crash OH - any errors there would just throw an exception. If things are really crashing out, then it’s more likely to be something in the JVM or low level routines.

Probably not - it requires the ZWave.me dongle and their software license.

ulfwin · August 17, 2017, 5:12pm

@5iver: I’ve pasted the output from my openhab.log file for one failed startup. Would be great if you could take a look!

2017-08-17 18:36:29.646 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Creating new ServletContextHandler for HTTP context [DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.9.0.b5 [99], contextID=default]] and model [ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-1,name=,httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.9.0.b5 [99], contextID=default],contextParams={},virtualHosts={},connectors={}}]
2017-08-17 18:36:29.787 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - configureSessionManager for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.9.0.b5 [99], contextID=default]}] using - timeout:10, cookie:JSESSIONID, url:jsessionid, cookieHttpOnly:false, workerName:null, lazyLoad:false, storeDirectory: null
2017-08-17 18:36:29.789 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session timeout set to 10 minutes for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.9.0.b5 [99], contextID=default]}]
2017-08-17 18:36:29.792 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie set to JSESSIONID for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.9.0.b5 [99], contextID=default]}]
2017-08-17 18:36:29.793 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookieHttpOnly set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.9.0.b5 [99], contextID=default]}]
2017-08-17 18:36:29.794 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie secure set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.9.0.b5 [99], contextID=default]}]
2017-08-17 18:36:29.795 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session URL set to jsessionid for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.9.0.b5 [99], contextID=default]}]
2017-08-17 18:36:29.796 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - is LazyLoad active? false
2017-08-17 18:36:29.797 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Added servlet context: HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.9.0.b5 [99], contextID=default]}
2017-08-17 18:36:30.340 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - ServletContextHandler for HTTP context [DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.9.0.b5 [99], contextID=default]] referenced [1] times.
2017-08-17 18:36:30.965 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Creating new ServletContextHandler for HTTP context [DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [9], contextID=default]] and model [ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-3,name=,httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [9], contextID=default],contextParams={},virtualHosts={},connectors={}}]
2017-08-17 18:36:30.995 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - configureSessionManager for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [9], contextID=default]}] using - timeout:10, cookie:JSESSIONID, url:jsessionid, cookieHttpOnly:false, workerName:null, lazyLoad:false, storeDirectory: null
2017-08-17 18:36:30.997 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session timeout set to 10 minutes for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [9], contextID=default]}]
2017-08-17 18:36:30.997 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie set to JSESSIONID for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [9], contextID=default]}]
2017-08-17 18:36:30.998 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookieHttpOnly set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [9], contextID=default]}]
2017-08-17 18:36:30.999 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie secure set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [9], contextID=default]}]
2017-08-17 18:36:31.000 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session URL set to jsessionid for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [9], contextID=default]}]
2017-08-17 18:36:31.001 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - is LazyLoad active? false
2017-08-17 18:36:31.001 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Added servlet context: HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [9], contextID=default]}
2017-08-17 18:36:31.002 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - (Re)starting servlet contexts...
2017-08-17 18:36:40.008 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mysql.persist'
2017-08-17 18:36:46.155 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Creating new ServletContextHandler for HTTP context [DefaultHttpContext [bundle=org.eclipse.smarthome.ui_0.9.0.b5 [136], contextID=default]] and model [ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-6,name=,httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui_0.9.0.b5 [136], contextID=default],contextParams={},virtualHosts={},connectors={}}]
2017-08-17 18:36:46.186 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - configureSessionManager for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui_0.9.0.b5 [136], contextID=default]}] using - timeout:10, cookie:JSESSIONID, url:jsessionid, cookieHttpOnly:false, workerName:null, lazyLoad:false, storeDirectory: null
2017-08-17 18:36:46.187 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session timeout set to 10 minutes for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui_0.9.0.b5 [136], contextID=default]}]
2017-08-17 18:36:46.188 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie set to JSESSIONID for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui_0.9.0.b5 [136], contextID=default]}]
2017-08-17 18:36:46.189 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookieHttpOnly set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui_0.9.0.b5 [136], contextID=default]}]
2017-08-17 18:36:46.189 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie secure set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui_0.9.0.b5 [136], contextID=default]}]
2017-08-17 18:36:46.190 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session URL set to jsessionid for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui_0.9.0.b5 [136], contextID=default]}]
2017-08-17 18:36:46.191 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - is LazyLoad active? false
2017-08-17 18:36:46.192 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Added servlet context: HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui_0.9.0.b5 [136], contextID=default]}
2017-08-17 18:36:46.192 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - (Re)starting servlet contexts...
2017-08-17 18:36:46.413 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Creating new ServletContextHandler for HTTP context [DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.9.0.b5 [137], contextID=default]] and model [ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-9,name=,httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.9.0.b5 [137], contextID=default],contextParams={},virtualHosts={},connectors={}}]
2017-08-17 18:36:46.438 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - configureSessionManager for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.9.0.b5 [137], contextID=default]}] using - timeout:10, cookie:JSESSIONID, url:jsessionid, cookieHttpOnly:false, workerName:null, lazyLoad:false, storeDirectory: null
2017-08-17 18:36:46.440 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session timeout set to 10 minutes for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.9.0.b5 [137], contextID=default]}]
2017-08-17 18:36:46.442 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie set to JSESSIONID for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.9.0.b5 [137], contextID=default]}]
2017-08-17 18:36:46.443 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookieHttpOnly set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.9.0.b5 [137], contextID=default]}]
2017-08-17 18:36:46.445 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie secure set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.9.0.b5 [137], contextID=default]}]
2017-08-17 18:36:46.447 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session URL set to jsessionid for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.9.0.b5 [137], contextID=default]}]
2017-08-17 18:36:46.449 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - is LazyLoad active? false
2017-08-17 18:36:46.451 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Added servlet context: HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.9.0.b5 [137], contextID=default]}
2017-08-17 18:36:46.453 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - (Re)starting servlet contexts...
2017-08-17 18:36:47.837 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Creating new ServletContextHandler for HTTP context [org.jupnp.transport.impl.osgi.DisableAuthenticationHttpContext@8bf37f] and model [ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-11,name=,httpContext=org.jupnp.transport.impl.osgi.DisableAuthenticationHttpContext@8bf37f,contextParams={},virtualHosts={},connectors={}}]
2017-08-17 18:36:47.866 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - configureSessionManager for context [HttpServiceContext{httpContext=org.jupnp.transport.impl.osgi.DisableAuthenticationHttpContext@8bf37f}] using - timeout:10, cookie:JSESSIONID, url:jsessionid, cookieHttpOnly:false, workerName:null, lazyLoad:false, storeDirectory: null
2017-08-17 18:36:47.868 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session timeout set to 10 minutes for context [HttpServiceContext{httpContext=org.jupnp.transport.impl.osgi.DisableAuthenticationHttpContext@8bf37f}]
2017-08-17 18:36:47.869 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie set to JSESSIONID for context [HttpServiceContext{httpContext=org.jupnp.transport.impl.osgi.DisableAuthenticationHttpContext@8bf37f}]
2017-08-17 18:36:47.870 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookieHttpOnly set to false for context [HttpServiceContext{httpContext=org.jupnp.transport.impl.osgi.DisableAuthenticationHttpContext@8bf37f}]
2017-08-17 18:36:47.872 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie secure set to false for context [HttpServiceContext{httpContext=org.jupnp.transport.impl.osgi.DisableAuthenticationHttpContext@8bf37f}]
2017-08-17 18:36:47.873 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session URL set to jsessionid for context [HttpServiceContext{httpContext=org.jupnp.transport.impl.osgi.DisableAuthenticationHttpContext@8bf37f}]
2017-08-17 18:36:47.874 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - is LazyLoad active? false
2017-08-17 18:36:47.876 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Added servlet context: HttpServiceContext{httpContext=org.jupnp.transport.impl.osgi.DisableAuthenticationHttpContext@8bf37f}
2017-08-17 18:36:47.877 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - (Re)starting servlet contexts...
2017-08-17 18:36:48.421 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Creating new ServletContextHandler for HTTP context [DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.1.0 [170], contextID=default]] and model [ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-13,name=,httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.1.0 [170], contextID=default],contextParams={},virtualHosts={},connectors={}}]
2017-08-17 18:36:48.462 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - configureSessionManager for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.1.0 [170], contextID=default]}] using - timeout:10, cookie:JSESSIONID, url:jsessionid, cookieHttpOnly:false, workerName:null, lazyLoad:false, storeDirectory: null
2017-08-17 18:36:48.464 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session timeout set to 10 minutes for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.1.0 [170], contextID=default]}]
2017-08-17 18:36:48.467 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie set to JSESSIONID for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.1.0 [170], contextID=default]}]
2017-08-17 18:36:48.470 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookieHttpOnly set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.1.0 [170], contextID=default]}]
2017-08-17 18:36:48.472 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie secure set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.1.0 [170], contextID=default]}]
2017-08-17 18:36:48.475 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session URL set to jsessionid for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.1.0 [170], contextID=default]}]
2017-08-17 18:36:48.477 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - is LazyLoad active? false
2017-08-17 18:36:48.480 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Added servlet context: HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.1.0 [170], contextID=default]}
2017-08-17 18:36:48.482 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - (Re)starting servlet contexts...
2017-08-17 18:36:48.535 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 192.168.0.6
2017-08-17 18:36:48.537 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://10.8.0.1:8080
2017-08-17 18:36:48.540 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 192.168.0.6
2017-08-17 18:36:48.542 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://10.8.0.1:8443
2017-08-17 18:36:48.873 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Creating new ServletContextHandler for HTTP context [DefaultHttpContext [bundle=org.eclipse.smarthome.ui.basic_0.9.0.b5 [176], contextID=default]] and model [ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-16,name=,httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.basic_0.9.0.b5 [176], contextID=default],contextParams={},virtualHosts={},connectors={}}]
2017-08-17 18:36:48.920 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - configureSessionManager for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.basic_0.9.0.b5 [176], contextID=default]}] using - timeout:10, cookie:JSESSIONID, url:jsessionid, cookieHttpOnly:false, workerName:null, lazyLoad:false, storeDirectory: null
2017-08-17 18:36:48.921 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session timeout set to 10 minutes for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.basic_0.9.0.b5 [176], contextID=default]}]
2017-08-17 18:36:48.922 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie set to JSESSIONID for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.basic_0.9.0.b5 [176], contextID=default]}]
2017-08-17 18:36:48.924 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookieHttpOnly set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.basic_0.9.0.b5 [176], contextID=default]}]
2017-08-17 18:36:48.951 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie secure set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.basic_0.9.0.b5 [176], contextID=default]}]
2017-08-17 18:36:48.953 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session URL set to jsessionid for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.basic_0.9.0.b5 [176], contextID=default]}]
2017-08-17 18:36:48.954 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - is LazyLoad active? false
2017-08-17 18:36:48.955 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Added servlet context: HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.basic_0.9.0.b5 [176], contextID=default]}
2017-08-17 18:36:48.956 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - (Re)starting servlet contexts...
2017-08-17 18:36:49.407 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2017-08-17 18:36:49.489 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Creating new ServletContextHandler for HTTP context [DefaultHttpContext [bundle=org.eclipse.smarthome.ui.paper_0.9.0.b5 [177], contextID=default]] and model [ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-20,name=,httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.paper_0.9.0.b5 [177], contextID=default],contextParams={},virtualHosts={},connectors={}}]
2017-08-17 18:36:49.526 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - configureSessionManager for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.paper_0.9.0.b5 [177], contextID=default]}] using - timeout:10, cookie:JSESSIONID, url:jsessionid, cookieHttpOnly:false, workerName:null, lazyLoad:false, storeDirectory: null
2017-08-17 18:36:49.528 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session timeout set to 10 minutes for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.paper_0.9.0.b5 [177], contextID=default]}]
2017-08-17 18:36:49.529 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie set to JSESSIONID for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.paper_0.9.0.b5 [177], contextID=default]}]
2017-08-17 18:36:49.531 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookieHttpOnly set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.paper_0.9.0.b5 [177], contextID=default]}]
2017-08-17 18:36:49.532 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie secure set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.paper_0.9.0.b5 [177], contextID=default]}]
2017-08-17 18:36:49.533 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session URL set to jsessionid for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.paper_0.9.0.b5 [177], contextID=default]}]
2017-08-17 18:36:49.534 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - is LazyLoad active? false
2017-08-17 18:36:49.536 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Added servlet context: HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.paper_0.9.0.b5 [177], contextID=default]}
2017-08-17 18:36:49.537 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - (Re)starting servlet contexts...
2017-08-17 18:36:49.549 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2017-08-17 18:36:49.635 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Creating new ServletContextHandler for HTTP context [DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.1.0 [179], contextID=default]] and model [ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-22,name=,httpContext=DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.1.0 [179], contextID=default],contextParams={},virtualHosts={},connectors={}}]
2017-08-17 18:36:49.674 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - configureSessionManager for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.1.0 [179], contextID=default]}] using - timeout:10, cookie:JSESSIONID, url:jsessionid, cookieHttpOnly:false, workerName:null, lazyLoad:false, storeDirectory: null
2017-08-17 18:36:49.675 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session timeout set to 10 minutes for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.1.0 [179], contextID=default]}]
2017-08-17 18:36:49.676 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie set to JSESSIONID for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.1.0 [179], contextID=default]}]
2017-08-17 18:36:49.677 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookieHttpOnly set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.1.0 [179], contextID=default]}]
2017-08-17 18:36:49.679 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie secure set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.1.0 [179], contextID=default]}]
2017-08-17 18:36:49.680 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session URL set to jsessionid for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.1.0 [179], contextID=default]}]
2017-08-17 18:36:49.681 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - is LazyLoad active? false
2017-08-17 18:36:49.682 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Added servlet context: HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.1.0 [179], contextID=default]}
2017-08-17 18:36:49.683 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - (Re)starting servlet contexts...
2017-08-17 18:36:49.694 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2017-08-17 18:36:51.784 [DEBUG] [org.openhab.binding.zwave           ] - BundleEvent STARTING - org.openhab.binding.zwave
2017-08-17 18:36:51.793 [DEBUG] [inding.zwave.internal.ZWaveActivator] - Z-Wave binding started. Version 2.1.0
2017-08-17 18:36:52.032 [DEBUG] [org.openhab.binding.zwave           ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.ConfigOptionProvider, org.eclipse.smarthome.config.core.ConfigDescriptionProvider}={component.name=org.openhab.binding.zwave.ConfigDescription, component.id=180, service.id=303, service.bundleid=192, service.scope=bundle} - org.openhab.binding.zwave
2017-08-17 18:36:52.045 [DEBUG] [org.openhab.binding.zwave           ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.events.EventFactory}={component.name=org.openhab.binding.zwave.event.BindingEventFactory, component.id=181, service.id=304, service.bundleid=192, service.scope=bundle} - org.openhab.binding.zwave
2017-08-17 18:36:52.090 [DEBUG] [org.openhab.binding.zwave           ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=org.openhab.binding.zwave.internal.ZWaveHandlerFactory, component.id=184, service.id=305, service.bundleid=192, service.scope=bundle} - org.openhab.binding.zwave
2017-08-17 18:36:52.092 [DEBUG] [org.openhab.binding.zwave           ] - BundleEvent STARTED - org.openhab.binding.zwave
2017-08-17 18:36:52.163 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Creating new ServletContextHandler for HTTP context [DefaultHttpContext [bundle=org.openhab.core_2.1.0 [166], contextID=default]] and model [ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-24,name=,httpContext=DefaultHttpContext [bundle=org.openhab.core_2.1.0 [166], contextID=default],contextParams={},virtualHosts={},connectors={}}]
2017-08-17 18:36:52.196 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - configureSessionManager for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core_2.1.0 [166], contextID=default]}] using - timeout:10, cookie:JSESSIONID, url:jsessionid, cookieHttpOnly:false, workerName:null, lazyLoad:false, storeDirectory: null
2017-08-17 18:36:52.197 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session timeout set to 10 minutes for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core_2.1.0 [166], contextID=default]}]
2017-08-17 18:36:52.198 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie set to JSESSIONID for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core_2.1.0 [166], contextID=default]}]
2017-08-17 18:36:52.199 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookieHttpOnly set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core_2.1.0 [166], contextID=default]}]
2017-08-17 18:36:52.201 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session cookie secure set to false for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core_2.1.0 [166], contextID=default]}]
2017-08-17 18:36:52.202 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Session URL set to jsessionid for context [HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core_2.1.0 [166], contextID=default]}]
2017-08-17 18:36:52.203 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - is LazyLoad active? false
2017-08-17 18:36:52.204 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - Added servlet context: HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core_2.1.0 [166], contextID=default]}
2017-08-17 18:36:52.205 [DEBUG] [ce.jetty.internal.JettyServerWrapper] - (Re)starting servlet contexts...
2017-08-17 18:36:56.776 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.link.ThingLinkManager@b53227' takes more than 5000ms.
2017-08-17 18:36:56.958 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.
2017-08-17 18:36:56.961 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller.
2017-08-17 18:36:56.965 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'

@chris: I fear you’re right… would you have any tip for me to continue if this i the case? I’ve been searching for a tool to debug the z-stick but not found any. I’m using zulu since that was recommended. Is it an idea to try openJDK instead? Do you have any other idea how I can dig deeper?

chris · August 17, 2017, 5:24pm

Based on the log, if this is all there is, then the binding isn’t even talking to the stick. It’s trying to open the serial port, and then it seems to crash out. I’m pretty sure this is going to be a low level issue - drivers or something like that.

You could try any serial port software to see if the port opens or not - that might at least provide some information since the binding isn’t even getting that far.

5iver · August 17, 2017, 6:12pm

Just to get this out of the way… turn off the trace logging for jetty.

You confirmed dmesg | grep tty only returned ttyACM0. This command will provide some device details (including driver).

udevadm info --a -p $(udevadm info -q path -n /dev/ttyACM0)

ulfwin · August 17, 2017, 6:33pm

Ah, that reduced the messages quite a bit :). Here it is:

2017-08-17 20:26:39.935 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mysql.persist'
2017-08-17 20:26:48.271 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 192.168.0.6
2017-08-17 20:26:48.275 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://10.8.0.1:8080
2017-08-17 20:26:48.279 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 192.168.0.6
2017-08-17 20:26:48.282 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://10.8.0.1:8443
2017-08-17 20:26:49.047 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2017-08-17 20:26:49.226 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2017-08-17 20:26:49.482 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2017-08-17 20:26:56.829 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'

It appears I don’t have udevadm installed, and it doesn’t exist using apt-get. I’ll look into it to see if I can get it installed…

5iver · August 17, 2017, 6:47pm

How about stty -F /dev/ttyACM0? If it gets a response, the port should be working.

ulfwin · August 18, 2017, 9:44am

Hi @5iver,

There appears to be a response:

debian@debian-armhf:/usr/lib/jvm$ sudo stty -F /dev/ttyACM0
speed 9600 baud; line = 0;
min = 0; time = 0;
-brkint -icrnl -imaxbel
-opost -onlcr
-isig -icanon -iexten -echo -echoe -echok -echoctl -echoke

I read in the openhab installation instructions that java for ARM 64 bit specifically fails for serial communication. I am using 32 bit, but It made me start fiddling with java.

I’ve tried openjdk 6 and 7 (which are not supposed to work anyway I guess), and zulu version 1.8.0_131 and 1.8.0_121, but none of them make any difference.

I also tried to communicate with the dongle using minicom, but I have not figured out exactly what config I need, so no result there.

Do you guys have any other idea of what I might try?

5iver · August 18, 2017, 11:37am

Can you run stty with the account running OH, to make sure it has the permissions it needs? Does anything change if you run OH as root?

ulfwin · August 18, 2017, 1:51pm

Tried your suggestion but no hit I’m afraid:

debian@debian-armhf:/usr/lib/jvm$ sudo -u openhab stty -F /dev/ttyACM0
[sudo] password for debian: 
speed 9600 baud; line = 0;
min = 0; time = 0;
-brkint -icrnl -imaxbel
-opost -onlcr
-isig -icanon -iexten -echo -echoe -echok -echoctl -echoke

I also temporarily changed the init.d script to run as root, but I see the same symptom. Appears to be a tricky issue, this one…

5iver · August 18, 2017, 2:46pm

Here is the stty result from my zstick:

[root@fedora01 rules]# stty -F /dev/ttyACM0
speed 115200 baud; line = 0;
eof = ^A; min = 1; time = 0;
-brkint -icrnl -imaxbel
-opost -onlcr
-isig -icanon -iexten -echo -echoe -echok -echoctl -echoke

The baud rate stands out to me, but the eof might come into play too. The binding may set the baud rate for you (@chris would know). If not, that might be something to try (stty -F /dev/ttyACM0 115200).

Yes… but there has to be a log somewhere with some details . Here are some more things I would try…

Is Java core dumping?
Maybe running OH in debug mode would show something new.
I’m not sure how you are viewing the log, but it looks like you may be sshing into the Karaf console and viewing the log. Can you use ssh into the Wandboard and manually launch OH to see if there’s more being reported after the ssh session ends?
Have you looked into the actual log file and does it literally just stop after connecting to the serial port, or is there more in the file? If you’re manually running OH, you could also then use strace to dig deeper.
To possibly rule out Java as the issue, you could try another app and see if it can communicate with the port. It’s a little old, but maybe something like Java Serial Port Terminal download | SourceForge.net.

chris · August 18, 2017, 2:54pm

Yes - the baud rate is set by the binding (I don’t think it’s possible to open a serial port without specifying the baud rate).

ulfwin · August 18, 2017, 5:40pm

Finally I got an error message! Only one line, but still. I searched for a “core.pid” file in the whole file system, but found none. However, if I manually ran java and openhab, I got this message:

/usr/lib/jvm/zulu-embedded-8-armhf/bin/java: symbol lookup error: /var/lib/openhab2/tmp/libNRJavaSerial_HF_root_0/libNRJavaSerial_HF.so: undefined symbol: __fdelt_chk

Does this say anything to you guys?

Perhaps it is of interest to know how I manually ran openhab. I simply copied the line from ps -ef, after starting it with sudo service openhab2 start. It’s a super long line. Here it is:

sudo /usr/lib/jvm/zulu-embedded-8-armhf/bin/java -Dopenhab.home=/usr/share/openhab2 -Dopenhab.conf=/etc/openhab2 -Dopenhab.runtime=/usr/share/openhab2/runtime -Dopenhab.userdata=/var/lib/openhab2 -Dopenhab.logdir=/var/log/openhab2 -Dfelix.cm.dir=/var/lib/openhab2/config -Djetty.host=0.0.0.0 -Dorg.ops4j.pax.web.listening.addresses=0.0.0.0 -Dorg.osgi.service.http.port=8080 -Dorg.osgi.service.http.port.secure=8443 -Dopenhab.home=/usr/share/openhab2 -Dopenhab.conf=/etc/openhab2 -Dopenhab.runtime=/usr/share/openhab2/runtime -Dopenhab.userdata=/var/lib/openhab2 -Dopenhab.logdir=/var/log/openhab2 -Dfelix.cm.dir=/var/lib/openhab2/config -Djetty.host=0.0.0.0 -Dorg.ops4j.pax.web.listening.addresses=0.0.0.0 -Dorg.osgi.service.http.port=8080 -Dorg.osgi.service.http.port.secure=8443 -Djava.awt.headless=true -Djava.awt.headless=true -Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0:/dev/ttyS0:/dev/ttyS2:/dev/ttyACM0:/dev/ttyAMA0 -Djava.endorsed.dirs=/usr/lib/jvm/zulu-embedded-8-armhf/jre/lib/endorsed:/usr/lib/jvm/zulu-embedded-8-armhf/lib/endorsed:/usr/share/openhab2/runtime/lib/endorsed -Djava.ext.dirs=/usr/lib/jvm/zulu-embedded-8-armhf/jre/lib/ext:/usr/lib/jvm/zulu-embedded-8-armhf/lib/ext:/usr/share/openhab2/runtime/lib/ext -Dkaraf.instances=/usr/share/openhab2/runtime/instances -Dkaraf.home=/usr/share/openhab2/runtime -Dkaraf.base=/var/lib/openhab2 -Dkaraf.data=/var/lib/openhab2 -Dkaraf.etc=/var/lib/openhab2/etc -Dkaraf.restart.jvm.supported=true -Djava.io.tmpdir=/var/lib/openhab2/tmp -Djava.util.logging.config.file=/var/lib/openhab2/etc/java.util.logging.properties -Dkaraf.startLocalConsole=false -Dkaraf.startRemoteShell=true -classpath /usr/share/openhab2/runtime/lib/boot/org.apache.karaf.diagnostic.boot-4.0.8.jar:/usr/share/openhab2/runtime/lib/boot/org.apache.karaf.jaas.boot-4.0.8.jar:/usr/share/openhab2/runtime/lib/boot/org.apache.karaf.main-4.0.8.jar:/usr/share/openhab2/runtime/lib/boot/org.osgi.core-6.0.0.jar org.apache.karaf.main.Main

5iver · August 18, 2017, 6:07pm

No, but this looks similar and there are some other posts in the forum. Maybe you need a newer glibc?

github.com/openhab/openhab-core

nrjavaserial 3.12.0 requires glibc > 2.13

opened 05:22PM - 12 Jan 17 UTC

closed 09:08AM - 15 Apr 20 UTC

tsheldon

tl;dr; fresh install of oh 2.0.0~20170111215718 which includes nrjavaserial 3.1…2.0 causes silent failure with zwave (and possibly rfxcom) binding. After seeing the announcement of moving to Bintray, I went and ran the upgrade as described in the thread. The system immediately started crashing on startup when trying to open the serial port. After debugging for a bit, I decided to purge the install and start fresh. When I did, OH started fine. *until* I installed just the zwave binding. As soon as the binding tried to open the serial port, it started crashing again. The only debug info I have been able to retrieve is this: ``` 09:19:22.535 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0' /usr/bin/java: symbol lookup error: /var/lib/openhab2/tmp/libNRJavaSerial_HF_openhab_0/libNRJavaSerial_HF.so: undefined symbol: __fdelt_chk ``` <bountysource-plugin> --- Want to back this issue? **[Post a bounty on it!](https://www.bountysource.com/issues/40893788-nrjavaserial-3-12-0-requires-glibc-2-13?utm_campaign=plugin&utm_content=tracker%2F28054058&utm_medium=issues&utm_source=github)** We accept bounties via [Bountysource](https://www.bountysource.com/?utm_campaign=plugin&utm_content=tracker%2F28054058&utm_medium=issues&utm_source=github). </bountysource-plugin>

Why not run start.sh?

ulfwin · August 18, 2017, 9:05pm

It appears you are correct! I have glibc 2.13. I tried to replace nrjavaserial with the patched one in the post, but I must be doing something wrong. I replaced the file in this directory:

/usr/share/openhab2/runtime/system/org/openhab/nrjavaserial/3.12.0.OH

It didn’t change anything, but also I noticed that I could remove the file completely with exactly the same behavior (I would expect some openhab error message instead). Is the addon actually used located somewhere else perhaps?

This is where it shows why I chose the beginner category for this question Now I know, thanks!

ulfwin · August 19, 2017, 11:28am

Perhaps I should move my question above to the other thread. Now I know what the problem is, and worst case I have to update my debian to a newer version, so I’m marking this as solved!

Thanks to all of you!

5iver · August 21, 2017, 11:11pm

I thought I read in the PR that you’d need to uninstall nrjavaserial (from Karaf, bundle:uninstall nrjavaserial should do it), then drop the jar with the patch into the Addons directory. Have you tried that?

We all have to start some place!

ulfwin · August 22, 2017, 5:20pm

Your suggestion worked! This saves me a lot of hassle updating the OS, so I’m very happy, thank you! I’ll give the detailed instruction to the git issue as well, in case somebody struggled like me.