Hi,
today I installed the FritzBox TR064 Binding. The configuration is correct and the communication with my FritzBox is ok. OpenHab read out all values from FritzBox. But I have a lot of Error Messages an I don’t know why. The setup in the fritzbox is right also.
The Log show:
18:56:33.714 [ERROR] [ding.fritzboxtr064.internal.Tr064Comm] - Cannot send/receive: Read timed out
18:56:33.714 [WARN ] [ding.fritzboxtr064.internal.Tr064Comm] - Releasing connection to FritzBox because of error.
18:56:33.730 [WARN ] [ding.fritzboxtr064.internal.Tr064Comm] - Error retrieving SOAP response from FritzBox
18:56:40.823 [ERROR] [ding.fritzboxtr064.internal.Tr064Comm] - Cannot send/receive: Read timed out
18:56:40.823 [WARN ] [ding.fritzboxtr064.internal.Tr064Comm] - Releasing connection to FritzBox because of error.
18:56:40.823 [WARN ] [ding.fritzboxtr064.internal.Tr064Comm] - Error retrieving SOAP response from FritzBox
18:56:45.698 [ERROR] [ding.fritzboxtr064.internal.Tr064Comm] - Cannot send/receive: Read timed out
18:56:45.698 [WARN ] [ding.fritzboxtr064.internal.Tr064Comm] - Releasing connection to FritzBox because of error.
18:56:45.698 [WARN ] [ding.fritzboxtr064.internal.Tr064Comm] - Error retrieving SOAP response from FritzBox
18:56:50.417 [ERROR] [ding.fritzboxtr064.internal.Tr064Comm] - Cannot send/receive: Read timed out
18:56:50.417 [WARN ] [ding.fritzboxtr064.internal.Tr064Comm] - Releasing connection to FritzBox because of error.
18:56:50.432 [WARN ] [ding.fritzboxtr064.internal.Tr064Comm] - Error retrieving SOAP response from FritzBox
18:56:55.135 [ERROR] [ding.fritzboxtr064.internal.Tr064Comm] - Cannot send/receive: Read timed out
18:56:55.135 [WARN ] [ding.fritzboxtr064.internal.Tr064Comm] - Releasing connection to FritzBox because of error.
18:56:55.135 [WARN ] [ding.fritzboxtr064.internal.Tr064Comm] - Error retrieving SOAP response from FritzBox
Now the Log with DEBUG:
18:10:07.543 [DEBUG] [org.eclipse.jetty.server.HttpChannel ] - HttpChannelOverHttp@282db23a{r=78,c=false,a=IDLE,uri=//192.168.170.2:8080/rest/sitemaps/haus/0300?_=04b4a3dd4cd9,age=0} onContentComplete
18:10:07.543 [DEBUG] [org.eclipse.jetty.server.HttpChannel ] - HttpChannelOverHttp@282db23a{r=78,c=false,a=IDLE,uri=//192.168.170.2:8080/rest/sitemaps/haus/0300?_=04b4a3dd4cd9,age=0} onRequestComplete
18:10:07.543 [DEBUG] [org.eclipse.jetty.server.HttpInput ] - HttpInputOverHTTP@3f1d5ac4[c=0,q=0,[0]=null,s=STREAM] addContent EOF
18:10:07.543 [DEBUG] [g.eclipse.jetty.server.HttpConnection] - HttpConnection@42563224[p=HttpParser{s=END,0 of -1},g=HttpGenerator@222695cd{s=START}]=>HttpChannelOverHttp@282db23a{r=78,c=false,a=IDLE,uri=//192.168.170.2:8080/rest/sitemaps/haus/0300?_=04b4a3dd4cd9,age=0}<-SocketChannelEndPoint@64189a55{/192.168.170.21:55378<->/192.168.170.2:8080,OPEN,fill=-,flush=-,to=15/30000}{io=0/0,kio=0,kro=1}->HttpConnection@42563224[p=HttpParser{s=END,0 of -1},g=HttpGenerator@222695cd{s=START}]=>HttpChannelOverHttp@282db23a{r=78,c=false,a=IDLE,uri=//192.168.170.2:8080/rest/sitemaps/haus/0300?_=04b4a3dd4cd9,age=0} parsed true HttpParser{s=END,0 of -1}
18:10:07.543 [DEBUG] [g.eclipse.jetty.server.HttpConnection] - releaseRequestBuffer HttpConnection@42563224[p=HttpParser{s=END,0 of -1},g=HttpGenerator@222695cd{s=START}]=>HttpChannelOverHttp@282db23a{r=78,c=false,a=IDLE,uri=//192.168.170.2:8080/rest/sitemaps/haus/0300?_=04b4a3dd4cd9,age=0}<-SocketChannelEndPoint@64189a55{/192.168.170.21:55378<->/192.168.170.2:8080,OPEN,fill=-,flush=-,to=15/30000}{io=0/0,kio=0,kro=1}->HttpConnection@42563224[p=HttpParser{s=END,0 of -1},g=HttpGenerator@222695cd{s=START}]=>HttpChannelOverHttp@282db23a{r=78,c=false,a=IDLE,uri=//192.168.170.2:8080/rest/sitemaps/haus/0300?_=04b4a3dd4cd9,age=0}
18:10:07.543 [DEBUG] [org.eclipse.jetty.server.HttpChannel ] - HttpChannelOverHttp@282db23a{r=78,c=false,a=IDLE,uri=//192.168.170.2:8080/rest/sitemaps/haus/0300?_=04b4a3dd4cd9,age=0} handle //192.168.170.2:8080/rest/sitemaps/haus/0300?_=04b4a3dd4cd9
18:10:07.559 [DEBUG] [eclipse.jetty.server.HttpChannelState] - handling HttpChannelState@390cae89{s=IDLE a=NOT_ASYNC i=true r=IDLE w=false}
18:10:07.559 [DEBUG] [org.eclipse.jetty.server.HttpChannel ] - HttpChannelOverHttp@282db23a{r=78,c=false,a=DISPATCHED,uri=//192.168.170.2:8080/rest/sitemaps/haus/0300?_=04b4a3dd4cd9,age=16} action DISPATCH
18:10:07.559 [DEBUG] [org.eclipse.jetty.server.Server ] - REQUEST GET /rest/sitemaps/haus/0300 on HttpChannelOverHttp@282db23a{r=78,c=false,a=DISPATCHED,uri=//192.168.170.2:8080/rest/sitemaps/haus/0300?_=04b4a3dd4cd9,age=16}
18:10:07.559 [DEBUG] [pax.web.service.spi.model.ServerModel] - Matching [/rest/sitemaps/haus/0300]...
18:10:07.559 [DEBUG] [pax.web.service.spi.model.ServerModel] - Path [/rest/sitemaps/haus/0300] 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@6eba2a23,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 [20], contextID=default],contextParams={},virtualHosts={},connectors={}}}}
18:10:07.559 [DEBUG] [e.jetty.server.handler.ContextHandler] - scope null||/rest/sitemaps/haus/0300 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [20], contextID=default]}
18:10:07.559 [DEBUG] [e.jetty.server.handler.ContextHandler] - context=||/rest/sitemaps/haus/0300 @ HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [20], contextID=default]}
18:10:07.559 [DEBUG] [org.eclipse.jetty.server.session ] - sessionHandler=org.eclipse.jetty.server.session.SessionHandler566994926==dftMaxIdleSec=600
18:10:07.559 [DEBUG] [org.eclipse.jetty.server.session ] - session=null
18:10:07.559 [DEBUG] [.eclipse.jetty.servlet.ServletHandler] - servlet |/rest|/sitemaps/haus/0300 -> org.ops4j.pax.web.service.spi.model.ServletModel-5@378be0fd==com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge,jsp=null,order=-1,inst=true
18:10:07.574 [DEBUG] [ice.jetty.internal.HttpServiceContext] - Handling request for [/rest/sitemaps/haus/0300] using http context [DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [20], contextID=default]]
18:10:07.574 [DEBUG] [ty.internal.HttpServiceServletHandler] - handling request org.ops4j.pax.web.service.jetty.internal.HttpServiceRequestWrapper@f064b7, org.ops4j.pax.web.service.jetty.internal.HttpServiceResponseWrapper@5d6b36f4
18:10:07.574 [DEBUG] [.eclipse.jetty.servlet.ServletHandler] - chain=null
18:10:07.918 [DEBUG] [p.conn.ssl.SSLConnectionSocketFactory] - Secure session established
18:10:07.918 [DEBUG] [p.conn.ssl.SSLConnectionSocketFactory] - negotiated protocol: TLSv1.2
18:10:07.918 [DEBUG] [p.conn.ssl.SSLConnectionSocketFactory] - negotiated cipher suite: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
18:10:07.934 [DEBUG] [p.conn.ssl.SSLConnectionSocketFactory] - peer principal: CN=dyn.kuinke.de
18:10:07.934 [DEBUG] [p.conn.ssl.SSLConnectionSocketFactory] - peer alternative names: [dyn.kuinke.de, duyejuhnmf8kdaln.myfritz.net, fritz.box, www.fritz.box, myfritz.box, www.myfritz.box, fritz.nas, www.fritz.nas]
18:10:07.934 [DEBUG] [p.conn.ssl.SSLConnectionSocketFactory] - issuer principal: CN=dyn.kuinke.de
18:10:07.949 [DEBUG] [n.DefaultHttpClientConnectionOperator] - Connection established 192.168.170.2:56638<->192.168.170.1:49443
18:10:07.949 [DEBUG] [he.http.impl.execchain.MainClientExec] - Executing request POST /upnp/control/deviceinfo HTTP/1.1
18:10:07.949 [DEBUG] [he.http.impl.execchain.MainClientExec] - Target auth state: SUCCESS
18:10:07.949 [DEBUG] [he.http.impl.execchain.MainClientExec] - Proxy auth state: UNCHALLENGED
18:10:07.949 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> POST /upnp/control/deviceinfo HTTP/1.1
18:10:07.949 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> SOAPAction: urn:dslforum-org:service:DeviceInfo:1#GetInfo
18:10:07.949 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> Content-Length: 264
18:10:07.949 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> Content-Type: text/xml; charset=UTF-8
18:10:07.965 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> Host: 192.168.170.1:49443
18:10:07.965 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> Connection: Keep-Alive
18:10:07.965 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> User-Agent: Apache-HttpClient/4.4.1 (Java/1.8.0_191)
18:10:07.965 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> Accept-Encoding: gzip,deflate
18:10:07.965 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> Authorization: Digest username="openHAB", realm="HTTPS Access", nonce="", uri="/upnp/control/deviceinfo", response="1bc9d2971c6ff329aab90a1fa311f2fd", algorithm=MD5
18:10:07.965 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "POST /upnp/control/deviceinfo HTTP/1.1[\r][\n]"
18:10:07.965 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "SOAPAction: urn:dslforum-org:service:DeviceInfo:1#GetInfo[\r][\n]"
18:10:07.981 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "Content-Length: 264[\r][\n]"
18:10:07.981 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "Content-Type: text/xml; charset=UTF-8[\r][\n]"
18:10:07.981 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "Host: 192.168.170.1:49443[\r][\n]"
18:10:07.981 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "Connection: Keep-Alive[\r][\n]"
18:10:07.981 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "User-Agent: Apache-HttpClient/4.4.1 (Java/1.8.0_191)[\r][\n]"
18:10:07.981 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "Accept-Encoding: gzip,deflate[\r][\n]"
18:10:07.996 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "Authorization: Digest username="openHAB", realm="HTTPS Access", nonce="", uri="/upnp/control/deviceinfo", response="1bc9d2971c6ff329aab90a1fa311f2fd", algorithm=MD5[\r][\n]"
18:10:07.996 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "[\r][\n]"
18:10:07.996 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "<?xml version="1.0" encoding="UTF-8" ?><s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Header/><s:Body><u:GetInfo xmlns:u="urn:dslforum-org:service:DeviceInfo:1"/></s:Body></s:Envelope>"
18:10:08.012 [DEBUG] [org.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
18:10:08.012 [DEBUG] [org.quartz.core.JobRunShell ] - Calling execute on job DEFAULT.init.rules#sunrise-sunset#8 * * * * ?
18:10:08.012 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 << "HTTP/1.1 401 Unauthorized[\r][\n]"
18:10:08.012 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 << "Connection: keep-alive[\r][\n]"
18:10:08.028 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 << "Content-Length: 170[\r][\n]"
18:10:08.028 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 << "Content-Type: text/html[\r][\n]"
18:10:08.028 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 << "Pragma: no-cache[\r][\n]"
18:10:08.028 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 << "Server: Webserver[\r][\n]"
18:10:08.043 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 << "WWW-Authenticate: Digest realm="HTTPS Access",nonce="D31468A1E633F29A",algorithm=MD5,qop="auth"[\r][\n]"
18:10:08.043 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 << "[\r][\n]"
18:10:08.043 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 << HTTP/1.1 401 Unauthorized
18:10:08.043 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 << Connection: keep-alive
18:10:08.043 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 << Content-Length: 170
18:10:08.043 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 << Content-Type: text/html
18:10:08.059 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 << Pragma: no-cache
18:10:08.059 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 << Server: Webserver
18:10:08.059 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 << WWW-Authenticate: Digest realm="HTTPS Access",nonce="D31468A1E633F29A",algorithm=MD5,qop="auth"
18:10:08.059 [DEBUG] [he.http.impl.execchain.MainClientExec] - Connection can be kept alive indefinitely
18:10:08.059 [DEBUG] [ache.http.impl.auth.HttpAuthenticator] - Authentication required
18:10:08.059 [DEBUG] [l.client.TargetAuthenticationStrategy] - Clearing cached auth scheme for https://192.168.170.1:49443
18:10:08.059 [DEBUG] [ache.http.impl.auth.HttpAuthenticator] - 192.168.170.1:49443 requested authentication
18:10:08.074 [DEBUG] [l.client.TargetAuthenticationStrategy] - Authentication schemes in the order of preference: [Negotiate, Kerberos, NTLM, Digest, Basic]
18:10:08.074 [DEBUG] [l.client.TargetAuthenticationStrategy] - Challenge for Negotiate authentication scheme not available
18:10:08.074 [DEBUG] [l.client.TargetAuthenticationStrategy] - Challenge for Kerberos authentication scheme not available
18:10:08.074 [DEBUG] [l.client.TargetAuthenticationStrategy] - Challenge for NTLM authentication scheme not available
18:10:08.074 [DEBUG] [l.client.TargetAuthenticationStrategy] - Challenge for Basic authentication scheme not available
18:10:08.074 [DEBUG] [ache.http.impl.auth.HttpAuthenticator] - Selected authentication options: [DIGEST [complete=true, nonce=null, nc=0]]
18:10:08.090 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 << "<HTML><HEAD><TITLE>401 Unauthorized (ERR_NONE)</TITLE></HEAD><BODY><H1>401 Unauthorized</H1><BR>ERR_NONE<HR><B>Webserver</B> Fri, 18 Jan 2019 17:10:07 GMT</BODY></HTML>[\r][\n]"
18:10:08.090 [DEBUG] [he.http.impl.execchain.MainClientExec] - Executing request POST /upnp/control/deviceinfo HTTP/1.1
18:10:08.090 [DEBUG] [he.http.impl.execchain.MainClientExec] - Target auth state: CHALLENGED
18:10:08.090 [DEBUG] [ache.http.impl.auth.HttpAuthenticator] - Generating response to an authentication challenge using digest scheme
18:10:08.090 [DEBUG] [he.http.impl.execchain.MainClientExec] - Proxy auth state: UNCHALLENGED
18:10:08.090 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> POST /upnp/control/deviceinfo HTTP/1.1
18:10:08.106 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> SOAPAction: urn:dslforum-org:service:DeviceInfo:1#GetInfo
18:10:08.106 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> Content-Length: 264
18:10:08.106 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> Content-Type: text/xml; charset=UTF-8
18:10:08.106 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> Host: 192.168.170.1:49443
18:10:08.106 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> Connection: Keep-Alive
18:10:08.106 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> User-Agent: Apache-HttpClient/4.4.1 (Java/1.8.0_191)
18:10:08.106 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> Accept-Encoding: gzip,deflate
18:10:08.121 [DEBUG] [org.apache.http.headers ] - http-outgoing-382 >> Authorization: Digest username="openHAB", realm="HTTPS Access", nonce="D31468A1E633F29A", uri="/upnp/control/deviceinfo", response="ddd46506eb861365c75671daa024a952", qop=auth, nc=00000001, cnonce="78be794393c1ead0", algorithm=MD5
18:10:08.121 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "POST /upnp/control/deviceinfo HTTP/1.1[\r][\n]"
18:10:08.121 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "SOAPAction: urn:dslforum-org:service:DeviceInfo:1#GetInfo[\r][\n]"
18:10:08.121 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "Content-Length: 264[\r][\n]"
18:10:08.121 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "Content-Type: text/xml; charset=UTF-8[\r][\n]"
18:10:08.121 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "Host: 192.168.170.1:49443[\r][\n]"
18:10:08.137 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "Connection: Keep-Alive[\r][\n]"
18:10:08.137 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "User-Agent: Apache-HttpClient/4.4.1 (Java/1.8.0_191)[\r][\n]"
18:10:08.137 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "Accept-Encoding: gzip,deflate[\r][\n]"
18:10:08.137 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "Authorization: Digest username="openHAB", realm="HTTPS Access", nonce="D31468A1E633F29A", uri="/upnp/control/deviceinfo", response="ddd46506eb861365c75671daa024a952", qop=auth, nc=00000001, cnonce="78be794393c1ead0", algorithm=MD5[\r][\n]"
18:10:08.137 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "[\r][\n]"
18:10:08.153 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 >> "<?xml version="1.0" encoding="UTF-8" ?><s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Header/><s:Body><u:GetInfo xmlns:u="urn:dslforum-org:service:DeviceInfo:1"/></s:Body></s:Envelope>"
18:10:08.793 [DEBUG] [org.eclipse.jetty.server.session ] - node0 scavenging sessions
18:10:08.793 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler324515190==dftMaxIdleSec=600 scavenging sessions
18:10:08.793 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler324515190==dftMaxIdleSec=600 scavenging session ids []
18:10:08.793 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.DefaultSessionCache@1d24b706[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] checking expiration on []
18:10:08.793 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler566994926==dftMaxIdleSec=600 scavenging sessions
18:10:08.793 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler566994926==dftMaxIdleSec=600 scavenging session ids []
18:10:08.793 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.DefaultSessionCache@13e35ad2[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] checking expiration on []
18:10:08.793 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler1984585807==dftMaxIdleSec=600 scavenging sessions
18:10:08.793 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler1984585807==dftMaxIdleSec=600 scavenging session ids []
18:10:08.793 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.DefaultSessionCache@17dcdc76[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] checking expiration on []
18:10:08.793 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler1886069934==dftMaxIdleSec=600 scavenging sessions
18:10:08.809 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler1886069934==dftMaxIdleSec=600 scavenging session ids []
18:10:08.809 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.DefaultSessionCache@52de50e9[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] checking expiration on []
18:10:08.809 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler1621473664==dftMaxIdleSec=600 scavenging sessions
18:10:08.809 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler1621473664==dftMaxIdleSec=600 scavenging session ids []
18:10:08.809 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.DefaultSessionCache@6afa4133[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] checking expiration on []
18:10:08.809 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler1423655836==dftMaxIdleSec=600 scavenging sessions
18:10:08.809 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler1423655836==dftMaxIdleSec=600 scavenging session ids []
18:10:08.809 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.DefaultSessionCache@63c6a374[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] checking expiration on []
18:10:08.809 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler1322921968==dftMaxIdleSec=600 scavenging sessions
18:10:08.809 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler1322921968==dftMaxIdleSec=600 scavenging session ids []
18:10:08.809 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.DefaultSessionCache@1208ec16[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] checking expiration on []
18:10:08.824 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler1534952241==dftMaxIdleSec=600 scavenging sessions
18:10:08.824 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler1534952241==dftMaxIdleSec=600 scavenging session ids []
18:10:08.824 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.DefaultSessionCache@32f1afa6[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] checking expiration on []
18:10:08.824 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler393405951==dftMaxIdleSec=600 scavenging sessions
18:10:08.824 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler393405951==dftMaxIdleSec=600 scavenging session ids []
18:10:08.824 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.DefaultSessionCache@a3a9312[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] checking expiration on []
18:10:08.840 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler370440228==dftMaxIdleSec=600 scavenging sessions
18:10:08.840 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler370440228==dftMaxIdleSec=600 scavenging session ids []
18:10:08.840 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.DefaultSessionCache@5c315c22[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] checking expiration on []
18:10:08.840 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler104399791==dftMaxIdleSec=600 scavenging sessions
18:10:08.840 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler104399791==dftMaxIdleSec=600 scavenging session ids []
18:10:08.840 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.DefaultSessionCache@90c63ee[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] checking expiration on []
18:10:08.856 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler984000860==dftMaxIdleSec=600 scavenging sessions
18:10:08.856 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler984000860==dftMaxIdleSec=600 scavenging session ids []
18:10:08.856 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.DefaultSessionCache@36bf71f6[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] checking expiration on []
18:10:08.856 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler604482395==dftMaxIdleSec=600 scavenging sessions
18:10:08.856 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler604482395==dftMaxIdleSec=600 scavenging session ids []
18:10:08.856 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.DefaultSessionCache@6843d630[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] checking expiration on []
18:10:08.871 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler315697359==dftMaxIdleSec=600 scavenging sessions
18:10:08.871 [DEBUG] [org.eclipse.jetty.io.IdleTimeout ] - SocketChannelEndPoint@1b3c6aba{/192.168.170.21:54325<->/192.168.170.2:8080,OPEN,fill=-,flush=-,to=8453/30000}{io=0/0,kio=0,kro=1}->HttpConnection@45effdf5[p=HttpParser{s=END,0 of -1},g=HttpGenerator@3513ac99{s=COMMITTED}]=>HttpChannelOverHttp@1f41431d{r=1,c=true,a=ASYNC_WAIT,uri=//192.168.170.2:8080/rest/events,age=10694807} idle timeout check, elapsed: 8453 ms, remaining: 21547 ms
18:10:08.871 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler315697359==dftMaxIdleSec=600 scavenging session ids []
18:10:08.871 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.DefaultSessionCache@3e454756[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] checking expiration on []
18:10:08.871 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler158257457==dftMaxIdleSec=600 scavenging sessions
18:10:08.871 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.SessionHandler158257457==dftMaxIdleSec=600 scavenging session ids []
18:10:08.871 [DEBUG] [org.eclipse.jetty.server.session ] - org.eclipse.jetty.server.session.DefaultSessionCache@543c5063[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] checking expiration on []
18:10:10.762 [DEBUG] [org.apache.felix.configadmin ] - getConfiguration(pid=org.openhab.addons)
18:10:10.762 [DEBUG] [org.apache.felix.configadmin ] - Found cached configuration org.openhab.addons bound to mvn:org.openhab.core/org.openhab.core.karaf/2.4.0
18:10:10.762 [DEBUG] [org.apache.felix.configadmin ] - getConfiguration(pid=org.ops4j.pax.url.mvn, location=null)
18:10:10.762 [DEBUG] [org.apache.felix.configadmin ] - Explicit Permission; grant configure permission on configuration bound to * to bundle mvn:org.openhab.core/org.openhab.core.karaf/2.4.0
18:10:10.762 [DEBUG] [org.apache.felix.configadmin ] - Found cached configuration org.ops4j.pax.url.mvn bound to ?
18:10:10.762 [DEBUG] [org.apache.felix.configadmin ] - Explicit Permission; grant configure permission on configuration bound to ? to bundle mvn:org.openhab.core/org.openhab.core.karaf/2.4.0
18:10:10.762 [DEBUG] [org.apache.felix.configadmin ] - getConfiguration(pid=org.ops4j.pax.url.mvn, location=null)
18:10:10.762 [DEBUG] [org.apache.felix.configadmin ] - Explicit Permission; grant configure permission on configuration bound to * to bundle mvn:org.openhab.core/org.openhab.core.karaf/2.4.0
18:10:10.777 [DEBUG] [org.apache.felix.configadmin ] - Found cached configuration org.ops4j.pax.url.mvn bound to ?
18:10:10.777 [DEBUG] [org.apache.felix.configadmin ] - Explicit Permission; grant configure permission on configuration bound to ? to bundle mvn:org.openhab.core/org.openhab.core.karaf/2.4.0
18:10:12.168 [DEBUG] [org.apache.http.wire ] - http-outgoing-382 << "[read] I/O error: Read timed out"
18:10:12.168 [DEBUG] [nn.DefaultManagedHttpClientConnection] - http-outgoing-382: Close connection
18:10:12.168 [DEBUG] [nn.DefaultManagedHttpClientConnection] - http-outgoing-382: Shutdown connection
18:10:12.168 [DEBUG] [he.http.impl.execchain.MainClientExec] - Connection discarded
18:10:12.168 [DEBUG] [nn.DefaultManagedHttpClientConnection] - http-outgoing-382: Close connection
18:10:12.168 [DEBUG] [nn.PoolingHttpClientConnectionManager] - Connection released: [id: 382][route: {s}->https://192.168.170.1:49443][total kept alive: 0; route allocated: 0 of 2; total allocated: 0 of 20]
18:10:12.168 [ERROR] [ding.fritzboxtr064.internal.Tr064Comm] - Cannot send/receive: Read timed out
18:10:12.184 [WARN ] [ding.fritzboxtr064.internal.Tr064Comm] - Releasing connection to FritzBox because of error.
18:10:12.184 [DEBUG] [nn.PoolingHttpClientConnectionManager] - Connection manager is shutting down
18:10:12.184 [DEBUG] [nn.PoolingHttpClientConnectionManager] - Connection manager shut down
18:10:12.199 [DEBUG] [he.http.impl.execchain.MainClientExec] - Cancelling request execution
18:10:12.199 [WARN ] [ding.fritzboxtr064.internal.Tr064Comm] - Error retrieving SOAP response from FritzBox
Someone an idea, where is the problem?