[gelöst] FHEM sporadische Auslastung (die x-te)

[zife]

Gibt's noch Ideen, was ich probieren könnte? Zumindest Freezemon zeigt ja meist Module, die "nach draussen telefonieren". Und die vielen HttpUtils-Einträge... hilft einem das weiter bei der Ursachenforschung?

Sind Freezes oder die CPU Auslastungsspitzen die Ursache für fhem-Hänger oder hängt das direkt miteinander zusammen?

[KölnSolar]

Gibt's noch Ideen, was ich probieren könnte?

Ja.

Code Auswählen Erweitern

attr Deinfreezemon fm_logFile ./log/freeze-%Y%m%d.logDort sieht man mehr, was die freezes verursachen könnte.
Grüße Markus

[zife]

Ok, danke, das hab ich ausprobiert - und innerhalb von einer knappen Viertelstunde war das LOG schon >300 MB. Die Einträge verstehe ich noch nicht 100%ig...:

EDIT:
Hier klappt gerade was nicht mit dem Post, sorry... editiere ihn nochmal.

[KölnSolar]

innerhalb von einer knappen Viertelstunde war das LOG schon >300 MB

Das klingt nach einem Problem. 
Stell mal nur einen Extrakt ein, wo Du anhand des timestamps den freeze erkennst. +/- ca. 20 Zeilen.
Die Detaildaten im obigen Post sind uninteressant(scheint ja nur ne Masse Daten von der Bewässerungssteuerung)

Denk beim posten daran ggfs. persönliche Daten zu anonymisieren !

[zife]

Ich bekomm das hier nicht gequoted. Also mal Auszüge:

Es fängt an mit:

Code Auswählen Erweitern

