2020-03-19 09:01:45.739 [DEBUG] [org.eclipse.jetty.io.ManagedSelector] - Selector sun.nio.ch.EPollSelectorImpl@4b6ca4b2 woken up from select, 1/1/2 selected 2020-03-19 09:01:45.740 [DEBUG] [org.eclipse.jetty.io.ManagedSelector] - Selector sun.nio.ch.EPollSelectorImpl@4b6ca4b2 processing 1 keys, 0 updates 2020-03-19 09:01:45.740 [DEBUG] [org.eclipse.jetty.io.ManagedSelector] - selected 1 sun.nio.ch.SelectionKeyImpl@7aff7f19 SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=FI,flush=-,to=15273/30000}{io=1/1,kio=1,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=165,c=false,c=false/false,a=IDLE,uri=null,age=0} 2020-03-19 09:01:45.740 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - onSelected 1->0 r=true w=false for SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=FI,flush=-,to=15274/30000}{io=1/0,kio=1,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=165,c=false,c=false/false,a=IDLE,uri=null,age=0} 2020-03-19 09:01:45.740 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - task CEP:SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=FI,flush=-,to=15274/30000}{io=1/0,kio=1,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=165,c=false,c=false/false,a=IDLE,uri=null,age=0}:runFillable:BLOCKING 2020-03-19 09:01:45.741 [DEBUG] [y.util.thread.ReservedThreadExecutor] - ReservedThreadExecutor@1ba966cb{s=2/5,p=0} tryExecute EatWhatYouKill@4456fecf/SelectorProducer@22f5d4c0/PRODUCING/p=false/QueuedThreadPool[qtp2056382618]@7a91e89a{STARTED,2<=16<=50,i=6,r=5,q=0}[ReservedThreadExecutor@1ba966cb{s=2/5,p=0}][pc=3,pic=0,pec=5,epc=86]@2020-03-19T09:01:45.741Z 2020-03-19 09:01:45.741 [DEBUG] [y.util.thread.ReservedThreadExecutor] - ReservedThreadExecutor@1ba966cb{s=1/5,p=0}@6d7c1bea offer EatWhatYouKill@4456fecf/SelectorProducer@22f5d4c0/PRODUCING/p=false/QueuedThreadPool[qtp2056382618]@7a91e89a{STARTED,2<=16<=50,i=6,r=5,q=0}[ReservedThreadExecutor@1ba966cb{s=1/5,p=0}][pc=3,pic=0,pec=5,epc=86]@2020-03-19T09:01:45.741Z 2020-03-19 09:01:45.742 [DEBUG] [y.util.thread.ReservedThreadExecutor] - ReservedThreadExecutor@1ba966cb{s=1/5,p=0}@6d7c1bea task=EatWhatYouKill@4456fecf/SelectorProducer@22f5d4c0/IDLE/p=true/QueuedThreadPool[qtp2056382618]@7a91e89a{STARTED,2<=16<=50,i=6,r=5,q=0}[ReservedThreadExecutor@1ba966cb{s=1/5,p=0}][pc=3,pic=0,pec=5,epc=86]@2020-03-19T09:01:45.742Z 2020-03-19 09:01:45.742 [DEBUG] [.util.thread.strategy.EatWhatYouKill] - EatWhatYouKill@4456fecf/SelectorProducer@22f5d4c0/IDLE/p=true/QueuedThreadPool[qtp2056382618]@7a91e89a{STARTED,2<=16<=50,i=6,r=5,q=0}[ReservedThreadExecutor@1ba966cb{s=1/5,p=0}][pc=3,pic=0,pec=5,epc=86]@2020-03-19T09:01:45.742Z m=EXECUTE_PRODUCE_CONSUME t=CEP:SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=FI,flush=-,to=15275/30000}{io=1/0,kio=1,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=165,c=false,c=false/false,a=IDLE,uri=null,age=0}:runFillable:BLOCKING/BLOCKING 2020-03-19 09:01:45.742 [DEBUG] [.util.thread.strategy.EatWhatYouKill] - EatWhatYouKill@4456fecf/SelectorProducer@22f5d4c0/IDLE/p=true/QueuedThreadPool[qtp2056382618]@7a91e89a{STARTED,2<=16<=50,i=6,r=5,q=0}[ReservedThreadExecutor@1ba966cb{s=1/5,p=0}][pc=3,pic=0,pec=5,epc=87]@2020-03-19T09:01:45.742Z tryProduce true 2020-03-19 09:01:45.742 [DEBUG] [org.eclipse.jetty.io.FillInterest ] - fillable FillInterest@28e9d11e{AC.ReadCB@67d4a332{HttpConnection@67d4a332::SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=FI,flush=-,to=15276/30000}{io=1/0,kio=1,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=165,c=false,c=false/false,a=IDLE,uri=null,age=0}}} 2020-03-19 09:01:45.742 [DEBUG] [org.eclipse.jetty.io.ManagedSelector] - updateable 0 2020-03-19 09:01:45.742 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@67d4a332::SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=-,flush=-,to=15276/30000}{io=1/0,kio=1,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=165,c=false,c=false/false,a=IDLE,uri=null,age=0} onFillable enter HttpChannelState@288a317f{s=IDLE a=NOT_ASYNC i=true r=IDLE w=false} null 2020-03-19 09:01:45.743 [DEBUG] [org.eclipse.jetty.io.ManagedSelector] - updates 0 2020-03-19 09:01:45.743 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 529 HeapByteBuffer@3eef0430[p=0,l=529,c=8192,r=529]={<<>>"}\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} 2020-03-19 09:01:45.743 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - Key interests updated 1 -> 0 on SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=165,c=false,c=false/false,a=IDLE,uri=null,age=0} 2020-03-19 09:01:45.743 [DEBUG] [org.eclipse.jetty.io.ManagedSelector] - Selector sun.nio.ch.EPollSelectorImpl@4b6ca4b2 waiting with 2 keys 2020-03-19 09:01:45.743 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@67d4a332::SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=165,c=false,c=false/false,a=IDLE,uri=null,age=0} filled 529 HeapByteBuffer@3eef0430[p=0,l=529,c=8192,r=529]={<<>>"}\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} 2020-03-19 09:01:45.743 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@67d4a332::SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=165,c=false,c=false/false,a=IDLE,uri=null,age=0} parse HeapByteBuffer@3eef0430[p=0,l=529,c=8192,r=529]={<<>>"}\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} {} 2020-03-19 09:01:45.744 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - parseNext s=START HeapByteBuffer@3eef0430[p=0,l=529,c=8192,r=529]={<<>>"}\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} 2020-03-19 09:01:45.744 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - START --> SPACE1 2020-03-19 09:01:45.744 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - SPACE1 --> URI 2020-03-19 09:01:45.744 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - URI --> SPACE2 2020-03-19 09:01:45.744 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - SPACE2 --> REQUEST_VERSION 2020-03-19 09:01:45.745 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - REQUEST_VERSION --> HEADER 2020-03-19 09:01:45.745 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Host: 192.168.1.10:8080 --> IN_VALUE 2020-03-19 09:01:45.745 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Host: 192.168.1.10:8080 --> FIELD 2020-03-19 09:01:45.746 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Connection: keep-alive --> IN_VALUE 2020-03-19 09:01:45.746 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Connection: keep-alive --> FIELD 2020-03-19 09:01:45.746 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Content-Length --> VALUE 2020-03-19 09:01:45.746 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Content-Length --> IN_VALUE 2020-03-19 09:01:45.747 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Content-Length --> FIELD 2020-03-19 09:01:45.747 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Accept: application/json, text/plain, */* --> IN_VALUE 2020-03-19 09:01:45.747 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Accept: application/json, text/plain, */* --> FIELD 2020-03-19 09:01:45.747 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/80.0.3987.116 Safari/537.36 --> IN_VALUE 2020-03-19 09:01:45.748 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/80.0.3987.116 Safari/537.36 --> FIELD 2020-03-19 09:01:45.748 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Content-Type: application/json;charset=UTF-8 --> IN_VALUE 2020-03-19 09:01:45.748 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Content-Type: application/json;charset=UTF-8 --> FIELD 2020-03-19 09:01:45.748 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Origin --> VALUE 2020-03-19 09:01:45.749 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Origin --> IN_VALUE 2020-03-19 09:01:45.749 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Origin --> FIELD 2020-03-19 09:01:45.749 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Referer --> VALUE 2020-03-19 09:01:45.749 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Referer --> IN_VALUE 2020-03-19 09:01:45.750 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Referer --> FIELD 2020-03-19 09:01:45.750 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Accept-Encoding: gzip, deflate --> IN_VALUE 2020-03-19 09:01:45.750 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Accept-Encoding: gzip, deflate --> FIELD 2020-03-19 09:01:45.750 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Accept-Language: nl-NL,nl;q=0.9,en-US;q=0.8,en;q=0.7 --> IN_VALUE 2020-03-19 09:01:45.751 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER:Accept-Language: nl-NL,nl;q=0.9,en-US;q=0.8,en;q=0.7 --> FIELD 2020-03-19 09:01:45.751 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - HEADER --> CONTENT 2020-03-19 09:01:45.751 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - REQUEST for //192.168.1.10:8080/rest/extensions/binding-http1/install on HttpChannelOverHttp@76b57edb{r=166,c=false,c=false/false,a=IDLE,uri=//192.168.1.10:8080/rest/extensions/binding-http1/install,age=0} POST //192.168.1.10:8080/rest/extensions/binding-http1/install HTTP/1.1 Host: 192.168.1.10:8080 Connection: keep-alive Content-Length: 22 Accept: application/json, text/plain, */* User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/80.0.3987.116 Safari/537.36 Content-Type: application/json;charset=UTF-8 Origin: http://192.168.1.10:8080 Referer: http://192.168.1.10:8080/paperui/index.html Accept-Encoding: gzip, deflate Accept-Language: nl-NL,nl;q=0.9,en-US;q=0.8,en;q=0.7 2020-03-19 09:01:45.751 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@67d4a332::SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=-,flush=-,to=8/30000}{io=0/0,kio=0,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=CONTENT,0 of 22},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=166,c=false,c=false/false,a=IDLE,uri=//192.168.1.10:8080/rest/extensions/binding-http1/install,age=0} parsed true HttpParser{s=CONTENT,0 of 22} 2020-03-19 09:01:45.752 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@76b57edb{r=166,c=false,c=false/false,a=IDLE,uri=//192.168.1.10:8080/rest/extensions/binding-http1/install,age=1} handle //192.168.1.10:8080/rest/extensions/binding-http1/install 2020-03-19 09:01:45.752 [DEBUG] [clipse.jetty.server.HttpChannelState] - handling HttpChannelState@288a317f{s=IDLE a=NOT_ASYNC i=true r=IDLE w=false} 2020-03-19 09:01:45.752 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@76b57edb{r=166,c=false,c=false/false,a=DISPATCHED,uri=//192.168.1.10:8080/rest/extensions/binding-http1/install,age=1} action DISPATCH 2020-03-19 09:01:45.752 [DEBUG] [org.eclipse.jetty.server.Server ] - REQUEST POST /rest/extensions/binding-http1/install on HttpChannelOverHttp@76b57edb{r=166,c=false,c=false/false,a=DISPATCHED,uri=//192.168.1.10:8080/rest/extensions/binding-http1/install,age=1} 2020-03-19 09:01:45.752 [DEBUG] [ax.web.service.spi.model.ServerModel] - Matching [/rest/extensions/binding-http1/install]... 2020-03-19 09:01:45.753 [DEBUG] [ax.web.service.spi.model.ServerModel] - Path [/rest/extensions/binding-http1/install] matched to {pattern=/rest/.*,model=ServletModel{id=org.ops4j.pax.web.service.spi.model.ServletModel-5,name=org.ops4j.pax.web.service.spi.model.ServletModel-5,urlPatterns=[/rest/*],alias=/rest,servlet=com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge@1da5f45c,initParams={},context=ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-4,name=,httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [19], contextID=default],contextParams={},virtualHosts={},connectors={}}}} 2020-03-19 09:01:45.753 [DEBUG] [.jetty.server.handler.ContextHandler] - scope null||/rest/extensions/binding-http1/install @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [19], contextID=default]} 2020-03-19 09:01:45.753 [DEBUG] [.jetty.server.handler.ContextHandler] - context=||/rest/extensions/binding-http1/install @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [19], contextID=default]} 2020-03-19 09:01:45.753 [DEBUG] [org.eclipse.jetty.server.session ] - SessionHandler.doScope 2020-03-19 09:01:45.754 [DEBUG] [org.eclipse.jetty.server.session ] - sessionHandler=org.eclipse.jetty.server.session.SessionHandler1764392328==dftMaxIdleSec=600 session=null 2020-03-19 09:01:45.754 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - servlet |/rest|/extensions/binding-http1/install -> org.ops4j.pax.web.service.spi.model.ServletModel-5@378be0fd==com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge,jsp=null,order=-1,inst=true,async=true 2020-03-19 09:01:45.754 [DEBUG] [ce.jetty.internal.HttpServiceContext] - Handling request for [/rest/extensions/binding-http1/install] using http context [DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [19], contextID=default]] 2020-03-19 09:01:45.754 [DEBUG] [y.internal.HttpServiceServletHandler] - handling request org.ops4j.pax.web.service.jetty.internal.HttpServiceRequestWrapper@249c7248, org.ops4j.pax.web.service.jetty.internal.HttpServiceResponseWrapper@170922b5 2020-03-19 09:01:45.755 [DEBUG] [eclipse.jetty.servlet.ServletHandler] - chain=null 2020-03-19 09:01:45.756 [DEBUG] [org.eclipse.jetty.server.session ] - FinalSession=null, old_session_handler=null, this=org.eclipse.jetty.server.session.SessionHandler1764392328==dftMaxIdleSec=600, calling complete=true 2020-03-19 09:01:45.757 [DEBUG] [org.eclipse.jetty.server.session ] - Complete called with session null 2020-03-19 09:01:45.757 [DEBUG] [org.eclipse.jetty.server.Server ] - handled=true async=false committed=false on HttpChannelOverHttp@76b57edb{r=166,c=false,c=false/false,a=DISPATCHED,uri=//192.168.1.10:8080/rest/extensions/binding-http1/install,age=6} 2020-03-19 09:01:45.757 [DEBUG] [clipse.jetty.server.HttpChannelState] - unhandle HttpChannelState@288a317f{s=DISPATCHED a=NOT_ASYNC i=true r=IDLE w=false} 2020-03-19 09:01:45.757 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@76b57edb{r=166,c=false,c=false/false,a=COMPLETING,uri=//192.168.1.10:8080/rest/extensions/binding-http1/install,age=6} action COMPLETE 2020-03-19 09:01:45.758 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=HeapByteBuffer@207fe958[p=0,l=0,c=0,r=0]={<<<>>>} complete=true committing=true callback=Blocker@1d2b76b8{null} 2020-03-19 09:01:45.758 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - COMMIT for /rest/extensions/binding-http1/install on HttpChannelOverHttp@76b57edb{r=166,c=true,c=false/false,a=COMPLETING,uri=//192.168.1.10:8080/rest/extensions/binding-http1/install,age=7} 200 OK HTTP/1.1 Content-Type: text/plain 2020-03-19 09:01:45.758 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@6e347c35[PROCESSING][i=HTTP/1.1{s=200,h=1,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$SendCallback@be7bfcf] generate: NEED_HEADER (null,[p=0,l=0,c=0,r=0],true)@START 2020-03-19 09:01:45.758 [DEBUG] [org.apache.felix.configadmin ] - getConfiguration(pid=org.openhab.addons, location=null) 2020-03-19 09:01:45.758 [DEBUG] [org.eclipse.jetty.http.HttpGenerator] - generateHeaders HTTP/1.1{s=200,h=1,cl=-1} last=true content=HeapByteBuffer@207fe958[p=0,l=0,c=0,r=0]={<<<>>>} 2020-03-19 09:01:45.759 [DEBUG] [org.apache.felix.configadmin ] - Found cached configuration org.openhab.addons bound to mvn:org.openhab.core.bundles/org.openhab.core.karaf/2.5.0 2020-03-19 09:01:45.759 [DEBUG] [org.eclipse.jetty.http.HttpGenerator] - Content-Type: text/plain 2020-03-19 09:01:45.759 [DEBUG] [org.eclipse.jetty.http.HttpGenerator] - CONTENT_LENGTH 2020-03-19 09:01:45.759 [DEBUG] [org.apache.felix.configadmin ] - update(properties={action=, binding=boschindego,http1, legacy=true, misc=, package=standard, persistence=, service.pid=org.openhab.addons, transformation=, ui=paper, voice=}) 2020-03-19 09:01:45.759 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@6e347c35[PROCESSING][i=HTTP/1.1{s=200,h=1,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$SendCallback@be7bfcf] generate: FLUSH ([p=0,l=97,c=8192,r=97],[p=0,l=0,c=0,r=0],true)@COMPLETING 2020-03-19 09:01:45.759 [DEBUG] [org.apache.felix.configadmin ] - Updating config org.openhab.addons with {action=, binding=boschindego,http1, legacy=true, misc=, package=standard, persistence=, service.pid=org.openhab.addons, transformation=, ui=paper, voice=} 2020-03-19 09:01:45.759 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - write: WriteFlusher@5a631f33{IDLE}->null [HeapByteBuffer@36042eac[p=0,l=97,c=8192,r=97]={<<>>son, text/plain, ...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}] 2020-03-19 09:01:45.760 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@5a631f33{WRITING}->null:IDLE-->WRITING 2020-03-19 09:01:45.760 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 97 SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=-,flush=W,to=17/30000}{io=0/0,kio=0,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=CONTENT,0 of 22},g=HttpGenerator@75772acd{s=COMPLETING}]=>HttpChannelOverHttp@76b57edb{r=166,c=true,c=false/false,a=COMPLETING,uri=//192.168.1.10:8080/rest/extensions/binding-http1/install,age=9} 2020-03-19 09:01:45.760 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - Flushed=true written=97 remaining=0 WriteFlusher@5a631f33{WRITING}->null 2020-03-19 09:01:45.760 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@5a631f33{IDLE}->null:WRITING-->IDLE 2020-03-19 09:01:45.760 [DEBUG] [org.apache.felix.configadmin ] - No SynchronousConfigurationListeners to send CM_UPDATED event to. 2020-03-19 09:01:45.761 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@6e347c35[PROCESSING][i=HTTP/1.1{s=200,h=1,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$SendCallback@be7bfcf] generate: DONE ([p=97,l=97,c=8192,r=0],[p=0,l=0,c=0,r=0],true)@END 2020-03-19 09:01:45.761 [DEBUG] [org.apache.felix.configadmin ] - Scheduling task Fire ConfigurationEvent: pid=org.openhab.addons 2020-03-19 09:01:45.761 [DEBUG] [org.apache.felix.configadmin ] - Running task Fire ConfigurationEvent: pid=org.openhab.addons 2020-03-19 09:01:45.761 [DEBUG] [org.apache.felix.configadmin ] - Scheduling task Update: pid=org.openhab.addons 2020-03-19 09:01:45.761 [DEBUG] [org.apache.felix.configadmin ] - Sending CM_UPDATED event for org.openhab.addons to [org.openhab.core.karaf.internal.FeatureInstaller, org.osgi.service.cm.ConfigurationListener, id=233, bundle=160/mvn:org.openhab.core.bundles/org.openhab.core.karaf/2.5.0] 2020-03-19 09:01:45.761 [DEBUG] [org.apache.felix.configadmin ] - UpdateConfiguration(org.openhab.addons) scheduled 2020-03-19 09:01:45.761 [DEBUG] [org.apache.felix.configadmin ] - Sending CM_UPDATED event for org.openhab.addons to [org.osgi.service.cm.ConfigurationListener, id=122, bundle=9/mvn:org.apache.felix/org.apache.felix.configadmin/1.9.16] 2020-03-19 09:01:45.761 [DEBUG] [org.apache.felix.configadmin ] - Running task Update: pid=org.openhab.addons 2020-03-19 09:01:45.762 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(service.pid=org.openhab.addons)) 2020-03-19 09:01:45.762 [DEBUG] [org.apache.felix.configadmin ] - Updating configuration org.openhab.addons to revision #127 2020-03-19 09:01:45.762 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (service.pid=org.openhab.addons) 2020-03-19 09:01:45.762 [DEBUG] [org.apache.felix.configadmin ] - Adding configuration org.openhab.addons 2020-03-19 09:01:45.763 [DEBUG] [org.apache.felix.configadmin ] - getConfiguration(pid=org.ops4j.pax.url.mvn, location=null) 2020-03-19 09:01:45.763 [DEBUG] [org.apache.felix.configadmin ] - Found cached configuration org.ops4j.pax.url.mvn bound to ? 2020-03-19 09:01:45.763 [DEBUG] [org.apache.felix.configadmin ] - getConfiguration(pid=org.ops4j.pax.url.mvn, location=null) 2020-03-19 09:01:45.764 [DEBUG] [org.apache.felix.configadmin ] - Found cached configuration org.ops4j.pax.url.mvn bound to ? 2020-03-19 09:01:45.761 [DEBUG] [clipse.jetty.server.HttpChannelState] - onComplete HttpChannelState@288a317f{s=COMPLETING a=NOT_ASYNC i=false r=IDLE w=false} 2020-03-19 09:01:45.765 [DEBUG] [ps4j.pax.url.mvn.internal.Connection] - Resolving [mvn:org.openhab.distro/openhab-addons-legacy/2.5.2/xml/features] 2020-03-19 09:01:45.765 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - COMPLETE for /rest/extensions/binding-http1/install written=0 2020-03-19 09:01:45.765 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent MODIFIED - {org.openhab.core.karaf.internal.FeatureInstaller, org.osgi.service.cm.ConfigurationListener}={action=, package=standard, service.id=233, service.bundleid=160, service.scope=bundle, binding=boschindego,http1, persistence=, transformation=, misc=, component.name=org.openhab.addons, service.config.label=Add-on Management, component.id=104, ui=paper, voice=, service.config.category=system, legacy=true, service.config.description.uri=system:addons, service.pid=org.openhab.addons} 2020-03-19 09:01:45.765 [DEBUG] [.eclipse.jetty.server.HttpConnection] - unconsumed input HttpConnection@67d4a332::SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=-,flush=-,to=5/30000}{io=0/0,kio=0,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=CONTENT,0 of 22},g=HttpGenerator@75772acd{s=END}]=>HttpChannelOverHttp@76b57edb{r=166,c=true,c=true/true,a=COMPLETED,uri=//192.168.1.10:8080/rest/extensions/binding-http1/install,age=14} 2020-03-19 09:01:45.766 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@67d4a332::SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=-,flush=-,to=5/30000}{io=0/0,kio=0,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=CONTENT,0 of 22},g=HttpGenerator@75772acd{s=END}]=>HttpChannelOverHttp@76b57edb{r=166,c=true,c=true/true,a=COMPLETED,uri=//192.168.1.10:8080/rest/extensions/binding-http1/install,age=15} parse HeapByteBuffer@3eef0430[p=507,l=529,c=8192,r=22]={POST /rest/extens....8,en;q=0.7\r\n\r\n<<<{"id":"binding-http1"}>>>"}\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} {} 2020-03-19 09:01:45.766 [DEBUG] [org.apache.felix.configadmin ] - Sending CM_UPDATED event for org.openhab.addons to [org.osgi.service.cm.ConfigurationListener, id=41, bundle=13/mvn:org.apache.karaf.shell/org.apache.karaf.shell.core/4.2.7] 2020-03-19 09:01:45.766 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - parseNext s=CONTENT HeapByteBuffer@3eef0430[p=507,l=529,c=8192,r=22]={POST /rest/extens....8,en;q=0.7\r\n\r\n<<<{"id":"binding-http1"}>>>"}\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} 2020-03-19 09:01:45.766 [DEBUG] [org.apache.felix.configadmin ] - Sending CM_UPDATED event for org.openhab.addons to [org.osgi.service.cm.ConfigurationListener, id=70, bundle=47/mvn:org.apache.karaf.config/org.apache.karaf.config.core/4.2.7] 2020-03-19 09:01:45.766 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@76b57edb{r=166,c=true,c=true/true,a=COMPLETED,uri=//192.168.1.10:8080/rest/extensions/binding-http1/install,age=15} onContent Content@1a7a72a3{HeapByteBufferR@5db35d96[p=507,l=529,c=8192,r=22]={POST /rest/extens....8,en;q=0.7\r\n\r\n<<<{"id":"binding-http1"}>>>"}\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}} 2020-03-19 09:01:45.767 [DEBUG] [org.apache.felix.configadmin ] - Sending CM_UPDATED event for org.openhab.addons to [org.osgi.service.cm.ConfigurationListener, org.apache.felix.fileinstall.ArtifactListener, org.apache.felix.fileinstall.ArtifactInstaller, id=40, bundle=10/mvn:org.apache.felix/org.apache.felix.fileinstall/3.6.4] 2020-03-19 09:01:45.767 [DEBUG] [org.apache.felix.configadmin ] - getConfiguration(pid=org.openhab.addons, location=?) 2020-03-19 09:01:45.767 [DEBUG] [org.eclipse.jetty.server.HttpInput ] - HttpInputOverHTTP@31f9bf1a[c=0,q=0,[0]=null,s=STREAM] addContent Content@1a7a72a3{HeapByteBufferR@5db35d96[p=507,l=529,c=8192,r=22]={POST /rest/extens....8,en;q=0.7\r\n\r\n<<<{"id":"binding-http1"}>>>"}\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}} 2020-03-19 09:01:45.767 [DEBUG] [org.apache.felix.configadmin ] - Found cached configuration org.openhab.addons bound to mvn:org.openhab.core.bundles/org.openhab.core.karaf/2.5.0 2020-03-19 09:01:45.767 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - CONTENT --> END 2020-03-19 09:01:45.767 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@76b57edb{r=166,c=true,c=true/true,a=COMPLETED,uri=//192.168.1.10:8080/rest/extensions/binding-http1/install,age=16} onContentComplete 2020-03-19 09:01:45.767 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@76b57edb{r=166,c=true,c=true/true,a=COMPLETED,uri=//192.168.1.10:8080/rest/extensions/binding-http1/install,age=16} onRequestComplete 2020-03-19 09:01:45.768 [DEBUG] [org.eclipse.jetty.server.HttpInput ] - HttpInputOverHTTP@31f9bf1a[c=0,q=1,[0]=EOF,s=STREAM] addContent EOF 2020-03-19 09:01:45.768 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@67d4a332::SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=-,flush=-,to=7/30000}{io=0/0,kio=0,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=END,22 of 22},g=HttpGenerator@75772acd{s=END}]=>HttpChannelOverHttp@76b57edb{r=166,c=true,c=true/true,a=COMPLETED,uri=//192.168.1.10:8080/rest/extensions/binding-http1/install,age=17} parsed false HttpParser{s=END,22 of 22} 2020-03-19 09:01:45.768 [DEBUG] [.eclipse.jetty.server.HttpConnection] - releaseRequestBuffer HttpConnection@67d4a332::SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=-,flush=-,to=7/30000}{io=0/0,kio=0,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=END,22 of 22},g=HttpGenerator@75772acd{s=END}]=>HttpChannelOverHttp@76b57edb{r=166,c=true,c=true/true,a=COMPLETED,uri=//192.168.1.10:8080/rest/extensions/binding-http1/install,age=17} 2020-03-19 09:01:45.768 [DEBUG] [clipse.jetty.server.HttpChannelState] - recycle HttpChannelState@288a317f{s=COMPLETED a=NOT_ASYNC i=false r=IDLE w=false} 2020-03-19 09:01:45.769 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - reset HttpParser{s=END,22 of 22} 2020-03-19 09:01:45.769 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - END --> START 2020-03-19 09:01:45.769 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - HttpChannelOverHttp@76b57edb{r=166,c=false,c=false/false,a=IDLE,uri=null,age=0} handle exit, result COMPLETE 2020-03-19 09:01:45.769 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 HeapByteBuffer@3eef0430[p=0,l=0,c=8192,r=0]={<<<>>>POST /rest/extens...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 2020-03-19 09:01:45.769 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - filled 0 HeapByteBuffer@3eef0430[p=0,l=0,c=8192,r=0]={<<<>>>POST /rest/extens...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 2020-03-19 09:01:45.770 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@67d4a332::SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=-,flush=-,to=9/30000}{io=0/0,kio=0,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=166,c=false,c=false/false,a=IDLE,uri=null,age=0} filled 0 HeapByteBuffer@3eef0430[p=0,l=0,c=8192,r=0]={<<<>>>POST /rest/extens...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 2020-03-19 09:01:45.770 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@67d4a332::SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=-,flush=-,to=9/30000}{io=0/0,kio=0,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=166,c=false,c=false/false,a=IDLE,uri=null,age=0} parse HeapByteBuffer@3eef0430[p=0,l=0,c=8192,r=0]={<<<>>>POST /rest/extens...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} {} 2020-03-19 09:01:45.770 [DEBUG] [org.eclipse.jetty.http.HttpParser ] - parseNext s=START HeapByteBuffer@3eef0430[p=0,l=0,c=8192,r=0]={<<<>>>POST /rest/extens...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 2020-03-19 09:01:45.770 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@67d4a332::SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=-,flush=-,to=9/30000}{io=0/0,kio=0,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=166,c=false,c=false/false,a=IDLE,uri=null,age=0} parsed false HttpParser{s=START,0 of -1} 2020-03-19 09:01:45.770 [DEBUG] [.eclipse.jetty.server.HttpConnection] - releaseRequestBuffer HttpConnection@67d4a332::SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=-,flush=-,to=10/30000}{io=0/0,kio=0,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=166,c=false,c=false/false,a=IDLE,uri=null,age=0} 2020-03-19 09:01:45.771 [DEBUG] [.eclipse.jetty.io.AbstractConnection] - fillInterested HttpConnection@67d4a332::SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=-,flush=-,to=10/30000}{io=0/0,kio=0,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=166,c=false,c=false/false,a=IDLE,uri=null,age=0} 2020-03-19 09:01:45.771 [DEBUG] [org.eclipse.jetty.io.FillInterest ] - interested FillInterest@28e9d11e{AC.ReadCB@67d4a332{HttpConnection@67d4a332::SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=FI,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=166,c=false,c=false/false,a=IDLE,uri=null,age=0}}} 2020-03-19 09:01:45.771 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - changeInterests p=false 0->1 for SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=FI,flush=-,to=0/30000}{io=0/1,kio=0,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=166,c=false,c=false/false,a=IDLE,uri=null,age=0} 2020-03-19 09:01:45.771 [DEBUG] [org.eclipse.jetty.io.ManagedSelector] - Queued change org.eclipse.jetty.io.ChannelEndPoint$1@51111cb5 on ManagedSelector@17fbabc5{STARTED} id=2 keys=2 selected=0 updates=0 2020-03-19 09:01:45.771 [DEBUG] [org.eclipse.jetty.io.ManagedSelector] - Wakeup on submit ManagedSelector@17fbabc5{STARTED} id=2 keys=2 selected=0 updates=1 2020-03-19 09:01:45.772 [DEBUG] [org.eclipse.jetty.io.ManagedSelector] - Selector sun.nio.ch.EPollSelectorImpl@4b6ca4b2 woken with none selected 2020-03-19 09:01:45.772 [DEBUG] [.eclipse.jetty.server.HttpConnection] - HttpConnection@67d4a332::SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=FI,flush=-,to=0/30000}{io=0/1,kio=0,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=166,c=false,c=false/false,a=IDLE,uri=null,age=0} onFillable exit HttpChannelState@288a317f{s=IDLE a=NOT_ASYNC i=true r=IDLE w=false} null 2020-03-19 09:01:45.772 [DEBUG] [org.eclipse.jetty.io.ManagedSelector] - Selector sun.nio.ch.EPollSelectorImpl@4b6ca4b2 woken up from select, 0/0/2 selected 2020-03-19 09:01:45.772 [DEBUG] [y.util.thread.ReservedThreadExecutor] - ReservedThreadExecutor@1ba966cb{s=2/5,p=0}@206d426c waiting 2020-03-19 09:01:45.772 [DEBUG] [org.eclipse.jetty.io.ManagedSelector] - Selector sun.nio.ch.EPollSelectorImpl@4b6ca4b2 processing 0 keys, 1 updates 2020-03-19 09:01:45.772 [DEBUG] [org.eclipse.jetty.io.ManagedSelector] - updateable 1 2020-03-19 09:01:45.772 [DEBUG] [org.eclipse.jetty.io.ManagedSelector] - update org.eclipse.jetty.io.ChannelEndPoint$1@51111cb5 2020-03-19 09:01:45.773 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - Key interests updated 0 -> 1 on SocketChannelEndPoint@13d02c21{/192.168.111.41:56790<->/192.168.1.10:8080,OPEN,fill=FI,flush=-,to=1/30000}{io=1/1,kio=1,kro=1}->HttpConnection@67d4a332[p=HttpParser{s=START,0 of -1},g=HttpGenerator@75772acd{s=START}]=>HttpChannelOverHttp@76b57edb{r=166,c=false,c=false/false,a=IDLE,uri=null,age=0} 2020-03-19 09:01:45.773 [DEBUG] [org.eclipse.jetty.io.ManagedSelector] - updates 0 2020-03-19 09:01:45.773 [DEBUG] [org.eclipse.jetty.io.ManagedSelector] - Selector sun.nio.ch.EPollSelectorImpl@4b6ca4b2 waiting with 2 keys 2020-03-19 09:01:45.777 [INFO ] [internal.service.FeaturesServiceImpl] - Adding features: openhab-binding-http1/[1.14.0,1.14.0] 2020-03-19 09:01:45.777 [DEBUG] [org.apache.felix.configadmin ] - getConfiguration(pid=org.ops4j.pax.url.mvn, location=null) 2020-03-19 09:01:45.778 [DEBUG] [org.apache.felix.configadmin ] - Found cached configuration org.ops4j.pax.url.mvn bound to ? 2020-03-19 09:01:45.788 [DEBUG] [.impl.DefaultLocalRepositoryProvider] - Using manager PaxLocalRepositoryManager with priority 0.0 for /usr/share/openhab2/runtime/system 2020-03-19 09:01:45.791 [DEBUG] [.impl.DefaultLocalRepositoryProvider] - Using manager PaxLocalRepositoryManager with priority 0.0 for /usr/share/openhab2/runtime/system 2020-03-19 09:01:45.798 [DEBUG] [.impl.DefaultLocalRepositoryProvider] - Using manager PaxLocalRepositoryManager with priority 0.0 for /var/lib/openhab2/tmp/kar/openhab-addons-2.5.2 2020-03-19 09:01:45.812 [DEBUG] [.impl.DefaultLocalRepositoryProvider] - Using manager PaxLocalRepositoryManager with priority 0.0 for /var/lib/openhab2/tmp/kar/openhab-addons-2.5.2 2020-03-19 09:01:45.834 [DEBUG] [.impl.DefaultLocalRepositoryProvider] - Using manager PaxLocalRepositoryManager with priority 0.0 for /usr/share/openhab2/runtime/system 2020-03-19 09:01:46.572 [INFO ] [internal.service.FeaturesServiceImpl] - Changes to perform: 2020-03-19 09:01:46.573 [INFO ] [internal.service.FeaturesServiceImpl] - Region: root 2020-03-19 09:01:46.573 [INFO ] [internal.service.FeaturesServiceImpl] - Bundles to uninstall: 2020-03-19 09:01:46.573 [INFO ] [internal.service.FeaturesServiceImpl] - org.apache.httpcomponents.httpclient/4.5.5 2020-03-19 09:01:46.573 [INFO ] [internal.service.FeaturesServiceImpl] - org.apache.httpcomponents.httpcore/4.4.9 2020-03-19 09:01:46.574 [INFO ] [internal.service.FeaturesServiceImpl] - Bundles to install: 2020-03-19 09:01:46.574 [INFO ] [internal.service.FeaturesServiceImpl] - mvn:org.codehaus.jackson/jackson-core-asl/1.9.2 2020-03-19 09:01:46.574 [INFO ] [internal.service.FeaturesServiceImpl] - mvn:org.codehaus.jackson/jackson-mapper-asl/1.9.2 2020-03-19 09:01:46.574 [INFO ] [internal.service.FeaturesServiceImpl] - mvn:commons-collections/commons-collections/3.2.2 2020-03-19 09:01:46.575 [INFO ] [internal.service.FeaturesServiceImpl] - mvn:org.apache.httpcomponents/httpclient-osgi/4.2.3 2020-03-19 09:01:46.575 [INFO ] [internal.service.FeaturesServiceImpl] - mvn:org.apache.httpcomponents/httpcore-osgi/4.2.3 2020-03-19 09:01:46.575 [INFO ] [internal.service.FeaturesServiceImpl] - mvn:org.apache.servicemix.bundles/org.apache.servicemix.bundles.commons-httpclient/3.1_7 2020-03-19 09:01:46.575 [INFO ] [internal.service.FeaturesServiceImpl] - mvn:org.openhab.binding/org.openhab.binding.http/[1.14.0,1.15) 2020-03-19 09:01:46.576 [INFO ] [internal.service.FeaturesServiceImpl] - mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0 2020-03-19 09:01:46.576 [INFO ] [internal.service.FeaturesServiceImpl] - Stopping bundles: 2020-03-19 09:01:46.576 [DEBUG] [f.features.internal.service.Deployer] - Usage for bundle org.apache.httpcomponents.httpcore_4.4.9 [479] is 0 2020-03-19 09:01:46.577 [DEBUG] [f.features.internal.service.Deployer] - Usage for bundle org.apache.httpcomponents.httpclient_4.5.5 [478] is 0 2020-03-19 09:01:46.577 [DEBUG] [f.features.internal.service.Deployer] - Usage for bundle org.openhab.binding.boschindego_2.5.2 [448] is 0 2020-03-19 09:01:46.578 [DEBUG] [f.features.internal.service.Deployer] - Selected bundles [org.apache.httpcomponents.httpcore_4.4.9 [479], org.apache.httpcomponents.httpclient_4.5.5 [478], org.openhab.binding.boschindego_2.5.2 [448]] for destroy (no services in use) 2020-03-19 09:01:46.578 [INFO ] [internal.service.FeaturesServiceImpl] - org.apache.httpcomponents.httpcore/4.4.9 2020-03-19 09:01:46.578 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpcore (479): Starting destruction process 2020-03-19 09:01:46.579 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpcore (479): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.579 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpcore (479): Starting destruction process 2020-03-19 09:01:46.579 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpcore (479): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.580 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STOPPING 2020-03-19 09:01:46.583 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpcore (479): Starting destruction process 2020-03-19 09:01:46.583 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpcore (479): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.583 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STOPPED 2020-03-19 09:01:46.586 [INFO ] [internal.service.FeaturesServiceImpl] - org.apache.httpcomponents.httpclient/4.5.5 2020-03-19 09:01:46.586 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpclient (478): Starting destruction process 2020-03-19 09:01:46.587 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpclient (478): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.587 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpclient (478): Starting destruction process 2020-03-19 09:01:46.587 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpclient (478): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.588 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STOPPING 2020-03-19 09:01:46.593 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent UNREGISTERING - {org.osgi.service.cm.ManagedServiceFactory}={service.description=Apache HTTP Client Proxy Configuration Factory, service.id=382, service.bundleid=478, service.scope=singleton, service.vendor=The Apache Software Foundation, service.pid=org.apache.http.proxyconfigurator} 2020-03-19 09:01:46.593 [DEBUG] [org.apache.felix.configadmin ] - Unregistering service [org.osgi.service.cm.ManagedServiceFactory, id=382, bundle=478/mvn:org.apache.httpcomponents/httpclient-osgi/4.5.5] 2020-03-19 09:01:46.594 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent UNREGISTERING - {org.apache.http.osgi.services.HttpClientBuilderFactory}={service.description=Apache HTTP Client Client Factory, service.id=383, service.bundleid=478, service.scope=singleton, service.vendor=The Apache Software Foundation, service.pid=org.apache.http.httpclientfactory} 2020-03-19 09:01:46.595 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent UNREGISTERING - {org.apache.http.osgi.services.CachingHttpClientBuilderFactory}={service.description=Apache HTTP Client Caching Client Factory, service.id=384, service.bundleid=478, service.scope=singleton, service.vendor=The Apache Software Foundation, service.pid=org.apache.http.cachinghttpclientfactory} 2020-03-19 09:01:46.597 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpclient (478): Starting destruction process 2020-03-19 09:01:46.597 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpclient (478): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.597 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STOPPED 2020-03-19 09:01:46.602 [INFO ] [internal.service.FeaturesServiceImpl] - org.openhab.binding.boschindego/2.5.2 2020-03-19 09:01:46.602 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.boschindego (448): Starting destruction process 2020-03-19 09:01:46.602 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.boschindego (448): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.603 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.boschindego (448): Starting destruction process 2020-03-19 09:01:46.603 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.boschindego (448): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.603 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STOPPING 2020-03-19 09:01:46.608 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=381, service.bundleid=448, service.scope=bundle, component.name=org.openhab.binding.boschindego.internal.BoschIndegoHandlerFactory, component.id=227} 2020-03-19 09:01:46.611 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@30df624e[p=0,l=185,c=32768,r=185]={<<>>Detail\\":\\"NONE\\"...gs":[],"groupNa} complete=false committing=false callback=Blocker@58b3d634{null} ==> log/events.log <== 2020-03-19 09:01:46.611 [hingStatusInfoChangedEvent] - 'boschindego:indego:82885ae2' changed from ONLINE to UNINITIALIZED ==> log/openhab.log <== 2020-03-19 09:01:46.611 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@60a3ad66] generate: FLUSH (null,[p=0,l=185,c=32768,r=185],false)@COMMITTED 2020-03-19 09:01:46.611 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - write: WriteFlusher@40a2fdab{IDLE}->null [HeapByteBuffer@38292f70[p=0,l=6,c=1024,r=6]={<<<\r\nB9\r\n>>>\n\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},DirectByteBuffer@30df624e[p=0,l=185,c=32768,r=185]={<<>>Detail\\":\\"NONE\\"...gs":[],"groupNa}] 2020-03-19 09:01:46.612 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{WRITING}->null:IDLE-->WRITING 2020-03-19 09:01:46.612 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 191 SocketChannelEndPoint@8d559f2{/192.168.111.41:56744<->/192.168.1.10:8080,OPEN,fill=-,flush=W,to=6765/30000}{io=0/0,kio=0,kro=1}->HttpConnection@472faca3[p=HttpParser{s=END,0 of -1},g=HttpGenerator@6597677d{s=COMMITTED}]=>HttpChannelOverHttp@612a698{r=15,c=true,c=false/false,a=ASYNC_WAIT,uri=//192.168.1.10:8080/rest/events,age=453006} 2020-03-19 09:01:46.612 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - Flushed=true written=191 remaining=0 WriteFlusher@40a2fdab{WRITING}->null 2020-03-19 09:01:46.612 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{IDLE}->null:WRITING-->IDLE 2020-03-19 09:01:46.613 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@60a3ad66] generate: DONE (null,[p=185,l=185,c=32768,r=0],false)@COMMITTED 2020-03-19 09:01:46.613 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@30df624e[p=0,l=251,c=32768,r=251]={<<>>tusInfoChangedEve...gs":[],"groupNa} complete=false committing=false callback=Blocker@58b3d634{null} 2020-03-19 09:01:46.614 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@158177b5] generate: FLUSH (null,[p=0,l=251,c=32768,r=251],false)@COMMITTED 2020-03-19 09:01:46.614 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - write: WriteFlusher@40a2fdab{IDLE}->null [HeapByteBuffer@38292f70[p=0,l=6,c=1024,r=6]={<<<\r\nFB\r\n>>>\n\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},DirectByteBuffer@30df624e[p=0,l=251,c=32768,r=251]={<<>>tusInfoChangedEve...gs":[],"groupNa}] 2020-03-19 09:01:46.614 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{WRITING}->null:IDLE-->WRITING 2020-03-19 09:01:46.615 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 257 SocketChannelEndPoint@8d559f2{/192.168.111.41:56744<->/192.168.1.10:8080,OPEN,fill=-,flush=W,to=2/30000}{io=0/0,kio=0,kro=1}->HttpConnection@472faca3[p=HttpParser{s=END,0 of -1},g=HttpGenerator@6597677d{s=COMMITTED}]=>HttpChannelOverHttp@612a698{r=15,c=true,c=false/false,a=ASYNC_WAIT,uri=//192.168.1.10:8080/rest/events,age=453009} 2020-03-19 09:01:46.615 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - Flushed=true written=257 remaining=0 WriteFlusher@40a2fdab{WRITING}->null 2020-03-19 09:01:46.615 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{IDLE}->null:WRITING-->IDLE 2020-03-19 09:01:46.615 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@158177b5] generate: DONE (null,[p=251,l=251,c=32768,r=0],false)@COMMITTED ==> log/events.log <== 2020-03-19 09:01:46.620 [hingStatusInfoChangedEvent] - 'boschindego:indego:82885ae2' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR) ==> log/openhab.log <== 2020-03-19 09:01:46.627 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@30df624e[p=0,l=202,c=32768,r=202]={<<>>NONE\\"}]","type":...gs":[],"groupNa} complete=false committing=false callback=Blocker@58b3d634{null} 2020-03-19 09:01:46.627 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@2a7701b0] generate: FLUSH (null,[p=0,l=202,c=32768,r=202],false)@COMMITTED 2020-03-19 09:01:46.629 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - write: WriteFlusher@40a2fdab{IDLE}->null [HeapByteBuffer@38292f70[p=0,l=6,c=1024,r=6]={<<<\r\nCA\r\n>>>\n\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},DirectByteBuffer@30df624e[p=0,l=202,c=32768,r=202]={<<>>NONE\\"}]","type":...gs":[],"groupNa}] 2020-03-19 09:01:46.630 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{WRITING}->null:IDLE-->WRITING 2020-03-19 09:01:46.631 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 208 SocketChannelEndPoint@8d559f2{/192.168.111.41:56744<->/192.168.1.10:8080,OPEN,fill=-,flush=W,to=15/30000}{io=0/0,kio=0,kro=1}->HttpConnection@472faca3[p=HttpParser{s=END,0 of -1},g=HttpGenerator@6597677d{s=COMMITTED}]=>HttpChannelOverHttp@612a698{r=15,c=true,c=false/false,a=ASYNC_WAIT,uri=//192.168.1.10:8080/rest/events,age=453024} 2020-03-19 09:01:46.631 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - Flushed=true written=208 remaining=0 WriteFlusher@40a2fdab{WRITING}->null 2020-03-19 09:01:46.632 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.boschindego (448): Starting destruction process 2020-03-19 09:01:46.632 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{IDLE}->null:WRITING-->IDLE 2020-03-19 09:01:46.632 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@2a7701b0] generate: DONE (null,[p=202,l=202,c=32768,r=0],false)@COMMITTED 2020-03-19 09:01:46.632 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.boschindego (448): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.632 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STOPPED 2020-03-19 09:01:46.633 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@30df624e[p=0,l=275,c=32768,r=275]={<<>>ther client conne...gs":[],"groupNa} complete=false committing=false callback=Blocker@58b3d634{null} 2020-03-19 09:01:46.633 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@613fd7b6] generate: FLUSH (null,[p=0,l=275,c=32768,r=275],false)@COMMITTED 2020-03-19 09:01:46.633 [DEBUG] [f.features.internal.service.Deployer] - Usage for bundle org.apache.servicemix.bundles.not-yet-commons-ssl_0.3.11.1 [65] is 0 2020-03-19 09:01:46.634 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - write: WriteFlusher@40a2fdab{IDLE}->null [HeapByteBuffer@38292f70[p=0,l=7,c=1024,r=7]={<<<\r\n113\r\n>>>\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},DirectByteBuffer@30df624e[p=0,l=275,c=32768,r=275]={<<>>ther client conne...gs":[],"groupNa}] 2020-03-19 09:01:46.634 [DEBUG] [f.features.internal.service.Deployer] - Usage for bundle org.apache.karaf.shell.ssh_4.2.7 [63] is 1 2020-03-19 09:01:46.634 [DEBUG] [f.features.internal.service.Deployer] - Selected bundles [org.apache.servicemix.bundles.not-yet-commons-ssl_0.3.11.1 [65]] for destroy (no services in use) 2020-03-19 09:01:46.634 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{WRITING}->null:IDLE-->WRITING 2020-03-19 09:01:46.634 [INFO ] [internal.service.FeaturesServiceImpl] - org.apache.servicemix.bundles.not-yet-commons-ssl/0.3.11.1 2020-03-19 09:01:46.634 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 282 SocketChannelEndPoint@8d559f2{/192.168.111.41:56744<->/192.168.1.10:8080,OPEN,fill=-,flush=W,to=3/30000}{io=0/0,kio=0,kro=1}->HttpConnection@472faca3[p=HttpParser{s=END,0 of -1},g=HttpGenerator@6597677d{s=COMMITTED}]=>HttpChannelOverHttp@612a698{r=15,c=true,c=false/false,a=ASYNC_WAIT,uri=//192.168.1.10:8080/rest/events,age=453028} 2020-03-19 09:01:46.634 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.servicemix.bundles.not-yet-commons-ssl (65): Starting destruction process 2020-03-19 09:01:46.635 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - Flushed=true written=282 remaining=0 WriteFlusher@40a2fdab{WRITING}->null 2020-03-19 09:01:46.635 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.servicemix.bundles.not-yet-commons-ssl (65): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.635 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.servicemix.bundles.not-yet-commons-ssl (65): Starting destruction process 2020-03-19 09:01:46.635 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{IDLE}->null:WRITING-->IDLE 2020-03-19 09:01:46.636 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.servicemix.bundles.not-yet-commons-ssl (65): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.636 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STOPPING 2020-03-19 09:01:46.636 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@613fd7b6] generate: DONE (null,[p=275,l=275,c=32768,r=0],false)@COMMITTED 2020-03-19 09:01:46.637 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.servicemix.bundles.not-yet-commons-ssl (65): Starting destruction process 2020-03-19 09:01:46.637 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.servicemix.bundles.not-yet-commons-ssl (65): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.638 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STOPPED 2020-03-19 09:01:46.639 [DEBUG] [f.features.internal.service.Deployer] - Usage for bundle org.apache.karaf.shell.ssh_4.2.7 [63] is 1 2020-03-19 09:01:46.639 [DEBUG] [f.features.internal.service.Deployer] - Currently selecting bundle org.apache.karaf.shell.ssh_4.2.7 [63] for destroy (with reference {org.apache.sshd.server.SshServer}={service.id=380, service.bundleid=63, service.scope=singleton}) 2020-03-19 09:01:46.639 [DEBUG] [f.features.internal.service.Deployer] - Selected bundle [org.apache.karaf.shell.ssh_4.2.7 [63]] for destroy (lowest ranking service) 2020-03-19 09:01:46.639 [INFO ] [internal.service.FeaturesServiceImpl] - org.apache.karaf.shell.ssh/4.2.7 2020-03-19 09:01:46.640 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.karaf.shell.ssh (63): Starting destruction process 2020-03-19 09:01:46.640 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.karaf.shell.ssh (63): Scheduling extension destruction 2020-03-19 09:01:46.640 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.karaf.shell.ssh (63): Waiting for extension destruction 2020-03-19 09:01:46.640 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.karaf.shell.ssh (63): Destroying extension 2020-03-19 09:01:46.641 [INFO ] [ll.impl.action.osgi.CommandExtension] - Unregistering commands for bundle org.apache.karaf.shell.ssh/4.2.7 2020-03-19 09:01:46.642 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.karaf.shell.ssh (63): Finished destroying extension 2020-03-19 09:01:46.642 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.karaf.shell.ssh (63): Starting destruction process 2020-03-19 09:01:46.643 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.karaf.shell.ssh (63): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.643 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STOPPING 2020-03-19 09:01:46.645 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent UNREGISTERING - {org.osgi.service.cm.ManagedService}={service.id=377, service.bundleid=63, service.scope=singleton, service.pid=org.apache.karaf.shell} 2020-03-19 09:01:46.645 [DEBUG] [org.apache.felix.configadmin ] - Unregistering service [org.osgi.service.cm.ManagedService, id=377, bundle=63/mvn:org.apache.karaf.shell/org.apache.karaf.shell.ssh/4.2.7] 2020-03-19 09:01:46.647 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent UNREGISTERING - {org.apache.karaf.shell.api.console.CommandLoggingFilter}={service.id=378, service.bundleid=63, service.scope=singleton} 2020-03-19 09:01:46.648 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent UNREGISTERING - {org.apache.karaf.shell.api.console.CommandLoggingFilter}={service.id=379, service.bundleid=63, service.scope=singleton} 2020-03-19 09:01:46.649 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent UNREGISTERING - {org.apache.sshd.server.SshServer}={service.id=380, service.bundleid=63, service.scope=singleton} 2020-03-19 09:01:46.650 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.karaf.shell.ssh (63): Starting destruction process 2020-03-19 09:01:46.650 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.karaf.shell.ssh (63): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.650 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STOPPED 2020-03-19 09:01:46.651 [INFO ] [internal.service.FeaturesServiceImpl] - Uninstalling bundles: 2020-03-19 09:01:46.652 [INFO ] [internal.service.FeaturesServiceImpl] - org.apache.httpcomponents.httpclient/4.5.5 2020-03-19 09:01:46.652 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpclient (478): Starting destruction process 2020-03-19 09:01:46.653 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpclient (478): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.653 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent UNRESOLVED 2020-03-19 09:01:46.654 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpclient (478): Starting destruction process 2020-03-19 09:01:46.654 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpclient (478): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.654 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent UNINSTALLED 2020-03-19 09:01:46.655 [INFO ] [internal.service.FeaturesServiceImpl] - org.apache.httpcomponents.httpcore/4.4.9 2020-03-19 09:01:46.655 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpcore (479): Starting destruction process 2020-03-19 09:01:46.655 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpcore (479): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.656 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent UNRESOLVED 2020-03-19 09:01:46.657 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpcore (479): Starting destruction process 2020-03-19 09:01:46.657 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpcore (479): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.657 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent UNINSTALLED 2020-03-19 09:01:46.659 [INFO ] [internal.service.FeaturesServiceImpl] - Installing bundles: 2020-03-19 09:01:46.659 [INFO ] [internal.service.FeaturesServiceImpl] - mvn:org.codehaus.jackson/jackson-core-asl/1.9.2 2020-03-19 09:01:46.665 [DEBUG] [ell.impl.action.osgi.CommandExtender] - jackson-core-asl (480): Starting destruction process 2020-03-19 09:01:46.665 [DEBUG] [ell.impl.action.osgi.CommandExtender] - jackson-core-asl (480): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.665 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent INSTALLED 2020-03-19 09:01:46.666 [INFO ] [internal.service.FeaturesServiceImpl] - mvn:org.codehaus.jackson/jackson-mapper-asl/1.9.2 2020-03-19 09:01:46.679 [DEBUG] [ell.impl.action.osgi.CommandExtender] - jackson-mapper-asl (481): Starting destruction process 2020-03-19 09:01:46.679 [DEBUG] [ell.impl.action.osgi.CommandExtender] - jackson-mapper-asl (481): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.679 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent INSTALLED 2020-03-19 09:01:46.680 [INFO ] [internal.service.FeaturesServiceImpl] - mvn:commons-collections/commons-collections/3.2.2 2020-03-19 09:01:46.689 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.commons.collections (482): Starting destruction process 2020-03-19 09:01:46.690 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.commons.collections (482): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.690 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent INSTALLED 2020-03-19 09:01:46.691 [INFO ] [internal.service.FeaturesServiceImpl] - mvn:org.apache.httpcomponents/httpclient-osgi/4.2.3 2020-03-19 09:01:46.704 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpclient (483): Starting destruction process 2020-03-19 09:01:46.705 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpclient (483): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.705 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent INSTALLED 2020-03-19 09:01:46.706 [INFO ] [internal.service.FeaturesServiceImpl] - mvn:org.apache.httpcomponents/httpcore-osgi/4.2.3 2020-03-19 09:01:46.716 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpcore (484): Starting destruction process 2020-03-19 09:01:46.716 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpcore (484): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.717 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent INSTALLED 2020-03-19 09:01:46.717 [INFO ] [internal.service.FeaturesServiceImpl] - mvn:org.apache.servicemix.bundles/org.apache.servicemix.bundles.commons-httpclient/3.1_7 2020-03-19 09:01:46.725 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.servicemix.bundles.commons-httpclient (485): Starting destruction process 2020-03-19 09:01:46.725 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.servicemix.bundles.commons-httpclient (485): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.726 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent INSTALLED 2020-03-19 09:01:46.726 [INFO ] [internal.service.FeaturesServiceImpl] - mvn:org.openhab.binding/org.openhab.binding.http/[1.14.0,1.15) 2020-03-19 09:01:46.730 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.http (486): Starting destruction process 2020-03-19 09:01:46.730 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.http (486): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.730 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent INSTALLED 2020-03-19 09:01:46.731 [INFO ] [internal.service.FeaturesServiceImpl] - mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0 2020-03-19 09:01:46.738 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.core.compat1x (487): Starting destruction process 2020-03-19 09:01:46.739 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.core.compat1x (487): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.739 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent INSTALLED 2020-03-19 09:01:46.743 [DEBUG] [internal.service.FeaturesServiceImpl] - Configuration file /etc/openhab2/services/http.cfg already exist, don't override it 2020-03-19 09:01:46.744 [INFO ] [internal.service.FeaturesServiceImpl] - Refreshing bundles: 2020-03-19 09:01:46.744 [INFO ] [internal.service.FeaturesServiceImpl] - org.apache.httpcomponents.httpclient/4.5.5 (Bundle will be uninstalled) 2020-03-19 09:01:46.744 [INFO ] [internal.service.FeaturesServiceImpl] - org.apache.httpcomponents.httpcore/4.4.9 (Bundle will be uninstalled) 2020-03-19 09:01:46.745 [INFO ] [internal.service.FeaturesServiceImpl] - org.apache.karaf.shell.ssh/4.2.7 (Wired to org.apache.servicemix.bundles.not-yet-commons-ssl/0.3.11.1 which is being refreshed) 2020-03-19 09:01:46.745 [INFO ] [internal.service.FeaturesServiceImpl] - org.apache.servicemix.bundles.not-yet-commons-ssl/0.3.11.1 (Should be wired to: org.apache.servicemix.bundles.commons-httpclient/3.1.0.7 (through [org.apache.servicemix.bundles.not-yet-commons-ssl/0.3.11.1] osgi.wiring.package; resolution:=optional; filter:="(osgi.wiring.package=org.apache.commons.httpclient.params)")) 2020-03-19 09:01:46.745 [INFO ] [internal.service.FeaturesServiceImpl] - org.openhab.binding.boschindego/2.5.2 (Wired to org.apache.httpcomponents.httpcore/4.4.9 which is being refreshed) 2020-03-19 09:01:46.749 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.boschindego (448): Starting destruction process 2020-03-19 09:01:46.749 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.boschindego (448): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.749 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent UNRESOLVED 2020-03-19 09:01:46.750 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.servicemix.bundles.not-yet-commons-ssl (65): Starting destruction process 2020-03-19 09:01:46.750 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.servicemix.bundles.not-yet-commons-ssl (65): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.751 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent UNRESOLVED 2020-03-19 09:01:46.751 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.karaf.shell.ssh (63): Starting destruction process 2020-03-19 09:01:46.752 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.karaf.shell.ssh (63): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.752 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent UNRESOLVED 2020-03-19 09:01:46.808 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.karaf.shell.ssh (63): Starting destruction process 2020-03-19 09:01:46.809 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.karaf.shell.ssh (63): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.809 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent RESOLVED 2020-03-19 09:01:46.812 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.servicemix.bundles.not-yet-commons-ssl (65): Starting destruction process 2020-03-19 09:01:46.813 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.servicemix.bundles.not-yet-commons-ssl (65): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.814 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent RESOLVED 2020-03-19 09:01:46.816 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.servicemix.bundles.commons-httpclient (485): Starting destruction process 2020-03-19 09:01:46.817 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.servicemix.bundles.commons-httpclient (485): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.817 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent RESOLVED 2020-03-19 09:01:46.820 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.core.compat1x (487): Starting destruction process 2020-03-19 09:01:46.820 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.core.compat1x (487): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.820 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent RESOLVED 2020-03-19 09:01:46.823 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpcore (484): Starting destruction process 2020-03-19 09:01:46.823 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpcore (484): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.879 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent RESOLVED 2020-03-19 09:01:46.886 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpclient (483): Starting destruction process 2020-03-19 09:01:46.887 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.httpcomponents.httpclient (483): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.888 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent RESOLVED 2020-03-19 09:01:46.896 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.commons.collections (482): Starting destruction process 2020-03-19 09:01:46.896 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.commons.collections (482): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.897 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent RESOLVED 2020-03-19 09:01:46.904 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.http (486): Starting destruction process 2020-03-19 09:01:46.904 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.http (486): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.905 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent RESOLVED 2020-03-19 09:01:46.908 [DEBUG] [ell.impl.action.osgi.CommandExtender] - jackson-core-asl (480): Starting destruction process 2020-03-19 09:01:46.908 [DEBUG] [ell.impl.action.osgi.CommandExtender] - jackson-core-asl (480): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.909 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent RESOLVED 2020-03-19 09:01:46.911 [DEBUG] [ell.impl.action.osgi.CommandExtender] - jackson-mapper-asl (481): Starting destruction process 2020-03-19 09:01:46.912 [DEBUG] [ell.impl.action.osgi.CommandExtender] - jackson-mapper-asl (481): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.913 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent RESOLVED 2020-03-19 09:01:46.925 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.boschindego (448): Starting destruction process 2020-03-19 09:01:46.926 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.boschindego (448): Not an extended bundle or destruction of extension already finished 2020-03-19 09:01:46.926 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent RESOLVED 2020-03-19 09:01:46.929 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTING 2020-03-19 09:01:46.939 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent REGISTERED - {org.osgi.service.cm.ManagedService}={service.id=385, service.bundleid=63, service.scope=singleton, service.pid=org.apache.karaf.shell} 2020-03-19 09:01:46.940 [DEBUG] [org.apache.felix.configadmin ] - Registering service [org.osgi.service.cm.ManagedService, id=385, bundle=63/mvn:org.apache.karaf.shell/org.apache.karaf.shell.ssh/4.2.7] 2020-03-19 09:01:46.941 [DEBUG] [org.apache.felix.configadmin ] - Scheduling task ManagedService Update: pid=[org.apache.karaf.shell] 2020-03-19 09:01:46.941 [DEBUG] [org.apache.felix.configadmin ] - [ManagedService Update: pid=[org.apache.karaf.shell]] scheduled 2020-03-19 09:01:46.941 [DEBUG] [org.apache.felix.configadmin ] - Running task ManagedService Update: pid=[org.apache.karaf.shell] 2020-03-19 09:01:46.942 [DEBUG] [org.apache.felix.configadmin ] - Found cached configuration org.apache.karaf.shell bound to mvn:org.apache.karaf.shell/org.apache.karaf.shell.ssh/4.2.7 2020-03-19 09:01:46.942 [DEBUG] [org.apache.felix.configadmin ] - canReceive=true: bundle=mvn:org.apache.karaf.shell/org.apache.karaf.shell.ssh/4.2.7; configuration=mvn:org.apache.karaf.shell/org.apache.karaf.shell.ssh/4.2.7 2020-03-19 09:01:46.942 [DEBUG] [org.apache.felix.configadmin ] - Updating service org.apache.karaf.shell with configuration org.apache.karaf.shell@1 2020-03-19 09:01:46.943 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.apache.karaf.shell.ssh (63): Starting extension synchronously 2020-03-19 09:01:46.952 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent REGISTERED - {org.apache.karaf.shell.api.console.CommandLoggingFilter}={service.id=386, service.bundleid=63, service.scope=singleton} 2020-03-19 09:01:46.954 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent REGISTERED - {org.apache.karaf.shell.api.console.CommandLoggingFilter}={service.id=387, service.bundleid=63, service.scope=singleton} 2020-03-19 09:01:46.957 [INFO ] [ll.impl.action.osgi.CommandExtension] - Command registration delayed for bundle org.apache.karaf.shell.ssh/4.2.7. Missing dependencies: [org.apache.sshd.server.SshServer] 2020-03-19 09:01:46.958 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTED 2020-03-19 09:01:46.959 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle org.apache.karaf.shell.ssh 2020-03-19 09:01:46.959 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - Bundle Considered for SPI providers: org.apache.karaf.shell.ssh 2020-03-19 09:01:46.959 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - No 'SPI-Provider' Manifest header. Skipping bundle: org.apache.karaf.shell.ssh 2020-03-19 09:01:46.960 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTING 2020-03-19 09:01:46.961 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTED 2020-03-19 09:01:46.962 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle org.apache.servicemix.bundles.not-yet-commons-ssl 2020-03-19 09:01:46.963 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - Bundle Considered for SPI providers: org.apache.servicemix.bundles.not-yet-commons-ssl 2020-03-19 09:01:46.963 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - No 'SPI-Provider' Manifest header. Skipping bundle: org.apache.servicemix.bundles.not-yet-commons-ssl 2020-03-19 09:01:46.964 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent [unknown: 512] 2020-03-19 09:01:46.966 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent REGISTERED - {org.apache.sshd.server.SshServer}={service.id=388, service.bundleid=63, service.scope=singleton} 2020-03-19 09:01:46.966 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.factoryPid=org.openhab.binding.http.genericbindingprovider)(service.factoryPid=org.openhab.binding.http.genericbindingprovider|org.openhab.binding.http)(service.factoryPid=org.openhab.binding.http.genericbindingprovider|org.openhab.binding.http|1.14.0)(service.factoryPid=org.openhab.binding.http.genericbindingprovider|org.openhab.binding.http|1.14.0|mvn:org.openhab.binding/org.openhab.binding.http/[1.14.0,1.15\)))) 2020-03-19 09:01:46.968 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.shell.ssh/4.2.7 2020-03-19 09:01:46.967 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.factoryPid=org.openhab.binding.http.genericbindingprovider)(service.factoryPid=org.openhab.binding.http.genericbindingprovider|org.openhab.binding.http)(service.factoryPid=org.openhab.binding.http.genericbindingprovider|org.openhab.binding.http|1.14.0)(service.factoryPid=org.openhab.binding.http.genericbindingprovider|org.openhab.binding.http|1.14.0|mvn:org.openhab.binding/org.openhab.binding.http/[1.14.0,1.15\))) 2020-03-19 09:01:46.969 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.pid=org.openhab.binding.http.genericbindingprovider)(service.pid=org.openhab.binding.http.genericbindingprovider|org.openhab.binding.http)(service.pid=org.openhab.binding.http.genericbindingprovider|org.openhab.binding.http|1.14.0)(service.pid=org.openhab.binding.http.genericbindingprovider|org.openhab.binding.http|1.14.0|mvn:org.openhab.binding/org.openhab.binding.http/[1.14.0,1.15\)))) 2020-03-19 09:01:46.970 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.pid=org.openhab.binding.http.genericbindingprovider)(service.pid=org.openhab.binding.http.genericbindingprovider|org.openhab.binding.http)(service.pid=org.openhab.binding.http.genericbindingprovider|org.openhab.binding.http|1.14.0)(service.pid=org.openhab.binding.http.genericbindingprovider|org.openhab.binding.http|1.14.0|mvn:org.openhab.binding/org.openhab.binding.http/[1.14.0,1.15\))) 2020-03-19 09:01:46.970 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.factoryPid=org.openhab.binding.http)(service.factoryPid=org.openhab.binding.http|org.openhab.binding.http)(service.factoryPid=org.openhab.binding.http|org.openhab.binding.http|1.14.0)(service.factoryPid=org.openhab.binding.http|org.openhab.binding.http|1.14.0|mvn:org.openhab.binding/org.openhab.binding.http/[1.14.0,1.15\)))) 2020-03-19 09:01:46.971 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.factoryPid=org.openhab.binding.http)(service.factoryPid=org.openhab.binding.http|org.openhab.binding.http)(service.factoryPid=org.openhab.binding.http|org.openhab.binding.http|1.14.0)(service.factoryPid=org.openhab.binding.http|org.openhab.binding.http|1.14.0|mvn:org.openhab.binding/org.openhab.binding.http/[1.14.0,1.15\))) 2020-03-19 09:01:46.971 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.pid=org.openhab.binding.http)(service.pid=org.openhab.binding.http|org.openhab.binding.http)(service.pid=org.openhab.binding.http|org.openhab.binding.http|1.14.0)(service.pid=org.openhab.binding.http|org.openhab.binding.http|1.14.0|mvn:org.openhab.binding/org.openhab.binding.http/[1.14.0,1.15\)))) 2020-03-19 09:01:46.971 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.pid=org.openhab.binding.http)(service.pid=org.openhab.binding.http|org.openhab.binding.http)(service.pid=org.openhab.binding.http|org.openhab.binding.http|1.14.0)(service.pid=org.openhab.binding.http|org.openhab.binding.http|1.14.0|mvn:org.openhab.binding/org.openhab.binding.http/[1.14.0,1.15\))) 2020-03-19 09:01:46.972 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent REGISTERED - {org.openhab.model.item.binding.BindingConfigReader, org.openhab.binding.http.HttpBindingProvider}={service.id=389, service.bundleid=486, service.scope=bundle, component.name=org.openhab.binding.http.genericbindingprovider, component.id=228} 2020-03-19 09:01:46.977 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTING 2020-03-19 09:01:46.979 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTED 2020-03-19 09:01:46.982 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle org.openhab.binding.http 2020-03-19 09:01:46.983 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - Bundle Considered for SPI providers: org.openhab.binding.http 2020-03-19 09:01:46.984 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - No 'SPI-Provider' Manifest header. Skipping bundle: org.openhab.binding.http 2020-03-19 09:01:46.993 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTING 2020-03-19 09:01:46.995 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTED 2020-03-19 09:01:46.996 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle org.openhab.binding.boschindego 2020-03-19 09:01:46.996 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - Bundle Considered for SPI providers: org.openhab.binding.boschindego 2020-03-19 09:01:46.997 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - No 'SPI-Provider' Manifest header. Skipping bundle: org.openhab.binding.boschindego 2020-03-19 09:01:47.003 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.factoryPid=binding.boschindego)(service.factoryPid=binding.boschindego|org.openhab.binding.boschindego)(service.factoryPid=binding.boschindego|org.openhab.binding.boschindego|2.5.2)(service.factoryPid=binding.boschindego|org.openhab.binding.boschindego|2.5.2|mvn:org.openhab.addons.bundles/org.openhab.binding.boschindego/[2.5.0,2.6\)))) 2020-03-19 09:01:47.004 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.factoryPid=binding.boschindego)(service.factoryPid=binding.boschindego|org.openhab.binding.boschindego)(service.factoryPid=binding.boschindego|org.openhab.binding.boschindego|2.5.2)(service.factoryPid=binding.boschindego|org.openhab.binding.boschindego|2.5.2|mvn:org.openhab.addons.bundles/org.openhab.binding.boschindego/[2.5.0,2.6\))) 2020-03-19 09:01:47.004 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.pid=binding.boschindego)(service.pid=binding.boschindego|org.openhab.binding.boschindego)(service.pid=binding.boschindego|org.openhab.binding.boschindego|2.5.2)(service.pid=binding.boschindego|org.openhab.binding.boschindego|2.5.2|mvn:org.openhab.addons.bundles/org.openhab.binding.boschindego/[2.5.0,2.6\)))) 2020-03-19 09:01:47.005 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.pid=binding.boschindego)(service.pid=binding.boschindego|org.openhab.binding.boschindego)(service.pid=binding.boschindego|org.openhab.binding.boschindego|2.5.2)(service.pid=binding.boschindego|org.openhab.binding.boschindego|2.5.2|mvn:org.openhab.addons.bundles/org.openhab.binding.boschindego/[2.5.0,2.6\))) 2020-03-19 09:01:47.008 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=390, service.bundleid=448, service.scope=bundle, component.name=org.openhab.binding.boschindego.internal.BoschIndegoHandlerFactory, component.id=230} ==> log/events.log <== 2020-03-19 09:01:47.015 [hingStatusInfoChangedEvent] - 'boschindego:indego:82885ae2' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING ==> log/openhab.log <== 2020-03-19 09:01:47.016 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@30df624e[p=0,l=184,c=32768,r=184]={<<>>us\\":\\"UNINITIALI...gs":[],"groupNa} complete=false committing=false callback=Blocker@58b3d634{null} 2020-03-19 09:01:47.017 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@1c8a8e6a] generate: FLUSH (null,[p=0,l=184,c=32768,r=184],false)@COMMITTED 2020-03-19 09:01:47.017 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - write: WriteFlusher@40a2fdab{IDLE}->null [HeapByteBuffer@38292f70[p=0,l=6,c=1024,r=6]={<<<\r\nB8\r\n>>>\n\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},DirectByteBuffer@30df624e[p=0,l=184,c=32768,r=184]={<<>>us\\":\\"UNINITIALI...gs":[],"groupNa}] 2020-03-19 09:01:47.017 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{WRITING}->null:IDLE-->WRITING 2020-03-19 09:01:47.018 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 190 SocketChannelEndPoint@8d559f2{/192.168.111.41:56744<->/192.168.1.10:8080,OPEN,fill=-,flush=W,to=382/30000}{io=0/0,kio=0,kro=1}->HttpConnection@472faca3[p=HttpParser{s=END,0 of -1},g=HttpGenerator@6597677d{s=COMMITTED}]=>HttpChannelOverHttp@612a698{r=15,c=true,c=false/false,a=ASYNC_WAIT,uri=//192.168.1.10:8080/rest/events,age=453412} 2020-03-19 09:01:47.018 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - Flushed=true written=190 remaining=0 WriteFlusher@40a2fdab{WRITING}->null 2020-03-19 09:01:47.018 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{IDLE}->null:WRITING-->IDLE 2020-03-19 09:01:47.019 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@1c8a8e6a] generate: DONE (null,[p=184,l=184,c=32768,r=0],false)@COMMITTED 2020-03-19 09:01:47.019 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@30df624e[p=0,l=274,c=32768,r=274]={<<>>\nther client conn...gs":[],"groupNa} complete=false committing=false callback=Blocker@58b3d634{null} 2020-03-19 09:01:47.020 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@2286e91] generate: FLUSH (null,[p=0,l=274,c=32768,r=274],false)@COMMITTED 2020-03-19 09:01:47.020 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - write: WriteFlusher@40a2fdab{IDLE}->null [HeapByteBuffer@38292f70[p=0,l=7,c=1024,r=7]={<<<\r\n112\r\n>>>\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},DirectByteBuffer@30df624e[p=0,l=274,c=32768,r=274]={<<>>\nther client conn...gs":[],"groupNa}] 2020-03-19 09:01:47.020 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{WRITING}->null:IDLE-->WRITING 2020-03-19 09:01:47.021 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 281 SocketChannelEndPoint@8d559f2{/192.168.111.41:56744<->/192.168.1.10:8080,OPEN,fill=-,flush=W,to=2/30000}{io=0/0,kio=0,kro=1}->HttpConnection@472faca3[p=HttpParser{s=END,0 of -1},g=HttpGenerator@6597677d{s=COMMITTED}]=>HttpChannelOverHttp@612a698{r=15,c=true,c=false/false,a=ASYNC_WAIT,uri=//192.168.1.10:8080/rest/events,age=453415} 2020-03-19 09:01:47.021 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - Flushed=true written=281 remaining=0 WriteFlusher@40a2fdab{WRITING}->null 2020-03-19 09:01:47.021 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{IDLE}->null:WRITING-->IDLE 2020-03-19 09:01:47.022 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@2286e91] generate: DONE (null,[p=274,l=274,c=32768,r=0],false)@COMMITTED 2020-03-19 09:01:47.023 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@30df624e[p=0,l=179,c=32768,r=179]={<<>>IALIZED\\",\\"statu...gs":[],"groupNa} complete=false committing=false callback=Blocker@58b3d634{null} ==> log/events.log <== 2020-03-19 09:01:47.023 [hingStatusInfoChangedEvent] - 'boschindego:indego:82885ae2' changed from INITIALIZING to OFFLINE ==> log/openhab.log <== 2020-03-19 09:01:47.023 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@104085e5] generate: FLUSH (null,[p=0,l=179,c=32768,r=179],false)@COMMITTED 2020-03-19 09:01:47.024 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - write: WriteFlusher@40a2fdab{IDLE}->null [HeapByteBuffer@38292f70[p=0,l=6,c=1024,r=6]={<<<\r\nB3\r\n>>>\n\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},DirectByteBuffer@30df624e[p=0,l=179,c=32768,r=179]={<<>>IALIZED\\",\\"statu...gs":[],"groupNa}] 2020-03-19 09:01:47.024 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{WRITING}->null:IDLE-->WRITING 2020-03-19 09:01:47.025 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 185 SocketChannelEndPoint@8d559f2{/192.168.111.41:56744<->/192.168.1.10:8080,OPEN,fill=-,flush=W,to=3/30000}{io=0/0,kio=0,kro=1}->HttpConnection@472faca3[p=HttpParser{s=END,0 of -1},g=HttpGenerator@6597677d{s=COMMITTED}]=>HttpChannelOverHttp@612a698{r=15,c=true,c=false/false,a=ASYNC_WAIT,uri=//192.168.1.10:8080/rest/events,age=453418} 2020-03-19 09:01:47.025 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - Flushed=true written=185 remaining=0 WriteFlusher@40a2fdab{WRITING}->null 2020-03-19 09:01:47.025 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{IDLE}->null:WRITING-->IDLE 2020-03-19 09:01:47.026 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@104085e5] generate: DONE (null,[p=179,l=179,c=32768,r=0],false)@COMMITTED 2020-03-19 09:01:47.026 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@30df624e[p=0,l=251,c=32768,r=251]={<<>>tusInfoChangedEve...gs":[],"groupNa} complete=false committing=false callback=Blocker@58b3d634{null} 2020-03-19 09:01:47.026 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@f5d723c] generate: FLUSH (null,[p=0,l=251,c=32768,r=251],false)@COMMITTED 2020-03-19 09:01:47.027 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - write: WriteFlusher@40a2fdab{IDLE}->null [HeapByteBuffer@38292f70[p=0,l=6,c=1024,r=6]={<<<\r\nFB\r\n>>>\n\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},DirectByteBuffer@30df624e[p=0,l=251,c=32768,r=251]={<<>>tusInfoChangedEve...gs":[],"groupNa}] 2020-03-19 09:01:47.027 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{WRITING}->null:IDLE-->WRITING 2020-03-19 09:01:47.027 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: java.lang.NoClassDefFoundError: org/apache/http/impl/client/HttpClients at de.zazaz.iot.bosch.indego.IndegoController.connect(IndegoController.java:116) ~[?:?] at org.openhab.binding.boschindego.internal.handler.BoschIndegoHandler.poll(BoschIndegoHandler.java:110) ~[?:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_242] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_242] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_242] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_242] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_242] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_242] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_242] Caused by: java.lang.ClassNotFoundException: org.apache.http.impl.client.HttpClients cannot be found by org.openhab.binding.boschindego_2.5.2 at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:433) ~[org.eclipse.osgi-3.12.100.jar:?] at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:395) ~[org.eclipse.osgi-3.12.100.jar:?] at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:387) ~[org.eclipse.osgi-3.12.100.jar:?] at org.eclipse.osgi.internal.loader.ModuleClassLoader.loadClass(ModuleClassLoader.java:150) ~[org.eclipse.osgi-3.12.100.jar:?] at java.lang.ClassLoader.loadClass(ClassLoader.java:352) ~[?:1.8.0_242] ... 9 more 2020-03-19 09:01:47.028 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 257 SocketChannelEndPoint@8d559f2{/192.168.111.41:56744<->/192.168.1.10:8080,OPEN,fill=-,flush=W,to=2/30000}{io=0/0,kio=0,kro=1}->HttpConnection@472faca3[p=HttpParser{s=END,0 of -1},g=HttpGenerator@6597677d{s=COMMITTED}]=>HttpChannelOverHttp@612a698{r=15,c=true,c=false/false,a=ASYNC_WAIT,uri=//192.168.1.10:8080/rest/events,age=453421} 2020-03-19 09:01:47.030 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - Flushed=true written=257 remaining=0 WriteFlusher@40a2fdab{WRITING}->null 2020-03-19 09:01:47.030 [DEBUG] [org.osgi.framework.FrameworkEvent ] - FrameworkEvent PACKAGES REFRESHED 2020-03-19 09:01:47.031 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{IDLE}->null:WRITING-->IDLE 2020-03-19 09:01:47.031 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@f5d723c] generate: DONE (null,[p=251,l=251,c=32768,r=0],false)@COMMITTED 2020-03-19 09:01:47.033 [INFO ] [internal.service.FeaturesServiceImpl] - Starting bundles: 2020-03-19 09:01:47.036 [INFO ] [internal.service.FeaturesServiceImpl] - org.apache.commons.collections/3.2.2 2020-03-19 09:01:47.060 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTING 2020-03-19 09:01:47.064 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTED 2020-03-19 09:01:47.066 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle org.apache.commons.collections 2020-03-19 09:01:47.067 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - Bundle Considered for SPI providers: org.apache.commons.collections 2020-03-19 09:01:47.068 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - No 'SPI-Provider' Manifest header. Skipping bundle: org.apache.commons.collections 2020-03-19 09:01:47.117 [INFO ] [internal.service.FeaturesServiceImpl] - org.apache.servicemix.bundles.commons-httpclient/3.1.0.7 2020-03-19 09:01:47.118 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTING 2020-03-19 09:01:47.135 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTED 2020-03-19 09:01:47.136 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle org.apache.servicemix.bundles.commons-httpclient 2020-03-19 09:01:47.137 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - Bundle Considered for SPI providers: org.apache.servicemix.bundles.commons-httpclient 2020-03-19 09:01:47.137 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - No 'SPI-Provider' Manifest header. Skipping bundle: org.apache.servicemix.bundles.commons-httpclient 2020-03-19 09:01:47.138 [INFO ] [internal.service.FeaturesServiceImpl] - jackson-core-asl/1.9.2 2020-03-19 09:01:47.138 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTING 2020-03-19 09:01:47.139 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTED 2020-03-19 09:01:47.140 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle jackson-core-asl 2020-03-19 09:01:47.141 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - Bundle Considered for SPI providers: jackson-core-asl 2020-03-19 09:01:47.141 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - No 'SPI-Provider' Manifest header. Skipping bundle: jackson-core-asl 2020-03-19 09:01:47.142 [INFO ] [internal.service.FeaturesServiceImpl] - org.apache.httpcomponents.httpcore/4.2.3 2020-03-19 09:01:47.142 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTING 2020-03-19 09:01:47.146 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTED 2020-03-19 09:01:47.171 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle org.apache.httpcomponents.httpcore 2020-03-19 09:01:47.172 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - Bundle Considered for SPI providers: org.apache.httpcomponents.httpcore 2020-03-19 09:01:47.172 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - No 'SPI-Provider' Manifest header. Skipping bundle: org.apache.httpcomponents.httpcore 2020-03-19 09:01:47.173 [INFO ] [internal.service.FeaturesServiceImpl] - org.apache.httpcomponents.httpclient/4.2.3 2020-03-19 09:01:47.174 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTING 2020-03-19 09:01:47.177 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTED 2020-03-19 09:01:47.179 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle org.apache.httpcomponents.httpclient 2020-03-19 09:01:47.179 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - Bundle Considered for SPI providers: org.apache.httpcomponents.httpclient 2020-03-19 09:01:47.180 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - No 'SPI-Provider' Manifest header. Skipping bundle: org.apache.httpcomponents.httpclient 2020-03-19 09:01:47.182 [INFO ] [internal.service.FeaturesServiceImpl] - jackson-mapper-asl/1.9.2 2020-03-19 09:01:47.182 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTING 2020-03-19 09:01:47.185 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTED 2020-03-19 09:01:47.187 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle jackson-mapper-asl 2020-03-19 09:01:47.187 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - Bundle Considered for SPI providers: jackson-mapper-asl 2020-03-19 09:01:47.188 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - No 'SPI-Provider' Manifest header. Skipping bundle: jackson-mapper-asl 2020-03-19 09:01:47.231 [INFO ] [internal.service.FeaturesServiceImpl] - org.openhab.core.compat1x/2.5.0 2020-03-19 09:01:47.232 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTING 2020-03-19 09:01:47.235 [DEBUG] [org.osgi.framework.BundleEvent ] - BundleEvent STARTED 2020-03-19 09:01:47.236 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle org.openhab.core.compat1x 2020-03-19 09:01:47.236 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - Bundle Considered for SPI providers: org.openhab.core.compat1x 2020-03-19 09:01:47.237 [DEBUG] [rg.apache.aries.spifly.BaseActivator] - No 'SPI-Provider' Manifest header. Skipping bundle: org.openhab.core.compat1x 2020-03-19 09:01:47.240 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.factoryPid=org.openhab.core.autoupdate.internal.AutoUpdateProviderDelegate)(service.factoryPid=org.openhab.core.autoupdate.internal.AutoUpdateProviderDelegate|org.openhab.core.compat1x)(service.factoryPid=org.openhab.core.autoupdate.internal.AutoUpdateProviderDelegate|org.openhab.core.compat1x|2.5.0)(service.factoryPid=org.openhab.core.autoupdate.internal.AutoUpdateProviderDelegate|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0))) 2020-03-19 09:01:47.241 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.factoryPid=org.openhab.core.autoupdate.internal.AutoUpdateProviderDelegate)(service.factoryPid=org.openhab.core.autoupdate.internal.AutoUpdateProviderDelegate|org.openhab.core.compat1x)(service.factoryPid=org.openhab.core.autoupdate.internal.AutoUpdateProviderDelegate|org.openhab.core.compat1x|2.5.0)(service.factoryPid=org.openhab.core.autoupdate.internal.AutoUpdateProviderDelegate|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0)) 2020-03-19 09:01:47.241 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.pid=org.openhab.core.autoupdate.internal.AutoUpdateProviderDelegate)(service.pid=org.openhab.core.autoupdate.internal.AutoUpdateProviderDelegate|org.openhab.core.compat1x)(service.pid=org.openhab.core.autoupdate.internal.AutoUpdateProviderDelegate|org.openhab.core.compat1x|2.5.0)(service.pid=org.openhab.core.autoupdate.internal.AutoUpdateProviderDelegate|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0))) 2020-03-19 09:01:47.242 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.pid=org.openhab.core.autoupdate.internal.AutoUpdateProviderDelegate)(service.pid=org.openhab.core.autoupdate.internal.AutoUpdateProviderDelegate|org.openhab.core.compat1x)(service.pid=org.openhab.core.autoupdate.internal.AutoUpdateProviderDelegate|org.openhab.core.compat1x|2.5.0)(service.pid=org.openhab.core.autoupdate.internal.AutoUpdateProviderDelegate|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0)) 2020-03-19 09:01:47.242 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.factoryPid=org.openhab.core.binding.internal.BindingConfigReaderFactory)(service.factoryPid=org.openhab.core.binding.internal.BindingConfigReaderFactory|org.openhab.core.compat1x)(service.factoryPid=org.openhab.core.binding.internal.BindingConfigReaderFactory|org.openhab.core.compat1x|2.5.0)(service.factoryPid=org.openhab.core.binding.internal.BindingConfigReaderFactory|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0))) 2020-03-19 09:01:47.243 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.factoryPid=org.openhab.core.binding.internal.BindingConfigReaderFactory)(service.factoryPid=org.openhab.core.binding.internal.BindingConfigReaderFactory|org.openhab.core.compat1x)(service.factoryPid=org.openhab.core.binding.internal.BindingConfigReaderFactory|org.openhab.core.compat1x|2.5.0)(service.factoryPid=org.openhab.core.binding.internal.BindingConfigReaderFactory|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0)) 2020-03-19 09:01:47.243 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.pid=org.openhab.core.binding.internal.BindingConfigReaderFactory)(service.pid=org.openhab.core.binding.internal.BindingConfigReaderFactory|org.openhab.core.compat1x)(service.pid=org.openhab.core.binding.internal.BindingConfigReaderFactory|org.openhab.core.compat1x|2.5.0)(service.pid=org.openhab.core.binding.internal.BindingConfigReaderFactory|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0))) 2020-03-19 09:01:47.244 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.pid=org.openhab.core.binding.internal.BindingConfigReaderFactory)(service.pid=org.openhab.core.binding.internal.BindingConfigReaderFactory|org.openhab.core.compat1x)(service.pid=org.openhab.core.binding.internal.BindingConfigReaderFactory|org.openhab.core.compat1x|2.5.0)(service.pid=org.openhab.core.binding.internal.BindingConfigReaderFactory|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0)) 2020-03-19 09:01:47.244 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.factoryPid=org.openhab.core.events.EventPublisherDelegate)(service.factoryPid=org.openhab.core.events.EventPublisherDelegate|org.openhab.core.compat1x)(service.factoryPid=org.openhab.core.events.EventPublisherDelegate|org.openhab.core.compat1x|2.5.0)(service.factoryPid=org.openhab.core.events.EventPublisherDelegate|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0))) 2020-03-19 09:01:47.245 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.factoryPid=org.openhab.core.events.EventPublisherDelegate)(service.factoryPid=org.openhab.core.events.EventPublisherDelegate|org.openhab.core.compat1x)(service.factoryPid=org.openhab.core.events.EventPublisherDelegate|org.openhab.core.compat1x|2.5.0)(service.factoryPid=org.openhab.core.events.EventPublisherDelegate|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0)) 2020-03-19 09:01:47.245 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.pid=org.openhab.core.events.EventPublisherDelegate)(service.pid=org.openhab.core.events.EventPublisherDelegate|org.openhab.core.compat1x)(service.pid=org.openhab.core.events.EventPublisherDelegate|org.openhab.core.compat1x|2.5.0)(service.pid=org.openhab.core.events.EventPublisherDelegate|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0))) 2020-03-19 09:01:47.245 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.pid=org.openhab.core.events.EventPublisherDelegate)(service.pid=org.openhab.core.events.EventPublisherDelegate|org.openhab.core.compat1x)(service.pid=org.openhab.core.events.EventPublisherDelegate|org.openhab.core.compat1x|2.5.0)(service.pid=org.openhab.core.events.EventPublisherDelegate|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0)) 2020-03-19 09:01:47.246 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.factoryPid=org.openhab.core.events.internal.EventBridge)(service.factoryPid=org.openhab.core.events.internal.EventBridge|org.openhab.core.compat1x)(service.factoryPid=org.openhab.core.events.internal.EventBridge|org.openhab.core.compat1x|2.5.0)(service.factoryPid=org.openhab.core.events.internal.EventBridge|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0))) 2020-03-19 09:01:47.246 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.factoryPid=org.openhab.core.events.internal.EventBridge)(service.factoryPid=org.openhab.core.events.internal.EventBridge|org.openhab.core.compat1x)(service.factoryPid=org.openhab.core.events.internal.EventBridge|org.openhab.core.compat1x|2.5.0)(service.factoryPid=org.openhab.core.events.internal.EventBridge|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0)) 2020-03-19 09:01:47.247 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.pid=org.openhab.core.events.internal.EventBridge)(service.pid=org.openhab.core.events.internal.EventBridge|org.openhab.core.compat1x)(service.pid=org.openhab.core.events.internal.EventBridge|org.openhab.core.compat1x|2.5.0)(service.pid=org.openhab.core.events.internal.EventBridge|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0))) 2020-03-19 09:01:47.247 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.pid=org.openhab.core.events.internal.EventBridge)(service.pid=org.openhab.core.events.internal.EventBridge|org.openhab.core.compat1x)(service.pid=org.openhab.core.events.internal.EventBridge|org.openhab.core.compat1x|2.5.0)(service.pid=org.openhab.core.events.internal.EventBridge|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0)) 2020-03-19 09:01:47.248 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.factoryPid=org.openhab.core.items.internal.ItemUIRegistryDelegate)(service.factoryPid=org.openhab.core.items.internal.ItemUIRegistryDelegate|org.openhab.core.compat1x)(service.factoryPid=org.openhab.core.items.internal.ItemUIRegistryDelegate|org.openhab.core.compat1x|2.5.0)(service.factoryPid=org.openhab.core.items.internal.ItemUIRegistryDelegate|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0))) 2020-03-19 09:01:47.248 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.factoryPid=org.openhab.core.items.internal.ItemUIRegistryDelegate)(service.factoryPid=org.openhab.core.items.internal.ItemUIRegistryDelegate|org.openhab.core.compat1x)(service.factoryPid=org.openhab.core.items.internal.ItemUIRegistryDelegate|org.openhab.core.compat1x|2.5.0)(service.factoryPid=org.openhab.core.items.internal.ItemUIRegistryDelegate|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0)) 2020-03-19 09:01:47.249 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.pid=org.openhab.core.items.internal.ItemUIRegistryDelegate)(service.pid=org.openhab.core.items.internal.ItemUIRegistryDelegate|org.openhab.core.compat1x)(service.pid=org.openhab.core.items.internal.ItemUIRegistryDelegate|org.openhab.core.compat1x|2.5.0)(service.pid=org.openhab.core.items.internal.ItemUIRegistryDelegate|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0))) 2020-03-19 09:01:47.249 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.pid=org.openhab.core.items.internal.ItemUIRegistryDelegate)(service.pid=org.openhab.core.items.internal.ItemUIRegistryDelegate|org.openhab.core.compat1x)(service.pid=org.openhab.core.items.internal.ItemUIRegistryDelegate|org.openhab.core.compat1x|2.5.0)(service.pid=org.openhab.core.items.internal.ItemUIRegistryDelegate|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0)) 2020-03-19 09:01:47.251 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.factoryPid=org.openhab.core.persistence.internal.PersistenceServiceFactory)(service.factoryPid=org.openhab.core.persistence.internal.PersistenceServiceFactory|org.openhab.core.compat1x)(service.factoryPid=org.openhab.core.persistence.internal.PersistenceServiceFactory|org.openhab.core.compat1x|2.5.0)(service.factoryPid=org.openhab.core.persistence.internal.PersistenceServiceFactory|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0))) 2020-03-19 09:01:47.251 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.factoryPid=org.openhab.core.persistence.internal.PersistenceServiceFactory)(service.factoryPid=org.openhab.core.persistence.internal.PersistenceServiceFactory|org.openhab.core.compat1x)(service.factoryPid=org.openhab.core.persistence.internal.PersistenceServiceFactory|org.openhab.core.compat1x|2.5.0)(service.factoryPid=org.openhab.core.persistence.internal.PersistenceServiceFactory|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0)) 2020-03-19 09:01:47.251 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.pid=org.openhab.core.persistence.internal.PersistenceServiceFactory)(service.pid=org.openhab.core.persistence.internal.PersistenceServiceFactory|org.openhab.core.compat1x)(service.pid=org.openhab.core.persistence.internal.PersistenceServiceFactory|org.openhab.core.compat1x|2.5.0)(service.pid=org.openhab.core.persistence.internal.PersistenceServiceFactory|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0))) 2020-03-19 09:01:47.252 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.pid=org.openhab.core.persistence.internal.PersistenceServiceFactory)(service.pid=org.openhab.core.persistence.internal.PersistenceServiceFactory|org.openhab.core.compat1x)(service.pid=org.openhab.core.persistence.internal.PersistenceServiceFactory|org.openhab.core.compat1x|2.5.0)(service.pid=org.openhab.core.persistence.internal.PersistenceServiceFactory|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0)) 2020-03-19 09:01:47.252 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.factoryPid=org.openhab.core.scriptengine.action.internal.ActionServiceFactory)(service.factoryPid=org.openhab.core.scriptengine.action.internal.ActionServiceFactory|org.openhab.core.compat1x)(service.factoryPid=org.openhab.core.scriptengine.action.internal.ActionServiceFactory|org.openhab.core.compat1x|2.5.0)(service.factoryPid=org.openhab.core.scriptengine.action.internal.ActionServiceFactory|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0))) 2020-03-19 09:01:47.253 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.factoryPid=org.openhab.core.scriptengine.action.internal.ActionServiceFactory)(service.factoryPid=org.openhab.core.scriptengine.action.internal.ActionServiceFactory|org.openhab.core.compat1x)(service.factoryPid=org.openhab.core.scriptengine.action.internal.ActionServiceFactory|org.openhab.core.compat1x|2.5.0)(service.factoryPid=org.openhab.core.scriptengine.action.internal.ActionServiceFactory|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0)) 2020-03-19 09:01:47.253 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.pid=org.openhab.core.scriptengine.action.internal.ActionServiceFactory)(service.pid=org.openhab.core.scriptengine.action.internal.ActionServiceFactory|org.openhab.core.compat1x)(service.pid=org.openhab.core.scriptengine.action.internal.ActionServiceFactory|org.openhab.core.compat1x|2.5.0)(service.pid=org.openhab.core.scriptengine.action.internal.ActionServiceFactory|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0))) 2020-03-19 09:01:47.254 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.pid=org.openhab.core.scriptengine.action.internal.ActionServiceFactory)(service.pid=org.openhab.core.scriptengine.action.internal.ActionServiceFactory|org.openhab.core.compat1x)(service.pid=org.openhab.core.scriptengine.action.internal.ActionServiceFactory|org.openhab.core.compat1x|2.5.0)(service.pid=org.openhab.core.scriptengine.action.internal.ActionServiceFactory|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0)) 2020-03-19 09:01:47.254 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.factoryPid=org.openhab.ui.chart.internal.ChartProviderFactory)(service.factoryPid=org.openhab.ui.chart.internal.ChartProviderFactory|org.openhab.core.compat1x)(service.factoryPid=org.openhab.ui.chart.internal.ChartProviderFactory|org.openhab.core.compat1x|2.5.0)(service.factoryPid=org.openhab.ui.chart.internal.ChartProviderFactory|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0))) 2020-03-19 09:01:47.255 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.factoryPid=org.openhab.ui.chart.internal.ChartProviderFactory)(service.factoryPid=org.openhab.ui.chart.internal.ChartProviderFactory|org.openhab.core.compat1x)(service.factoryPid=org.openhab.ui.chart.internal.ChartProviderFactory|org.openhab.core.compat1x|2.5.0)(service.factoryPid=org.openhab.ui.chart.internal.ChartProviderFactory|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0)) 2020-03-19 09:01:47.255 [DEBUG] [org.apache.felix.configadmin ] - listConfigurations(filter=(|(service.pid=org.openhab.ui.chart.internal.ChartProviderFactory)(service.pid=org.openhab.ui.chart.internal.ChartProviderFactory|org.openhab.core.compat1x)(service.pid=org.openhab.ui.chart.internal.ChartProviderFactory|org.openhab.core.compat1x|2.5.0)(service.pid=org.openhab.ui.chart.internal.ChartProviderFactory|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0))) 2020-03-19 09:01:47.255 [DEBUG] [org.apache.felix.configadmin ] - Listing configurations matching (|(service.pid=org.openhab.ui.chart.internal.ChartProviderFactory)(service.pid=org.openhab.ui.chart.internal.ChartProviderFactory|org.openhab.core.compat1x)(service.pid=org.openhab.ui.chart.internal.ChartProviderFactory|org.openhab.core.compat1x|2.5.0)(service.pid=org.openhab.ui.chart.internal.ChartProviderFactory|org.openhab.core.compat1x|2.5.0|mvn:org.openhab.core.bundles/org.openhab.core.compat1x/2.5.0)) 2020-03-19 09:01:47.261 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.items.MetadataProvider}={service.id=391, service.bundleid=487, service.scope=bundle, component.name=org.openhab.core.autoupdate.internal.AutoUpdateProviderDelegate, component.id=231} 2020-03-19 09:01:47.266 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.model.item.BindingConfigReader}={service.id=392, service.bundleid=487, service.scope=singleton} 2020-03-19 09:01:47.270 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent REGISTERED - {org.openhab.core.events.EventPublisher}={service.id=393, service.bundleid=487, service.scope=bundle, component.name=org.openhab.core.events.EventPublisherDelegate, component.id=233} 2020-03-19 09:01:47.282 [INFO ] [b.core.service.AbstractActiveService] - HTTP Refresh Service has been started 2020-03-19 09:01:47.282 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent REGISTERED - {org.osgi.service.cm.ManagedService, org.osgi.service.event.EventHandler}={service.id=394, service.bundleid=486, service.scope=bundle, event.topics=openhab/*, service.pid=org.openhab.http, component.name=org.openhab.binding.http, component.id=229} 2020-03-19 09:01:47.283 [DEBUG] [org.apache.felix.configadmin ] - Registering service [org.osgi.service.cm.ManagedService, org.osgi.service.event.EventHandler, id=394, bundle=486/mvn:org.openhab.binding/org.openhab.binding.http/[1.14.0,1.15)] 2020-03-19 09:01:47.284 [DEBUG] [org.apache.felix.configadmin ] - Scheduling task ManagedService Update: pid=[org.openhab.http] 2020-03-19 09:01:47.284 [DEBUG] [org.apache.felix.configadmin ] - Running task ManagedService Update: pid=[org.openhab.http] 2020-03-19 09:01:47.284 [DEBUG] [org.apache.felix.configadmin ] - [ManagedService Update: pid=[org.openhab.http]] scheduled 2020-03-19 09:01:47.284 [DEBUG] [org.apache.felix.configadmin ] - Found cached configuration org.openhab.http bound to null 2020-03-19 09:01:47.285 [DEBUG] [org.apache.felix.configadmin ] - canReceive=true; bundle=mvn:org.openhab.binding/org.openhab.binding.http/[1.14.0,1.15); configuration=(unbound) 2020-03-19 09:01:47.285 [DEBUG] [org.apache.felix.configadmin ] - Dynamically binding config org.openhab.http to mvn:org.openhab.binding/org.openhab.binding.http/[1.14.0,1.15) 2020-03-19 09:01:47.286 [DEBUG] [org.apache.felix.configadmin ] - No SynchronousConfigurationListeners to send CM_LOCATION_CHANGED event to. 2020-03-19 09:01:47.287 [DEBUG] [org.apache.felix.configadmin ] - Scheduling task Fire ConfigurationEvent: pid=org.openhab.http 2020-03-19 09:01:47.288 [DEBUG] [org.apache.felix.configadmin ] - LocationChanged not scheduled for org.openhab.http (old location is null or configuration is new) 2020-03-19 09:01:47.288 [DEBUG] [org.apache.felix.configadmin ] - Running task Fire ConfigurationEvent: pid=org.openhab.http 2020-03-19 09:01:47.289 [DEBUG] [org.apache.felix.configadmin ] - Sending CM_LOCATION_CHANGED event for org.openhab.http to [org.openhab.core.karaf.internal.FeatureInstaller, org.osgi.service.cm.ConfigurationListener, id=233, bundle=160/mvn:org.openhab.core.bundles/org.openhab.core.karaf/2.5.0] 2020-03-19 09:01:47.289 [DEBUG] [org.apache.felix.configadmin ] - Sending CM_LOCATION_CHANGED event for org.openhab.http to [org.osgi.service.cm.ConfigurationListener, id=122, bundle=9/mvn:org.apache.felix/org.apache.felix.configadmin/1.9.16] 2020-03-19 09:01:47.288 [DEBUG] [org.apache.felix.configadmin ] - Updating service org.openhab.http with configuration org.openhab.http@1 2020-03-19 09:01:47.289 [DEBUG] [org.apache.felix.configadmin ] - Sending CM_LOCATION_CHANGED event for org.openhab.http to [org.osgi.service.cm.ConfigurationListener, id=41, bundle=13/mvn:org.apache.karaf.shell/org.apache.karaf.shell.core/4.2.7] 2020-03-19 09:01:47.290 [DEBUG] [org.apache.felix.configadmin ] - Sending CM_LOCATION_CHANGED event for org.openhab.http to [org.osgi.service.cm.ConfigurationListener, id=70, bundle=47/mvn:org.apache.karaf.config/org.apache.karaf.config.core/4.2.7] 2020-03-19 09:01:47.290 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent REGISTERED - {org.osgi.service.event.EventHandler, org.eclipse.smarthome.core.events.EventSubscriber}={service.id=395, service.bundleid=487, service.scope=bundle, event.topics=smarthome/*, component.name=org.openhab.core.events.internal.EventBridge, component.id=234} 2020-03-19 09:01:47.290 [DEBUG] [org.apache.felix.configadmin ] - Sending CM_LOCATION_CHANGED event for org.openhab.http to [org.osgi.service.cm.ConfigurationListener, org.apache.felix.fileinstall.ArtifactListener, org.apache.felix.fileinstall.ArtifactInstaller, id=40, bundle=10/mvn:org.apache.felix/org.apache.felix.fileinstall/3.6.4] 2020-03-19 09:01:47.292 [DEBUG] [org.osgi.framework.ServiceEvent ] - ServiceEvent REGISTERED - {org.openhab.core.items.ItemRegistry, org.openhab.ui.items.ItemUIRegistry}={service.id=396, service.bundleid=487, service.scope=bundle, component.name=org.openhab.core.items.internal.ItemUIRegistryDelegate, component.id=235} 2020-03-19 09:01:47.301 [INFO ] [internal.service.FeaturesServiceImpl] - Done. ==> log/events.log <== 2020-03-19 09:01:47.303 [thome.event.ExtensionEvent] - Extension 'binding-http1' has been installed. ==> log/openhab.log <== 2020-03-19 09:01:47.304 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@30df624e[p=0,l=133,c=32768,r=133]={<<>>usDetail\\":\\"NONE...gs":[],"groupNa} complete=false committing=false callback=Blocker@58b3d634{null} 2020-03-19 09:01:47.304 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@47ec5463] generate: FLUSH (null,[p=0,l=133,c=32768,r=133],false)@COMMITTED 2020-03-19 09:01:47.305 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - write: WriteFlusher@40a2fdab{IDLE}->null [HeapByteBuffer@38292f70[p=0,l=6,c=1024,r=6]={<<<\r\n85\r\n>>>\n\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},DirectByteBuffer@30df624e[p=0,l=133,c=32768,r=133]={<<>>usDetail\\":\\"NONE...gs":[],"groupNa}] 2020-03-19 09:01:47.305 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{WRITING}->null:IDLE-->WRITING 2020-03-19 09:01:47.306 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 139 SocketChannelEndPoint@8d559f2{/192.168.111.41:56744<->/192.168.1.10:8080,OPEN,fill=-,flush=W,to=275/30000}{io=0/0,kio=0,kro=1}->HttpConnection@472faca3[p=HttpParser{s=END,0 of -1},g=HttpGenerator@6597677d{s=COMMITTED}]=>HttpChannelOverHttp@612a698{r=15,c=true,c=false/false,a=ASYNC_WAIT,uri=//192.168.1.10:8080/rest/events,age=453700} 2020-03-19 09:01:47.306 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - Flushed=true written=139 remaining=0 WriteFlusher@40a2fdab{WRITING}->null 2020-03-19 09:01:47.306 [DEBUG] [org.eclipse.jetty.io.WriteFlusher ] - update WriteFlusher@40a2fdab{IDLE}->null:WRITING-->IDLE 2020-03-19 09:01:47.306 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@2430703d[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@47ec5463] generate: DONE (null,[p=133,l=133,c=32768,r=0],false)@COMMITTED