[SOLVED] AVM FRITZ! Binding loses Connection a day after restart OH2.5.0.M3

fibu-freak · October 17, 2019, 2:11pm

Since a while I observe that the connection between Fritz-Box and Binding seems to be broken a day after restart. No bundle restart helps. There are no ERROR-Messages in the log.

When discovered it I activated “DEBUG” in the console and get that logging:

2019-10-15 09:18:20.340 [DEBUG] [al.handler.AVMFritzBaseBridgeHandler] - Poll FRITZ!Box for updates avmfritz:fritzbox:Fritz-Box-7490
2019-10-15 09:18:20.348 [DEBUG] [ternal.hardware.FritzAhaWebInterface] - Failed to GET url 'http://fritz.box/login_sid.lua': java.util.concurrent.RejectedExecutionException: Max requests queued per destination 1024 exceeded for HttpDestination[http://fritz.box]@1a6987e,queue=1024,pool=DuplexConnectionPool@ac2756[c=2/2,a=2,i=0]
java.util.concurrent.ExecutionException: java.util.concurrent.RejectedExecutionException: Max requests queued per destination 1024 exceeded for HttpDestination[http://fritz.box]@1a6987e,queue=1024,pool=DuplexConnectionPool@ac2756[c=2/2,a=2,i=0]
	at org.eclipse.jetty.client.util.FutureResponseListener.getResult(FutureResponseListener.java:118) ~[?:?]
	at org.eclipse.jetty.client.util.FutureResponseListener.get(FutureResponseListener.java:101) ~[?:?]
	at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:683) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.FritzAhaWebInterface.syncGet(FritzAhaWebInterface.java:252) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.FritzAhaWebInterface.authenticate(FritzAhaWebInterface.java:100) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.FritzAhaWebInterface.asyncGet(FritzAhaWebInterface.java:271) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.FritzAhaWebInterface.asyncGet(FritzAhaWebInterface.java:281) ~[?:?]
	at org.openhab.binding.avmfritz.internal.handler.AVMFritzBaseBridgeHandler.poll(AVMFritzBaseBridgeHandler.java:188) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.util.concurrent.RejectedExecutionException: Max requests queued per destination 1024 exceeded for HttpDestination[http://fritz.box]@1a6987e,queue=1024,pool=DuplexConnectionPool@ac2756[c=2/2,a=2,i=0]
	at org.eclipse.jetty.client.HttpDestination.send(HttpDestination.java:276) ~[?:?]
	at org.eclipse.jetty.client.HttpDestination.send(HttpDestination.java:246) ~[?:?]
	at org.eclipse.jetty.client.HttpClient.send(HttpClient.java:576) ~[?:?]
	at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:726) ~[?:?]
	at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:679) ~[?:?]
	... 12 more
2019-10-15 09:18:20.416 [DEBUG] [nal.hardware.FritzAhaContentExchange] - response failed: Max requests queued per destination 1024 exceeded for HttpDestination[http://fritz.box]@1a6987e,queue=1024,pool=DuplexConnectionPool@ac2756[c=2/2,a=2,i=0]
2019-10-15 09:18:20.419 [DEBUG] [nal.hardware.FritzAhaContentExchange] - response failed: Max requests queued per destination 1024 exceeded for HttpDestination[http://fritz.box]@1a6987e,queue=1024,pool=DuplexConnectionPool@ac2756[c=2/2,a=2,i=0]
2019-10-15 09:18:20.421 [DEBUG] [nal.hardware.FritzAhaContentExchange] - response complete: null
2019-10-15 09:18:20.424 [DEBUG] [ternal.hardware.FritzAhaWebInterface] - Failed to GET url 'http://fritz.box/login_sid.lua': java.util.concurrent.RejectedExecutionException: Max requests queued per destination 1024 exceeded for HttpDestination[http://fritz.box]@1a6987e,queue=1024,pool=DuplexConnectionPool@ac2756[c=2/2,a=2,i=0]
java.util.concurrent.ExecutionException: java.util.concurrent.RejectedExecutionException: Max requests queued per destination 1024 exceeded for HttpDestination[http://fritz.box]@1a6987e,queue=1024,pool=DuplexConnectionPool@ac2756[c=2/2,a=2,i=0]
	at org.eclipse.jetty.client.util.FutureResponseListener.getResult(FutureResponseListener.java:118) ~[?:?]
	at org.eclipse.jetty.client.util.FutureResponseListener.get(FutureResponseListener.java:101) ~[?:?]
	at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:683) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.FritzAhaWebInterface.syncGet(FritzAhaWebInterface.java:252) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.FritzAhaWebInterface.authenticate(FritzAhaWebInterface.java:100) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.callbacks.FritzAhaReauthCallback.execute(FritzAhaReauthCallback.java:105) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.callbacks.FritzAhaUpdateCallback.execute(FritzAhaUpdateCallback.java:60) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.FritzAhaContentExchange.onComplete(FritzAhaContentExchange.java:74) ~[?:?]
	at org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:196) ~[?:?]
	at org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:188) ~[?:?]
	at org.eclipse.jetty.client.HttpExchange.notifyFailureComplete(HttpExchange.java:269) ~[?:?]
	at org.eclipse.jetty.client.HttpExchange.abort(HttpExchange.java:252) ~[?:?]
	at org.eclipse.jetty.client.HttpConversation.abort(HttpConversation.java:149) ~[?:?]
	at org.eclipse.jetty.client.HttpRequest.abort(HttpRequest.java:766) ~[?:?]
	at org.eclipse.jetty.client.HttpDestination.send(HttpDestination.java:276) ~[?:?]
	at org.eclipse.jetty.client.HttpDestination.send(HttpDestination.java:246) ~[?:?]
	at org.eclipse.jetty.client.HttpClient.send(HttpClient.java:576) ~[?:?]
	at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:726) ~[?:?]
	at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:718) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.FritzAhaWebInterface.asyncGet(FritzAhaWebInterface.java:276) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.FritzAhaWebInterface.asyncGet(FritzAhaWebInterface.java:281) ~[?:?]
	at org.openhab.binding.avmfritz.internal.handler.AVMFritzBaseBridgeHandler.poll(AVMFritzBaseBridgeHandler.java:188) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.util.concurrent.RejectedExecutionException: Max requests queued per destination 1024 exceeded for HttpDestination[http://fritz.box]@1a6987e,queue=1024,pool=DuplexConnectionPool@ac2756[c=2/2,a=2,i=0]
	at org.eclipse.jetty.client.HttpDestination.send(HttpDestination.java:276) ~[?:?]
	at org.eclipse.jetty.client.HttpDestination.send(HttpDestination.java:246) ~[?:?]
	at org.eclipse.jetty.client.HttpClient.send(HttpClient.java:576) ~[?:?]
	at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:726) ~[?:?]
	at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:679) ~[?:?]
	... 26 more
