FHEM Log Cannot fork: Cannot allocate memory

[herrmannj]

short: händisch ja, automatisch nein.

long: Jeder Eintrag im heap (+stack ) müsste manuell erforscht und einem modul zugeordnet werden. Das dauert "etwas" Im Zweifel ist es besser 2 dumps anzulegen. Einen nach dem Start und einen wenn der Speicher "voll läuft". Dort sucht man nach Auffälligkeiten. Es gibt auch Speicherleichen die aus FHEM (also "von innen") überhaupt nicht mehr finden lassen.

Beispiel:

Code Auswählen Erweitern


sub
test {
  my $a;
  my $b;

  $a->{b} = \$b;
  $a->{0} = [1..65535];
  $b->{a} = \$a;
  $b->{0} = [1..65535];
  return;
}
for (1..65535) {
  test();
}
)
for (1..65535) {
  test();
}


Nach dem Verlassen von "test" laufen "a" und "b" aus dem scope, bleiben aber im Speicher. Wenn "test" fertig ist kann man keine der beiden Variablen mehr erreichen (ergo löschen). Sie belegen jedoch weiter Speicher. Im Beipiel 65k x ein dutzend bytes.

Das Beispiel ist übersichtlich. closures, "$parent", rekursive functionen verstecken das oft so "gut" das es schwer zu sehen ist. Weil FHEM jedoch ein long running process ist summiert sich das. Es sind oft nur wenige bytes die "verloren" gehen. IO Operationen (Netzwerk Kommikation) findet aber so oft statt das sich auch kleine leaks (bugs) im Laufe von Tagen / Wochen summieren.

Aus dem verlinkten dokument:

As the user guide explains:

    The basic workflow consists of two main stages: first a heap dump file is generated from the perl process being debugged, at or around the time that the problem becomes apparent, and secondly this file is loaded by an analysis tool in order to inspect the contents.

    These two stages are described here separately. It is important to note that they don't have to be done at the same time, on the same perl process, or even on the same sort of machine. It is fully possible to capture the heap from a process on, say, a small server, then copy the file to a development workstation or laptop and analyse it there at a later time.

edit: codebeispiel

[herrmannj]

Bitte schön

https://forum.fhem.de/index.php/topic,73490.msg653927.html#msg653927

yepp. Aber leaks wie aus dem post darüber sieht man damit auch nicht.

[CoolTux]

Nun sei mal nicht so Jörg. Bin froh mich mit 40 überhaupt noch an den Thread erinnern zu können 

Ach so.
Jörg hat Recht 

[Wernieman]

@CoolTux:

Was soll ich sagen, ich habe es gelesen, ausprobiert und einen Tag später .... aber 40 ist wirklich nicht mehr viel los mit einem 

[frank]

Thema ist zwar schon älter, aber die Meldung habe ich die letzten Tage auch immer mal wieder im Log. Eine Frage, die indirekt damit zu tun hat, kann ich irgendwie auf die Meldung Triggern. Soll heißen ich würde mir gerne eine Nachricht schicken lassen, wenn diese Meldung im Log auftaucht um Zeitnah zu schauen. Soll heißen gibt es ein entsprechendes EVENT dazu?

notify's können mit attr readLog auch auf fhem.log lauschen. 

[Amenophis86]

notify's können mit attr readLog auch auf fhem.log lauschen. 

Schau an, gut zu wissen. Werde ich mich die Tage mal dran machen und versuchen. Dank dir.

[Wernieman]

Wenn Du etwas gefunden hast, könntest Du deine Lösung posten?

[Amenophis86]

also das notify war kein Problem. Jetzt wollte ich mit dem debugbefehl: fhemdebug memusage arbeiten, aber dieser lässt mein FHEM direkt ohne Meldung abstürzen. Ich habe Devel::Size sowohl über

Code Auswählen Erweitern

cpanm Devel::Size als auch mittels

Code Auswählen Erweitern

apt-get -s install libdevel-size-perl
als auch

Code Auswählen Erweitern

apt-get install libdevel-size-perl installiert bzw. versucht. Kann ich irgendwie prüfen ob es klappt bzw. warum es nicht klappt?

[Wernieman]

d.h. enn Du (auch manuell)? aufrufst:
fhemdebug memusage

Ist fhem sofort weg? Was sagt denn das Log?

[Amenophis86]

