PRESENCE: riesige Menge an Fehlermeldungen bringt Logdatei zum Explodieren

[Uli Zappe]

Hallo,

seit dem 2. Juli schreibt PRESENCE bei mir plötzlich derart viele Fehlermeldungen in die fhem-2016-07.log-Datei, dass selbige am Explodieren ist.

Ich habe insgesamt 5 PRESENCE-Instanzen aktiviert, die sekündlich den Status abfragen. 4 davon lan-ping, und 1 shellscript (ruft ein selbstgeschriebenes C-Binary auf).

Das ging bislang ohne Probleme, allerdings habe ich 2 lan-ping-Instanzen erst neulich (am 2. Juli?? – ich meine aber, es war früher) hinzugefügt.

Jedenfalls bekomme ich seit dem 2. Juli alle Nase lang folgende Meldungen in die Logdatei geschrieben:

lan-ping:

Code Auswählen Erweitern

2016.07.03 05:24:53 2: PRESENCE (spring_STATE) - error while processing check: Could not execute ping command: "ping -c 1 spring"
2016.07.03 05:30:58 1: PERL WARNING: Use of uninitialized value $temp in scalar chomp at /usr/share/fhem/FHEM/73_PRESENCE.pm line 664.
2016.07.03 05:30:58 1: PERL WARNING: Use of uninitialized value $temp in string ne at /usr/share/fhem/FHEM/73_PRESENCE.pm line 665.

shellscript:

Code Auswählen Erweitern

2016.07.03 09:34:12 2: PRESENCE (Projektor_STATE) - error while processing check: scriptcall doesn't return any output
2016.07.03 09:34:40 1: PERL WARNING: Use of uninitialized value $ret in scalar chomp at /usr/share/fhem/FHEM/73_PRESENCE.pm line 905.
2016.07.03 09:34:40 1: PERL WARNING: Use of uninitialized value $ret in concatenation (.) or string at /usr/share/fhem/FHEM/73_PRESENCE.pm line 907.

Obwohl alle 4 lan-ping-Instanzen absolut identisch konfiguriert sind (nur unterschiedliche ping-Ziele, die aber wiederum allesamt Macs im lokalen Netzwerk sind, sich also auch zumindest ähnlich verhalten), ist die Fehlerhäufigkeit höchst unterschiedlich verteilt; in den letzen 3 Tagen gab es für die 4 Instanzen folgende Zahl von Fehlermeldungen:

1376 – 70 – 65 – 55

Die Zahl der Fehlermeldungen korreliert dabei nicht mir der Reihenfolge, in der die Instanzen in fhem.pl definiert sind. Die Fehlermeldungen sind auch zeitlich völlig ungleichmäßig verteilt; mal ballen sie sich, dann ist wieder Ruhe. Es ist alles völlig erratisch.

Die shellscript-Instanz hat 2424 Fehlermeldungen in den letzten 3 Tagen erzeugt.

56 mal eingestreut kam schließlich die Meldung:

Code Auswählen Erweitern

2016.07.04 07:32:08 1: Cannot fork: Nicht genügend Hauptspeicher verfügbar
2016.07.04 07:32:08 1: Cannot fork: Nicht genügend Hauptspeicher verfügbar

Als erste Hilfe wäre ich äußerst dankbar für einen Hinweis, ob/wie ich durch Auskommentieren o.ä. verhindern kann, dass diese Fehlermeldungen weiterhin in die Logdatei geschrieben werden, sonst ist in wenigen Tagen kein Platz mehr auf dem Speichermedium von meinem kleinen FHEM-Rechner ...

Von der Sache her bedeutet das alles ja lediglich, dass ca. einmal pro Minute eine Sekunde bei der Überprüfung ausgelassen wird; das ist eigentlich kein Beinbruch; bei der Nutzung stört das kaum – ich habe es ja nicht mal bemerkt. Das Problem ist wirklich die überlaufende Logdatei.

