Cannot fork: Cannot allocate memory | BlockingInformParent

[towag]

Ich habe das globale Attribut blockingCallMax auf 6 gesetzt.

Nachdem es scheinbar auch einen Zusammenhang zwischen den Perl Stacktrace Meldungen im Logfile und dem Speicherverbrauch gibt habe ich betroffene Module "sysmon" und "Spotify" disabled.
Jetzt habe ich "nur mehr" einen fast linearen Anstieg von 5% pro Stunde.

[rudolfkoenig]

Nachdem es scheinbar auch einen Zusammenhang zwischen den Perl Stacktrace Meldungen im Logfile und dem Speicherverbrauch gibt

An stacktrace selbst liegt das vermutlich nicht:

Code Auswählen Erweitern

define a at +*00:00:01 { stacktrace() } In 13 Minuten (780 at/stacktrace Aufrufe) ist FHEM laut ps kein Kilobyte gewachsen.
Habs mit perl 5.18 getestet.

[towag]

Ich habe 2 weitere Beobachtungen, die sich irgendwie auf das Speicherverhalten auswirken:

1) Für 3 Standorte ist das UWZ Modul in Einsatz. Bisher erfolgte die Abfrage jede Stunde. Ich habe das Intervall auf 4 Stunden hochgesetzt und die Memory Kurve ist um einiges flacher. (Sieht man auch in der Anlage)
Im Gegenzug steigt der Verbrauch aber nicht massiv an, wenn ich das Polling im Minutentakt durchführe. Also auch nicht schlüssig.
In beiden Fällen traten keine Fehlersituationen laut Logfile auf.

2) Heute trat ein Timeout bei der Abfrage von ProPlanta auf: Zur gleichen Zeit stieg der Memory Verbrauch:
2019.07.07 17:59:59 1: PROPLANTA wetter_Wien: HtmlAcquire.590 Error: Can't get https://www.proplanta.de/Wetter-Oesterreich/profi-wetter-at.php?SITEID=70&PLZ=Wien&STADT=Wien&WETTERaufrufen=stadt&Wtp=&SUCHE=Wetter&wT=0 -- 500 read timeout
2019.07.07 18:00:09 1: PROPLANTA wetter_Wien: HtmlAcquire.590 Error: Can't get https://www.proplanta.de/Wetter-Oesterreich/profi-wetter-at.php?SITEID=70&PLZ=Wien&STADT=Wien&WETTERaufrufen=stadt&Wtp=&SUCHE=Wetter&wT=4 -- 500 read timeout


Ich bin nicht der Perl-Programmierer, also lege ich meine Hände jetzt etwas ins Feuer:
Ich habe ein paar Perl-Module (im Zusammenspiel mit URL-Abfragen, ...) durch http://perlcritic.com/critique/file geschickt.

In httpUtils.pm
Bareword file handle opened at line 122, column 3. See pages 202,204 of PBP.
Using bareword symbols to refer to file handles is particularly evil because they are global, and you have no idea if that symbol already points to some other file handle.
Was passiert, wenn mehrere Abfragen zur gleichen Zeit laufen?

[rudolfkoenig]

Bareword file handle opened at line 122, column 3. See pages 202,204 of PBP.

Wird in den (eigentlch unueblichen) Fall verwendet, wenn HttpUtils_*Get mit "file://" aufgerufen wird.
Weiterhin ist FHEM single-threaded: es ist nicht moeglich, diesen Codestueck parallel aufzurufen.
Und drittens (wenn ich 59_PROPLANTA.pm richtig lese), wird hier nicht HttpUtils verwendet sondern (das blockierende) LWP::UserAgent

[Jens_B]

Hallo Zusammen,

ich weiß nicht ob es weiterhilft, ich habe meinen fhem Server auf buster geupdatet (also über dist upgrade). Auch wenn es nicht empfohlen wird.
Aber es hat funktioniert und die Perl Version ist jetzt 5.28.1.
Seit dem Update habe ich kein Memoryleck mehr und der Speicheverbrauch unter fhem steigt nicht mehr an.

