NEWS
Load average am Anschlag -> Neustart
-
Und das Memory.log noch
Such ich dir!
Ansonsten hier der Vorrat

Und der chart dazu

Edit
memory.logDa ist hoffentlich was dabei, die load war die ganze Zeit hoch und kommt jetzt erst wieder zur Ruhe

Muss jetzt weg!
-
Und das Memory.log noch
Such ich dir!
Ansonsten hier der Vorrat

Und der chart dazu

Edit
memory.logDa ist hoffentlich was dabei, die load war die ganze Zeit hoch und kommt jetzt erst wieder zur Ruhe

Muss jetzt weg!
hier das ergebnis der analyse
Ja. Die Logs zeigen inzwischen ziemlich eindeutig, in welche Richtung wir suchen müssen.
Der entscheidende Fund ist nicht
CachedoderSlab, sondern die explosionsartige Zunahme der Anzahl von Tasks/Threads. Beim Ereignis um 09:45:01 fälltMemFreevon etwa 2,5 GB auf 253 MB. Gleichzeitig liegtMemAvailablenur noch bei ca. 515 MB. Das ist also tatsächlich belegter bzw. kurzfristig nicht verfügbarer Speicher und nicht bloß Filesystem-Cache.Noch deutlicher wird es in
/proc/meminfo:AnonPagesliegt während des Peaks bei rund 6,0 GB,PageTablesbei enormen ~685 MB undKernelStackbei ~39 MB. Cache und Slab sind dagegen relativ klein.Der eigentliche Fingerzeig steht aber im
loadavg:09:08 1/706 09:45 150/2317 09:49 8/958 10:02 44/1461 10:34 32/2899 10:43 32/2553Normalerweise hat dein System also ungefähr 700 Tasks. Während der heftigen Ereignisse sind es plötzlich 2.300–2.900 Tasks/Threads.
Das passt hervorragend zu den anderen Werten:
Wert normal extremer Peak Tasks ~700 2.300–2.900 MemFree ~3 GB 200–300 MB AnonPages ~3,2–3,8 GB ~6 GB PageTables ~340 MB ~700 MB KernelStack ~11 MB ~40 MB Beim späteren Ereignis um 10:43 sieht man beispielsweise unmittelbar
AnonPagesvon rund 3,2 GB auf 6,06 GB,PageTablesvon rund 344 MB auf 710 MB,KernelStackvon rund 11 MB auf 40 MB und gleichzeitig 2.553 Tasks.Damit ist die Ursache schon erheblich eingegrenzt
Es sieht sehr stark nach einem Process-/Thread-Storm aus.
Irgendein Prozess erzeugt kurzfristig ungefähr 1.500–2.200 zusätzliche Tasks. Das können echte Prozesse oder Threads sein. Dabei entstehen zusätzlich:
- anonymer Prozessspeicher,
- Page Tables,
- Kernel Stacks,
- weitere Kernel-Strukturen.
Und wenige Sekunden später verschwinden die Tasks wieder.
Das erklärt auch perfekt, warum wir in den bisherigen
ps-Snapshots keinen 2-GB-Prozess sehen.Unser bisheriges Script hat genau an dieser Stelle einen Fehler
In
log_detailed_snapshot()machen wir momentan:cat /proc/meminfo free -h vmstat 1 5 ps ...vmstat 1 5wartet ungefähr fünf Sekunden.Bei 09:45 passiert deshalb Folgendes: Beim Start des Snapshots sind noch ungefähr 2.300 Tasks vorhanden. Während
vmstatläuft, normalisiert sich der Speicher bereits wieder. Die erste vmstat-Messung sieht noch die Situation, danach steigtfreesofort wieder massiv an.Erst danach wird
psausgeführt.Dann sind die Tausenden kurzlebigen Prozesse/Threads bereits wieder verschwunden und wir sehen nur die normalen ioBroker-Prozesse. Der Controller selbst hat beispielsweise nur rund 448 MB RSS,
javascript.1rund 278 MB. Keiner davon erklärt den Peak.Das müssen wir ändern.
Ich würde
memwatch.shjetzt gezielt erweiternGanz am Anfang von
log_detailed_snapshot()sollten sofort Prozess- und Threadinformationen geschrieben werden, noch bevorfree,vmstat,slabtopusw. ausgeführt werden.Insbesondere diese Befehle:
echo "===== IMMEDIATE PROCESS SNAPSHOT =====" echo "--- process count ---" ps -e --no-headers | wc -l echo "--- task/thread count ---" ps -eLf --no-headers | wc -l echo echo "--- processes with most threads ---" ps -eo pid,ppid,user,nlwp,rss,vsz,stat,comm,args \ --sort=-nlwp | head -80 echo echo "--- processes by RSS ---" ps -eo pid,ppid,user,nlwp,rss,vsz,stat,comm,args \ --sort=-rss | head -80 echo echo "--- process count grouped by parent PID ---" ps -eo ppid= | sort -n | uniq -c | sort -nr | head -50 echo echo "--- process count grouped by command ---" ps -eo comm= | sort | uniq -c | sort -nr | head -50 echo echo "--- full process tree ---" ps -eo pid,ppid,user,nlwp,rss,vsz,stat,comm,args --forestBesonders interessant wird:
ps -eo pid,ppid,user,nlwp,rss,vsz,stat,comm,args --sort=-nlwpAngenommen, wir sehen beim nächsten Peak:
PID PPID NLWP COMMAND 40099 39859 1650 io.javascript.1dann hätten wir den Schuldigen praktisch direkt.
Oder:
PID PPID 123001 40099 123002 40099 123003 40099 ...Dann erzeugt PID
40099hunderte oder tausende Child-Prozesse.Oder beispielsweise:
1800 nodein der Gruppierung nach
comm, dann wissen wir ebenfalls sofort, was los ist.Auch die alten OOM-Ereignisse passen ins Bild
In
dmesggibt es sogar bereits zwei echte Out-of-Memory-Ereignisse vom Vorabend bzw. kurz nach Mitternacht. Dabei hat der Kernel jeweilsiobroker.js-controllerabgeschossen.Das heißt allerdings nicht, dass der Controller die Ursache war. Der OOM-Killer musste schlicht einen Prozess auswählen. Auffällig ist vielmehr, dass das System offenbar schon vorher durch dasselbe oder ein ähnliches Ereignis tatsächlich bis zum OOM getrieben wurde.
Meine derzeitige Einschätzung
Ich würde die Wahrscheinlichkeit momentan ungefähr so einordnen:
Sehr wahrscheinlich: Ein Prozess erzeugt für wenige Sekunden eine sehr große Anzahl von Prozessen oder Threads.
Wahrscheinlich: Der Ursprung liegt im ioBroker-/Node.js-Umfeld, einfach weil dort sehr viele Prozesse laufen und insbesondere JavaScript-Skripte externe Programme oder Child-Prozesse erzeugen können. Bewiesen ist das aber noch nicht.
Sehr unwahrscheinlich: Filesystem/Page Cache, Slab Leak oder tmpfs. Dafür passen die Messwerte überhaupt nicht.
Ebenfalls unwahrscheinlich: Ein klassischer Memory Leak eines einzelnen ioBroker-Adapters. Dafür ist das Verhalten viel zu abrupt und der Speicher wird unmittelbar wieder frei.
Das Auffälligste ist wirklich diese Kombination:
700 → 2.900 Tasks, AnonPages +~3 GB, PageTables +~350 MB, KernelStack +~30 MB und wenige Sekunden später alles wieder weg.
Das ist fast ein Fingerabdruck eines massiven kurzfristigen Prozess-/Thread-Spawns.
Ich würde daher als nächsten Schritt nicht mehr primär RAM messen, sondern das vorhandene
memwatch.shso umbauen, dass es den Verursacher innerhalb dieser 2–5 Sekunden erwischt. Ich kann dir dafür direkt die komplett überarbeitete Version des Scripts erstellen; dabei würde ich zusätzlich PPID-Gruppierung und Thread-Zahlen einbauen, sodass wir beim nächsten 2–3-GB-Einbruch sehr wahrscheinlich genau sehen, welcher ioBroker-Adapter oder welcher andere Prozess die Tausenden Tasks erzeugt. -
Und das Memory.log noch
Such ich dir!
Ansonsten hier der Vorrat

Und der chart dazu

Edit
memory.logDa ist hoffentlich was dabei, die load war die ganze Zeit hoch und kommt jetzt erst wieder zur Ruhe