2019-10-15 09:18:20.485 [DEBUG] [ternal.hardware.FritzAhaWebInterface] - Failed to GET url 'http://fritz.box/login_sid.lua': java.util.concurrent.RejectedExecutionException: Max requests queued per destination 1024 exceeded for HttpDestination[http://fritz.box]@1a6987e,queue=1024,pool=DuplexConnectionPool@ac2756[c=2/2,a=2,i=0]
java.util.concurrent.ExecutionException: java.util.concurrent.RejectedExecutionException: Max requests queued per destination 1024 exceeded for HttpDestination[http://fritz.box]@1a6987e,queue=1024,pool=DuplexConnectionPool@ac2756[c=2/2,a=2,i=0]
	at org.eclipse.jetty.client.util.FutureResponseListener.getResult(FutureResponseListener.java:118) ~[?:?]
	at org.eclipse.jetty.client.util.FutureResponseListener.get(FutureResponseListener.java:101) ~[?:?]
	at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:683) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.FritzAhaWebInterface.syncGet(FritzAhaWebInterface.java:252) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.FritzAhaWebInterface.authenticate(FritzAhaWebInterface.java:100) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.FritzAhaWebInterface.asyncGet(FritzAhaWebInterface.java:271) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.callbacks.FritzAhaReauthCallback.execute(FritzAhaReauthCallback.java:108) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.callbacks.FritzAhaUpdateCallback.execute(FritzAhaUpdateCallback.java:60) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.FritzAhaContentExchange.onComplete(FritzAhaContentExchange.java:74) ~[?:?]
	at org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:196) ~[?:?]
	at org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:188) ~[?:?]
	at org.eclipse.jetty.client.HttpExchange.notifyFailureComplete(HttpExchange.java:269) ~[?:?]
	at org.eclipse.jetty.client.HttpExchange.abort(HttpExchange.java:252) ~[?:?]
	at org.eclipse.jetty.client.HttpConversation.abort(HttpConversation.java:149) ~[?:?]
	at org.eclipse.jetty.client.HttpRequest.abort(HttpRequest.java:766) ~[?:?]
	at org.eclipse.jetty.client.HttpDestination.send(HttpDestination.java:276) ~[?:?]
	at org.eclipse.jetty.client.HttpDestination.send(HttpDestination.java:246) ~[?:?]
	at org.eclipse.jetty.client.HttpClient.send(HttpClient.java:576) ~[?:?]
	at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:726) ~[?:?]
	at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:718) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.FritzAhaWebInterface.asyncGet(FritzAhaWebInterface.java:276) ~[?:?]
	at org.openhab.binding.avmfritz.internal.hardware.FritzAhaWebInterface.asyncGet(FritzAhaWebInterface.java:281) ~[?:?]
	at org.openhab.binding.avmfritz.internal.handler.AVMFritzBaseBridgeHandler.poll(AVMFritzBaseBridgeHandler.java:188) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.util.concurrent.RejectedExecutionException: Max requests queued per destination 1024 exceeded for HttpDestination[http://fritz.box]@1a6987e,queue=1024,pool=DuplexConnectionPool@ac2756[c=2/2,a=2,i=0]
	at org.eclipse.jetty.client.HttpDestination.send(HttpDestination.java:276) ~[?:?]
	at org.eclipse.jetty.client.HttpDestination.send(HttpDestination.java:246) ~[?:?]
	at org.eclipse.jetty.client.HttpClient.send(HttpClient.java:576) ~[?:?]
	at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:726) ~[?:?]
	at org.eclipse.jetty.client.HttpRequest.send(HttpRequest.java:679) ~[?:?]
	... 27 more
