fhem.cfg verschwindet

[Hardy74]

Moin,

gestern habe ich logdb mit DbLogSelectionMode include eingerichtet. MariaDB läuft auf meinem NAS, die Funktion ist zur Zufriedenheit gegeben.
Fhem läuft seit Jahren auf einem Raspberry in einem Dockercontainer, ebenfalls zur Zufriedenheit.

Seit der Einrichtung von logdb ist fhem nun allerdings bereits 2x "ausgestiegen", meint: der Container versucht fhem neu zu starten, was nicht gelingt, da die fhem.cfg verschwunden ist.

Das erste Mal hier, warum auch immer wird ein Shutdown ausgeführt, der Container versucht fhem neu zu starten, was zunächst auch zu klappen scheint, einige Sekunden später enden jedoch die Logausgaben, 2h später habe ich den Container funktionslos mit fehlender fhem.cfg vorgefunden. Nach Wiederhestellung dieser funktionierte alles wieder. (Der Shelly Networkerror ist ok, der Shelly befindet sich derzeit nicht im Netzwerk).

Code Auswählen Erweitern

2025.10.27 13:02:06.062 0: Server shutdown
2025.10.27 13:02:06.070 1: Shutdown executed
2025.10.27 13:02:06.080 2: logdb - stopping SubProcess PID >19042< ...
2025.10.27 13:02:06.125 2: logdb - SubProcess PID >19042< stopped
2025.10.27 13:02:23.538 3: From the FHEM_GLOBALATTR environment: attr global logfile /var/log/fhem/fhem-%Y-%m-%d.log
2025.10.27 13:02:23.539 3: From the FHEM_GLOBALATTR environment: attr global updateInBackground 1
2025.10.27 13:02:23.539 3: From the FHEM_GLOBALATTR environment: attr global pidfilename /var/log/fhem/fhem.pid
2025.10.27 13:02:23.539 3: From the FHEM_GLOBALATTR environment: attr global nofork 0
2025.10.27 13:02:23.616 1: Including fhem.cfg
2025.10.27 13:02:26.907 2: logdb - Subprocess >28465< initialized ... ready for non-blocking operation
... diverse, übliche Logausgaben
2025.10.27 13:02:55.507 1: [Shelly_status] Device KellerTruhe has Error 'not connected (no route)', state is set to 'Error: Network'
2025.10.27 15:08:10.253 3: From the FHEM_GLOBALATTR environment: attr global nofork 0

Das zweite Mal dann heute Nacht. Nur das hier nach dem nicht gewollten Shutdown nichts mehr passierte. Die letzte Zeile ist die erste heute Morgen, nachdem ich die fhem.cfg wieder hergestellt hatte.

Code Auswählen Erweitern

2025.10.28 04:00:00.011 0: Server shutdown
2025.10.28 04:00:00.021 1: Shutdown executed
2025.10.28 04:00:00.042 2: logdb - stopping SubProcess PID >20830< ...
2025.10.28 04:00:00.058 2: logdb - SubProcess PID >20830< stopped
2025.10.28 09:51:32.592 3: From the FHEM_GLOBALATTR environment: attr global nofork 0

Die Fragen liegen auf der Hand:
Wieso wird ein shutdown ausgeführt?
Warum verschwindet die fhem.cfg?
Gibt es einen Zusammenhang zu logdb?

Grüße,
Hartwig

[rudolfkoenig]

Wieso wird ein shutdown ausgeführt?

Moegliche Ursachen:
- es wurde shutdown eingetippt oder per Web-/DOIF/etc ausgeloest
- Aenderung von attr global encoding
- das PIFACE Modul
- der fhem Process hat SIGTERM bekommen

In diesem Fall vermute ich Letzteres, und wuerde die Linux- bzw. docker-logs pruefen.

Warum verschwindet die fhem.cfg?

FHEM entfernt das nicht.
Wie wird die Datei dem Container bereitgestellt?

[Hardy74]

