openHAB 2.0 binding
OpenHAB
534
Posts
88
Posters
479.5k
Views
99
Watching
-
Hi All
Big thumb up to all those who made it possible, awsome job here
Truely amazing for us diyers to have access to that technology so easily. Thanks a lotBUT! I have a problem with binding... in short :
1- I installed openhab2 on RPi3 with a fresh SDCard
2-Updated java (as per https://community.openhab.org/t/my-openhab-connectio-failed/12957/11)
3- I followed tobof 's excellent step-by-step howto
4- I installed mysGateway (RPi acting as controller AND gateway)
5- Withpi@raspberrypi:~/MySensors $ sudo ./examples_linux/mysGateway -di can see that my motion sensor and my RPi gateway get on wellmysGateway: Starting gateway... mysGateway: Protocol version - 2.0.1-beta mysGateway: MCO:BGN:INIT GW,CP=RNNG---,VER=2.0.1-beta mysGateway: TSF:LRT:OK mysGateway: TSM:INIT mysGateway: TSM:INIT:TSP OK mysGateway: TSM:INIT:GW MODE mysGateway: TSM:READY mysGateway: MCO:REG:NOT NEEDED mysGateway: MCO:BGN:STP mysGateway: MCO:BGN:INIT OK,ID=0,PAR=0,DIS=0,REG=1 mysGateway: TSF:MSG:READ,1-1-0,s=1,c=1,t=16,pt=0,l=1,sg=0:1 mysGateway: TSF:MSG:READ,1-1-0,s=1,c=1,t=16,pt=0,l=1,sg=0:0 mysGateway: TSF:MSG:READ,1-1-0,s=1,c=1,t=16,pt=0,l=1,sg=0:1 mysGateway: TSF:MSG:READ,1-1-0,s=1,c=1,t=16,pt=0,l=1,sg=0:06- created a thing (text editor) for the bridge
pi@raspberrypi:/usr/share/openhab2/conf/things $ nano home.thingsBridge mysensors:bridge-ser:gateway [ serialPort="/dev/pts/2", sendDelay=200 ] { }7- Following openhab2 "live" log with
pi@raspberrypi:/usr/share/openhab2 $ sudo ./start_debug.sh05:37:32.536 [DEBUG] [org.openhab.binding.mysensors ] - BundleEvent STARTING - org.openhab.binding.mysensors 05:37:32.561 [DEBUG] [org.openhab.binding.mysensors ] - BundleEvent STARTED - org.openhab.binding.mysensors 05:37:32.789 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=org.openhab.binding.mysensors.internal.MySensorsHandlerFactory, component.id=0, service.id=110, service.bundleid=10, service.scope=bundle} - org.openhab.binding.mysensors 05:37:50.539 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'home.items' 05:37:58.611 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'home.sitemap' 05:37:59.319 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'home.things' 05:37:59.664 [INFO ] [smarthome.event.ThingAddedEvent ] - Thing 'mysensors:bridge-ser:gateway' has been added. 05:38:00.412 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=232, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors 05:38:00.435 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:bridge-ser, thing.id=mysensors:bridge-ser:gateway, service.id=233, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors 05:38:00.473 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-ser:gateway' changed from UNINITIALIZED to INITIALIZING 05:38:00.474 [DEBUG] [nsors.handler.MySensorsBridgeHandler] - Initialization of the MySensors Bridge 05:38:00.594 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'MotionTest-mysensors:motion:1584d6773a3:armed' has been added. 05:38:00.605 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'MotionTest-mysensors:motion:1584d6773a3:tripped' has been added. RXTX Warning: Removing stale lock file. /var/lock/LCK..ttyAMA0 05:38:00.658 [DEBUG] [col.serial.MySensorsSerialConnection] - Successfully connected to serial port. 05:38:00.677 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-ser:gateway' changed from INITIALIZING to ONLINE 05:38:05.333 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app 05:38:06.180 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app 05:38:08.009 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui 05:38:08.223 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start 05:38:08.951 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin 05:38:09.203 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel 05:38:11.343 [INFO ] [o.myopenhab.internal.MyOpenHABClient] - Connected to my.openHAB service (UUID = 7c0faa03-e826-473a-b1f7-8b685b487bb8, base URL = http://localhost:8080)Looks pretty to me...
8- but then i try to register my sensor (arduino pro and 501PIR sensor) with paper UI
No luck. Discovery window stays on forever!
0_1479359161452_Scan.jpegsudo usermod -a -G dialout openhabreturns "unknown user" ...Any clue ?
Thanks a lot for your help ! -
Binding is still unsuccessful
Following error disapeared (Updated my previous post).
Guess that happened as RPi started reboot before openhab session was properly closed... 3 reboots cured that error...in
pi@raspberrypi:/usr/share/openhab2/userdata/logs $ nano openhab.log:2016-11-17 06:40:00.094 [DEBUG] [org.openhab.binding.mysensors ] - BundleEvent STARTING - org.openhab.binding.mysensors 2016-11-17 06:40:00.383 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=org.openhab.bindin$ 2016-11-17 06:40:00.480 [DEBUG] [org.openhab.binding.mysensors ] - BundleEvent STARTED - org.openhab.binding.mysensors 2016-11-17 06:40:11.249 [WARN ] [eclipse.jetty.servlet.ServletHandler] - javax.servlet.ServletException: A MultiException has 1 exceptions. They are: 1. java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_0,0,33431755) has been shut down at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:489)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76)[12:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253] at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:812)[82:org.eclipse.jetty.servlet:9.2.14.v20151106] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:587)[82:org.eclipse.jetty.servlet:9.2.14.v20151106] at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:70)[173:org.ops4j.pax.web.pax-web-jetty:4.2.4] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577)[80:org.eclipse.jetty.security:9.2.14.v20151106] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:271)[173:org.ops4j.pax.web.pax-web-jetty:4.2.4] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)[82:org.eclipse.jetty.servlet:9.2.14.v20151106] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80)[173:org.ops4j.pax.web.pax-web-jetty:4.2.4] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.Server.handle(Server.java:499)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:311)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:544)[73:org.eclipse.jetty.io:9.2.14.v20151106] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)[84:org.eclipse.jetty.util:9.2.14.v20151106] at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)[84:org.eclipse.jetty.util:9.2.14.v20151106] at java.lang.Thread.run(Thread.java:745)[:1.8.0_111] Caused by: A MultiException has 1 exceptions. They are: 1. java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_0,0,33431755) has been shut down at org.jvnet.hk2.internal.FactoryCreator.getFactoryHandle(FactoryCreator.java:106)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.FactoryCreator.dispose(FactoryCreator.java:173)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.SystemDescriptor.dispose(SystemDescriptor.java:526)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.glassfish.jersey.process.internal.RequestScope$Instance.remove(RequestScope.java:532)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.process.internal.RequestScope$Instance.release(RequestScope.java:549)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:319)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] ... 26 more Caused by: java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_0,0,33431755) has been shut down at org.jvnet.hk2.internal.ServiceLocatorImpl.checkState(ServiceLocatorImpl.java:2288)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandleImpl(ServiceLocatorImpl.java:629)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandle(ServiceLocatorImpl.java:622)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandle(ServiceLocatorImpl.java:640)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.FactoryCreator.getFactoryHandle(FactoryCreator.java:103)[151:org.glassfish.hk2.locator:2.4.0.b34] ... 34 more 2016-11-17 06:40:11.296 [WARN ] [org.eclipse.jetty.server.HttpChannel] - /rest/events javax.servlet.ServletException: javax.servlet.ServletException: A MultiException has 1 exceptions. They are: 1. java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_0,0,33431755) has been shut down at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:88)[173:org.ops4j.pax.web.pax-web-jetty:4.2.4] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.Server.handle(Server.java:499)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:311)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:544)[73:org.eclipse.jetty.io:9.2.14.v20151106] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)[84:org.eclipse.jetty.util:9.2.14.v20151106] at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)[84:org.eclipse.jetty.util:9.2.14.v20151106] at java.lang.Thread.run(Thread.java:745)[:1.8.0_111] Caused by: javax.servlet.ServletException: A MultiException has 1 exceptions. They are: 1. java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_0,0,33431755) has been shut down at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:489)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76)[12:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253] at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:812)[82:org.eclipse.jetty.servlet:9.2.14.v20151106] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:587)[82:org.eclipse.jetty.servlet:9.2.14.v20151106] at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:70)[173:org.ops4j.pax.web.pax-web-jetty:4.2.4] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577)[80:org.eclipse.jetty.security:9.2.14.v20151106] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:271)[173:org.ops4j.pax.web.pax-web-jetty:4.2.4] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)[82:org.eclipse.jetty.servlet:9.2.14.v20151106] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80)[173:org.ops4j.pax.web.pax-web-jetty:4.2.4] ... 8 more Caused by: A MultiException has 1 exceptions. They are: 1. java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_0,0,33431755) has been shut down at org.jvnet.hk2.internal.FactoryCreator.getFactoryHandle(FactoryCreator.java:106)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.FactoryCreator.dispose(FactoryCreator.java:173)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.SystemDescriptor.dispose(SystemDescriptor.java:526)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.glassfish.jersey.process.internal.RequestScope$Instance.remove(RequestScope.java:532)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.process.internal.RequestScope$Instance.release(RequestScope.java:549)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:319)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:319)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] ... 26 more Caused by: java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_0,0,33431755) has been shut down at org.jvnet.hk2.internal.ServiceLocatorImpl.checkState(ServiceLocatorImpl.java:2288)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandleImpl(ServiceLocatorImpl.java:629)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandle(ServiceLocatorImpl.java:622)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandle(ServiceLocatorImpl.java:640)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.FactoryCreator.getFactoryHandle(FactoryCreator.java:103)[151:org.glassfish.hk2.locator:2.4.0.b34] ... 34 more 2016-11-17 06:40:11.330 [WARN ] [org.eclipse.jetty.server.HttpChannel] - Could not send response error 500: javax.servlet.ServletException: javax.servlet.ServletException: A MultiException has 1 e$ 1. java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_0,0,33431755) has been shut down 2016-11-17 06:40:20.925 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'home.items' 2016-11-17 06:40:28.127 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'home.sitemap' 2016-11-17 06:40:29.101 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'home.things' 2016-11-17 06:40:30.364 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=235, service.bundleid=10, s$ 2016-11-17 06:40:30.385 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:bridge-ser, thing.i$ 2016-11-17 06:40:30.435 [DEBUG] [nsors.handler.MySensorsBridgeHandler] - Initialization of the MySensors Bridge 2016-11-17 06:40:30.654 [DEBUG] [col.serial.MySensorsSerialConnection] - Successfully connected to serial port. 2016-11-17 06:40:36.145 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app 2016-11-17 06:40:38.163 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app 2016-11-17 06:40:38.712 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui 2016-11-17 06:40:39.160 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start 2016-11-17 06:40:39.955 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin 2016-11-17 06:40:40.396 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel 2016-11-17 06:40:42.527 [INFO ] [o.myopenhab.internal.MyOpenHABClient] - Connected to my.openHAB service (UUID = 7c0faa03-e826-473a-b1f7-8b685b487bb8, base URL = http://localhost:8080) -
Binding is still unsuccessful
Following error disapeared (Updated my previous post).
Guess that happened as RPi started reboot before openhab session was properly closed... 3 reboots cured that error...in
pi@raspberrypi:/usr/share/openhab2/userdata/logs $ nano openhab.log:2016-11-17 06:40:00.094 [DEBUG] [org.openhab.binding.mysensors ] - BundleEvent STARTING - org.openhab.binding.mysensors 2016-11-17 06:40:00.383 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=org.openhab.bindin$ 2016-11-17 06:40:00.480 [DEBUG] [org.openhab.binding.mysensors ] - BundleEvent STARTED - org.openhab.binding.mysensors 2016-11-17 06:40:11.249 [WARN ] [eclipse.jetty.servlet.ServletHandler] - javax.servlet.ServletException: A MultiException has 1 exceptions. They are: 1. java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_0,0,33431755) has been shut down at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:489)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76)[12:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253] at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:812)[82:org.eclipse.jetty.servlet:9.2.14.v20151106] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:587)[82:org.eclipse.jetty.servlet:9.2.14.v20151106] at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:70)[173:org.ops4j.pax.web.pax-web-jetty:4.2.4] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577)[80:org.eclipse.jetty.security:9.2.14.v20151106] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:271)[173:org.ops4j.pax.web.pax-web-jetty:4.2.4] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)[82:org.eclipse.jetty.servlet:9.2.14.v20151106] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80)[173:org.ops4j.pax.web.pax-web-jetty:4.2.4] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.Server.handle(Server.java:499)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:311)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:544)[73:org.eclipse.jetty.io:9.2.14.v20151106] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)[84:org.eclipse.jetty.util:9.2.14.v20151106] at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)[84:org.eclipse.jetty.util:9.2.14.v20151106] at java.lang.Thread.run(Thread.java:745)[:1.8.0_111] Caused by: A MultiException has 1 exceptions. They are: 1. java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_0,0,33431755) has been shut down at org.jvnet.hk2.internal.FactoryCreator.getFactoryHandle(FactoryCreator.java:106)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.FactoryCreator.dispose(FactoryCreator.java:173)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.SystemDescriptor.dispose(SystemDescriptor.java:526)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.glassfish.jersey.process.internal.RequestScope$Instance.remove(RequestScope.java:532)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.process.internal.RequestScope$Instance.release(RequestScope.java:549)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:319)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] ... 26 more Caused by: java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_0,0,33431755) has been shut down at org.jvnet.hk2.internal.ServiceLocatorImpl.checkState(ServiceLocatorImpl.java:2288)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandleImpl(ServiceLocatorImpl.java:629)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandle(ServiceLocatorImpl.java:622)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandle(ServiceLocatorImpl.java:640)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.FactoryCreator.getFactoryHandle(FactoryCreator.java:103)[151:org.glassfish.hk2.locator:2.4.0.b34] ... 34 more 2016-11-17 06:40:11.296 [WARN ] [org.eclipse.jetty.server.HttpChannel] - /rest/events javax.servlet.ServletException: javax.servlet.ServletException: A MultiException has 1 exceptions. They are: 1. java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_0,0,33431755) has been shut down at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:88)[173:org.ops4j.pax.web.pax-web-jetty:4.2.4] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.Server.handle(Server.java:499)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:311)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:544)[73:org.eclipse.jetty.io:9.2.14.v20151106] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)[84:org.eclipse.jetty.util:9.2.14.v20151106] at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)[84:org.eclipse.jetty.util:9.2.14.v20151106] at java.lang.Thread.run(Thread.java:745)[:1.8.0_111] Caused by: javax.servlet.ServletException: A MultiException has 1 exceptions. They are: 1. java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_0,0,33431755) has been shut down at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:489)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76)[12:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253] at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:812)[82:org.eclipse.jetty.servlet:9.2.14.v20151106] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:587)[82:org.eclipse.jetty.servlet:9.2.14.v20151106] at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:70)[173:org.ops4j.pax.web.pax-web-jetty:4.2.4] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577)[80:org.eclipse.jetty.security:9.2.14.v20151106] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:271)[173:org.ops4j.pax.web.pax-web-jetty:4.2.4] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)[82:org.eclipse.jetty.servlet:9.2.14.v20151106] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)[81:org.eclipse.jetty.server:9.2.14.v20151106] at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80)[173:org.ops4j.pax.web.pax-web-jetty:4.2.4] ... 8 more Caused by: A MultiException has 1 exceptions. They are: 1. java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_0,0,33431755) has been shut down at org.jvnet.hk2.internal.FactoryCreator.getFactoryHandle(FactoryCreator.java:106)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.FactoryCreator.dispose(FactoryCreator.java:173)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.SystemDescriptor.dispose(SystemDescriptor.java:526)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.glassfish.jersey.process.internal.RequestScope$Instance.remove(RequestScope.java:532)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.process.internal.RequestScope$Instance.release(RequestScope.java:549)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:319)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:319)[158:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)[159:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473)[156:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] ... 26 more Caused by: java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_0,0,33431755) has been shut down at org.jvnet.hk2.internal.ServiceLocatorImpl.checkState(ServiceLocatorImpl.java:2288)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandleImpl(ServiceLocatorImpl.java:629)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandle(ServiceLocatorImpl.java:622)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandle(ServiceLocatorImpl.java:640)[151:org.glassfish.hk2.locator:2.4.0.b34] at org.jvnet.hk2.internal.FactoryCreator.getFactoryHandle(FactoryCreator.java:103)[151:org.glassfish.hk2.locator:2.4.0.b34] ... 34 more 2016-11-17 06:40:11.330 [WARN ] [org.eclipse.jetty.server.HttpChannel] - Could not send response error 500: javax.servlet.ServletException: javax.servlet.ServletException: A MultiException has 1 e$ 1. java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_0,0,33431755) has been shut down 2016-11-17 06:40:20.925 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'home.items' 2016-11-17 06:40:28.127 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'home.sitemap' 2016-11-17 06:40:29.101 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'home.things' 2016-11-17 06:40:30.364 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=235, service.bundleid=10, s$ 2016-11-17 06:40:30.385 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:bridge-ser, thing.i$ 2016-11-17 06:40:30.435 [DEBUG] [nsors.handler.MySensorsBridgeHandler] - Initialization of the MySensors Bridge 2016-11-17 06:40:30.654 [DEBUG] [col.serial.MySensorsSerialConnection] - Successfully connected to serial port. 2016-11-17 06:40:36.145 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app 2016-11-17 06:40:38.163 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app 2016-11-17 06:40:38.712 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui 2016-11-17 06:40:39.160 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start 2016-11-17 06:40:39.955 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin 2016-11-17 06:40:40.396 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel 2016-11-17 06:40:42.527 [INFO ] [o.myopenhab.internal.MyOpenHABClient] - Connected to my.openHAB service (UUID = 7c0faa03-e826-473a-b1f7-8b685b487bb8, base URL = http://localhost:8080)@ben999 The error in your second post does not seem to be related the to binding and I've no clue what it means. So I'm glad the error is gone. ;-)
Have you enabled DEBUG for the binding? Please show me the output after you started the discovery process. The connection to the serial gateway is successful, so no need to change the permissions with usermod at the moment.
With debug enabled you should see the messages incoming from the gateway. If you don't see the messages arriving please check the connection between serial gateway and the node.
-
@ben999 The error in your second post does not seem to be related the to binding and I've no clue what it means. So I'm glad the error is gone. ;-)
Have you enabled DEBUG for the binding? Please show me the output after you started the discovery process. The connection to the serial gateway is successful, so no need to change the permissions with usermod at the moment.
With debug enabled you should see the messages incoming from the gateway. If you don't see the messages arriving please check the connection between serial gateway and the node.
@TimO Thanks a lot for your message
Talking right to the boss !! :wink:Actually, except that https://forum.mysensors.org/uploads/files/1479359162183-scan.jpeg nothing else happens...
Log from sensor (arduino micro++nrf24+dth22) :
No change, even when i launch a "scan for things"Starting sensor (RNNNA-, 2.0.0) TSM:INIT TSM:RADIO:OK TSP:ASSIGNID:OK (ID=1) TSM:FPAR TSP:MSG:SEND 1-1-255-255 s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=bc: TSP:MSG:READ 0-0-1 s=255,c=3,t=8,pt=1,l=1,sg=0:0 TSP:MSG:FPAR RES (ID=0, dist=0) TSP:MSG:PAR OK (ID=0, dist=1) TSM:FPAR:OK TSM:ID TSM:CHKID:OK (ID=1) TSM:UPL TSP:PING:SEND (dest=0) TSP:MSG:SEND 1-1-0-0 s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=ok:1 TSP:MSG:READ 0-0-1 s=255,c=3,t=25,pt=1,l=1,sg=0:1 TSP:MSG:PONG RECV (hops=1) TSP:CHKUPL:OK TSM:UPL:OK TSM:READY TSP:MSG:SEND 1-1-0-0 s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=ok:0100 !TSP:MSG:SEND 1-1-0-0 s=255,c=0,t=17,pt=0,l=5,sg=0,ft=0,st=fail:2.0.0 TSP:MSG:SEND 1-1-0-0 s=255,c=3,t=6,pt=1,l=1,sg=0,ft=1,st=ok:0 TSP:MSG:SEND 1-1-0-0 s=255,c=3,t=11,pt=0,l=22,sg=0,ft=0,st=ok:TemperatureAndHumidity TSP:MSG:SEND 1-1-0-0 s=255,c=3,t=12,pt=0,l=3,sg=0,ft=0,st=ok:1.1 TSP:MSG:SEND 1-1-0-0 s=0,c=0,t=7,pt=0,l=0,sg=0,ft=0,st=ok: TSP:MSG:SEND 1-1-0-0 s=1,c=0,t=6,pt=0,l=0,sg=0,ft=0,st=ok: Request registration... TSP:MSG:SEND 1-1-0-0 s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=ok:2 TSP:MSG:READ 0-0-1 s=255,c=3,t=27,pt=1,l=1,sg=0:1 Node registration=1 Init complete, id=1, parent=0, distance=1, registration=1 TSP:MSG:SEND 1-1-0-0 s=1,c=1,t=0,pt=7,l=5,sg=0,ft=0,st=ok:18.5 T: 18.50 TSP:MSG:SEND 1-1-0-0 s=0,c=1,t=1,pt=7,l=5,sg=0,ft=0,st=ok:68.1 H: 68.10And that's the openhab log... again, no change when i start a "scan for things"... :
pi@raspberrypi:/usr/share/openhab2 $ sudo ./start_debug.sh Launching the openHAB runtime... Listening for transport dt_socket at address: 5005 __ _____ ____ ____ ____ ___ ____ / / / / | / __ ) / __ \/ __ \/ _ \/ __ \/ /_/ / /| | / __ | / /_/ / /_/ / __/ / / / __ / ___ |/ /_/ / \____/ .___/\___/_/ /_/_/ /_/_/ |_/_____/ /_/ 2.0.0-SNAPSHOT Build #574 Hit '<tab>' for a list of available commands and '[cmd] --help' for help on a specific command. Hit '<ctrl-d>' or type 'system:shutdown' or 'logout' to shutdown openHAB. openhab> log:set DEBUG org.openhab.binding.mysensors openhab> log:tail 19:47:20.265 [DEBUG] [org.openhab.binding.mysensors ] - BundleEvent STARTING - org.openhab.binding.mysensors 19:47:20.517 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=org.openhab.binding.mysensors.internal.MySensorsHandlerFactory, component.id=0, service.id=109, service.bundleid=10, service.scope=bundle} - org.openhab.binding.mysensors 19:47:20.619 [DEBUG] [org.openhab.binding.mysensors ] - BundleEvent STARTED - org.openhab.binding.mysensors 19:47:40.172 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'home.items' 19:47:48.877 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'home.sitemap' 19:47:49.580 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'home.things' 19:47:49.939 [INFO ] [smarthome.event.ThingAddedEvent ] - Thing 'mysensors:bridge-ser:gateway' has been added. 19:47:50.853 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=234, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors 19:47:50.869 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:bridge-ser, thing.id=mysensors:bridge-ser:gateway, service.id=235, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors 19:47:50.908 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-ser:gateway' changed from UNINITIALIZED to INITIALIZING 19:47:50.915 [DEBUG] [nsors.handler.MySensorsBridgeHandler] - Initialization of the MySensors Bridge 19:47:51.047 [INFO ] [smarthome.event.ThingAddedEvent ] - Thing 'mysensors:humidity:4008f727' has been added. 19:47:51.072 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:humidity:4008f727' changed from UNINITIALIZED to INITIALIZING 19:47:51.073 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:humidity, thing.id=mysensors:humidity:4008f727, service.id=237, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors 19:47:51.084 [INFO ] [smarthome.event.ThingAddedEvent ] - Thing 'mysensors:temperature:762194fe' has been added. 19:47:51.210 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:temperature, thing.id=mysensors:temperature:762194fe, service.id=238, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors 19:47:51.212 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:temperature:762194fe' changed from UNINITIALIZED to INITIALIZING 19:47:51.329 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:humidity:4008f727' changed from INITIALIZING to ONLINE 19:47:51.330 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:temperature:762194fe' changed from INITIALIZING to ONLINE 19:47:51.332 [DEBUG] [col.serial.MySensorsSerialConnection] - Successfully connected to serial port. 19:47:51.341 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'MotionTest-mysensors:motion:1584d6773a3:armed' has been added. 19:47:51.345 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'MotionTest-mysensors:motion:1584d6773a3:tripped' has been added. 19:47:51.357 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-ser:gateway' changed from INITIALIZING to ONLINE 19:47:51.413 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'mysensors_humidity_4008f727_battery' has been added. 19:47:51.417 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mysensors_humidity_4008f727_battery-mysensors:humidity:4008f727:battery' has been added. 19:47:51.421 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'mysensors_humidity_4008f727_hum' has been added. 19:47:51.425 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mysensors_humidity_4008f727_hum-mysensors:humidity:4008f727:hum' has been added. 19:47:51.431 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'mysensors_temperature_762194fe_battery' has been added. 19:47:51.434 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mysensors_temperature_762194fe_battery-mysensors:temperature:762194fe:battery' has been added. 19:47:51.440 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'mysensors_temperature_762194fe_temp' has been added. 19:47:51.454 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mysensors_temperature_762194fe_temp-mysensors:temperature:762194fe:temp' has been added. 19:47:56.749 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app 19:47:57.810 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app 19:47:58.557 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui 19:47:59.161 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start 19:47:59.682 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin 19:47:59.807 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel 19:48:04.034 [INFO ] [o.myopenhab.internal.MyOpenHABClient] - Connected to my.openHAB service (UUID = 7c0faa03-e826-473a-b1f7-8b685b487bb8, base URL = http://localhost:8080)Is there any other log that is worth having a look at ?
This is really strange, because when i hook up a PIR sensor to the same arduino and nrf24, and i launchpi@raspberrypi:~/MySensors $ sudo ./examples_linux/mysGateway -di can see that arduino and raspberry interract together...Thanks a lot for your time
-
@TimO Thanks a lot for your message
Talking right to the boss !! :wink:Actually, except that https://forum.mysensors.org/uploads/files/1479359162183-scan.jpeg nothing else happens...
Log from sensor (arduino micro++nrf24+dth22) :
No change, even when i launch a "scan for things"Starting sensor (RNNNA-, 2.0.0) TSM:INIT TSM:RADIO:OK TSP:ASSIGNID:OK (ID=1) TSM:FPAR TSP:MSG:SEND 1-1-255-255 s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=bc: TSP:MSG:READ 0-0-1 s=255,c=3,t=8,pt=1,l=1,sg=0:0 TSP:MSG:FPAR RES (ID=0, dist=0) TSP:MSG:PAR OK (ID=0, dist=1) TSM:FPAR:OK TSM:ID TSM:CHKID:OK (ID=1) TSM:UPL TSP:PING:SEND (dest=0) TSP:MSG:SEND 1-1-0-0 s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=ok:1 TSP:MSG:READ 0-0-1 s=255,c=3,t=25,pt=1,l=1,sg=0:1 TSP:MSG:PONG RECV (hops=1) TSP:CHKUPL:OK TSM:UPL:OK TSM:READY TSP:MSG:SEND 1-1-0-0 s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=ok:0100 !TSP:MSG:SEND 1-1-0-0 s=255,c=0,t=17,pt=0,l=5,sg=0,ft=0,st=fail:2.0.0 TSP:MSG:SEND 1-1-0-0 s=255,c=3,t=6,pt=1,l=1,sg=0,ft=1,st=ok:0 TSP:MSG:SEND 1-1-0-0 s=255,c=3,t=11,pt=0,l=22,sg=0,ft=0,st=ok:TemperatureAndHumidity TSP:MSG:SEND 1-1-0-0 s=255,c=3,t=12,pt=0,l=3,sg=0,ft=0,st=ok:1.1 TSP:MSG:SEND 1-1-0-0 s=0,c=0,t=7,pt=0,l=0,sg=0,ft=0,st=ok: TSP:MSG:SEND 1-1-0-0 s=1,c=0,t=6,pt=0,l=0,sg=0,ft=0,st=ok: Request registration... TSP:MSG:SEND 1-1-0-0 s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=ok:2 TSP:MSG:READ 0-0-1 s=255,c=3,t=27,pt=1,l=1,sg=0:1 Node registration=1 Init complete, id=1, parent=0, distance=1, registration=1 TSP:MSG:SEND 1-1-0-0 s=1,c=1,t=0,pt=7,l=5,sg=0,ft=0,st=ok:18.5 T: 18.50 TSP:MSG:SEND 1-1-0-0 s=0,c=1,t=1,pt=7,l=5,sg=0,ft=0,st=ok:68.1 H: 68.10And that's the openhab log... again, no change when i start a "scan for things"... :
pi@raspberrypi:/usr/share/openhab2 $ sudo ./start_debug.sh Launching the openHAB runtime... Listening for transport dt_socket at address: 5005 __ _____ ____ ____ ____ ___ ____ / / / / | / __ ) / __ \/ __ \/ _ \/ __ \/ /_/ / /| | / __ | / /_/ / /_/ / __/ / / / __ / ___ |/ /_/ / \____/ .___/\___/_/ /_/_/ /_/_/ |_/_____/ /_/ 2.0.0-SNAPSHOT Build #574 Hit '<tab>' for a list of available commands and '[cmd] --help' for help on a specific command. Hit '<ctrl-d>' or type 'system:shutdown' or 'logout' to shutdown openHAB. openhab> log:set DEBUG org.openhab.binding.mysensors openhab> log:tail 19:47:20.265 [DEBUG] [org.openhab.binding.mysensors ] - BundleEvent STARTING - org.openhab.binding.mysensors 19:47:20.517 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=org.openhab.binding.mysensors.internal.MySensorsHandlerFactory, component.id=0, service.id=109, service.bundleid=10, service.scope=bundle} - org.openhab.binding.mysensors 19:47:20.619 [DEBUG] [org.openhab.binding.mysensors ] - BundleEvent STARTED - org.openhab.binding.mysensors 19:47:40.172 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'home.items' 19:47:48.877 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'home.sitemap' 19:47:49.580 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'home.things' 19:47:49.939 [INFO ] [smarthome.event.ThingAddedEvent ] - Thing 'mysensors:bridge-ser:gateway' has been added. 19:47:50.853 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=234, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors 19:47:50.869 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:bridge-ser, thing.id=mysensors:bridge-ser:gateway, service.id=235, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors 19:47:50.908 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-ser:gateway' changed from UNINITIALIZED to INITIALIZING 19:47:50.915 [DEBUG] [nsors.handler.MySensorsBridgeHandler] - Initialization of the MySensors Bridge 19:47:51.047 [INFO ] [smarthome.event.ThingAddedEvent ] - Thing 'mysensors:humidity:4008f727' has been added. 19:47:51.072 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:humidity:4008f727' changed from UNINITIALIZED to INITIALIZING 19:47:51.073 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:humidity, thing.id=mysensors:humidity:4008f727, service.id=237, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors 19:47:51.084 [INFO ] [smarthome.event.ThingAddedEvent ] - Thing 'mysensors:temperature:762194fe' has been added. 19:47:51.210 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:temperature, thing.id=mysensors:temperature:762194fe, service.id=238, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors 19:47:51.212 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:temperature:762194fe' changed from UNINITIALIZED to INITIALIZING 19:47:51.329 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:humidity:4008f727' changed from INITIALIZING to ONLINE 19:47:51.330 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:temperature:762194fe' changed from INITIALIZING to ONLINE 19:47:51.332 [DEBUG] [col.serial.MySensorsSerialConnection] - Successfully connected to serial port. 19:47:51.341 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'MotionTest-mysensors:motion:1584d6773a3:armed' has been added. 19:47:51.345 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'MotionTest-mysensors:motion:1584d6773a3:tripped' has been added. 19:47:51.357 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-ser:gateway' changed from INITIALIZING to ONLINE 19:47:51.413 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'mysensors_humidity_4008f727_battery' has been added. 19:47:51.417 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mysensors_humidity_4008f727_battery-mysensors:humidity:4008f727:battery' has been added. 19:47:51.421 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'mysensors_humidity_4008f727_hum' has been added. 19:47:51.425 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mysensors_humidity_4008f727_hum-mysensors:humidity:4008f727:hum' has been added. 19:47:51.431 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'mysensors_temperature_762194fe_battery' has been added. 19:47:51.434 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mysensors_temperature_762194fe_battery-mysensors:temperature:762194fe:battery' has been added. 19:47:51.440 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'mysensors_temperature_762194fe_temp' has been added. 19:47:51.454 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mysensors_temperature_762194fe_temp-mysensors:temperature:762194fe:temp' has been added. 19:47:56.749 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app 19:47:57.810 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app 19:47:58.557 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui 19:47:59.161 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start 19:47:59.682 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin 19:47:59.807 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel 19:48:04.034 [INFO ] [o.myopenhab.internal.MyOpenHABClient] - Connected to my.openHAB service (UUID = 7c0faa03-e826-473a-b1f7-8b685b487bb8, base URL = http://localhost:8080)Is there any other log that is worth having a look at ?
This is really strange, because when i hook up a PIR sensor to the same arduino and nrf24, and i launchpi@raspberrypi:~/MySensors $ sudo ./examples_linux/mysGateway -di can see that arduino and raspberry interract together...Thanks a lot for your time
@ben999 The OH2 log looks good, but could you please enable debug output in OH2 for the binding as described in the Wiki?
In the log from the node I see that the presentation message is the one that failed to deliver. Does this happen all the time? The binding is looking for that message. This could be a power issue.
-
@ben999 The OH2 log looks good, but could you please enable debug output in OH2 for the binding as described in the Wiki?
In the log from the node I see that the presentation message is the one that failed to deliver. Does this happen all the time? The binding is looking for that message. This could be a power issue.
@TimO thank you for your answer
Both RPi and sensors have been power with different power supplies but no change
Then, to get the debug output at the karaf prompt I typed :openhab> log:set DEBUG
This is what i got when asking for a "search for things" process:openhab> log:set DEBUG openhab> log:tail 22:59:40.423 [DEBUG] [e.osgi.LoggingCommandSessionListener] - Command: 'log:clear' returned 'null' 22:59:42.378 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers 22:59:43.026 [DEBUG] [e.osgi.LoggingCommandSessionListener] - Executing command: 'log:set DEBUG' 22:59:43.028 [DEBUG] [org.apache.felix.configadmin ] - getProperties() 22:59:43.032 [DEBUG] [org.apache.felix.configadmin ] - getProperties() 22:59:44.731 [DEBUG] [e.osgi.LoggingCommandSessionListener] - Executing command: 'log:tail' 22:59:46.716 [DEBUG] [io.socket.engineio.client.Socket ] - writing ping packet - expecting pong within 60000ms 22:59:46.720 [DEBUG] [io.socket.engineio.client.Socket ] - flushing 1 packets in socket 22:59:46.765 [DEBUG] [io.socket.engineio.client.Socket ] - socket received: type 'pong', data 'null' 22:59:55.667 [DEBUG] [org.eclipse.jetty.io.IdleTimeout ] - SelectChannelEndPoint@10fcc9b{/192.168.1.9:45209<->8080,Open,in,out,-,-,30000/30000,HttpConnection}{io=0,kio=0,kro=1} idle timeout check, elapsed: 30000 ms, remaining: 0 ms 22:59:55.669 [DEBUG] [org.eclipse.jetty.io.IdleTimeout ] - SelectChannelEndPoint@10fcc9b{/192.168.1.9:45209<->8080,Open,in,out,-,-,30002/30000,HttpConnection}{io=0,kio=0,kro=1} idle timeout expired 22:59:55.671 [DEBUG] [rg.eclipse.jetty.io.AbstractEndPoint] - Ignored idle endpoint SelectChannelEndPoint@10fcc9b{/192.168.1.9:45209<->8080,Open,in,out,-,-,30004/30000,HttpConnection}{io=0,kio=0,kro=1} 22:59:57.110 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Queued change org.eclipse.jetty.io.SelectorManager$ManagedSelector$Accept@13e699a 22:59:57.112 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Running change org.eclipse.jetty.io.SelectorManager$ManagedSelector$Accept@13e699a 22:59:57.113 [DEBUG] [rg.eclipse.jetty.io.AbstractEndPoint] - onOpen SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,0/30000,null}{io=0,kio=0,kro=0} 22:59:57.116 [DEBUG] [org.eclipse.jetty.io.IdleTimeout ] - SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,1/30000,null}{io=0,kio=0,kro=0} idle timeout check, elapsed: 1 ms, remaining: 29999 ms 22:59:57.123 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - new HttpChannelOverHttp@1a5f1b6{r=0,c=false,a=IDLE,uri=} -> SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,9/30000,null}{io=0,kio=0,kro=0},null,HttpChannelState@1d0ab0c{s=IDLE i=true a=null} 22:59:57.126 [DEBUG] [.eclipse.jetty.server.HttpConnection] - New HTTP Connection HttpConnection@ec8647[IDLE,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,11/30000,null}{io=0,kio=0,kro=0}][p=HttpParser{s=START,0 of 0},g=HttpGenerator{s=START},c=HttpChannelOverHttp@1a5f1b6{r=0,c=false,a=IDLE,uri=}] 22:59:57.128 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - onOpen HttpConnection@ec8647[IDLE,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,14/30000,HttpConnection}{io=0,kio=0,kro=0}][p=HttpParser{s=START,0 of 0},g=HttpGenerator{s=START},c=HttpChannelOverHttp@1a5f1b6{r=0,c=false,a=IDLE,uri=}] 22:59:57.133 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - fillInterested HttpConnection@ec8647[IDLE,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,15/30000,HttpConnection}{io=0,kio=0,kro=0}][p=HttpParser{s=START,0 of 0},g=HttpGenerator{s=START},c=HttpChannelOverHttp@1a5f1b6{r=0,c=false,a=IDLE,uri=}] 22:59:57.136 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - IDLE-->FILL_INTERESTED HttpConnection@ec8647[FILL_INTERESTED,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,22/30000,HttpConnection}{io=0,kio=0,kro=0}][p=HttpParser{s=START,0 of 0},g=HttpGenerator{s=START},c=HttpChannelOverHttp@1a5f1b6{r=0,c=false,a=IDLE,uri=}] 22:59:57.138 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Local interests updating 0 -> 1 for SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,R,-,0/30000,HttpConnection}{io=1,kio=0,kro=0} 22:59:57.139 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Queued change org.eclipse.jetty.io.SelectChannelEndPoint$1@b87e8a 22:59:57.141 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Created SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,R,-,3/30000,HttpConnection}{io=1,kio=0,kro=0} 22:59:57.143 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@b87e8a 22:59:57.145 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Key interests updated 0 -> 1 on SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,R,-,7/30000,HttpConnection}{io=1,kio=1,kro=0} 22:59:57.146 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop waiting on select 22:59:57.148 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop woken up from select, 1/1 selected 22:59:57.150 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Key interests updated 1 -> 0 on SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,R,-,12/30000,HttpConnection}{io=1,kio=0,kro=1} 22:59:57.152 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Local interests updating 1 -> 0 for SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,R,-,14/30000,HttpConnection}{io=0,kio=0,kro=1} 22:59:57.153 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Queued change org.eclipse.jetty.io.SelectChannelEndPoint$1@b87e8a 22:59:57.156 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILL_INTERESTED-->FILLING HttpConnection@ec8647[FILLING,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,17/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of 0},g=HttpGenerator{s=START},c=HttpChannelOverHttp@1a5f1b6{r=0,c=false,a=IDLE,uri=}] 22:59:57.157 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@b87e8a 22:59:57.158 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop waiting on select 22:59:57.158 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@ec8647[FILLING,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,20/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of 0},g=HttpGenerator{s=START},c=HttpChannelOverHttp@1a5f1b6{r=0,c=false,a=IDLE,uri=}] onFillable HttpChannelState@1d0ab0c{s=IDLE i=true a=null} 22:59:57.159 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 381 SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,22/30000,HttpConnection}{io=0,kio=0,kro=1} 22:59:57.160 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - parseNext s=START HeapByteBuffer@16d7302[p=0,l=381,c=8192,r=381]={<<<GET /rest/discove....6,en;q=0.4\r\n\r\n>>>2.168.1.96:8080/u...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 22:59:57.161 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - START --> SPACE1 22:59:57.162 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - SPACE1 --> URI 22:59:57.162 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - URI --> SPACE2 22:59:57.163 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - SPACE2 --> REQUEST_VERSION 22:59:57.163 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - REQUEST_VERSION --> HEADER 22:59:57.164 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_VALUE 22:59:57.165 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_VALUE --> HEADER_IN_VALUE 22:59:57.167 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 22:59:57.172 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 22:59:57.173 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 22:59:57.175 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_VALUE 22:59:57.177 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_VALUE --> HEADER_IN_VALUE 22:59:57.178 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 22:59:57.180 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_VALUE 22:59:57.181 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_VALUE --> HEADER_IN_VALUE 22:59:57.183 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 22:59:57.184 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_VALUE 22:59:57.185 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_VALUE --> HEADER_IN_VALUE 22:59:57.187 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 22:59:57.188 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 22:59:57.189 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 22:59:57.190 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_VALUE 22:59:57.192 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_VALUE --> HEADER_IN_VALUE 22:59:57.193 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 22:59:57.194 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> END 22:59:57.195 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1a5f1b6{r=1,c=false,a=IDLE,uri=/rest/discovery} messageComplete 22:59:57.201 [DEBUG] [org.eclipse.jetty.server.HttpInput ] - HttpInputOverHTTP@1a10417 EOF 22:59:57.204 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1a5f1b6{r=1,c=false,a=IDLE,uri=/rest/discovery} handle enter 22:59:57.207 [DEBUG] [clipse.jetty.server.HttpChannelState] - HttpChannelState@1d0ab0c{s=IDLE i=true a=null} handling IDLE 22:59:57.214 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1a5f1b6{r=1,c=false,a=DISPATCHED,uri=/rest/discovery} action REQUEST_DISPATCH 22:59:57.218 [DEBUG] [org.eclipse.jetty.server.Server ] - REQUEST GET /rest/discovery on HttpChannelOverHttp@1a5f1b6{r=1,c=false,a=DISPATCHED,uri=/rest/discovery} 22:59:57.220 [DEBUG] [ax.web.service.spi.model.ServerModel] - Matching [/rest/discovery]... 22:59:57.223 [DEBUG] [ax.web.service.spi.model.ServerModel] - Path [/rest/discovery] matched to {pattern=/rest/.*,model=ServletModel{id=org.ops4j.pax.web.service.spi.model.ServletModel-2,name=org.ops4j.pax.web.service.spi.model.ServletModel-2,urlPatterns=[/rest/*],alias=/rest,servlet=com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge@bc5ed1,initParams={},context=ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-1,name=,httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default],contextParams={},virtualHosts={},connectors={}}}} 22:59:57.225 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]} 22:59:57.227 [DEBUG] [.jetty.server.handler.ContextHandler] - context=||/rest/discovery @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]} 22:59:57.228 [DEBUG] [org.eclipse.jetty.server.session ] - sessionManager=org.ops4j.pax.web.service.jetty.internal.LateInvalidatingHashSessionManager@32d70e 22:59:57.229 [DEBUG] [org.eclipse.jetty.server.session ] - session=null 22:59:57.231 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - servlet |/rest|/discovery -> org.ops4j.pax.web.service.spi.model.ServletModel-2@378be0fa==com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge,-1,true 22:59:57.232 [DEBUG] [ce.jetty.internal.HttpServiceContext] - Handling request for [/rest/discovery] using http context [DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]] 22:59:57.233 [DEBUG] [y.internal.HttpServiceServletHandler] - handling request org.ops4j.pax.web.service.jetty.internal.HttpServiceRequestWrapper@166f693, org.ops4j.pax.web.service.jetty.internal.HttpServiceResponseWrapper@1596f67 22:59:57.235 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - chain=null 22:59:57.244 [DEBUG] [e.internal.WriterInterceptorExecutor] - Message body writer (class com.eclipsesource.jaxrs.provider.gson.GsonProvider) is trying to close the entity output stream. Not closing. 22:59:57.246 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@5bfca8[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,13,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@1b5d408] generate: NEED_HEADER (null,[p=0,l=13,c=8192,r=13],true)@START 22:59:57.249 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@5bfca8[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,13,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@1b5d408] generate: FLUSH ([p=0,l=141,c=8192,r=141],[p=0,l=13,c=8192,r=13],true)@COMPLETING 22:59:57.253 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 154 SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,W,93/30000,HttpConnection}{io=0,kio=0,kro=1} 22:59:57.256 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@5bfca8[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,13,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@1b5d408] generate: DONE ([p=141,l=141,c=8192,r=0],[p=13,l=13,c=8192,r=0],true)@END 22:59:57.259 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery @ o.e.j.s.h.ContextHandler@190a83a{/static,null,AVAILABLE} 22:59:57.261 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.9.0.201611041332 [100], contextID=default]} 22:59:57.262 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui_0.9.0.201611041332 [137], contextID=default]} 22:59:57.264 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.9.0.201611041332 [138], contextID=default]} 22:59:57.269 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery @ HttpServiceContext{httpContext=org.jupnp.transport.impl.osgi.DisableAuthenticationHttpContext@1ea92c5} 22:59:57.270 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.basic_0.9.0.201611041332 [186], contextID=default]} 22:59:57.272 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.classic_0.9.0.201611041332 [187], contextID=default]} 22:59:57.273 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.paper_0.9.0.201611041332 [188], contextID=default]} 22:59:57.274 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.io.rest.docs_2.0.0.201611062131 [189], contextID=default]} 22:59:57.276 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.0.0.201611062131 [192], contextID=default]} 22:59:57.277 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core_2.0.0.201611062131 [168], contextID=default]} 22:59:57.278 [DEBUG] [org.eclipse.jetty.server.Server ] - RESPONSE /rest/discovery 200 handled=true 22:59:57.279 [DEBUG] [clipse.jetty.server.HttpChannelState] - HttpChannelState@1d0ab0c{s=DISPATCHED i=true a=null} unhandle DISPATCHED 22:59:57.281 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - reset HttpParser{s=END,0 of 0} 22:59:57.281 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - END --> START 22:59:57.283 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1a5f1b6{r=1,c=false,a=IDLE,uri=} handle exit, result COMPLETE 22:59:57.301 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,45/30000,HttpConnection}{io=0,kio=0,kro=1} 22:59:57.303 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,46/30000,HttpConnection}{io=0,kio=0,kro=1} 22:59:57.304 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - parseNext s=START HeapByteBuffer@1860225[p=0,l=0,c=8192,r=0]={<<<>>>HTTP/1.1 200 OK\r\n...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 22:59:57.307 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - fillInterested HttpConnection@ec8647[FILLING,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,50/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@1a5f1b6{r=1,c=false,a=IDLE,uri=}] 22:59:57.310 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILLING-->FILLING_FILL_INTERESTED HttpConnection@ec8647[FILLING_FILL_INTERESTED,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,52/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@1a5f1b6{r=1,c=false,a=IDLE,uri=}] 22:59:57.313 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILLING_FILL_INTERESTED-->FILL_INTERESTED HttpConnection@ec8647[FILL_INTERESTED,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,55/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@1a5f1b6{r=1,c=false,a=IDLE,uri=}] 22:59:57.315 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Local interests updating 0 -> 1 for SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,R,-,0/30000,HttpConnection}{io=1,kio=0,kro=1} 22:59:57.316 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Queued change org.eclipse.jetty.io.SelectChannelEndPoint$1@b87e8a 22:59:57.318 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop woken up from select, 0/1 selected 22:59:57.320 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@b87e8a 22:59:57.322 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Key interests updated 0 -> 1 on SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,R,-,7/30000,HttpConnection}{io=1,kio=1,kro=1} 22:59:57.323 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop waiting on select 23:00:01.810 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop woken up from select, 1/1 selected 23:00:01.812 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Key interests updated 1 -> 0 on SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,R,-,4497/30000,HttpConnection}{io=1,kio=0,kro=1} 23:00:01.814 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Local interests updating 1 -> 0 for SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,R,-,4499/30000,HttpConnection}{io=0,kio=0,kro=1} 23:00:01.814 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Queued change org.eclipse.jetty.io.SelectChannelEndPoint$1@b87e8a 23:00:01.816 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILL_INTERESTED-->FILLING HttpConnection@ec8647[FILLING,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,4502/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@1a5f1b6{r=1,c=false,a=IDLE,uri=}] 23:00:01.817 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@b87e8a 23:00:01.818 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop waiting on select 23:00:01.819 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@ec8647[FILLING,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,4504/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@1a5f1b6{r=1,c=false,a=IDLE,uri=}] onFillable HttpChannelState@1d0ab0c{s=IDLE i=true a=null} 23:00:01.821 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 525 SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,4506/30000,HttpConnection}{io=0,kio=0,kro=1} 23:00:01.822 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - parseNext s=START HeapByteBuffer@16d7302[p=0,l=525,c=8192,r=525]={<<<POST /rest/discov...d":"mysensors"}>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 23:00:01.822 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - START --> SPACE1 23:00:01.823 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - SPACE1 --> URI 23:00:01.824 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - URI --> SPACE2 23:00:01.824 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - SPACE2 --> REQUEST_VERSION 23:00:01.825 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - REQUEST_VERSION --> HEADER 23:00:01.826 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 23:00:01.827 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 23:00:01.828 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 23:00:01.828 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 23:00:01.829 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_VALUE 23:00:01.830 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_VALUE --> HEADER_IN_VALUE 23:00:01.831 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 23:00:01.832 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 23:00:01.832 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 23:00:01.833 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_NAME 23:00:01.834 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_NAME --> HEADER_VALUE 23:00:01.835 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_VALUE --> HEADER_IN_VALUE 23:00:01.835 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 23:00:01.836 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 23:00:01.837 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 23:00:01.838 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 23:00:01.839 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 23:00:01.839 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_VALUE 23:00:01.840 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_VALUE --> HEADER_IN_VALUE 23:00:01.841 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 23:00:01.842 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 23:00:01.843 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER -
This post is deleted!
-
end of debug log (sorry, post too long)
23:00:01.843 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 23:00:01.844 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 23:00:01.845 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> CONTENT 23:00:01.846 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1a5f1b6{r=2,c=false,a=IDLE,uri=/rest/discovery/bindings/mysensors/scan} handle enter 23:00:01.847 [DEBUG] [clipse.jetty.server.HttpChannelState] - HttpChannelState@1d0ab0c{s=IDLE i=true a=null} handling IDLE 23:00:01.848 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1a5f1b6{r=2,c=false,a=DISPATCHED,uri=/rest/discovery/bindings/mysensors/scan} action REQUEST_DISPATCH 23:00:01.849 [DEBUG] [org.eclipse.jetty.server.Server ] - REQUEST POST /rest/discovery/bindings/mysensors/scan on HttpChannelOverHttp@1a5f1b6{r=2,c=false,a=DISPATCHED,uri=/rest/discovery/bindings/mysensors/scan} 23:00:01.850 [DEBUG] [ax.web.service.spi.model.ServerModel] - Matching [/rest/discovery/bindings/mysensors/scan]... 23:00:01.851 [DEBUG] [ax.web.service.spi.model.ServerModel] - Path [/rest/discovery/bindings/mysensors/scan] matched to {pattern=/rest/.*,model=ServletModel{id=org.ops4j.pax.web.service.spi.model.ServletModel-2,name=org.ops4j.pax.web.service.spi.model.ServletModel-2,urlPatterns=[/rest/*],alias=/rest,servlet=com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge@bc5ed1,initParams={},context=ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-1,name=,httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default],contextParams={},virtualHosts={},connectors={}}}} 23:00:01.852 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]} 23:00:01.853 [DEBUG] [.jetty.server.handler.ContextHandler] - context=||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]} 23:00:01.853 [DEBUG] [org.eclipse.jetty.server.session ] - sessionManager=org.ops4j.pax.web.service.jetty.internal.LateInvalidatingHashSessionManager@32d70e 23:00:01.854 [DEBUG] [org.eclipse.jetty.server.session ] - session=null 23:00:01.855 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - servlet |/rest|/discovery/bindings/mysensors/scan -> org.ops4j.pax.web.service.spi.model.ServletModel-2@378be0fa==com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge,-1,true 23:00:01.856 [DEBUG] [ce.jetty.internal.HttpServiceContext] - Handling request for [/rest/discovery/bindings/mysensors/scan] using http context [DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]] 23:00:01.857 [DEBUG] [y.internal.HttpServiceServletHandler] - handling request org.ops4j.pax.web.service.jetty.internal.HttpServiceRequestWrapper@a929e4, org.ops4j.pax.web.service.jetty.internal.HttpServiceResponseWrapper@13d3535 23:00:01.857 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - chain=null 23:00:01.872 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@5bfca8[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,4,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@1866dfa] generate: NEED_HEADER (null,[p=0,l=4,c=8192,r=4],true)@START 23:00:01.874 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@5bfca8[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,4,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@1866dfa] generate: FLUSH ([p=0,l=134,c=8192,r=134],[p=0,l=4,c=8192,r=4],true)@COMPLETING 23:00:01.875 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 138 SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,W,54/30000,HttpConnection}{io=0,kio=0,kro=1} 23:00:01.877 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@5bfca8[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,4,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@1866dfa] generate: DONE ([p=134,l=134,c=8192,r=0],[p=4,l=4,c=8192,r=0],true)@END 23:00:01.879 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ o.e.j.s.h.ContextHandler@190a83a{/static,null,AVAILABLE} 23:00:01.880 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.9.0.201611041332 [100], contextID=default]} 23:00:01.881 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui_0.9.0.201611041332 [137], contextID=default]} 23:00:01.882 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.9.0.201611041332 [138], contextID=default]} 23:00:01.883 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=org.jupnp.transport.impl.osgi.DisableAuthenticationHttpContext@1ea92c5} 23:00:01.884 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.basic_0.9.0.201611041332 [186], contextID=default]} 23:00:01.884 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.classic_0.9.0.201611041332 [187], contextID=default]} 23:00:01.885 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.paper_0.9.0.201611041332 [188], contextID=default]} 23:00:01.886 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.io.rest.docs_2.0.0.201611062131 [189], contextID=default]} 23:00:01.887 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.0.0.201611062131 [192], contextID=default]} 23:00:01.888 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core_2.0.0.201611062131 [168], contextID=default]} 23:00:01.889 [DEBUG] [org.eclipse.jetty.server.Server ] - RESPONSE /rest/discovery/bindings/mysensors/scan 200 handled=true 23:00:01.891 [DEBUG] [clipse.jetty.server.HttpChannelState] - HttpChannelState@1d0ab0c{s=DISPATCHED i=true a=null} unhandle DISPATCHED 23:00:01.893 [DEBUG] [.eclipse.jetty.server.HttpConnection] - unconsumed input HttpConnection@ec8647[FILLING,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,16/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=CONTENT,0 of 25},g=HttpGenerator{s=END},c=HttpChannelOverHttp@1a5f1b6{r=2,c=true,a=COMPLETED,uri=/rest/discovery/bindings/mysensors/scan}] 23:00:01.894 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - parseNext s=CONTENT HeapByteBuffer@16d7302[p=500,l=525,c=8192,r=25]={POST /rest/discov....6,en;q=0.4\r\n\r\n<<<{"bindingId":"mysensors"}>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 23:00:01.895 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1a5f1b6{r=2,c=true,a=COMPLETED,uri=/rest/discovery/bindings/mysensors/scan} content java.nio.HeapByteBufferR[pos=500 lim=525 cap=8192] 23:00:01.897 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - parseNext s=CONTENT HeapByteBuffer@16d7302[p=525,l=525,c=8192,r=0]={POST /rest/discov...d":"mysensors"}<<<>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 23:00:01.897 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - CONTENT --> END 23:00:01.898 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1a5f1b6{r=2,c=true,a=COMPLETED,uri=/rest/discovery/bindings/mysensors/scan} messageComplete 23:00:01.899 [DEBUG] [org.eclipse.jetty.server.HttpInput ] - HttpInputOverHTTP@1a10417 EOF 23:00:01.901 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,24/30000,HttpConnection}{io=0,kio=0,kro=1} 23:00:01.903 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@ec8647[FILLING,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,26/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=END,25 of 25},g=HttpGenerator{s=END},c=HttpChannelOverHttp@1a5f1b6{r=2,c=true,a=COMPLETED,uri=/rest/discovery/bindings/mysensors/scan}] filled 0 23:00:01.904 [DEBUG] [org.eclipse.jetty.server.HttpInput ] - HttpInputOverHTTP@1a10417 eof EOF 23:00:01.905 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - reset HttpParser{s=END,25 of 25} 23:00:01.905 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - END --> START 23:00:01.907 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1a5f1b6{r=2,c=false,a=IDLE,uri=} handle exit, result COMPLETE 23:00:01.908 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,31/30000,HttpConnection}{io=0,kio=0,kro=1} 23:00:01.909 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,33/30000,HttpConnection}{io=0,kio=0,kro=1} 23:00:01.910 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - parseNext s=START HeapByteBuffer@1860225[p=0,l=0,c=8192,r=0]={<<<>>>HTTP/1.1 200 OK\r\n...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 23:00:01.912 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - fillInterested HttpConnection@ec8647[FILLING,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,36/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@1a5f1b6{r=2,c=false,a=IDLE,uri=}] 23:00:01.914 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILLING-->FILLING_FILL_INTERESTED HttpConnection@ec8647[FILLING_FILL_INTERESTED,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,38/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@1a5f1b6{r=2,c=false,a=IDLE,uri=}] 23:00:01.917 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILLING_FILL_INTERESTED-->FILL_INTERESTED HttpConnection@ec8647[FILL_INTERESTED,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,40/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@1a5f1b6{r=2,c=false,a=IDLE,uri=}] 23:00:01.918 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Local interests updating 0 -> 1 for SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,R,-,1/30000,HttpConnection}{io=1,kio=0,kro=1} 23:00:01.919 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Queued change org.eclipse.jetty.io.SelectChannelEndPoint$1@b87e8a 23:00:01.920 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop woken up from select, 0/1 selected 23:00:01.923 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@b87e8a 23:00:01.925 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Key interests updated 0 -> 1 on SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,R,-,7/30000,HttpConnection}{io=1,kio=1,kro=1} 23:00:01.926 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop waiting on select 23:00:09.067 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers 23:00:11.859 [DEBUG] [io.socket.engineio.client.Socket ] - writing ping packet - expecting pong within 60000ms 23:00:11.859 [DEBUG] [io.socket.engineio.client.Socket ] - flushing 1 packets in socket 23:00:11.904 [DEBUG] [io.socket.engineio.client.Socket ] - socket received: type 'pong', data 'null':scream:
192.168.1.9 is the computer (ubuntu) from which i do ssh...And this is the log during "idle"
23:02:48.131 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers 23:02:55.692 [DEBUG] [org.eclipse.jetty.io.IdleTimeout ] - SelectChannelEndPoint@10fcc9b{/192.168.1.9:45209<->8080,Open,in,out,-,-,30000/30000,HttpConnection}{io=0,kio=0,kro=1} idle timeout check, elapsed: 30000 ms, remaining: 0 ms 23:02:55.693 [DEBUG] [org.eclipse.jetty.io.IdleTimeout ] - SelectChannelEndPoint@10fcc9b{/192.168.1.9:45209<->8080,Open,in,out,-,-,30002/30000,HttpConnection}{io=0,kio=0,kro=1} idle timeout expired 23:02:55.695 [DEBUG] [rg.eclipse.jetty.io.AbstractEndPoint] - Ignored idle endpoint SelectChannelEndPoint@10fcc9b{/192.168.1.9:45209<->8080,Open,in,out,-,-,30003/30000,HttpConnection}{io=0,kio=0,kro=1} 23:03:08.614 [DEBUG] [io.socket.engineio.client.Socket ] - writing ping packet - expecting pong within 60000ms 23:03:08.614 [DEBUG] [io.socket.engineio.client.Socket ] - flushing 1 packets in socket 23:03:08.655 [DEBUG] [io.socket.engineio.client.Socket ] - socket received: type 'pong', data 'null' -
end of debug log (sorry, post too long)
23:00:01.843 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 23:00:01.844 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 23:00:01.845 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> CONTENT 23:00:01.846 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1a5f1b6{r=2,c=false,a=IDLE,uri=/rest/discovery/bindings/mysensors/scan} handle enter 23:00:01.847 [DEBUG] [clipse.jetty.server.HttpChannelState] - HttpChannelState@1d0ab0c{s=IDLE i=true a=null} handling IDLE 23:00:01.848 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1a5f1b6{r=2,c=false,a=DISPATCHED,uri=/rest/discovery/bindings/mysensors/scan} action REQUEST_DISPATCH 23:00:01.849 [DEBUG] [org.eclipse.jetty.server.Server ] - REQUEST POST /rest/discovery/bindings/mysensors/scan on HttpChannelOverHttp@1a5f1b6{r=2,c=false,a=DISPATCHED,uri=/rest/discovery/bindings/mysensors/scan} 23:00:01.850 [DEBUG] [ax.web.service.spi.model.ServerModel] - Matching [/rest/discovery/bindings/mysensors/scan]... 23:00:01.851 [DEBUG] [ax.web.service.spi.model.ServerModel] - Path [/rest/discovery/bindings/mysensors/scan] matched to {pattern=/rest/.*,model=ServletModel{id=org.ops4j.pax.web.service.spi.model.ServletModel-2,name=org.ops4j.pax.web.service.spi.model.ServletModel-2,urlPatterns=[/rest/*],alias=/rest,servlet=com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge@bc5ed1,initParams={},context=ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-1,name=,httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default],contextParams={},virtualHosts={},connectors={}}}} 23:00:01.852 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]} 23:00:01.853 [DEBUG] [.jetty.server.handler.ContextHandler] - context=||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]} 23:00:01.853 [DEBUG] [org.eclipse.jetty.server.session ] - sessionManager=org.ops4j.pax.web.service.jetty.internal.LateInvalidatingHashSessionManager@32d70e 23:00:01.854 [DEBUG] [org.eclipse.jetty.server.session ] - session=null 23:00:01.855 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - servlet |/rest|/discovery/bindings/mysensors/scan -> org.ops4j.pax.web.service.spi.model.ServletModel-2@378be0fa==com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge,-1,true 23:00:01.856 [DEBUG] [ce.jetty.internal.HttpServiceContext] - Handling request for [/rest/discovery/bindings/mysensors/scan] using http context [DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]] 23:00:01.857 [DEBUG] [y.internal.HttpServiceServletHandler] - handling request org.ops4j.pax.web.service.jetty.internal.HttpServiceRequestWrapper@a929e4, org.ops4j.pax.web.service.jetty.internal.HttpServiceResponseWrapper@13d3535 23:00:01.857 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - chain=null 23:00:01.872 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@5bfca8[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,4,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@1866dfa] generate: NEED_HEADER (null,[p=0,l=4,c=8192,r=4],true)@START 23:00:01.874 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@5bfca8[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,4,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@1866dfa] generate: FLUSH ([p=0,l=134,c=8192,r=134],[p=0,l=4,c=8192,r=4],true)@COMPLETING 23:00:01.875 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 138 SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,W,54/30000,HttpConnection}{io=0,kio=0,kro=1} 23:00:01.877 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@5bfca8[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,4,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@1866dfa] generate: DONE ([p=134,l=134,c=8192,r=0],[p=4,l=4,c=8192,r=0],true)@END 23:00:01.879 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ o.e.j.s.h.ContextHandler@190a83a{/static,null,AVAILABLE} 23:00:01.880 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.9.0.201611041332 [100], contextID=default]} 23:00:01.881 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui_0.9.0.201611041332 [137], contextID=default]} 23:00:01.882 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.9.0.201611041332 [138], contextID=default]} 23:00:01.883 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=org.jupnp.transport.impl.osgi.DisableAuthenticationHttpContext@1ea92c5} 23:00:01.884 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.basic_0.9.0.201611041332 [186], contextID=default]} 23:00:01.884 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.classic_0.9.0.201611041332 [187], contextID=default]} 23:00:01.885 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.paper_0.9.0.201611041332 [188], contextID=default]} 23:00:01.886 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.io.rest.docs_2.0.0.201611062131 [189], contextID=default]} 23:00:01.887 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.0.0.201611062131 [192], contextID=default]} 23:00:01.888 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/discovery/bindings/mysensors/scan @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core_2.0.0.201611062131 [168], contextID=default]} 23:00:01.889 [DEBUG] [org.eclipse.jetty.server.Server ] - RESPONSE /rest/discovery/bindings/mysensors/scan 200 handled=true 23:00:01.891 [DEBUG] [clipse.jetty.server.HttpChannelState] - HttpChannelState@1d0ab0c{s=DISPATCHED i=true a=null} unhandle DISPATCHED 23:00:01.893 [DEBUG] [.eclipse.jetty.server.HttpConnection] - unconsumed input HttpConnection@ec8647[FILLING,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,16/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=CONTENT,0 of 25},g=HttpGenerator{s=END},c=HttpChannelOverHttp@1a5f1b6{r=2,c=true,a=COMPLETED,uri=/rest/discovery/bindings/mysensors/scan}] 23:00:01.894 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - parseNext s=CONTENT HeapByteBuffer@16d7302[p=500,l=525,c=8192,r=25]={POST /rest/discov....6,en;q=0.4\r\n\r\n<<<{"bindingId":"mysensors"}>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 23:00:01.895 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1a5f1b6{r=2,c=true,a=COMPLETED,uri=/rest/discovery/bindings/mysensors/scan} content java.nio.HeapByteBufferR[pos=500 lim=525 cap=8192] 23:00:01.897 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - parseNext s=CONTENT HeapByteBuffer@16d7302[p=525,l=525,c=8192,r=0]={POST /rest/discov...d":"mysensors"}<<<>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 23:00:01.897 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - CONTENT --> END 23:00:01.898 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1a5f1b6{r=2,c=true,a=COMPLETED,uri=/rest/discovery/bindings/mysensors/scan} messageComplete 23:00:01.899 [DEBUG] [org.eclipse.jetty.server.HttpInput ] - HttpInputOverHTTP@1a10417 EOF 23:00:01.901 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,24/30000,HttpConnection}{io=0,kio=0,kro=1} 23:00:01.903 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@ec8647[FILLING,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,26/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=END,25 of 25},g=HttpGenerator{s=END},c=HttpChannelOverHttp@1a5f1b6{r=2,c=true,a=COMPLETED,uri=/rest/discovery/bindings/mysensors/scan}] filled 0 23:00:01.904 [DEBUG] [org.eclipse.jetty.server.HttpInput ] - HttpInputOverHTTP@1a10417 eof EOF 23:00:01.905 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - reset HttpParser{s=END,25 of 25} 23:00:01.905 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - END --> START 23:00:01.907 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@1a5f1b6{r=2,c=false,a=IDLE,uri=} handle exit, result COMPLETE 23:00:01.908 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,31/30000,HttpConnection}{io=0,kio=0,kro=1} 23:00:01.909 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,33/30000,HttpConnection}{io=0,kio=0,kro=1} 23:00:01.910 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - parseNext s=START HeapByteBuffer@1860225[p=0,l=0,c=8192,r=0]={<<<>>>HTTP/1.1 200 OK\r\n...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 23:00:01.912 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - fillInterested HttpConnection@ec8647[FILLING,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,36/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@1a5f1b6{r=2,c=false,a=IDLE,uri=}] 23:00:01.914 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILLING-->FILLING_FILL_INTERESTED HttpConnection@ec8647[FILLING_FILL_INTERESTED,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,38/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@1a5f1b6{r=2,c=false,a=IDLE,uri=}] 23:00:01.917 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILLING_FILL_INTERESTED-->FILL_INTERESTED HttpConnection@ec8647[FILL_INTERESTED,SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,-,-,40/30000,HttpConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@1a5f1b6{r=2,c=false,a=IDLE,uri=}] 23:00:01.918 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Local interests updating 0 -> 1 for SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,R,-,1/30000,HttpConnection}{io=1,kio=0,kro=1} 23:00:01.919 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Queued change org.eclipse.jetty.io.SelectChannelEndPoint$1@b87e8a 23:00:01.920 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop woken up from select, 0/1 selected 23:00:01.923 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@b87e8a 23:00:01.925 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Key interests updated 0 -> 1 on SelectChannelEndPoint@15c7d05{/192.168.1.9:45427<->8080,Open,in,out,R,-,7/30000,HttpConnection}{io=1,kio=1,kro=1} 23:00:01.926 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop waiting on select 23:00:09.067 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers 23:00:11.859 [DEBUG] [io.socket.engineio.client.Socket ] - writing ping packet - expecting pong within 60000ms 23:00:11.859 [DEBUG] [io.socket.engineio.client.Socket ] - flushing 1 packets in socket 23:00:11.904 [DEBUG] [io.socket.engineio.client.Socket ] - socket received: type 'pong', data 'null':scream:
192.168.1.9 is the computer (ubuntu) from which i do ssh...And this is the log during "idle"
23:02:48.131 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers 23:02:55.692 [DEBUG] [org.eclipse.jetty.io.IdleTimeout ] - SelectChannelEndPoint@10fcc9b{/192.168.1.9:45209<->8080,Open,in,out,-,-,30000/30000,HttpConnection}{io=0,kio=0,kro=1} idle timeout check, elapsed: 30000 ms, remaining: 0 ms 23:02:55.693 [DEBUG] [org.eclipse.jetty.io.IdleTimeout ] - SelectChannelEndPoint@10fcc9b{/192.168.1.9:45209<->8080,Open,in,out,-,-,30002/30000,HttpConnection}{io=0,kio=0,kro=1} idle timeout expired 23:02:55.695 [DEBUG] [rg.eclipse.jetty.io.AbstractEndPoint] - Ignored idle endpoint SelectChannelEndPoint@10fcc9b{/192.168.1.9:45209<->8080,Open,in,out,-,-,30003/30000,HttpConnection}{io=0,kio=0,kro=1} 23:03:08.614 [DEBUG] [io.socket.engineio.client.Socket ] - writing ping packet - expecting pong within 60000ms 23:03:08.614 [DEBUG] [io.socket.engineio.client.Socket ] - flushing 1 packets in socket 23:03:08.655 [DEBUG] [io.socket.engineio.client.Socket ] - socket received: type 'pong', data 'null'@ben999 My bad sorry, your first log already contained the debug information.
To which serial port is the gateway connected? I see that it connected, but I'm missing a few messages that should appear. Could you please specify the bridge / gateway (only the gateway) in the *.things file according to the description in the wiki and see if that works?
We should see the messages the gateway receives in the debug output.
-
I have almost the same problem. Items don't get added to the inbox when a new node is found.
Also when i add them manualy, things don't work(it was working earlier) So i think something changed for the bindings. So at the moment the MySensors binding is not working with latest snapshot(#597)My Debug log:
2016-11-20 01:43:15.119 [DEBUG] [ernal.handler.MySensorsBridgeHandler] - Initialization of the MySensors bridge 2016-11-20 01:43:15.119 [DEBUG] [col.serial.MySensorsSerialConnection] - Set skip check on startup to: false 2016-11-20 01:43:15.119 [DEBUG] [col.serial.MySensorsSerialConnection] - Enabling connection watchdog 2016-11-20 01:43:15.126 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache file: given_ids.cached exist. 2016-11-20 01:43:15.126 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache (given_ids) content: [32, 52, 51, 40, 36, 35] 2016-11-20 01:43:15.126 [DEBUG] [ernal.handler.MySensorsBridgeHandler] - Initialization of the MySensors bridge DONE! 2016-11-20 01:43:15.127 [DEBUG] [col.serial.MySensorsSerialConnection] - Connecting to /dev/ttyUSB21 [baudRate:9600] 2016-11-20 01:43:15.127 [DEBUG] [col.serial.MySensorsSerialConnection] - Final port list: /dev/ttyUSB21 2016-11-20 01:43:15.133 [DEBUG] [col.serial.MySensorsSerialConnection] - Successfully connected to serial port. 2016-11-20 01:43:15.133 [DEBUG] [col.serial.MySensorsSerialConnection] - Waiting 3 seconds to allow correct reset trigger on serial connection opening 2016-11-20 01:43:18.235 [DEBUG] [rs.internal.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2; 2016-11-20 01:43:18.246 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;2;2.0.0 2016-11-20 01:43:18.246 [DEBUG] [col.serial.MySensorsSerialConnection] - Good,Gateway is up and running! (Ver:2.0.0) 2016-11-20 01:43:18.247 [INFO ] [col.serial.MySensorsSerialConnection] - Successfully connected to MySensors Bridge. 2016-11-20 01:43:18.247 [WARN ] [col.serial.MySensorsSerialConnection] - Network Sanity Checker thread disabled from bridge configuration 2016-11-20 01:43:18.258 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 32, chiledId: 0, revertState: false 2016-11-20 01:43:18.259 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 35, chiledId: 0, revertState: false 2016-11-20 01:43:18.259 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 51, chiledId: 3, revertState: false 2016-11-20 01:43:18.259 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 52, chiledId: 3, revertState: false 2016-11-20 01:43:18.259 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 35, chiledId: 3, revertState: false 2016-11-20 01:43:18.260 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 40, chiledId: 0, revertState: true 2016-11-20 01:43:18.260 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 36, chiledId: 3, revertState: false 2016-11-20 01:43:18.260 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 36, chiledId: 1, revertState: false 2016-11-20 01:43:18.260 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 36, chiledId: 0, revertState: false 2016-11-20 01:43:18.260 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 32, chiledId: 3, revertState: false 2016-11-20 01:43:18.261 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 52, chiledId: 4, revertState: false 2016-11-20 01:43:18.261 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 52, chiledId: 5, revertState: false 2016-11-20 01:43:18.262 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 32, chiledId: 1, revertState: false 2016-11-20 01:43:18.262 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 35, chiledId: 1, revertState: false 2016-11-20 01:43:18.263 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 51, chiledId: 4, revertState: false 2016-11-20 01:43:20.379 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:SANCHK:OK 2016-11-20 01:43:28.247 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:43:20.379 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:SANCHK:OK 2016-11-20 01:43:28.247 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:43:38.248 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:43:48.248 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:43:58.249 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:44:01.834 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 32-32-0 s=255,c=3,t=22,pt=5,l=4,sg=0:19562725 2016-11-20 01:44:01.845 [DEBUG] [rs.internal.protocol.MySensorsReader] - 32;255;3;0;22;19562725 2016-11-20 01:44:02.591 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 32-32-0 s=1,c=1,t=0,pt=7,l=5,sg=0:18.2 2016-11-20 01:44:02.591 [DEBUG] [rs.internal.protocol.MySensorsReader] - 32;1;1;0;0;18.2 2016-11-20 01:44:02.683 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 32-32-0 s=2,c=1,t=4,pt=7,l=5,sg=0:1000.8 2016-11-20 01:44:02.683 [DEBUG] [rs.internal.protocol.MySensorsReader] - 32;2;1;0;4;1000.8 2016-11-20 01:44:02.764 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 32-32-0 s=0,c=1,t=1,pt=7,l=5,sg=0:52.1 2016-11-20 01:44:02.774 [DEBUG] [rs.internal.protocol.MySensorsReader] - 32;0;1;0;1;52.1 2016-11-20 01:44:02.855 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 32-32-0 s=2,c=1,t=5,pt=0,l=6,sg=0:cloudy 2016-11-20 01:44:02.856 [DEBUG] [rs.internal.protocol.MySensorsReader] - 32;2;1;0;5;cloudy 2016-11-20 01:44:08.249 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:44:18.249 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:44:20.380 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:SANCHK:OK 2016-11-20 01:44:27.370 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 52-52-0 s=4,c=1,t=0,pt=7,l=5,sg=0:15.1 2016-11-20 01:44:27.370 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:ACK msg 2016-11-20 01:44:27.380 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:SEND 0-0-52-52 s=4,c=1,t=0,pt=7,l=5,sg=0,ft=0,st=ok:15.1 2016-11-20 01:44:27.381 [DEBUG] [rs.internal.protocol.MySensorsReader] - 52;4;1;0;0;15.1 2016-11-20 01:44:27.522 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 52-52-0 s=3,c=1,t=1,pt=7,l=5,sg=0:49.3 2016-11-20 01:44:27.522 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:ACK msg 2016-11-20 01:44:27.563 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;!TSP:MSG:SEND 0-0-52-52 s=3,c=1,t=1,pt=7,l=5,sg=0,ft=0,st=ok:49.3 2016-11-20 01:44:27.564 [DEBUG] [rs.internal.protocol.MySensorsReader] - 52;3;1;0;1;49.3 2016-11-20 01:44:28.250 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:44:30.102 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 51-51-0 s=4,c=1,t=0,pt=7,l=5,sg=0:4.5 2016-11-20 01:44:30.102 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:ACK msg 2016-11-20 01:44:30.113 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:SEND 0-0-51-51 s=4,c=1,t=0,pt=7,l=5,sg=0,ft=0,st=ok:4.5 2016-11-20 01:44:30.113 [DEBUG] [rs.internal.protocol.MySensorsReader] - 51;4;1;0;0;4.5 2016-11-20 01:44:30.204 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 51-51-0 s=3,c=1,t=1,pt=7,l=5,sg=0:91.8 2016-11-20 01:44:30.204 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:ACK msg 2016-11-20 01:44:30.255 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;!TSP:MSG:SEND 0-0-51-51 s=3,c=1,t=1,pt=7,l=5,sg=0,ft=0,st=fail:91.8 2016-11-20 01:44:30.255 [DEBUG] [rs.internal.protocol.MySensorsReader] - 51;3;1;0;1;91.8 2016-11-20 01:44:38.250 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:44:42.816 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 35-35-0 s=255,c=3,t=0,pt=1,l=1,sg=0:57 2016-11-20 01:44:42.826 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:ACK msg 2016-11-20 01:44:42.826 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:SEND 0-0-35-35 s=255,c=3,t=0,pt=1,l=1,sg=0,ft=0,st=ok:57 2016-11-20 01:44:42.837 [DEBUG] [rs.internal.protocol.MySensorsReader] - 35;255;3;0;0;57 2016-11-20 01:44:42.908 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 35-35-0 s=3,c=1,t=38,pt=7,l=5,sg=0:2.6600 2016-11-20 01:44:42.908 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:ACK msg 2016-11-20 01:44:42.918 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:SEND 0-0-35-35 s=3,c=1,t=38,pt=7,l=5,sg=0,ft=0,st=ok:2.6600 2016-11-20 01:44:42.919 [DEBUG] [rs.internal.protocol.MySensorsReader] - 35;3;1;0;38;2.6600 2016-11-20 01:44:43.040 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 35-35-0 s=1,c=1,t=0,pt=7,l=5,sg=0:18.9 2016-11-20 01:44:43.040 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:ACK msg 2016-11-20 01:44:43.081 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;!TSP:MSG:SEND 0-0-35-35 s=1,c=1,t=0,pt=7,l=5,sg=0,ft=0,st=ok:18.9 2016-11-20 01:44:43.081 [DEBUG] [rs.internal.protocol.MySensorsReader] - 35;1;1;0;0;18.9As you can see, i recieve messages from the gateway. No items are updated.
-
I have almost the same problem. Items don't get added to the inbox when a new node is found.
Also when i add them manualy, things don't work(it was working earlier) So i think something changed for the bindings. So at the moment the MySensors binding is not working with latest snapshot(#597)My Debug log:
2016-11-20 01:43:15.119 [DEBUG] [ernal.handler.MySensorsBridgeHandler] - Initialization of the MySensors bridge 2016-11-20 01:43:15.119 [DEBUG] [col.serial.MySensorsSerialConnection] - Set skip check on startup to: false 2016-11-20 01:43:15.119 [DEBUG] [col.serial.MySensorsSerialConnection] - Enabling connection watchdog 2016-11-20 01:43:15.126 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache file: given_ids.cached exist. 2016-11-20 01:43:15.126 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache (given_ids) content: [32, 52, 51, 40, 36, 35] 2016-11-20 01:43:15.126 [DEBUG] [ernal.handler.MySensorsBridgeHandler] - Initialization of the MySensors bridge DONE! 2016-11-20 01:43:15.127 [DEBUG] [col.serial.MySensorsSerialConnection] - Connecting to /dev/ttyUSB21 [baudRate:9600] 2016-11-20 01:43:15.127 [DEBUG] [col.serial.MySensorsSerialConnection] - Final port list: /dev/ttyUSB21 2016-11-20 01:43:15.133 [DEBUG] [col.serial.MySensorsSerialConnection] - Successfully connected to serial port. 2016-11-20 01:43:15.133 [DEBUG] [col.serial.MySensorsSerialConnection] - Waiting 3 seconds to allow correct reset trigger on serial connection opening 2016-11-20 01:43:18.235 [DEBUG] [rs.internal.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2; 2016-11-20 01:43:18.246 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;2;2.0.0 2016-11-20 01:43:18.246 [DEBUG] [col.serial.MySensorsSerialConnection] - Good,Gateway is up and running! (Ver:2.0.0) 2016-11-20 01:43:18.247 [INFO ] [col.serial.MySensorsSerialConnection] - Successfully connected to MySensors Bridge. 2016-11-20 01:43:18.247 [WARN ] [col.serial.MySensorsSerialConnection] - Network Sanity Checker thread disabled from bridge configuration 2016-11-20 01:43:18.258 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 32, chiledId: 0, revertState: false 2016-11-20 01:43:18.259 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 35, chiledId: 0, revertState: false 2016-11-20 01:43:18.259 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 51, chiledId: 3, revertState: false 2016-11-20 01:43:18.259 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 52, chiledId: 3, revertState: false 2016-11-20 01:43:18.259 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 35, chiledId: 3, revertState: false 2016-11-20 01:43:18.260 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 40, chiledId: 0, revertState: true 2016-11-20 01:43:18.260 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 36, chiledId: 3, revertState: false 2016-11-20 01:43:18.260 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 36, chiledId: 1, revertState: false 2016-11-20 01:43:18.260 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 36, chiledId: 0, revertState: false 2016-11-20 01:43:18.260 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 32, chiledId: 3, revertState: false 2016-11-20 01:43:18.261 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 52, chiledId: 4, revertState: false 2016-11-20 01:43:18.261 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 52, chiledId: 5, revertState: false 2016-11-20 01:43:18.262 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 32, chiledId: 1, revertState: false 2016-11-20 01:43:18.262 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 35, chiledId: 1, revertState: false 2016-11-20 01:43:18.263 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 51, chiledId: 4, revertState: false 2016-11-20 01:43:20.379 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:SANCHK:OK 2016-11-20 01:43:28.247 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:43:20.379 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:SANCHK:OK 2016-11-20 01:43:28.247 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:43:38.248 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:43:48.248 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:43:58.249 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:44:01.834 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 32-32-0 s=255,c=3,t=22,pt=5,l=4,sg=0:19562725 2016-11-20 01:44:01.845 [DEBUG] [rs.internal.protocol.MySensorsReader] - 32;255;3;0;22;19562725 2016-11-20 01:44:02.591 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 32-32-0 s=1,c=1,t=0,pt=7,l=5,sg=0:18.2 2016-11-20 01:44:02.591 [DEBUG] [rs.internal.protocol.MySensorsReader] - 32;1;1;0;0;18.2 2016-11-20 01:44:02.683 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 32-32-0 s=2,c=1,t=4,pt=7,l=5,sg=0:1000.8 2016-11-20 01:44:02.683 [DEBUG] [rs.internal.protocol.MySensorsReader] - 32;2;1;0;4;1000.8 2016-11-20 01:44:02.764 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 32-32-0 s=0,c=1,t=1,pt=7,l=5,sg=0:52.1 2016-11-20 01:44:02.774 [DEBUG] [rs.internal.protocol.MySensorsReader] - 32;0;1;0;1;52.1 2016-11-20 01:44:02.855 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 32-32-0 s=2,c=1,t=5,pt=0,l=6,sg=0:cloudy 2016-11-20 01:44:02.856 [DEBUG] [rs.internal.protocol.MySensorsReader] - 32;2;1;0;5;cloudy 2016-11-20 01:44:08.249 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:44:18.249 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:44:20.380 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:SANCHK:OK 2016-11-20 01:44:27.370 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 52-52-0 s=4,c=1,t=0,pt=7,l=5,sg=0:15.1 2016-11-20 01:44:27.370 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:ACK msg 2016-11-20 01:44:27.380 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:SEND 0-0-52-52 s=4,c=1,t=0,pt=7,l=5,sg=0,ft=0,st=ok:15.1 2016-11-20 01:44:27.381 [DEBUG] [rs.internal.protocol.MySensorsReader] - 52;4;1;0;0;15.1 2016-11-20 01:44:27.522 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 52-52-0 s=3,c=1,t=1,pt=7,l=5,sg=0:49.3 2016-11-20 01:44:27.522 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:ACK msg 2016-11-20 01:44:27.563 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;!TSP:MSG:SEND 0-0-52-52 s=3,c=1,t=1,pt=7,l=5,sg=0,ft=0,st=ok:49.3 2016-11-20 01:44:27.564 [DEBUG] [rs.internal.protocol.MySensorsReader] - 52;3;1;0;1;49.3 2016-11-20 01:44:28.250 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:44:30.102 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 51-51-0 s=4,c=1,t=0,pt=7,l=5,sg=0:4.5 2016-11-20 01:44:30.102 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:ACK msg 2016-11-20 01:44:30.113 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:SEND 0-0-51-51 s=4,c=1,t=0,pt=7,l=5,sg=0,ft=0,st=ok:4.5 2016-11-20 01:44:30.113 [DEBUG] [rs.internal.protocol.MySensorsReader] - 51;4;1;0;0;4.5 2016-11-20 01:44:30.204 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 51-51-0 s=3,c=1,t=1,pt=7,l=5,sg=0:91.8 2016-11-20 01:44:30.204 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:ACK msg 2016-11-20 01:44:30.255 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;!TSP:MSG:SEND 0-0-51-51 s=3,c=1,t=1,pt=7,l=5,sg=0,ft=0,st=fail:91.8 2016-11-20 01:44:30.255 [DEBUG] [rs.internal.protocol.MySensorsReader] - 51;3;1;0;1;91.8 2016-11-20 01:44:38.250 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped 2016-11-20 01:44:42.816 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 35-35-0 s=255,c=3,t=0,pt=1,l=1,sg=0:57 2016-11-20 01:44:42.826 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:ACK msg 2016-11-20 01:44:42.826 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:SEND 0-0-35-35 s=255,c=3,t=0,pt=1,l=1,sg=0,ft=0,st=ok:57 2016-11-20 01:44:42.837 [DEBUG] [rs.internal.protocol.MySensorsReader] - 35;255;3;0;0;57 2016-11-20 01:44:42.908 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 35-35-0 s=3,c=1,t=38,pt=7,l=5,sg=0:2.6600 2016-11-20 01:44:42.908 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:ACK msg 2016-11-20 01:44:42.918 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:SEND 0-0-35-35 s=3,c=1,t=38,pt=7,l=5,sg=0,ft=0,st=ok:2.6600 2016-11-20 01:44:42.919 [DEBUG] [rs.internal.protocol.MySensorsReader] - 35;3;1;0;38;2.6600 2016-11-20 01:44:43.040 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:READ 35-35-0 s=1,c=1,t=0,pt=7,l=5,sg=0:18.9 2016-11-20 01:44:43.040 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;TSP:MSG:ACK msg 2016-11-20 01:44:43.081 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;9;!TSP:MSG:SEND 0-0-35-35 s=1,c=1,t=0,pt=7,l=5,sg=0,ft=0,st=ok:18.9 2016-11-20 01:44:43.081 [DEBUG] [rs.internal.protocol.MySensorsReader] - 35;1;1;0;0;18.9As you can see, i recieve messages from the gateway. No items are updated.
@FutureCow Strange, I'll look into it. I suppose I've introduced this bug with the latest refactoring. :-/
-
@ben999 My bad sorry, your first log already contained the debug information.
To which serial port is the gateway connected? I see that it connected, but I'm missing a few messages that should appear. Could you please specify the bridge / gateway (only the gateway) in the *.things file according to the description in the wiki and see if that works?
We should see the messages the gateway receives in the debug output.
@TimO
Hi Tim
Thanks a lot for your message.
NRF is connected to GPIO pins as per https://www.mysensors.org/build/raspberry
I have rundmesg |grep -i ttyas suggested by @Yveaux and i got[ 0.000000] Kernel command line: 8250.nr_uarts=0 dma.dmachans=0x7f35 bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2709.boardrev=0xa02082 bcm2709.serial=0xcc3e67e3 smsc95xx.macaddr=B8:27:EB:3E:67:E3 bcm2708_fb.fbswap=1 bcm2709.uart_clock=48000000 vc_mem.mem_base=0x3dc00000 vc_mem.mem_size=0x3f000000 dwc_otg.lpm_enable=0 console=ttyS0,115200 console=tty1 root=/dev/mmcblk0p2 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait [ 0.001337] console [tty1] enabled [ 1.781491] 3f201000.uart: ttyAMA0 at MMIO 0x3f201000 (irq = 87, base_baud = 0) is a PL011 rev2I assumed that my serail port would be ttyAMA0
So i wrote my "home.things" file with it:Bridge mysensors:bridge-ser:gateway [ serialPort="/dev/ttyAMA0", sendDelay=200 ] { /** define things connected to that bridge here */ }This
pi@raspberrypi:~ $ screen /dev/ttyAMA0 115200returns that[screen is terminating]Also, when watching the live output from
sudo ./bin/mysgw -di can see thatpi@raspberrypi:~ $ cd MySensors pi@raspberrypi:~/MySensors $ sudo ./bin/mysgw -d mysgw: Starting gateway... mysgw: Protocol version - 2.0.1-beta mysgw: MCO:BGN:INIT GW,CP=RNNG---,VER=2.0.1-beta mysgw: TSF:LRT:OK mysgw: TSM:INIT mysgw: TSM:INIT:TSP OK mysgw: TSM:INIT:GW MODE mysgw: TSM:READY mysgw: Listening for connections on 0.0.0.0:5003but when i launch openhab with
sudo ./start_debug.shi seeLaunching the openHAB runtime... Listening for transport dt_socket at address: 50055003 vs 5005... I tried that
pi@raspberrypi:~/MySensors $ ./configure --my-port=5005but no luck, I got that in return...mysgw: accept: Bad file descriptor mysgw: accept: Bad file descriptorgoing forever :(
-
Features
- Serial Gateway supported (with variable baud rate)
- Ethernet Gateway supported
- Supported sensors: S_TEMP, S_HUM, S_VOLTAGE, S_LIGHT, S_POWER, S_BARO, S_DOOR, S_MOTION, S_SMOKE, S_DIMMER, S_COVER (Stop not implemented in OH2 yet), S_WIND, S_RAIN, S_UV, S_WEIGHT, S_DISTANCE, S_LIGHT_LEVEL
- Request for an ID is answered (random free number is given)
- Discovery of devices, to use it: start the scan for devices in OpenHAB 2.0 and restart your nodes
Pictures
Discovery:
What is not working yet:
- no reconnect after lost connection
How to test:
Visit the wiki on the GitHub Repo.
@TimO said:
GitHub Repo
So I´m very new to OpenHAB, but I´ve tried to bind MySensors for a few days now, and I´m stuck. I´d be really happy if someone could guide me a little further.-I´ve flashed and installed OpenHABian on my Raspberry. (OpenHAB2)
-Managed to bind my Sonos through the paper ui, so the OpenHAB2 install looks good.
-Now I wish to bind Mysensors on a serial gateway.Looking at the GitHub install guide it seems as simple as adding the MySensors.jar file to the addons directory, but from what I can see, bindings are not managed like that in OpenHab2? All guiding I read seems to refer to another file structure in OpenHab 1.8.
I managed to find an addons directory in /usr/share/openhab2/addons, but I can´t find a way to copy the .jar file there, as I get permission denied both through WinSCP in sudo mode and terminal ssh. The folder has permission 0775.Can anyone guide me to thread that describes how to install MySensors on an OpenHABian Raspberry installation?
-
@bentrik said:
I managed to find an addons directory in /usr/share/openhab2/addons, but I can´t find a way to copy the .jar file there, as I get permission denied both through WinSCP in sudo mode and terminal ssh. The folder has permission 0775.
That is the correct directory if you installed OH2 via .deb. Seems like you are using a user in WinSCP that is not allowed to write to the directory above. To circumvent this:
- Copy the binding jar to /tmp.
- Login via ssh and execute:
sudo cp /tmp/org.openhab.binding.mysensors-2.0.0-SNAPSHOT.jar /usr/share/openhab2/addons/and
sudo chmod openhab.openhab /usr/share/openhab2/addons/org.openhab.binding.mysensors-2.0.0-SNAPSHOT.jarOH2 is started/stopped/restarted with
service openhab2 start/stop/restartTo log into the karaf console do:
ssh openhab@localhost -p 8101Password is: habopen
Follow the guide/wiki from:
In the console enter feature:install openhab-transport-serial -
@TimO
Hi Tim
Thanks a lot for your message.
NRF is connected to GPIO pins as per https://www.mysensors.org/build/raspberry
I have rundmesg |grep -i ttyas suggested by @Yveaux and i got[ 0.000000] Kernel command line: 8250.nr_uarts=0 dma.dmachans=0x7f35 bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2709.boardrev=0xa02082 bcm2709.serial=0xcc3e67e3 smsc95xx.macaddr=B8:27:EB:3E:67:E3 bcm2708_fb.fbswap=1 bcm2709.uart_clock=48000000 vc_mem.mem_base=0x3dc00000 vc_mem.mem_size=0x3f000000 dwc_otg.lpm_enable=0 console=ttyS0,115200 console=tty1 root=/dev/mmcblk0p2 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait [ 0.001337] console [tty1] enabled [ 1.781491] 3f201000.uart: ttyAMA0 at MMIO 0x3f201000 (irq = 87, base_baud = 0) is a PL011 rev2I assumed that my serail port would be ttyAMA0
So i wrote my "home.things" file with it:Bridge mysensors:bridge-ser:gateway [ serialPort="/dev/ttyAMA0", sendDelay=200 ] { /** define things connected to that bridge here */ }This
pi@raspberrypi:~ $ screen /dev/ttyAMA0 115200returns that[screen is terminating]Also, when watching the live output from
sudo ./bin/mysgw -di can see thatpi@raspberrypi:~ $ cd MySensors pi@raspberrypi:~/MySensors $ sudo ./bin/mysgw -d mysgw: Starting gateway... mysgw: Protocol version - 2.0.1-beta mysgw: MCO:BGN:INIT GW,CP=RNNG---,VER=2.0.1-beta mysgw: TSF:LRT:OK mysgw: TSM:INIT mysgw: TSM:INIT:TSP OK mysgw: TSM:INIT:GW MODE mysgw: TSM:READY mysgw: Listening for connections on 0.0.0.0:5003but when i launch openhab with
sudo ./start_debug.shi seeLaunching the openHAB runtime... Listening for transport dt_socket at address: 50055003 vs 5005... I tried that
pi@raspberrypi:~/MySensors $ ./configure --my-port=5005but no luck, I got that in return...mysgw: accept: Bad file descriptor mysgw: accept: Bad file descriptorgoing forever :(
If you are using the RPi gateway with the options you provided above:
sudo ./bin/mysgw -dYou need to configure the OH2 binding to connect to a ethernet gateway (via localhost, 127.0.0.1 and port 5003), don't use the serial gateway. You are able to confirm this if you execute a "telnet localhost 5003" on the RPi and should be see the messages incoming from the node.
-
I did some testing with older and newer version:
OpenHAB #457, MySensor_Binding Aug2016, Text conf: No problems
OpenHAB #457, MySensor_Binding Nov2016, Text conf: No problems
OpenHAB #457, MySensor_Binding Aug2016, PaperUI conf: No autodiscovery, Manual Add: No problems
OpenHAB #457, MySensor_Binding Nov2016, PaperUI conf: No autodiscovery, Manual Add: No problemsOpenHAB #603, MySensor_Binding Aug2016, Text conf: Doesn't Work!
OpenHAB #603, MySensor_Binding Nov2016, Text conf: Doesn't work!
OpenHAB #603, MySensor_Binding Aug2016, PaperUI conf: No autodiscovery, Manual Add: Doesn't work!
OpenHAB #603, MySensor_Binding Nov2016, PaperUI conf: No autodiscovery, Manual Add: Doesn't work!Doesn't work! means the gateway is working, I receive messages, but the items doesn't get updated.
Also restarting openhab/mysensor binding doesnt solve the problem. -
I did some testing with older and newer version:
OpenHAB #457, MySensor_Binding Aug2016, Text conf: No problems
OpenHAB #457, MySensor_Binding Nov2016, Text conf: No problems
OpenHAB #457, MySensor_Binding Aug2016, PaperUI conf: No autodiscovery, Manual Add: No problems
OpenHAB #457, MySensor_Binding Nov2016, PaperUI conf: No autodiscovery, Manual Add: No problemsOpenHAB #603, MySensor_Binding Aug2016, Text conf: Doesn't Work!
OpenHAB #603, MySensor_Binding Nov2016, Text conf: Doesn't work!
OpenHAB #603, MySensor_Binding Aug2016, PaperUI conf: No autodiscovery, Manual Add: Doesn't work!
OpenHAB #603, MySensor_Binding Nov2016, PaperUI conf: No autodiscovery, Manual Add: Doesn't work!Doesn't work! means the gateway is working, I receive messages, but the items doesn't get updated.
Also restarting openhab/mysensor binding doesnt solve the problem.@FutureCow Thanks for testing! There definiatly is a bug and slowly I'm getting a grip on it. The annoying thing is: in my development environment everything works smooth, so I updated my production environment and voila there is the problem: no thing updates.
It looks like a timing issue on initialization of the bridge/gateway. I'll dig deeper!
The topic autodiscovery will follow, I've not spent much time in testing this feature as it was of no use till lately. Now PaperUI/Habpanel are getting the functionality that makes it usable and will make the big difference to OpenHAB 1.
-
I also have similar problems, after upgrade OH to latest snapshot yesterday. All things remain in offline status. Discovery is working when I hit "Search for things" from Paper UI and force presentation/reset on some sensor.
21:23:12.982 [DEBUG] [org.openhab.binding.mysensors ] - BundleEvent STARTING - org.openhab.binding.mysensors 21:23:13.062 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=org.openhab.binding.mysensors.internal.factory.MySensorsHandlerFactory, component.id=252, service.id=400, service.bundleid=198, service.scope=bundle} - org.openhab.binding.mysensors 21:23:13.082 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=401, service.bundleid=198, service.scope=singleton} - org.openhab.binding.mysensors 21:23:13.121 [DEBUG] [org.openhab.binding.mysensors ] - BundleEvent STARTED - org.openhab.binding.mysensors 21:23:13.548 [DEBUG] [ernal.handler.MySensorsBridgeHandler] - Initialization of the MySensors bridge 21:23:13.551 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Set skip check on startup to: false 21:23:13.552 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Enabling connection watchdog 21:23:13.555 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache file: given_ids.cached exist. 21:23:13.557 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache (given_ids) content: [5, 12, 7, 10, 1, 9, 3, 8, 30, 6, 24] 21:23:13.559 [DEBUG] [ernal.handler.MySensorsBridgeHandler] - Initialization of the MySensors bridge DONE! 21:23:13.549 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-eth:gateway' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING 21:23:13.571 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Connecting to IP bridge [127.0.0.1:5003] 21:23:13.596 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;14;Gateway startup complete. 21:23:13.598 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;0;0;18;2.0.1-beta 21:23:13.778 [DEBUG] [rs.internal.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2; 21:23:13.797 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;2;2.0.1-beta 21:23:13.800 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Good,Gateway is up and running! (Ver:2.0.1-beta) 21:23:13.813 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-eth:gateway' changed from INITIALIZING to ONLINE 21:23:13.828 [INFO ] [al.protocol.ip.MySensorsIpConnection] - Successfully connected to MySensors Bridge. 21:23:13.830 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 12, chiledId: 1, revertState: false 21:23:13.830 [WARN ] [al.protocol.ip.MySensorsIpConnection] - Network Sanity Checker thread disabled from bridge configuration 21:23:13.855 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:power:gateway:house_power_12_1' changed from INITIALIZING to OFFLINE 21:23:13.856 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:power:gateway:house_power_12_1' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING 21:23:13.882 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 24, chiledId: 1, revertState: false 21:23:13.892 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:dimmer:gateway:Dimmer_24_1' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING 21:23:13.892 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 5, chiledId: 1, revertState: false 21:23:13.899 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:dimmer:gateway:living_room_5_1' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING 21:23:13.904 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:dimmer:gateway:Dimmer_24_1' changed from INITIALIZING to OFFLINE 21:23:13.926 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:dimmer:gateway:living_room_5_1' changed from INITIALIZING to OFFLINE 21:23:23.832 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped 21:23:25.599 [DEBUG] [rs.internal.protocol.MySensorsReader] - 12;1;1;0;17;516 21:23:25.624 [DEBUG] [rs.internal.protocol.MySensorsReader] - 12;1;1;0;24;550307 21:23:25.639 [DEBUG] [rs.internal.protocol.MySensorsReader] - 12;1;1;0;18;55.0307 21:23:29.103 [DEBUG] [rs.internal.protocol.MySensorsReader] - 7;1;1;0;0;19.8 21:23:29.119 [DEBUG] [rs.internal.protocol.MySensorsReader] - 7;255;3;0;22;1208410Also, when I stop bundle from karaf console, this error appears in log:
21:24:37.371 [DEBUG] [org.openhab.binding.mysensors ] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=401, service.bundleid=198, service.scope=singleton} - org.openhab.binding.mysensors 21:24:37.379 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:dimmer:gateway:Dimmer_24_1' changed from OFFLINE to UNINITIALIZED (HANDLER_MISSING_ERROR) 21:24:37.397 [DEBUG] [ernal.handler.MySensorsBridgeHandler] - Disposing of the MySensors bridge 21:24:37.399 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Destroying connection 21:24:37.400 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Disconnecting from IP bridge ... 21:24:37.401 [DEBUG] [rs.internal.protocol.MySensorsWriter] - Stopping Writer thread 21:24:37.413 [ERROR] [rs.internal.protocol.MySensorsWriter] - (java.lang.InterruptedException) on writing from serial port, message: class org.openhab.binding.mysensors.internal.protocol.ip.MySensorsIpWriter 21:24:37.414 [DEBUG] [rs.internal.protocol.MySensorsReader] - Stopping Reader thread 21:24:37.422 [ERROR] [rs.internal.protocol.MySensorsReader] - (java.lang.InterruptedException: sleep interrupted) on reading from serial port, message: class org.openhab.binding.mysensors.internal.protocol.ip.MySensorIpReader 21:24:37.422 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache file: given_ids.cached exist. 21:24:37.426 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache (given_ids) content: [5, 12, 7, 10, 1, 9, 3, 8, 30, 6, 24] 21:24:37.433 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-eth:gateway' changed from ONLINE to UNINITIALIZED (HANDLER_MISSING_ERROR) 21:24:37.429 [ERROR] [ome.core.thing.internal.ThingManager] - Exception occured while disposing handler of thing 'mysensors:bridge-eth:gateway': java.lang.NullPointerException java.util.concurrent.ExecutionException: java.lang.NullPointerException at java.util.concurrent.FutureTask.report(FutureTask.java:122)[:1.8.0_65] at java.util.concurrent.FutureTask.get(FutureTask.java:206)[:1.8.0_65] at org.eclipse.smarthome.core.common.SafeMethodCaller.callAsynchronous(SafeMethodCaller.java:186) at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:79) at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:63) at org.eclipse.smarthome.core.thing.internal.ThingManager.doDisposeHandler(ThingManager.java:858) at org.eclipse.smarthome.core.thing.internal.ThingManager.disposeHandler(ThingManager.java:848) at org.eclipse.smarthome.core.thing.internal.ThingManager.removeThingHandlerFactory(ThingManager.java:1045) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.8.0_65] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_65] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_65] at java.lang.reflect.Method.invoke(Method.java:497)[:1.8.0_65] at org.apache.felix.scr.impl.helper.BaseMethod.invokeMethod(BaseMethod.java:222)[34:org.apache.felix.scr:2.0.2] at org.apache.felix.scr.impl.helper.BaseMethod.access$500(BaseMethod.java:37)[34:org.apache.felix.scr:2.0.2] at org.apache.felix.scr.impl.helper.BaseMethod$Resolved.invoke(BaseMethod.java:615)[34:org.apache.felix.scr:2.0.2] at org.apache.felix.scr.impl.helper.BaseMethod.invoke(BaseMethod.java:499)[34:org.apache.felix.scr:2.0.2] at org.apache.felix.scr.impl.helper.BindMethod.invoke(BindMethod.java:41)[34:org.apache.felix.scr:2.0.2] at org.apache.felix.scr.impl.manager.DependencyManager.invokeUnbindMethod(DependencyManager.java:1774)[34:org.apache.felix.scr:2.0.2] at org.apache.felix.scr.impl.manager.SingleComponentManager.invokeUnbindMethod(SingleComponentManager.java:393)[34:org.apache.felix.scr:2.0.2] at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.removedService(DependencyManager.java:364)[34:org.apache.felix.scr:2.0.2] at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.removedService(DependencyManager.java:295)[34:org.apache.felix.scr:2.0.2] at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerRemoved(ServiceTracker.java:1241)[34:org.apache.felix.scr:2.0.2] at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerRemoved(ServiceTracker.java:1136)[34:org.apache.felix.scr:2.0.2] at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.untrack(ServiceTracker.java:996)[34:org.apache.felix.scr:2.0.2] at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1175)[34:org.apache.felix.scr:2.0.2] at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:120)[34:org.apache.felix.scr:2.0.2] at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:] -
If you are using the RPi gateway with the options you provided above:
sudo ./bin/mysgw -dYou need to configure the OH2 binding to connect to a ethernet gateway (via localhost, 127.0.0.1 and port 5003), don't use the serial gateway. You are able to confirm this if you execute a "telnet localhost 5003" on the RPi and should be see the messages incoming from the node.
@TimO
Thank you one more time TimSo i went ahead and replaced
Bridge mysensors:bridge-ser:gateway [ serialPort="/dev/ttyAMA0", sendDelay=200 ]with
Bridge mysensors:bridge-eth:gateway [ ipAddress="127.0.0.1", tcpPort=5003, sendDelay=200 ]together with
pi@raspberrypi:/usr/share/openhab2 $ ./configure --my-gateway=ethernet --my-port=5003 --my-serial-port=/dev/ttyAMA0pi@raspberrypi:/ $ telnet 127.0.0.1 5003returns what is expected i guess :Trying 127.0.0.1... Connected to 127.0.0.1. Escape character is '^]'. 0;255;3;0;14;Gateway startup complete. 0;255;0;0;18;2.0.1-beta 1;255;0;0;17;2.0.0 1;255;3;0;11;TemperatureAndHumidity 1;255;3;0;12;1.1 1;0;0;0;7; 1;1;0;0;6; 1;1;1;0;0;19.1 1;0;1;0;1;62.5But still, there must be a missing link : neither in PaperUi nor openHab on iOS i get temp and humidity readings...
This is my OH2 log:tail
06:26:19.597 [DEBUG] [e.internal.WriterInterceptorExecutor] - Message body writer (class com.eclipsesource.jaxrs.provider.gson.GsonProvider) is trying to close the entity output stream. Not closing. 06:26:19.598 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1785907[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,740,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@113ab9] generate: NEED_HEADER (null,[p=0,l=740,c=8192,r=740],true)@START 06:26:19.600 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1785907[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,740,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@113ab9] generate: FLUSH ([p=0,l=105,c=8192,r=105],[p=0,l=740,c=8192,r=740],true)@COMPLETING 06:26:19.601 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - write: WriteFlusher@af70aa{IDLE} [HeapByteBuffer@2a5ea9[p=0,l=105,c=8192,r=105]={<<<HTTP/1.1 200 OK\r\n....v20151106)\r\n\r\n>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},HeapByteBuffer@1ef785[p=0,l=740,c=8192,r=740]={<<<{"id":"_default",...idgets":[]}]}]}>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}] 06:26:19.602 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@af70aa{WRITING}:IDLE-->WRITING 06:26:19.604 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@d43845{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,W,128/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,58/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=END,0 of -1},g=HttpGenerator{s=COMPLETING},c=HttpChannelOverHttp@170a7cc{r=25,c=true,a=DISPATCHED,uri=/rest/sitemaps/_default/_default}] flush enter [java.nio.HeapByteBuffer[pos=0 lim=105 cap=8192], java.nio.HeapByteBuffer[pos=0 lim=740 cap=8192]] 06:26:19.607 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@d43845{NOT_HANDSHAKING,eio=-1/874,di=-1} -> HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,W,131/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,61/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=END,0 of -1},g=HttpGenerator{s=COMPLETING},c=HttpChannelOverHttp@170a7cc{r=25,c=true,a=DISPATCHED,uri=/rest/sitemaps/_default/_default}] wrap Status = OK HandshakeStatus = NOT_HANDSHAKING bytesConsumed = 845 bytesProduced = 874 06:26:19.610 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,W,134/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,65/30000,SslConnection}{io=0,kio=0,kro=1} OK HeapByteBuffer@1543b4c[p=0,l=874,c=17408,r=874]={<<<\x17\x03\x03\x03e\x00\x00\x00\x00\x00\x00\x00\x19\xC1\xE8\x8c-...g\xEbkEP\x05\xD7D\x1d\xD51\xA4\x92\x86Y>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 06:26:19.613 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 874 SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,68/30000,SslConnection}{io=0,kio=0,kro=1} 06:26:19.615 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@d43845{NOT_HANDSHAKING,eio=-1/0,di=-1} -> HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,W,140/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,0/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=END,0 of -1},g=HttpGenerator{s=COMPLETING},c=HttpChannelOverHttp@170a7cc{r=25,c=true,a=DISPATCHED,uri=/rest/sitemaps/_default/_default}] flush exit, consumed 845 06:26:19.617 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@af70aa{IDLE}:WRITING-->IDLE 06:26:19.619 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1785907[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,740,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@113ab9] generate: DONE ([p=105,l=105,c=8192,r=0],[p=740,l=740,c=8192,r=0],true)@END 06:26:19.621 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/_default @ o.e.j.s.h.ContextHandler@2b17f5{/static,null,AVAILABLE} 06:26:19.622 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/_default @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.9.0.201611041332 [100], contextID=default]} 06:26:19.623 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/_default @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui_0.9.0.201611041332 [137], contextID=default]} 06:26:19.624 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/_default @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.9.0.201611041332 [138], contextID=default]} 06:26:19.625 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/_default @ HttpServiceContext{httpContext=org.jupnp.transport.impl.osgi.DisableAuthenticationHttpContext@715e88} 06:26:19.626 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/_default @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.basic_0.9.0.201611041332 [186], contextID=default]} 06:26:19.627 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/_default @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.classic_0.9.0.201611041332 [187], contextID=default]} 06:26:19.629 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/_default @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.paper_0.9.0.201611041332 [188], contextID=default]} 06:26:19.630 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/_default @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.io.rest.docs_2.0.0.201611062131 [189], contextID=default]} 06:26:19.631 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/_default @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.0.0.201611062131 [192], contextID=default]} 06:26:19.632 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/_default @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core_2.0.0.201611062131 [168], contextID=default]} 06:26:19.632 [DEBUG] [org.eclipse.jetty.server.Server ] - RESPONSE /rest/sitemaps/_default/_default 200 handled=true 06:26:19.633 [DEBUG] [clipse.jetty.server.HttpChannelState] - HttpChannelState@8beceb{s=DISPATCHED i=true a=null} unhandle DISPATCHED 06:26:19.635 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - reset HttpParser{s=END,0 of -1} 06:26:19.636 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - END --> START 06:26:19.637 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=} handle exit, result COMPLETE 06:26:19.638 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@d43845{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,163/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,23/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] fill enter 06:26:19.640 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,24/30000,SslConnection}{io=0,kio=0,kro=1} 06:26:19.641 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@d43845{NOT_HANDSHAKING,eio=0/-1,di=-1} -> HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,166/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,26/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] filled 0 encrypted bytes 06:26:19.643 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@d43845{NOT_HANDSHAKING,eio=0/-1,di=-1} -> HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,168/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,28/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] unwrap Status = BUFFER_UNDERFLOW HandshakeStatus = NOT_HANDSHAKING bytesConsumed = 0 bytesProduced = 0 06:26:19.645 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@d43845{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,170/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,30/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] fill exit 06:26:19.647 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@d43845{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,171/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,31/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] fill enter 06:26:19.648 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,33/30000,SslConnection}{io=0,kio=0,kro=1} 06:26:19.650 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@d43845{NOT_HANDSHAKING,eio=0/-1,di=-1} -> HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,174/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,34/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] filled 0 encrypted bytes 06:26:19.652 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@d43845{NOT_HANDSHAKING,eio=0/-1,di=-1} -> HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,176/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,36/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] unwrap Status = BUFFER_UNDERFLOW HandshakeStatus = NOT_HANDSHAKING bytesConsumed = 0 bytesProduced = 0 06:26:19.654 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@d43845{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,178/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,38/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] fill exit 06:26:19.654 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - parseNext s=START HeapByteBuffer@ad25df[p=0,l=0,c=17408,r=0]={<<<>>>GET /rest/sitemap...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 06:26:19.656 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - fillInterested HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,181/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,41/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] 06:26:19.658 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILLING-->FILLING_FILL_INTERESTED HttpConnection@5d1aa0[FILLING_FILL_INTERESTED,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,183/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,43/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] 06:26:19.660 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILLING_FILL_INTERESTED-->FILL_INTERESTED HttpConnection@5d1aa0[FILL_INTERESTED,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,184/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,44/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] 06:26:19.661 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - fillInterested SslConnection@d43845{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@5d1aa0[FILL_INTERESTED,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,R,-,1/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,46/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] 06:26:19.663 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - IDLE-->FILL_INTERESTED SslConnection@d43845{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@5d1aa0[FILL_INTERESTED,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,R,-,3/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,48/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] 06:26:19.664 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Local interests updating 0 -> 1 for SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,R,-,0/30000,SslConnection}{io=1,kio=0,kro=1} 06:26:19.665 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Queued change org.eclipse.jetty.io.SelectChannelEndPoint$1@2ea554 06:26:19.666 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop woken up from select, 0/1 selected 06:26:19.667 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@2ea554 06:26:19.667 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Key interests updated 0 -> 1 on SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,R,-,3/30000,SslConnection}{io=1,kio=1,kro=1} 06:26:19.667 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop waiting on select 06:26:19.714 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop woken up from select, 1/1 selected 06:26:19.714 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Key interests updated 1 -> 0 on SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,R,-,50/30000,SslConnection}{io=1,kio=0,kro=1} 06:26:19.715 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Local interests updating 1 -> 0 for SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,R,-,51/30000,SslConnection}{io=0,kio=0,kro=1} 06:26:19.715 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Queued change org.eclipse.jetty.io.SelectChannelEndPoint$1@2ea554 06:26:19.716 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILL_INTERESTED-->FILLING SslConnection@d43845{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@5d1aa0[FILL_INTERESTED,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,R,-,56/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,52/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] 06:26:19.717 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - onFillable enter DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,R,-,57/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,53/30000,SslConnection}{io=0,kio=0,kro=1} 06:26:19.718 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILL_INTERESTED-->FILLING HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,58/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,54/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] 06:26:19.719 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - onFillable exit DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,59/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,55/30000,SslConnection}{io=0,kio=0,kro=1} 06:26:19.720 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,59/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,55/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] onFillable HttpChannelState@8beceb{s=IDLE i=true a=null} 06:26:19.721 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILLING-->IDLE SslConnection@d43845{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,60/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,56/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] 06:26:19.721 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@d43845{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,60/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,56/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] fill enter 06:26:19.721 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@2ea554 06:26:19.722 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop waiting on select 06:26:19.722 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 515 SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,57/30000,SslConnection}{io=0,kio=0,kro=1} 06:26:19.726 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@d43845{NOT_HANDSHAKING,eio=515/-1,di=-1} -> HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,62/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,2/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] filled 515 encrypted bytes 06:26:19.730 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@d43845{NOT_HANDSHAKING,eio=0/-1,di=-1} -> HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,70/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,8/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] unwrap Status = OK HandshakeStatus = NOT_HANDSHAKING bytesConsumed = 515 bytesProduced = 486 06:26:19.733 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@d43845{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@5d1aa0[FILLING,DecryptedEndPoint@12d4ea{/192.168.1.24:54399<->8443,Open,in,out,-,-,73/30000,HttpConnection}->SelectChannelEndPoint@bd1cb6{/192.168.1.24:54399<->8443,Open,in,out,-,-,11/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@170a7cc{r=25,c=false,a=IDLE,uri=}] fill exit 06:26:19.735 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - parseNext s=START HeapByteBuffer@19b0494[p=0,l=486,c=17408,r=486]={<<<GET /rest/sitemap...rwin/16.1.0\r\n\r\n>>>\xBd\xE2\xFb\xC2E\x82\xF6\xD7\xEf\x82(\xE4\xBd`i\xDf\xBd...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 06:26:19.737 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - START --> SPACE1 06:26:19.738 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - SPACE1 --> URI 06:26:19.740 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - URI --> SPACE2 06:26:19.740 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - SPACE2 --> REQUEST_VERSION 06:26:19.741 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - REQUEST_VERSION --> HEADER 06:26:19.742 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 06:26:19.743 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 06:26:19.744 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_NAME 06:26:19.745 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_NAME --> HEADER_VALUE 06:26:19.746 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_VALUE --> HEADER_IN_VALUE 06:26:19.746 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 06:26:19.747 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 06:26:19.748 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 06:26:19.748 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 06:26:19.749 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 06:26:19.750 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 06:26:19.751 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 06:26:19.752 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 06:26:19.752 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 06:26:19.753 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_NAME 06:26:19.754 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_NAME --> HEADER_VALUE 06:26:19.755 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_VALUE --> HEADER_IN_VALUE 06:26:19.755 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 06:26:19.756 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_NAME 06:26:19.756 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_NAME --> HEADER_VALUE 06:26:19.757 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_VALUE --> HEADER_IN_VALUE 06:26:19.758 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 06:26:19.759 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 06:26:19.759 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 06:26:19.760 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 06:26:19.761 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 06:26:19.761 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> HEADER_IN_VALUE 06:26:19.762 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER_IN_VALUE --> HEADER 06:26:19.763 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> END 06:26:19.764 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@170a7cc{r=26,c=false,a=IDLE,uri=/rest/sitemaps/_default/_default} messageComplete 06:26:19.765 [DEBUG] [org.eclipse.jetty.server.HttpInput ] - HttpInputOverHTTP@1f4ee36 EOF 06:26:19.765 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@170a7cc{r=26,c=false,a=IDLE,uri=/rest/sitemaps/_default/_default} handle enter 06:26:19.766 [DEBUG] [clipse.jetty.server.HttpChannelState] - HttpChannelState@8beceb{s=IDLE i=true a=null} handling IDLE 06:26:19.767 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@170a7cc{r=26,c=false,a=DISPATCHED,uri=/rest/sitemaps/_default/_default} action REQUEST_DISPATCH 06:26:19.769 [DEBUG] [org.eclipse.jetty.server.Server ] - REQUEST GET /rest/sitemaps/_default/_default on HttpChannelOverHttp@170a7cc{r=26,c=false,a=DISPATCHED,uri=/rest/sitemaps/_default/_default} 06:26:19.769 [DEBUG] [ax.web.service.spi.model.ServerModel] - Matching [/rest/sitemaps/_default/_default]... 06:26:19.770 [DEBUG] [ax.web.service.spi.model.ServerModel] - Path [/rest/sitemaps/_default/_default] matched to {pattern=/rest/.*,model=ServletModel{id=org.ops4j.pax.web.service.spi.model.ServletModel-2,name=org.ops4j.pax.web.service.spi.model.ServletModel-2,urlPatterns=[/rest/*],alias=/rest,servlet=com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge@f40c7,initParams={},context=ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-1,name=,httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default],contextParams={},virtualHosts={},connectors={}}}} 06:26:19.771 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/_default @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]} 06:26:19.772 [DEBUG] [.jetty.server.handler.ContextHandler] - context=||/rest/sitemaps/_default/_default @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]} 06:26:19.773 [DEBUG] [org.eclipse.jetty.server.session ] - sessionManager=org.ops4j.pax.web.service.jetty.internal.LateInvalidatingHashSessionManager@18d27f3 06:26:19.774 [DEBUG] [org.eclipse.jetty.server.session ] - session=null 06:26:19.775 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - servlet |/rest|/sitemaps/_default/_default -> org.ops4j.pax.web.service.spi.model.ServletModel-2@378be0fa==com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge,-1,true 06:26:19.775 [DEBUG] [ce.jetty.internal.HttpServiceContext] - Handling request for [/rest/sitemaps/_default/_default] using http context [DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]] 06:26:19.776 [DEBUG] [y.internal.HttpServiceServletHandler] - handling request org.ops4j.pax.web.service.jetty.internal.HttpServiceRequestWrapper@edd379, org.ops4j.pax.web.service.jetty.internal.HttpServiceResponseWrapper@662e02 06:26:19.777 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - chain=nullrepeated every few seconds... anything can be understood from that?