2019-10-15 09:18:20.546 [DEBUG] [nal.hardware.FritzAhaContentExchange] - response failed: Max requests queued per destination 1024 exceeded for HttpDestination[http://fritz.box]@1a6987e,queue=1024,pool=DuplexConnectionPool@ac2756[c=2/2,a=2,i=0]
2019-10-15 09:18:20.549 [DEBUG] [nal.hardware.FritzAhaContentExchange] - response failed: Max requests queued per destination 1024 exceeded for HttpDestination[http://fritz.box]@1a6987e,queue=1024,pool=DuplexConnectionPool@ac2756[c=2/2,a=2,i=0]
2019-10-15 09:18:20.551 [DEBUG] [nal.hardware.FritzAhaContentExchange] - response complete: null
2019-10-15 09:18:20.553 [DEBUG] [are.callbacks.FritzAhaUpdateCallback] - request is invalid: 0
2019-10-15 09:18:20.557 [DEBUG] [are.callbacks.FritzAhaUpdateCallback] - request is invalid: 0
2019-10-15 09:18:35.561 [DEBUG] [al.handle

when working normal the DEBUG shows:

2019-10-15 20:11:53.834 [DEBUG] [nal.hardware.FritzAhaContentExchange] - HTTP response: 200
2019-10-15 20:11:53.838 [DEBUG] [nal.hardware.FritzAhaContentExchange] - HTTP response: 200
2019-10-15 20:11:53.842 [DEBUG] [nal.hardware.FritzAhaContentExchange] - response complete: <devicelist version="1"><device identifier="11960 1003400" id="17" functionbitmask="320" fwversion="03.54" manufacturer="AVM" productname="Comet DECT"><present>1</present><name>Comet DECT #1 Arbeitszimmer</name><battery>60</battery><batterylow>0</batterylow><temperature><celsius>210</celsius><offset>-10</offset></temperature><hkr><tist>42</tist><tsoll>34</tsoll><absenk>34</absenk><komfort>44</komfort><lock>0</lock><devicelock>0</devicelock><errorcode>0</errorcode><windowopenactiv>0</windowopenactiv><batterylow>0</batterylow><battery>60</battery><nextchange><endperiod>0</endperiod><tchange>44</tchange></nextchange><summeractive>0</summeractive><holidayactive>0</holidayactive></hkr></device><device identifier="11960 0949320" id="18" functionbitmask="320" fwversion="03.54" manufacturer="AVM" productname="Comet DECT"><present>1</present><name>Comet DECT #2 Zimmer Peter</name><battery>60</battery><batterylow>0</batterylow><temperature><celsius>225</celsius><offset>10</offset></temperature><hkr><tist>45</tist><tsoll>42</tsoll><absenk>32</absenk><komfort>42</komfort><lock>0</lock><devicelock>0</devicelock><errorcode>0</errorcode><windowopenactiv>0</windowopenactiv><batterylow>0</batterylow><battery>60</battery><nextchange><endperiod>1571169600</endperiod><tchange>32</tchange></nextchange><summeractive>0</summeractive><holidayactive>0</holidayactive></hkr></device><device identifier="09995 0152273" id="28" functionbitmask="320" fwversion="04.89" manufacturer="AVM" productname="FRITZ!DECT 301"><present>1</present><name>FRITZ!DECT 301 #3 ELW Wohnzi </name><battery>100</battery><batterylow>0</batterylow><temperature><celsius>190</celsius><offset>-10</offset></temperature><hkr><tist>38</tist><tsoll>42</tsoll><absenk>32</absenk><komfort>42</komfort><lock>0</lock><devicelock>0</devicelock><errorcode>0</errorcode><windowopenactiv>0</windowopenactiv><batterylow>0</batterylow><battery>100</battery><nextchange><endperiod>1571169600</endperiod><tchange>32</tchange></nextchange><summeractive>0</summeractive><holidayactive>0</holidayactive></hkr></device><device identifier="09995 0074210" id="20" functionbitmask="320" fwversion="04.89" manufacturer="AVM" productname="FRITZ!DECT 301"><present>1</present><name>FRITZ!DECT 301 #4 Bad</name><battery>90</battery><batterylow>0</batterylow><temperature><celsius>185</celsius><offset>-15</offset></temperature><hkr><tist>37</tist><tsoll>36</tsoll><absenk>36</absenk><komfort>46</komfort><lock>0</lock><devicelock>0</devicelock><errorcode>0</errorcode><windowopenactiv>0</windowopenactiv><batterylow>0</batterylow><battery>90</battery><nextchange><endperiod>0</endperiod><tchange>46</tchange></nextchange><summeractive>0</summeractive><holidayactive>0</holidayactive></hkr></device><device identifier="11795 0357048" id="25" functionbitmask="320" fwversion="03.54" manufacturer="AVM" productname="Comet DECT"><present>1</present><name>Comet DECT #5 - ELW Bad</name><battery>50</battery><batterylow>0</batterylow><temperature><celsius>185</celsius><offset>0</offset></temperature><hkr><tist>37</tist><tsoll>44</tsoll><absenk>36</absenk><komfort>44</komfort><lock>0</lock><devicelock>0</devicelock><errorcode>0</errorcode><windowopenactiv>0</windowopenactiv><batterylow>0</batterylow><battery>50</battery><nextchange><endperiod>1571171400</endperiod><tchange>36</tchange></nextchange><summeractive>0</summeractive><holidayactive>0</holidayactive></hkr></device><device identifier="11960 0710200" id="22" functionbitmask="320" fwversion="03.54" manufacturer="AVM" productname="Comet DECT"><present>1</present><name>Comet DECT #6 - Claudia</name><battery>50</battery><batterylow>0</batterylow><temperature><celsius>200</celsius><offset>-10</offset></temperature><hkr><tist>40</tist><tsoll>32</tsoll><absenk>32</absenk><komfort>42</komfort><lock>0</lock><devicelock>0</devicelock><errorcode>0</errorcode><windowopenactiv>0</windowopenactiv><batterylow>0</batterylow><battery>50</battery><nextchange><endperiod>1571169600</endperiod><tchange>32</tchange></nextchange><summeractive>0</summeractive><holidayactive>0</holidayactive></hkr></device><device identifier="09995 0133789" id="29" functionbitmask="320" fwversion="04.89" manufacturer="AVM" productname="FRITZ!DECT 301"><present>1</present><name>FRITZ!DECT 301 #7 ELW Schlaf</name><battery>100</battery><batterylow>0</batterylow><temperature><celsius>185</celsius><offset>-10</offset></temperature><hkr><tist>37</tist><tsoll>44</tsoll><absenk>36</absenk><komfort>44</komfort><lock>0</lock><devicelock>0</devicelock><errorcode>0</errorcode><windowopenactiv>0</windowopenactiv><batterylow>0</batterylow><battery>100</battery><nextchange><endperiod>1571173200</endperiod><tchange>36</tchange></nextchange><summeractive>0</summeractive><holidayactive>0</holidayactive></hkr></device><device identifier="11657 0136076" id="27" functionbitmask="2944" fwversion="04.17" manufacturer="AVM" productname="FRITZ!DECT 210"><present>1</present><name>Steckdose FRITZ!DECT 210 #1 - Garage</name><switch><state>0</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><powermeter><voltage>236577</voltage><power>0</power><energy>23</energy></powermeter><temperature><celsius>175</celsius><offset>0</offset></temperature></device><device identifier="08761 0467933" id="21" functionbitmask="2944" fwversion="04.16" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><name>Steckdose FRITZ!DECT 200 #2 - Küche Dun</name><switch><state>1</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><powermeter><voltage>236444</voltage><power>1070</power><energy>32114</energy></powermeter><temperature><celsius>265</celsius><offset>0</offset></temperature></device><device identifier="11657 0075282" id="24" functionbitmask="2944" fwversion="04.17" manufacturer="AVM" productname="FRITZ!DECT 210"><present>1</present><name>Steckdose FRITZ!DECT 210 #3 - Dachboden</name><switch><state>1</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><powermeter><voltage>238285</voltage><power>1410</power><energy>11531</energy></powermeter><temperature><celsius>180</celsius><offset>-5</offset></temperature></device><device identifier="08761 0494097" id="23" functionbitmask="2944" fwversion="04.16" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><name>Steckdose FRITZ!DECT 200 #4 - Büro</name><switch><state>1</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><powermeter><voltage>236556</voltage><power>24390</power><energy>210938</energy></powermeter><temperature><celsius>240</celsius><offset>0</offset></temperature></device></devicelist>
2019-10-15 20:11:53.957 [DEBUG] [al.handler.AVMFritzBaseBridgeHandler] - update thing 'avmfritz:FRITZ_DECT_210:Fritz-Box-7490:116570136076' with device model: org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@1b73e7[org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@1b73e7[ain=116570136076,bitmask=2944,isHANFUNDevice=false,isButton=false,isAlarmSensor=false,isSwitchableOutlet=true,isTempSensor=true,isPowermeter=true,isDectRepeater=false,isHeatingThermostat=false,isMicrophone=true,isHANFUNUnit=false,id=27,manufacturer=AVM,productname=FRITZ!DECT 210,fwversion=04.17,present=1,name=Steckdose FRITZ!DECT 210 #1 - Garage,org.openhab.binding.avmfritz.internal.ahamodel.SwitchModel@106d351[state=0,mode=MANUAL,lock=0,devicelock=0],org.openhab.binding.avmfritz.internal.ahamodel.PowerMeterModel@1c7e4ab[voltage=236.577,power=0.000,energy=23],<null>],org.openhab.binding.avmfritz.internal.ahamodel.TemperatureModel@16c0719[celsius=17.5,offset=0.0],<null>,<null>,<null>]
2019-10-15 20:11:53.986 [DEBUG] [al.handler.AVMFritzBaseBridgeHandler] - update thing 'avmfritz:FRITZ_DECT_200:Fritz-Box-7490:087610467933' with device model: org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@37c818[org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@37c818[ain=087610467933,bitmask=2944,isHANFUNDevice=false,isButton=false,isAlarmSensor=false,isSwitchableOutlet=true,isTempSensor=true,isPowermeter=true,isDectRepeater=false,isHeatingThermostat=false,isMicrophone=true,isHANFUNUnit=false,id=21,manufacturer=AVM,productname=FRITZ!DECT 200,fwversion=04.16,present=1,name=Steckdose FRITZ!DECT 200 #2 - Küche Dun,org.openhab.binding.avmfritz.internal.ahamodel.SwitchModel@1761454[state=1,mode=MANUAL,lock=0,devicelock=0],org.openhab.binding.avmfritz.internal.ahamodel.PowerMeterModel@1064aad[voltage=236.444,power=1.070,energy=32114],<null>],org.openhab.binding.avmfritz.internal.ahamodel.TemperatureModel@37c3db[celsius=26.5,offset=0.0],<null>,<null>,<null>]
2019-10-15 20:11:54.017 [DEBUG] [al.handler.AVMFritzBaseBridgeHandler] - update thing 'avmfritz:FRITZ_DECT_210:Fritz-Box-7490:116570075282' with device model: org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@24a2cd[org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@24a2cd[ain=116570075282,bitmask=2944,isHANFUNDevice=false,isButton=false,isAlarmSensor=false,isSwitchableOutlet=true,isTempSensor=true,isPowermeter=true,isDectRepeater=false,isHeatingThermostat=false,isMicrophone=true,isHANFUNUnit=false,id=24,manufacturer=AVM,productname=FRITZ!DECT 210,fwversion=04.17,present=1,name=Steckdose FRITZ!DECT 210 #3 - Dachboden,org.openhab.binding.avmfritz.internal.ahamodel.SwitchModel@147d0a9[state=1,mode=MANUAL,lock=0,devicelock=0],org.openhab.binding.avmfritz.internal.ahamodel.PowerMeterModel@b3a54e[voltage=238.285,power=1.410,energy=11531],<null>],org.openhab.binding.avmfritz.internal.ahamodel.TemperatureModel@d48718[celsius=18.0,offset=-0.5],<null>,<null>,<null>]
2019-10-15 20:11:54.073 [DEBUG] [al.handler.AVMFritzBaseBridgeHandler] - update thing 'avmfritz:FRITZ_DECT_200:Fritz-Box-7490:087610494097' with device model: org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@1576645[org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@1576645[ain=087610494097,bitmask=2944,isHANFUNDevice=false,isButton=false,isAlarmSensor=false,isSwitchableOutlet=true,isTempSensor=true,isPowermeter=true,isDectRepeater=false,isHeatingThermostat=false,isMicrophone=true,isHANFUNUnit=false,id=23,manufacturer=AVM,productname=FRITZ!DECT 200,fwversion=04.16,present=1,name=Steckdose FRITZ!DECT 200 #4 - Büro,org.openhab.binding.avmfritz.internal.ahamodel.SwitchModel@88331e[state=1,mode=MANUAL,lock=0,devicelock=0],org.openhab.binding.avmfritz.internal.ahamodel.PowerMeterModel@1087354[voltage=236.556,power=24.390,energy=210938],<null>],org.openhab.binding.avmfritz.internal.ahamodel.TemperatureModel@18ad7ea[celsius=24.0,offset=0.0],<null>,<null>,<null>]
2019-10-15 20:11:54.098 [DEBUG] [al.handler.AVMFritzBaseBridgeHandler] - update thing 'avmfritz:Comet_DECT:Fritz-Box-7490:119601003400' with device model: org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@12ffed0[org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@12ffed0[ain=119601003400,bitmask=320,isHANFUNDevice=false,isButton=false,isAlarmSensor=false,isSwitchableOutlet=false,isTempSensor=true,isPowermeter=false,isDectRepeater=false,isHeatingThermostat=true,isMicrophone=false,isHANFUNUnit=false,id=17,manufacturer=AVM,productname=Comet DECT,fwversion=03.54,present=1,name=Comet DECT #1 Arbeitszimmer,<null>,<null>,org.openhab.binding.avmfritz.internal.ahamodel.HeatingModel@183728[tist=42,tsoll=34,absenk=34,komfort=44,lock=0,devicelock=0,errorcode=0,batterylow=0,windowopenactiv=0,battery=60,nextchange=org.openhab.binding.avmfritz.internal.ahamodel.HeatingModel$NextChangeModel@b6686c[endperiod=0,tchange=44],summeractive=0,holidayactive=0]],org.openhab.binding.avmfritz.internal.ahamodel.TemperatureModel@1c4c357[celsius=21.0,offset=-1.0],<null>,<null>,<null>]
2019-10-15 20:11:54.134 [DEBUG] [al.handler.AVMFritzBaseBridgeHandler] - update thing 'avmfritz:Comet_DECT:Fritz-Box-7490:119600949320' with device model: org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@1b37541[org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@1b37541[ain=119600949320,bitmask=320,isHANFUNDevice=false,isButton=false,isAlarmSensor=false,isSwitchableOutlet=false,isTempSensor=true,isPowermeter=false,isDectRepeater=false,isHeatingThermostat=true,isMicrophone=false,isHANFUNUnit=false,id=18,manufacturer=AVM,productname=Comet DECT,fwversion=03.54,present=1,name=Comet DECT #2 Zimmer Peter,<null>,<null>,org.openhab.binding.avmfritz.internal.ahamodel.HeatingModel@25a768[tist=45,tsoll=42,absenk=32,komfort=42,lock=0,devicelock=0,errorcode=0,batterylow=0,windowopenactiv=0,battery=60,nextchange=org.openhab.binding.avmfritz.internal.ahamodel.HeatingModel$NextChangeModel@1a95888[endperiod=1571169600,tchange=32],summeractive=0,holidayactive=0]],org.openhab.binding.avmfritz.internal.ahamodel.TemperatureModel@dcf011[celsius=22.5,offset=1.0],<null>,<null>,<null>]
2019-10-15 20:11:54.161 [DEBUG] [al.handler.AVMFritzBaseBridgeHandler] - update thing 'avmfritz:FRITZ_DECT_301:Fritz-Box-7490:099950152273' with device model: org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@7d8cf6[org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@7d8cf6[ain=099950152273,bitmask=320,isHANFUNDevice=false,isButton=false,isAlarmSensor=false,isSwitchableOutlet=false,isTempSensor=true,isPowermeter=false,isDectRepeater=false,isHeatingThermostat=true,isMicrophone=false,isHANFUNUnit=false,id=28,manufacturer=AVM,productname=FRITZ!DECT 301,fwversion=04.89,present=1,name=FRITZ!DECT 301 #3 ELW Wohnzi ,<null>,<null>,org.openhab.binding.avmfritz.internal.ahamodel.HeatingModel@15a7ab6[tist=38,tsoll=42,absenk=32,komfort=42,lock=0,devicelock=0,errorcode=0,batterylow=0,windowopenactiv=0,battery=100,nextchange=org.openhab.binding.avmfritz.internal.ahamodel.HeatingModel$NextChangeModel@1007cd[endperiod=1571169600,tchange=32],summeractive=0,holidayactive=0]],org.openhab.binding.avmfritz.internal.ahamodel.TemperatureModel@16d2fa6[celsius=19.0,offset=-1.0],<null>,<null>,<null>]
2019-10-15 20:11:54.185 [DEBUG] [al.handler.AVMFritzBaseBridgeHandler] - update thing 'avmfritz:FRITZ_DECT_301:Fritz-Box-7490:099950074210' with device model: org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@1e50141[org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@1e50141[ain=099950074210,bitmask=320,isHANFUNDevice=false,isButton=false,isAlarmSensor=false,isSwitchableOutlet=false,isTempSensor=true,isPowermeter=false,isDectRepeater=false,isHeatingThermostat=true,isMicrophone=false,isHANFUNUnit=false,id=20,manufacturer=AVM,productname=FRITZ!DECT 301,fwversion=04.89,present=1,name=FRITZ!DECT 301 #4 Bad,<null>,<null>,org.openhab.binding.avmfritz.internal.ahamodel.HeatingModel@1fe5e41[tist=37,tsoll=36,absenk=36,komfort=46,lock=0,devicelock=0,errorcode=0,batterylow=0,windowopenactiv=0,battery=90,nextchange=org.openhab.binding.avmfritz.internal.ahamodel.HeatingModel$NextChangeModel@130171c[endperiod=0,tchange=46],summeractive=0,holidayactive=0]],org.openhab.binding.avmfritz.internal.ahamodel.TemperatureModel@1080c43[celsius=18.5,offset=-1.5],<null>,<null>,<null>]
2019-10-15 20:11:54.222 [DEBUG] [al.handler.AVMFritzBaseBridgeHandler] - update thing 'avmfritz:Comet_DECT:Fritz-Box-7490:117950357048' with device model: org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@1cfbea[org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@1cfbea[ain=117950357048,bitmask=320,isHANFUNDevice=false,isButton=false,isAlarmSensor=false,isSwitchableOutlet=false,isTempSensor=true,isPowermeter=false,isDectRepeater=false,isHeatingThermostat=true,isMicrophone=false,isHANFUNUnit=false,id=25,manufacturer=AVM,productname=Comet DECT,fwversion=03.54,present=1,name=Comet DECT #5 - ELW Bad,<null>,<null>,org.openhab.binding.avmfritz.internal.ahamodel.HeatingModel@1a5af7e[tist=37,tsoll=44,absenk=36,komfort=44,lock=0,devicelock=0,errorcode=0,batterylow=0,windowopenactiv=0,battery=50,nextchange=org.openhab.binding.avmfritz.internal.ahamodel.HeatingModel$NextChangeModel@ac8a1[endperiod=1571171400,tchange=36],summeractive=0,holidayactive=0]],org.openhab.binding.avmfritz.internal.ahamodel.TemperatureModel@1afaa37[celsius=18.5,offset=0.0],<null>,<null>,<null>]
2019-10-15 20:11:54.256 [DEBUG] [al.handler.AVMFritzBaseBridgeHandler] - update thing 'avmfritz:Comet_DECT:Fritz-Box-7490:119600710200' with device model: org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@ffc743[org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@ffc743[ain=119600710200,bitmask=320,isHANFUNDevice=false,isButton=false,isAlarmSensor=false,isSwitchableOutlet=false,isTempSensor=true,isPowermeter=false,isDectRepeater=false,isHeatingThermostat=true,isMicrophone=false,isHANFUNUnit=false,id=22,manufacturer=AVM,productname=Comet DECT,fwversion=03.54,present=1,name=Comet DECT #6 - Claudia,<null>,<null>,org.openhab.binding.avmfritz.internal.ahamodel.HeatingModel@cd513d[tist=40,tsoll=32,absenk=32,komfort=42,lock=0,devicelock=0,errorcode=0,batterylow=0,windowopenactiv=0,battery=50,nextchange=org.openhab.binding.avmfritz.internal.ahamodel.HeatingModel$NextChangeModel@32d485[endperiod=1571169600,tchange=32],summeractive=0,holidayactive=0]],org.openhab.binding.avmfritz.internal.ahamodel.TemperatureModel@982466[celsius=20.0,offset=-1.0],<null>,<null>,<null>]
2019-10-15 20:11:54.285 [DEBUG] [al.handler.AVMFritzBaseBridgeHandler] - update thing 'avmfritz:FRITZ_DECT_301:Fritz-Box-7490:099950133789' with device model: org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@1928a9[org.openhab.binding.avmfritz.internal.ahamodel.DeviceModel@1928a9[ain=099950133789,bitmask=320,isHANFUNDevice=false,isButton=false,isAlarmSensor=false,isSwitchableOutlet=false,isTempSensor=true,isPowermeter=false,isDectRepeater=false,isHeatingThermostat=true,isMicrophone=false,isHANFUNUnit=false,id=29,manufacturer=AVM,productname=FRITZ!DECT 301,fwversion=04.89,present=1,name=FRITZ!DECT 301 #7 ELW Schlaf,<null>,<null>,org.openhab.binding.avmfritz.internal.ahamodel.HeatingModel@61cbee[tist=37,tsoll=44,absenk=36,komfort=44,lock=0,devicelock=0,errorcode=0,batterylow=0,windowopenactiv=0,battery=100,nextchange=org.openhab.binding.avmfritz.internal.ahamodel.HeatingModel$NextChangeModel@87b8db[endperiod=1571173200,tchange=36],summeractive=0,holidayactive=0]],org.openhab.binding.avmfritz.internal.ahamodel.TemperatureModel@14f00f9[celsius=18.5,offset=-1.0],<null>,<null>,<null>]
2019-10-15 20:12:02.746 [DEBUG] [al.handler.AVMFritzBaseBridgeHandler] - Poll FRITZ!Box for updates avmfritz:fritzbox:Fritz-Box-7490
2019-10-15 20:12:06.124 [DEBUG] [nal.hardware.FritzAhaContentExchange] - HTTP response: 200
2019-10-15 20:12:06.129 [DEBUG] [nal.hardware.FritzAhaContentExchange] - HTTP response: 200
2

dk.mailbox · December 3, 2019, 9:34pm

Can I raise the flag on this topic - I’ve the same issue here, Fritzbox 7490, same DEBUG log messages as OP.

I’m using openHab 2.5.0.M6 as of today, running in docker on raspian. After container restart, the avmfritz binding works for a while; then I get the debug/error messages indicted above.
I’m connecting to a 7490, latest software version, dedicated user for openhab/smart home capabilities.

Any ideas at all, what might be causing this? This is kind of the last hurdle between me and openhab bliss…

fibu-freak · December 4, 2019, 12:17pm

Hi Daniel,

when switching to OH 2.5 M5 it seemed that the error was gone, but this morning I observed it again under OH2.5.M6. Don’t know what can help. Maybe @cweitkamp can help ?

dk.mailbox · December 4, 2019, 1:41pm

Hi Peter, I’ve also had that issue with M5 - was hoping for a resolution with M6 but alas…

Beginning to think about the issue and what I can do… Dummy question: does the docker image bring its own jre? The one in raspian is some 1.8, oldish…
I’ve had the polling interval on my fritzbox thing reduced to 10 secs (instead of the default 15) - reverted to default yesterday, but I don’t expect that will change anything.

… might have to get a dev workspace set up on my machine to look at the code…

fibu-freak · December 4, 2019, 2:00pm

I think Version 1.8 is the one on which OH is based for “openhabian hassle free”. I don’t know if there are higher Versions possible on other Distributions like Docker or manual Installations.

How did you create your Bridge and the Things ? Via PaperUI or via textual files? I’m using textual ones.

miba · December 4, 2019, 2:15pm

Actually, the problem already seemed to be solved. Strange… For the sake of completeness, here are the corresponding threads:

https://github.com/openhab/openhab2-addons/issues/4558

dk.mailbox · December 4, 2019, 7:20pm

@fibu-freak I’m a complete openHab noob, so I’m exclusively using the Paper UI for now.

@Michael I’ve not set up an openHab dev workspace yet, didn’t check whether the fix you refer to made it into the 2.5 milestones - but I definitely have that issue in M6, had it with M5, and I’ve before that tried M4 and M3 to see whether things would be better there (they weren’t).

So either that fix isn’t covering it all, or there’s been a regression somewhere along the way.

(also, contrary to what’s described in the thread you linked: the issue happens on my setup also without the FritzBox having restarted - it’s enough to let things run for a couple of hours after openHab restart)

Is there anything useful I can do to facilitate analysis? Short of getting a workspace set up

dk.mailbox · December 5, 2019, 9:08pm

Any ideas?

Also: I am trying to get a workspace set up, both attempts so far didn’t work out of the box (and I’m trying to play around with starting conditions rather than get mad over maven errors…). The docs say, openHab wants a 1.8 JDK - does that have to be an Oracle JDK, or should openJDK also be good?

cweitkamp · December 7, 2019, 10:22am

Hi all,

Sry, I never saw such an error before. I will not have much time for a deeper investigation. OH 2.5 release is coming …

dk.mailbox · December 9, 2019, 5:17pm

Yesterday I removed and reconfigured the avmfritz binding, only added the router so far (not any dependent devices) - so far this is running fine, since about 22hours now. Will extend the config again with attached devices bit by bit, see if it remains so.
Let’s see what happens first - I get a usable workspace up, or the openhab setup stabilizes

fibu-freak · December 9, 2019, 8:44pm

Hi Christoph,
do you think that 2.5stable will solve the problem ?

cweitkamp · December 9, 2019, 8:50pm

No, it will not. I am not aware that someone did implement a fix for it.

dk.mailbox · December 9, 2019, 8:52pm

Got a workspace up and running now - no idea whatsoever what is different now, opposed to the last couple of evenings. Anyways, feels good to be over that hurdle.

avmfritz binding on my openhab also running fine so far; but something is generally strange in how things behave. For example, after a day of running it now ‘discovered’ my powerline adapter, which it never did in previous attempts (where I immediately added the other discovered things - no idea whether there is a correlation there).
I’ll let it run for another day in the current state, then add the next discovered thing. In parallel, lets see whether I can get my bearings around the binding codebase.

fibu-freak · December 9, 2019, 8:55pm

thx for answering. That’s too bad. Do you not maintain the binding anymore ?

cweitkamp · December 9, 2019, 9:12pm

I do. But my time is limited. Priority is openHAB Core. Additionally I am not very happy with the code anymore.

To give you a glimmer of hope: I am planning a huge refactoring of the binding for OH3 which not only improves the code but hopefully provides a lot more features - e.g. I would like to merge the OH2 AVM FRITZ! binding and the OH1 TR064 binding into one code base.

One note: Do not nail me on that …

fibu-freak · December 9, 2019, 9:25pm

…I won’t do that. I’m glad to hear that you are still in the project, and I really understand your limited time slots and the priorities you set within.
At this point, thanks from my side for the work you(and of course all the other developers, maintainers, etc) have done in the past and for efforts and the time you’ll spend for OH in the future…
Cheers,
Peter

dk.mailbox · December 9, 2019, 9:27pm

@cweitkamp That does sound good. If you have some menial work to hand out in that scope, give me a shout out!

Don’t nail me on that either

dk.mailbox · December 17, 2019, 2:58pm

Update: the avmfritz setup has now been working for me, for more than a week. I have no clue what’s changed, other than that I re-created the binding and added devices one after the other, with a day or two in between to observe whether things remain stable.

fibu-freak · December 17, 2019, 4:57pm

Hi Daniel,
thx for your info and for explaining the steps you made.
Maybe my manual created textual Bridge/Things are not quite correct anymore, although this setup was ok in the past, so I’m thinking about doing it as you have done and recreate it totally via PaperUI.

I’m running OH2.5 stable since yesterday and since then I do not have any breaks. I have to say that there was a problem after a restart, but after a minute the Bridge reconnected and since that it runs. So I will observe it too.

To see when the disconnection/connection happens I made a rule, which shows me when the error occurs again.

rule "Fritz-Box Online Check"

 when
  Thing "avmfritz:fritzbox:Fritz-Box-7490" changed
 then
   var Status            = getThingStatusInfo("avmfritz:fritzbox:Fritz-Box-7490").getStatus()
   var StatusDetail      = getThingStatusInfo("avmfritz:fritzbox:Fritz-Box-7490").getStatusDetail()
   var StatusDescription = getThingStatusInfo("avmfritz:fritzbox:Fritz-Box-7490").getDescription()
  logInfo ("Fritz-Box","Fritz-Box Status hat sich verändert. Status Ist:{} Detail:{} Beschreibung:{}", Status, StatusDetail, StatusDescription)
end

dk.mailbox · December 22, 2019, 7:31pm

Problem is back - openhab restart helps for a time, then it goes bad again…

Dunno what I can do, yet… luckily the avm stuff is not an active part of my home automation setup, so this is not critical at the moment.