Umstellung auf DBLog - ständig Neustarts

[monkye]

Hallo Zusammen,
inzwischen bin ich leicht verzweifelt, weil ich nicht weiterkomme. Auf einem Raspi4 läuft FHEM. Hardwareseitig sieht es so aus:
- Raspberry Pi 4 2GB (bootet von 120GB SSD per USB-Adapter)
- RaspBee als Steckmodul drauf
- Signalduino (Arduino Mini mit USB und CC1101 433MHz)

Auf dem System läuft
- deConz autark zum Testen von ZigBee-Teilen
- ein MQTT Server
- ein Apache auf Port 8000 (für phpMyAdmin)
- MariaDB auf Port 3306 (für FHEM)

Sobald ich DBLog aktiviere, dann fliegt alle 10-20 Sekunden die Verbindung weg und FHEM startet neu. Ohne DBLog läuft es vor sich hin, erkennt die Temperatursensoren usw.

Die mariaDB wird erreicht von FHEM erreicht und läuft asynchron. Es landen Einträge in der History-Tabelle. Das kann ich auch sehen, wenn ich FHEM aus dem Verzeichnis direkt aufrufe, so wie im Wiki empfohlen zur Fehlersauch.

Die fhem.cfg ist fast leer, weil außer dem Signalduino noch nichts eingebunden/angesteckt ist.

Die CFG kann ich nachher hochladen, sobald ich daheim bin. Was wäre noch nötig damit Ihr helfen könnt?

[DS_Starter]

Ein Auszug aus deinem FHEM-Log kurz um den Zeitpunkt des Restarts herum hilft an der Stelle.
Vermutlich fehlt dir ein Perl-Modul, wobei ich mir momentan nicht vorstellen kann welches das sein sollte weil ich in der Zwischenzeit aber so gut wie alles abfange. Aber vllt. fehlt noch etwas und es fällt nur bei dir auf weil du noch so gut wie nichts eingebunden hast.

Edit: Natürlich setze ich ein aktuelles FHEM voraus !?

[monkye]

Also hier die zwei Protokolle.
Das erste "dblog-error.txt" ist mit "journalctl -u fhem -f" mitgeschrieben worden. Die zweite Datei  "dblog-error" ist mit dem Aufruf "perl fhem.pl fhem.cfg" aufgezeichnet worden.

[DS_Starter]

Ich wollte eigentlich mal einen Auszug aus dem FHEM-Log sehen. Links unten im FHEMWEB->Logfile bzw. aus /opt/fhem/log/<Logfile>

Sorry ist ja dabei ..

[DS_Starter]

Also ich kann keine Fehlermitteilungen sehen die sich auf DbLog beziehen.

Aber aufgefallen ist mir:

Code Auswählen Erweitern


define Logfile FileLog ./log/fhem-%Y-%m.log fakelog: Can't open ./log/fhem-2020-09.log: Permission denied

Es scheint prinzipielle Probleme mit den Schreibrechten auf BS Ebene zu geben.

Code Auswählen Erweitern


ZWDongle: Can't open /dev/serial0: Device or resource busy
CUL: Can't open /dev/ttyS0: Device or resource busy

Auch sicherlich nicht wie es sein soll..

So wie ich das sehe, wird dein FHEM ganz regulär durch den Linux systemd immer wieder restartet wegen einem timeout beim Start (in dblog-error 1.txt):

Sep 27 16:59:35 rpi4 perl[21280]: 2020.09.27 16:59:35 3: DbLog DBLogging - Creating Push-Handle to database mysql:database=fhem;host=localhost;port=3306 with user fhemuser
Sep 27 16:59:35 rpi4 perl[21280]: 2020.09.27 16:59:35 3: DbLog DBLogging - Push-Handle to db mysql:database=fhem;host=localhost;port=3306 created
Sep 27 16:59:35 rpi4 perl[21280]: 2020.09.27 16:59:35 3: DbLog DBLogging - UTF8 support enabled
Sep 27 17:00:03 rpi4 perl[21280]: 2020.09.27 17:00:03 3: telnetForBlockingFn_1601218803: port 44343 opened
Sep 27 17:00:33 rpi4 perl[21280]: 2020.09.27 17:00:33 4: sdinoCC1101: KeepAlive, ok, retry = 0
Sep 27 17:00:59 rpi4 systemd[1]: fhem.service: Start operation timed out. Terminating.
Sep 27 17:00:59 rpi4 perl[21280]: 2020.09.27 17:00:59 2: DbLog DBLogging - Last database write cycle due to shutdown ...
Sep 27 17:00:59 rpi4 perl[21280]: 2020.09.27 17:00:59 2: DbLog DBLogging - no data for last database write cycle
Sep 27 17:00:59 rpi4 perl[21280]: 2020.09.27 17:00:59 1: Server shutdown delayed due to DBLogging for max 10 sec
Sep 27 17:01:09 rpi4 perl[21280]: 2020.09.27 17:01:09 0: Server shutdown
Sep 27 17:01:09 rpi4 perl[21280]: 2020.09.27 17:01:09 5: sdinoCC1101: SimpleWrite, XQ
Sep 27 17:01:09 rpi4 systemd[1]: fhem.service: Failed with result 'timeout'.
Sep 27 17:01:09 rpi4 systemd[1]: Failed to start FHEM Home Automation.