Muss jetzt weg!
und hier das neue script
Ja. Ich würde das bisherige Script ersetzen und neben dem RAM-Einbruch jetzt insbesondere Prozess-/Thread-Stürme erfassen. Wichtig ist, dass
psund die Thread-Informationen sofort nach dem Trigger geschrieben werden – noch vorvmstat,slabtopusw.Du kannst den folgenden Block komplett per Copy & Paste ausführen:
sudo tee /usr/local/sbin/memwatch.sh > /dev/null <<'EOF' #!/usr/bin/env bash ############################################################################### # memwatch.sh # # Überwacht: # - MemFree / MemAvailable # - AnonPages # - PageTables # - KernelStack # - Anzahl Prozesse # - Anzahl Tasks/Threads # # Bei einem auffälligen Ereignis wird sofort ein detaillierter Snapshot # erzeugt, insbesondere um kurzlebige Prozess-/Thread-Stürme zu erfassen. ############################################################################### LOGDIR="/var/log/memwatch" # Messintervall in Sekunden INTERVAL=5 # Trigger: Verlust von MemFree zwischen zwei Messungen DROP_THRESHOLD_KB=$((256 * 1024)) # 256 MB # Trigger: Verlust von MemAvailable zwischen zwei Messungen AVAILABLE_DROP_THRESHOLD_KB=$((256 * 1024)) # 256 MB # Trigger: Anzahl zusätzlicher Tasks/Threads zwischen zwei Messungen TASK_JUMP_THRESHOLD=200 # Trigger: absolute Task-Anzahl TASK_ABSOLUTE_THRESHOLD=1200 # Trigger: kritisch niedriger verfügbarer Speicher AVAILABLE_LOW_KB=$((768 * 1024)) # 768 MB # Nach einem Snapshot für diese Zeit keinen neuen Snapshot erzeugen. # Verhindert mehrere Snapshots desselben Ereignisses. COOLDOWN_SECONDS=15 # Logs nach X Tagen löschen KEEP_DAYS=14 ############################################################################### # Initialisierung ############################################################################### mkdir -p "$LOGDIR" MAINLOG="$LOGDIR/memory.log" LAST_SNAPSHOT_TIME=0 ############################################################################### # Hilfsfunktionen ############################################################################### get_meminfo_value() { awk -v key="$1" '$1 == key ":" {print $2}' /proc/meminfo } get_memfree() { get_meminfo_value "MemFree" } get_memavailable() { get_meminfo_value "MemAvailable" } get_anonpages() { get_meminfo_value "AnonPages" } get_pagetables() { get_meminfo_value "PageTables" } get_kernelstack() { get_meminfo_value "KernelStack" } get_process_count() { ps -e --no-headers 2>/dev/null | wc -l } get_task_count() { # /proc/loadavg enthält als vorletztes Feld: # # laufende_Tasks/gesamte_Tasks # # Beispiel: # 0.12 0.20 0.30 1/702 12345 # # -> 702 Tasks # awk '{split($4,a,"/"); print a[2]}' /proc/loadavg } cleanup_old_logs() { find "$LOGDIR" -type f -mtime +"$KEEP_DAYS" -delete 2>/dev/null } ############################################################################### # Normales Logging ############################################################################### log_basic_snapshot() { { echo "===== $(date '+%F %T') =====" grep -E \ '^(MemTotal|MemFree|MemAvailable|Buffers|Cached|SwapCached|Active|Inactive|AnonPages|Mapped|Shmem|Slab|SReclaimable|SUnreclaim|KernelStack|PageTables|Dirty|Writeback|SwapTotal|SwapFree|Committed_AS):' \ /proc/meminfo echo "--- processes/tasks ---" echo "Processes: $(get_process_count)" echo "Tasks: $(get_task_count)" echo "--- load ---" cat /proc/loadavg echo } >> "$MAINLOG" } ############################################################################### # Detaillierter Snapshot ############################################################################### log_detailed_snapshot() { REASON="$1" TS="$(date '+%Y%m%d_%H%M%S')" SNAP="$LOGDIR/snapshot_$TS.log" ########################################################################### # WICHTIG: # # Die folgenden Informationen werden SOFORT erfasst. # # Keine langsamen Kommandos wie vmstat oder slabtop davor setzen! ########################################################################### { echo "############################################################" echo "MEMORY / PROCESS EVENT SNAPSHOT" echo "Time: $(date '+%F %T')" echo "Reason: $REASON" echo "############################################################" echo ####################################################################### # Sofortiger Systemzustand ####################################################################### echo "===== IMMEDIATE SYSTEM STATE =====" echo "Processes: $(get_process_count)" echo "Tasks: $(get_task_count)" echo cat /proc/loadavg echo ####################################################################### # meminfo SOFORT ####################################################################### echo "===== IMMEDIATE /proc/meminfo =====" cat /proc/meminfo echo ####################################################################### # Prozesse mit den meisten Threads ####################################################################### echo "===== PROCESSES WITH MOST THREADS =====" ps -eo \ pid,ppid,user,nlwp,%mem,rss,vsz,stat,lstart,comm,args \ --sort=-nlwp \ 2>/dev/null | head -100 echo ####################################################################### # Prozesse mit höchstem RSS ####################################################################### echo "===== TOP PROCESSES BY RSS =====" ps -eo \ pid,ppid,user,nlwp,%mem,rss,vsz,stat,lstart,comm,args \ --sort=-rss \ 2>/dev/null | head -100 echo ####################################################################### # Prozesse mit höchstem VSZ ####################################################################### echo "===== TOP PROCESSES BY VSZ =====" ps -eo \ pid,ppid,user,nlwp,%mem,rss,vsz,stat,lstart,comm,args \ --sort=-vsz \ 2>/dev/null | head -100 echo ####################################################################### # Anzahl Prozesse pro Parent PID # # Wenn z.B. ein Prozess 1500 Child-Prozesse erzeugt, sieht man hier # sofort die PPID. ####################################################################### echo "===== PROCESS COUNT GROUPED BY PPID =====" ps -eo ppid= 2>/dev/null | sort -n | uniq -c | sort -nr | head -100 echo ####################################################################### # Parent PID inklusive Namen ermitteln ####################################################################### echo "===== TOP PARENTS WITH PROCESS INFORMATION =====" ps -eo ppid= 2>/dev/null | sort -n | uniq -c | sort -nr | head -50 | while read -r COUNT PPID; do if [[ "$PPID" =~ ^[0-9]+$ ]] && [ "$PPID" -gt 0 ]; then INFO="$(ps -p "$PPID" -o pid=,ppid=,user=,nlwp=,rss=,vsz=,stat=,comm=,args= 2>/dev/null)" printf "%6s children | %s\n" "$COUNT" "$INFO" fi done echo ####################################################################### # Anzahl Prozesse gruppiert nach Programm ####################################################################### echo "===== PROCESS COUNT GROUPED BY COMMAND =====" ps -eo comm= 2>/dev/null | sort | uniq -c | sort -nr | head -100 echo ####################################################################### # Anzahl Threads gruppiert nach Prozess ####################################################################### echo "===== THREAD COUNT GROUPED BY PROCESS =====" ps -eo pid=,ppid=,nlwp=,comm=,args= \ --sort=-nlwp \ 2>/dev/null | head -100 echo ####################################################################### # Vollständige Thread-Liste # # Wichtig bei einem Thread-Storm. ####################################################################### echo "===== FULL THREAD LIST =====" ps -eLf \ -o pid,ppid,lwp,nlwp,user,psr,stat,rss,vsz,comm,args \ 2>/dev/null | head -5000 echo ####################################################################### # Prozessbaum ####################################################################### echo "===== PROCESS TREE =====" ps -eo \ pid,ppid,user,nlwp,rss,vsz,stat,comm,args \ --forest \ 2>/dev/null | head -5000 echo ####################################################################### # /proc Status der Prozesse mit den meisten Threads ####################################################################### echo "===== /proc STATUS OF TOP THREAD PROCESSES =====" ps -eo pid=,nlwp= \ --sort=-nlwp \ 2>/dev/null | head -20 | while read -r PID NLWP; do if [ -r "/proc/$PID/status" ]; then echo echo "------------------------------------------------------------" echo "PID: $PID" echo "NLWP: $NLWP" echo "------------------------------------------------------------" grep -E \ '^(Name|Pid|PPid|Threads|VmPeak|VmSize|VmRSS|RssAnon|RssFile|RssShmem|VmData|VmStk|VmExe|VmLib|VmPTE|VmSwap|voluntary_ctxt_switches|nonvoluntary_ctxt_switches):' \ "/proc/$PID/status" 2>/dev/null fi done echo ####################################################################### # free ####################################################################### echo "===== free -h =====" free -h echo ####################################################################### # Jetzt erst langsamere Messungen ####################################################################### echo "===== vmstat =====" vmstat 1 5 echo ####################################################################### # Slab ####################################################################### echo "===== SLAB SUMMARY =====" if command -v slabtop >/dev/null 2>&1; then slabtop -o -s c 2>/dev/null | head -100 else head -200 /proc/slabinfo fi echo ####################################################################### # PSI ####################################################################### echo "===== PRESSURE STALL INFORMATION =====" for f in \ /proc/pressure/cpu \ /proc/pressure/io \ /proc/pressure/memory do if [ -f "$f" ]; then echo "--- $f ---" cat "$f" fi done echo ####################################################################### # Kernelmeldungen / OOM ####################################################################### echo "===== DMESG MEMORY / OOM =====" dmesg --ctime 2>/dev/null | grep -Ei \ 'memory|oom|out of memory|killed process|page allocation|fork|clone|resource temporarily unavailable|slab' | tail -300 echo ####################################################################### # Journal ####################################################################### if command -v journalctl >/dev/null 2>&1; then echo "===== JOURNAL LAST 5 MINUTES =====" journalctl \ --since "-5 min" \ --no-pager \ 2>/dev/null | tail -500 echo fi ####################################################################### # Filesystem ####################################################################### echo "===== FILESYSTEM =====" df -h echo echo "===== INODE USAGE =====" df -i echo ####################################################################### # System ####################################################################### echo "===== UPTIME =====" uptime echo echo "===== SNAPSHOT END =====" echo "Time: $(date '+%F %T')" } > "$SNAP" echo "$(date '+%F %T') EVENT snapshot written: $SNAP" >> "$MAINLOG" } ############################################################################### # Vorbereitung ############################################################################### cleanup_old_logs PREV_FREE="$(get_memfree)" PREV_AVAILABLE="$(get_memavailable)" PREV_TASKS="$(get_task_count)" ############################################################################### # Hauptschleife ############################################################################### while true; do CURRENT_FREE="$(get_memfree)" CURRENT_AVAILABLE="$(get_memavailable)" CURRENT_TASKS="$(get_task_count)" CURRENT_ANON="$(get_anonpages)" CURRENT_PAGETABLES="$(get_pagetables)" CURRENT_KERNELSTACK="$(get_kernelstack)" log_basic_snapshot ########################################################################### # Differenzen berechnen ########################################################################### DROP_FREE=0 DROP_AVAILABLE=0 TASK_JUMP=0 if [[ "$PREV_FREE" =~ ^[0-9]+$ ]] && [[ "$CURRENT_FREE" =~ ^[0-9]+$ ]]; then DROP_FREE=$((PREV_FREE - CURRENT_FREE)) fi if [[ "$PREV_AVAILABLE" =~ ^[0-9]+$ ]] && [[ "$CURRENT_AVAILABLE" =~ ^[0-9]+$ ]]; then DROP_AVAILABLE=$((PREV_AVAILABLE - CURRENT_AVAILABLE)) fi if [[ "$PREV_TASKS" =~ ^[0-9]+$ ]] && [[ "$CURRENT_TASKS" =~ ^[0-9]+$ ]]; then TASK_JUMP=$((CURRENT_TASKS - PREV_TASKS)) fi ########################################################################### # Trigger prüfen ########################################################################### TRIGGER=0 REASONS="" if (( DROP_FREE >= DROP_THRESHOLD_KB )); then TRIGGER=1 REASONS+="MemFree drop $((DROP_FREE / 1024)) MB; " fi if (( DROP_AVAILABLE >= AVAILABLE_DROP_THRESHOLD_KB )); then TRIGGER=1 REASONS+="MemAvailable drop $((DROP_AVAILABLE / 1024)) MB; " fi if (( TASK_JUMP >= TASK_JUMP_THRESHOLD )); then TRIGGER=1 REASONS+="Task jump +${TASK_JUMP}; " fi if (( CURRENT_TASKS >= TASK_ABSOLUTE_THRESHOLD )); then TRIGGER=1 REASONS+="Task count ${CURRENT_TASKS}; " fi if (( CURRENT_AVAILABLE <= AVAILABLE_LOW_KB )); then TRIGGER=1 REASONS+="MemAvailable low $((CURRENT_AVAILABLE / 1024)) MB; " fi ########################################################################### # Snapshot mit Cooldown ########################################################################### if (( TRIGGER == 1 )); then NOW="$(date +%s)" SINCE_LAST=$((NOW - LAST_SNAPSHOT_TIME)) if (( SINCE_LAST >= COOLDOWN_SECONDS )); then { echo "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!" echo "$(date '+%F %T') MEMORY / TASK EVENT DETECTED" echo echo "Reason: $REASONS" echo echo "Previous MemFree: $((PREV_FREE / 1024)) MB" echo "Current MemFree: $((CURRENT_FREE / 1024)) MB" echo "MemFree drop: $((DROP_FREE / 1024)) MB" echo echo "Previous MemAvailable: $((PREV_AVAILABLE / 1024)) MB" echo "Current MemAvailable: $((CURRENT_AVAILABLE / 1024)) MB" echo "MemAvailable drop: $((DROP_AVAILABLE / 1024)) MB" echo echo "Previous Tasks: $PREV_TASKS" echo "Current Tasks: $CURRENT_TASKS" echo "Task increase: $TASK_JUMP" echo echo "AnonPages: $((CURRENT_ANON / 1024)) MB" echo "PageTables: $((CURRENT_PAGETABLES / 1024)) MB" echo "KernelStack: $((CURRENT_KERNELSTACK / 1024)) MB" echo "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!" } >> "$MAINLOG" LAST_SNAPSHOT_TIME="$NOW" log_detailed_snapshot "$REASONS" fi fi ########################################################################### # Werte für nächste Messung übernehmen ########################################################################### PREV_FREE="$CURRENT_FREE" PREV_AVAILABLE="$CURRENT_AVAILABLE" PREV_TASKS="$CURRENT_TASKS" sleep "$INTERVAL" done EOF sudo chmod +x /usr/local/sbin/memwatch.shVorhandenen Dienst neu starten
Falls dein
memwatch.servicebereits wie bisher eingerichtet ist, reicht anschließend:sudo systemctl restart memwatch.serviceUnd prüfen:
systemctl status memwatch.serviceLive beobachten:
tail -f /var/log/memwatch/memory.logIch habe das Intervall bewusst von 10 auf 5 Sekunden reduziert. Bei deinen bisherigen Ereignissen entstehen die zusätzlichen Tasks offenbar sehr schnell und verschwinden teilweise schon nach wenigen Sekunden wieder. 10 Sekunden sind daher für diesen Fehler etwas grob.
Was das neue Script zusätzlich erkennt
Es löst jetzt nicht nur bei einem RAM-Einbruch aus, sondern auch bei einem ungewöhnlichen Anstieg der Task-Anzahl. Aktuell gelten diese Schwellen:
DROP_THRESHOLD_KB=$((256 * 1024)) AVAILABLE_DROP_THRESHOLD_KB=$((256 * 1024)) TASK_JUMP_THRESHOLD=200 TASK_ABSOLUTE_THRESHOLD=1200 AVAILABLE_LOW_KB=$((768 * 1024))Das passt ziemlich gut zu deinen bisherigen Daten, weil dein Normalzustand ungefähr bei 650–750 Tasks liegt, während wir bei den problematischen Ereignissen über 2.000 bis fast 3.000 Tasks gesehen haben. Das neue Script sollte deshalb schon anschlagen, bevor der RAM vollständig aufgefressen wurde.
Besonders wichtig sind im nächsten Snapshot dann die Abschnitte:
PROCESSES WITH MOST THREADS PROCESS COUNT GROUPED BY PPID TOP PARENTS WITH PROCESS INFORMATION PROCESS COUNT GROUPED BY COMMAND THREAD COUNT GROUPED BY PROCESS FULL THREAD LISTWenn beispielsweise ein einzelner Node/ioBroker-Prozess 1.500 Threads erzeugt, sollte
PROCESSES WITH MOST THREADSihn direkt zeigen. Wenn stattdessen ein Prozess 1.500 Child-Prozesse erzeugt, solltePROCESS COUNT GROUPED BY PPIDdie betreffende Parent-PID sofort auffällig machen.Ein zusätzlicher Vorteil: Das Script schreibt jetzt beim Trigger bereits in
memory.log:Previous Tasks: 704 Current Tasks: 2543 Task increase: 1839 AnonPages: 5921 MB PageTables: 693 MB KernelStack: 39 MBDamit können wir schon anhand von
memory.logsehen, ob sich unsere Hypothese bestätigt.Beim nächsten Ereignis würde ich mir am liebsten
memory.logund den dazugehörigen neuensnapshot_*.logansehen. Mit dieser Version sollten wir eine wesentlich bessere Chance haben, die konkrete PID beziehungsweise den ioBroker-Adapter oder das Script zu identifizieren. -
Und das Memory.log noch
Such ich dir!
Ansonsten hier der Vorrat

