openHAB 2.0 binding

[Puneit Thukral]

This post is deleted!

[ben999]

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'

[TimO]

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

[FutureCow]

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.

[FutureCow]

This post is deleted!

[TimO]

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

[ben999]

@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

[bentrik]

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

[TimO]

@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

[TimO]

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

[FutureCow]

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.

[TimO]

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

[bathoryr]

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

[ben999]

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

[TimO]

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.

[FutureCow]

Thanks, the new version is working nice. only your link didn't work for me, i used this one:
https://github.com/tobof/openhab2-addons/blob/MySensors/addons/binding/org.openhab.binding.mysensors/target/org.openhab.binding.mysensors-2.0.0-SNAPSHOT.jar?raw=true

[ben999]

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

[ben999]

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

[TimO]

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

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

[undee]

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

[Jic]

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

thank you very much

[ben999]

@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

[TimO]

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

[TimO]

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

[undee]

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

[ben999]

@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

[TimO]

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

[Jic]

@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

[TimO]

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

[Jic]

@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

No more events, but the lastupdate change

[Jic]

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

[TimO]

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

[Jic]

@TimO

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

[TimO]

@Jic No sorry, I've no idea.

[patrick schaerer]

@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

[tademet]

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?

[jogant]

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

[tademet]

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

[TimO]

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

[Nicklas Starkel]

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

[TimO]

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.

[infrag]

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

[infrag]

@TimO

According to this:
https://www.eclipse.org/smarthome/documentation/javadoc/org/eclipse/smarthome/core/thing/binding/ThingHandler.html#bridgeStatusChanged-org.eclipse.smarthome.core.thing.ThingStatusInfo-

The old method of bridgeHandlerDisposed is Depreciated now.

[TimO]

Hey @infrag !

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

[infrag]

@TimO

ah that explains it. Thanks!

[FutureCow]

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

[A Former User]

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

[TimO]

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?

[A Former User]

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

[TimO]

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

[Fabien]

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

[TimO]

@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

[AndrewZ]

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?

[TimO]

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

[AndrewZ]

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

[Duncan Pullen]

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

[TimO]

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.

[hek]

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

[FusedHe3]

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?

[TimO]

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

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.

[TimO]

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

[FusedHe3]

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

[AndrewZ]

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?

[krejcarek]

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?

[TimO]

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

[AndrewZ]

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

[TimO]

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

[AndrewZ]

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

[jogant]

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.

[ben999]

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

[hillmanr]

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

[krejcarek]

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

[TimO]

@hillmanr please try this link: Download

[TimO]

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

[hillmanr]

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

[ben999]

@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

[Fabien]

This binding works fine with 2.1.1 sensors actually Temp/Hum, Ph/ORP, RollerShutters. thanks for your work on this binding @TimO !
Is this binding work with firmware update : http://docs.openhab.org/administration/runtime.html ?

[TimO]

@Fabien Thank you for your feedback!
And: I've waited for that question according firmware updates to come up.

I've looked into it and I'm very interested but till now there is only the implementation in the library, I've not seen an implementation in a binding. I'll continue to look at it, but with low priority.

Current priority list is:

1. Include binding in OH2 repository.
2. Test and include the big refactoring from @andreacioni .
3. Add MQTT gateway (proof of concept working, full integration after refactoring).
4. Add little feature requests, add sensors ...

[Fritzin]

This is so great. I am fairly new to openhab 2. I have it up and running on a RP3. No issues during the install. I was able to get Habmin and paperhab up and running. I installed a few add-ons that were part of the img on openhab.com. However, i cant figure out how to add mysensors.org add-on. I am using OSX and I can't figure out where to place the file in openhab2 on the raspberry pi. Please help!!!!

[TimO]

The jar needs to be placed here:

/usr/share/openhab2/addons/

You'll find further instructions here:

https://github.com/tobof/openhab2-addons/wiki/Installation

[azuntik]

I was able to successfully install the binding, but when I added a temperature sensor as a test, it keeps failing. This is the error message I'm getting:

17:01:28.130 [ERROR] [ome.core.thing.internal.ThingManager] - Exception occured while initializing handler of thing 'mysensors:temperature:4c0b17b9': java.lang.NullPointerException
java.util.concurrent.ExecutionException: java.lang.NullPointerException
        at java.util.concurrent.FutureTask.report(FutureTask.java:122)[:1.8.0_121]
        at java.util.concurrent.FutureTask.get(FutureTask.java:206)[:1.8.0_121]
        at org.eclipse.smarthome.core.common.SafeMethodCaller.callAsynchronous(SafeMethodCaller.java:188)[98:org.eclipse.smarthome.core:0.9.0.b4]
        at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:81)[98:org.eclipse.smarthome.core:0.9.0.b4]
        at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:65)[98:org.eclipse.smarthome.core:0.9.0.b4]
        at org.eclipse.smarthome.core.thing.internal.ThingManager$9.run(ThingManager.java:710)[105:org.eclipse.smarthome.core.thing:0.9.0.b4]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_121]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_121]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)[:1.8.0_121]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)[:1.8.0_121]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_121]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_121]
        at java.lang.Thread.run(Thread.java:745)[:1.8.0_121]