Der systemd fährt nach 90 Sekunden nach dem Start deine System wieder runter weil es offensichtlich nicht korrekt gestartet werden kann.
Ich würde erstmal schauen dass du die oben genannten Dinge beseitigst.

Mehr sehe ich momentan nicht. Am DbLog-Modul liegt es jedenfalls nicht.
Vielleicht kann ein Linux Admin noch mehr Hinweise geben.

[monkye]

Code Auswählen Erweitern


define Logfile FileLog ./log/fhem-%Y-%m.log fakelog: Can't open ./log/fhem-2020-09.log: Permission denied

Es scheint prinzipielle Probleme mit den Schreibrechten auf BS Ebene zu geben.

OK, das kann ich schnell prüfen und ändern. Hat das ,,Fakelog" Auswirkungen auf das Verhalten z.B. bei Autocreate

Code Auswählen Erweitern


ZWDongle: Can't open /dev/serial0: Device or resource busy
CUL: Can't open /dev/ttyS0: Device or resource busy

Auch sicherlich nicht wie es sein soll..

Beim letzten Punkt weiß ich nicht wo das her ist - da ist kein CUL und auch kein Z-Wave Dongle dran.

Wenn ich die verplemperte Zeit anschaue... ist neu aufsetzen des gesamten Systems wahrscheinlich einfacher.

[monkye]

Bleibt bei Verwendung von DBLog das ,,Fakelog" immer auf Filelog? Das ist mir nicht ganz klar.

[monkye]

Code Auswählen Erweitern


pi@rpi4:~ $ ls /opt/fhem/log -al
insgesamt 628
drwxr-xr-x  2 fhem dialout   4096 Sep 23 19:22 .
drwxr-xr-x 10 fhem dialout   4096 Sep 27 18:20 ..
-rw-r--r--  1 fhem dialout   1634 Sep 27 18:23 eventTypes.txt
-rw-r--r--  1 fhem dialout   3533 Dez 24  2019 fhem-2019-12.log
-rw-r--r--  1 fhem dialout  29626 Aug 16 19:09 fhem-2020-08.log
-rw-r--r--  1 fhem dialout 550371 Sep 27 18:23 fhem-2020-09.log
-rw-r--r--  1 fhem dialout    763 Sep 27 18:23 fhem.save
-rw-r--r--  1 fhem dialout    331 Sep 23 19:22 GT_WT_02_149-2020.log
-rw-r--r--  1 fhem dialout    331 Sep 23 19:23 GT_WT_02_228-2020.log
-rw-r--r--  1 fhem dialout    897 Sep 23 19:24 SD_WS_51_TH_1-2020.log
-rw-r--r--  1 fhem dialout   3798 Sep 23 19:15 SIGNALduino-Flash.log
-rw-r--r--  1 fhem dialout    616 Sep 23 19:20 TCM218943_112-2020.log
-rw-r--r--  1 fhem dialout     45 Sep 23 19:22 Unknown-2020.log
-rw-r--r--  1 fhem dialout   2271 Sep 23 19:38 W044_214-2020.log


Warum der Zugriff nicht geht...keine Ahnung.

Code Auswählen Erweitern


pi@rpi4:~ $ id fhem
uid=999(fhem) gid=20(dialout) Gruppen=20(dialout)


[DS_Starter]

Das Fakelog bezieht sich auf dein normales FHEM-Log. Das hat mit DbLog nichts zu tun, da DbLog wie auch FileLog die Events des Systems behandelt.
Das FHEM-Log sind Systemmeldungen die durch Modulautoren mit den verbose Leveln geschrieben werden.

Bleibt also so.

[monkye]

