NEWS
[gelöst] Versuch Logdatei download führt zu Admin-Absturz
-
Seit einigen Tagen häufen sich die Fehleranzeigen in der Logdatei. Heute wollte ich mich an die Analyse setzen und die Logdatei über das Web-UI herunterladen, leider führte dies zum Absturz des Admin.
Über die Konsole war der Raspberry (Master) erreichbar und die ioB-Statusabfrage ergab
Connection is closed. Uncaught Rejection: Error: Objects DB is not allowed to start in the current Mul tihost environment at Redis.<anonymous> (file:///opt/iobroker/node_modules/@iobroker/db-objects -redis/build/esm/lib/objects/objectsInRedisClient.js:488:23) at process.processTicksAndRejections (node:internal/process/task_queues:95:5 ) Unable to subscribe to expiry Keyspace events from Redis Server: Connection is closed. Unable to subscribe to evicted Keyspace events from Redis Server: Connection is closed. Unable to subscribe to meta namespace "meta." changes: Connection is closed.
Daraufhin ioB diag ausgeführt (s. unten), die jetzt nach erster Durchsicht keine Auffälligkeiten aufwies (bin aber Laiin!), außer dem hier
- Adapter State
No connection to databases possible
Die erneut ausgeführte Statusabfrage ergab jetzt
supervisor@PI4Master:~ $ iob status iobroker is running on this host. Objects type: jsonl States type: jsonl
Seitdem bekomme ich zudem auch angezeigt, dass eine langsame Zugriffszeit erkannt wird. Das System (Master, 2 Slave, alle Raspberry Pi 4 auf SD) lief bis dahin stabil, ohne Fehler usw.
Diese Auffälligkeit war reproduzierbar, auch nachdem ich alle Raspis neu gestartet habe.
Hier die komplette Diagnose-Ausgabe:
- Adapter State
-
@maloross sagte in Versuch Logdatei download führt zu Admin-Absturz:
Pending OS-Updates: 73
seufz
Updaten. Vollständig auf allen Kisten.
Systemuptime and Load:
10:06:51 up 176 days, 22 min, 2 users, load average: 6.08, 6.08, 4.54
CPU threads: 4
Die Mühle ist mehr als ausgelastet.
Edit: Vermutlich von dem hm-rpc.1-Prozess
-
@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?
-
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. -
@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?
-
@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.
-
@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.
-
@maloross dann hat iob sich vorher nicht ordentlich abgemeldet.
Wahrscheinlich weil der pi abgestürzt war.
nochmal wahrscheinlich weil der RAM ausgeht -
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
-
@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. -
@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. -
@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
-
@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...
-
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?
-
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. -
@thomas-braun sagte in Versuch Logdatei download führt zu Admin-Absturz:
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? -
@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"
-
@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. -
@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
-
Und dann würde ich die Instanz auch nicht auf 'debug'-Level loggen lassen.