Und der chart dazu

Edit
memory.logDa ist hoffentlich was dabei, die load war die ganze Zeit hoch und kommt jetzt erst wieder zur Ruhe

Muss jetzt weg!
-
Ganz ganz lieben Dank!
Vieles passt zu dem was ich vermutet habe, aber mangels Wissens nicht so tief durchschaue.
Bin nur kurz zu Hause und muss sofort wieder los!
Wenn ich es richtig verstanden habe:
- script komplett ersetzen
- den Service neu starten
- logs löschen
...und warten?
Nach den execs sehe ich nachher.
Was ich definitiv weiss ist das exec für free -m alle 15 sekunden -
Ganz ganz lieben Dank!
Vieles passt zu dem was ich vermutet habe, aber mangels Wissens nicht so tief durchschaue.
Bin nur kurz zu Hause und muss sofort wieder los!
Wenn ich es richtig verstanden habe:
- script komplett ersetzen
- den Service neu starten
- logs löschen
...und warten?
Nach den execs sehe ich nachher.
Was ich definitiv weiss ist das exec für free -m alle 15 sekunden -
Ganz ganz lieben Dank!
Vieles passt zu dem was ich vermutet habe, aber mangels Wissens nicht so tief durchschaue.
Bin nur kurz zu Hause und muss sofort wieder los!
Wenn ich es richtig verstanden habe:
- script komplett ersetzen
- den Service neu starten
- logs löschen
...und warten?
Nach den execs sehe ich nachher.
Was ich definitiv weiss ist das exec für free -m alle 15 sekunden -
puh@BrokerRaspi:~ $ sudo systemctl restart memwatch.service puh@BrokerRaspi:~ $ systemctl status memwatch.service ● memwatch.service - Memory Drop Monitor Loaded: loaded (/etc/systemd/system/memwatch.service; enabled; preset: enabled) Active: activating (auto-restart) (Result: exit-code) since Mon 2026-08-31 14:01:07 CEST; 2s ago Invocation: 661e703cd9e5457f9f6bbe0df09f5248 Process: 222183 ExecStart=/usr/local/sbin/memwatch.sh (code=exited, status=203/EXEC) Main PID: 222183 (code=exited, status=203/EXEC) CPU: 6ms puh@BrokerRaspi:~ $ tail -f /var/log/memwatch/memory.log tail: cannot open '/var/log/memwatch/memory.log' for reading: No such file or directory tail: no files remaining -
Ja genau so vorgehen.
Achtung, im Vergleich zum letzten Skript, ist das einfach ein Copy und Paste Befehl.
Einfach kopieren und auf deiner Konsole einfügen und ausführen sofern du die Pfade nicht geändert hast -
vor dem start des neuen scripts
alle bisher erzeugten logdateien löschen, damit wir nicht mit alten daten durcheinander kommenhast du in einem deinen javascripts etwas was das uU viel den exec befehl auslösen könnte?
-
du musst schauen ob um so ein exec eine schleife liegt die entsprechend oft so ein exec ausführt
oder eine funktion mit einem trigger,die ein exec enthält, was entsprechend oft aufgerufen wird.
auch setInterval oder setTimeout sind gefährlich
auch runScript/startScript oder
schedule in einer schleife oder innerhalb eines triggersggfs mal vor jedes Exec oder andere Befehle eine log ausgabe setzen. Dann sieht man es im log wie oft so etwas ausgeführt wird.
ist nur eine idee. die analyse wird uns maximal auf den prozess bringen. wenn das ergebnis javascript adapter ist, muss man da drin dann einzeln suchen.
aber mal schauen, evtl ist es auch ein anderer prozess -
du musst schauen ob um so ein exec eine schleife liegt die entsprechend oft so ein exec ausführt
oder eine funktion mit einem trigger,die ein exec enthält, was entsprechend oft aufgerufen wird.
auch setInterval oder setTimeout sind gefährlich
auch runScript/startScript oder
schedule in einer schleife oder innerhalb eines triggersggfs mal vor jedes Exec oder andere Befehle eine log ausgabe setzen. Dann sieht man es im log wie oft so etwas ausgeführt wird.
ist nur eine idee. die analyse wird uns maximal auf den prozess bringen. wenn das ergebnis javascript adapter ist, muss man da drin dann einzeln suchen.
aber mal schauen, evtl ist es auch ein anderer prozessso ein exec eine schleife liegt die entsprechend oft so ein exec
Nein, niemals!
Einfaches aufrufen, auswerten, schreibendie analyse wird uns maximal auf den prozess bringen
Falls das js ist muss ich weitersuchen.

