[gelöst] Versuch Logdatei download führt zu Admin-Absturz

[maloross]

@thomas-braun danke für die Rückmeldung und Asche auf mein Haupt: durch den Absturz habe ich die heutige Aktualisierung (im Normalfall mache ich das alle 14 Tage sonntags) nicht gemacht.

Noch zum besseren Verständnis: auf den beiden Slaves sind lediglich die Instanzen installiert, die ich für die jeweiligen Controller (zwave/homematic) benötige, auf dem Master ist der ganze Rest, weil dieser an der USV hängt.

Bringt eine Umverteilung der Instanzen eine Verbesserung?

[Thomas Braun]

@maloross

Es sollten aber in 14 Tagen keine 73 Updates auflaufen.
Und du solltest auch einen Reboot einplanen. In den 176 Tagen ist mit Sicherheit auch ein Paket angepackt wurden, das gerne komplett neugestartet werden will. Kernel-Updates z. B.

[maloross]

@thomas-braun Danke für die konstruktiven Hinweise, habe auf allen drei Geräten update und reboot durchgeführt; die diversen Instanzen habe ich umverteilt. Das Ergebnis sieht dann jetzt so aus:

Systemuptime and Load:
Vorher: 
10:06:51 up 176 days, 22 min, 2 users, load average: 6.08, 6.08, 4.54
CPU threads: 4

Nachher:
15:05:07 up 32 min, 2 users, load average: 2.05, 1.79, 1.82
CPU threads: 4

Dazu noch eine Frage: die drei Werte, was repräsentieren sie (M, S1, S2) und welche Größe sollte nicht überschritten werden?

[Homoran]

@maloross so ganz zur Ruhe gekommen ist das System noch nicht

@maloross sagte in Versuch Logdatei download führt zu Admin-Absturz:

die drei Werte, was repräsentieren sie

die load average des Systems.
für die letzte, die letzten 5 und die letzten 15 Minuten

@maloross sagte in Versuch Logdatei download führt zu Admin-Absturz:

welche Größe sollte nicht überschritten werden?

die Anzahl Kerne der CPU.

wenn also >4 dann wird der Rückstau abzuarbeitender Aufgabenzu hoch und es schaukelt sich ggf. noch weiter auf.

[maloross]

@homoran @Thomas-Braun Vielen lieben Dank für eure Unterstützung, habe heute einiges dazugelernt.

Allerdings verabschiedet sich der Admin bzw. startet neu, sobald ich die Logdatei herunterladen will. Über die Konsole bekomme ich dann diese Meldungen:

supervisor@PI4Master:~ $ iob status
No connection to databases possible ...
supervisor@PI4Master:~ $ iob restart

supervisor@PI4Master:~ $ iob status
Server Cannot start inMem-states on port 9000: Failed to lock DB file "/opt/iobroker/iobroker-data/states.jsonl"!

supervisor@PI4Master:~ $ iob restart
supervisor@PI4Master:~ $ iob status
iobroker is running on this host.
Objects type: jsonl
States  type: jsonl
supervisor@PI4Master:~ $

Die "states.jsonl" befindet sich ordnungsgemäß in dem Verzeichnis (über WinSCP geprüft), erst nach nochmaligem restart läuft der Admin.

[Homoran]

@maloross dann hat iob sich vorher nicht ordentlich abgemeldet.
Wahrscheinlich weil der pi abgestürzt war.
nochmal wahrscheinlich weil der RAM ausgeht

[maloross]

@homoran

Komische kleine Kiste - ich bin davon ausgegangen, dass bei dem Master die 8 GB mehr als ausreichend sind, auch vor dem Hintergrund, dass ich einige Instanzen umgelagert habe. Die beiden Slaves haben nur 4 GB.

Master:

*** MEMORY ***
               total        used        free      shared  buff/cache   available
