openHAB 2.0 binding


  • Hero Member

    Thanks @Fleischtorte!

    There already was a request for IR and I've added one for V_TEXT.

    https://github.com/tobof/openhab2-addons/issues

    @andreacioni has done some serious refactoring of the code. After looking in the refactoring I'll add the missing sensors.



  • I have the following setup:

    1. MQTT Gateway on Wemos D1 mini (ESP8266)
    2. Node on Arduin pro mini

    i can't get the openhab binding to distribute address to the nodes, in things in openhab there is no option for MQTT Gateway to add, what is the procedure ?

    Cheers



  • @Meshx86 the openhab binding doesnt support MQTT as far as I know.

    If you are using the MQTT binding then you need another controller/method to provide the internal functions for my sensors. I use NodeRed workflow to listen for ID requests and it provides them.

    Or static assign them in the node stretch.



  • @TimO: Thanks to you this weekend, while kids slept or napped, I managed to setup RPi gateway/controller with NRF24 and OH2.
    Following the OH2 install instructions caused me some trouble, not sure why, but following your install instructions it came right up.
    Thank you for the time and effort here.



  • Having a couple issues:

    1. while adding 2nd node (tried power and temp/hum) OH2 would not assign node ID.
    2. assigned node ID manually (ID=2) and OH2 recognized power node but will not respond to V_VAR1 request.
    16:23:58.850 [DEBUG] [rs.internal.protocol.MySensorsReader] - 1;1;1;0;0;20.4
    16:23:58.874 [DEBUG] [rs.internal.protocol.MySensorsReader] - 1;0;1;0;1;47.3
    16:24:01.910 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    16:24:09.293 [DEBUG] [rs.internal.protocol.MySensorsReader] - 1;0;1;0;1;47.5
    16:24:11.911 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    16:24:11.942 [DEBUG] [rs.internal.protocol.MySensorsReader] - 2;0;2;0;24;
    16:24:19.736 [DEBUG] [rs.internal.protocol.MySensorsReader] - 1;0;1;0;1;47.7
    16:24:21.912 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    16:24:26.987 [DEBUG] [rs.internal.protocol.MySensorsReader] - 2;0;2;0;24;
    16:24:30.177 [DEBUG] [rs.internal.protocol.MySensorsReader] - 1;0;1;0;1;47.6
    16:24:31.913 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    16:24:40.604 [DEBUG] [rs.internal.protocol.MySensorsReader] - 1;0;1;0;1;47.5
    16:24:41.914 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    16:24:42.044 [DEBUG] [rs.internal.protocol.MySensorsReader] - 2;0;2;0;24;
    16:24:51.916 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    16:24:57.102 [DEBUG] [rs.internal.protocol.MySensorsReader] - 2;0;2;0;24;
    16:25:01.917 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    16:25:11.919 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    16:25:12.145 [DEBUG] [rs.internal.protocol.MySensorsReader] - 2;0;2;0;24;
    16:25:21.921 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    16:25:22.304 [DEBUG] [rs.internal.protocol.MySensorsReader] - 1;0;1;0;1;47.6
    

    Things:

    Bridge mysensors:bridge-ser:gateway [ serialPort="/dev/pts/2", sendDelay=200 ] {
       /** define things connected to that bridge here */
       humidity        hum01   [ nodeId="1", childId="0" ]
       temperature     temp01  [ nodeId="1", childId="1" ]
       power           power01 [ nodeId="2", childId="0" ]
    }
    

    Items:

    Number hum01   "Humidity"              <humidity> { channel="mysensors:humidity:gateway:hum01:hum" }
    Number temp01  "Temperature"           <temperature> { channel="mysensors:temperature:gateway:temp01:temp" }
    Number temp01F "Temperature [%.1f °F]" <temperature>
    DateTime Sensor01LastUpdate "Last seen [%1$ta %1$tR]" <clock>
    DateTime Sensor02LastUpdate "Last seen [%1$ta %1$tR]" <clock>
    Number watt01  "Current Demand [%.0f Watt]" { channel="mysensors:power:gateway:power01:watt" }
    Number kwh01  "Daily Use [%.1f kWh]"        { channel="mysensors:power:gateway:power01:kwh" }
    
    

    What am i doing wrong?



  • OK, I think I got past that, I reinstalled everything and cleaned up my MySensors libraries.There is a chance I was pulling from different version when compiling the different examples from different packages.

    But, I noticed this exception at OH2 startup:

    06:29:26.838 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-ser:gateway' changed from UNINITIALIZED to INITIALIZING
    06:29:26.924 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 1, chiledId: 1, revertState: false
    06:29:26.924 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 1, chiledId: 0, revertState: false
    06:29:26.932 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 2, chiledId: 0, revertState: false
    06:29:26.951 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:humidity:gateway:hum01' changed from UNINITIALIZED to INITIALIZING
    06:29:26.946 [DEBUG] [col.serial.MySensorsSerialConnection] - Set skip check on startup to: false
    06:29:26.956 [DEBUG] [col.serial.MySensorsSerialConnection] - Enabling connection watchdog
    06:29:26.964 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:temperature:gateway:temp01' changed from UNINITIALIZED to INITIALIZING
    06:29:26.969 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:power:gateway:power01' changed from UNINITIALIZED to INITIALIZING
    06:29:26.993 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache file: given_ids.cached exist.
    06:29:27.001 [DEBUG] [col.serial.MySensorsSerialConnection] - Connecting to /dev/pts/3 [baudRate:115200]
    06:29:27.032 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache (given_ids) content: []
    06:29:27.067 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-ser:gateway' changed from INITIALIZING to UNINITIALIZED (HANDLER_INITIALIZING_ERROR)
    06:29:27.041 [ERROR] [ome.core.thing.internal.ThingManager] - Exception occured while initializing handler of thing 'mysensors:bridge-ser:gateway': java.lang.UnsupportedOperationException
    java.util.concurrent.ExecutionException: java.lang.UnsupportedOperationException
    	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)[99:org.eclipse.smarthome.core:0.9.0.201610220816]
    	at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:79)[99:org.eclipse.smarthome.core:0.9.0.201610220816]
    	at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:63)[99:org.eclipse.smarthome.core:0.9.0.201610220816]
    	at org.eclipse.smarthome.core.thing.internal.ThingManager$9.run(ThingManager.java:755)[106:org.eclipse.smarthome.core.thing:0.9.0.201610220816]
    	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_65]
    	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_65]
    	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)[:1.8.0_65]
    	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)[:1.8.0_65]
    	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_65]
    	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_65]
    	at java.lang.Thread.run(Thread.java:745)[:1.8.0_65]
    Caused by: java.lang.UnsupportedOperationException
    	at java.util.AbstractList.add(AbstractList.java:148)[:1.8.0_65]
    	at java.util.AbstractList.add(AbstractList.java:108)[:1.8.0_65]
    	at org.openhab.binding.mysensors.internal.handler.MySensorsBridgeHandler.loadCacheFile(MySensorsBridgeHandler.java:176)[10:org.openhab.binding.mysensors:2.0.0.201610021604]
    	at org.openhab.binding.mysensors.internal.handler.MySensorsBridgeHandler.initialize(MySensorsBridgeHandler.java:90)[10:org.openhab.binding.mysensors:2.0.0.201610021604]
    	at org.eclipse.smarthome.core.thing.internal.ThingManager$9$1.call(ThingManager.java:758)[106:org.eclipse.smarthome.core.thing:0.9.0.201610220816]
    	at org.eclipse.smarthome.core.thing.internal.ThingManager$9$1.call(ThingManager.java:1)[106:org.eclipse.smarthome.core.thing:0.9.0.201610220816]
    	at org.eclipse.smarthome.core.common.SafeMethodCaller$CallableWrapper.call(SafeMethodCaller.java:177)[99:org.eclipse.smarthome.core:0.9.0.201610220816]
    	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_65]
    	... 3 more
    06:29:27.198 [DEBUG] [col.serial.MySensorsSerialConnection] - Final port list: /dev/pts/3
    06:29:27.232 [DEBUG] [col.serial.MySensorsSerialConnection] - Successfully connected to serial port.
    06:29:27.234 [DEBUG] [col.serial.MySensorsSerialConnection] - Waiting 3 seconds to allow correct reset trigger on serial connection opening
    06:29:29.428 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
    06:29:29.897 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app
    06:29:30.262 [DEBUG] [rs.internal.protocol.MySensorsReader] - ;255;3;0;14;Gateway startup complete.
    06:29:30.274 [ERROR] [rs.internal.protocol.MySensorsReader] - (java.lang.NumberFormatException: For input string: "") on reading from serial port, message: class org.openhab.binding.mysensors.internal.protocol.serial.MySensorsSerialReader
    06:29:30.283 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;0;0;18;2.0.1-beta
    

    Things still seem to work, but do I have something wrong?



  • Hi @carlyler 🙂

    what version of JVM are you using? 1.7 or 1.8?



  • @andreacioni after reading this thread I realized you have done a lot of work here as well, thank you.

    I am running:
    pi@raspberrypi:~ $ java -version
    java version "1.8.0_65"
    Java(TM) SE Runtime Environment (build 1.8.0_65-b17)
    Java HotSpot(TM) Client VM (build 25.65-b01, mixed mode)
    pi@raspberrypi:~ $



  • Hello community,

    i have a small problem with openhab2 (on a orange pi with armbian - similar to raspberry) and mysensors Serial Gateway.
    I installed openhab2 with the get methode and it works fine. I was able, to start it with openhab2.service (also automated) and openhab2 worked as it should. But if i want to connect the mysensors serial gateway to the orange pi with openhab2, openhab2 can't find my gateway. The log says "openhab is unable to connect to serial port, wrong serial port?"
    But my serial port is ok.
    If i stop openhab2.service and manual start openhab2, than all is fine, it can connect to serial gateway immediately and work fine. I don't know, why it can't work if openhab2 starts as service. Can you help me in this case?

    Thank you.

    And sorry for my english, it's not my first language


  • Hero Member

    @hausinger Sounds like a problem with the permissions. The openhab2 service is running as user and group openhab and this user needs permission to the serial port (dialout).

    sudo usermod -a -G dialout openhab
    

  • Hardware Contributor

    Hi all
    I have a problem when my raspberry pi and mysensors/openhab when i do a restart. The problems seems to be ralated to the serial gateway and that the openhab dont find it or has the wrong settings.

    Openhab starts when i make a reboot

    I checked the serial by typing
    stty -F /dev/ttyUSB0
    response was
    0_1478456625054_image.png
    Seems here that the baudrate is wrong as my settings in the things file is
    0_1478456718472_image.png

    What i did to make it work was just to change this to use baud 9600 and then back to baud = 115200
    after this it looked like
    0_1478456804927_image.png

    And everything started to work nicely

    Does anyone now what the cause of this is and also how to fix it?



  • @ TimO thank you. That was the problem 🙂



  • I have 2 simpel questions.

    1. What is the status of the PR for mysensors to get inside openhab native?
    2. What type of sensor do i need to use for a relay?

  • Hero Member

    @FutureCow

    1. Sadly there is no progress at all: https://github.com/openhab/openhab2-addons/pull/1243 Till now nobody found the time to look into the PR.

    2. Use "Light" for a Relay. If you discover the device via PaperUI it will be represented as a "Light" (Switch).


  • Admin

    @TimO I took a quick look at your pull request (personal curiosity) and noticed that one of your committed files includes a merge conflict - you probably want to fix that before the OpenHab team accepts your PR.


  • Hero Member

    @blacey said:

    I took a quick look at your pull request (personal curiosity) and noticed that one of your committed files includes a merge conflict

    Hey @blacey, thank you for peeking in. 😄
    I haven't touched the PR for a long time, but it will be necessary soon because there were a lot changes in the development branch. I will fix that too!


  • Admin

    @TimO Nice! While I have been a longtime Vera user, I think my next move will be OpenHab. I sponsored the Pine64 project on KickStarter and have one sitting on my project desk ready for some prototyping. I think it is great that you are making MySensors a first-class OpenHab 2.0 citizen. Hopefully Kai or one of the OpenHab contributors will merge your binding into the distro.



  • @TimO It seems the binding does not support autoupdate="false" yet. Can you confirm this and do you consider adding this option? I could use the MQTT binding to get what I want (for example feedback of rollershutter position while moving based on the value sent by the sensor and not based on the command sent via the UI), but I don't want to move away from the MySensors binding.



  • 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 lot

    BUT! 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- With pi@raspberrypi:~/MySensors $ sudo ./examples_linux/mysGateway -d i can see that my motion sensor and my RPi gateway get on well

    mysGateway: 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:0
    

    6- created a thing (text editor) for the bridge pi@raspberrypi:/usr/share/openhab2/conf/things $ nano home.things

    Bridge mysensors:bridge-ser:gateway [ serialPort="/dev/pts/2", sendDelay=200 ] {  }
    

    7- Following openhab2 "live" log with pi@raspberrypi:/usr/share/openhab2 $ sudo ./start_debug.sh

    05: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.jpeg

    sudo usermod -a -G dialout openhab returns "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)
    

  • Hero Member

    @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 !! 😉

    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.10
    

    And 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 launch pi@raspberrypi:~/MySensors $ sudo ./examples_linux/mysGateway -d i can see that arduino and raspberry interract together...

    Thanks a lot for your time


  • Hero Member

    @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'
    

    😱
    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'
    

  • Hero Member

    @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.9
    
    

    As you can see, i recieve messages from the gateway. No items are updated.



  • This post is deleted!

  • Hero Member

    @FutureCow Strange, I'll look into it. I suppose I've introduced this bug with the latest refactoring. 😕



  • @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 run dmesg |grep -i tty as 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 rev2
    

    I 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 115200 returns that

    [screen is terminating]
    

    Also, when watching the live output from sudo ./bin/mysgw -d i can see that

    pi@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:5003
    

    but when i launch openhab with sudo ./start_debug.sh i see

    Launching the openHAB runtime...
    Listening for transport dt_socket at address: 5005
    

    5003 vs 5005... I tried that pi@raspberrypi:~/MySensors $ ./configure --my-port=5005 but no luck, I got that in return...

    mysgw: accept: Bad file descriptor
    mysgw: accept: Bad file descriptor
    

    going forever 😞



  • @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?


  • Hero Member

    @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:

    1. Copy the binding jar to /tmp.
    2. 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.jar
    

    OH2 is started/stopped/restarted with

    service openhab2 start/stop/restart
    

    To log into the karaf console do:

    ssh openhab@localhost -p 8101
    

    Password is: habopen

    Follow the guide/wiki from:

    In the console enter feature:install openhab-transport-serial
    

  • Hero Member

    @ben999

    If you are using the RPi gateway with the options you provided above:

    sudo ./bin/mysgw -d
    

    You 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 problems

    OpenHAB #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.


  • Hero Member

    @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;1208410
    
    

    Also, 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:]
    


  • @TimO
    Thank you one more time Tim

    So 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/ttyAMA0
    

    pi@raspberrypi:/ $ telnet 127.0.0.1 5003 returns 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.5
    

    But 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=null
    

    repeated every few seconds... anything can be understood from that?


  • Hero Member

    Ok, here is the corrected jar file: LINK

    The things now should update.

    I've tested it with the current snapshot on two systems / mysensors environments. I've not tested it against the curren testing (beta4). It should work, but it may throw exceptions on startup.

    At the moment please only update if you expierence problems. I would like to ensure the binding is now working.





  • @TimO
    Thank you for that new jar file.
    Gateway is "online" in PaperUI
    Sensors are "Uninitialised"
    PaperUI says Status: UNINITIALIZED - HANDLER_INITIALIZING_ERROR org.eclipse.smarthome.core.thing.Bridge.getHandler()Lorg/eclipse/smarthome/core/thing/binding/BridgeHandler;
    I have added these sensors manually to thing file:

    Bridge mysensors:bridge-eth:gateway [ ipAddress="127.0.0.1", tcpPort=5003, sendDelay=200, skipStartupCheck=true ] {
            humidity        bathHum01               [ nodeId="1", childId="0" ]
            temperature     bathTemp01              [ nodeId="1", childId="1" ]    }
    

    Here is log file from OH2

    22:06:55.465 [DEBUG] [io.socket.engineio.client.Socket    ] - writing ping packet - expecting pong within 60000ms
    22:06:55.466 [DEBUG] [io.socket.engineio.client.Socket    ] - flushing 1 packets in socket
    22:06:55.509 [DEBUG] [io.socket.engineio.client.Socket    ] - socket received: type 'pong', data 'null'
    22:07:04.487 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    22:07:07.682 [DEBUG] [org.eclipse.jetty.io.IdleTimeout    ] - SelectChannelEndPoint@310200{/192.168.1.9:60520<->8080,Open,in,out,-,-,30000/30000,HttpConnection}{io=0,kio=0,kro=1} idle timeout check, elapsed: 30000 ms, remaining: 0 ms
    22:07:07.683 [DEBUG] [org.eclipse.jetty.io.IdleTimeout    ] - SelectChannelEndPoint@310200{/192.168.1.9:60520<->8080,Open,in,out,-,-,30002/30000,HttpConnection}{io=0,kio=0,kro=1} idle timeout expired
    22:07:07.684 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - ignored: WriteFlusher@82249d{IDLE} java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms
    22:07:07.685 [DEBUG] [rg.eclipse.jetty.io.AbstractEndPoint] - Ignored idle endpoint SelectChannelEndPoint@310200{/192.168.1.9:60520<->8080,Open,in,out,-,-,30003/30000,HttpConnection}{io=0,kio=0,kro=1}
    22:07:09.977 [DEBUG] [org.eclipse.jetty.io.IdleTimeout    ] - SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,29439/30000,SslConnection}{io=0,kio=0,kro=1} idle timeout check, elapsed: 29439 ms, remaining: 561 ms
    22:07:10.540 [DEBUG] [org.eclipse.jetty.io.IdleTimeout    ] - SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,30001/30000,SslConnection}{io=0,kio=0,kro=1} idle timeout check, elapsed: 30001 ms, remaining: -1 ms
    22:07:10.541 [DEBUG] [org.eclipse.jetty.io.IdleTimeout    ] - SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,30002/30000,SslConnection}{io=0,kio=0,kro=1} idle timeout expired
    22:07:10.541 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - ignored: WriteFlusher@f4107c{IDLE} java.util.concurrent.TimeoutException: Idle timeout expired: 30001/30000 ms
    22:07:10.542 [DEBUG] [rg.eclipse.jetty.io.AbstractEndPoint] - Ignored idle endpoint SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,30004/30000,SslConnection}{io=0,kio=0,kro=1}
    22:07:10.884 [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:07:10.886 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@ad3ff7[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,1051,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@b60904] generate: NEED_HEADER (null,[p=0,l=1051,c=8192,r=1051],true)@START
    22:07:10.887 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@ad3ff7[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,1051,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@b60904] generate: FLUSH ([p=0,l=106,c=8192,r=106],[p=0,l=1051,c=8192,r=1051],true)@COMPLETING
    22:07:10.889 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@18a5ae6{IDLE} [HeapByteBuffer@107873[p=0,l=106,c=8192,r=106]={<<<HTTP/1.1 200 OK\r\n....v20151106)\r\n\r\n>>> chunked\r\nServer:...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},HeapByteBuffer@6612b4[p=0,l=1051,c=8192,r=1051]={<<<{"id":"0000","tit..."widgets":[]}]}>>>\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}]
    22:07:10.892 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@18a5ae6{WRITING}:IDLE-->WRITING
    22:07:10.895 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,W,30371/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,353/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=END,0 of -1},g=HttpGenerator{s=COMPLETING},c=HttpChannelOverHttp@d19aaf{r=38,c=true,a=DISPATCHED,uri=/rest/sitemaps/_default/0000}] flush enter [java.nio.HeapByteBuffer[pos=0 lim=106 cap=8192], java.nio.HeapByteBuffer[pos=0 lim=1051 cap=8192]]
    22:07:10.901 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/1186,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,W,30377/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,358/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=END,0 of -1},g=HttpGenerator{s=COMPLETING},c=HttpChannelOverHttp@d19aaf{r=38,c=true,a=DISPATCHED,uri=/rest/sitemaps/_default/0000}] wrap Status = OK HandshakeStatus = NOT_HANDSHAKING
    bytesConsumed = 1157 bytesProduced = 1186
    22:07:10.903 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,W,30379/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,361/30000,SslConnection}{io=0,kio=0,kro=1} OK HeapByteBuffer@eb6978[p=0,l=1186,c=17408,r=1186]={<<<\x17\x03\x03\x04\x9d\x00\x00\x00\x00\x00\x00\x00&\xFe3\xE3|...\xFe$\xE1\xF9J\xE06\xE9\xE96_=\x9a\xAa\x0c>>>\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}
    22:07:10.906 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 1186 SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,363/30000,SslConnection}{io=0,kio=0,kro=1}
    22:07:10.908 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/0,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,W,30384/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,1/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=END,0 of -1},g=HttpGenerator{s=COMPLETING},c=HttpChannelOverHttp@d19aaf{r=38,c=true,a=DISPATCHED,uri=/rest/sitemaps/_default/0000}] flush exit, consumed 1157
    22:07:10.910 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@18a5ae6{IDLE}:WRITING-->IDLE
    22:07:10.912 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@ad3ff7[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,1051,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@b60904] generate: DONE ([p=106,l=106,c=8192,r=0],[p=1051,l=1051,c=8192,r=0],true)@END
    22:07:10.915 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ o.e.j.s.h.ContextHandler@1f3fece{/static,null,AVAILABLE}
    22:07:10.916 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.9.0.201611041332 [100], contextID=default]}
    22:07:10.917 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui_0.9.0.201611041332 [137], contextID=default]}
    22:07:10.918 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.9.0.201611041332 [138], contextID=default]}
    22:07:10.919 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=org.jupnp.transport.impl.osgi.DisableAuthenticationHttpContext@14870c1}
    22:07:10.919 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.basic_0.9.0.201611041332 [186], contextID=default]}
    22:07:10.920 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.classic_0.9.0.201611041332 [187], contextID=default]}
    22:07:10.921 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.paper_0.9.0.201611041332 [188], contextID=default]}
    22:07:10.921 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.io.rest.docs_2.0.0.201611062131 [189], contextID=default]}
    22:07:10.922 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.0.0.201611062131 [192], contextID=default]}
    22:07:10.923 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core_2.0.0.201611062131 [168], contextID=default]}
    22:07:10.924 [DEBUG] [org.eclipse.jetty.server.Server     ] - RESPONSE /rest/sitemaps/_default/0000  200 handled=true
    22:07:10.925 [DEBUG] [clipse.jetty.server.HttpChannelState] - HttpChannelState@6e53d6{s=DISPATCHED i=true a=null} unhandle DISPATCHED
    22:07:10.926 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - reset HttpParser{s=END,0 of -1}
    22:07:10.926 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - END --> START
    22:07:10.927 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=} handle exit, result COMPLETE
    22:07:10.929 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,30405/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,22/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}] fill enter
    22:07:10.931 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,23/30000,SslConnection}{io=0,kio=0,kro=1}
    22:07:10.933 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=0/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,30409/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,25/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}] filled 0 encrypted bytes
    22:07:10.935 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=0/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,30411/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,27/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}] unwrap Status = BUFFER_UNDERFLOW HandshakeStatus = NOT_HANDSHAKING
    bytesConsumed = 0 bytesProduced = 0
    22:07:10.937 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,30413/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,29/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}] fill exit
    22:07:10.939 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,30415/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,32/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}] fill enter
    22:07:10.941 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,33/30000,SslConnection}{io=0,kio=0,kro=1}
    22:07:10.942 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=0/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,30419/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,35/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}] filled 0 encrypted bytes
    22:07:10.945 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=0/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,30421/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,37/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}] unwrap Status = BUFFER_UNDERFLOW HandshakeStatus = NOT_HANDSHAKING
    bytesConsumed = 0 bytesProduced = 0
    22:07:10.947 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,30423/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,39/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}] fill exit
    22:07:10.948 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - parseNext s=START HeapByteBuffer@1ac887b[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}
    22:07:10.949 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - fillInterested HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,30426/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,42/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}]
    22:07:10.951 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILLING-->FILLING_FILL_INTERESTED HttpConnection@12c6b19[FILLING_FILL_INTERESTED,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,30427/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->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@d19aaf{r=38,c=false,a=IDLE,uri=}]
    22:07:10.953 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILLING_FILL_INTERESTED-->FILL_INTERESTED HttpConnection@12c6b19[FILL_INTERESTED,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,30429/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->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@d19aaf{r=38,c=false,a=IDLE,uri=}]
    22:07:10.955 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - fillInterested SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILL_INTERESTED,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,R,-,0/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->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@d19aaf{r=38,c=false,a=IDLE,uri=}]
    22:07:10.958 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - IDLE-->FILL_INTERESTED SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILL_INTERESTED,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,R,-,3/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,50/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}]
    22:07:10.959 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Local interests updating 0 -> 1 for SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,R,-,0/30000,SslConnection}{io=1,kio=0,kro=1}
    22:07:10.960 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Queued change org.eclipse.jetty.io.SelectChannelEndPoint$1@1d2164a
    22:07:10.961 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop woken up from select, 0/1 selected
    22:07:10.961 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@1d2164a
    22:07:10.962 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Key interests updated 0 -> 1 on SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,R,-,3/30000,SslConnection}{io=1,kio=1,kro=1}
    22:07:10.962 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop waiting on select
    22:07:11.035 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop woken up from select, 1/1 selected
    22:07:11.036 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Key interests updated 1 -> 0 on SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,R,-,78/30000,SslConnection}{io=1,kio=0,kro=1}
    22:07:11.036 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Local interests updating 1 -> 0 for SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,R,-,78/30000,SslConnection}{io=0,kio=0,kro=1}
    22:07:11.037 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Queued change org.eclipse.jetty.io.SelectChannelEndPoint$1@1d2164a
    22:07:11.038 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILL_INTERESTED-->FILLING SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILL_INTERESTED,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,R,-,83/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,79/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}]
    22:07:11.038 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - onFillable enter DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,R,-,84/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,80/30000,SslConnection}{io=0,kio=0,kro=1}
    22:07:11.039 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILL_INTERESTED-->FILLING HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,85/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,81/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}]
    22:07:11.040 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - onFillable exit DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,86/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,82/30000,SslConnection}{io=0,kio=0,kro=1}
    22:07:11.041 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,86/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,82/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}] onFillable HttpChannelState@6e53d6{s=IDLE i=true a=null}
    22:07:11.041 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILLING-->IDLE SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,87/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,83/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}]
    22:07:11.042 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,87/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,83/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}] fill enter
    22:07:11.042 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@1d2164a
    22:07:11.042 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop waiting on select
    22:07:11.042 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 473 SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,84/30000,SslConnection}{io=0,kio=0,kro=1}
    22:07:11.043 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=473/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,89/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,1/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}] filled 473 encrypted bytes
    22:07:11.045 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=0/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,91/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,3/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}] unwrap Status = OK HandshakeStatus = NOT_HANDSHAKING
    bytesConsumed = 473 bytesProduced = 444
    22:07:11.046 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,92/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,4/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=38,c=false,a=IDLE,uri=}] fill exit
    22:07:11.047 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - parseNext s=START HeapByteBuffer@c998ba[p=0,l=444,c=17408,r=444]={<<<GET /rest/sitemap...rwin/16.1.0\r\n\r\n>>>.0 CFNetwork/808....\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}
    22:07:11.047 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - START --> SPACE1
    22:07:11.047 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - SPACE1 --> URI
    22:07:11.048 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - URI --> SPACE2
    22:07:11.048 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - SPACE2 --> REQUEST_VERSION
    22:07:11.048 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - REQUEST_VERSION --> HEADER
    22:07:11.048 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_VALUE
    22:07:11.049 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.049 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_NAME
    22:07:11.049 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_NAME --> HEADER_VALUE
    22:07:11.049 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_VALUE --> HEADER_IN_VALUE
    22:07:11.050 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.050 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_VALUE
    22:07:11.050 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.050 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_VALUE
    22:07:11.050 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.050 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_VALUE
    22:07:11.051 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.051 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_VALUE
    22:07:11.051 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.051 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_VALUE
    22:07:11.051 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.052 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_NAME
    22:07:11.052 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_NAME --> HEADER_VALUE
    22:07:11.052 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_VALUE --> HEADER_IN_VALUE
    22:07:11.052 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.052 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_VALUE
    22:07:11.053 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.053 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_VALUE
    22:07:11.053 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.053 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> END
    22:07:11.054 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=/rest/sitemaps/_default/0000} messageComplete
    22:07:11.054 [DEBUG] [org.eclipse.jetty.server.HttpInput  ] - HttpInputOverHTTP@15ca2 EOF
    22:07:11.055 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=/rest/sitemaps/_default/0000} handle enter
    22:07:11.055 [DEBUG] [clipse.jetty.server.HttpChannelState] - HttpChannelState@6e53d6{s=IDLE i=true a=null} handling IDLE
    22:07:11.056 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@d19aaf{r=39,c=false,a=DISPATCHED,uri=/rest/sitemaps/_default/0000} action REQUEST_DISPATCH
    22:07:11.056 [DEBUG] [org.eclipse.jetty.server.Server     ] - REQUEST GET /rest/sitemaps/_default/0000 on HttpChannelOverHttp@d19aaf{r=39,c=false,a=DISPATCHED,uri=/rest/sitemaps/_default/0000}
    22:07:11.057 [DEBUG] [ax.web.service.spi.model.ServerModel] - Matching [/rest/sitemaps/_default/0000]...
    22:07:11.057 [DEBUG] [ax.web.service.spi.model.ServerModel] - Path [/rest/sitemaps/_default/0000] 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@1efe36d,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:07:11.057 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]}
    22:07:11.058 [DEBUG] [.jetty.server.handler.ContextHandler] - context=||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]}
    22:07:11.058 [DEBUG] [org.eclipse.jetty.server.session    ] - sessionManager=org.ops4j.pax.web.service.jetty.internal.LateInvalidatingHashSessionManager@1a5ce14
    22:07:11.059 [DEBUG] [org.eclipse.jetty.server.session    ] - session=null
    22:07:11.059 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - servlet |/rest|/sitemaps/_default/0000 -> org.ops4j.pax.web.service.spi.model.ServletModel-2@378be0fa==com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge,-1,true
    22:07:11.059 [DEBUG] [ce.jetty.internal.HttpServiceContext] - Handling request for [/rest/sitemaps/_default/0000] using http context [DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]]
    22:07:11.060 [DEBUG] [y.internal.HttpServiceServletHandler] - handling request org.ops4j.pax.web.service.jetty.internal.HttpServiceRequestWrapper@5ce2b2, org.ops4j.pax.web.service.jetty.internal.HttpServiceResponseWrapper@97896c
    22:07:11.060 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - chain=null
    22:07:11.073 [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:07:11.075 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@ad3ff7[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,1051,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@1ccbd33] generate: NEED_HEADER (null,[p=0,l=1051,c=8192,r=1051],true)@START
    22:07:11.075 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@ad3ff7[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,1051,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@1ccbd33] generate: FLUSH ([p=0,l=106,c=8192,r=106],[p=0,l=1051,c=8192,r=1051],true)@COMPLETING
    22:07:11.076 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@18a5ae6{IDLE} [HeapByteBuffer@107873[p=0,l=106,c=8192,r=106]={<<<HTTP/1.1 200 OK\r\n....v20151106)\r\n\r\n>>> chunked\r\nServer:...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},HeapByteBuffer@193feb4[p=0,l=1051,c=8192,r=1051]={<<<{"id":"0000","tit..."widgets":[]}]}>>>\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}]
    22:07:11.076 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@18a5ae6{WRITING}:IDLE-->WRITING
    22:07:11.077 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,W,123/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,35/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=END,0 of -1},g=HttpGenerator{s=COMPLETING},c=HttpChannelOverHttp@d19aaf{r=39,c=true,a=DISPATCHED,uri=/rest/sitemaps/_default/0000}] flush enter [java.nio.HeapByteBuffer[pos=0 lim=106 cap=8192], java.nio.HeapByteBuffer[pos=0 lim=1051 cap=8192]]
    22:07:11.102 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/1186,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,W,147/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,60/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=END,0 of -1},g=HttpGenerator{s=COMPLETING},c=HttpChannelOverHttp@d19aaf{r=39,c=true,a=DISPATCHED,uri=/rest/sitemaps/_default/0000}] wrap Status = OK HandshakeStatus = NOT_HANDSHAKING
    bytesConsumed = 1157 bytesProduced = 1186
    22:07:11.103 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,W,148/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,61/30000,SslConnection}{io=0,kio=0,kro=1} OK HeapByteBuffer@eb6978[p=0,l=1186,c=17408,r=1186]={<<<\x17\x03\x03\x04\x9d\x00\x00\x00\x00\x00\x00\x00']\x1a(\xA4...\x94_\xF6\x11\x13PZf&0^\x1a\xC5c\x85>>>\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}
    22:07:11.104 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 1186 SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,61/30000,SslConnection}{io=0,kio=0,kro=1}
    22:07:11.105 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/0,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,W,150/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->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@d19aaf{r=39,c=true,a=DISPATCHED,uri=/rest/sitemaps/_default/0000}] flush exit, consumed 1157
    22:07:11.105 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@18a5ae6{IDLE}:WRITING-->IDLE
    22:07:11.106 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@ad3ff7[PROCESSING][i=ResponseInfo{HTTP/1.1 200 OK,1051,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@1ccbd33] generate: DONE ([p=106,l=106,c=8192,r=0],[p=1051,l=1051,c=8192,r=0],true)@END
    22:07:11.107 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ o.e.j.s.h.ContextHandler@1f3fece{/static,null,AVAILABLE}
    22:07:11.107 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.core.audio_0.9.0.201611041332 [100], contextID=default]}
    22:07:11.108 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui_0.9.0.201611041332 [137], contextID=default]}
    22:07:11.108 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.9.0.201611041332 [138], contextID=default]}
    22:07:11.108 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=org.jupnp.transport.impl.osgi.DisableAuthenticationHttpContext@14870c1}
    22:07:11.109 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.basic_0.9.0.201611041332 [186], contextID=default]}
    22:07:11.109 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.classic_0.9.0.201611041332 [187], contextID=default]}
    22:07:11.110 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.paper_0.9.0.201611041332 [188], contextID=default]}
    22:07:11.110 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.io.rest.docs_2.0.0.201611062131 [189], contextID=default]}
    22:07:11.110 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.0.0.201611062131 [192], contextID=default]}
    22:07:11.111 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core_2.0.0.201611062131 [168], contextID=default]}
    22:07:11.111 [DEBUG] [org.eclipse.jetty.server.Server     ] - RESPONSE /rest/sitemaps/_default/0000  200 handled=true
    22:07:11.111 [DEBUG] [clipse.jetty.server.HttpChannelState] - HttpChannelState@6e53d6{s=DISPATCHED i=true a=null} unhandle DISPATCHED
    22:07:11.112 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - reset HttpParser{s=END,0 of -1}
    22:07:11.112 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - END --> START
    22:07:11.112 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=} handle exit, result COMPLETE
    22:07:11.114 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,159/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,9/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}] fill enter
    22:07:11.114 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,10/30000,SslConnection}{io=0,kio=0,kro=1}
    22:07:11.115 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=0/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,161/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->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@d19aaf{r=39,c=false,a=IDLE,uri=}] filled 0 encrypted bytes
    22:07:11.116 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=0/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,162/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,12/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}] unwrap Status = BUFFER_UNDERFLOW HandshakeStatus = NOT_HANDSHAKING
    bytesConsumed = 0 bytesProduced = 0
    22:07:11.118 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,163/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,13/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}] fill exit
    22:07:11.119 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,164/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,14/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}] fill enter
    22:07:11.119 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,15/30000,SslConnection}{io=0,kio=0,kro=1}
    22:07:11.120 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=0/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,166/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,16/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}] filled 0 encrypted bytes
    22:07:11.121 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=0/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,167/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,17/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}] unwrap Status = BUFFER_UNDERFLOW HandshakeStatus = NOT_HANDSHAKING
    bytesConsumed = 0 bytesProduced = 0
    22:07:11.122 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,168/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,18/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}] fill exit
    22:07:11.123 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - parseNext s=START HeapByteBuffer@138a3c8[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}
    22:07:11.124 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - fillInterested HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,169/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,19/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}]
    22:07:11.125 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILLING-->FILLING_FILL_INTERESTED HttpConnection@12c6b19[FILLING_FILL_INTERESTED,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,170/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,20/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}]
    22:07:11.126 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILLING_FILL_INTERESTED-->FILL_INTERESTED HttpConnection@12c6b19[FILL_INTERESTED,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,171/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,21/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}]
    22:07:11.127 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - fillInterested SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILL_INTERESTED,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,R,-,0/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,22/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}]
    22:07:11.128 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - IDLE-->FILL_INTERESTED SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILL_INTERESTED,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,R,-,1/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,24/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}]
    22:07:11.129 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Local interests updating 0 -> 1 for SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,R,-,0/30000,SslConnection}{io=1,kio=0,kro=1}
    22:07:11.129 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Queued change org.eclipse.jetty.io.SelectChannelEndPoint$1@1d2164a
    22:07:11.129 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop woken up from select, 0/1 selected
    22:07:11.130 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@1d2164a
    22:07:11.130 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Key interests updated 0 -> 1 on SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,R,-,2/30000,SslConnection}{io=1,kio=1,kro=1}
    22:07:11.131 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop waiting on select
    22:07:11.238 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop woken up from select, 1/1 selected
    22:07:11.238 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Key interests updated 1 -> 0 on SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,R,-,110/30000,SslConnection}{io=1,kio=0,kro=1}
    22:07:11.239 [DEBUG] [lipse.jetty.io.SelectChannelEndPoint] - Local interests updating 1 -> 0 for SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,R,-,111/30000,SslConnection}{io=0,kio=0,kro=1}
    22:07:11.239 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Queued change org.eclipse.jetty.io.SelectChannelEndPoint$1@1d2164a
    22:07:11.240 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILL_INTERESTED-->FILLING SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILL_INTERESTED,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,R,-,114/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,112/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}]
    22:07:11.241 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - onFillable enter DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,R,-,115/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,113/30000,SslConnection}{io=0,kio=0,kro=1}
    22:07:11.242 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILL_INTERESTED-->FILLING HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,115/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,114/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}]
    22:07:11.243 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,117/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,115/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}] onFillable HttpChannelState@6e53d6{s=IDLE i=true a=null}
    22:07:11.244 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,118/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,116/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}] fill enter
    22:07:11.245 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 511 SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,117/30000,SslConnection}{io=0,kio=0,kro=1}
    22:07:11.246 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=511/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,120/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,1/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}] filled 511 encrypted bytes
    22:07:11.248 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=0/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,121/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,3/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}] unwrap Status = OK HandshakeStatus = NOT_HANDSHAKING
    bytesConsumed = 511 bytesProduced = 482
    22:07:11.249 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,122/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,4/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=START,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=39,c=false,a=IDLE,uri=}] fill exit
    22:07:11.249 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - parseNext s=START HeapByteBuffer@1ac887b[p=0,l=482,c=17408,r=482]={<<<GET /rest/sitemap...rwin/16.1.0\r\n\r\n>>>in/16.1.0\r\n\r\n\xE0\xBc\xB1\xF2...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}
    22:07:11.250 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - START --> SPACE1
    22:07:11.250 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - SPACE1 --> URI
    22:07:11.250 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - URI --> SPACE2
    22:07:11.250 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - SPACE2 --> REQUEST_VERSION
    22:07:11.250 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - REQUEST_VERSION --> HEADER
    22:07:11.251 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_VALUE
    22:07:11.251 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.251 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_NAME
    22:07:11.251 [DEBUG] [g.eclipse.jetty.io.ssl.SslConnection] - onFillable exit DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,123/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,5/30000,SslConnection}{io=0,kio=0,kro=1}
    22:07:11.251 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_NAME --> HEADER_VALUE
    22:07:11.252 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_VALUE --> HEADER_IN_VALUE
    22:07:11.252 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.252 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_VALUE
    22:07:11.252 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.252 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_VALUE
    22:07:11.252 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.253 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_VALUE
    22:07:11.253 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.253 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_VALUE
    22:07:11.253 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.254 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_NAME
    22:07:11.254 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_NAME --> HEADER_VALUE
    22:07:11.254 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_VALUE --> HEADER_IN_VALUE
    22:07:11.254 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.254 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_NAME
    22:07:11.255 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_NAME --> HEADER_VALUE
    22:07:11.255 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_VALUE --> HEADER_IN_VALUE
    22:07:11.255 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.255 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_VALUE
    22:07:11.255 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.255 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_VALUE
    22:07:11.256 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.256 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> HEADER_IN_VALUE
    22:07:11.256 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER_IN_VALUE --> HEADER
    22:07:11.256 [DEBUG] [org.eclipse.jetty.http.HttpParser   ] - HEADER --> END
    22:07:11.257 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@d19aaf{r=40,c=false,a=IDLE,uri=/rest/sitemaps/_default/0000} messageComplete
    22:07:11.257 [DEBUG] [org.eclipse.jetty.server.HttpInput  ] - HttpInputOverHTTP@15ca2 EOF
    22:07:11.257 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - FILLING-->IDLE SslConnection@140f96f{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> HttpConnection@12c6b19[FILLING,DecryptedEndPoint@47d536{/192.168.1.24:55097<->8443,Open,in,out,-,-,127/30000,HttpConnection}->SelectChannelEndPoint@c36456{/192.168.1.24:55097<->8443,Open,in,out,-,-,9/30000,SslConnection}{io=0,kio=0,kro=1}][p=HttpParser{s=HEADER_IN_VALUE,0 of -1},g=HttpGenerator{s=START},c=HttpChannelOverHttp@d19aaf{r=40,c=false,a=IDLE,uri=/rest/sitemaps/_default/0000}]
    22:07:11.257 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@d19aaf{r=40,c=false,a=IDLE,uri=/rest/sitemaps/_default/0000} handle enter
    22:07:11.258 [DEBUG] [clipse.jetty.server.HttpChannelState] - HttpChannelState@6e53d6{s=IDLE i=true a=null} handling IDLE
    22:07:11.258 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@1d2164a
    22:07:11.258 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@d19aaf{r=40,c=false,a=DISPATCHED,uri=/rest/sitemaps/_default/0000} action REQUEST_DISPATCH
    22:07:11.259 [DEBUG] [org.eclipse.jetty.server.Server     ] - REQUEST GET /rest/sitemaps/_default/0000 on HttpChannelOverHttp@d19aaf{r=40,c=false,a=DISPATCHED,uri=/rest/sitemaps/_default/0000}
    22:07:11.260 [DEBUG] [ax.web.service.spi.model.ServerModel] - Matching [/rest/sitemaps/_default/0000]...
    22:07:11.260 [DEBUG] [ax.web.service.spi.model.ServerModel] - Path [/rest/sitemaps/_default/0000] 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@1efe36d,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:07:11.260 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]}
    22:07:11.261 [DEBUG] [.jetty.server.handler.ContextHandler] - context=||/rest/sitemaps/_default/0000 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]}
    22:07:11.261 [DEBUG] [org.eclipse.jetty.io.SelectorManager] - Selector loop waiting on select
    22:07:11.261 [DEBUG] [org.eclipse.jetty.server.session    ] - sessionManager=org.ops4j.pax.web.service.jetty.internal.LateInvalidatingHashSessionManager@1a5ce14
    22:07:11.261 [DEBUG] [org.eclipse.jetty.server.session    ] - session=null
    22:07:11.262 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - servlet |/rest|/sitemaps/_default/0000 -> org.ops4j.pax.web.service.spi.model.ServletModel-2@378be0fa==com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge,-1,true
    22:07:11.262 [DEBUG] [ce.jetty.internal.HttpServiceContext] - Handling request for [/rest/sitemaps/_default/0000] using http context [DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [12], contextID=default]]
    22:07:11.262 [DEBUG] [y.internal.HttpServiceServletHandler] - handling request org.ops4j.pax.web.service.jetty.internal.HttpServiceRequestWrapper@fee5d4, org.ops4j.pax.web.service.jetty.internal.HttpServiceResponseWrapper@1d0961
    22:07:11.263 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - chain=null
    22:07:12.534 [DEBUG] [org.eclipse.jetty.io.IdleTimeout    ] - SelectChannelEndPoint@dd0653{/192.168.1.9:60519<->8080,Open,in,out,-,-,30000/30000,HttpConnection}{io=0,kio=0,kro=1} idle timeout check, elapsed: 30000 ms, remaining: 0 ms
    22:07:12.534 [DEBUG] [org.eclipse.jetty.io.IdleTimeout    ] - SelectChannelEndPoint@dd0653{/192.168.1.9:60519<->8080,Open,in,out,-,-,30001/30000,HttpConnection}{io=0,kio=0,kro=1} idle timeout expired
    22:07:12.535 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - ignored: WriteFlusher@aca643{IDLE} java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms
    22:07:12.535 [DEBUG] [rg.eclipse.jetty.io.AbstractEndPoint] - Ignored idle endpoint SelectChannelEndPoint@dd0653{/192.168.1.9:60519<->8080,Open,in,out,-,-,30002/30000,HttpConnection}{io=0,kio=0,kro=1}
    22:07:14.488 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    22:07:19.729 [DEBUG] [org.eclipse.jetty.io.IdleTimeout    ] - SelectChannelEndPoint@17b31db{/192.168.1.9:60535<->8080,Open,in,out,-,-,30000/30000,HttpConnection}{io=0,kio=0,kro=1} idle timeout check, elapsed: 30000 ms, remaining: 0 ms
    22:07:19.730 [DEBUG] [org.eclipse.jetty.io.IdleTimeout    ] - SelectChannelEndPoint@17b31db{/192.168.1.9:60535<->8080,Open,in,out,-,-,30001/30000,HttpConnection}{io=0,kio=0,kro=1} idle timeout expired
    22:07:19.730 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - ignored: WriteFlusher@14d7529{IDLE} java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms
    22:07:19.731 [DEBUG] [rg.eclipse.jetty.io.AbstractEndPoint] - Ignored idle endpoint SelectChannelEndPoint@17b31db{/192.168.1.9:60535<->8080,Open,in,out,-,-,30003/30000,HttpConnection}{io=0,kio=0,kro=1}
    22:07:20.626 [DEBUG] [io.socket.engineio.client.Socket    ] - writing ping packet - expecting pong within 60000ms
    22:07:20.626 [DEBUG] [io.socket.engineio.client.Socket    ] - flushing 1 packets in socket
    22:07:20.669 [DEBUG] [io.socket.engineio.client.Socket    ] - socket received: type 'pong', data 'null'
    22:07:21.383 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
    22:07:24.489 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    

    Repeated again and again
    Log at startup would be of any interest ?
    There is some progress though: NEW CONNECTION when starting OH2!!! 🙂

    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:5003
    mysgw: MCO:REG:NOT NEEDED
    mysgw: MCO:BGN:STP
    mysgw: MCO:BGN:INIT OK,ID=0,PAR=0,DIS=0,REG=1
    mysgw: TSF:MSG:READ,1-1-0,s=255,c=3,t=26,pt=1,l=1,sg=0:2
    mysgw: TSF:MSG:SEND,0-0-1-1,s=255,c=3,t=27,pt=1,l=1,sg=0,ft=0,st=OK:1
    mysgw: TSF:MSG:READ,1-1-0,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
    mysgw: TSF:MSG:SEND,0-0-1-1,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100
    mysgw: TSF:MSG:READ,1-1-0,s=255,c=0,t=17,pt=0,l=5,sg=0:2.0.0
    mysgw: TSF:MSG:READ,1-1-0,s=255,c=3,t=6,pt=1,l=1,sg=0:0
    mysgw: TSF:MSG:READ,1-1-0,s=255,c=3,t=11,pt=0,l=22,sg=0:TemperatureAndHumidity
    mysgw: TSF:MSG:READ,1-1-0,s=255,c=3,t=12,pt=0,l=3,sg=0:1.1
    mysgw: TSF:MSG:READ,1-1-0,s=0,c=0,t=7,pt=0,l=0,sg=0:
    mysgw: TSF:MSG:READ,1-1-0,s=1,c=0,t=6,pt=0,l=0,sg=0:
    mysgw: TSF:MSG:READ,1-1-0,s=255,c=3,t=26,pt=1,l=1,sg=0:2
    mysgw: TSF:MSG:SEND,0-0-1-1,s=255,c=3,t=27,pt=1,l=1,sg=0,ft=0,st=OK:1
    mysgw: TSF:MSG:READ,1-1-0,s=1,c=1,t=0,pt=7,l=5,sg=0:19.9
    mysgw: TSF:MSG:READ,1-1-0,s=0,c=1,t=1,pt=7,l=5,sg=0:61.2
    mysgw: New connection from 127.0.0.1
    mysgw: Client 0 connected
    mysgw: TSF:MSG:READ,1-1-0,s=0,c=1,t=1,pt=7,l=5,sg=0:61.3
    

    Thank you so much for your time


  • Hero Member

    @ben999 had a chat @Jic right now who has exactly the same problem.

    There is still something wrong! 😞
    I'll keep searching!



  • @TimO Can you say anything regarding the autoupdate=false option yet? It would be useful to separate the UI user action from the status displayed by the UI. Rollershutters for example can show the percentage of how much the shutters are down. This conflicts with the autoupdate=true behaviour which sets the value to 0 as soon as the UP button is pushed.



  • @TimO I have reviewed all my steps, and seems that I had not updated correctly the binding.
    So later update Openhab2 to latest snapshot, the latest org.openhab.binding.mysensors-2.0.0-SNAPSHOT.jar now it working right.

    0_1479854234589_Selección_003.png

    thank you very much



  • @TimO
    Will do as @Jic said and will start fresh tonight (europe) with latest OH2 and all on a fresh SD Card
    There might be old files and bugs on this really messed up install...
    Thanks again for your time and effort


  • Hero Member

    @Jic I'm glad it worked out finally, thank you for your feedback!

    @ben999 Please do so and ensure you install the latest snapshot of OH2.

    At least I think we found the guilty one:

    "The methods ThingHandler.bridgeHandlerInitialized() and ThingHandler.bridgeHandlerDisposed() are removed. This breaks the API."
    PR LINK

    The most annoying part is: I don't see a way to keep up backward compatibility with the current testing release (beta4).


  • Hero Member

    @undee I'm not able to find a hint, that it is already implemented in OH2, do you have more information for me?

    Defining:

    Switch light01  "light01"       { autoupdate=false, channel="mysensors:light:gateway:light01:status" }
    

    Returns:

    [.e.s.m.i.i.GenericItemProvider:385  ] - Couldn't find ItemFactory for item 'channel' of type 'false'
    

    Does not look like OH2 already knows what it means.



  • @TimO The MQTT binding might be helpful. It is possible to implement the following behaviour with MQTT when autoupdate is set to false:

    When you touch a switch, the defined message is published to an MQTT topic, but the button status remains unchanged. Then, for example, the device processes the message and publishes a status message which then causes the update to the visible status of the button.

    The same can be implemented with shutters. When you push the button to move the shutters up, with autoupdate=true the icon is immediately set to reflect 0%. With autoupdate=false, you can show the current position by updating the position while it is in motion.

    I can't do this with the MySensors binding yet because pushing a button always updates the status automatically.



  • @TimO
    👑 you deserve that one 🙂
    All working fine, no trouble
    Very clean OH2 log file
    Happy man i am!
    Thanks again for time, effort and availability
    Please let me know if i can help in any way

    pi@raspberrypi:/usr/share/openhab2 $ ./start.sh
    Launching the openHAB runtime...
    
                              __  _____    ____      
      ____  ____  ___  ____  / / / /   |  / __ )     
     / __ \/ __ \/ _ \/ __ \/ /_/ / /| | / __  | 
    / /_/ / /_/ /  __/ / / / __  / ___ |/ /_/ /      
    \____/ .___/\___/_/ /_/_/ /_/_/  |_/_____/     
        /_/                        2.0.0-SNAPSHOT
                                   Build #609   
    
    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
    21:42:00.387 [DEBUG] [org.openhab.binding.mysensors       ] - BundleEvent STARTING - org.openhab.binding.mysensors
    21:42:00.403 [DEBUG] [org.openhab.binding.mysensors       ] - BundleEvent STARTED - org.openhab.binding.mysensors
    21:42:00.523 [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=0, service.id=106, service.bundleid=10, service.scope=bundle} - org.openhab.binding.mysensors
    21:42:14.666 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'home.things'
    21:42:14.994 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'mysensors:bridge-eth:gateway' has been added.                                                                                   
    21:42:15.002 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'mysensors:humidity:gateway:bathHum01' has been added.                                                                           
    21:42:15.006 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'mysensors:temperature:gateway:bathTemp01' has been added.                                                                       
    21:42:15.433 [DEBUG] [org.openhab.binding.mysensors       ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=230, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors
    21:42:15.451 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-eth:gateway' changed from UNINITIALIZED to INITIALIZING
    21:42:15.453 [DEBUG] [ernal.handler.MySensorsBridgeHandler] - Initialization of the MySensors bridge
    21:42:15.464 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:humidity:gateway:bathHum01' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
    21:42:15.474 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:temperature:gateway:bathTemp01' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)                         
    21:42:15.507 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Set skip check on startup to: false
    21:42:15.508 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Enabling connection watchdog
    21:42:15.517 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Connecting to IP bridge [127.0.0.1:5003]
    21:42:15.532 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache file: given_ids.cached exist.
    21:42:15.534 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache (given_ids) content: [1]
    21:42:15.540 [DEBUG] [ernal.handler.MySensorsBridgeHandler] - Initialization of the MySensors bridge DONE!
    21:42:15.541 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;14;Gateway startup complete.
    21:42:15.548 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;14;Gateway startup complete.
    21:42:15.552 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_humidity_gateway_bathHum01_hum' has been added.
    21:42:15.554 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;0;0;18;2.0.1-beta
    21:42:15.556 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mysensors_humidity_gateway_bathHum01_hum-mysensors:humidity:gateway:bathHum01:hum' has been added.
    21:42:15.555 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;0;0;18;2.0.1-beta
    21:42:15.559 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_humidity_gateway_bathHum01_lastupdate' has been added.
    21:42:15.562 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mysensors_humidity_gateway_bathHum01_lastupdate-mysensors:humidity:gateway:bathHum01:lastupdate' has been added.                 
    21:42:15.565 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_temperature_gateway_bathTemp01_lastupdate' has been added.                                                             
    21:42:15.569 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mysensors_temperature_gateway_bathTemp01_lastupdate-mysensors:temperature:gateway:bathTemp01:lastupdate' has been added.         
    21:42:15.571 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_temperature_gateway_bathTemp01_temp' has been added.                                                                   
    21:42:15.573 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mysensors_temperature_gateway_bathTemp01_temp-mysensors:temperature:gateway:bathTemp01:temp' has been added.                     
    21:42:15.729 [DEBUG] [rs.internal.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2;
    21:42:15.743 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;2;2.0.1-beta
    21:42:15.744 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Good,Gateway is up and running! (Ver:2.0.1-beta)
    21:42:15.745 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;2;2.0.1-beta
    21:42:15.749 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-eth:gateway' changed from INITIALIZING to ONLINE
    21:42:15.759 [INFO ] [al.protocol.ip.MySensorsIpConnection] - Successfully connected to MySensors Bridge.
    21:42:15.761 [WARN ] [al.protocol.ip.MySensorsIpConnection] - Network Sanity Checker thread disabled from bridge configuration
    21:42:15.788 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 1, chiledId: 1, revertState: false
    21:42:15.789 [DEBUG] [ternal.handler.MySensorsThingHandler] - Event listener for node 1-1 not registered yet, registering...
    21:42:15.789 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: node 1, chiledId: 0, revertState: false
    21:42:15.790 [DEBUG] [ternal.handler.MySensorsThingHandler] - Event listener for node 1-0 not registered yet, registering...
    21:42:15.794 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:temperature:gateway:bathTemp01' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
    21:42:15.796 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:humidity:gateway:bathHum01' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
    21:42:15.797 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:temperature:gateway:bathTemp01' changed from INITIALIZING to ONLINE
    21:42:15.799 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:humidity:gateway:bathHum01' changed from INITIALIZING to ONLINE
    21:42:17.115 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
    21:42:17.453 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app
    21:42:17.949 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui
    21:42:18.125 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start
    21:42:25.762 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    21:42:35.763 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    21:42:45.765 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    21:42:55.766 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    21:43:05.768 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    21:43:13.988 [DEBUG] [rs.internal.protocol.MySensorsReader] - 1;0;1;0;1;62.5
    21:43:14.005 [DEBUG] [ternal.handler.MySensorsThingHandler] - Setting last update for node 1 to 2016-11-23T21:43:13.995+0000
    21:43:14.010 [DEBUG] [ternal.handler.MySensorsThingHandler] - Setting last update for node 1 to 2016-11-23T21:43:14.006+0000
    21:43:14.016 [DEBUG] [rs.internal.protocol.MySensorsReader] - 1;0;1;0;1;62.5
    21:43:14.022 [INFO ] [marthome.event.ItemStateChangedEvent] - mysensors_temperature_gateway_bathTemp01_lastupdate changed from NULL to 2016-11-23T21:43:13.995+0000
    21:43:14.037 [INFO ] [marthome.event.ItemStateChangedEvent] - mysensors_humidity_gateway_bathHum01_lastupdate changed from NULL to 2016-11-23T21:43:14.006+0000
    21:43:14.040 [INFO ] [marthome.event.ItemStateChangedEvent] - mysensors_humidity_gateway_bathHum01_hum changed from NULL to 62.5
    21:43:15.769 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    21:43:25.771 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    21:43:35.772 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    21:43:45.775 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    21:43:55.778 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    21:44:05.779 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    21:44:15.780 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    21:44:20.330 [DEBUG] [rs.internal.protocol.MySensorsReader] - 1;1;1;0;0;18.9
    21:44:20.340 [DEBUG] [ternal.handler.MySensorsThingHandler] - Setting last update for node 1 to 2016-11-23T21:44:20.333+0000
    21:44:20.348 [DEBUG] [ternal.handler.MySensorsThingHandler] - Setting last update for node 1 to 2016-11-23T21:44:20.342+0000
    21:44:20.349 [DEBUG] [rs.internal.protocol.MySensorsReader] - 1;1;1;0;0;18.9
    21:44:20.352 [DEBUG] [rs.internal.protocol.MySensorsReader] - 1;0;1;0;1;62.0
    21:44:20.362 [DEBUG] [rs.internal.protocol.MySensorsReader] - 1;0;1;0;1;62.0
    21:44:20.364 [INFO ] [marthome.event.ItemStateChangedEvent] - mysensors_temperature_gateway_bathTemp01_lastupdate changed from 2016-11-23T21:43:13.995+0000 to 2016-11-23T21:44:20.333+0000
    21:44:20.370 [INFO ] [marthome.event.ItemStateChangedEvent] - mysensors_temperature_gateway_bathTemp01_temp changed from NULL to 18.9
    21:44:20.381 [INFO ] [marthome.event.ItemStateChangedEvent] - mysensors_humidity_gateway_bathHum01_lastupdate changed from 2016-11-23T21:43:14.006+0000 to 2016-11-23T21:44:20.342+0000
    21:44:20.387 [INFO ] [marthome.event.ItemStateChangedEvent] - mysensors_humidity_gateway_bathHum01_hum changed from 62.5 to 62.0
    21:44:25.783 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    21:44:35.785 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    21:44:45.786 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    21:44:55.788 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    21:45:05.789 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    21:45:15.792 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Bridge is connected, connection skipped
    

  • Hero Member

    @ben999 Thank you for your kind words and for your patience! 🙂

    I'm glad it is working now. As it is quiet for a day now, I suppose the problem is solved.



  • @TimO thanks to you. My Sensor seems working right since a week. 🙂

    But I have noticed a beahaviour that I think it's anomal.
    I have a Door Sensor, their lastupdate attribute upate their value almost each 10 minuts approximately. I think it should be updated when the state of the tripped value changes, or not?

    Also, if the tripped value change quickly, the lastupdate attribute not change.

    I'm triying that the lastupdate value is the last time the door was open or close, but I don't find the way to do that. Is this a bug? I have reviewed my skecht and I don't see any posible error in it.

    Thanks in advance


  • Hero Member

    @Jic Do you have a corresponding log for me?

    My last update value only updates if a update is received. If I don't get an update for hours the last update variable won't change.

    Maybe you receive a not tripped from the motion sensor? That will update the last update variable.



  • @TimO right now, I have only one Door sensor.
    my logs are

    2016-12-01 23:02:43.047 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    2016-12-01 23:02:53.049 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    2016-12-01 23:02:53.909 [DEBUG] [rs.internal.protocol.MySensorsReader] - 10;1;1;0;16;1
    2016-12-01 23:02:53.923 [DEBUG] [ternal.handler.MySensorsThingHandler] - Setting last update for node 10 to 2016-12-01T23:02:53.913+0100
    2016-12-01 23:02:53.990 [DEBUG] [rs.internal.protocol.MySensorsReader] - 10;255;3;0;22;100788
    2016-12-01 23:03:03.051 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    2016-12-01 23:03:13.053 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    2016-12-01 23:07:03.111 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    2016-12-01 23:07:05.190 [DEBUG] [rs.internal.protocol.MySensorsReader] - 10;255;3;0;21;0
    2016-12-01 23:07:05.203 [DEBUG] [ternal.handler.MySensorsThingHandler] - Setting last update for node 10 to 2016-12-01T23:07:05.193+0100
    
    ==> events.log <==
    2016-12-01 23:07:05.229 [ItemStateChangedEvent     ] - mysensors_door_gateway_Door_10_1_lastupdate changed from 2016-12-01T23:02:53.913+0100 to 2016-12-01T23:07:05.193+0100
    2016-12-01 23:07:05.264 [ItemStateChangedEvent     ] - Cancela01time changed from 2016-12-01T23:02:53.913+0100 to 2016-12-01T23:07:05.193+0100
    

    You can see last event is at 23:07, however in the following snapshot the time is 11:17

    0_1480631760477_Selección_004.png

    No more events, but the lastupdate change



  • @TimO ok, I have discovered that my "tail" command doesn't work rigth, sorry

    My logs are

    2016-12-01 23:02:53.990 [DEBUG] [rs.internal.protocol.MySensorsReader] - 10;255;3;0;22;100788
    2016-12-01 23:07:05.190 [DEBUG] [rs.internal.protocol.MySensorsReader] - 10;255;3;0;21;0
    2016-12-01 23:17:05.248 [DEBUG] [rs.internal.protocol.MySensorsReader] - 10;255;3;0;21;0
    2016-12-01 23:27:05.326 [DEBUG] [rs.internal.protocol.MySensorsReader] - 10;255;3;0;21;0
    2016-12-01 23:37:05.409 [DEBUG] [rs.internal.protocol.MySensorsReader] - 10;255;3;0;21;0
    2016-12-01 23:47:05.486 [DEBUG] [rs.internal.protocol.MySensorsReader] - 10;255;3;0;21;0
    2016-12-01 23:57:05.562 [DEBUG] [rs.internal.protocol.MySensorsReader] - 10;255;3;0;21;0
    2016-12-02 00:07:05.639 [DEBUG] [rs.internal.protocol.MySensorsReader] - 10;255;3;0;21;0
    

    I don't understand why am I reciving this message?


  • Hero Member

    @Jic According to the serial API this is a I_DISCOVER_RESPONSE, but why is it sent? This seeems to update the lastUpdate channel.

    I see it this way: "lastUpdate" is the last time the node has sent something, so everything is working as expected. 😄



  • @TimO

    Thanks. I don't know why is it sending a I_DISCOVER_RESPONSE message. Any Idea?


  • Hero Member

    @Jic No sorry, I've no idea. 😕



  • @TimO said:

    @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:

    1. Copy the binding jar to /tmp.
    2. 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.jar
    

    OH2 is started/stopped/restarted with

    service openhab2 start/stop/restart
    

    To log into the karaf console do:

    ssh openhab@localhost -p 8101
    

    Password is: habopen

    Follow the guide/wiki from:

    In the console enter feature:install openhab-transport-serial
    

    I have installed openhab with the openhabian image. I could start the mysensors gateway too.
    I followed the github-openhab2 installation instructions.
    To this point

    In the console enter feature:install openhab-transport-serial
    

    I read a lot of posts on this thread but on get this error:

    openhab> install openhab-transport-serial
    Bundle IDs:
    Error executing command: Error installing bundles:
    	Unable to install bundle openhab-transport-serial
    

    the chmod line posted above doesn't work neither. chmod does not accept openhab.openhab

    I dont have any clue how to install the binding for openhab2 ... why isn't that possible from paperui 😞



  • I have install the addon and am getting the error:

    17:49:40.745 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Connecting to IP bridge [null:1883]
    17:49:40.745 [ERROR] [al.protocol.ip.MySensorsIpConnection] - IP must be not null/empty
    17:49:40.752 [ERROR] [al.protocol.ip.MySensorsIpConnection] - Failed connecting to bridge...next retry in 10 seconds (Retry No.:46)
    17:49:40.753 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Disconnecting from IP bridge ...
    

    MySensors does not show up as a binding in HabMin or PaperUI.

    Where do I configure the MySensors binding if it doesn't show up in the UI?



  • @tademet
    as stated in the configuration wiki https://github.com/tobof/openhab2-addons/wiki/Configuration you have to define the bridge in your thing-configuration, depending on the type of your gateway serial or ethernet.



  • @jogant
    I have added the config to the thing file.

    Bridge mysensors:bridge-eth:gateway [ ipAddress:"10.9.167.116", tcpPort=5003, sendDelay=200, imperial=true] {
    
    }
    

    But still getting the error:

    08:10:25.214 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Connecting to IP bridge [null:5003]
    08:10:25.215 [ERROR] [al.protocol.ip.MySensorsIpConnection] - IP must be not null/empty
    08:10:25.216 [ERROR] [al.protocol.ip.MySensorsIpConnection] - Failed connecting to bridge...next retry in 10 seconds (Retry No.:3)
    08:10:25.217 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Disconnecting from IP bridge ...
    
    

    I changed the port and it recognized that change but is not recognizing ipAddress. Am I misspelling this?


  • Hero Member

    @tademet there's a ":" instead of a "=" between ipAddress and the IP adress.



  • Just stumbled across this binding great work!
    Until now I have used MQTT binding and MQTT gateway.
    Will try this later on.
    However, is there a reason why this binding is not part as downloadable from within OH2?
    Cheers 🙂


  • Hero Member

    Hey @Nicklas-Starkel !
    I hope it will work out for you! 🙂

    It is not yet part of OH2 and downloadable within OH2 because my pull request is still open. A OH2 developer needs to look at it. 🙂



  • @TimO

    I've downloaded your code from github for this binding and tried to modify it a bit for my specific needs. However I'm having trouble compiling it. I've then gone back to basics and added in your unedited code to Eclipse. However it complains about:

    @Override
    public void bridgeHandlerDisposed(ThingHandler thingHandler, Bridge bridge)

    Saying : The method bridgeHandlerDisposed(Thinghandler,Bridge) of type MySensorsHandler must override or implement a supertype method.

    Do you have any advice for me on this? 🙂

    Thanks for your work on this!




  • Hero Member

    Hey @infrag !

    Switch to the MySensors branch, the master branch is outdated. 🙂



  • @TimO

    ah that explains it. Thanks! 🙂



  • @TimO
    I'm trying to add a CO2 sensor. What is the sensor i need to select inside OpenHAB?

    TSP:MSG:SEND 70-70-0-0 s=0,c=1,t=37,pt=4,l=4,sg=0,ft=0,st=ok:1162
    CO2 level = 1162 ppm

    sketch:
    MyMessage msg(CHILD_ID_AIQ, V_LEVEL);
    present(CHILD_ID_AIQ, S_AIR_QUALITY);



  • Hello everyone,
    In an OH2 environment with 2 nodes reporting temperature, one attached to the gateway and one on his own I receive the following error:
    [ERROR] [rs.internal.protocol.MySensorsReader] - (java.lang.IllegalStateException: Could not update state, because callback is missing) on reading from connection, message: class org.openhab.binding.mysensors.internal.protocol.serial.MySensorsSerialReader

    The node attached to the gateway works fine, his item gets updated but the other one not.
    The only code difference between their loop methods are calls to isTransportOK() and receiveTime() which are made by the latter node.
    Doesn't this version support those 2 methods or I'm missing something ?
    https://github.com/tobof/openhab2-addons/blob/MySensors/addons/binding/org.openhab.binding.mysensors/target/org.openhab.binding.mysensors-2.0.0-SNAPSHOT.jar

    Thx for all the hard work on this library 😃


  • Hero Member

    Hey @frg !

    1. receiveTime() is supported by the binding and should work. In the binding log should appear a message like:
    I_TIME request received from 123, answering...
    

    Do you have some more log for me?

    1. isTransportOK() is only handled within the node, no message is send so there is nothing the binding could support. By the way, the method was renamed to isTransportReady() with the current version 2.1.0.

    Are there no updates from the second node? Did you check in the serial log of the node that messages were sent?



  • @TimO
    Hello,
    Well this is bit of embarrassing...after changing the sleep time from 5 minutes to 1 minute for the troublesome node and re-uploading the sketch, it is reporting the temperature just fine. I tried all kinds of combinations trying to replicate the initial behavior, stopped the controller, rebooted the gateway, powered them off for while, moving back to 5 minutes sleep, to no avail, node registers and the temperature is reporting is showed in the paperui.

    On the other hand I don't see that I_TIME request received from... message in the logs (used log:set DEBUG org.openhab.binding.mysensors and log:tail) so I'm not sure if the receiveTime() is called.
    I suppose I can write something in the EEPROM when the callback function runs and check that.
    Thank you

    01:30:45.291 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    01:30:50.280 [DEBUG] [rs.internal.protocol.MySensorsReader] - 2;0;1;0;0;22.0
    01:30:50.282 [DEBUG] [ternal.handler.MySensorsThingHandler] - Setting last update for node 2 to 2017-01-06T01:30:50.281+0200
    01:30:50.285 [INFO ] [marthome.event.ItemStateChangedEvent] - TemperatureOutside_LastUpdate changed from 2017-01-06T01:28:52.282+0200 to 2017-01-06T01:30:50.281+0200
    01:30:53.550 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;1;1;0;0;23.1
    01:30:55.292 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    01:31:05.293 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    01:31:15.293 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    01:31:25.294 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    01:31:35.294 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    01:31:45.295 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    01:31:49.287 [DEBUG] [rs.internal.protocol.MySensorsReader] - 2;0;1;0;0;22.0
    01:31:53.541 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;1;1;0;0;23.1
    01:31:53.544 [DEBUG] [ternal.handler.MySensorsThingHandler] - Setting last update for node 0 to 2017-01-06T01:31:53.543+0200
    01:31:53.552 [INFO ] [marthome.event.ItemStateChangedEvent] - TemperatureGateway_LastUpdate changed from 2017-01-06T01:29:53.559+0200 to 2017-01-06T01:31:53.543+0200
    01:31:55.295 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    01:32:05.296 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    01:32:15.296 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    01:32:25.297 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    01:32:35.298 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    01:32:45.298 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    01:32:48.283 [DEBUG] [rs.internal.protocol.MySensorsReader] - 2;0;1;0;0;22.0
    01:32:48.284 [DEBUG] [ternal.handler.MySensorsThingHandler] - Setting last update for node 2 to 2017-01-06T01:32:48.284+0200
    01:32:48.290 [INFO ] [marthome.event.ItemStateChangedEvent] - TemperatureOutside_LastUpdate changed from 2017-01-06T01:30:50.281+0200 to 2017-01-06T01:32:48.284+0200
    01:32:53.532 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;1;1;0;0;23.1
    01:32:55.299 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    
    

    Node 0 is gateway attached, Node 2 is battery run -TemperatureOutside.


  • Hero Member

    @frg Sometimes magic just happens. 😉
    I'm glad it is working now! 👍



  • I try to send ORP calibration value to my sensors but it doesn't work.
    NODE_ID : 10, CHILD_NODE_ID : 0
    When I'm recieve ORP from my sensors it's ok :

    13:55:38.216 [DEBUG] [rs.internal.protocol.MySensorsReader] - 10;0;1;0;52;996.3
    

    But when I change the value, the value is not send :

    14:09:24.051 [INFO ] [marthome.event.ItemStateChangedEvent] - orp01 changed from 40 to 50
    14:09:24.266 [INFO ] [smarthome.event.ItemCommandEvent    ] - Item 'orp01' received command 60
    14:09:24.266 [DEBUG] [rs.internal.protocol.MySensorsWriter] - Sending to MySensors: 10;0;1;0;0;
    

    Item :

    Number	orp01	"Redox [%.1f mV]" <faucet> (gPiscine) { channel="mysensors:waterQuality:gateway:orp01:orp"}
    

    Sitemap :

      sitemap test label="Main Menu" { 
        Frame label="Piscine" { 
    		Setpoint item=orp01 label="Calirabte ORP" minValue=0 maxValue=1000 step=10
        } 
      }
    

  • Hero Member

    @Fabien I need a little bit more time to reproduce this behaviour. I've opened an issue here: https://github.com/tobof/openhab2-addons/issues/50



  • Hello everyone
    I'm slowly migrating to OH2, my small MySensors network generally works fine but I see some weird behavior with the binding configuration in Paper UI.
    So far it looks like "Disable network sanity check" is reversed - I'm sliding it to the left which means for me 'not disabled', i.e. 'enabled', but in the log I see "Checker thread disabled".

    2017-01-11 16:50:38.405 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;14;Gateway startup complete.
    2017-01-11 16:50:38.408 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;0;0;18;2.1.0
    2017-01-11 16:50:38.503 [DEBUG] [rs.internal.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2;
    2017-01-11 16:50:38.511 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;2;2.1.0
    2017-01-11 16:50:38.512 [DEBUG] [col.serial.MySensorsSerialConnection] - Good,Gateway is up and running! (Ver:2.1.0)
    2017-01-11 16:50:38.514 [INFO ] [col.serial.MySensorsSerialConnection] - Successfully connected to MySensors Bridge.
    2017-01-11 16:50:38.515 [WARN ] [col.serial.MySensorsSerialConnection] - Network Sanity Checker thread disabled from bridge configuration
    2017-01-11 16:50:48.516 [DEBUG] [col.serial.MySensorsSerialConnection] - Bridge is connected, connection skipped
    
    

    Is that ok?


  • Hero Member

    @AndrewZ Don't worry about that message, the debug log looks good. The warning is confusing and we need to change that. 🙂



  • @TimO Thanks, will keep it off in the GUI.



  • Hi @TimO

    I've logged a job to include documentation about non-native OpenHAB 2.0 bindings in the official OH2 docs.

    ThomDeitrich is looking to know why it's not yet in the official distro. Can provide some info?

    https://github.com/openhab/openhab-docs/issues/188


  • Hero Member

    Hey @Duncan-Pullen !

    The main reason is: I'm waiting for suggestions / approval from the OH2 developers. 🙂

    The MySensors binding has grown big and a review takes some time.


  • Admin

    @TimO, thank you for all the effort you've put into this!



  • Hi everyone,
    @TimO, thanks for everything you did here!

    I just made the 2.0 version (code in comments of respective post) of petewill's Simple Scene Controller and discovered that a Scene Controller is not yet implemented in the OpenHAB binding. Is there a possibility that it will be implemented in the future?
    For now, is it possible to get this working with CustomSensor or Text?


  • Hero Member

    Hi @FusedHe3 !

    My first thought was: that's easy, lets add this! But after a second thought ...

    I see one problem with S_SCENE_CONTROLLER: how do I map this in OpenHAB?

    In MySensors there is V_SCENE_ON and V_SCENE_OFF. The message contains the corresponding scene number.

    In OpenHAB I've: Number, Switch, Selection ...

    0_1484735515591_upload-dac7eae9-cec0-4cbd-95ec-a0428268441c

    In OpenHAB I may choose between Scene A, Scene B and so on, but I can't select between ON and OFF. Is Scene A switched off, when I select Scene B?

    I'm using scenes with a switch in OpenHAB. Something like "Christmas decoration ON". In OpenHAB I'm using a group for that gChristmasDecoration or a rule: switch light on, shutter to 33%, ..

    My approach in implementing a (hardware) scene controller would be a mapping of those switches. So I would define a switch / child for every button (scene) on the controller.

    I'm open for ideas on how to map V_SCENE_CONTROLLER in OpenHAB, so if you or someone else have and idea, shout it out. 😄


  • Hero Member

    Ah, by the way, I forgot to mention: SmartSleep is supported since last week.

    0_1484736645455_upload-d9d8432b-4892-4c07-876a-3abd4def86a0



  • @TimO Thanks for the quick reply!
    I do think the ON/OFF switch for every scene would be the most logical solution. In that way it's fully compatibel with the MySensors Scene Controller and you can have multiple scenes active at the same time.



  • Just updated my OH2 installation from snapshot to RC/beta and immediately got an error with the binding:

    [ERROR] [rs.internal.protocol.MySensorsReader] - (java.lang.NumberFormatException: For input string: "Gateway startup complete.") on reading from connection, message: class org.openhab.binding.mysensors.internal.protocol.serial.MySensorsSerialReader
    

    But then the usual:

    [INFO ] [col.serial.MySensorsSerialConnection] - Successfully connected to MySensors Bridge.
    [WARN ] [col.serial.MySensorsSerialConnection] - Network Sanity Checker thread disabled from bridge configuration
    

    What could be a problem? Do I need to perform some cleanup on my system? What exactly needs to be deleted?



  • I ran into trouble today by apt-get updating Openhab.

    I am over redefining the Distro for Snapshot... I have 2.0.0-SNAPSHOT, Build #743 up and running.

    my bundle list looks following:
    204 | Active | 80 | 3.12.0.OH | nrjavaserial
    205 | Installed | 80 | 2.0.0.201611221149 | MySensors Binding

    Still getting these errors:
    "03:17:10.911 [ERROR] [org.openhab.binding.mysensors ] - FrameworkEvent ERROR - org.openhab.binding.mysensors
    org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.mysensors [205]
    Unresolved requirement: Require-Bundle: org.openhab.io.transport.serial"

    Any idea for next step?


  • Hero Member

    @krejcarek please upgrade the binding to the most recent version. 🙂



  • @TimO what about my error? I'm on the latest version already.


  • Hero Member

    @AndrewZ Sorry! Is it working despite the error? I need to test with RC1 myself. The error looks like it could be ignored. From time to time messages get corrupted, due to connection issues and the parser stumbles about that. But it should continue to work just fine. I suppose this is the case here, but I'll check!



  • @TimO yes, it is working, but please check this one and 2nd (Network Sanity Checker thread disabled). Thank you!



  • I had the same error messages on first boot of OH. After finishing upgrade procedure and restarting OH once again error message is gone. New version of the binding is working well. No hickups at the moment.



  • Hi Guys
    I am currently playing with a fairly fresh install of openhab2 (last weekend)
    I have played with the auto-discovery function in PaperUI
    Wow that's amazing 🙂
    But i am having trouble when it comes to sitemap file : sitemap function is not included within PaperUI (as far as i know) and i need this file to configure properly my iOS app
    So i have to go back to the old fashionned way and edit thing, item and map files with a text editor (which is fine)

    Two questions from here:

    • please prove me wrong in the way that i can discover things and configure items within paperUI and still create a valid sitemap file usable by my iOS devices
    • if above not possible, is there a way to "flush" openhab things and items database as i am getting warnings about things that don't exist anymore (things previously discovered by paperUI but deleted since)
      Thanks a lot for reading


  • I must be missing something. I have the same error as well. Is there a link to the latest binding. The one on the instructions page is dated 20161122 and a second one refereed to in this topic above dated 20161222. Which binding should I be using



  • @TimO, Thanks for the quick response. Probably was some stupid mistake with copying.jar file. Got mine now on 2.0.0.201701181308, and works like charm.
    Hoping to have mysensors soon as official binding to avoid the need of workarounds and thus prone to mistakes.


  • Hero Member

    @hillmanr please try this link: Download


  • Hero Member

    @ben999

    1. It is possible to discover things with PaperUI and afterwards insert them in an item and sitemap file. Just use the channel that was given due to recovery. This way you don't need the things file.

    2. You may delete the hole database or edit it with a text editor as it is a jsondb file. I'm on my phone, so I can't give you the correct location right now.

    Did you try habmin? I've seen some amazing screenshots but haven't tried it myself.



  • Got the 2.0.0.201701181308 binding, works, thanks. Amazing effort on the binding, great job.



  • @TimO
    Thanks a lot Tim
    Found a few interresting files in /usr/share/openhab2/userdata/jsondb (one containing history of discovery)
    Got rid of them all then rebooted but no change: my log is still polluted with that kind of entries:

    05:33:19.658 [WARN ] [ome.core.thing.internal.ThingManager] - Cannot delegate update '3' for item 'salonBatt01' to handler for channel 'mysensors:temperature:gateway:Temperature_1_0:battery', because no thing with the UID 'mysensors:temperature:gateway:Temperature_1_0' could be found.
    05:33:19.660 [WARN ] [ome.core.thing.internal.ThingManager] - Cannot delegate update '3' for item 'salonBatt01' to handler for channel 'mysensors:humidity:gateway:salonBatt01:battery', because no thing with the UID 'mysensors:humidity:gateway:salonBatt01' could be found.
    

    There also was a backup directory in there... deleted but no change
    Another location?

    EDIT : files in that directory are back after a reboot 😄 (meaning that the files themselves are back, and the one containing discovery data still contains it !!!)

    Thanks a lot for your help buddies


Log in to reply
 

Suggested Topics

  • 22
  • 3
  • 19
  • 5
  • 10
  • 4

25
Online

11.2k
Users

11.1k
Topics

112.5k
Posts