Caused by: java.lang.NullPointerException
        at org.openhab.binding.mysensors.internal.handler.MySensorsThingHandler.getBridgeHandler(MySensorsThingHandler.java:268)[193:org.openhab.binding.mysensors:2.0.0.201701181308]
        at org.openhab.binding.mysensors.internal.handler.MySensorsThingHandler.initialize(MySensorsThingHandler.java:77)[193:org.openhab.binding.mysensors:2.0.0.201701181308]
        at org.eclipse.smarthome.core.thing.internal.ThingManager$9$1.call(ThingManager.java:713)[105:org.eclipse.smarthome.core.thing:0.9.0.b4]
        at org.eclipse.smarthome.core.thing.internal.ThingManager$9$1.call(ThingManager.java:1)[105:org.eclipse.smarthome.core.thing:0.9.0.b4]
        at org.eclipse.smarthome.core.common.SafeMethodCaller$CallableWrapper.call(SafeMethodCaller.java:179)[98:org.eclipse.smarthome.core:0.9.0.b4]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_121]
        ... 3 more

Any thoughts?

[TimO]

@azuntik Did you configure the temperature thing in the things and items file? Please post the contents of these files. Please add the debug log from the time before and after the exception occurs. Which version (snapshot, stable) of OH2 are you running?

[azuntik]

@TimO I'll be honest with you: I'm not sure I configured everything properly. I don't have things or items files, because I set things up through the PaperUI. Do I need to set everything up through config files?

I've attached the complete log file. I'm running stable.

Thanks for your help!

Edit: Nevermind. I don't have permission to upload a file. So, here's a pastebin: http://pastebin.com/jLeTXbvX (the timestamps are wrong, you can ignore the date).

Edit2: One thing that I was having trouble with was determining the Node and Child IDs. I finally settled on what I think they are (105 and 255, respectively), but I may be wrong. Any advice with regard to figuring that out would also be greatly appreciated!

[marceltrapman]

@azuntik You should know what you are creating

In PaperUI you first create a thing for the gateway (I assume that worked for you).
Next OpenHAB should find all attached things for you, no need to create them manually. Just confirm what OpenHAB found.
Based on available properties you create an Item.

[azuntik]

@marceltrapman Frankenstein's Monster?

So, the UI is not detecting anything, although testing mysgw shows it receiving data. Is this a misconfiguration on my part?

Edit: Nevermind. I think what you said just sank in. Thanks for your help!

[nikos1671]

Hi TimO
Can you please add support for gas meter S_GAS like the water meter.

Thanks
Nikos

[David Link]

Hello all! I believe I have done my due diligence in solving my own problem, but I am stuck. Can anyone point me in the right direction?

I am trying to get started with an Ethernet Gateway. The gateway is displayed on the PaperUI, but in the log, it continues to try and connect to the ip bridge (Sending to MySensors: 0;0;3;0;2;)

I am on:
openhab 2.1.0-snapshot build #791
MySensors Binding: 2.0.0.201701181308
Gateway is using library 2.1.1

I have tried:
Clearing the EEPROM on the gateway thinking some garbage got stuck there.
Set up and successfully used an MQTT gateway, thinking bad hardware?
Restarted the binding, openhab, kitchen sink countless times.
Updating everything to the latest build I could find
Manually creating things

The only thing that seems odd to me is the gateway repeats over and over what appears to be initialization data (displays ip address, 0;255;3;0;9;MC0;BGN;STP.....). However, it does receive data from a temperature node I built.

I appreciate any pointers that can be provided, including "have you read this page?", though I think my Google search is permanently stuck on "mysensors openhab" at this point.

Thanks,

Dave

[stoffej]

@nikos1671

Where do I found the Mysensors Binding 2.0.0.201701181308 jar file for download?
Or is it mandatory to compile it from source?

Thanks Kristoffer

[TimO]

@David-Link Are you sure the gateway isn't in a boot loop?

[TimO]

@stoffej HERE

[David Link]

@TimO That's exactly what is going on. Thank you for the tip, I was pulling my hair out. Now on to solving that problem! Thanks again.

[mlava]

Hi @TimO
I am having trouble but think I might be doing it wrong.
Is it possible to use this binding with a MQTT gateway?
I see that it needs to find the gateway on port 5003 but this isn't defined in MQTT gateway.
Is it possible?