Mem:            8.2G        3.0G        4.0G        1.5M        1.4G        5.2G
Swap:           209M          0B        209M
Total:          8.4G        3.0G        4.2G
         7809 M total memory
         2850 M used memory
         2815 M active memory
          939 M inactive memory
         3781 M free memory
          182 M buffer memory
         1166 M swap cache
          199 M total swap
            0 M used swap
          199 M free swap

Slave:

*** MEMORY ***
               total        used        free      shared  buff/cache   available
Mem:            4.0G        881M        2.3G        1.3M        921M        3.1G
Swap:           209M          0B        209M
Total:          4.2G        881M        2.5G
         3791 M total memory
          841 M used memory
          874 M active memory
          515 M inactive memory
         2148 M free memory
          115 M buffer memory
          762 M swap cache
          199 M total swap
            0 M used swap
          199 M free swap

[Homoran]

@maloross sieht "eigentlich" gut aus.
der Swap ist noch nicht angegriffen.

ALLERDINGS muss man dabei wissen, ob der Raspi nach dem Problem neu gestartet ist.
Dann sagt der Wert nichts aus.

[maloross]

@homoran Das kann ich so jetzt nicht sagen, werde es aber im Auge behalten.

Wenn ich dich richtig verstehe, ist die Größe der Auslagerungsdatei (free Swap) der Indikator, das RAM ungenügend zur Verfügung steht.
Ich vermute, über den Adapter "RPI-Monitor" kann man sich diese (und andere) relevanten Werte anzeigen lassen. Hatte den mal vor langer Zeit getestet, aber nicht genutzt.

[Homoran]

@maloross sagte in Versuch Logdatei download führt zu Admin-Absturz:

ist die Größe der Auslagerungsdatei (free Swap) der Indikator, das RAM ungenügend zur Verfügung steht.

jein, used SWAP sollte möglichst nicht angekratzt sein

@maloross sagte in Versuch Logdatei download führt zu Admin-Absturz:

über den Adapter "RPI-Monitor" kann man sich diese (und andere) relevanten Werte anzeigen lassen.