korrekt, auch dann. Mit ohne Meldung meinte ich, dass auch im Log keine Meldung mehr kommt. Ist direkt weg und nix geht mehr. In der Beschreibung von Rudi steht ja, dass es zum Absturz kommen kann, weiß nur nicht, wie ich das verhindern kann.

[Wernieman]

Sorry, da kann ich Dir nicht helfen, da müssen wir auf "tiefere" Experten warten

[rudolfkoenig]

Eigentlich muesste Devel::Size gefixt werden, dazu habe ich aber keine Musse.
Falls das Perl-Modul nicht installiert ist, dann meldet FHEM das direkt.

Ich habe eine neue Version eingecheckt, der bei "attr global verbose 5" das naechste Element ausgibt, was geprueft wird. Nach einem Absturz sollte das als Letztes im fhem-Log stehen.

[Amenophis86]

Werde es die Tage prüfen und mich melden. Danke

[abc2006]

Hi,
nachdem ich jetzt viel Hilfe von Heiko erhalten habe, komm ich hier mal rein:

Ich hab das Problem, dass logdb async in letzter Zeit regelmäßig abstürzt, und mittlerweile herausgefunden, dass es an "can not allocate memory" liegt.
Das Problem war heute gerade wieder aktuell, weshalb ich diesen Thread gefunden habe.
Daraufhin hab ich "fhemdebug memusage" ausgeführt, natürlich ohne vorher global auf verbose 5 zu schalten. FHEM ist genauso natürlich abgestürzt.
Wenn ich jetzt am (frisch gestarteten) FHEM das fhemdebug memusage ausführe, stürzt es ebenfalls ab. Im Log stehen dann diese Meldungen:

Code Auswählen Erweitern