Das neue Skript läuft leider erst nach dem großen drop und hat bisher drei drops gefunden
snapshot_20260831_140543.log snapshot_20260831_142136.log snapshot_20260831_141701.logWobei in meinen Augen der um 14:21 i terssant sein könnte weil da die Load höher ging (erwa 3)
Hier das log von 14:24 -
Hiho,
ich kenn mich mal garnicht mit dem aus was ihr hier alles schreibt und macht, aber denoch verfolge ich es (wer weis für was es gut ist). Ich hab zum Spaß mal das Script dem kostenlosen Claude hingeworfen und der findet es super und auch die Auswertung und Analyse von @oliverio ist korekt.
Er hat hur einen Verbesserungsvorschlag =Ein zusätzlicher Punkt, den man noch ergänzen könnte, falls der andere User es nicht schon vorhat: Da das Intervall des Hauptloops bei 5 Sekunden liegt und der Peak selbst nur wenige Sekunden dauert, könnte es sinnvoll sein, während eines erkannten Triggers kurzzeitig das Polling-Intervall zu verkürzen (z.B. auf 0,5–1 Sekunde für die nächsten 10 Sekunden), um die Chance zu erhöhen, den Prozess-Storm überhaupt im richtigen Moment zu erwischen – aktuell hängt der Erfolg stark davon ab, dass der 5-Sekunden-Tick zufällig mitten in den Peak fällt.dachte nur dass euch das vielleicht hilft ;)
-
Hiho,
ich kenn mich mal garnicht mit dem aus was ihr hier alles schreibt und macht, aber denoch verfolge ich es (wer weis für was es gut ist). Ich hab zum Spaß mal das Script dem kostenlosen Claude hingeworfen und der findet es super und auch die Auswertung und Analyse von @oliverio ist korekt.
Er hat hur einen Verbesserungsvorschlag =Ein zusätzlicher Punkt, den man noch ergänzen könnte, falls der andere User es nicht schon vorhat: Da das Intervall des Hauptloops bei 5 Sekunden liegt und der Peak selbst nur wenige Sekunden dauert, könnte es sinnvoll sein, während eines erkannten Triggers kurzzeitig das Polling-Intervall zu verkürzen (z.B. auf 0,5–1 Sekunde für die nächsten 10 Sekunden), um die Chance zu erhöhen, den Prozess-Storm überhaupt im richtigen Moment zu erwischen – aktuell hängt der Erfolg stark davon ab, dass der 5-Sekunden-Tick zufällig mitten in den Peak fällt.dachte nur dass euch das vielleicht hilft ;)
@Michael-Schmitt klingt sinnvoll.
Aber ich weiss ja auch nicht was hier abgeht
Wollte gerade los ne nvme und eine icybox zu holen um den anderen pi mit wasauchimmer als OS zu füttern und sehen ob es auch dann die selben Probleme gibt.
Hab es auf morgen verschoben -
Hiho,
ich kenn mich mal garnicht mit dem aus was ihr hier alles schreibt und macht, aber denoch verfolge ich es (wer weis für was es gut ist). Ich hab zum Spaß mal das Script dem kostenlosen Claude hingeworfen und der findet es super und auch die Auswertung und Analyse von @oliverio ist korekt.
Er hat hur einen Verbesserungsvorschlag =Ein zusätzlicher Punkt, den man noch ergänzen könnte, falls der andere User es nicht schon vorhat: Da das Intervall des Hauptloops bei 5 Sekunden liegt und der Peak selbst nur wenige Sekunden dauert, könnte es sinnvoll sein, während eines erkannten Triggers kurzzeitig das Polling-Intervall zu verkürzen (z.B. auf 0,5–1 Sekunde für die nächsten 10 Sekunden), um die Chance zu erhöhen, den Prozess-Storm überhaupt im richtigen Moment zu erwischen – aktuell hängt der Erfolg stark davon ab, dass der 5-Sekunden-Tick zufällig mitten in den Peak fällt.dachte nur dass euch das vielleicht hilft ;)
@Michael-Schmitt
sehr schön wenn sich die KIs gegenseitig loben :) -
@Michael-Schmitt klingt sinnvoll.
Aber ich weiss ja auch nicht was hier abgeht
Wollte gerade los ne nvme und eine icybox zu holen um den anderen pi mit wasauchimmer als OS zu füttern und sehen ob es auch dann die selben Probleme gibt.
Hab es auf morgen verschobenhier die neue analyse. leider mit noch nicht ganz so eindeutigen hinweisen.
auch leben diese tasks zu kurz als das der 5 sekunden rythmus ausgereicht hätte. das Ereignis um 14:21 war auch nicht stark genug.
Analyse der memwatch-Logs vom 31.08.2026
Kurzfazit
Die Dateien belegen einen kurzlebigen Task-/Thread-Sturm am 31.08.2026 um
14:21:36. Innerhalb eines Messintervalls von fünf Sekunden stieg die Taskzahl
von 679 auf 891, also um 212. Gleichzeitig gingen rund 400 MB verfügbarer
Speicher verloren.Der Sturm war beim Schreiben des detaillierten Snapshots bereits teilweise
vorbei: Dort wurden nur noch 736 Tasks gezählt. Deshalb ist der eigentliche
Verursacher in der normalen Prozessliste nicht mehr vollständig enthalten.Der auffälligste zeitliche Zusammenhang ist der ioBroker-Adapter
system.adapter.dwd.0: Sein Prozessio.dwd.0(PID 229073, Parent PID 39859)
wurde um 14:21:33 gestartet, nur drei Sekunden vor dem Peak. Im Snapshot
belegte er bereits 180.544 kB RSS. Damit istdwd.0der derzeit stärkste
Verdächtige, aber anhand dieser Dateien noch nicht zweifelsfrei als Erzeuger
aller 212 zusätzlichen Tasks bewiesen.Ausgewertete Dateien
1788179405632-1424memory.log1788179326889-snapshot_20260831_140543.log1788179326893-snapshot_20260831_141701.log1788179326891-snapshot_20260831_142136.log
Erkannte Ereignisse
Zeitpunkt MemFree-Abfall MemAvailable-Abfall Taskänderung Tasks am Trigger Besonderheit 14:05:43 392 MB 301 MB +3 652 Speicherimpuls ohne Task-Sturm 14:17:01 285 MB 285 MB +18 678 Speicherimpuls, kleiner Taskanstieg 14:21:36 389 MB 400 MB +212 891 klarer Task-/Thread-Sturm Alle drei Ereignisse waren kurzlebig. Bereits bei den jeweils nächsten
Messungen hatte sich ein wesentlicher Teil des Speicherverbrauchs wieder
zurückgebildet. Das spricht eher für kurz gestartete Prozesse/Threads oder eine
kurze, speicherintensive Adapteraktivität als für ein stetiges Speicherleck.Detailanalyse des Ereignisses um 14:21:36
Zwischen den beiden Messpunkten änderten sich die wichtigsten Werte ungefähr
wie folgt:- Tasks: 679 -> 891 (+212)
- MemAvailable: 3.546 MB -> 3.146 MB (-400 MB)
- MemFree: 2.908 MB -> 2.519 MB (-389 MB)
AnonPages: etwa 3.428 MB -> 3.807 MB (ca. +379 MB)PageTables: etwa 340 MB -> 376 MB (ca. +36 MB)KernelStack: etwa 10,6 MB -> 13,9 MB (ca. +3,2 MB)
Die Kombination aus deutlich steigenden
AnonPages,PageTables,
KernelStackund Tasks passt technisch zu sehr vielen kurzfristig angelegten
Ausführungskontexten. Sie passt weniger zu einem reinen Dateicache- oder
Slab-Problem.Der Snapshot zeigt unmittelbar danach:
- 242 Prozesse und 736 Tasks; gegenüber den 891 Tasks am Trigger waren also
bereits 155 Tasks wieder verschwunden. io.dwd.0, PID 229073, PPID 39859, gestartet um 14:21:33.io.dwd.0hatte 12 noch sichtbare Threads und 180.544 kB RSS.- Der ioBroker-Controller PID 39859 war der Parent der Adapterprozesse.
- Kein noch sichtbarer Prozess hatte im Snapshot eine ungewöhnlich hohe
Threadzahl; die ioBroker-/Node-Prozesse lagen überwiegend bei 11 oder 12.
Das bedeutet: Die zusätzlichen Tasks waren entweder sehr kurzlebig oder der
Peak wurde in einer Phase erfasst, die vor dem erstenps-Snapshot schon
endete. Die verbleibenden 12 Threads vondwd.0erklären den Peak allein
nicht. Der Startzeitpunkt und sein hoher anfänglicher RSS machen den Adapter
aber zum besten konkreten Ansatzpunkt.Die anderen beiden Ereignisse
14:05:43
Der Speicherverlust von 301 MB bei
MemAvailabletrat bei nur drei zusätzlichen
Tasks auf. Die Prozessliste zeigt keinen Thread-Sturm und keinen einzelnen neu
gestarteten Großverbraucher. Der Effekt bildete sich schnell zurück.14:17:01
Der Speicherverlust von 285 MB trat zusammen mit 18 zusätzlichen Tasks auf.
Auch hier zeigt der Snapshot keinen Prozess mit auffälliger Threadzahl. Um
14:17:01 lief zusätzlich/etc/cron.hourly; das ist zeitlich korreliert, aber
die vorliegenden Daten belegen keine ursächliche Verbindung.Weitere relevante Beobachtungen
- Swap war bereits mit etwa 1,1 GiB von 2,0 GiB belegt. Während der fünf
vmstat-Sekunden fand beim Ereignis aber kein aktuelles Ein- oder Ausswappen
statt (si/sojeweils 0 nach der Summenzeile). - Die CPU-Last stieg kurz an und fiel innerhalb weniger Sekunden wieder ab.
- Die Slab-Auswertung war unauffällig; insbesondere erklärt der Slab-Verbrauch
nicht den kurzfristigen Verlust von etwa 400 MB. - Es gab während dieser drei Snapshots keinen neuen OOM-Kill. Die in
dmesg
enthaltenen OOM-Einträge stammen von 23:58:02 und 00:24:01 und damit aus
früheren Ereignissen. Damals wurden ioBroker-Controller-Prozesse beendet. - Die SSH-Anmeldung des Benutzers
puhum 14:13 erzeugte nur wenige Prozesse
und erklärt den Peak um 14:21 nicht.
Fehler und Lücken im aktuellen Messskript
1. Parent-Auswertung bricht ab
Im Journal steht bei jedem Snapshot:
/usr/local/sbin/memwatch.sh: line 264: PPID: readonly variablePPIDist in Bash eine reservierte, schreibgeschützte Variable. Dadurch bleibt
der AbschnittTOP PARENTS WITH PROCESS INFORMATIONleer. In der Schleife muss
die Variable beispielsweisePARENT_PIDheißen:while read -r COUNT PARENT_PID; do if [[ "$PARENT_PID" =~ ^[0-9]+$ ]] && [ "$PARENT_PID" -gt 0 ]; then INFO="$(ps -p "$PARENT_PID" -o pid=,ppid=,user=,nlwp=,rss=,vsz=,stat=,comm=,args= 2>/dev/null)" printf "%6s children | %s\n" "$COUNT" "$INFO" fi done2.
FULL THREAD LISTist leerIn allen drei Snapshots folgt direkt nach der Überschrift
FULL THREAD LIST
bereitsPROCESS TREE. Das verwendeteps -eLf -o ...liefert auf diesem
System offenbar keine Daten (der Fehler wird durch2>/dev/nullverborgen).
Vor dem nächsten Lauf sollte der Befehl direkt auf dem Raspberry Pi getestet
werden. Eine robustere Variante ist beispielsweise:ps -eL -o pid,ppid,lwp,nlwp,user,psr,stat,rss,vsz,comm,args3. Snapshot-Erfassung dauert etwa fünf Sekunden
Zwischen Triggerzeit und
snapshot writtenliegen jeweils vier bis fünf
Sekunden. Schon vor dem ersten detaillierten Taskwert war beim stärksten
Ereignis ein großer Teil des Sturms vorbei. Für solche Peaks sollte beim Trigger
zuerst eine sehr schnelle Rohkopie von/procbeziehungsweise mindestens eine
sofortige Threadliste in eine separate Datei geschrieben werden. Erst danach
sollten Sortierungen und mehrfacheps-Aufrufe folgen.4. Taskzahl im Trigger und Snapshot unterscheiden sich
Das ist kein Rechenfehler:
memory.logmisst 891 Tasks am Trigger, während der
nachfolgende Snapshot 736 anzeigt. Diese Differenz ist gerade ein wichtiger
Hinweis auf die kurze Lebensdauer der zusätzlichen Tasks.Bewertung der wahrscheinlichsten Ursache
- Sehr wahrscheinlich: ein kurzlebiger Prozess-/Thread-Sturm verursacht
den starken Peak um 14:21:36. - Wahrscheinlichster konkreter Auslöser: Start oder Startaktivität von
system.adapter.dwd.0, daio.dwd.0drei Sekunden vor dem Peak neu gestartet
wurde und unmittelbar 180 MB RSS belegte. - Noch nicht bewiesen: Ob
dwd.0selbst alle zusätzlichen Tasks erzeugte,
ob ein von ihm ausgelöster Node-/Systemvorgang beteiligt war oder ob ein
zeitgleicher, bereits verschwundener Prozess verantwortlich war. - Unwahrscheinlich als alleinige Ursache: Slab, Dateicache, SSH-Sitzung oder
ein dauerhaft wachsender einzelner ioBroker-Prozess.
Empfohlene nächste Schritte
- Die Variable
PPIDim Skript inPARENT_PIDumbenennen. - Den Befehl für
FULL THREAD LISTkorrigieren und seine Fehler vorübergehend
nicht nach/dev/nullumleiten. - ioBroker-Logs für
system.adapter.dwd.0im Zeitraum 14:21:25 bis 14:21:45
sichern und prüfen, warum der Adapter um 14:21:33 gestartet wurde. - In den ioBroker-Objekten/Logs die Restart-Zahl und den Exit-Grund von
dwd.0prüfen. - Für den nächsten Peak eine minimale Soforterfassung vor allen aufwendigen
Befehlen ergänzen, etwaps -eL ...und eine Liste aller numerischen
/proc/<PID>/task/<TID>-Einträge. - Optional
dwd.0kontrolliert deaktivieren und beobachten, ob die Peaks
ausbleiben. Das wäre ein aussagekräftiger A/B-Test, sollte aber nur erfolgen,
wenn der vorübergehende Ausfall der DWD-Daten akzeptabel ist.
Gesamtergebnis
Das verbesserte Monitoring hat die bisherige Vermutung grundsätzlich bestätigt:
Mindestens eines der Speicherereignisse ist mit einem massiven, sehr kurzen
Taskanstieg gekoppelt. Der Snapshot kam noch knapp zu spät, um sämtliche Tasks
ihrem Prozess zuzuordnen.dwd.0ist aufgrund seines Startzeitpunkts der klare
Hauptverdächtige. Für einen belastbaren Beweis müssen die beiden fehlerhaften
Snapshot-Abschnitte repariert und die erste Threadliste noch früher geschrieben
werden. -
@Michael-Schmitt klingt sinnvoll.
Aber ich weiss ja auch nicht was hier abgeht
Wollte gerade los ne nvme und eine icybox zu holen um den anderen pi mit wasauchimmer als OS zu füttern und sehen ob es auch dann die selben Probleme gibt.
Hab es auf morgen verschobendaher hier ein neues verbessertes script.
einfach mit nano das bisherige script ersetzen.
das letzte skript hatte wohl probleme mit der ausführung eines bestimmten ps befehls#!/usr/bin/env bash # Monitors memory and task changes and writes a fast process/thread capture # before producing a more expensive diagnostic snapshot. set -u LOGDIR="/var/log/memwatch" INTERVAL=5 DROP_THRESHOLD_KB=$((256 * 1024)) AVAILABLE_DROP_THRESHOLD_KB=$((256 * 1024)) TASK_JUMP_THRESHOLD=200 TASK_ABSOLUTE_THRESHOLD=1200 AVAILABLE_LOW_KB=$((768 * 1024)) COOLDOWN_SECONDS=15 KEEP_DAYS=14 mkdir -p "$LOGDIR" MAINLOG="$LOGDIR/memory.log" LAST_SNAPSHOT_TIME=0 get_meminfo_value() { awk -v key="$1" '$1 == key ":" {print $2}' /proc/meminfo } get_memfree() { get_meminfo_value MemFree; } get_memavailable() { get_meminfo_value MemAvailable; } get_anonpages() { get_meminfo_value AnonPages; } get_pagetables() { get_meminfo_value PageTables; } get_kernelstack() { get_meminfo_value KernelStack; } get_process_count() { ps -e --no-headers 2>/dev/null | wc -l } get_task_count() { awk '{split($4,a,"/"); print a[2]}' /proc/loadavg } cleanup_old_logs() { find "$LOGDIR" -maxdepth 1 -type f -mtime +"$KEEP_DAYS" -delete 2>/dev/null } log_basic_snapshot() { { echo "===== $(date '+%F %T') =====" grep -E '^(MemTotal|MemFree|MemAvailable|Buffers|Cached|SwapCached|Active|Inactive|AnonPages|Mapped|Shmem|Slab|SReclaimable|SUnreclaim|KernelStack|PageTables|Dirty|Writeback|SwapTotal|SwapFree|Committed_AS):' /proc/meminfo echo "--- processes/tasks ---" echo "Processes: $(get_process_count)" echo "Tasks: $(get_task_count)" echo "--- load ---" cat /proc/loadavg echo } >> "$MAINLOG" } log_detailed_snapshot() { local reason="$1" local ts snap fast_threads fast_processes ts="$(date '+%Y%m%d_%H%M%S')" snap="$LOGDIR/snapshot_$ts.log" fast_threads="$LOGDIR/.fast_threads_$ts.tmp" fast_processes="$LOGDIR/.fast_processes_$ts.tmp" # Capture volatile data first. Do not put other commands before these. # Errors are retained so a broken ps format cannot silently create an # empty section again. ps -eL -o pid,ppid,lwp,nlwp,user,psr,stat,rss,vsz,comm,args \ > "$fast_threads" 2>&1 || true ps -eo pid,ppid,user,nlwp,%mem,rss,vsz,stat,lstart,comm,args \ > "$fast_processes" 2>&1 || true { echo "############################################################" echo "MEMORY / PROCESS EVENT SNAPSHOT" echo "Time: $(date '+%F %T')" echo "Reason: $reason" echo "############################################################" echo echo "===== FAST THREAD CAPTURE (FIRST ACTION) =====" cat "$fast_threads" echo echo "===== FAST PROCESS CAPTURE (SECOND ACTION) =====" cat "$fast_processes" echo echo "===== IMMEDIATE SYSTEM STATE =====" echo "Processes: $(get_process_count)" echo "Tasks: $(get_task_count)" cat /proc/loadavg echo echo "===== IMMEDIATE /proc/meminfo =====" cat /proc/meminfo echo echo "===== PROCESSES WITH MOST THREADS =====" ps -eo pid,ppid,user,nlwp,%mem,rss,vsz,stat,lstart,comm,args \ --sort=-nlwp 2>&1 | head -100 echo echo "===== TOP PROCESSES BY RSS =====" ps -eo pid,ppid,user,nlwp,%mem,rss,vsz,stat,lstart,comm,args \ --sort=-rss 2>&1 | head -100 echo echo "===== TOP PROCESSES BY VSZ =====" ps -eo pid,ppid,user,nlwp,%mem,rss,vsz,stat,lstart,comm,args \ --sort=-vsz 2>&1 | head -100 echo echo "===== PROCESS COUNT GROUPED BY PPID =====" ps -eo ppid= 2>/dev/null | sort -n | uniq -c | sort -nr | head -100 echo echo "===== TOP PARENTS WITH PROCESS INFORMATION =====" ps -eo ppid= 2>/dev/null | sort -n | uniq -c | sort -nr | head -50 | while read -r count parent_pid; do if [[ "$parent_pid" =~ ^[0-9]+$ ]] && (( parent_pid > 0 )); then parent_info="$(ps -p "$parent_pid" -o pid=,ppid=,user=,nlwp=,rss=,vsz=,stat=,comm=,args= 2>/dev/null)" printf "%6s children | %s\n" "$count" "$parent_info" fi done echo echo "===== PROCESS COUNT GROUPED BY COMMAND =====" ps -eo comm= 2>/dev/null | sort | uniq -c | sort -nr | head -100 echo echo "===== THREAD COUNT GROUPED BY PROCESS =====" ps -eo pid=,ppid=,nlwp=,comm=,args= --sort=-nlwp 2>&1 | head -100 echo echo "===== FULL THREAD LIST =====" # -eL is used instead of the previously failing -eLf/-o combination. ps -eL -o pid,ppid,lwp,nlwp,user,psr,stat,rss,vsz,comm,args 2>&1 | head -5000 echo echo "===== PROCESS TREE =====" ps -eo pid,ppid,user,nlwp,rss,vsz,stat,comm,args --forest 2>&1 | head -5000 echo echo "===== /proc STATUS OF TOP THREAD PROCESSES =====" ps -eo pid=,nlwp= --sort=-nlwp 2>/dev/null | head -20 | while read -r process_pid thread_count; do if [[ "$process_pid" =~ ^[0-9]+$ ]] && [[ -r "/proc/$process_pid/status" ]]; then echo echo "------------------------------------------------------------" echo "PID: $process_pid" echo "NLWP: $thread_count" echo "------------------------------------------------------------" grep -E '^(Name|Pid|PPid|Threads|VmPeak|VmSize|VmRSS|RssAnon|RssFile|RssShmem|VmData|VmStk|VmExe|VmLib|VmPTE|VmSwap|voluntary_ctxt_switches|nonvoluntary_ctxt_switches):' \ "/proc/$process_pid/status" 2>/dev/null fi done echo echo "===== free -h =====" free -h echo echo "===== vmstat =====" vmstat 1 5 echo echo "===== SLAB SUMMARY =====" if command -v slabtop >/dev/null 2>&1; then slabtop -o -s c 2>&1 | head -100 elif [[ -r /proc/slabinfo ]]; then head -200 /proc/slabinfo else echo "/proc/slabinfo is not readable" fi echo echo "===== PRESSURE STALL INFORMATION =====" for pressure_file in /proc/pressure/cpu /proc/pressure/io /proc/pressure/memory; do if [[ -r "$pressure_file" ]]; then echo "--- $pressure_file ---" cat "$pressure_file" fi done echo echo "===== DMESG MEMORY / OOM =====" dmesg --ctime 2>/dev/null | grep -Ei 'memory|oom|out of memory|killed process|page allocation|fork|clone|resource temporarily unavailable|slab' | tail -300 echo if command -v journalctl >/dev/null 2>&1; then echo "===== JOURNAL LAST 5 MINUTES =====" journalctl --since "-5 min" --no-pager 2>&1 | tail -500 echo fi echo "===== FILESYSTEM =====" df -h echo echo "===== INODE USAGE =====" df -i echo echo "===== UPTIME =====" uptime echo echo "===== SNAPSHOT END =====" echo "Time: $(date '+%F %T')" } > "$snap" rm -f -- "$fast_threads" "$fast_processes" echo "$(date '+%F %T') EVENT snapshot written: $snap" >> "$MAINLOG" } cleanup_old_logs PREV_FREE="$(get_memfree)" PREV_AVAILABLE="$(get_memavailable)" PREV_TASKS="$(get_task_count)" while true; do CURRENT_FREE="$(get_memfree)" CURRENT_AVAILABLE="$(get_memavailable)" CURRENT_TASKS="$(get_task_count)" CURRENT_ANON="$(get_anonpages)" CURRENT_PAGETABLES="$(get_pagetables)" CURRENT_KERNELSTACK="$(get_kernelstack)" log_basic_snapshot DROP_FREE=0 DROP_AVAILABLE=0 TASK_JUMP=0 if [[ "$PREV_FREE" =~ ^[0-9]+$ && "$CURRENT_FREE" =~ ^[0-9]+$ ]]; then DROP_FREE=$((PREV_FREE - CURRENT_FREE)) fi if [[ "$PREV_AVAILABLE" =~ ^[0-9]+$ && "$CURRENT_AVAILABLE" =~ ^[0-9]+$ ]]; then DROP_AVAILABLE=$((PREV_AVAILABLE - CURRENT_AVAILABLE)) fi if [[ "$PREV_TASKS" =~ ^[0-9]+$ && "$CURRENT_TASKS" =~ ^[0-9]+$ ]]; then TASK_JUMP=$((CURRENT_TASKS - PREV_TASKS)) fi TRIGGER=0 REASONS="" if (( DROP_FREE >= DROP_THRESHOLD_KB )); then TRIGGER=1 REASONS+="MemFree drop $((DROP_FREE / 1024)) MB; " fi if (( DROP_AVAILABLE >= AVAILABLE_DROP_THRESHOLD_KB )); then TRIGGER=1 REASONS+="MemAvailable drop $((DROP_AVAILABLE / 1024)) MB; " fi if (( TASK_JUMP >= TASK_JUMP_THRESHOLD )); then TRIGGER=1 REASONS+="Task jump +$TASK_JUMP; " fi if (( CURRENT_TASKS >= TASK_ABSOLUTE_THRESHOLD )); then TRIGGER=1 REASONS+="Task count $CURRENT_TASKS; " fi if (( CURRENT_AVAILABLE <= AVAILABLE_LOW_KB )); then TRIGGER=1 REASONS+="MemAvailable low $((CURRENT_AVAILABLE / 1024)) MB; " fi if (( TRIGGER == 1 )); then NOW="$(date +%s)" SINCE_LAST=$((NOW - LAST_SNAPSHOT_TIME)) if (( SINCE_LAST >= COOLDOWN_SECONDS )); then { echo "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!" echo "$(date '+%F %T') MEMORY / TASK EVENT DETECTED" echo echo "Reason: $REASONS" echo echo "Previous MemFree: $((PREV_FREE / 1024)) MB" echo "Current MemFree: $((CURRENT_FREE / 1024)) MB" echo "MemFree drop: $((DROP_FREE / 1024)) MB" echo echo "Previous MemAvailable: $((PREV_AVAILABLE / 1024)) MB" echo "Current MemAvailable: $((CURRENT_AVAILABLE / 1024)) MB" echo "MemAvailable drop: $((DROP_AVAILABLE / 1024)) MB" echo echo "Previous Tasks: $PREV_TASKS" echo "Current Tasks: $CURRENT_TASKS" echo "Task increase: $TASK_JUMP" echo echo "AnonPages: $((CURRENT_ANON / 1024)) MB" echo "PageTables: $((CURRENT_PAGETABLES / 1024)) MB" echo "KernelStack: $((CURRENT_KERNELSTACK / 1024)) MB" echo "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!" } >> "$MAINLOG" LAST_SNAPSHOT_TIME="$NOW" log_detailed_snapshot "$REASONS" fi fi PREV_FREE="$CURRENT_FREE" PREV_AVAILABLE="$CURRENT_AVAILABLE" PREV_TASKS="$CURRENT_TASKS" sleep "$INTERVAL" done -
@Michael-Schmitt klingt sinnvoll.
Aber ich weiss ja auch nicht was hier abgeht
Wollte gerade los ne nvme und eine icybox zu holen um den anderen pi mit wasauchimmer als OS zu füttern und sehen ob es auch dann die selben Probleme gibt.
Hab es auf morgen verschobenwieder die bisherigen logdateien löschen und dann
den service neu starten
sudo chmod +x /usr/local/sbin/memwatch.sh sudo systemctl restart memwatch.service systemctl status memwatch.serviceopenai ist wohl gerade überlastet. konnte die dateien über chatgpt nicht hochladen. musste zu codex cli lokal wechseln
-
hier die neue analyse. leider mit noch nicht ganz so eindeutigen hinweisen.
auch leben diese tasks zu kurz als das der 5 sekunden rythmus ausgereicht hätte. das Ereignis um 14:21 war auch nicht stark genug.
Analyse der memwatch-Logs vom 31.08.2026
Kurzfazit
Die Dateien belegen einen kurzlebigen Task-/Thread-Sturm am 31.08.2026 um
14:21:36. Innerhalb eines Messintervalls von fünf Sekunden stieg die Taskzahl
von 679 auf 891, also um 212. Gleichzeitig gingen rund 400 MB verfügbarer
Speicher verloren.Der Sturm war beim Schreiben des detaillierten Snapshots bereits teilweise
vorbei: Dort wurden nur noch 736 Tasks gezählt. Deshalb ist der eigentliche
Verursacher in der normalen Prozessliste nicht mehr vollständig enthalten.Der auffälligste zeitliche Zusammenhang ist der ioBroker-Adapter
system.adapter.dwd.0: Sein Prozessio.dwd.0(PID 229073, Parent PID 39859)
wurde um 14:21:33 gestartet, nur drei Sekunden vor dem Peak. Im Snapshot
belegte er bereits 180.544 kB RSS. Damit istdwd.0der derzeit stärkste
Verdächtige, aber anhand dieser Dateien noch nicht zweifelsfrei als Erzeuger
aller 212 zusätzlichen Tasks bewiesen.Ausgewertete Dateien
1788179405632-1424memory.log1788179326889-snapshot_20260831_140543.log1788179326893-snapshot_20260831_141701.log1788179326891-snapshot_20260831_142136.log
Erkannte Ereignisse
Zeitpunkt MemFree-Abfall MemAvailable-Abfall Taskänderung Tasks am Trigger Besonderheit 14:05:43 392 MB 301 MB +3 652 Speicherimpuls ohne Task-Sturm 14:17:01 285 MB 285 MB +18 678 Speicherimpuls, kleiner Taskanstieg 14:21:36 389 MB 400 MB +212 891 klarer Task-/Thread-Sturm Alle drei Ereignisse waren kurzlebig. Bereits bei den jeweils nächsten
Messungen hatte sich ein wesentlicher Teil des Speicherverbrauchs wieder
zurückgebildet. Das spricht eher für kurz gestartete Prozesse/Threads oder eine
kurze, speicherintensive Adapteraktivität als für ein stetiges Speicherleck.Detailanalyse des Ereignisses um 14:21:36
Zwischen den beiden Messpunkten änderten sich die wichtigsten Werte ungefähr
wie folgt:- Tasks: 679 -> 891 (+212)
- MemAvailable: 3.546 MB -> 3.146 MB (-400 MB)
- MemFree: 2.908 MB -> 2.519 MB (-389 MB)
AnonPages: etwa 3.428 MB -> 3.807 MB (ca. +379 MB)PageTables: etwa 340 MB -> 376 MB (ca. +36 MB)KernelStack: etwa 10,6 MB -> 13,9 MB (ca. +3,2 MB)
Die Kombination aus deutlich steigenden
AnonPages,PageTables,
KernelStackund Tasks passt technisch zu sehr vielen kurzfristig angelegten
Ausführungskontexten. Sie passt weniger zu einem reinen Dateicache- oder
Slab-Problem.Der Snapshot zeigt unmittelbar danach:
- 242 Prozesse und 736 Tasks; gegenüber den 891 Tasks am Trigger waren also
bereits 155 Tasks wieder verschwunden. io.dwd.0, PID 229073, PPID 39859, gestartet um 14:21:33.io.dwd.0hatte 12 noch sichtbare Threads und 180.544 kB RSS.- Der ioBroker-Controller PID 39859 war der Parent der Adapterprozesse.
- Kein noch sichtbarer Prozess hatte im Snapshot eine ungewöhnlich hohe
Threadzahl; die ioBroker-/Node-Prozesse lagen überwiegend bei 11 oder 12.
Das bedeutet: Die zusätzlichen Tasks waren entweder sehr kurzlebig oder der
Peak wurde in einer Phase erfasst, die vor dem erstenps-Snapshot schon
endete. Die verbleibenden 12 Threads vondwd.0erklären den Peak allein
nicht. Der Startzeitpunkt und sein hoher anfänglicher RSS machen den Adapter
aber zum besten konkreten Ansatzpunkt.Die anderen beiden Ereignisse
14:05:43
Der Speicherverlust von 301 MB bei
MemAvailabletrat bei nur drei zusätzlichen
Tasks auf. Die Prozessliste zeigt keinen Thread-Sturm und keinen einzelnen neu
gestarteten Großverbraucher. Der Effekt bildete sich schnell zurück.14:17:01
Der Speicherverlust von 285 MB trat zusammen mit 18 zusätzlichen Tasks auf.
Auch hier zeigt der Snapshot keinen Prozess mit auffälliger Threadzahl. Um
14:17:01 lief zusätzlich/etc/cron.hourly; das ist zeitlich korreliert, aber
die vorliegenden Daten belegen keine ursächliche Verbindung.Weitere relevante Beobachtungen
- Swap war bereits mit etwa 1,1 GiB von 2,0 GiB belegt. Während der fünf
vmstat-Sekunden fand beim Ereignis aber kein aktuelles Ein- oder Ausswappen
statt (si/sojeweils 0 nach der Summenzeile). - Die CPU-Last stieg kurz an und fiel innerhalb weniger Sekunden wieder ab.
- Die Slab-Auswertung war unauffällig; insbesondere erklärt der Slab-Verbrauch
nicht den kurzfristigen Verlust von etwa 400 MB. - Es gab während dieser drei Snapshots keinen neuen OOM-Kill. Die in
dmesg
enthaltenen OOM-Einträge stammen von 23:58:02 und 00:24:01 und damit aus
früheren Ereignissen. Damals wurden ioBroker-Controller-Prozesse beendet. - Die SSH-Anmeldung des Benutzers
puhum 14:13 erzeugte nur wenige Prozesse
und erklärt den Peak um 14:21 nicht.
Fehler und Lücken im aktuellen Messskript
1. Parent-Auswertung bricht ab
Im Journal steht bei jedem Snapshot:
/usr/local/sbin/memwatch.sh: line 264: PPID: readonly variablePPIDist in Bash eine reservierte, schreibgeschützte Variable. Dadurch bleibt
der AbschnittTOP PARENTS WITH PROCESS INFORMATIONleer. In der Schleife muss
die Variable beispielsweisePARENT_PIDheißen:while read -r COUNT PARENT_PID; do if [[ "$PARENT_PID" =~ ^[0-9]+$ ]] && [ "$PARENT_PID" -gt 0 ]; then INFO="$(ps -p "$PARENT_PID" -o pid=,ppid=,user=,nlwp=,rss=,vsz=,stat=,comm=,args= 2>/dev/null)" printf "%6s children | %s\n" "$COUNT" "$INFO" fi done2.
FULL THREAD LISTist leerIn allen drei Snapshots folgt direkt nach der Überschrift
FULL THREAD LIST
bereitsPROCESS TREE. Das verwendeteps -eLf -o ...liefert auf diesem
System offenbar keine Daten (der Fehler wird durch2>/dev/nullverborgen).
Vor dem nächsten Lauf sollte der Befehl direkt auf dem Raspberry Pi getestet
werden. Eine robustere Variante ist beispielsweise:ps -eL -o pid,ppid,lwp,nlwp,user,psr,stat,rss,vsz,comm,args3. Snapshot-Erfassung dauert etwa fünf Sekunden
Zwischen Triggerzeit und
snapshot writtenliegen jeweils vier bis fünf
Sekunden. Schon vor dem ersten detaillierten Taskwert war beim stärksten
Ereignis ein großer Teil des Sturms vorbei. Für solche Peaks sollte beim Trigger
zuerst eine sehr schnelle Rohkopie von/procbeziehungsweise mindestens eine
sofortige Threadliste in eine separate Datei geschrieben werden. Erst danach
sollten Sortierungen und mehrfacheps-Aufrufe folgen.4. Taskzahl im Trigger und Snapshot unterscheiden sich
Das ist kein Rechenfehler:
memory.logmisst 891 Tasks am Trigger, während der
nachfolgende Snapshot 736 anzeigt. Diese Differenz ist gerade ein wichtiger
Hinweis auf die kurze Lebensdauer der zusätzlichen Tasks.Bewertung der wahrscheinlichsten Ursache
- Sehr wahrscheinlich: ein kurzlebiger Prozess-/Thread-Sturm verursacht
den starken Peak um 14:21:36. - Wahrscheinlichster konkreter Auslöser: Start oder Startaktivität von
system.adapter.dwd.0, daio.dwd.0drei Sekunden vor dem Peak neu gestartet
wurde und unmittelbar 180 MB RSS belegte. - Noch nicht bewiesen: Ob
dwd.0selbst alle zusätzlichen Tasks erzeugte,
ob ein von ihm ausgelöster Node-/Systemvorgang beteiligt war oder ob ein
zeitgleicher, bereits verschwundener Prozess verantwortlich war. - Unwahrscheinlich als alleinige Ursache: Slab, Dateicache, SSH-Sitzung oder
ein dauerhaft wachsender einzelner ioBroker-Prozess.
Empfohlene nächste Schritte
- Die Variable
PPIDim Skript inPARENT_PIDumbenennen. - Den Befehl für
FULL THREAD LISTkorrigieren und seine Fehler vorübergehend
nicht nach/dev/nullumleiten. - ioBroker-Logs für
system.adapter.dwd.0im Zeitraum 14:21:25 bis 14:21:45
sichern und prüfen, warum der Adapter um 14:21:33 gestartet wurde. - In den ioBroker-Objekten/Logs die Restart-Zahl und den Exit-Grund von
dwd.0prüfen. - Für den nächsten Peak eine minimale Soforterfassung vor allen aufwendigen
Befehlen ergänzen, etwaps -eL ...und eine Liste aller numerischen
/proc/<PID>/task/<TID>-Einträge. - Optional
dwd.0kontrolliert deaktivieren und beobachten, ob die Peaks
ausbleiben. Das wäre ein aussagekräftiger A/B-Test, sollte aber nur erfolgen,
wenn der vorübergehende Ausfall der DWD-Daten akzeptabel ist.
Gesamtergebnis
Das verbesserte Monitoring hat die bisherige Vermutung grundsätzlich bestätigt:
Mindestens eines der Speicherereignisse ist mit einem massiven, sehr kurzen
Taskanstieg gekoppelt. Der Snapshot kam noch knapp zu spät, um sämtliche Tasks
ihrem Prozess zuzuordnen.dwd.0ist aufgrund seines Startzeitpunkts der klare
Hauptverdächtige. Für einen belastbaren Beweis müssen die beiden fehlerhaften
Snapshot-Abschnitte repariert und die erste Threadliste noch früher geschrieben
werden.leider mit noch nicht ganz so eindeutigen hinweisen.
Ich hätte jetzt was neues für dich
Die snapshots kommen im minutentakt

