Neues Modul: 98_FREEZEMON Freezes monitoren und Verursacher identifizieren

Begonnen von KernSani, 05 Februar 2018, 23:27:22

Vorheriges Thema - Nächstes Thema

ToKa

Hallo Oli,

leider noch keine Erfolgsmeldung... auch mit der letzten Version hier aus dem Forum kommt es zu einem Absturz von fhem. Letzte Meldung im log

2018.02.20 18:36:17.549 1: PERL WARNING: Use of uninitialized value $shortarg in concatenation (.) or string at ./FHEM/98_freezemon.pm line 586.
Can't use an undefined value as a subroutine reference at fhem.pl line 3094.


Falls Du ein verbose 5 log brauchst, sag Bescheid.

Beste Grüße
Torsten
RaspberryPi3 mit RaZberry2 und Conbee II
Fibaro: FGWPE/F-101 Switch & FIBARO System FGWPE/F Wall Plug Gen5, FGSD002 Smoke Sensor
EUROtronic: SPIRIT Wall Radiator Thermostat Valve Control
Shelly2.5 Rollladenaktoren
Zipato Bulb 2, Osram und InnrLight

KernSani

#91
Zitat von: ToKa am 20 Februar 2018, 18:40:20
Can't use an undefined value as a subroutine reference at fhem.pl line 3094.

der Absturz kommt aber aus der fhem.pl und zwar aus der Zeile in der die prioqueues abgearbeitet werden. Habe ich auf meinem Testsystem auch gesehen, als ich deinen Code nachgebaut habe. Schau ich mir später nochmal an.
RasPi: RFXTRX, HM, zigbee2mqtt, mySensors, JeeLink, miLight, squeezbox, Alexa, Siri, ...

Wuppi68

Hi,

danke für das Modul :-)

Hatte zwar noch keine Freezes, aber besser schon einmal gerüstet sein ...

kannst Du noch das Coding der Umlaute in der Deutschen Commandref anpassen?

als Beispiel
freezeDevice: Liste von möglicherweise den Freeze auslösenden Funktionen(Devices)
Jetzt auf nem I3 und primär Homematic - kein Support für cfg Editierer

Support heißt nicht wenn die Frau zu Ihrem Mann sagt: Geh mal bitte zum Frauenarzt, ich habe Bauchschmerzen

KernSani

Ich habe es endlich geschafft, mich mal um die PrioQueues zu kümmern (und die Umlaute in der Commandref bereinigt). Wäre dankbar für ein paar Tests bevor ich einchecke.

RasPi: RFXTRX, HM, zigbee2mqtt, mySensors, JeeLink, miLight, squeezbox, Alexa, Siri, ...

ToKa

Hallo Oli,

den bisherige Fehler / Absturz des Systems konnte ich damit nicht mehr provozieren.

Danke für die neue Version!

Gruß
Torsten
RaspberryPi3 mit RaZberry2 und Conbee II
Fibaro: FGWPE/F-101 Switch & FIBARO System FGWPE/F Wall Plug Gen5, FGSD002 Smoke Sensor
EUROtronic: SPIRIT Wall Radiator Thermostat Valve Control
Shelly2.5 Rollladenaktoren
Zipato Bulb 2, Osram und InnrLight

gandy

Oft wird geraten, für eine detailliertere Analyse das loglevel hochzusetzen und das so erzeugte Log zu analysieren. Allerdings möchte man vielleicht nicht unbedingt generell ein global verbose 5 gesetzt haben.

Deshalb im Anhang ein Patch, der Log3 mit einem Wrapper versieht, der zunächst generell alle Log-Meldungen ungeachtet des Loglevels zwischenspeichert. Bei einem Freeze werden diese dann in eine Datei geschrieben. Dazu kann über das neue Attribut fm_logFile der Dateiname (mit den üblichen Datumswildcards) für Logfiles gesetzt werden (um für jeden Freeze eine eigene Datei zu erzeugen, bietet sich z.B. log/freeze-%Y%m%d-%H%M%S.log an). Kommt es nicht zum Freeze, werden die Meldungen wieder verworfen.

