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

This is a hard problem to analyse - now, it’s been good again for about 2 days. The good thing is, I’ve managed to do some remote package capturing between my RaspBee and the FritzBox, to get an idea what regular traffic looks like.
Now, I’d need it to break again, to compare… :smile:

Hi Daniel,
as you I detached my Items, Thing/Bridge, Rules from the OH-System and then uninstalled die Binding. After that I made:

sudo systemctl stop openhab2
sudo openhab-cli clean-cache
sudo shutdown

After a while I made the system start again, so openHAB comes up again. (Don’t know anymore if I had to restart openHAB twice or three times again to get a correct startup-sequence).

Then I changed the Fritzbox-Name in the Bridge from “Fritz-Box-7490” to “7490” as shown here:

Bridge avmfritz:fritzbox:7490 "Fritz Box 7490" @ "Office" [ ipAddress="fritz.box", user="santaClause", password="IneverWillTellYou" ] {.....

and of course the Channel-Definitions in the .items.file

Then I installed the Binding again and after that I activated first the Bridge/Thing and then the .items-File.

At the moment I do not have running any Rule-Files affecting Fritz-Items with the exception of the above Rule, which will show me if the communication breaks.

I have done that procedure two days ago, and (touch Wood) there are still no errors.

The next step I will do, if the binding is not broken 'til the end of the week, is to activate my rules again (rule by rule).
I’ll keep you informed. But now:
have a merry christmas and a happy new year:christmas_tree::christmas_tree::fireworks::fireworks::sparkler::sparkler::firecracker::sparkles:

Cheers
Peter

1 Like

Also from me - merry x-mas and a happy new year to everyone!

@fibu-freak thank you for the detailed description of your attempts to get to the root of this - my setup is now running ok for almost 2 days, without any changes other than a openHab restarts when things were broken. What is noteworthy, last time when the binding was borked, it wan’t possible to just restart the avmfritz bundle from the console.
I’ll wait for things to break again now, then compare network traffic to my fritzbox with the know-good pattern. Try to figure out where to problem is…

1 Like

Hi Daniel,
just want to inform you, that the binding runs quite fine without any breaks 'til today.:slightly_smiling_face:.
Today I installed two updates (libsasl2-modules) via “openhabian-config” which where pending since some days. Therefore OH2.5 restarts after that procedure, anyway.

Now I will begin to reintegrate my rules, one after the other. At the moment, my suspicion is that my Rules are causing the breaks, but don’t know which one, as far as I can see they are not very complicate.

I have this rule to show me the offset between the temperature between radiator and room (from the fritzbox settings), which uses REST-Api:

// ***********************************************************************************************************************
// ***************** Berechnung der Temperatur am AVM-Thermostat direkt, da in den Channels ******************************
// ***************** "{ channel="avmfritz:Comet_DECT:Fritz-Box-7490:119601003400:actual_temp" } nicht ausgewiesen ********
// *********************************************************************************************************************** 

rule "offset temperature calculating"
  when
    Item Dummy4x changed to ON or
    Item radiator_valve_01_Temp changed or
    Item radiator_valve_02_Temp changed or
    Item radiator_valve_03_Temp changed or
    Item radiator_valve_04_Temp changed or
    Item radiator_valve_05_Temp changed or
    Item radiator_valve_06_Temp changed or
    Item radiator_valve_07_Temp changed 
  then
//   logInfo ("http", "Triggering-Item-> Bezeichnung: {} Name: {} Status: {}" , triggeringItem.label, triggeringItem.name, triggeringItem.state)
    radiator_valve_01.postUpdate((radiator_valve_01_Temp.state as Number).floatValue - Float::parseFloat(transform("JSONPATH", "$.channels[3].configuration.offset", sendHttpGetRequest("http://192.168.178.xx:8080/rest/things/avmfritz%3AComet_DECT%3A7490%3A119601003400"))))
    radiator_valve_02.postUpdate((radiator_valve_02_Temp.state as Number).floatValue - Float::parseFloat(transform("JSONPATH", "$.channels[3].configuration.offset", sendHttpGetRequest("http://192.168.178.xx:8080/rest/things/avmfritz%3AComet_DECT%3A7490%3A119600949320"))))
    radiator_valve_03.postUpdate((radiator_valve_03_Temp.state as Number).floatValue - Float::parseFloat(transform("JSONPATH", "$.channels[3].configuration.offset", sendHttpGetRequest("http://192.168.178.xx:8080/rest/things/avmfritz%3AFRITZ_DECT_301%3A7490%3A099950152273"))))
    radiator_valve_04.postUpdate((radiator_valve_04_Temp.state as Number).floatValue - Float::parseFloat(transform("JSONPATH", "$.channels[3].configuration.offset", sendHttpGetRequest("http://192.168.178.xx:8080/rest/things/avmfritz%3AFRITZ_DECT_301%3A7490%3A099950074210"))))
    radiator_valve_05.postUpdate((radiator_valve_05_Temp.state as Number).floatValue - Float::parseFloat(transform("JSONPATH", "$.channels[3].configuration.offset", sendHttpGetRequest("http://192.168.178.xx:8080/rest/things/avmfritz%3AComet_DECT%3A7490%3A117950357048"))))
    radiator_valve_06.postUpdate((radiator_valve_06_Temp.state as Number).floatValue - Float::parseFloat(transform("JSONPATH", "$.channels[3].configuration.offset", sendHttpGetRequest("http://192.168.178.xx:8080/rest/things/avmfritz%3AComet_DECT%3A7490%3A119600710200"))))
    radiator_valve_07.postUpdate((radiator_valve_07_Temp.state as Number).floatValue - Float::parseFloat(transform("JSONPATH", "$.channels[3].configuration.offset", sendHttpGetRequest("http://192.168.178.xx:8080/rest/things/avmfritz%3AFRITZ_DECT_301%3A7490%3A099950133789"))))
//    logInfo("http"," Thermostat-Offset http 1 ist: {}, 6 ist:{}, 7 ist:{} ",radiator_valve_01 ,radiator_valve_06, radiator_valve_07)
end

and some others like those:

//===============================================================================
rule "Fenster Arbeitszimmer Offen"
    when
      Item gWindowOffice changed from "CLOSED" to "OPEN" 
    then
	  if(radiator_valve_01_Mode.state == "OFF") return;  // Es sind bereits Fenster offen bzw. der Thermostat ist ausgeschaltet
      radiator_valve_01_Set_prev.postUpdate(radiator_valve_01_Set.state)
      radiator_valve_01_Mode_prev.postUpdate(radiator_valve_01_Mode.state)
      radiator_valve_01_Mode.sendCommand("OFF")
      logInfo("Fenster Arbeitszimmer Offen"," radiator_valve_01_Set {}", radiator_valve_01_Set)
end
//===============================================================================
rule "Fenster Arbeitszimmer Geschlossen"
    when
      Item gWindowOffice changed from "OPEN" to "CLOSED"
    then
      if ((radiator_valve_01_Mode_prev.state == "ECO") || (radiator_valve_01_Mode_prev.state == "COMFORT") || (radiator_valve_01_Mode_prev.state == "OFF")) {
        radiator_valve_01_Mode.sendCommand(radiator_valve_01_Mode_prev.state.toString)
        logInfo("Fenster Arbeitszimmer Geschlossen"," radiator_valve_01_Set {}", radiator_valve_01_Set)
      }
      if (radiator_valve_01_Mode_prev.state == "ON") {
        radiator_valve_01_Set.sendCommand(radiator_valve_01_Set_prev.state as Number)
        logInfo("Fenster Arbeitszimmer Geschlossen"," radiator_valve_01_Set {}", radiator_valve_01_Set)
      }
end
//===============================================================================
rule "HM Fenster Status York"
    when
//    Item Dummy4 changed to ON or
    Item HmIP_SWDO_689A_1STATECONTACT changed from "CLOSED" to "OPEN"
    then
        radiator_valve_02_Set_prev.postUpdate(radiator_valve_02_Set.state)
        radiator_valve_02_Mode_prev.postUpdate(radiator_valve_02_Mode.state)
        radiator_valve_02_Mode.sendCommand("OFF")
        logInfo("homematic"," HM Fenster AUF Status York Heizkörper {} prev {}", radiator_valve_02_Mode.state, radiator_valve_02_Mode_prev.state )
end
//===============================================================================
rule "HM Fenster Status York Geschlossen"
    when
//    Item Dummy3 changed to ON or
    Item HmIP_SWDO_689A_1STATECONTACT changed from "OPEN" to "CLOSED"
    then
    if ((radiator_valve_02_Mode_prev.state == "ECO") || (radiator_valve_02_Mode_prev.state == "COMFORT") || (radiator_valve_02_Mode_prev.state == "OFF")) {
        radiator_valve_02_Mode.sendCommand(radiator_valve_02_Mode_prev.state.toString)
        logInfo("homematic"," HM Fenster ZU(ECO,COMFORT) Status York Heizkörper Temp:{}  Modus:{}", radiator_valve_02_Set_prev.state, radiator_valve_02_Mode_prev.state)
    }
    if (radiator_valve_02_Mode_prev.state == "ON") {
        radiator_valve_02_Mode.sendCommand(radiator_valve_02_Mode_prev.state.toString)
        radiator_valve_02_Set.sendCommand(radiator_valve_02_Set_prev.state.toString)
        logInfo("homematic"," HM Fenster ZU(ON) Status York Heizkörper {}", radiator_valve_02_Set.state)
    }
end
//===============================================================================

…which observe weather a window is opened ore closed, to open ore close the corresponding thermostats.
Maybe there are some hidden errors :thinking: ???!!!

Hi @fibu-freak, I can definitely say that your rules are not the issue - the binding breaks occasionally, all by itself - I do not have any rules set up that involve the avmfritz binding at the moment.

What I can also say (just had the problem again, today): when the error occurs, there is no more http conversation between openhab and the fritz box on the network. Meaning, the issue is on the openhab side (as it’s openhab that is cyclically requesting device info data from the fritz box).

I’ll look into the exception message again, now - there was something I found a couple of weeks back wrt this, stating that it’s related to some issue in java libraries or something…

UPDATE: Allright, I’ve not much to go on, but the current hypothesis (based onthis google groups thread) is that the following happens in my case: occasionally, my fritzbox slows down to a crawl, indicated by the fact that network (Wifi) routing performance tanks, logging into/working with the web interface becomes unbelievably slow, etc - this either goes away by itself after a while, or it can be fixed by rebooting the box*.
I had one of those slowdowns this morning - and when I checked later today, the avmfritz binding exhibited the problem this thread is about.
So I’m guessing that during these slowdowns, the connection pool buffer use by openhab fills up, and never recovers.
If that is the case, a workaround could be to increase the pool size numbers; even better would be to find a way to recover from the situation. No idea whether that’s possible, but I’ll have a look around.

(*) Why the fritzbox slows down so much is also a good question; I haven’t investigated this yet, one assumption is that it’s to do with USB memory that I’ve mounted, and maybe it’s running an indexer on that stick occasionally, causing the slowdowns? No clue; I’ve removed the mounted storage now, and will look for information about this as well.

2 Likes

Interim update: my fritz binding has been running without an issue for two weeks now. Might be coincidental, but maybe there was some connection to the NAS function and associated tasks that caused a intermittent slowdown (and thus that overflow of the connection handler pool in openhab).

Hi Daniel,
I think you found the reason for the breaks. As you I have running a USB-Stick on my fritz-box, which I used for Data-Transfer from another RPi_xx to my OH-RPi. I used a simple Bash-Script which was executed by the EXEC-Binding to get a value from a file on the USB-Stick, which was written into from the other RPI via a Script (Cron-driven).
Both Pis were mounted to the USB-Stick

This means:
RPi_xxx reads it’s CPU-Temperature and write it via Script to the File on the USB-Stick(NAS).
RPi_OH reads theFile via EXEC-Script an filled and item.

This works for a while, but after some time the USB-Stick was locked (I can see this in the Fritz-Box).

As said, I suspend all my Rules and the EXEC-Scripts too in the mid of December. Then I started OH again on Dec, 22nd, 2019. No more errors or breaks since then !!!.
10 days ago I began to activate my rules again. Now all rules are running without any problems.

Since yesterday I’m on “openHAB 2.5.1-2 (Release Build)” ( I have to restart 3 times to get rid of all the silly messages) but now everything runs as it should.

I didn’t reactivate the EXEC-Scripts and the “mounts” of NAS, only local EXEC-Scripts are running. I’m using now a much better way to communicate, between the two (meanwhile three :wink:) Rpi’s. It’s just “MQTT” and it works like charm.

So I think you found the reason of the breaks. Thanks for your help and your investigation.

Cheers,
Peter

FYI: @cweitkamp

@fibu-freak … nah, too early. I’m getting these errors again, with no NAS functionality used on the fritz box. So it might still be a similar cause, but not using storage doesn’t fix it.

I guess whatever it is, we need robustness for it in the avmfritz binding/the libraries that are used there.

Oooh, that’s not good news. The only thing I can say for the moment is that the system is running stable since Dec, 22nd, 2019 without any breaks. I’ll keep you informed

My avmfritz is in a bad way right now - breaks almost all the time, after a couple of hours at most.

It doens’t help to just restart the avmfritz bundle, either - only restarting entire docker image helps. This points back to the instance of this error pattern I found on the internets, where the root cause is in some java connection library.

Mine is running now stable without any breaks.

Do you still have the fritz-NAS mounted to your system ? Or do you have more than one OH-System communicating with the fritz-box ?

No and no - nothing complicated…

That’s weird …!!! :thinking: :thinking:

Maybe last act in the saga, for me (but we’ll see): had to upgrade to a 7530 now, because of getting faster DSL. Put the new box in yesterday, no problems so far but let’s see how that develops.

1 Like

That’s good news. At the moment I see problems with avm-binding and the exec-binding (with whitelist) in OH-Version 2.5.2.
As I only have two scripts running with the Exec-Binding I stopped it and problems were gone. I try to find another way to get the information I former got from Exec-Scripts (MQTT2 or REST).

I keep fingers crossed for you. :crossed_fingers: :crossed_fingers: :crossed_fingers:

For the 2.5.2-EXEC-Binding-whitelist problem there is a interim fix available: EXEC-Binding errors after update to Openhab2 2.5.2-1
after 24h 2.5.2 up I still have the said problem with 7590.

After restarting the Pi twice or three times the errors with AVM were gone. As a workaround I saved the “exec.whiteliste” file after the restart and everything works fine now.

Logger:

2020-02-24 22:32:59.979 [WARN ] [pse.smarthome.model.script.Fritz-Box] - Fritz-Box Status hat sich verändert. Status Ist:INITIALIZING Detail:NONE Beschreibung:null
2020-02-24 22:33:00.981 [WARN ] [pse.smarthome.model.script.Fritz-Box] - Fritz-Box Status hat sich verändert. Status Ist:ONLINE Detail:NONE Beschreibung:Established FRITZ!Box connection with SID 88cd139c81d5ac33
2020-02-24 22:33:10.328 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to 'localhost' with clientid OH2_hans
2020-02-24 22:33:10.364 [WARN ] [ng.exec.internal.handler.ExecHandler] - Tried to execute '/bin/bash /etc/openhab2/scripts/test.sh', but it is not contained in whitelist.
2020-02-24 22:33:10.404 [WARN ] [ng.exec.internal.handler.ExecHandler] - Tried to execute '/bin/bash /etc/openhab2/scripts/cpu_temp.sh', but it is not contained in whitelist.
2020-02-24 22:33:13.417 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
2020-02-24 22:33:13.598 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2020-02-24 22:33:13.721 [INFO ] [openhab.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2020-02-24 22:33:31.040 [INFO ] [smarthome.model.script.sonoff_status] - Timer wird initialisiert null
2020-02-24 22:35:01.086 [INFO ] [smarthome.model.script.sonoff_status] - Device Id : sonoffs Command published
2020-02-24 22:35:01.093 [INFO ] [smarthome.model.script.sonoff_status] - Timer tSonoffState ist abgearbeitet und wird wieder auf "null" gesetzt: null

Restarted OH2 yesterday evening and as you can see, Fritz-Box started and is online and whitelist warned one time.

BTW: I know about the interim-fix, but I will wait 'til OH2.5.3 is online. For the moment I use the other “trick” with the “resave” of the whitelist-file. It takes a second and under normal circumstances it takes a longer period to restart openHAB :wink:

Merging OH2 AVM Fritz! and OH1 TR064 into one binding would be sweet. I’d say most that try to get the most out of their Fritz!box are using both.

/M

I face the same problem, too.
Deleting an creating a new avmfritz thing with a new name did not help.
It’s very annoying and I would love to see a sign towards a solution…

Do you still have the problem, too?

No more problems with my AVMFritz-Binding. Everything is working fine (Knock on wood).