Monatsrückblick Juli / August 2026 ist online!

[OliverIO]

@Homoran

Dann weiter viel Glück beim beobachten

[Homoran]

@OliverIO hab noch was editiert

[Homoran]

@OliverIO
Nachdem wir so viel an den Symptomen gebastelt haben und iob inzwischen schon 1.7 Tage lief, hab ich wirklich gedacht: das war's!

Pustekuchen!
Heute Nacht ist iob 2-3x neu gestartet

Das anschließende backitup hat er wie i mer problemlos überstanden.

Ich hab jetzt das KI logging (hoffentlich richtig- aktiviert

===== 2026-08-31 08:50:45 =====
MemTotal:        8255872 kB
MemFree:         2875856 kB
MemAvailable:    3263424 kB
Buffers:          152512 kB
Cached:           317808 kB
SwapCached:          672 kB
Active:          2748256 kB
Inactive:        1377264 kB
SwapTotal:       2097136 kB
SwapFree:        1000208 kB
Dirty:               240 kB
Writeback:             0 kB
AnonPages:       3654736 kB
Mapped:            66976 kB
Shmem:              4080 kB
Slab:             321040 kB
SReclaimable:     225696 kB
SUnreclaim:        95344 kB
KernelStack:       10608 kB
PageTables:       345408 kB
--- load ---
0.34 0.38 0.48 1/660 95481

Weisst du ob das log unendlich geschrieben wird oder irgenwann wieder teilweise gelöscht ?

Was mir auffällt ist dass der swap mittlerweile schon zu 1GB verbraucht ist.
Das geht natürlich auch in die I/O Belastung

Aus dem journal (nur die errors)

Aug 30 22:14:07 BrokerRaspi systemd-udevd[380]: /usr/lib/udev/rules.d/90-alsa-restore.rules:18 GOTO="alsa_restore_std" has no matching label, i>Aug 30 22:14:07 BrokerRaspi systemd-udevd[380]: /usr/lib/udev/rules.d/90-alsa-restore.rules:18 The line has no effect any more, dropping.
Aug 30 22:14:07 BrokerRaspi systemd-udevd[380]: /usr/lib/udev/rules.d/90-alsa-restore.rules:22 GOTO="alsa_restore_std" has no matching label, i>Aug 30 22:14:07 BrokerRaspi systemd-udevd[380]: /usr/lib/udev/rules.d/90-alsa-restore.rules:22 The line has no effect any more, dropping.
.
.
.
Aug 30 22:14:08 BrokerRaspi systemd[1]: Reached target remote-fs.target - Remote File Systems.
Aug 30 22:14:08 BrokerRaspi blkmapd[765]: open pipe file /run/rpc_pipefs/nfs/blocklayout failed: No such file or directory
Aug 30 22:14:08 BrokerRaspi systemd[1]: Started nfs-blkmap.service - pNFS block layout mapping daemon.
.
.
.

Aug 30 22:14:10 BrokerRaspi bluetoothd[792]: Bluetooth daemon 5.82
Aug 30 22:14:10 BrokerRaspi kernel: raspberrypi-firmware soc@107c000000:firmware: Request 0x00030097 returned status 0x80000001
Aug 30 22:14:10 BrokerRaspi systemd[1]: sshswitch.service: Deactivated successfully.
.
.
.
Aug 30 23:58:04 BrokerRaspi kernel: oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0-7,global_oom,task_memcg=/,task=>Aug 30 23:58:04 BrokerRaspi kernel: Out of memory: Killed process 1190 (iobroker.js-con) total-vm:12241856kB, anon-rss:326736kB, file-rss:256kB>Aug 30 23:58:07 BrokerRaspi systemd[1]: iobroker.service: Main process exited, code=killed, status=9/KILL
.
.
.
Aug 31 00:24:01 BrokerRaspi kernel: oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0-7,global_oom,task_memcg=/,task=>Aug 31 00:24:01 BrokerRaspi kernel: Out of memory: Killed process 29115 (iobroker.js-con) total-vm:12270864kB, anon-rss:234672kB, file-rss:96kB>Aug 31 00:24:02 BrokerRaspi systemd[1]: iobroker.service: Main process exited, code=killed, status=9/KILL
.
.
.
Aug 31 03:55:55 BrokerRaspi kernel: cp210x ttyUSB0: usb_serial_generic_read_bulk_callback - urb stopped: -32
Aug 31 03:55:55 BrokerRaspi kernel: cp210x ttyUSB0: usb_serial_generic_read_bulk_callback - urb stopped: -32
Aug 31 03:55:55 BrokerRaspi kernel: usb 3-2.1.3: USB disconnect, device number 8
Aug 31 03:55:55 BrokerRaspi kernel: cp210x ttyUSB0: failed set request 0x7 status: -19
Aug 31 03:55:55 BrokerRaspi kernel: cp210x ttyUSB0: failed set request 0x12 status: -19
Aug 31 03:55:55 BrokerRaspi kernel: cp210x ttyUSB0: failed set request 0x0 status: -19
.
.
.

[OliverIO]

@Homoran

Das Script löscht Dateien alter als 14 tage
Kann man mit dem Parameter am Anfang des Skript einstellen. Keep Days

Wir warten auf eine snapshot Datei
Auf wieviel hast du drop threshoud eingestellt

Das Script wartet darauf das das freemen um 512mb fällt.
Wie die KI erwähnte, kannst du es auch empfindlicher einstellen mit 256

[Homoran]

@OliverIO sagte:

Auf wieviel hast du drop threshoud eingestellt

ich hab nur kopiert!

Muss7ch mir ansehen

Edit

@OliverIO sagte:

DROP_THRESHOLD_KB=$((512 * 1024)) # Trigger bei >512 MB Verlust seit letzter Messung

Hier die 512 gegen 256 ändern?

[paul53]

@Homoran [sagte]:
backitup hat er wie i mer problemlos überstanden.

Man sieht, das dabei "buffer" um 1,8 GB steigt.
Der Grund für die Abstürze ist offenbar ein anderer.

[Homoran]

@paul53 sehe ich genau so!
Danke

[Homoran]

############################################################
MEMORY EVENT SNAPSHOT
Time: 2026-08-31 09:08:06
############################################################

===== /proc/meminfo =====
MemTotal:        8255872 kB
MemFree:         2220016 kB
MemAvailable:    2643200 kB
Buffers:          158848 kB
Cached:           346800 kB
SwapCached:          672 kB
Active:          3010608 kB
Inactive:        1408752 kB
Active(anon):    2806336 kB
Inactive(anon):  1110944 kB
Active(file):     204272 kB
Inactive(file):   297808 kB
Unevictable:           0 kB
Mlocked:               0 kB
SwapTotal:       2097136 kB

Da scheint jetzt schon der nächste event zu sein

Edit

############################################################
MEMORY EVENT SNAPSHOT
Time: 2026-08-31 09:45:01
############################################################

===== /proc/meminfo =====
MemTotal:        8255872 kB
MemFree:          386752 kB
MemAvailable:     650272 kB
Buffers:           34720 kB
Cached:            94336 kB
SwapCached:          592 kB
Active:          2235792 kB
Inactive:        3726624 kB
Active(anon):    2164832 kB
Inactive(anon):  3671312 kB
Active(file):      70960 kB
Inactive(file):    55312 kB
Unevictable:           0 kB
Mlocked:               0 kB
SwapTotal:       2097136 kB

Edit2
Falls die KI was aktuelles dazu sehen will

Noch ein snapshot

############################################################
MEMORY EVENT SNAPSHOT
Time: 2026-08-31 09:49:56
############################################################

===== /proc/meminfo =====
MemTotal:        8255872 kB
MemFree:         2163712 kB
MemAvailable:    2516336 kB
Buffers:           43760 kB
Cached:           175776 kB
SwapCached:          512 kB
Active:          2481600 kB
Inactive:        1401344 kB
Active(anon):    2393040 kB
Inactive(anon):  1273184 kB
Active(file):      88560 kB
Inactive(file):   128160 kB
Unevictable:           0 kB
Mlocked:               0 kB
SwapTotal:       2097136 kB

Den dazugehörigen drop hab ich gar nicht wirklich als "bedrohlich" registriert.

[Ro75]

Und mal ganz doof gefragt. Kann es sein, dass der PI5 selbst eine Macke hat?

Ro75.

[Homoran]

@Ro75 möchlich ist alles!

Aber dann hätte der andere wahrscheinlich die selbe Macke.
Dort traten due Abstürze zuerst auf.
Weil wir kurz vorher Stromausfall hatten und da immer noch bookworm drauf lief, bin ich dann auf den neuen mit Trixie umgezogen, alles neu installiert, backup restored, dadurch Pakete neu gepackt, aber die Probleme blieben

[Ro75]

Also betrifft es letztlich 2 Pi's. Schon mal einen mit Ubuntu versucht?

Ro75.

[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?