Schau mal, ob Du das so übernehmen möchtest. Könnte mir vorstellen, dass sich das auch noch gut erweitern lässt, z.B. mit zusätzlichen Informationen aus apptime, etc.

Beste Grüße,
Andy.
fhem (svn) auf i5-4210U NUC
2x HMLAN, 19x HM-SEC-RHS, 15x HM-LC-Bl1PBU-FM, etc.
ODYS Neron Tablet / Android 4.2
Samsung Galaxy Tab 2 10.1N / Android 4.1.2
Samsung Galaxy Note / Android 6.0.1

KernSani

@Andy: coole Funktion. Vielen Dank. Habe sie etwas angepasst und in angehängter Version übernommen.

Achtung - die angehängte Version ist zusätzlich bez. der internalTimer optimiert, die seit ca. 20. Feb. in fhem.pl verfügbar sind, d.h. ein aktuelles FHEM ist Voraussetzung.

Edit: Todo wäre noch, die zusätzlichen Logs leicht zugänglich zu machen. Meine Idee wäre im "get freeze" popup einen Link auf das jeweilige Log einzubauen. Bessere Ideen?



RasPi: RFXTRX, HM, zigbee2mqtt, mySensors, JeeLink, miLight, squeezbox, Alexa, Siri, ...

gandy

Danke fürs Übernehmen. Die Anpassungen gefallen mir, werde das bei nächster Gelegenheit testen  :)

Die Idee mit dem Link ist gar nicht so schlecht, für das Arbeiten über die Webschnittstelle ist das sicher ein guter Ansatz.

In meinem Produktivsystem (cubietruck mit 650 defined entities) kommt es bei aktviertem Log3 Wrapper phasenweise zu zusätzlichen Freezes, wenn der Threshold bei einer Sekunde liegt. Die Abarbeitung aller Devices und aller Trigger benötigt meist knapp eine Sekunde, manchmal aber auch mehr. Die zusätzlichen Log-Dumps scheinen das dann aufzuschaukeln :o  Evtl wäre hier noch ein Hinweis in der command_ref wertvoll, den Thresholdwert auf einen vernünftigen Wert hochzusetzen.

Cheers,
Andy.
fhem (svn) auf i5-4210U NUC
2x HMLAN, 19x HM-SEC-RHS, 15x HM-LC-Bl1PBU-FM, etc.
ODYS Neron Tablet / Android 4.2
Samsung Galaxy Tab 2 10.1N / Android 4.1.2
Samsung Galaxy Note / Android 6.0.1

KernSani

Neue Version ist eingecheckt und steht morgen mit dem Update zur Verfügung:

* angepasst an neue internal Timer (https://forum.fhem.de/index.php/topic,81365.0.html)
* Logging von loglevel 5 Meldungen bei freeze (nochmal danke gandy) mit zusätzlichem get-Befehl um komfortabel aufs Log zuzugreifen.


RasPi: RFXTRX, HM, zigbee2mqtt, mySensors, JeeLink, miLight, squeezbox, Alexa, Siri, ...

Rewe2000

Hallo KernSani,

habe nun auch wieder das FREEZEMON Device aktiv, und werde es ab jetzt anstelle von Perfmon verwenden.

Es ist mir aufgefallen, dass (nach shutdown restart) einige Meldungen bei mir im log stehen:

2018.03.04 15:28:49 1: PERL WARNING: "my" variable $sfl masks earlier declaration in same scope at ./FHEM/98_freezemon.pm line 414, <$fh> line 3375.
2018.03.04 15:28:49 3: freezemon defined freezemon freezemon
2018.03.04 15:28:49 0: [FREEZEMON] freezemon: Wrapping Log3
2018.03.04 15:28:49 1: PERL WARNING: Subroutine main::Log3 redefined at ./FHEM/98_freezemon.pm line 741, <$fh> line 3380.
2018.03.04 15:28:49 1: Including ./log/fhem.save
......
......
2018.03.04 15:30:02 1: PERL WARNING: Subroutine HandleTimeout redefined at ./FHEM/98_apptime.pm line 42.
2018.03.04 15:30:02 1: PERL WARNING: Subroutine CallFn redefined at ./FHEM/98_apptime.pm line 151.


Der Fehler, in Verbindung mit apptime (einfrieren des Systems wenn apptime aktiv) sollte ja zwischenzeitlich gelöst sein.

Die Lösung mit fm_logFile gefällt mir sehr gut, hätte aber dazu noch eine Idee.
Wäre es möglich die erzeugten Logfiles nach XTagen automatisiert über ein einstellbares attr (1-30 Tage) wieder zu löschen?
Ich habe die Befürchtung, bei häufigen Freeze wird das Logfile ziemlich strapaziert, wenn hier nicht per Hand aufgeräumt wird.

Tolles Modul, Danke für deine Arbeit für die Fhem Gemeinde.

Gruß Reinhard


Gruß Reinhard
Fhem 6.3 auf Raspberry Pi4 SSD mit Raspbian Bookworm, Homematic, Homematic IP, CCU3 mit RapberryMatic, WAGO 750-880, E3DC S10E Hauskraftwerk, E3DC Wallbox, my-PV AC ELWA-E Heizstab, Fritz!Box 7590, KIA Bluelinky

KernSani

Hi Reinhard,

Zitat
2018.03.04 15:28:49 1: PERL WARNING: "my" variable $sfl masks earlier declaration in same scope at ./FHEM/98_freezemon.pm line 414, <$fh> line 3375.
Das ist mir auch schon aufgefallen und wird mit dem nächsten Update gefixt.
Zitat
PERL WARNING: Subroutine main::Log3 redefined at ./FHEM/98_freezemon.pm line 741, <$fh> line 3380.
liegt daran, dass freezemon (um die Level 5 Meldungen zu bekommen) die originale Log-Funktion überschreibt (ähnlich wie apptime das macht)

Ich bin mir übrigens nicht ganz sicher, ob apptime gefixt ist - Mein Testsystem ist auf fast aktuellem Stand und da ist es noch problematisch.

Logfile löschen dachte ich auch schon... Die Frage ist nur, wie ich das mache... Nach Datum ist schwerig, da man ja theoretisch auch ein Jahreslog für Freezemon definieren kann. Ich denke ich werde das ähnlich wie beim globalen Logfile machen (die letzten x logfiles behalten).
RasPi: RFXTRX, HM, zigbee2mqtt, mySensors, JeeLink, miLight, squeezbox, Alexa, Siri, ...

KernSani

Neue Version eingecheckt, mit neuem Attribut fm_logKeep, wo man angeben kann, wieviele Logfiles behalten werden sollen.

Neue Version von apptime wurde übrigens von Martin auch heute eingecheckt.

Beides mit dem Update morgen verfügbar.
RasPi: RFXTRX, HM, zigbee2mqtt, mySensors, JeeLink, miLight, squeezbox, Alexa, Siri, ...

Rewe2000

Hallo KernSani,

die Warnung wegen upptime kam gestern leider zu spät für mich, habe dieses aktiv geschaltet und die Logfunktion von Freezemon eingeschaltet. Ich kann dir sagen, alles hat so wie geplant funktioniert, die Logs werden wirklich zuverlässig erzeugt, in meinem Fall über 13200 Stück ::).

Eben habe ich das Update gemacht und Freezemon läuft nun wieder mit aktiven apptime und der Logfunktion, jetzt aber begrenzt auf 500 Dateien (gute Lösung von dir mit der Zahlenmäßigen Begrenzung).

Nach dem Update waren keinerlei Fehler von Frezemon mehr im Log zu sehen.