es wurde shutdown eingetippt oder per Web-/DOIF/etc ausgeloest

Auszuschließen. Außer dem logdb habe ich gestern nichts an fhem geändert.

Aenderung von attr global encoding

Habe ich nicht geändert.
Am 21.10. bekam ich diesen Fehler:

Code Auswählen Erweitern

2025.10.21 16:26:21.985 3: FHEMWEB WEB CSRF error: csrf_155612548227981 ne csrf_112449131892381 for client WEB_192.168.178.92_59977 / command {sunrise}. For details see the csrfToken FHEMWEB attribute.
und löste das durch den Tip in diesem Post https://forum.fhem.de/index.php?topic=119797.0 durch

Code Auswählen Erweitern

attr WEB CORS 0Das ist nun 7 Tage her und macht augenscheinlich keine Probleme.

das PIFACE Modul

Kenne ich nicht. Wenn das nicht durch logdb angezogen wird, würde ich auch das ausschließen.

der fhem Process hat SIGTERM bekommen
In diesem Fall vermute ich Letzteres, und wuerde die Linux- bzw. docker-logs pruefen.

Naheliegende Vermutung, die Systemlogs hatte ich zugegebener Maßen nicht geprüft. SIGTERM finde ich als Text nicht in den Logs, dafür gestern Nachmittag zur besagten Zeit das Folgende. NICHT aber heute Nacht! Weiterhin kommt der Dockerfehler exakt 2Sekunden nach der letzten Logausgabe im fhem log. These, gerne widerlegen: Warum der shutdown überhaupt kommt, sei ersteinmal dahingestellt. Jedoch wird beim Versuch des Startens von fhem die fhem.cfg zermörtelt. Danach findet sie Docker nicht mehr, was zu dem Fehler führt. Warum die fhem.cfg heute morgen wieder weg war, aber keine Fehler im syslog zu finden sind, ist ebenfalls spannend. 

Code Auswählen Erweitern

Oct 27 13:02:37 raspi2-2 dockerd[625]: time="2025-10-27T13:02:37.051366020+01:00" level=warning msg="Health check for container 919036fa11a41f6c195d139b5b1a4fc0aa21e35fb4ee67c7d24b02f9b67f6b17 error: context deadline exceeded"
Oct 27 13:02:57 raspi2-2 dockerd[625]: time="2025-10-27T13:02:57.076845907+01:00" level=error msg="stream copy error: reading from a closed fifo"
Oct 27 13:02:57 raspi2-2 dockerd[625]: time="2025-10-27T13:02:57.076854314+01:00" level=error msg="stream copy error: reading from a closed fifo"
Oct 27 13:02:57 raspi2-2 dockerd[625]: time="2025-10-27T13:02:57.077300120+01:00" level=warning msg="Health check for container 919036fa11a41f6c195d139b5b1a4fc0aa21e35fb4ee67c7d24b02f9b67f6b17 error: cannot exec in a stopped state: unknown"
Die Container ID gehört zum fhem Container. Da heute Nacht zur fraglichen Zeit kein Error im syslog zu finden ist, wird das ganze nun interessant.
Warum verschwindet eine Datei, wenn sie nicht proaktiv gelöscht wird? Da fällt mir nur ein. dass sie offen ist, in sie geschrieben wird und der Stream dann abbricht.

Wie wird die Datei dem Container bereitgestellt?

Der Ordner /var/opt/fhem ist auf mein NAS gemounted. Das funktioniert seit Jahren einwandfrei und hat den charmanten Vorteil, dass jegliche Änderung an fhem jede Nacht mitgesichert wird. Aufgrund dessen, würde ich dieses Setup als plötzliche Fehlerquelle ausschließen.
Einziger Haken an dem Setup: nach einem Stromausfall kommt fhem nicht alleine aus dem Quark, da ein NAS naturgemäß länger zum Booten benötigt als ein Raspi, das Mounten in diesem Fall dann schief geht.