[TimO]

Hi @mlava !
The MQTT gateway is not supported at the moment. I've done a proof of concept and it will be implemented after the refactoring we're currently working on.

[mlava]

@TimO
Wonderful, thank you for the answer.
I'll wait eagerly for progress!

[Andrew Currie]

@David-Link It looks like you have a similar issue to me re the ethernet gateway. I have also tried "everything" and then yesterday discovered an old bug that might have resurfaced. I just put the following up on github:

https://github.com/mysensors/MySensors/issues/777

It might help you..

[Andrew Currie]

Further to my client ethernet gateway not working with the MySensors 2.1.1 library, I tried 2.0.0 and now go much further. The gateway does not keep restarting, talks to the openhab controller and at least reads the messages and tripped status from my motion sensor

0;255;3;0;9;Starting gateway (RNNGA-, 2.0.0)
0;255;3;0;9;TSM:INIT
0;255;3;0;9;TSM:RADIO:OK
0;255;3;0;9;TSM:GW MODE
0;255;3;0;9;TSM:READY
IP: 192.168.1.9
0;255;3;0;9;No registration required
0;255;3;0;9;Init complete, id=0, parent=0, distance=0, registration=1
0;255;3;0;9;TSP:MSG:READ 1-1-0 s=1,c=1,t=16,pt=0,l=1,sg=0:0
0;255;3;0;9;TSP:MSG:READ 1-1-0 s=1,c=1,t=16,pt=0,l=1,sg=0:1
0;255;3;0;9;TSP:MSG:READ 1-1-0 s=1,c=1,t=16,pt=0,l=1,sg=0:0
0;255;3;0;9;TSP:MSG:READ 1-1-0 s=1,c=1,t=16,pt=0,l=1,sg=0:1
0;255;3;0;9;TSP:MSG:READ 1-1-0 s=1,c=1,t=16,pt=0,l=1,sg=0:0
0;255;3;0;9;TSP:SANCHK:OK```

I had to turn on the skipStartupCheck for the ethernet gateway to come online in openhab (and the gateway serial monitor did show the 0;0;3;0;2; and ethernet messages between openhab and the gateway)

15:10:13.316 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Connecting to IP bridge [192.168.1.9:5003]
15:10:13.819 [DEBUG] [rs.internal.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2;
15:10:14.320 [DEBUG] [rs.internal.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2;
15:10:15.320 [DEBUG] [rs.internal.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2;
15:10:16.320 [DEBUG] [rs.internal.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2;
15:10:17.321 [DEBUG] [rs.internal.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2;
15:10:18.321 [ERROR] [al.protocol.ip.MySensorsIpConnection] - Cannot start reading/writing thread, probably sync message (I_VERSION) not received. Try set skipStartupCheck to true
15:10:18.322 [ERROR] [al.protocol.ip.MySensorsIpConnection] - Failed connecting to bridge...next retry in 10 seconds (Retry No.:1)
15:10:18.322 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Disconnecting from IP bridge ...
15:10:18.323 [DEBUG] [rs.internal.protocol.MySensorsWriter] - Stopping Writer thread
15:10:18.324 [DEBUG] [rs.internal.protocol.MySensorsReader] - Stopping Reader thread
15:10:18.324 [ERROR] [rs.internal.protocol.MySensorsWriter] - (java.lang.InterruptedException) on writing to connection, message: class org.openhab.binding.mysensors.internal.protocol.ip.MySensorsIpWriter
15:10:18.325 [ERROR] [rs.internal.protocol.MySensorsReader] - (java.lang.InterruptedException: sleep interrupted) on reading from connection, message: class org.openhab.binding.mysensors.internal.protocol.ip.MySensorIpReader
15:10:25.236 [DEBUG] [ernal.handler.MySensorsBridgeHandler] - Disposing of the MySensors bridge
15:10:25.236 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Destroying connection
15:10:25.236 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache file: given_ids.cached exist.
15:10:25.237 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache (given_ids) content: [1]
15:10:25.237 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Writing on cache given_ids, content: [1]
15:10:25.239 [DEBUG] [ernal.handler.MySensorsBridgeHandler] - Initialization of the MySensors bridge
15:10:25.239 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'mysensors:bridge-eth:cb1d6dd1' has been updated.
15:10:25.240 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Set skip check on startup to: true
15:10:25.240 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Enabling connection watchdog
15:10:25.240 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache file: given_ids.cached exist.
15:10:25.241 [DEBUG] [al.protocol.ip.MySensorsIpConnection] - Connecting to IP bridge [192.168.1.9:5003]
15:10:25.241 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache (given_ids) content: [1]
15:10:25.241 [DEBUG] [ernal.handler.MySensorsBridgeHandler] - Initialization of the MySensors bridge DONE!
15:10:25.244 [WARN ] [al.protocol.ip.MySensorsIpConnection] - Skipping I_VERSION connection test, not recommended...
15:10:25.244 [INFO ] [al.protocol.ip.MySensorsIpConnection] - Successfully connected to MySensors Bridge.

I then got my motion sensor to come online in openhab

15:13:24.300 [DEBUG] [ternal.handler.MySensorsThingHandler] - Configuration: nodeId 1, chiledId: 1, requestAck: false, revertState: false, smartSleep: false
15:13:24.301 [DEBUG] [ternal.handler.MySensorsThingHandler] - Event listener for node 1-1 not registered yet, registering...
15:13:24.305 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:motion:24559d07' changed from INITIALIZING to ONLINE```