Bisher konnte ich noch nicht feststellen das etwas nicht mehr funktioniert.

gruß
Jens

[MadMax-FHEM]

Hallo Zusammen,

ich weiß nicht ob es weiterhilft, ich habe meinen fhem Server auf buster geupdatet (also über dist upgrade). Auch wenn es nicht empfohlen wird.
Aber es hat funktioniert und die Perl Version ist jetzt 5.28.1.
Seit dem Update habe ich kein Memoryleck mehr und der Speicheverbrauch unter fhem steigt nicht mehr an.

Bisher konnte ich noch nicht feststellen das etwas nicht mehr funktioniert.

gruß
Jens

Tolle Info.

Werde ich auf meinem/n Testsystem/en mal testen...

Danke, Joachim

[Frank_Huber]

Mein neu installiertes Buster auf RPI4 zeigt einen kleinen konstanten Speicheranstieg.
Er läuft aber jetzt noch nicht lange.
Werde das erstmal paar Wochen so laufen lassen ohne Neustarts vom PI bzw FHEM.
Dann sieht man mehr.

[Jens_B]

Hallo Frank,
also der Anstieg unter Stretch ist bei Dir ja minimal . Das was bei Dir über den Monat passiert, war bei auf meinem fhem in 2 Tagen erreicht. Ich hatte ein script, was fhem automatisch neu gestartet hat, wenn ich Logfile der Fehler "cannot allocate memory" auftauchte.

Gruß
Jens

[HomeAuto_User]

Hallo,
nun melde ich mich auch mal zu Wort, da ich nun schon 3 Fach den Fehler sporadisch erhalten habe.

Code Auswählen Erweitern

Cannot fork: Cannot allocate memory

Meine ersten Vermutungen waren, das ganze liegt an der Speicherkarte vom RasPi3.
- Speicherkarte neu geschrieben und neuer Test

Irgendwann nach kurzer Zeit kam der Fehler erneut auf und ich nahm eine nagelneue Speicherkarte und setzte das System neu auf.
- Erkenntnis nach nicht mal 72h, Fehler

Code Auswählen Erweitern

Cannot fork: Cannot allocate memory welcher alles blockierte.

Mein System wo dies auftrat ist

PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster

Latest Revision: 19887

File                   Rev   Last Change

