Cannot fork: Cannot allocate memory | BlockingInformParent

iice64 · 23 Januar 2019, 17:46:31

Zitat von: Timmy.m am 23 Januar 2019, 16:16:11
Hattest du am 17.1 ein Neustart von FHEM gemacht? Es sieht bei dir so aus, als würde der RAM Verbrauch auch steigen... aber halt nur minimal. Hast du mal geschaut, ob du beim Räume wechseln (Zwischen Everything und anderen Räumen) per htop auch RAM Einbußen in 0.1% Schritten verzeichnen kannst.

Ja da war ein Neustart und dann dauert es halt immer bis alle Prozesse sich eingeschwungen haben.
Zumal bei mir nginx, tomcat (java heap), fhem und diverse Cronjobs laufen.
Aber der perl Prozess nimmt sich nicht ständig mehr Speicher wie perl 5.24.1. Da hat mein Pi nach ca. 10 Stunden keinen Speicher mehr gehabt.
Der Wechsel von Everything zu anderen Räumen führt nicht zu einer ständigen Zunahme des Speichers, sondern er pendelt um 285MB herum.

Skusi · 23 Januar 2019, 18:13:47

In 10 Stunden kein Ram mehr !? Das ist Krass.
Da bin ich ja noch froh das es bei mir "nur" ca 60 MB / Tag sind. Ich fliege ab Sonntag 14 Tage weg, da kann ich sowas nicht brauchen. Ich fasse nun auch nix mehr an, aus Angst alles noch schlimmer zu machen. Aber doof finde ich das schon extrem. Lief doch jahrelang ohne diese Lecks.

Also scheint dieses perlbrew wohl die beste Lösung zu sein. Da muß ich mich also nach meinem Urlaub mal mit beschäftigen. Ich bin aber noch guter Hoffnung das hier noch jemand die Ursache findet.

mumpitzstuff · 23 Januar 2019, 22:22:43

Geh mal ein paar Kommentare zurück, da gab es irgendwas, um bei einem Speicherproblem Fhem zu restarten. Könnte für den Urlaub hilfreich sein.

MadMax-FHEM · 23 Januar 2019, 22:37:34

Zitat von: mumpitzstuff am 23 Januar 2019, 22:22:43
Geh mal ein paar Kommentare zurück, da gab es irgendwas, um bei einem Speicherproblem Fhem zu restarten. Könnte für den Urlaub hilfreich sein.

Vermutlich das hier:

Code Auswählen

define nCannotForkRestart notify global:CANNOT_FORK shutdown restart

Gruß, Joachim

Timmy.m · 25 Januar 2019, 21:56:52

Dank der Anleitung hier im Forum habe ich nun mit Perlbrew die perl version 5.20.3.
Jetzt bekomme ich Fehler beim Start, dass Pakete nicht installiert sind

ZitatMessages collected while initializing FHEM:
configfile: Cannot load module UWZ
Cannot define A61 device. Perl modul HTML::TreeBuilder::XPath is missing.
Cannot load module SIP

Wie bekomme ich die nun Installiert... in der "Standard Perl Version" sind sie bereits installiert und wenn ich im Terminal Perlbrew mit perl version 5.20.3. aktiviere und nachinstalliere zeigt es für FHEM keine Wirkung. Ich bin ratlos.

Grüße Tim

Timmy.m · 26 Januar 2019, 10:49:00

Jetzt kommt die große Überraschung. Eine ganze Nacht lief nun der Raspberry mit version 5.20.3.
Und oh Wunder... er verbraucht immer noch RAM.

Bin nun endgültig fix und fertig!

Grüße Tim

frank · 26 Januar 2019, 12:30:49

da hast du dir ja was "eingefangen".

dein os ist nun stretch?
hast du dann ein neues stretch lite image genommen, oder dein altes jessie "aufgemotzt".

Timmy.m · 26 Januar 2019, 15:11:20

Hallo Frank.

