Hallo liebes Forum,
ich dachte erst es liegt an der SONOS Integration. weswegen ich versucht hatte dort Hilfe zu finden. Wie es aber nun aus sieht, liegt es an meinem FHEM selbst. (Habe SONOS komplett gelöscht, Problem bleibt.)
Welches Problem habe ich:
Mein Rase Pi 3 hat wenn ich über SSH Top aufrufe immer >80% CPU last. Zusätzlich ist FHEM / FTUI sehr langsam, bei der Bedienung.
Gefühlt wurde ich sagen, habe ich das Problem, seit ich ein update all ausgeführt habe (FHEM läuft seit ca. 3 Jahren auf dem PRI)
Zum deuchen habe ich nun folgenden versucht:
1. Alle möglichen Module deaktiviert / gelöscht -> bis dahin, das im Event Log kaum noch aufrufe da waren. Leider ohne Erfolg CPU Last weiterhin >80% / meist 99%
2. Debug über verbose 5, viel Aufrufe aber ich sehe keine Auffälligkeiten
3. Debug über strace
Leider fehlen mir die Fähigkeiten / Kenntnisse hier weiter zu kommen. Auch über google konnte ich leider nichts finden.
Meine Vermutung, woran es liegt:
- Es könnte sein, dass ich ein Problem mit der localtime hat und es irgendwie mit ntp zusammenhängt (Allerdings verschwindet der Fehler auch nicht, wenn ich FHEM zur Laufzeit über SSH Neustarte, womit die Fehlerbehebung aus anderen Threads bzgl. Verzögerung bei Neustarten weg fällt. Außerdem starten ich nicht über init.d, dass ich auch nicht weiß, wie ich die Verzögerung bei einem Service ausführen müsste)
Also stehe ich wie der Ochs vorm Berg,... ich hoffe ihr könnt mir helfen, ich würde nur sehr ungern, das Teil neu aufsetzen, da ich sehr viele EnOcean Geräte habe :-(
Im Anhang die folgenden Dateien:
1. Log mit Verbose 5 (Pi läuft sonst in Verbose 1)
2. Auszug aus strace
3. Log mit verbose 1 von heute
Viele liebe Grüße
Timo
Hallo Timo,
hast Du mal FHEM beendet und die Demo cfg gestartet? Letzter Punkt:
https://wiki.fhem.de/wiki/FHEM_startet_nicht_-_Tipps_zur_Fehlersuche
Gruß Otto
Der Verbose 5 Log ist ca 400 Sekunden lang. In dieser Zeit wurde
- /fhem/www/tablet/ftui2/images/empty.jpg 342 mal abgeholt. Weitere 60 Aufrufe vom Webtablet machen den Aufrufzahl rund (1 FHEMWEB-Request pro Sekunde).
- HUEBridge 580-mal gepollt (HTTP Requests)
- 140 weitere HTTP Aufrufe abgesetzt (spotify, netatmo, fritz.box, etc, etc)
- 406 Event-Gruppen verarbeitet. Vermutlich schnell genug, aber ohne "attr global mseclog" sieht man das nicht. Es sind 691 FHEM-Definitionen vorhanden (davon 193 notify, 143 FileLog) d.h. es gibt etliche Geraete, die was tun.
Das sollte ein RPi 3 zwar verkraften, man kann ihm aber auch helfen, indem man seltener pollt.
Fuer bessere Ratschlaege brauche ich zusaetzlich zu "attr global verbose 5" auch "attr global mseclog 1".
Ist sicher, dass FHEM die 80% CPU-Last verursacht?
Hallo Ihr beiden,
schonmal vielen Dank für Eure Unterstützung,
zu Otto:
habe gerade meine FHEM Instanz als Demo Config gestartet, hier habe ich kaum CPU Auslastung und kann die Demo Konfiguriert über den Webbrowser aufrufen. Es scheint also nicht grundsätzlich an meinem RPi zu liegen.
zu rudolfkoenig:
ja, ich habe mehrere Tablets / Funktionen die während des Verbose 5 Modes aktiv waren. Hatte aber im Anschluss sehr viele Module deaktiviert / alle FTUIs ausgeschaltet und das Problem bestand weiterhin! Das ich denke, ja es ist viel, aber nicht der Ursprung des Problems, wie meinst du das mit dem seltener Pollen?
--> Wie stelle ich das bei der HUEBridge / in FTUI ein?
--> Kann ich das Global verringern bei HTTP Aufrufen oder muss ich das im jeweiligen Modul (Spotify / netatmo etc. machen?)
--> siehe Anhang Verbose 5 + attr global mseclog Neustart + 3 Minuten Laufzeit fhem mit >80% CPU
--> ob ich mir sicher bin das fhem die CPU Last verursacht? Ich sehe es halt über SSH in der Anzeige über Top (siehe Screenshot im Anhang)
Ihr seid Spitze, ich habe das Gefühl, wie finden den Fehler :-)
Grüße Timo
Hab gerade mal geschaut, bei z.B. HUE finde ich gar keine Einstellung um das Rolling zu verringern,... :-(
Ich sag mal noch: das hier ist unnütz - aber scheinbar nicht das Problem. Könntest Du aber beheben
Zitat2021.10.02 00:03:14 1: Error evaluating MS75dummy userReading DurchschnittV: Illegal division by zero at (eval 23789) line 1.
Ansonsten klingt es mir danach, dass durch das update eine Schleife auftaucht. Wie alt war das System vor dem Update?
Wäre es eine Option, zum Test das update mit restore zurück zu drehen?
update ist jetzt 1,5 Monate her und davor ca. 1,5 Jahre alt,... was passiert bei ReStore denn genau? (Es war aber nicht das letzte Update, hatte es Gestern auch nochmal ausgeführt) ist Restore dann trotzdem noch möglich?
Was genau passiert den bei Restore? (Ist das reversibel?)
Was mir gerade noch auffällt, worauf ich aber keine Erklärung habe:
Meine Logdateien liegen zum Teil in der Zukunft!? Siehe Screenshot aktuell war es 22:40 Uhr. Mein System selbst zeigt aber die Richtige Zeit an, habe es mit:
{ localtime }
{qx(date +%R)}
{$hms}
überprüft. Kann es vielleicht daran liegen,...
Im letzten Log sind 2:25 verwertbare Daten (vom Start bis zum Abschalten des mseclogs).
Die Event-Verarbeitung (notify+Filelog+...) belegt aus diesen 145 Sekunden insg. 17.692 (entspricht 12% CPU), wobei Sonos_WOhnzimmer mit 9.164s ueber die Haelfte ausmacht.
Den Rest kann ich nicht erklaeren, da muss man andere tools / FHEM-Module verwenden.
Die Zeit-Unterschiede koennten auch an den unterschiedlichen Timezonen der beiden Rechner liegen.
Zitat von: rudolfkoenig am 02 Oktober 2021, 23:02:47
Im letzten Log sind 2:25 verwertbare Daten (vom Start bis zum Abschalten des mseclogs).
Die Event-Verarbeitung (notify+Filelog+...) belegt aus diesen 145 Sekunden insg. 17.692 (entspricht 12% CPU), wobei Sonos_WOhnzimmer mit 9.164s ueber die Haelfte ausmacht.
Den Rest kann ich nicht erklaeren, da muss man andere tools / FHEM-Module verwenden.
Die Zeit-Unterschiede koennten auch an den unterschiedlichen Timezonen der beiden Rechner liegen.
Bedeutet irgendwas scheint komisch zu sein, da 12% CPU nicht zusammenpasst zu dem was ich in TOP sehe!? Noch eine Idee, was das sein könnte: "andere tools / FHEM-Module verwenden" - also was ich hier noch tun könnte zum Debuggen?
Zitat von: TimoD am 02 Oktober 2021, 22:24:48
update ist jetzt 1,5 Monate her und davor ca. 1,5 Jahre alt,... was passiert bei ReStore denn genau? (Es war aber nicht das letzte Update, hatte es Gestern auch nochmal ausgeführt) ist Restore dann trotzdem noch möglich?
Was genau passiert den bei Restore? (Ist das reversibel?)
gib help restore ein für Hilfe. Restore holt die Moduldateien vor dem Update zurück. Es werden keine Daten geändert. Ich will das aber jetzt nicht empfehlen.
Das mit der Zeit ist sehr komisch. Also das Du etwas anderes als die echte Zeit angezeigt bekommst liegt an Deinem Zugriff, entweder auf dem Pi oder auf dem PC die falsche Zeitzone (ich sage nicht das die Uhr eine falsch Zeit zeigt).
Aber das die Logs unterschiedliche Zeiten haben kann ich nicht erklären, dann müssten Module mit unterschiedlichen Zeiteinstellungen arbeiten?
Was zeigt denn {qx(date)} und {localtime} an?
Zitat von: Otto123 am 03 Oktober 2021, 00:18:43
gib help restore ein für Hilfe. Restore holt die Moduldateien vor dem Update zurück. Es werden keine Daten geändert. Ich will das aber jetzt nicht empfehlen.
Das mit der Zeit ist sehr komisch. Also das Du etwas anderes als die echte Zeit angezeigt bekommst liegt an Deinem Zugriff, entweder auf dem Pi oder auf dem PC die falsche Zeitzone (ich sage nicht das die Uhr eine falsch Zeit zeigt).
Aber das die Logs unterschiedliche Zeiten haben kann ich nicht erklären, dann müssten Module mit unterschiedlichen Zeiteinstellungen arbeiten?
Was zeigt denn {qx(date)} und {localtime} an?
Beide das Selbe, die Richtige Zeit :-( (Hab gerade auch nochmal die Zeitzone konfiguriert, hat aber gepasst). Komme nicht weiter, habe nun so ziemlich alle Logs in FHEm deaktiviert, wirklich alle updates in Stretch / FHEM ausgeführt, FHEM aufgeräumt. Ohne Erfolg immer noch 100% Auslastung auf dem Kern wo FHEM läuft,... :-(
Dann würde ich anfangen, einzelne FHEM Module / Devices zu löschen, solange bis die CPU Auslastung wieder normal ist. Dann hast Du den Verursacher.
Z.B, HTTPMOD Devices machen schon mal Probleme wenn der regexp nicht stimmt..
Zitat von: Jamo am 03 Oktober 2021, 13:54:25
Dann würde ich anfangen, einzelne FHEM Module / Devices zu löschen, solange bis die CPU Auslastung wieder normal ist. Dann hast Du den Verursacher.
Z.B, HTTPMOD Devices machen schon mal Probleme wenn der regexp nicht stimmt..
Gibt es denn irgendeine Möglichkeit, die Module zu deaktivieren, ohne das ich es in meiner Konfiguration löschen muss? Hatte ich versucht, aber ohne Erfolg,..... (z.B. wenn ich die Modul.pm aus dem FHEM Ordner lösche!? (Was kann ich Adhoc alles löschen?)
Ok, ich meinte natürlich nicht die Module an sich aus dem FHEM Ordner. Aber deine Devices, nachdem Du vorher ein backup gemacht hast. Wenn Du den Verursacher gefunden hast, kannst du die fhem.cfg zurückkopieren. attr <device> disable 1 geht natürlich auch, oder z.B ein ,,attr TYPE=HTTPMOD disable 1" wenn du bestimmte Typen disablen willst.
Zitat von: TimoD am 03 Oktober 2021, 13:45:57
Beide das Selbe, die Richtige Zeit :-(
kann eigentlich nicht sein, denn nur ein Befehl liefert die Zeitzone. Wenn ich nach einer Ausgabe frage, würde ich gerne die Ausgabe sehen, falls sie keine Geheimnisse enthält. ;D
Irgendwas kann mit deiner Zeit nicht stimmen, sonst wären deine Logs nicht in unterschiedlichen Zeiten in der Zukunft!
Das die angezeigte Zeit stimmt ist kein Kriterium für: richtig ;)
Zitat von: Otto123 am 03 Oktober 2021, 18:39:41
kann eigentlich nicht sein, denn nur ein Befehl liefert die Zeitzone. Wenn ich nach einer Ausgabe frage, würde ich gerne die Ausgabe sehen, falls sie keine Geheimnisse enthält. ;D
Irgendwas kann mit deiner Zeit nicht stimmen, sonst wären deine Logs nicht in unterschiedlichen Zeiten in der Zukunft!
Das die angezeigte Zeit stimmt ist kein Kriterium für: richtig ;)
Natürlich gerne:
{localtime} Sun Oct 3 19:27:07 2021
{qx(date)} Sun 3 Oct 19:27:35 CEST 2021
Sorry, die Ausgabe war für mich erstmal richtig, deswegen die Antwort,...
Zitat von: Jamo am 03 Oktober 2021, 15:23:15
Ok, ich meinte natürlich nicht die Module an sich aus dem FHEM Ordner. Aber deine Devices, nachdem Du vorher ein backup gemacht hast. Wenn Du den Verursacher gefunden hast, kannst du die fhem.cfg zurückkopieren. attr <device> disable 1 geht natürlich auch, oder z.B ein ,,attr TYPE=HTTPMOD disable 1" wenn du bestimmte Typen disablen willst.
Habe keine HTTPMOD device (sehe zumindest unter everything keine. das mit disable 1 habe ich versucht (auf gefühlt alle devices die es angeboten haben), aber ohne Erfolg. Leider weiß ich nicht, welches Update den Fehler verursacht hat, da nach 1,5 Jahren es sehr sehr viele waren.
Könnte ich denn die Module ggf. durch löschen im FHEM Ordner deaktivieren und komplett ohne Module starten? Oder zerschieße ich mir das die Geräte?
Naja nix für ungut, aber ich will gerne mitdenken. ;) Das Zusammenspiel zwischen Hardwareuhr, Systemuhr, Zeitzone, UTC, Sommerzeit, Serverzeit, Clientzeit usw. ist nicht jedem wirklich klar. Manch einer verbiegt sein System einfach so, dass die richtige Zeit angezeigt wird.
Und das hat wirklich 30 sekunden gedauert zwischen beiden Befehlen? :-\
Zitat von: Otto123 am 03 Oktober 2021, 19:49:30
Naja nix für ungut, aber ich will gerne mitdenken. ;) Das Zusammenspiel zwischen Hardwareuhr, Systemuhr, Zeitzone, UTC, Sommerzeit, Serverzeit, Clientzeit usw. ist nicht jedem wirklich klar. Manch einer verbiegt sein System einfach so, dass die richtige Zeit angezeigt wird.
Und das hat wirklich 30 sekunden gedauert zwischen beiden Befehlen? :-\
Ja, meine Tochter war unter der Dusche und ich musste ihr antworten,... :-) deshalb der Zeitversatz, hab es gerade nochmal gecheckt, Sec. sind synchron.
Noch ne Frage, wie kann ich denn FTUI und das Chart frontend deaktivieren ? Finde hierzu keine Infos,....
Ich hab ihn !!!!!!!!! Danke für Eure Hilfe! Das Modul "50-Mythz" verursacht den Fehler! Aufgefallen ist mir dies, da ich keine Intervalle beim Pooling einstellen konnte, bzw. ich das Rolling für die Unterschiedlichen sHC1 / sDHW / etc. nicht rausbekommen habe und diese weiterhin aktualisiert wurden! Juhu!
Ich habe eine Systemlast am PERl Prozess von <30% ;D
Mega
Fehlersuche und Beschreibung im zugehörigen Modul folgt dann morgen :-)
Doch nicht,... jetzt geh ich ins Bett >:(
Oder auch nicht, ich kann das Problem jetzt eingrenzen, es hat definitiv was mit meinen Usb Anschlüssen zu tun. Die Systemlast wird nämlich geringer, sobald ich ein USB Device "fehlerhaft" konfiguriert habe. Dann verschwinden auch die "{tv_sec=0, tv_usec=969537}) = 1 (in [156], left {tv_sec=0, tv_usec=969508})
_newselect(176, [4 5 6 7 8 10 22 122 129 156 160 161 162 163 164 165 168 171 172 174], NULL, NULL, " Fehler aus dem STRACE.
Stattdessen, die Fehler im strace zu fehlerhafter Usb Konfiguration.
Wenn ich aber alle Usb Device gelöscht habe, kommen die Fehler wieder! (Aktuell steckt am PI kein Usb Kabel mehr. Lediglich auf dem internen Port ein EnOcean, sollte das relevant sein.
Ein Schritt weiter näher am Ziel :-)
Siehe Screenshot, fehlerhafte Konfiguration mit der alles IO bzgl. Systemlast, wenn ich es ändere / das Device lösche Volllast,...
attr initialUsbCheck disable 1hast Du gesetzt?
Zitat von: Otto123 am 04 Oktober 2021, 08:55:54
attr initialUsbCheck disable 1hast Du gesetzt?
Ja, hab das Device nun sogar gelöscht, ohne Änderung.
auch nach save und restart?