2018.01.25 16:38:25.123 5: Cmd: >fhemdebug memusage<
2018.01.25 16:38:25.124 5: Loading ./FHEM/98_fhemdebug.pm
2018.01.25 16:38:25.142 5: main::oldvalue
2018.01.25 16:38:25.145 5: main::FW_fhemwebjs
2018.01.25 16:38:25.146 5: main::cmds
2018.01.25 16:38:25.147 5: main::FW_detail
2018.01.25 16:38:25.147 5: main::reread_active
2018.01.25 16:38:25.148 5: main::overload::numbers::names
2018.01.25 16:38:25.148 5: main::overload::category
2018.01.25 16:38:25.148 5: main::overload::constants
2018.01.25 16:38:25.149 5: main::overload::ops
2018.01.25 16:38:25.149 5: main::overload::BEGIN
2018.01.25 16:38:25.149 5: main::overload::package
2018.01.25 16:38:25.149 5: main::constant::BEGIN
2018.01.25 16:38:25.150 5: main::constant::__ANON__
2018.01.25 16:38:25.150 5: main::constant::declared
2018.01.25 16:38:25.151 5: main::integer::hint_bits
2018.01.25 16:38:25.151 5: main::Symbol::EXPORT
2018.01.25 16:38:25.152 5: main::Symbol::BEGIN
2018.01.25 16:38:25.152 5: main::Symbol::EXPORT_OK
2018.01.25 16:38:25.152 5: main::Symbol::ISA
2018.01.25 16:38:25.153 5: main::FH1
2018.01.25 16:38:25.153 5: main::INC
2018.01.25 16:38:25.154 5: main::selectlist
2018.01.25 16:38:25.157 1: PERL WARNING: Devel::Size: Unknown variable type: 251 encountered
2018.01.25 16:38:25.157 1: stacktrace:
2018.01.25 16:38:25.158 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (141)
2018.01.25 16:38:25.158 1:     (eval)                              called by ./FHEM/98_fhemdebug.pm (123)
2018.01.25 16:38:25.158 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (149)
2018.01.25 16:38:25.158 1:     main::fhemdebug_memusage            called by ./FHEM/98_fhemdebug.pm (41)
2018.01.25 16:38:25.158 1:     main::fhemdebug_Fn                  called by fhem.pl (1169)
2018.01.25 16:38:25.158 1:     main::AnalyzeCommand                called by fhem.pl (1023)
2018.01.25 16:38:25.159 1:     main::AnalyzeCommandChain           called by ./FHEM/01_FHEMWEB.pm (2486)
2018.01.25 16:38:25.159 1:     main::FW_fC                         called by ./FHEM/01_FHEMWEB.pm (881)
2018.01.25 16:38:25.159 1:     main::FW_answerCall                 called by ./FHEM/01_FHEMWEB.pm (525)
2018.01.25 16:38:25.159 1:     main::FW_Read                       called by fhem.pl (3493)
2018.01.25 16:38:25.159 1:     main::CallFn                        called by fhem.pl (688)
2018.01.25 16:38:25.160 1: PERL WARNING: Devel::Size: Unknown variable type: 62 encountered
2018.01.25 16:38:25.160 1: stacktrace:
2018.01.25 16:38:25.160 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (141)
2018.01.25 16:38:25.160 1:     (eval)                              called by ./FHEM/98_fhemdebug.pm (123)
2018.01.25 16:38:25.160 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (149)
2018.01.25 16:38:25.160 1:     main::fhemdebug_memusage            called by ./FHEM/98_fhemdebug.pm (41)
2018.01.25 16:38:25.161 1:     main::fhemdebug_Fn                  called by fhem.pl (1169)
2018.01.25 16:38:25.161 1:     main::AnalyzeCommand                called by fhem.pl (1023)
2018.01.25 16:38:25.161 1:     main::AnalyzeCommandChain           called by ./FHEM/01_FHEMWEB.pm (2486)
2018.01.25 16:38:25.161 1:     main::FW_fC                         called by ./FHEM/01_FHEMWEB.pm (881)
2018.01.25 16:38:25.161 1:     main::FW_answerCall                 called by ./FHEM/01_FHEMWEB.pm (525)
2018.01.25 16:38:25.161 1:     main::FW_Read                       called by fhem.pl (3493)
2018.01.25 16:38:25.161 1:     main::CallFn                        called by fhem.pl (688)
2018.01.25 16:38:25.162 1: PERL WARNING: Devel::Size: Unknown variable type: 62 encountered
2018.01.25 16:38:25.162 1: stacktrace:
2018.01.25 16:38:25.162 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (141)
2018.01.25 16:38:25.162 1:     (eval)                              called by ./FHEM/98_fhemdebug.pm (123)
2018.01.25 16:38:25.162 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (149)
2018.01.25 16:38:25.162 1:     main::fhemdebug_memusage            called by ./FHEM/98_fhemdebug.pm (41)
2018.01.25 16:38:25.163 1:     main::fhemdebug_Fn                  called by fhem.pl (1169)
2018.01.25 16:38:25.163 1:     main::AnalyzeCommand                called by fhem.pl (1023)
2018.01.25 16:38:25.163 1:     main::AnalyzeCommandChain           called by ./FHEM/01_FHEMWEB.pm (2486)
2018.01.25 16:38:25.163 1:     main::FW_fC                         called by ./FHEM/01_FHEMWEB.pm (881)
2018.01.25 16:38:25.163 1:     main::FW_answerCall                 called by ./FHEM/01_FHEMWEB.pm (525)
2018.01.25 16:38:25.164 1:     main::FW_Read                       called by fhem.pl (3493)
2018.01.25 16:38:25.164 1:     main::CallFn                        called by fhem.pl (688)


Liegt der Absturz am oben erwähnten Fehler von Devel::Size?
Wenn nein, was kann ich machen, damit es *nicht* abstürzt?
Kann jemand aus dem Log erkennen, was den Absturz von FHEM verursacht?


Wenns das nächste mal hängt, werd ich an verbose 5 denken und mich melden. Kann nicht lange dauern:)

Grüße
Stephan

[rudolfkoenig]

Liegt der Absturz am oben erwähnten Fehler von Devel::Size?

Vermutlich.

Kann jemand aus dem Log erkennen, was den Absturz von FHEM verursacht?

Irgendetwas war in %selectlist, was Devel::Size::total_size nicht vertragen hat. Vermutlich hat einer der von Dir verwendeten Module was unuebliches an Datentyp reingeschrieben.

Ich habe gerade eine neue Variante von fhemdebug eingecheckt: es werden mehr interne Hashes detailliert gemessen (wie %selectlist), und es gibt ein Blacklist: das MAX-Modul und HTTPMOD Geraete werden nicht geprueft, da diese bei mir in einem Testsetup den Absturz bewirkt haben. Falls es bei dir auch mit dieser Version abstuerzt, dann bitte die letzten Zeilen bei "attr global verbose 5" hier anhaengen.