Hab' jetzt auf die schnelle FHEM entfernt und neu installiert. Jetzt geht erstmal alles ohne Neustart. Die Rechteprobleme sind auch nicht mehr aufgetaucht. Die Abstürze hängen eindeutig damit jedoch nicht zusammen, diese kamen vom Signalduino. Keine Ahnung wie der zu dieser Situation beigetragen hat. Habe ein anderen Signalduino genommen und es ging wie erwartet.

Nochmal zur Klarstellung: "Fakelog" kann ich in der fhem.cfg stehen lassen, wenn ich DBLog verwenden will (braucht halt das Web-Frontend). Was ist mit autocreate, muss das raus? Die Umstellung auf ConfigDB ist dann der zweite Schritt.

[DS_Starter]

Nochmal zur Klarstellung: "Fakelog" kann ich in der fhem.cfg stehen lassen, wenn ich DBLog verwenden will

Ja, siehe oben. Das eine hat mit dem anderen nichts zu tun.
Der Begriff "kann ich in der fhem.cfg stehen lassen" suggeriert dass du in der fhem.cfg editierst.
Gerade als Anfänger sollte man das nicht tun und alle Änderungen über das FHEMWEB ausführen. Die fhem.cfg zu editieren ist im Normalfall völlig unnötig und birgt die Risiken sich undurchsichtige Fehler ins System zu holen.

Was ist mit autocreate, muss das raus?

Nein, muss nicht. Es ist ist vielen Fällen sehr hilfreich.

[Wernieman]

Ich hätte mal im kern-log des Systemes geschaut. Es hört sich (für mich) danach an, das Du den USB-Scan in FHEM aktiviert hast. Dadurch eventuell USB (bzw. die Platte) ein Problem bekommen, wodurch ....

[monkye]

Ich hätte mal im kern-log des Systemes geschaut. Es hört sich (für mich) danach an, das Du den USB-Scan in FHEM aktiviert hast. Dadurch eventuell USB (bzw. die Platte) ein Problem bekommen, wodurch ....

Ja OK, das Argument könnte passen. Aber es ist nur FHEM neu gestartet, nicht der RasPi. Und ohne den (komischen) Signalduino am USB-Port gab es auch keine Abstürze. Denn bis letzte Woche hab ich den RPi4 nur für MQTT, SQL und deConz verwendet.

Ich hätte mal im kern-log des Systemes geschaut. Es hört sich (für mich) danach an, das Du den USB-Scan in FHEM aktiviert hast. Dadurch eventuell USB (bzw. die Platte) ein Problem bekommen, wodurch ....

Stimmt, das mache ich direkt in der Datei und lege intakte Versionen zur Seite.

Ehrlich gesagt finde ich eine CFG-Datei unübersichtlich, wenn diese 1-2 Jahre alt sind und automatisch bzw. per Frontend ,,betankt" wurde. Vielleicht gibt es ja gute Tools zum strukturieren. Gerade wenn viele gleichartige Devices angelegt und zugeordnet werden sollen oder Technikwechsel ansteht.
Und alle preiswerten Sensoren ballern nach dem ,,ungesteuerten" Batteriewechsel (,,Die Anzeige war so schwach...") erstmal los und dann landet etwas in der CFG, was vorher unter anderer Kennung schon einmal da war. Aber hier habe ich bzgl. des Handlings sicher noch Potenzial

Mir ging es mit meinen Fragen nach den LOG-Files vor allem darum, nicht halbgar umzusteigen. Das konnte ich aus den Doku's und google nicht klar erkennen. Vor allem, weil ich beim Versuch die mariaDB auf den asynchronen Modus umstellen wollte, erstmal Fehlermeldungen bekam...

[Wernieman]

Ich habe nicht gesagt, das der Pi restartet. Es könnte aber erklären, warum FHEM kein logfile schreiben konnte ....

Hast DU noch ein kern.log von der Zeit? Kannst ja dann nach i/o Problemen greppen:

Code Auswählen Erweitern

grep -i i/o <Dein-Kern-log>

[monkye]

Ich habe nicht gesagt, das der Pi restartet. Es könnte aber erklären, warum FHEM kein logfile schreiben konnte ....

Hast DU noch ein kern.log von der Zeit? Kannst ja dann nach i/o Problemen greppen:

Code Auswählen Erweitern

grep -i i/o <Dein-Kern-log>

Ahhh, verstehe. Wegen dem Protokoll: Muss ich morgen früh schauen ob das noch nutzbar ist. Danke für den ,,Wink", manchmal braucht's einen Moment.