However the motion sensor (via gateway) and openhab controller are not talking to each other. Does skipping the startup check result in problems?

Any ideas on how to progress with MySensors 2.0.0 library or do I need to wait for a fix to 2.1.1?

Many Thanks...

[David Link]

@Andrew-Currie I think that is the same thing I am dealing with. I will take a look, thank you!

I "cheated" and just hooked it up to my Pi that is running OpenHab and it works like a charm.

[TimO]

@Andrew-Currie It should make no difference for the binding if you're using 2.0.0 or 2.1.1. I can't see any incoming messages in the debug log you've posted. If the gateway is properly connected you should see messages incoming, for example from your motion sensor. Could you please establish a telnet connection to the gateway at port 5003 and post the output? In parallel check the serial output of the gateway, there you should see the establishment of the telnet connection for example.

[Andrew Currie]

@TimO Thanks Tim for your feedback. Here is the log from the gateway. It receives messages from openhab re the ethernet connection and also from the motion sensor and gets a fail from one send

0;255;3;0;9;Starting gateway (RNNGA-, 2.0.0)
0;255;3;0;9;TSM:INIT
0;255;3;0;9;TSM:RADIO:OK
0;255;3;0;9;TSM:GW MODE
0;255;3;0;9;TSM:READY
IP: 192.168.1.9
0;255;3;0;9;No registration required
0;255;3;0;9;Init complete, id=0, parent=0, distance=0, registration=1
0;255;3;0;9;TSP:SANCHK:OK
0;255;3;0;9;TSP:SANCHK:OK
0;255;3;0;9;Eth: connect
0;255;3;0;9;Eth: 0;0;3;0;2;
0;255;3;0;9;Eth: 
0;255;3;0;9;Eth: 0;0;3;0;2;
0;255;3;0;9;Eth: 
0;255;3;0;9;Eth: 0;0;3;0;2;
0;255;3;0;9;Eth: 
0;255;3;0;9;Eth: 0;0;3;0;2;
0;255;3;0;9;Eth: 
0;255;3;0;9;Eth: 0;0;3;0;2;
0;255;3;0;9;Eth: 
0;255;3;0;9;Eth: disconnect
0;255;3;0;9;TSP:SANCHK:OK
0;255;3;0;9;Eth: connect
0;255;3;0;9;Eth: 0;0;3;0;2;
0;255;3;0;9;Eth: 
0;255;3;0;9;Eth: 0;0;3;0;2;
0;255;3;0;9;Eth: 
0;255;3;0;9;Eth: 0;0;3;0;2;
0;255;3;0;9;Eth: 
0;255;3;0;9;Eth: 0;0;3;0;2;
0;255;3;0;9;Eth: 
0;255;3;0;9;Eth: 0;0;3;0;2;
0;255;3;0;9;Eth: 
0;255;3;0;9;Eth: disconnect
0;255;3;0;9;TSP:SANCHK:OK
0;255;3;0;9;TSP:SANCHK:OK
0;255;3;0;9;TSP:MSG:READ 1-1-255 s=255,c=3,t=7,pt=0,l=0,sg=0:
0;255;3;0;9;TSP:MSG:BC
0;255;3;0;9;TSP:MSG:FPAR REQ (sender=1)
0;255;3;0;9;TSP:CHKUPL:OK
0;255;3;0;9;TSP:MSG:GWL OK
0;255;3;0;9;TSP:MSG:SEND 0-0-1-1 s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=ok:0
0;255;3;0;9;TSP:MSG:READ 1-1-0 s=255,c=3,t=24,pt=1,l=1,sg=0:1
0;255;3;0;9;TSP:MSG:PINGED (ID=1, hops=1)
0;255;3;0;9;TSP:MSG:SEND 0-0-1-1 s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=ok:1
0;255;3;0;9;TSP:MSG:READ 1-1-0 s=255,c=3,t=15,pt=6,l=2,sg=0:0100
0;255;3;0;9;!TSP:MSG:SEND 0-0-1-1 s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=fail:0100
0;255;3;0;9;TSP:MSG:READ 1-1-0 s=255,c=3,t=6,pt=1,l=1,sg=0:0
0;255;3;0;9;TSP:MSG:READ 1-1-0 s=255,c=3,t=11,pt=0,l=13,sg=0:Motion Sensor
0;255;3;0;9;TSP:MSG:READ 1-1-0 s=255,c=3,t=12,pt=0,l=3,sg=0:1.0
0;255;3;0;9;TSP:MSG:READ 1-1-0 s=1,c=0,t=1,pt=0,l=0,sg=0:
0;255;3;0;9;TSP:MSG:READ 1-1-0 s=255,c=3,t=26,pt=1,l=1,sg=0:2
0;255;3;0;9;TSP:MSG:SEND 0-0-1-1 s=255,c=3,t=27,pt=1,l=1,sg=0,ft=0,st=ok:1
0;255;3;0;9;TSP:MSG:READ 1-1-0 s=1,c=1,t=16,pt=0,l=1,sg=0:0
0;255;3;0;9;TSP:MSG:READ 1-1-0 s=1,c=1,t=16,pt=0,l=1,sg=0:1
0;255;3;0;9;TSP:MSG:READ 1-1-0 s=1,c=1,t=16,pt=0,l=1,sg=0:0
0;255;3;0;9;TSP:SANCHK:OK