Bei mir läuft ständig eine Modbuskommunikation (alle 10 Sekunden), somit steht natürlich im Log von Freezemon immer als Verursacher der ModbusTCPServer, da dieser ja immer, auch während eines einfrieren aktiv ist. Dies erschwert natürlich jegliche Auswertung um den Verursacher zu finden. Ich muss mal meine Log's auf dem Raspi auswerten, eventuell kann ich ja da den Verursacher in den 5 Sekunden vor auftreten finden.

2018.03.05 17:48:14 1: PERL WARNING: Subroutine HandleTimeout redefined at ./FHEM/98_apptime.pm line 46.
2018.03.05 17:48:14 1: PERL WARNING: Subroutine CallFn redefined at ./FHEM/98_apptime.pm line 149.
2018.03.05 17:48:39 3: [Freezemon] freezemon: dumping 462 log entries to ./log/freeze-20180305-174839.log
2018.03.05 17:48:39 2: [Freezemon] freezemon: possible freeze starting at 17:48:37, delay is 2.557 possibly caused by ModbusTCPServer_Poll(N/A)


Die beiden Perl Warnungen bezüglich apptime stehen nach dem ersten Freeze immer noch im Log.

Gruß Reinhard
Fhem 6.3 auf Raspberry Pi4 SSD mit Raspbian Bookworm, Homematic, Homematic IP, CCU3 mit RapberryMatic, WAGO 750-880, E3DC S10E Hauskraftwerk, E3DC Wallbox, my-PV AC ELWA-E Heizstab, Fritz!Box 7590, KIA Bluelinky

KernSani

Hi Reinhard,

autsch... da war FHEM nur noch mit Logfiles schreiben beschäftigt :-S

Zu den Warnungen von apptime - die lassen sich nicht verhindern - auch wenn du apptime manuell startest tauchen die im Log auf (liegt einfach daran, dass apptime Routinen aus der fhem.pl überschreibt).

Bez. des Modbus: Ich habe auch so Kandidaten, die (fast) immer als mögliche Verursacher auftauchen. Ich denke über eine Blacklist nach, in die man die aufnehmen kann und die dann als mögliche Verursacher ignoriert werden (anders als die existierenden ignoreDev - bei denen der komplette Freeze ignoriert wird).

Zum Logging an sich: Wie Andy (der Erfinder des Loggings) sehe ich auf meinem Produktivsystem auch gelegentlich Ausreisser, bei denen das Logging selbst einen zusätzlichen Freeze verursacht, daher werde ich versuchen die ganze Freeze-Behandlung im Laufe der WOche mal auf non-blocking umzustellen.

Grüße,

Oli
RasPi: RFXTRX, HM, zigbee2mqtt, mySensors, JeeLink, miLight, squeezbox, Alexa, Siri, ...

Rewe2000

Hallo Oli,

die Idee mit der Blacklist finde ich gut, somit können zumindest solche "Kandidaten" in den Hintergrund treten und machen die Sicht auf die wahrscheinlichsten Verursacher der Freezes frei.
Ich hatte auch den Eindruck Freezemon führt in einigen Fällen beim logging zum Freeze, Nonblocking würde da natürlich Abhilfe schaffen.

Ich denke einige attr kannst du dem Modul noch zumuten, aber es besteht immer die Gefahr wenn es zu viele werden, dass es von der Bedienung für "Neueinsteiger" nahezu nicht mehr zu verstehen ist. Den Ausgleich kann hier nur eine gute Doku (Wiki, Commandref) schaffen.

Auch das löschen der Log-Dateien funktioniert bei mir prima, spätestens Morgenvormittag werden ich sehen ob apptime jetzt OK ist. ;)

Danke nochmals für deine Arbeit.
Gruß Reinhard
Fhem 6.3 auf Raspberry Pi4 SSD mit Raspbian Bookworm, Homematic, Homematic IP, CCU3 mit RapberryMatic, WAGO 750-880, E3DC S10E Hauskraftwerk, E3DC Wallbox, my-PV AC ELWA-E Heizstab, Fritz!Box 7590, KIA Bluelinky