Monatsrückblick Juli / August 2026 ist online!

[OliverIO]

@Homoran

Das sieht nicht vollständig aus.
Das ist nur der Mem Info Bereich
Kannst du bitte mal die Befehle, die ich oben aufgelistet hab ausprobieren ob die auch da sind?

[Homoran]

@Ro75 sagte:

Schon mal einen mit Ubuntu versucht?

Nein!
Hab aber schon drüber nachgedacht.

Hab aber "eigentlich" keine Zeit zum experimentieren.

Deswegen wäre ich im Moment mit Symptombehebung zufrieden gewesen.

Die anderen SSD/SD wollte ich als Hardwarebackups halten und nicht überschreiben.

Vielleicht schaffe ich es heute Zeit und Genehmigung für eine Karte und nvme zu bekommen

[Homoran]

@OliverIO recht du hast!
Hab mich auch gewundert

Das sind ja 14 Seiten!

snapshot_20260831_090806.log snapshot_20260831_094501.log snapshot_20260831_094956.log

[OliverIO]

@Homoran

Und das Memory.log noch
Welches den Verlauf zeigt

[Homoran]

@OliverIO sagte:

Und das Memory.log noch

Such ich dir!

Ansonsten hier der Vorrat

Und der chart dazu

Edit
memory.log

Da ist hoffentlich was dabei, die load war die ganze Zeit hoch und kommt jetzt erst wieder zur Ruhe

Muss jetzt weg!

[OliverIO]

@Homoran

hier das ergebnis der analyse

Ja. Die Logs zeigen inzwischen ziemlich eindeutig, in welche Richtung wir suchen müssen.

Der entscheidende Fund ist nicht Cached oder Slab, sondern die explosionsartige Zunahme der Anzahl von Tasks/Threads. Beim Ereignis um 09:45:01 fällt MemFree von etwa 2,5 GB auf 253 MB. Gleichzeitig liegt MemAvailable nur 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: AnonPages liegt während des Peaks bei rund 6,0 GB, PageTables bei enormen ~685 MB und KernelStack bei ~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/2553

Normalerweise 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 AnonPages von rund 3,2 GB auf 6,06 GB, PageTables von rund 344 MB auf 710 MB, KernelStack von 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 5 wartet 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 vmstat läuft, normalisiert sich der Speicher bereits wieder. Die erste vmstat-Messung sieht noch die Situation, danach steigt free sofort wieder massiv an.

Erst danach wird ps ausgefü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.1 rund 278 MB. Keiner davon erklärt den Peak.

Das müssen wir ändern.

Ich würde memwatch.sh jetzt gezielt erweitern

Ganz am Anfang von log_detailed_snapshot() sollten sofort Prozess- und Threadinformationen geschrieben werden, noch bevor free, vmstat, slabtop usw. 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 --forest

Besonders interessant wird:

ps -eo pid,ppid,user,nlwp,rss,vsz,stat,comm,args --sort=-nlwp

Angenommen, wir sehen beim nächsten Peak:

PID     PPID    NLWP  COMMAND
40099   39859   1650  io.javascript.1

dann hätten wir den Schuldigen praktisch direkt.

Oder:

PID      PPID
123001   40099
123002   40099
123003   40099
...

Dann erzeugt PID 40099 hunderte oder tausende Child-Prozesse.

Oder beispielsweise:

1800 node

in der Gruppierung nach comm, dann wissen wir ebenfalls sofort, was los ist.

Auch die alten OOM-Ereignisse passen ins Bild

In dmesg gibt es sogar bereits zwei echte Out-of-Memory-Ereignisse vom Vorabend bzw. kurz nach Mitternacht. Dabei hat der Kernel jeweils iobroker.js-controller abgeschossen.

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.sh so 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.

[OliverIO]

@Homoran

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 ps und die Thread-Informationen sofort nach dem Trigger geschrieben werden – noch vor vmstat, slabtop usw.

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.sh

Vorhandenen Dienst neu starten

Falls dein memwatch.service bereits wie bisher eingerichtet ist, reicht anschließend:

sudo systemctl restart memwatch.service

Und prüfen:

systemctl status memwatch.service

Live beobachten:

tail -f /var/log/memwatch/memory.log

Ich 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 LIST

Wenn beispielsweise ein einzelner Node/ioBroker-Prozess 1.500 Threads erzeugt, sollte PROCESSES WITH MOST THREADS ihn direkt zeigen. Wenn stattdessen ein Prozess 1.500 Child-Prozesse erzeugt, sollte PROCESS COUNT GROUPED BY PPID die 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 MB

Damit können wir schon anhand von memory.log sehen, ob sich unsere Hypothese bestätigt.

Beim nächsten Ereignis würde ich mir am liebsten memory.log und den dazugehörigen neuen snapshot_*.log ansehen. Mit dieser Version sollten wir eine wesentlich bessere Chance haben, die konkrete PID beziehungsweise den ioBroker-Adapter oder das Script zu identifizieren.