The telnet connection shows no action and the gateway device is on the local network

$ telnet 192.168.1.9 5003
Trying 192.168.1.9...
Connected to 192.168.1.9.
Escape character is '^]'.

$ arp -a
HPB482AF (192.168.1.2) at 28:92:4a:c0:c3:27 [ether] on wlan0
WIZnet9FFEED (192.168.1.9) at de:ad:b1:9f:fe:ed [ether] on wlan0
NB604N.Home (192.168.1.1) at 00:60:64:83:50:8b [ether] on wlan0
HF-LPB100 (192.168.1.12) at f0:fe:6b:16:a1:4a [ether] on wlan0

I have tried all sorts of ubuntu firewall settings to allow access to and from 192.168.1.9 port 5003 and also looked into the router settings with no joy.

As another approach I tried the serial gateway and investigated the linux settings given in
http://docs.openhab.org/installation/linux.html#privileges-for-common-peripherals

The furthest I got with the serial gateway was as follows, first the debug log at startup and then when creating the gateway thing in the paper ui

10:07:04.218 [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=197, service.id=340, service.bundleid=250, service.scope=bundle} - org.openhab.binding.mysensors
10:07:04.219 [DEBUG] [org.openhab.binding.mysensors       ] - BundleEvent STARTED – org.openhab.binding.mysensors
10:08:52.520 [DEBUG] [org.openhab.binding.mysensors       ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=341, service.bundleid=250, service.scope=singleton} – org.openhab.binding.mysensors

10:08:52.524 [DEBUG] [ernal.handler.MySensorsBridgeHandler] - Initialization of the MySensors bridge
10:08:52.526 [DEBUG] [col.serial.MySensorsSerialConnection] - Set skip check on startup to: false
10:08:52.526 [DEBUG] [col.serial.MySensorsSerialConnection] - Enabling connection watchdog
10:08:52.527 [DEBUG] [col.serial.MySensorsSerialConnection] - Connecting to ttyUSB1 [baudRate:115200]
10:08:52.530 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache file: given_ids.cached exist.
10:08:52.531 [DEBUG] [ternal.factory.MySensorsCacheFactory] - Cache (given_ids) content: []
10:08:52.532 [DEBUG] [ernal.handler.MySensorsBridgeHandler] - Initialization of the MySensors bridge DONE!

testRead() open failed: /dev/ttyUSB1

localClose: File Descriptor error, not closing

testRead() open failed: /dev/ttyUSB1

localClose: File Descriptor error, not closing

testRead() open failed: /dev/ttyUSB1

localClose: File Descriptor error, not closing
10:08:52.545 [DEBUG] [col.serial.MySensorsSerialConnection] - Final port list: ttyUSB1:/dev/ttyUSB1

testRead() open failed: ttyUSB1

localClose: File Descriptor error, not closing
Failed to connect on port: ttyUSB1 exception: 
gnu.io.NoSuchPortException

While my plan was to test on my ubuntu 16.04 laptop, I have gone ahead and ordered a Raspberry pi 3 and intend to install the openhabianpi img file. Hopefully better progress there...

[balder88]

Hey guys, first message on this forum. Been reading alot before. But now I have a problem I just can't solve.
It's about smartsleep with openhab 2.
Im using wifi gw rfm 69.
Regular messages works as it should both ways.
But it almost seems like the smartsleep isn't enabled in the binding.
Here are my configs and logs.

Things file:

Bridge mysensors:bridge-eth:gw69 [ ipAddress="192.168.1.235", tcpPort=5003, sendDelay=100, enableNetworkSanCheck=true ] {
//  Anarduino
    humidity        AnHum   [ nodeId="66", childId="0" ]
    temperature     AnTemp  [ nodeId="66", childId="1" ]
    light           light02 [ nodeId="66", childId="3", smartSleep=true ]
  }

Items file:

Switch  TestLight   "Test lampa" (Test) { channel="mysensors:light:gw69:light02:status" }

Sketch: (Cleaned up the parts that dont matter, RTC and so on.)

// Enable debug prints to serial monitor
#define MY_DEBUG 

// Enable and select radio type attached
#define MY_RADIO_RFM69
#define MY_IS_RFM69HW
#define MY_NODE_ID 66
#define MY_RFM69_NETWORKID 100
#define MY_RFM69_FREQUENCY RF69_433MHZ
#define MY_SMART_SLEEP_WAIT_DURATION_MS 1000
#include <MySensors.h>
#include <TimeLib.h>
#include <Wire.h>
#include <MCP7940RTC.h>
#include <DHT.h>

#define MCP7940_CTRL_ID 0x6F
#define CSMEM_PIN 5

#define LEDPIN 9

long sleepIntervalSec=5;
long loopCnt=0;
uint8_t d[8];
uint8_t dAlarm[8];
int d1[8];

// Set this to the pin you connected the DHT's data pin to
#define DHT_DATA_PIN 6

// Set this offset if the sensor has a permanent small offset to the real temperatures
#define SENSOR_TEMP_OFFSET 0

// Sleep time between sensor updates (in milliseconds)
// Must be >1000ms for DHT22 and >2000ms for DHT11
static const uint64_t UPDATE_INTERVAL = 5000;

// Force sending an update of the temperature after n sensor reads, so a controller showing the
// timestamp of the last update doesn't show something like 3 hours in the unlikely case, that
// the value didn't change since;
// i.e. the sensor would force sending an update every UPDATE_INTERVAL*FORCE_UPDATE_N_READS [ms]
static const uint8_t FORCE_UPDATE_N_READS = 10;

#define CHILD_ID_HUM 0
#define CHILD_ID_TEMP 1
#define CHILD_ID_MULTIMETER 2

float lastTemp;
float lastHum;
uint8_t nNoUpdatesTemp;
uint8_t nNoUpdatesHum;
bool metric = true;

MyMessage msgHum(CHILD_ID_HUM, V_HUM);
MyMessage msgTemp(CHILD_ID_TEMP, V_TEMP);
MyMessage msgVolt(CHILD_ID_MULTIMETER, V_VOLTAGE);

DHT dht;

int BATTERY_SENSE_PIN = A0;  // select the input pin for the battery sense point
int oldBatteryPcnt = 0;
int batteryBasement = 812;
int batteryFull = 922;
float batteryConstant = 100.0 / (batteryFull - batteryBasement);
float lastbatteryV = 0;

const int buzzer = 7; //buzzer to arduino pin 7

#define RELAY_1  8  // Arduino Digital I/O pin number for first relay (second on pin+1 etc)
#define NUMBER_OF_RELAYS 1 // Total number of attached relays
#define RELAY_ON 1  // GPIO value to write to turn on attached relay
#define RELAY_OFF 0 // GPIO value to write to turn off attached relay

void before()
{
  for (int sensor=3, pin=RELAY_1; sensor<=NUMBER_OF_RELAYS; sensor++, pin++) {
    // Then set relay pins in output mode
    pinMode(pin, OUTPUT);
    // Set relay to last known state (using eeprom storage)
    digitalWrite(pin, loadState(sensor)?RELAY_ON:RELAY_OFF);
  }
}

void setup()  
{
   // use the 1.1 V internal reference
   analogReference(INTERNAL);

  pinMode(LEDPIN, OUTPUT);
  digitalWrite(LEDPIN, LOW);
  Wire.begin();
  pinMode(CSMEM_PIN, OUTPUT);
  digitalWrite(CSMEM_PIN, HIGH);

   dht.setup(DHT_DATA_PIN); // set data pin of DHT sensor
  if (UPDATE_INTERVAL <= dht.getMinimumSamplingPeriod()) {
    Serial.println("Warning: UPDATE_INTERVAL is smaller than supported by the sensor!");
  }
  // Sleep for the time of the minimum sampling period to give the sensor time to power up
  // (otherwise, timeout errors might occure for the first reading)
  sleepIntervalSec = dht.getMinimumSamplingPeriod();
  clearAlarm();
  delay(20);
  setNewAlarm();
  sleep(dht.getMinimumSamplingPeriod());
  analogRead(BATTERY_SENSE_PIN);
 }