Ich bin zurück auf Jessie per Backup. Also das alte System nur mit Perlbrew.

Grüße Tim

Skusi · 26 Januar 2019, 15:57:31

Na toll, dann bleibt ja nur noch nachzuweisen das es mit Perl ab 5.25.10 gefixt ist.

Danke an Timmy.m der mir den Weg über 5.20.3 erspart hat. Ich hoffe das es jemand nochmal testet um zu bestätigen das die Arbeit sich gelohnt hat. Wegen meine Reise hab ich erstmal nur die Auto Restart Funktion realisiert. So startet das System zwar alle paar Tage neu, aber mehr kann ich auf die schnelle nicht tun.

Ich mußte auch feststellen das verfügbarer Speicher unter 500 MB schon zum cannot_Fork führt. Das bedeutet das ich nach einem Neustart ca 5 Tage bis zum restart habe.

Hoffentlich geht das gut. Bin 12 Tage weg...

Ich hoffe nach meiner Rückkehr zu wissen was Zutun ist.

rudolfkoenig · 26 Januar 2019, 16:31:45

ZitatDanke an Timmy.m der mir den Weg über 5.20.3 erspart hat.

Wie ich geschrieben habe: Hier werden mehrere Probleme diskutiert, die das gleiche _Symptom_ haben. Einer der Ursachen ist sicher perl 5.24, die anderen Ursachen sind z.Zt. noch nicht bekannt, und das sie im Perl zu finden ist, ist (d)eine neue Hypothese.

Welche Ursache wen betrifft, ist je nach verwendetes Modul, gesetzte Attribute, OS und Hardware unterschiedlich. Solange deine Konfiguration, OS und Hardware mit der von Timmy.m nicht identisch ist, wuerde ich von perl 5.24 auf eine andere Version wechseln, damit dieses eine bekannte Bug schonmal ausgeschlosen wird.

Wernieman · 26 Januar 2019, 19:57:34

Vor allem, da es für jessie keine updates mehr gibt ...

Glaube auch, das arm eine zusätzliche Fehlerquelle ist. Bis jetzt habe ich bei X86 nichts gehört .... und meine (Allerdings kleine) fhem Installation dümpelt mit wenig Speicher vor sich hin (auf X86)

Damian · 26 Januar 2019, 21:06:11

Zitat von: Wernieman am 26 Januar 2019, 19:57:34
Vor allem, da es für jessie keine updates mehr gibt ...

Glaube auch, das arm eine zusätzliche Fehlerquelle ist. Bis jetzt habe ich bei X86 nichts gehört .... und meine (Allerdings kleine) fhem Installation dümpelt mit wenig Speicher vor sich hin (auf X86)

Perl 5.24 hat auch das Problem auch unter x86. Das kann ich aus eigener Erfahrung sagen.

maci · 27 Januar 2019, 08:56:30

Jetzt habe ich das Problem auch auf meinem Fhem Hauptserver.
Hier läuft die Perl-Problemversion 5.24.

Ich hatte das Problem hier bisher noch nie.
Vor kurzem habe ich hier grab installiert.
Anfangs habe ich mir nicht dabei gedacht.
Gestern ist mir aufgefallen, nach dem ich ein paar Tage nicht nachgesehen hatte, dass im Logfile das hier steht:

Code Auswählen

Cannot fork: Cannot allocate memory
2019.01.26 16:51:45 1: Cannot fork: Cannot allocate memory
2019.01.26 16:51:45 1: stacktrace:
2019.01.26 16:51:45 1:     main::fhemFork                      called by FHEM/Blocking.pm (172)
2019.01.26 16:51:45 1:     main::BlockingStart                 called by FHEM/Blocking.pm (107)
2019.01.26 16:51:45 1:     main::BlockingCall                  called by ./FHEM/42_SYSMON.pm (905)
2019.01.26 16:51:45 1:     main::SYSMON_Update                 called by ./FHEM/98_apptime.pm (205)
2019.01.26 16:51:45 1:     main::apptime_getTiming             called by ./FHEM/98_apptime.pm (113)
2019.01.26 16:51:45 1:     main::HandleTimeout                 called by fhem.pl (649)
2019.01.26 16:51:45 1: Cannot fork: Cannot allocate memory