[OliverIO]

@Homoran

vor dem start des neuen scripts
alle bisher erzeugten logdateien löschen, damit wir nicht mit alten daten durcheinander kommen

hast du in einem deinen javascripts etwas was das uU viel den exec befehl auslösen könnte?

[Homoran]

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

[OliverIO]

@Homoran

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

[OliverIO]

@Homoran

Eilt ja nicht, ist ja dein Rechner :)

[Homoran]

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

[Homoran]

@OliverIO sagte:

und ausführen

Das war's

Danke, läuft!

Bin gespannt

[Homoran]

@OliverIO sagte:

hast du in einem deinen javascripts etwas was das uU viel den exec befehl auslösen könnte?

In allen Blockly mit exec: trigger alle 15 Sekunden
Im js alle 2 Minuten

EDIT: Plattendaten alle 10 Minuten

[OliverIO]

@Homoran

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 triggers

ggfs 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

[Homoran]

@OliverIO sagte:

so ein exec eine schleife liegt die entsprechend oft so ein exec

Nein, niemals!
Einfaches aufrufen, auswerten, schreiben

@OliverIO sagte:

die 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.log

Wobei 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

1424memory.log

[Michael Schmitt]

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 ;)

[Homoran]

@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

[OliverIO]

@Michael-Schmitt
sehr schön wenn sich die KIs gegenseitig loben :)

[OliverIO]

@Homoran

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 Prozess io.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 ist dwd.0 der derzeit stärkste
Verdächtige, aber anhand dieser Dateien noch nicht zweifelsfrei als Erzeuger
aller 212 zusätzlichen Tasks bewiesen.

Ausgewertete Dateien

• 1788179405632-1424memory.log
• 1788179326889-snapshot_20260831_140543.log
• 1788179326893-snapshot_20260831_141701.log
• 1788179326891-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,
KernelStack und 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.0 hatte 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 ersten ps-Snapshot schon
endete. Die verbleibenden 12 Threads von dwd.0 erklä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 MemAvailable trat 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/so jeweils 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 puh um 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 variable

PPID ist in Bash eine reservierte, schreibgeschützte Variable. Dadurch bleibt
der Abschnitt TOP PARENTS WITH PROCESS INFORMATION leer. In der Schleife muss
die Variable beispielsweise PARENT_PID heiß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
done

2. FULL THREAD LIST ist leer

In allen drei Snapshots folgt direkt nach der Überschrift FULL THREAD LIST
bereits PROCESS TREE. Das verwendete ps -eLf -o ... liefert auf diesem
System offenbar keine Daten (der Fehler wird durch 2>/dev/null verborgen).
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,args

3. Snapshot-Erfassung dauert etwa fünf Sekunden

Zwischen Triggerzeit und snapshot written liegen 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 /proc beziehungsweise mindestens eine
sofortige Threadliste in eine separate Datei geschrieben werden. Erst danach
sollten Sortierungen und mehrfache ps-Aufrufe folgen.

4. Taskzahl im Trigger und Snapshot unterscheiden sich

Das ist kein Rechenfehler: memory.log misst 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

1. Sehr wahrscheinlich: ein kurzlebiger Prozess-/Thread-Sturm verursacht
   den starken Peak um 14:21:36.
2. Wahrscheinlichster konkreter Auslöser: Start oder Startaktivität von
   system.adapter.dwd.0, da io.dwd.0 drei Sekunden vor dem Peak neu gestartet
   wurde und unmittelbar 180 MB RSS belegte.
3. Noch nicht bewiesen: Ob dwd.0 selbst alle zusätzlichen Tasks erzeugte,
   ob ein von ihm ausgelöster Node-/Systemvorgang beteiligt war oder ob ein
   zeitgleicher, bereits verschwundener Prozess verantwortlich war.
4. Unwahrscheinlich als alleinige Ursache: Slab, Dateicache, SSH-Sitzung oder
   ein dauerhaft wachsender einzelner ioBroker-Prozess.

Empfohlene nächste Schritte

1. Die Variable PPID im Skript in PARENT_PID umbenennen.
2. Den Befehl für FULL THREAD LIST korrigieren und seine Fehler vorübergehend
   nicht nach /dev/null umleiten.
3. ioBroker-Logs für system.adapter.dwd.0 im Zeitraum 14:21:25 bis 14:21:45
   sichern und prüfen, warum der Adapter um 14:21:33 gestartet wurde.
4. In den ioBroker-Objekten/Logs die Restart-Zahl und den Exit-Grund von
   dwd.0 prüfen.
5. Für den nächsten Peak eine minimale Soforterfassung vor allen aufwendigen
   Befehlen ergänzen, etwa ps -eL ... und eine Liste aller numerischen
   /proc/<PID>/task/<TID>-Einträge.
6. Optional dwd.0 kontrolliert 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.0 ist 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.