fhem.pl                19805 2019-07-09 09:44:07Z rudolfkoenig
96_allowed.pm          19046 2019-03-27 08:09:43Z rudolfkoenig
42_AptToDate.pm        19639 2019-06-18 13:43:31Z CoolTux
90_at.pm               17561 2018-10-18 14:45:30Z rudolfkoenig
98_autocreate.pm       19372 2019-05-11 15:13:59Z rudolfkoenig
88_Beispiel.pm         15699 2017-12-26 21:17:50Z HomeAuto_User
00_CUL.pm              17559 2018-10-18 07:45:07Z rudolfkoenig
09_CUL_FHTTK.pm        18391 2019-01-23 19:05:58Z Matscher
14_CUL_TCM97001.pm     19762 2019-07-02 19:21:52Z bjoernh
14_CUL_WS.pm           18128 2019-01-03 19:20:43Z rudolfkoenig
95_Dashboard.pm        16920 2018-06-29 12:01:56Z DS_Starter
98_dewpoint.pm         18846 2019-03-10 11:45:58Z hotbso
98_DOIF.pm             19786 2019-07-05 21:47:08Z Damian
98_dummy.pm            19585 2019-06-09 08:04:48Z rudolfkoenig
91_eventTypes.pm       14888 2017-08-13 12:07:12Z rudolfkoenig
72_FB_CALLLIST.pm      18181 2019-01-08 12:46:07Z markusbloch
72_FB_CALLMONITOR.pm   19517 2019-06-01 12:18:45Z markusbloch
01_FHEMWEB.pm          19878 2019-07-21 10:26:47Z rudolfkoenig
11_FHT.pm              18068 2018-12-27 17:08:46Z rudolfkoenig
92_FileLog.pm          19102 2019-04-02 19:48:57Z rudolfkoenig
# $Id: 14_FLAMINGO.pm 3818 2016-08-15 HomeAuto_User $
72_FRITZBOX.pm         17437 2018-09-30 18:24:58Z tupol
10_FS10.pm               331 2017-06-23 17:00:00Z v3.3-dev
10_FS20.pm             14888 2017-08-13 12:07:12Z rudolfkoenig
14_Hideki.pm           14395 2017-12-03 21:00:00Z v3.3.3-dev
98_HTTPMOD.pm          18644 2019-02-19 17:20:27Z StefanStrobel
10_IT.pm               19761 2019-07-02 18:37:03Z bjoernh
82_LGTV_IP12.pm        15140 2017-09-26 09:20:09Z markusbloch
00_MQTT.pm             18719 2019-02-24 20:20:51Z hexenmeister
10_MQTT_DEVICE.pm      17362 2018-09-17 12:57:29Z hexenmeister
91_notify.pm           19374 2019-05-11 17:48:03Z rudolfkoenig
41_OREGON.pm           34476 2017-12-26 13:23:00Z dev
73_PRESENCE.pm         18314 2019-01-18 13:49:05Z markusbloch
59_PROPLANTA.pm        18714 2019-02-24 16:08:46Z tupol
98_rain.pm              6916 2014-11-08 11:28:26Z baumrasen
33_readingsGroup.pm    19774 2019-07-04 14:10:53Z justme1968
95_remotecontrol.pm    10724 2016-02-04 18:17:33Z ulimaass
14_SD_BELL.pm          18657 2019-02-19 21:02:24Z HomeAuto_User
14_SD_Keeloq.pm           32 2019-02-23 12:00:00Z v3.4-dev_02.12.
14_SD_UT.pm            19886 2019-07-22 19:22:52Z HomeAuto_User
# $Id: 14_SD_WS.pm 18674 2019-05-05 12:00:00Z Sidey/elektron-bbs (dev-r34) $
14_SD_WS07.pm          18673 2019-07-10 20:52:45Z Sidey
00_SIGNALduino.pm      10488 2019-07-10 12:00:00Z v3.4.0
88_SIGNALduino_TOOL.pm 13115 2019-07-22 21:17:50Z HomeAuto_User
# $Id: 90_SIGNALduino_un.pm 15479 2018-01-24 20:00:00 dev-r34 $
98_statistics.pm       16438 2018-03-18 18:51:57Z tupol
99_SUNRISE_EL.pm       18732 2019-02-25 13:15:34Z rudolfkoenig
98_SVG.pm              19688 2019-06-23 07:17:03Z rudolfkoenig
42_SYSMON.pm           17227 2018-08-29 19:58:18Z hexenmeister
98_telnet.pm           17529 2018-10-14 12:57:06Z rudolfkoenig
No Id found for 98_unittest.pm
99_Utils.pm            18920 2019-03-16 09:58:52Z rudolfkoenig
77_UWZ.pm              19869 2019-07-20 13:59:38Z CoolTux
98_version.pm          15140 2017-09-26 09:20:09Z markusbloch
98_weblink.pm          16293 2018-02-28 21:33:57Z rudolfkoenig
88_xs1Bridge.pm        16681 2018-04-30 18:23:25Z HomeAuto_User
88_xs1Dev.pm           16598 2018-04-13 13:48:07Z HomeAuto_User
71_YAMAHA_AVR.pm       17547 2018-10-16 18:17:01Z markusbloch

AttrTemplate.pm        19085 2019-04-01 17:00:24Z rudolfkoenig
Blocking.pm            17553 2018-10-17 15:56:35Z rudolfkoenig
Color.pm               18481 2019-02-02 09:35:08Z justme1968
DevIo.pm               19372 2019-05-11 15:13:59Z rudolfkoenig
FritzBoxUtils.pm       16691 2018-05-05 17:11:26Z rudolfkoenig
GPUtils.pm             19666 2019-06-20 11:17:29Z CoolTux
HttpUtils.pm           19689 2019-06-23 07:28:05Z rudolfkoenig
Meta.pm                19650 2019-06-19 16:06:23Z loredo
RTypes.pm              10476 2016-01-12 21:03:33Z borisneubert
No Id found for SD_ProtocolData.pm
No Id found for SD_Protocols.pm
SetExtensions.pm       19208 2019-04-17 19:27:09Z rudolfkoenig
SubProcess.pm          14334 2017-05-20 23:11:06Z neubert
TcpServerUtils.pm      19138 2019-04-07 10:17:21Z rudolfkoenig