[Freezemon] myFreezeMon: possible freeze starting at 18:07:54, delay is 14.736 possibly caused by: no bad guy found :-(
2022.01.30 18:07:53.087 4: https://smart.gardena.com/v1/devices?locationId=[anonymisiert]: HTTP response code 200
2022.01.30 18:07:53.087 5: HttpUtils https://smart.gardena.com/v1/devices?locationId=[anonymisiert]: Got data, length: 102771
2022.01.30 18:07:53.087 5: HttpUtils response header:
HTTP/1.1 200 OK
Content-Type: application/json
Content-Length: 102771
Connection: close
Date: Sun, 30 Jan 2022 17:07:52 GMT
x-amzn-RequestId: [anonymisiert]
X-Rate-Limit-Reset: 28
X-Rate-Limit-Remaining: 6299
x-amzn-Remapped-Connection: keep-alive
X-Rate-Limit-Limit: 6300
x-amz-apigw-id: [anonymisiert]
Vary: Accept-Encoding
x-amzn-Remapped-Date: Sun, 30 Jan 2022 17:07:52 GMT
X-Cache: Miss from cloudfront
Via: 1.1 [anonymisiert].cloudfront.net (CloudFront)
X-Amz-Cf-Pop: FRA50-C1
X-Amz-Cf-Id: [anonymisiert]==

Dann kommmt ein Request, der dermaßen lang ist, dass er hier den Editor sprengt. Fängt an mit:

Code Auswählen Erweitern

2022.01.30 18:07:53.088 4: GardenaSmartBridge (GardenaZentrale) - Request: {"devices":[{"id":"cf9454a...

Und dann:

Code Auswählen Erweitern

2022.01.30 18:07:53.154 4: GardenaSmartBridge (GardenaZentrale) - set internal timer function for recall getDevices sub
2022.01.30 18:07:53.199 5: End notify loop for GardenaZentrale
2022.01.30 18:07:53.408 5: GardenaSmartBridge (GardenaZentrale) - 160 == 160 and 160 > 0
2022.01.30 18:07:53.408 5: GardenaSmartBridge (GardenaZentrale) - 160 == 160 and 160 > 0
2022.01.30 18:07:53.408 5: GardenaSmartBridge (GardenaZentrale) - 160 == 160 and 160 > 0
2022.01.30 18:07:53.409 5: GardenaSmartBridge (GardenaZentrale) - 160 == 160 and 160 > 0

Das wiederholt sich jetzt Hundere Male, nur ab und zu mit anderen Zahlenwerten.

Ich hab Schwierigkeiten, das zu verstehen... im normalen FreezeMon hab ich ja laufend Einträge von Gardena, von MieleAtHome und HttpUtils (siehe oben). Hier ist nur Gardena drin, dafür aber hundertfach...

Wie kann ich das interpretieren?

EDIT: Wenn mein Editor wirklich Zeilen zählt, sind es nicht Hunderte Male, sondern fast 4 Mio (!) Zeilen mit o.g. Muster, mit Zeitstempeln über eine Viertelstunde hinweg 

[KölnSolar]

wie ich zuvor schrieb: guck auf den timestamp, ob Du einen riesen Verzug erkennen kannst. Oder anhand der Daten eine Schleife.
Ggfs. mal das device mit Massendaten disabeln.

[KölnSolar]

Editor wirklich Zeilen zählt, sind es nicht Hunderte Male, sondern fast 4 Mio (!) Zeilen

freeze Verursacher gefunden. Offenbar eine Schleife ?
disabeln - freeze Verursacher bestätigen - das böse device analysieren - Modulautor informieren

edit:

über eine Viertelstunde

die freezes sind wg. dem Logging nun viel länger.

[zife]

Ok, hab tatsächlich in den Mio Zeilen noch andere FreezeMon-"Verursacher" gefunden. Werde mir das Monsterfile jetzt erstmal genauer vorknöpfen und dann melde ich mich wieder.

EDIT:
Da sich in der Tat die überwältigende Mehrheit der Log-Einträge auf das Gardena-Modul beziehen, suche ich dort weiteren Rat.
https://forum.fhem.de/index.php/topic,75098.1545.html

Allen Helfern hier nochmal vielen Dank. Sofern es doch eine andere Ursache haben muss, setze ich hier fort, ansonsten setze ich hier auf gelöst.

[CoolTux]

Es könnte tatsächlich das GardenaBridge Device der Verursacher sein. Erklärung:
Die Antwort auf eine Anfrage an die API kann sehr lang ausfallen und kommt von daher nicht in einem Rutsch sondern Stück für Stück. Diese Stücke werden zwischen gespeichert und jedes mal bei Erhalt einer neuen Antwort geprüft ob sie komplett sind. Dies Prüfung ein einer Schleife kann je nach vorhandenen physikalischen Gardena Geräten in der Tat lange Dauern. Ich werde die Prüfung in eine externen asynchronen Prozess auslagern.


Grüße

[Beta-User]

Da du eh' in den Code reinschaust:
Muss denn die Log3-Funktion intern so häufig aufgerufen werden? Das sieht mir nämlich auch nicht unbedingt effizient aus:

Code Auswählen Erweitern

2022.01.30 18:07:53.408 5: GardenaSmartBridge (GardenaZentrale) - 160 == 160 and 160 > 0
2022.01.30 18:07:53.408 5: GardenaSmartBridge (GardenaZentrale) - 160 == 160 and 160 > 0
@zife:
Wernieman hat aber durchaus recht mit dem Hinweis, dass 100% Auslastung und "einfach nur warten" nicht besonders gut zusammenpassen. Daher noch ein anderer Punkt: Hast du "autocreate" deaktiviert? Dann kann es sich uU. lohnen, mal nach "please define it" zu suchen...

(Generell teile ich die Ansicht mancher Maintainer nicht, dass man autocreate ausschalten sollte. "Nachbar-Geräte" anlegen lassen und dann "ignore" verpassen ist die effizientere Methode!).

[zife]

Bisher ist bei mir "autocreate" noch aktiv.

Da ich ein "geläuterter" fhem.cfg-Editierer bin (mich also gerade schrittweise daran gewöhne, nur noch in der GUI zu arbeiten), kenne ich meine .cfg in und auswendig, und sortiert/kommentiert ist sie auch. Alte Krankheit aus längst vergangenen Basic/Pascal-Tagen, als ich noch "fit" war im Coden.
In der letzten Zeit hab ich keine Zugänge in Form neuer Devices, jedenfalls nicht via autocreate. Es spräche also von dieser Seite her nichts dagegen, es zu deaktivieren. Ich kann damit ja mal experimentieren, danke für die Idee.

[Beta-User]

Bisher ist bei mir "autocreate" noch aktiv.

Dann lass' das auch so...!
Das war grade _nicht_ die Empfehlung, es zu deaktivieren!

Da ich ein "geläuterter" fhem.cfg-Editierer bin (mich also gerade schrittweise daran gewöhne, nur noch in der GUI zu arbeiten), kenne ich meine .cfg in und auswendig, und sortiert/kommentiert ist sie auch. Alte Krankheit aus längst vergangenen Basic/Pascal-Tagen, als ich noch "fit" war im Coden.

Bin configDB-User und habe seit der Umstellung (vor Jahren, kommend von einigen includes "wegen der Übersichtlichkeit") nie mehr das Bedürfnis gehabt, irgendwelche Kommentare in Textfiles zu suchen. Etwas devspec iVm. "list" und "show", und schon ist "grep" vergessen, und wenn es mal was zu suchen gibt: "configdb search" .

Dir ist vermutlich schon klar, dass das direkte "Editieren" teils für ziemlich seltsame Effekte verantwortlich ist...?

[zife]

Ach so... Missverständnis     Na, dann bleibt's autocreate erstmal, wie es ist.

Ja, die Hinweise und zugegeben auch eigenen Erfahrungen haben mich ja veranlasst, die Finger möglichst von der .CFG zu lassen. Aber hey, alleine das Wissen, dass dann da mit der Zeit alles "unsortiert" untereinander steht, erhöht meinen Puls. 

Ich weiß, daß das irrational ist. Im Moment fahre ich den Kompromiss, daß ich alle paar Wochen mal den Editor anwerfe und nur umsortiere. Ja, und vereinzelt kommentiere. Gebt mir mal noch nen Jahr, dann hab ich's hoffentlich überwunden.

Ich kann aber (99%) ausschließen, dass die o.g. Schwierigkeiten mit Schreibaktionen in der .CFG zu tun haben. Meine DEFs, DOIFs, NOTIFYs und ATTR-Änderungen erstelle/editiere ich ja schon übers GUI...

[zife]

Code Auswählen Erweitern

attr Deinfreezemon fm_logFile ./log/freeze-%Y%m%d.logDort sieht man mehr, was die freezes verursachen könnte.
Grüße Markus

Also, das kann ich nur empfehlen - damit konnte die Ursache tatsächlich gefunden werden. Dank CoolTux läuft nun bereits die Testphase des aktualisierten betroffenen Moduls. Setze hier auf gelöst. Danke allen Helfern!