void presentation() {
   // Send the sketch version information to the gateway and Controller
   sendSketchInfo("Humidity sensor", "1.0");
   present(CHILD_ID_MULTIMETER, S_MULTIMETER, "VOLT", true);
   present(CHILD_ID_HUM, S_HUM, "HUMIDITY", true);
   present(CHILD_ID_TEMP, S_TEMP, "TEMP", true);
  for (int sensor=1, pin=RELAY_1; sensor<=NUMBER_OF_RELAYS; sensor++, pin++) {
    // Register all sensors to gw (they will be created as child devices)
    present(sensor, S_BINARY);
  }
  metric = getControllerConfig().isMetric;
}


void loop()
{
  wait(100);
   int sensorValue = analogRead(BATTERY_SENSE_PIN);
   #ifdef MY_DEBUG
   Serial.println(sensorValue);
   #endif
   float batteryV  = sensorValue * 0.004551646;
   if(sensorValue < batteryBasement) {
    sensorValue = batteryBasement;
    batteryV = 0;
   }
   else if (sensorValue > batteryFull) {
    sensorValue = batteryFull;
   }
   int batteryPcnt = (sensorValue - batteryBasement) * batteryConstant;
       if ((abs(oldBatteryPcnt - batteryPcnt) > 1)) {
      sendBatteryLevel(batteryPcnt);
      oldBatteryPcnt = batteryPcnt;
    }
   
   if(batteryV != lastbatteryV) {
   send(msgVolt.set(batteryV, 2));
   lastbatteryV = batteryV;
   }
   #ifdef MY_DEBUG
   Serial.print("Battery Voltage: ");
   Serial.print(batteryV);
   Serial.println(" V");
   Serial.print("Battery percent: ");
   Serial.print(batteryPcnt);
   Serial.println(" %");
   #endif

  // Force reading sensor, so it works also after sleep()
  dht.readSensor(true);

  // Get temperature from DHT library
  float temperature = dht.getTemperature();
  if (isnan(temperature)) {
    Serial.println("Failed reading temperature from DHT!");
  } else if (temperature != lastTemp || nNoUpdatesTemp == FORCE_UPDATE_N_READS) {
    // Only send temperature if it changed since the last measurement or if we didn't send an update for n times
    lastTemp = temperature;
    if (!metric) {
      temperature = dht.toFahrenheit(temperature);
    }
    // Reset no updates counter
    nNoUpdatesTemp = 0;
    temperature += SENSOR_TEMP_OFFSET;
    send(msgTemp.set(temperature, 1));
    #ifdef MY_DEBUG
    Serial.print("T: ");
    Serial.println(temperature);
    #endif
  } else {
    // Increase no update counter if the temperature stayed the same
    nNoUpdatesTemp++;
  }

  // Get humidity from DHT library
  float humidity = dht.getHumidity();
  if (isnan(humidity)) {
    Serial.println("Failed reading humidity from DHT");
  } else if (humidity != lastHum || nNoUpdatesHum == FORCE_UPDATE_N_READS) {
    // Only send humidity if it changed since the last measurement or if we didn't send an update for n times
    lastHum = humidity;
    // Reset no updates counter
    nNoUpdatesHum = 0;
    send(msgHum.set(humidity, 1));

    #ifdef MY_DEBUG
    Serial.print("H: ");
    Serial.println(humidity);
    #endif
  } else {
    // Increase no update counter if the humidity stayed the same
    nNoUpdatesHum++;
  }
long sleepTime = UPDATE_INTERVAL;
if (batteryPcnt < 50) {
  sleepTime = (sleepTime * 2);
}
  // Sleep for a while to save energy
  sleepIntervalSec = sleepTime / 1000;
  Serial.println();
  Serial.print("Setting new sleep time: ");
  Serial.print(sleepIntervalSec);
  Serial.println(" seconds.");
  clearAlarm();
  delay(20);
  setNewAlarm();
  smartSleep(sleepTime);

}

void receive(const MyMessage &message)
{
  // We only expect one type of message from controller. But we better check anyway.
  if (message.type==V_STATUS) {
    // Change relay state
    digitalWrite(message.sensor-1+RELAY_1, message.getBool()?RELAY_ON:RELAY_OFF);
    // Store state in eeprom
    saveState(message.sensor, message.getBool());
    // Write some debug info
    Serial.print("Incoming change for sensor:");
    Serial.print(message.sensor);
    Serial.print(", New status: ");
    Serial.println(message.getBool());
  }
}

Sensor startup:

0 MCO:BGN:INIT NODE,CP=RRNNA--,VER=2.1.1
3 MCO:BGN:BFR
4 TSM:INIT
5 TSF:WUR:MS=0
8 TSM:INIT:TSP OK
9 TSM:INIT:STATID=66
11 TSF:SID:OK,ID=66
13 TSM:FPAR
143 TSF:MSG:SEND,66-66-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
524 TSF:MSG:READ,0-0-66,s=255,c=3,t=8,pt=1,l=1,sg=0:0
529 TSF:MSG:FPAR OK,ID=0,D=1
2150 TSM:FPAR:OK
2151 TSM:ID
2152 TSM:ID:OK
2154 TSM:UPL
2161 TSF:MSG:SEND,66-66-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
2181 TSF:MSG:READ,0-0-66,s=255,c=3,t=25,pt=1,l=1,sg=0:1
2186 TSF:MSG:PONG RECV,HP=1
2189 TSM:UPL:OK
2190 TSM:READY:ID=66,PAR=0,DIS=1
2199 TSF:MSG:SEND,66-66-0-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100
2253 TSF:MSG:READ,0-0-66,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
2310 TSF:MSG:SEND,66-66-0-0,s=255,c=0,t=17,pt=0,l=5,sg=0,ft=0,st=OK:2.1.1
2366 TSF:MSG:SEND,66-66-0-0,s=255,c=3,t=6,pt=1,l=1,sg=0,ft=0,st=OK:0
2403 TSF:MSG:READ,0-0-66,s=255,c=3,t=6,pt=0,l=1,sg=0:M
2461 TSF:MSG:SEND,66-66-0-0,s=255,c=3,t=11,pt=0,l=15,sg=0,ft=0,st=OK:Humidity sensor
2562 TSF:MSG:SEND,66-66-0-0,s=255,c=3,t=12,pt=0,l=3,sg=0,ft=0,st=OK:1.0
2618 TSF:MSG:SEND,66-66-0-0,s=2,c=0,t=30,pt=0,l=4,sg=0,ft=0,st=OK:VOLT
2757 !TSF:MSG:SEND,66-66-0-0,s=0,c=0,t=7,pt=0,l=8,sg=0,ft=0,st=NACK:HUMIDITY
2777 TSF:MSG:SEND,66-66-0-0,s=1,c=0,t=6,pt=0,l=4,sg=0,ft=1,st=OK:TEMP
2912 !TSF:MSG:SEND,66-66-0-0,s=1,c=0,t=3,pt=0,l=0,sg=0,ft=0,st=NACK:
2918 MCO:REG:REQ
2974 TSF:MSG:SEND,66-66-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=1,st=OK:2
2991 TSF:MSG:READ,0-0-66,s=255,c=3,t=27,pt=1,l=1,sg=0:1
2996 MCO:PIM:NODE REG=1
2999 MCO:BGN:STP
3154 MCO:SLP:MS=2000,SMS=0,I1=255,M1=255,I2=255,M2=255
3160 MCO:SLP:TPD
3161 MCO:SLP:WUP=-1
3163 MCO:BGN:INIT OK,TSP=1

Log Sensor: (This is when I press the button when the sensor is awake)
It's sends away it's heartbeat correctly.

125578 TSF:MSG:READ,0-0-66,s=3,c=1,t=2,pt=0,l=1,sg=0:0
Incoming change for sensor:3, New status: 0

Setting new sleep time: 5 seconds.
137926 MCO:SLP:MS=5000,SMS=1,I1=255,M1=255,I2=255,M2=255
137939 TSF:MSG:SEND,66-66-0-0,s=255,c=3,t=22,pt=5,l=4,sg=0,ft=0,st=OK:134932

Log Openhab: And the gateway receives heartbeat.

18:21:37.174 [DEBUG] [rs.internal.protocol.MySensorsWriter] - Sending to MySensors: 66;3;1;0;2;0
18:21:37.178 [INFO ] [smarthome.event.ItemCommandEvent    ] - Item 'TestLight' received command OFF
18:21:37.181 [INFO ] [marthome.event.ItemStateChangedEvent] - TestLight changed from ON to OFF
18:22:15.416 [DEBUG] [rs.internal.protocol.MySensorsReader] - 66;255;3;0;22;134932
18:22:16.372 [DEBUG] [rs.internal.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2;
18:22:16.408 [DEBUG] [rs.internal.protocol.MySensorsReader] - 0;255;3;0;2;2.1.1

Log Openhab: When the node sleeps..

18:26:52.396 [DEBUG] [rs.internal.protocol.MySensorsWriter] - Sending to MySensors: 66;3;1;0;2;0
18:26:52.397 [INFO ] [smarthome.event.ItemCommandEvent    ] - Item 'TestLight' received command OFF
18:26:52.399 [INFO ] [marthome.event.ItemStateChangedEvent] - TestLight changed from ON to OFF

As you can see there is no mention in the openhab log file about buffering or smart sleep. Or a received heartbeat. Which it gets.
What am I doing wrong?