Grundsätzlich betrachtet ist aber natürlich die Frage, wo da ein Problem ist, und auch, wie FHEM generell mit solchen Mengen an Fehlermeldungen umgehen sollte. Vielleicht ab einer bestimmten Häufigkeit nur jede 10. oder 100. gleichartige Meldung in die Logdatei schreiben?

[betateilchen]

Als erste Hilfe wäre ich äußerst dankbar für einen Hinweis, ob/wie ich durch Auskommentieren o.ä. verhindern kann, dass diese Fehlermeldungen weiterhin in die Logdatei geschrieben werden

Nichts leichter als das... kommentiere am Anfang der Datei 73_PRESENCE.pm die Zeile "use warnings;" aus.

[frank]

2016.07.04 07:32:08 1: Cannot fork: Nicht genügend Hauptspeicher verfügbar

da ist wohl deine hardware zu "schwach".
entweder speicher vergrössern, oder zb die presence "aufrufe" entzerren, sodass immer nur 1 presence-check aktiv ist.

[betateilchen]

Man könnte auch über den Sinn von multiplen sekündlichen pings diskutieren...

[Markus Bloch]

Hallo zusammen,

ich habe soeben eine Änderung für PRESENCE eingecheckt, womit die Logmeldungen nicht mehr auftauchen. Die Warnings werden dann nicht mehr auftauchen. Die PRESENCE-eigenen Fehlermeldungen bleiben aber, da der entsprechende Shell-Aufruf (ping, C-Binary) dennoch nicht durchgeführt werden konnte. Wie Frank vermute ich hier ebenfalls einen Ressourcen-Engpass deiner Hardware.

Sekündliche PRESENCE-Definitionen sind nicht umbedingt schlimm, sofern die Hardware das stemmen kann (Speicher/CPU). Ein neuer Check wird immer erst dann nach 1 Sekunde gestartet, sobald der letzte Check fertig ist. Dies dient genau für solche Konfigurationen um eine Überlast zu vermeiden. Die Definition von weiteren 2 PRESENCE-Definitionen am 2.7. wäre eine sehr naheliegende Erklärung.

Welche Hardware genau benutzt du eigentlich? Was sagen CPU-, Arbeitspeicher-, Load-Auslastung?

Gruß
Markus

[Uli Zappe]

Danke für Eure Antworten und an Markus für die schnelle Hilfe! 

Nichts leichter als das... kommentiere am Anfang der Datei 73_PRESENCE.pm die Zeile "use warnings;" aus.

Guter Tipp, danke!    Aber Markus war schneller, als ich Deinen Tipp umsetzen konnte ... 

Man könnte auch über den Sinn von multiplen sekündlichen pings diskutieren...

Könnte man. 

Ich habe bei mir 4 Macs am Laufen, von denen ich so zeitnah wie möglich in FHEM sehen will, ob sie wach sind oder schlafen. Es gibt von Apple eine Fernwartungssoftware namens Remote Desktop, die den Status aller Macs im lokalen Netzwerk ebenfalls anzeigt. Nur läuft die selbst nur auf Macs, ihr Protokoll ist proprietär, und FHEM könnte in keiner Weise mit ihr kommunizieren. Also bleiben nach meinem Kenntnisstand nur sekündliche Pings. Wenn Du was Besseres weißt, immer her damit! 

Und eigentlich sollten für einen Rechner (auch einen kleinen) sekündliche Pings ein Klacks sein ...

ich habe soeben eine Änderung für PRESENCE eingecheckt, womit die Logmeldungen nicht mehr auftauchen. Die Warnings werden dann nicht mehr auftauchen. Die PRESENCE-eigenen Fehlermeldungen bleiben aber, da der entsprechende Shell-Aufruf (ping, C-Binary) dennoch nicht durchgeführt werden konnte.

Erstmal herzlichen Dank für die schnelle Reaktion! 

Verstehe ich Dich richtig, dass statt der zitierten 3 Zeilen pro Meldung jetzt nur noch 1 Zeile in der Logdatei auftauchen sollte, die mit PRESENCE, nicht die beiden mit PERL WARNING? Ich frage, weil nach der Installation des Updates und einem FHEM-Neustart zunächst doch wieder alle 3 Meldungen auftauchten, nach einem 2. Neustart dann aber gar keine mehr – so als ob das Problem jetzt plötzlich komplett verschwunden wäre.