snapshot_20260831_153941.log snapshot_20260831_153921.log snapshot_20260831_153841.log snapshot_20260831_153541.log snapshot_20260831_153440.log snapshot_20260831_153339.log snapshot_20260831_153309.log snapshot_20260831_153240.log snapshot_20260831_153140.log snapshot_20260831_153040.log 1540memory.log
Ich sehe mir jetzt sofort deine Vorschläge an
-
So,
Neues Programm läuft!Dwd.0 hat wohl Probleme mit der gesicherten Verbindung.
Das hatte das log zugespammt.Ich glaube da wurde nur das logging deaktiviert.
Dwd ist scheduled, daher due Aussage "direkt nach dem start...."
Hey! Du scheinst an dieser Unterhaltung interessiert zu sein, hast aber noch kein Konto.
Hast du es satt, bei jedem Besuch durch die gleichen Beiträge zu scrollen? Wenn du dich für ein Konto anmeldest, kommst du immer genau dorthin zurück, wo du zuvor warst, und kannst dich über neue Antworten benachrichtigen lassen (entweder per E-Mail oder Push-Benachrichtigung). Du kannst auch Lesezeichen speichern und Beiträge positiv bewerten, um anderen Community-Mitgliedern deine Wertschätzung zu zeigen.
Mit deinem Input könnte dieser Beitrag noch besser werden 💗
Registrieren Anmelden