Wie gesagt, die einzige Änderung gestern war das Hinzufügen von logdb in fhem und auf dem NAS das Installieren des MariaDB Packets in Verbindung mit dem Paket phpMyAdmin.

[rudolfkoenig]

Health check for container ... error: context deadline exceeded

Der Prozess im Container wird gestoppt, falls der Gesundheitscheck nicht ok liefert, die Voreinstellung fuer STOPSIGNAL ist SIGTERM.
Womoeglich hilft es die --health* Parameter fuer diesen Container anzupassen.

Zum Verschwinden der Datei habe ich keine Idee.
shutdown schreibt zwar log/fhem.state, aber nicht fhem.cfg

[Hardy74]

Moin,

den Grund für den Shutdown um 4Uhr habe ich gefunden:

Code Auswählen Erweitern

define ZyklRestart DOIF ([04:00]) (shutdown restart)Das hatte ich irgendwann mal eingebaut, da es gefühlt die Probleme mit HUE geworkaroundet hat. Das ist aber so lange her, dass ich es nicht mehr erinnerte. Meint: der Restart um 4Uhr hat bisher noch nie Probleme gemacht. Die Probleme treten erst jetzt, nach Implementierung von logdb auf. logdb schreibt beim shutdown ja ins log, vielleicht wird in dem Zuge auch die cfg durch logdb geöffnet und nicht wieder geschlossen?

Code Auswählen Erweitern

2025.10.30 04:00:00.042 2: logdb - stopping SubProcess PID >32576< ...
2025.10.30 04:00:00.058 2: logdb - SubProcess PID >32576< stopped

Irgendwas schreibt auch unregelmäßig in die fhem.cfg. Ich habe sie in Notepad++ auf und immer wieder fragt mich Notepad++, ob es die veränderte Datei neu laden soll. Ich werden beim nächsten Mal ein Diff machen, was sich denn geändert hat.

Gestern Nacht machte der Neustart keine Probleme, heute Nacht um 4Uhr ist die fhem.cfg wieder verschwunden, ohne Docker- oder sonstige Fehler. Ich werden das zyklische Restarten ersteinmal tot legen, was aber auch nur ein Pflasterkleben statt eines Fixing ist.

Grüße,
Hartwig

[rudolfkoenig]

vielleicht wird in dem Zuge auch die cfg durch logdb geöffnet und nicht wieder geschlossen?

Das sollte nicht notwendig sein, und das Oeffnen einer Datei fuehrt auch nicht zum Loeschen.
Damit die Datei weg ist, muss sie jemand explizit entfernt haben.

[Aurel_B]

Idee: vielleicht mit "auditctl" o.Ä. deine fhem.cfg überwachen und so herausfinden, welcher Prozess wann deine fhem.cfg löscht?

[Hardy74]

Das sollte nicht notwendig sein, und das Oeffnen einer Datei fuehrt auch nicht zum Loeschen

Bei Windowssystemen ist das eine steile These, ansonsten hätten ja auch Kiosksystem keine Existenzberechtigung, ebenso, wie hieß die Win Variant noch, die ausdrücklich nicht ins Dateinsystem schrieb, embedded? Zu lange her. Bei Linux kenne ich die Historie ehrlich gesagt nicht, Datei öffnen, während des Schreibens Stecker ziehen > wie sieht die Datei danach aus?
Ich würde ausschließen, dass jemand/etwas die Datei explizit löscht.

Letztlich ist dieses Problem auch "nur" ein Seiteneffekt des HUE-Problems. Ich musste fhem soeben händisch neu starten, da Events der HUE Bridge mal wieder nicht durchkamen (wen es interessiert: die motion Events kamen nicht, es kamen nur die nomotion Events -> Licht bleibt aus). Der Neustart klappte, nach dem Neustart von fhem kamen auch wieder alle Events der HUE Bridge bei fhem an.

Leider kümmert sich, nach Aussage von Rudolf, nicht unbedingt jemand mehr um die Probleme mit älteren Modul.