oder über die Datenpunkte unter 'system.host.xy' (nur im Expertenmodus zu sehen

[maloross]

@homoran sagte in Versuch Logdatei download führt zu Admin-Absturz:

'system.host.xy' (

Super - das ist perfekt! Ich sollte öfter mal in den Expertenmodus wechseln...

[maloross]

Heute noch einmal einen Versuch gewagt, jedoch gleiches Ergebnis:
Sobald ich die Logdatei "current" über die Schaltfläche abrufe, knickt der Admin ein und diese Meldung erscheint:

host.PI4Slave2 2025-04-14 12:58:30.421 warn "system.host.PI4Master" is offline

Parallel eine Statusabfrage über die Konsole (Putty) warf diese Meldung aus:

supervisor@PI4Master:~ $ iob status
 Unable to increase LUA script timeout: Connection is closed.
 Cannot determine Set feature status: Connection is closed.
 Unable to enable Expiry Keyspace events from Redis Server: Connection is closed.
 Connection is closed.
Uncaught Rejection: Error: States DB is not allowed to start in the current Multihost environment
    at Redis.<anonymous> (file:///opt/iobroker/node_modules/@iobroker/db-states-redis/build/esm/lib/states/statesInRedisClient.js:477:23)
    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)

Nach ca. 5 Minuten ist dann der Admin wieder erreichbar und auch die Logdatei wird jetzt im Browser angezeigt. Die durchgeführte Diagnose zeigt im Summary:

======================= SUMMARY =======================
                        v.2025-02-23


 Static hostname: PI4Master
       Icon name: computer
Operating System: Debian GNU/Linux 12 (bookworm)
          Kernel: Linux 6.12.20+rpt-rpi-v8
    Architecture: arm64

Installation:           native
Kernel:                 aarch64
Userland:               64 bit
Timezone:               Europe/Berlin (CEST, +0200)
User-ID:                1000
Display-Server:         false
Boot Target:            multi-user.target

Pending OS-Updates:     4
Pending iob updates:    0

Nodejs-Installation:
/usr/bin/nodejs         v20.19.0
/usr/bin/node           v20.19.0
/usr/bin/npm            10.8.2
/usr/bin/npx            10.8.2
/usr/bin/corepack       0.31.0

Recommended versions are nodejs 20.19.0 and npm 10.8.2
nodeJS installation is correct

MEMORY:
               total        used        free      shared  buff/cache   available
Mem:            8.2G        4.0G        2.3G        1.5M        2.0G        4.2G
Swap:           209M          0B        209M
Total:          8.4G        4.0G        2.5G

Active iob-Instances:   50
Upgrade policy: none

ioBroker Core:          js-controller           7.0.6
                        admin                   7.6.3

ioBroker Status:        iobroker is running on this host.


Objects type: jsonl
States  type: jsonl

Status admin and web instance:
+ system.adapter.admin.0                  : admin                 : PI4Master                                -  enabled, port: 8081, bind: 0.0.0.0, run as: admin
+ system.adapter.web.0                    : web                   : PI4Master                                -  enabled, port: 8099, bind: 0.0.0.0, run as: admin
  system.adapter.web.1                    : web                   : PI4Slave1                                - disabled, port: 8899, bind: 0.0.0.0, run as: admin

Objects:                26907
States:                 22823

Size of iob-Database:

56M     /opt/iobroker/iobroker-data/objects.jsonl
38M     /opt/iobroker/iobroker-data/states_new.jsonl
12M     /opt/iobroker/iobroker-data/states.jsonl


Operating System is the current Debian stable version codenamed 'bookworm'!

=================== END OF SUMMARY ====================

Über den Raspi2-Adapter lasse ich einige Status überwachen, hier zeigt sich zum Zeitpunkt des Absturzes ein Einbruch im freien Speicher:

Das System selbst lief sehr lange sehr stabil und unauffällig; es stellt sich jetzt die Frage: soll ich das System noch einmal komplett neu und sauber aufsetzen oder soll ich mir Gedanken machen, dass mein System zu groß für die kleinen Rechen geworden ist?

[Thomas Braun]

@maloross

Sind für mich typische Anzeichen einer Überlastung.
Vermutlich läuft da in zu kurzer Zeit zuviel in der Datenbank auf und die Kiste bekommt das nicht mehr schnell genug abgearbeitet.

[maloross]

@thomas-braun sagte in Versuch Logdatei download führt zu Admin-Absturz:

@maloross

Sind für mich typische Anzeichen einer Überlastung.
Vermutlich läuft da in zu kurzer Zeit zuviel in der Datenbank auf und die Kiste bekommt das nicht mehr schnell genug abgearbeitet.

ok, also weniger die Hardware.
Kann ein Umstieg auf Redis (was hier ja schon ausführlich besprochen wird bzw. wurde) Abhilfe schaffen?
Ich werde noch einmal alle Adapter durchgehen und die Abfrageintervalle checken, Adapter wie Fronius sind aber auf 1-2 Minuten eingestellt.
Kann mir da "htop" weiterhelfen und wenn ja, worauf muss ich da achten?

[Thomas Braun]

@maloross sagte in Versuch Logdatei download führt zu Admin-Absturz:

Kann ein Umstieg auf Redis (was hier ja schon ausführlich besprochen wird bzw. wurde) Abhilfe schaffen?

Möglich. Allerdings hast du ja gar nicht sooooo viele Daten. Ich denke eher, da fliegt zu viel zu schnell rein.
Schaumal, ob du da nicht reduzieren kannst.
Alleine der hm--rpc.1 schaufelt da offenbar im Milisekundentakt irgendwas rein:

2025-04-13 10:10:33.723  - debug: hm-rpc.1 (3536255) hm-rpc.1.00185BE98B3FD8.1.ILLUMINATION_STATUS ==> UNIT: "undefined" (min: undefined, max: undefined) From "0" => "0"

2025-04-13 10:10:33.724  - debug: hm-rpc.1 (3536255) xml multicall <event>: PI4Master:hm-rpc.1:719f6fd35f68f142a58f1339ad76168b,00185BE98B3FD8:1,SUNSHINEDURATION,12131

2025-04-13 10:10:33.724  - debug: hm-rpc.1 (3536255) xmlrpc <- event ["PI4Master:hm-rpc.1:719f6fd35f68f142a58f1339ad76168b","00185BE98B3FD8:1","SUNSHINEDURATION",12131]

2025-04-13 10:10:33.724  - debug: hm-rpc.1 (3536255) hm-rpc.1.00185BE98B3FD8.1.SUNSHINEDURATION ==> UNIT: "min" (min: 0, max: 16383) From "12131" => "12131"

2025-04-13 10:10:33.725  - debug: hm-rpc.1 (3536255) xml multicall <event>: PI4Master:hm-rpc.1:719f6fd35f68f142a58f1339ad76168b,00185BE98B3FD8:1,HUMIDITY_STATUS,0

2025-04-13 10:10:33.725  - debug: hm-rpc.1 (3536255) xmlrpc <- event ["PI4Master:hm-rpc.1:719f6fd35f68f142a58f1339ad76168b","00185BE98B3FD8:1","HUMIDITY_STATUS",0]

2025-04-13 10:10:33.725  - debug: hm-rpc.1 (3536255) hm-rpc.1.00185BE98B3FD8.1.HUMIDITY_STATUS ==> UNIT: "undefined" (min: undefined, max: undefined) From "0" => "0"

2025-04-13 10:10:33.725  - debug: hm-rpc.1 (3536255) xml multicall <event>: PI4Master:hm-rpc.1:719f6fd35f68f142a58f1339ad76168b,00185BE98B3FD8:1,WIND_DIR_RANGE_STATUS,0

2025-04-13 10:10:33.726  - debug: hm-rpc.1 (3536255) xmlrpc <- event ["PI4Master:hm-rpc.1:719f6fd35f68f142a58f1339ad76168b","00185BE98B3FD8:1","WIND_DIR_RANGE_STATUS",0]

2025-04-13 10:10:33.726  - debug: hm-rpc.1 (3536255) hm-rpc.1.00185BE98B3FD8.1.WIND_DIR_RANGE_STATUS ==> UNIT: "undefined" (min: undefined, max: undefined) From "0" => "0"

2025-04-13 10:10:33.726  - debug: hm-rpc.1 (3536255) xml multicall <event>: PI4Master:hm-rpc.1:719f6fd35f68f142a58f1339ad76168b,00185BE98B3FD8:1,ACTUAL_TEMPERATURE,13.8

2025-04-13 10:10:33.726  - debug: hm-rpc.1 (3536255) xmlrpc <- event ["PI4Master:hm-rpc.1:719f6fd35f68f142a58f1339ad76168b","00185BE98B3FD8:1","ACTUAL_TEMPERATURE",13.8]

2025-04-13 10:10:33.726  - debug: hm-rpc.1 (3536255) hm-rpc.1.00185BE98B3FD8.1.ACTUAL_TEMPERATURE ==> UNIT: "�C" (min: -3276.8, max: 3276.7) From "13.8" => "13.8"

2025-04-13 10:10:33.727  - debug: hm-rpc.1 (3536255) xml multicall <event>: PI4Master:hm-rpc.1:719f6fd35f68f142a58f1339ad76168b,00185BE98B3FD8:1,WIND_DIR_STATUS,0

2025-04-13 10:10:33.727  - debug: hm-rpc.1 (3536255) xmlrpc <- event ["PI4Master:hm-rpc.1:719f6fd35f68f142a58f1339ad76168b","00185BE98B3FD8:1","WIND_DIR_STATUS",0]

2025-04-13 10:10:33.727  - debug: hm-rpc.1 (3536255) hm-rpc.1.00185BE98B3FD8.1.WIND_DIR_STATUS ==> UNIT: "undefined" (min: undefined, max: undefined) From "0" => "0"

2025-04-13 10:10:33.727  - debug: hm-rpc.1 (3536255) xml multicall <event>: PI4Master:hm-rpc.1:719f6fd35f68f142a58f1339ad76168b,00185BE98B3FD8:1,RAIN_COUNTER_OVERFLOW,false

2025-04-13 10:10:33.728  - debug: hm-rpc.1 (3536255) xmlrpc <- event ["PI4Master:hm-rpc.1:719f6fd35f68f142a58f1339ad76168b","00185BE98B3FD8:1","RAIN_COUNTER_OVERFLOW",false]

2025-04-13 10:10:33.728  - debug: hm-rpc.1 (3536255) hm-rpc.1.00185BE98B3FD8.1.RAIN_COUNTER_OVERFLOW ==> UNIT: "undefined" (min: undefined, max: undefined) From "false" => "false"

2025-04-13 10:10:33.728  - debug: hm-rpc.1 (3536255) xml multicall <event>: PI4Master:hm-rpc.1:719f6fd35f68f142a58f1339ad76168b,00185BE98B3FD8:1,RAINING,false

2025-04-13 10:10:33.728  - debug: hm-rpc.1 (3536255) xmlrpc <- event ["PI4Master:hm-rpc.1:719f6fd35f68f142a58f1339ad76168b","00185BE98B3FD8:1","RAINING",false]

2025-04-13 10:10:33.729  - debug: hm-rpc.1 (3536255) hm-rpc.1.00185BE98B3FD8.1.RAINING ==> UNIT: "undefined" (min: undefined, max: undefined) From "false" => "false"

2025-04-13 10:10:33.729  - debug: hm-rpc.1 (3536255) xml multicall <event>: PI4Master:hm-rpc.1:719f6fd35f68f142a58f1339ad76168b,00185BE98B3FD8:1,WIND_SPEED,20.5

2025-04-13 10:10:33.729  - debug: hm-rpc.1 (3536255) xmlrpc <- event ["PI4Master:hm-rpc.1:719f6fd35f68f142a58f1339ad76168b","00185BE98B3FD8:1","WIND_SPEED",20.5]

2025-04-13 10:10:33.730  - debug: hm-rpc.1 (3536255) hm-rpc.1.00185BE98B3FD8.1.WIND_SPEED ==> UNIT: "km/h" (min: 0, max: 200) From "20.5" => "20.5"

[maloross]

@thomas-braun Das scheint wohl die Wetterstation (HM-IP) zu sein.

Ich habe die zyklischen Statusmeldungen entfernt, die beiden anderen Werte sind nach meinem Dafürhalten aber weniger problematisch.
Im ioB-Adapter "Homematic" hatte ich die Standardwerte (Verbindungstest180 sec, Wiederverbindung 30 sec.) belassen, habe sie mal verdoppelt.

[Homoran]

@maloross sagte in Versuch Logdatei download führt zu Admin-Absturz:

Das scheint wohl die Wetterstation (HM-IP) zu sein.

ja, aber die anschließend durchgeführten Aktionen sind in meinen Augen wahrscheinlich unnötig.

Das log sieht aus wie nach einem Neustart des Adapters.
Dann wird erst einmal alles eingelesen.

Das wäre vollkommen korrekt, wenn es nicht dauernd und vir allem unabsichtlich vorkommt

[Thomas Braun]

@maloross

Und dann würde ich die Instanz auch nicht auf 'debug'-Level loggen lassen.

[maloross]

@thomas-braun Das die Debug-Einstellung so viel ausmacht hatte ich nicht erwartet. Stelle jetzt alle Adapter, die im Debug sind, auf Info zurück.
Wieder ein Tag, an dem ich Neues gelernt habe.

[Thomas Braun]

@maloross sagte in Versuch Logdatei download führt zu Admin-Absturz:

Stelle jetzt alle Adapter, die im Debug sind, auf Info zurück.

Du hast da auch noch mehrere Instanzen im debug laufen? Kein Wunder, das die Kiste irgendwann dicht macht.
Stell die Adapter noch schweigsamer ein, wenn die stabil laufen. Meine laufen in der Regel auf 'Error' oder 'Warn'.