Die Steuerungen der Rolläden liefen allerdings normal weiter. Auch die Temperaturwerte wurden ordnungsgemäß in die DbLog eingetragen.

Am 20. 1 um 22:51 kam erstmals diese Meldung.
Dazwischen immer andere normale Logmeldungen.
Interessant ist, dass zwischen den Cannot fork Meldungen immer wieder Pausen von 4-6 Stunden sind. In dieser Zeit waren die Logmeldungen normal.

Habe gestern abend dann mal die stutdown restart Routine eingebaut, denn ein Downgrade will ich derzeit nicht machen.

Interessant ist allerdings, dass im Anschluß an mein Connot fork Meldungen dass hier kommt:

Code Auswählen

PERL WARNING: Use of uninitialized value in int at ./FHEM/42_SYSMON.pm line 3494.
2019.01.21 01:13:38 3: eval: {BlockingStart('33485')}
2019.01.21 01:13:38 1: stacktrace:
2019.01.21 01:13:38 1:     main::__ANON__                      called by ./FHEM/42_SYSMON.pm (3493)
2019.01.21 01:13:38 1:     main::SYSMON_isProcFS               called by ./FHEM/42_SYSMON.pm (1188)
2019.01.21 01:13:38 1:     main::SYSMON_obtainParameters_intern called by ./FHEM/42_SYSMON.pm (1129)
2019.01.21 01:13:38 1:     main::SYSMON_obtainParameters       called by ./FHEM/42_SYSMON.pm (956)
2019.01.21 01:13:38 1:     main::SYSMON_blockingCall           called by FHEM/Blocking.pm (192)
2019.01.21 01:13:38 1:     main::BlockingStart                 called by (eval 1035576) (1)
2019.01.21 01:13:38 1:     (eval)                              called by fhem.pl (1115)
2019.01.21 01:13:38 1:     main::AnalyzePerlCommand            called by fhem.pl (1140)
2019.01.21 01:13:38 1:     main::AnalyzeCommand                called by fhem.pl (1062)
2019.01.21 01:13:38 1:     main::AnalyzeCommandChain           called by ./FHEM/98_telnet.pm (242)
2019.01.21 01:13:38 1:     main::telnet_Read                   called by ./FHEM/98_apptime.pm (205)
2019.01.21 01:13:38 1:     main::apptime_getTiming             called by ./FHEM/98_apptime.pm (165)
2019.01.21 01:13:38 1:     main::CallFn                        called by fhem.pl (726)
2019.01.21 01:13:38 1: PERL WARNING: Use of uninitialized value in int at ./FHEM/42_SYSMON.pm line 3625.
2019.01.21 01:13:38 3: eval: {BlockingStart('33485')}
2019.01.21 01:13:38 1: stacktrace:
2019.01.21 01:13:38 1:     main::__ANON__                      called by ./FHEM/42_SYSMON.pm (3624)
2019.01.21 01:13:38 1:     main::SYSMON_isSysCpuNum            called by ./FHEM/42_SYSMON.pm (1572)
2019.01.21 01:13:38 1:     main::SYSMON_getCPUCoreNum_intern   called by ./FHEM/42_SYSMON.pm (1597)
2019.01.21 01:13:38 1:     main::SYSMON_getCPUCoreNum          called by ./FHEM/42_SYSMON.pm (1203)
2019.01.21 01:13:38 1:     main::SYSMON_obtainParameters_intern called by ./FHEM/42_SYSMON.pm (1129)
2019.01.21 01:13:38 1:     main::SYSMON_obtainParameters       called by ./FHEM/42_SYSMON.pm (956)
2019.01.21 01:13:38 1:     main::SYSMON_blockingCall           called by FHEM/Blocking.pm (192)
2019.01.21 01:13:38 1:     main::BlockingStart                 called by (eval 1035576) (1)
2019.01.21 01:13:38 1:     (eval)                              called by fhem.pl (1115)
2019.01.21 01:13:38 1:     main::AnalyzePerlCommand            called by fhem.pl (1140)
2019.01.21 01:13:38 1:     main::AnalyzeCommand                called by fhem.pl (1062)
2019.01.21 01:13:38 1:     main::AnalyzeCommandChain           called by ./FHEM/98_telnet.pm (242)
2019.01.21 01:13:38 1:     main::telnet_Read                   called by ./FHEM/98_apptime.pm (205)
2019.01.21 01:13:38 1:     main::apptime_getTiming             called by ./FHEM/98_apptime.pm (165)
2019.01.21 01:13:38 1:     main::CallFn                        called by fhem.pl (726)
2019.01.21 01:13:38 1: PERL WARNING: Use of uninitialized value $val in int at ./FHEM/42_SYSMON.pm line 1765.
2019.01.21 01:13:38 3: eval: {BlockingStart('33485')}
2019.01.21 01:13:38 1: stacktrace:
2019.01.21 01:13:38 1:     main::__ANON__                      called by ./FHEM/42_SYSMON.pm (1765)
2019.01.21 01:13:38 1:     main::SYSMON_getCPUTemp_RPi         called by ./FHEM/42_SYSMON.pm (1207)
2019.01.21 01:13:38 1:     main::SYSMON_obtainParameters_intern called by ./FHEM/42_SYSMON.pm (1129)
2019.01.21 01:13:38 1:     main::SYSMON_obtainParameters       called by ./FHEM/42_SYSMON.pm (956)
2019.01.21 01:13:38 1:     main::SYSMON_blockingCall           called by FHEM/Blocking.pm (192)
2019.01.21 01:13:38 1:     main::BlockingStart                 called by (eval 1035576) (1)
2019.01.21 01:13:38 1:     (eval)                              called by fhem.pl (1115)
2019.01.21 01:13:38 1:     main::AnalyzePerlCommand            called by fhem.pl (1140)
2019.01.21 01:13:38 1:     main::AnalyzeCommand                called by fhem.pl (1062)
2019.01.21 01:13:38 1:     main::AnalyzeCommandChain           called by ./FHEM/98_telnet.pm (242)
2019.01.21 01:13:38 1:     main::telnet_Read                   called by ./FHEM/98_apptime.pm (205)
2019.01.21 01:13:38 1:     main::apptime_getTiming             called by ./FHEM/98_apptime.pm (165)
2019.01.21 01:13:38 1:     main::CallFn                        called by fhem.pl (726)
2019.01.21 01:13:38 1: PERL WARNING: Use of uninitialized value in int at ./FHEM/42_SYSMON.pm line 3516.
2019.01.21 01:13:38 3: eval: {BlockingStart('33485')}
2019.01.21 01:13:38 1: stacktrace:
2019.01.21 01:13:38 1:     main::__ANON__                      called by ./FHEM/42_SYSMON.pm (3515)
2019.01.21 01:13:38 1:     main::SYSMON_isCPUTempBBB           called by ./FHEM/42_SYSMON.pm (1209)
2019.01.21 01:13:38 1:     main::SYSMON_obtainParameters_intern called by ./FHEM/42_SYSMON.pm (1129)
2019.01.21 01:13:38 1:     main::SYSMON_obtainParameters       called by ./FHEM/42_SYSMON.pm (956)
2019.01.21 01:13:38 1:     main::SYSMON_blockingCall           called by FHEM/Blocking.pm (192)
2019.01.21 01:13:38 1:     main::BlockingStart                 called by (eval 1035576) (1)
2019.01.21 01:13:38 1:     (eval)                              called by fhem.pl (1115)
2019.01.21 01:13:38 1:     main::AnalyzePerlCommand            called by fhem.pl (1140)
2019.01.21 01:13:38 1:     main::AnalyzeCommand                called by fhem.pl (1062)
2019.01.21 01:13:38 1:     main::AnalyzeCommandChain           called by ./FHEM/98_telnet.pm (242)
2019.01.21 01:13:38 1:     main::telnet_Read                   called by ./FHEM/98_apptime.pm (205)
2019.01.21 01:13:38 1:     main::apptime_getTiming             called by ./FHEM/98_apptime.pm (165)
2019.01.21 01:13:38 1:     main::CallFn                        called by fhem.pl (726)
2019.01.21 01:13:38 1: PERL WARNING: Use of uninitialized value $val in int at ./FHEM/42_SYSMON.pm line 1820.
2019.01.21 01:13:38 3: eval: {BlockingStart('33485')}
2019.01.21 01:13:38 1: stacktrace:
2019.01.21 01:13:38 1:     main::__ANON__                      called by ./FHEM/42_SYSMON.pm (1820)
2019.01.21 01:13:38 1:     main::SYSMON_getCPUTemp_X           called by ./FHEM/42_SYSMON.pm (1214)
2019.01.21 01:13:38 1:     main::SYSMON_obtainParameters_intern called by ./FHEM/42_SYSMON.pm (1129)
2019.01.21 01:13:38 1:     main::SYSMON_obtainParameters       called by ./FHEM/42_SYSMON.pm (956)
2019.01.21 01:13:38 1:     main::SYSMON_blockingCall           called by FHEM/Blocking.pm (192)
2019.01.21 01:13:38 1:     main::BlockingStart                 called by (eval 1035576) (1)
2019.01.21 01:13:38 1:     (eval)                              called by fhem.pl (1115)
2019.01.21 01:13:38 1:     main::AnalyzePerlCommand            called by fhem.pl (1140)
2019.01.21 01:13:38 1:     main::AnalyzeCommand                called by fhem.pl (1062)
2019.01.21 01:13:38 1:     main::AnalyzeCommandChain           called by ./FHEM/98_telnet.pm (242)
2019.01.21 01:13:38 1:     main::telnet_Read                   called by ./FHEM/98_apptime.pm (205)
2019.01.21 01:13:38 1:     main::apptime_getTiming             called by ./FHEM/98_apptime.pm (165)
2019.01.21 01:13:38 1:     main::CallFn                        called by fhem.pl (726)
2019.01.21 01:13:38 1: PERL WARNING: Use of uninitialized value $free_version in substitution (s///) at ./FHEM/42_SYSMON.pm line 2268.
2019.01.21 01:13:38 3: eval: {BlockingStart('33485')}
2019.01.21 01:13:38 1: stacktrace:
2019.01.21 01:13:38 1:     main::__ANON__                      called by ./FHEM/42_SYSMON.pm (2268)
2019.01.21 01:13:38 1:     main::SYSMON_getRamAndSwap          called by ./FHEM/42_SYSMON.pm (1255)
2019.01.21 01:13:38 1:     main::SYSMON_obtainParameters_intern called by ./FHEM/42_SYSMON.pm (1129)
2019.01.21 01:13:38 1:     main::SYSMON_obtainParameters       called by ./FHEM/42_SYSMON.pm (956)
2019.01.21 01:13:38 1:     main::SYSMON_blockingCall           called by FHEM/Blocking.pm (192)
2019.01.21 01:13:38 1:     main::BlockingStart                 called by (eval 1035576) (1)
2019.01.21 01:13:38 1:     (eval)                              called by fhem.pl (1115)
2019.01.21 01:13:38 1:     main::AnalyzePerlCommand            called by fhem.pl (1140)
2019.01.21 01:13:38 1:     main::AnalyzeCommand                called by fhem.pl (1062)
2019.01.21 01:13:38 1:     main::AnalyzeCommandChain           called by ./FHEM/98_telnet.pm (242)
2019.01.21 01:13:38 1:     main::telnet_Read                   called by ./FHEM/98_apptime.pm (205)
2019.01.21 01:13:38 1:     main::apptime_getTiming             called by ./FHEM/98_apptime.pm (165)
2019.01.21 01:13:38 1:     main::CallFn                        called by fhem.pl (726)
2019.01.21 01:13:38 1: PERL WARNING: Use of uninitialized value $free_version in numeric gt (>) at ./FHEM/42_SYSMON.pm line 2269.
2019.01.21 01:13:38 3: eval: {BlockingStart('33485')}
2019.01.21 01:13:38 1: stacktrace:
2019.01.21 01:13:38 1:     main::__ANON__                      called by ./FHEM/42_SYSMON.pm (2269)
2019.01.21 01:13:38 1:     main::SYSMON_getRamAndSwap          called by ./FHEM/42_SYSMON.pm (1255)
2019.01.21 01:13:38 1:     main::SYSMON_obtainParameters_intern called by ./FHEM/42_SYSMON.pm (1129)
2019.01.21 01:13:38 1:     main::SYSMON_obtainParameters       called by ./FHEM/42_SYSMON.pm (956)
2019.01.21 01:13:38 1:     main::SYSMON_blockingCall           called by FHEM/Blocking.pm (192)
2019.01.21 01:13:38 1:     main::BlockingStart                 called by (eval 1035576) (1)
2019.01.21 01:13:38 1:     (eval)                              called by fhem.pl (1115)
2019.01.21 01:13:38 1:     main::AnalyzePerlCommand            called by fhem.pl (1140)
2019.01.21 01:13:38 1:     main::AnalyzeCommand                called by fhem.pl (1062)
2019.01.21 01:13:38 1:     main::AnalyzeCommandChain           called by ./FHEM/98_telnet.pm (242)
2019.01.21 01:13:38 1:     main::telnet_Read                   called by ./FHEM/98_apptime.pm (205)
2019.01.21 01:13:38 1:     main::apptime_getTiming             called by ./FHEM/98_apptime.pm (165)
2019.01.21 01:13:38 1:     main::CallFn                        called by fhem.pl (726)

Danach ist wieder Ruhe und nur normale Einträge, bis es dann ein paar Stunden später wieder auftaucht.

Jedenfalls beobachte ich mein Fhem weiterhin etwas.

Gerrit · 27 Januar 2019, 09:58:41

Moin,

mir ist das "vollaufen" des Speichers vor ein paar Tagen auch zufällig aufgefallen. Ich hatte freezemon und yeelightbridge installiert. Nach der Deinstallation war wieder Ruhe. Perl ist 5.20.2

Gruß Gerrit
https://uploads.tapatalk-cdn.com/20190127/b705556ec1006601c241319858bdfa8d.jpg

Gesendet von meinem ONEPLUS A6013 mit Tapatalk

Timmy.m · 27 Januar 2019, 20:53:58

Danke Gerrit!

ich habe freezemon mal aus meiner Config raus geworfen und es sieht erst einmal besser aus. Werde es über Nacht einmal ansehen.
Wohlgemerkt habe ich nun Raspberry Pi3 mit Jessie und Perl 5.20.2, sowohl der Option Raspberry Pi3 mit Jessie und Perlbrew 5.20.3 und einen ganz neu aufgesetzten Raspberry PI3+ mit Stretch und Perl 5.24.1, wenn auch dieser verhält sich ohne freezemon wesentlich besser.

Die Frage ist halt, warum der Speicherverbrauch immer noch steigt und nicht wieder freigegeben wird, wenn man zwischen einem sehr vollen Raum "Everything" und einem anderen Raum wechselt. Irgendetwas mit dem WEB Modul?

Trotzdem bin ich noch etwas skeptisch, es muss noch etwas mehr dahinter stecken. Meine Probleme fingen an, als ich das Modul "HUEBridge" mit insgesamt 13 Lampen in Betrieb genommen habe, erst deswegen habe ich freezemon installiert.

Grüße Tim