Wie Frank vermute ich hier ebenfalls einen Ressourcen-Engpass deiner Hardware.
[...]
Welche Hardware genau benutzt du eigentlich? Was sagen CPU-, Arbeitspeicher-, Load-Auslastung?

Ja, mein armer kleiner Rechner ist schon etwas betagt, ein FOX Board G20 (http://www.acmesystems.it/FOXG20) von 2011, 400 MHz ARM9 CPU, 64 MB RAM, 4 GB SD Speicherkarte. Aber top sagt 40%-50% CPU-Auslastung, 40 MB von 64 MB RAM benutzt, kein Swap. Sieht alles nach grünem Bereich aus. Ich werde das mal über die nächsten Tage beobachten, vielleicht steckt ja irgendwo ein Memory Leak, und die Werte verschlechtern sich mit der Uptime.

[Uli Zappe]

Aber top sagt 40%-50% CPU-Auslastung, 40 MB von 64 MB RAM benutzt, kein Swap. Sieht alles nach grünem Bereich aus. Ich werde das mal über die nächsten Tage beobachten, vielleicht steckt ja irgendwo ein Memory Leak, und die Werte verschlechtern sich mit der Uptime.

Hm, nach 3 Stunden ist die CPU-Last gleich geblieben, aber der RAM-Verbrauch von 40 MB auf 55 MB angewachsen (außer FHEM laufen keine weiteren Anwendungsprozesse auf dem Rechner). Weiß jemand, der viel Erfahrung mit Linux und Perl hat, ob das ,,normal" ist?

PS: Nach wie vor keine einzige PRESENCE-Fehlermeldung!

[Wernieman]

Wie liest Du denn die Speicherwerte aus?

[Uli Zappe]

Wie liest Du denn die Speicherwerte aus?

Mit top. Scheint bei 55 MB jetzt aber stabil zu sein.

[Wernieman]

Dir ist klar, das "free" <> "Freier Speicher"?

Unix verwendet den Freien Speicher für das Cachen von Dateien (wie Windows mittlerweile auch). Anders als Windows, wird dieser Cache aber als "belegt" ausgegeben, d.h. free zeigt weniger. Deshalb genau geht der "freie" Speicher mit der Laufzeit des Systemes runter.

Anstatt top kannst Du aber auch "free" oder "vmstat" verwenden.

Mal zum "durchlesen"
http://www.cyberciti.biz/faq/linux-check-memory-usage/
https://wiki.ubuntuusers.de/vmstat/
http://www.linuxnix.com/find-ram-size-in-linuxunix/

Habe ich es richtig gelesen, das Dein System "nur" 64MByte-Ram hat?

[Uli Zappe]

Dir ist klar, das "free" <> "Freier Speicher"?

Ja, grundsätzlich schon (ich komme von NEXTSTEP/OS X, Windows kenne ich nicht  ). Aber mir fehlt auf Linux und mit Perl die Erfahrung und somit ,,Intuition", ob das konkret so OK aussieht. Wenn es jetzt bei 55 MB stoppt, ist es ja vermutlich OK (vielleicht problematisch bei einem FHEM-Update, wo evtl. nicht schnell genug Platz freigeschaufelt werden kann).

Habe ich es richtig gelesen, das Dein System "nur" 64MByte-Ram hat?

Ja, hast Du. 

[Uli Zappe]

Anstatt top kannst Du aber auch "free" oder "vmstat" verwenden.

free sieht freundlicher aus: 

             total       used       free     shared    buffers     cached
Mem:         60988      55572       5416          0       7568      13160
-/+ buffers/cache:      34844      26144
Swap:            0          0          0

[frank]

64MB sind für deinen anwendungsfall einfach zu wenig.

für jeden presence-check wird geforked, also eine weitere fheminstanz etabliert. bei einem fork wird dein speicher vermutlich noch genügen, denn du hattest bisher ja angeblich noch keine fehlermeldungen dies bezüglich. bei nun 5 presence-checks im sekundentakt steigt natürlich die wahrscheinlichkeit, dass weitere forks parallel gestartet werden sollen. irgendwann ist eben schluss.

ich habe das mit meiner fritzbox schon mal ausgiebig getestet. https://forum.fhem.de/index.php/topic,39887.0.html.

so schön diese nicht blockierenden module auch theoretisch sind. für server mit geringem speicher ist das aber ein k.o.-kriterium.

[Wernieman]

Und perl ist auch nicht gerade "speicherfreundlich" ....

Du solltest gucken, was Du alles installiert und wie konfiguriert hast. im zweifelsfalle auf "Speichersparsamkeit" setzen. 64MByte ist wirklich nicht viel ...

[Markus Bloch]

Hallo zusammen,

in der aktuellen Version gibt es nun ein neues Attribut für die Global-Definition mit dem man die maximale Anzahl an parallelen Prozessen begrenzen kann.

Code Auswählen Erweitern

attr global blockingCallMax 3

Dadurch kann man die Anzahl an parallel laufenden Prozessen begrenzen. Dies ist gerade für kleine Hardware sehr sinnvoll um dort nicht die Speichergrenzen zu sprengen.

Ich würde euch empfehlen dieses Attribut zu nutzen.

Sollte die maximale Anzahl an parallelen Prozessen erreicht sein, werden weitere Aufrufe in eine Warteschlange eingereiht. Sobald ein Prozess beendet wurde, werden die Aufrufe aus der Warteschlange abgearbeitet.

Gruß
Markus

[Uli Zappe]

Ich würde euch empfehlen dieses Attribut zu nutzen.

Dazu nur als kurzer Erfahrungswert:

Ich habe (nach Behebung der diesen Thread auslösenden Probleme durch Markus) mit meiner super-schwachbrüstigen Hardware (400 MHz ARM, ganze 64 MB RAM) keinerlei Probleme, 5 parallele PRESENCE-Abfragen im Sekundentakt laufen zu lassen. 

[carzl]

Hallo zusammen,

ich habe ganz ähnliche Probleme, bei mir laufen 17 Presence-Instanzen, ich liefere für so ziemlich alle Netzwerkgeräte, die ich hier so habe, im Minutentakt einen Status, ob an oder aus. Wobei mein Fhem auf einem RPi3 mit ja immerhin 1 GB RAM läuft.

Bevor ich jetzt lange versuche, das zu entzerren oder anderweitig zu fixen - haltet Ihr 17 Instanzen für grundsätzlich zu viel, sprich bekomme ich mit dieser Anzahl Überwachungen generell keine Ruhe rein?
Oder sollte da das blockingCallMax auf z.B. 5 schon gut helfen ?

Danke! 

[FunkOdyssey]

Hmm. Ich habe einen RasPi B2 und in FHEM 8 PRESENCE-Definitionen.

Da ich auch die Fehlermeldungen hatte...

Code Auswählen Erweitern

Cannot fork: Nicht genügend Hauptspeicher verfügbar

... habe ich blockingCallMax mal auf 5 gesetzt. Leider ohne Erfolg.

Ich werde das Intervall der PRESENCE-Geräte mal entzerren und blockingCallMax  auf 3 setzen. Mal schauen.

[carzl]

Ich habe die PRESENCE-Defs drastisch reduziert, die meisten waren eh nur Spielerei. Ich muss in Fhem nicht sehen, ob meine Fitnessuhr im eingeschalteten Zustand innerhalb der BT-Zone rumliegt... 
Seitdem habe ich Ruhe.

[FunkOdyssey]

Nehmen wir mal an, ich hätte ein Modul, welches mir den Status eines Geräts anzeigt (STV für Samsung TV oder YAMAHA_AVR für Yamaha Audio Receiver):
Welche Variante wäre dann weniger performancefressend, wenn man nur den Online-Status eines Geräts herausfinden will? Modul oder PRESENCE?