doif.js                    15546 2017-12-03 09:57:42Z Ellert
fhemweb.js                 19285 2019-04-28 20:18:39Z rudolfkoenig
fhemweb_readingsGroup.js   15189 2017-10-03 17:53:27Z justme1968
svg.js                     19667 2019-06-20 13:39:55Z rudolfkoenig

perl 5, version 28, subversion 1 (v5.28.1)

Nun habe ich das PRESENCE Modul sofort auf deaktiv gesetzt weil es mit einer Nachricht begann wie

PRESENCE (WLAN_Tablet) - error while processing check: Could not execute ping command: "ping -c 4 ASUS-T100HA"

Gibt es mitlerweile eine Möglichkeit, gezielt an die Fehlersuche des Problems heranzutreten anstall nur zu "schauen" nach verdächtigen Kanidaten?

MfG

[Wzut]

Ich habe einen Speicherfresser finden können : die FHEM interne Funktion backup
Im angehängten oberen Screenshot sieht man wie jeden Tag der freie Speicher einen größeren Schritt nach unten macht.
Die untere Grafik ist ein Zoom und dort sieht man das die Stufe täglich um 4:00 Uhr ist und genau um die Zeit lief das backup via at. -> {fhem("backup");}
Ich habe jetzt von backup auf rsync via cronjob umgestellt und zumindest die Treppen sind jetzt verschwunden.

[rudolfkoenig]

Ich habe gerade backup ein paarmal mit einer leeren Konfiguration gestartet: beim ersten mal ist RSS laut "ps -elf" von 22820 auf 34376 gestiegen, aber nach wiederholten weiteren backups nicht mehr. Entweder schaue ich auf die falschen Zahlen, habe die falsche OS/Perl Kombination oder ist backup nicht der wahre Grund.

[Skusi]

Wie schon geschrieben:
Bei mir ist es definitiv das echodevice Modul.

Ohne Echo´s alles bestens !

[Wzut]

Entweder schaue ich auf die falschen Zahlen

Nunja zumindes auf "andere" als ich
meine Grafik oben basiert auf der Ausgabe von

Code Auswählen Erweitern

cat /proc/meminfo |grep -e "MemFree" |awk '{WERT=$2/1024;printf ( "%.0f", WERT )}'
Das interen Backup macht im Grunde ja auch nur ein einfaches tar . Ich habe mir dann die komplette tar Zeile aus dem log kopiert und mehrmals direkt auf der Konsole ausgeführt. Nach jedem Lauf ist meine MemFree Ausgabe dann wieder ein Stück kleiner geworden.

[rudolfkoenig]

MemFree: The amount of physical RAM, in kilobytes, left unused by the system.

Backup erstellt eine Datei, das landet (auch) im Filesystem-/Block-Cache, und damit sinkt MemFree.
MemFree gibt den RAM an, den man entsorgen kann, ohne dass man ein Performance-Unterschied merkt, und taugt leider nicht zum Lokalisieren eines Speicherlochs.

[HomeAuto_User]

Aktuell nervt es bei mir.
Ich habe nun aus der Ferne mal geschaut und ich tippe und bin mir sicher, das es vermutlich ein Prozess / Modul in FHEM ist bzw. etwas was FHEM ,,aufschaukelt".

Das System nimmt auf einmal 70% vom Mem. Ich fügte mal die Prozessliste mit bei.

Def. ausgeschlossen Presence Modul.

(https://uploads.tapatalk-cdn.com/20190725/b245a9bb28129a18a4af6b5756d35db5.jpg)


Gesendet von iPhone mit Tapatalk Pro