Fhem aus Raspi: alle 90 Sekunden ein shutdown / restart

Begonnen von Rainer_G, 05 Oktober 2021, 00:01:21

Vorheriges Thema - Nächstes Thema

Rainer_G

Vor ca. 3 Wochen begann sich der Fhem Server auf meinem Raspi alle 90 Sekunden zu zurückzusetzen.
Aus dem log war die Ursache nicht zu entnehmen.
Die Events kurz vor den Server shutdown sind zufällig und scheinen mit dem shutdown nicht zusammen zu hängen.

2021.10.04 23:42:27 0: Server shutdown
2021.10.04 23:42:28 1: Shutdown executed
2021.10.04 23:42:28 3: telnetPort: port 7072 opened
2021.10.04 23:42:29 3: WEB: port 8083 opened
2021.10.04 23:42:29 3: WEBphone: port 8084 opened
2021.10.04 23:42:29 3: WEBtablet: port 8085 opened
2021.10.04 23:42:29 3: WEB: creating device allowed_WEB for attribute basicAuth WEBphone: creating device allowed_WEBphone for attribute basicAuth WEBtablet: creating device allowed_WEBtablet for attribute basicAuth
2021.10.04 23:42:29 3: Opening CUL_1 device /dev/ttyACM1
2021.10.04 23:42:29 3: Setting CUL_1 serial parameters to 38400,8,N,1
2021.10.04 23:42:30 3: CUL_1: Possible commands: ABbCeFGhiKkLlMmNRTtUuVWXxYZ
2021.10.04 23:42:30 3: CUL_1 device opened
2021.10.04 23:42:30 2: Switched CUL_1 rfmode to HomeMatic
2021.10.04 23:42:30 3: Opening CUL_0 device /dev/ttyACM0
2021.10.04 23:42:30 3: Setting CUL_0 serial parameters to 38400,8,N,1
2021.10.04 23:42:30 3: CUL_0: Possible commands: BbCFiAZNkGMKUYRTVWXefmLltux
2021.10.04 23:42:30 3: CUL_0 device opened
2021.10.04 23:42:30 2: eventTypes: loaded 769 events from ./log/eventTypes.txt
2021.10.04 23:42:31 1: PERL WARNING: Use of uninitialized value $m in int at ./FHEM/10_CUL_HM.pm line 9373.
2021.10.04 23:42:31 3: Device broadcast added to ActionDetector with 030:00 time
2021.10.04 23:42:31 3: Device kiHeater added to ActionDetector with 000:10 time
2021.10.04 23:42:31 3: Device ubHeater added to ActionDetector with 000:10 time
2021.10.04 23:42:31 3: WARNING master device kiHeater_Clima has no week profile - create default
2021.10.04 23:42:31 3: Opening myBroker device 127.0.0.1:1883
2021.10.04 23:42:31 3: myBroker device opened
2021.10.04 23:42:31 3: WARNING master device ubHeater_Clima has no week profile - create default
2021.10.04 23:42:31 0: Featurelevel: 6
2021.10.04 23:42:31 0: Server started with 214 defined entities (fhem.pl:22408/2020-07-16 perl:5.028001 os:linux user:fhem pid:15319)
2021.10.04 23:42:45 3: CUL_HM set kiHeater getConfig
2021.10.04 23:42:45 3: WARNING master device kiHeater_Clima has no week profile - create default
2021.10.04 23:43:58 0: Server shutdown
2021.10.04 23:43:58 1: Shutdown executed

Es scheint asynchron zu den irgendwelchen Aktivitäten im Fhem zu passieren.
Gibt es eine systematische Methode, die Ursache hierfür herauszufinden ?
Der Raspi läuft vollkommen stabil.
Diese Fhem Konfiguration lieft bis vor 3 Wochen ebenfalls stabil.
Es laufen keinerlei Chron Jobs auf dem Raspi.

Mein Config:
1 CUL Stick für das FS20 Protokoll ( 3 FHT 80 B)
1 CUL Stick für Homeatic ( 2 x HM-CC-RT-DN )
MQTT Broker ( viele Sonoff Schalter )

Sowohl Fhem, als auch das Raspi OS sind auf dem neusten Stand.

Die Hinweise in einem gleichlautenden Thread habe ich alle schon ausprobiert.
Ich wäre für jeden Tipp dankbar !!!

Beta-User

Würde auf systemd tippen, der nicht mitbekommt, dass FHEM stressfrei läuft und glaubt, dass es abgeschmiert ist. Wie ist denn der restart-timeout in der fhem.service?
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

Otto123

Siehe auch hier https://wiki.fhem.de/wiki/Fhem.service_(systemd_unit_file)#Restart_verz.C3.B6gern

Aber 90 sec ? Das kann kein Zufall sein. Da läuft entweder ein watchdog oder oder etwas blockiert solange?
Zumal er schmiert nicht ab, er macht ordentlich shutdown  ::)
Viele Grüße aus Leipzig  ⇉  nächster Stammtisch an der Lindennaundorfer Mühle
RaspberryPi B B+ B2 B3 B3+ ZeroW,HMLAN,HMUART,Homematic,Fritz!Box 7590,WRT3200ACS-OpenWrt,Sonos,VU+,Arduino nano,ESP8266,MQTT,Zigbee,deconz

betateilchen

Zitat von: Beta-User am 05 Oktober 2021, 07:18:33
Würde auf systemd tippen, der nicht mitbekommt, dass FHEM stressfrei läuft

Hinweise darauf würde man zumindest im syslog finden.
-----------------------
Formuliere die Aufgabe möglichst einfach und
setze die Lösung richtig um - dann wird es auch funktionieren.
-----------------------
Lesen gefährdet die Unwissenheit!

Rainer_G

Hallo Beta-User, Otto123 und betateilchen,
vielen Dank für die schnellen Antworten.
Dass die 90 Sekunden auf einen nicht getriggerten Watchdog hinweisen kam mir auch schon in den Sinn.
Leider kenne ich Linux zu wenig, um zu wissen, welcher WD von Fehm möglicherweise nicht getriggert wird.
Jetzt meine Anfänger Fragen:
@Beta-User: Wie teilt Fhem systemd mit, dass es stressfrei läuft ?
@betateilchen: Wo finde ich das syslog ?

Ich habe auch schon versucht, Fhem neu zu installieren, wonach der 90 sekündige reset tatsächlich ausbleibt.
Dann habe ich mein fhem.cfg sukkzessive auskommentiert, um evtl. das device einzukreisen, das das Problem verursacht.
Ebenfalls habe ich festgestellt, dass es einen Unterschied macht, ob ich fhem.cfg via FTP auf meinen Raspi kopiere, oder via Fhem GUI mit Copy/Paste einfüge.

Aber einen eindeutigen fhem.cfg Zustand, ab dem der zyklische Reset ausbleibt, ließ sich bisher nicht ausmachen.
Das spricht dafür, dass das OS von Außen Fhem immer wieder neu startet.

Ich probiere mittlerweile seit Wochen mit trial und error herum und möchte nun stattdessen auf diesem Wege
von Euch Experten ein bischen mehr über Linux lernen und so dem Problem systematisch zu Leibe rücken.

Es ist sehr schwierig, via Google hier die wertvolle Info aus dem Strom von weniger zielführenden Kommentaren herauszufiltern.
Im Voraus vielen Dank für jede Form der Hilfestellung !

Beta-User

Linux-Konsole. Habe aber kein RaspiOS, bei Debian zeigt z.B.
sudo grep fhem /var/log/syslog
an, was über "fhem" im heutigen syslog steht. Steht in der Datei nichts, wurde FHEM jedenfalls nicht von systemd neu gestartet.

cfg-Editieren ist "Bäh" und möglicherweise mit die Ursache für dein Problem. Am besten mit "leerer" fhem.cfg (also der svn-Version) starten und dann über das Web-Frontend (das "grüne Plus") dazubauen. Nur CUL_HM-Geräte (und vorher die zugehörigen Interfaces sollte man per direktem Edit in der cfg lassen. Dazu bitte aber am besten einen Linux-kompatiblen Editor nutzen. Meine Empfehlung: via ssh mc nutzen.
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

Wernieman

Du kannst doch Gerät auch über "Raw" in die fhem.cfg pushen?
- Bitte um Input für Output
- When there is a Shell, there is a Way
- Wann war Dein letztes Backup?

Wie man Fragen stellt: https://tty1.net/smart-questions_de.html

betateilchen

Zitat von: Beta-User am 06 Oktober 2021, 06:57:09
Habe aber kein RaspiOS, bei Debian zeigt z.B.

RaspiOS basiert auf Debian und hieß früher deshalb auch Raspbian.

Nach Einträgen von systemd sollte man auch in /var/log/daemon.log suchen, falls in /var/log/syslog nichts zu finden ist.


-----------------------
Formuliere die Aufgabe möglichst einfach und
setze die Lösung richtig um - dann wird es auch funktionieren.
-----------------------
Lesen gefährdet die Unwissenheit!

Rainer_G

Hallo Betateilchen,
vielen Dank für den Tipp !
War leider die letzten Tage verhindert und kann jetzt erst antworten.
Das Kommando
root@raspberrypi:/opt# grep fhem /var/log/syslog   
zeigt, dass fhem tatsächlich in ein Start Timeout läuft und den service terminiert.

Hier nur ein kleiner Ausschnitt der sich im 90 sekündigen Takt wiederholenden 5 Zeilen:

Oct  8 19:58:37 raspberrypi perl[15429]: 2021.10.08 19:58:37 1: Including fhem.cfg
Oct  8 20:00:07 raspberrypi systemd[1]: fhem.service: Start operation timed out. Terminating.
Oct  8 20:00:07 raspberrypi systemd[1]: fhem.service: Failed with result 'timeout'.
Oct  8 20:00:07 raspberrypi systemd[1]: fhem.service: Service RestartSec=100ms expired, scheduling restart.
Oct  8 20:00:07 raspberrypi systemd[1]: fhem.service: Scheduled restart job, restart counter is at 7440.
Oct  8 20:00:08 raspberrypi perl[15467]: 2021.10.08 20:00:08 1: Including fhem.cfg
Oct  8 20:01:37 raspberrypi systemd[1]: fhem.service: Start operation timed out. Terminating.
Oct  8 20:01:38 raspberrypi systemd[1]: fhem.service: Failed with result 'timeout'.
Oct  8 20:01:38 raspberrypi systemd[1]: fhem.service: Service RestartSec=100ms expired, scheduling restart.
Oct  8 20:01:38 raspberrypi systemd[1]: fhem.service: Scheduled restart job, restart counter is at 7441.
Oct  8 20:01:38 raspberrypi perl[15474]: 2021.10.08 20:01:38 1: Including fhem.cfg
Oct  8 20:03:08 raspberrypi systemd[1]: fhem.service: Start operation timed out. Terminating.
Oct  8 20:03:08 raspberrypi systemd[1]: fhem.service: Failed with result 'timeout'.
Oct  8 20:03:08 raspberrypi systemd[1]: fhem.service: Service RestartSec=100ms expired, scheduling restart.
Oct  8 20:03:08 raspberrypi systemd[1]: fhem.service: Scheduled restart job, restart counter is at 7442.
Oct  8 20:03:09 raspberrypi perl[15523]: 2021.10.08 20:03:09 1: Including fhem.cfg
Oct  8 20:04:38 raspberrypi systemd[1]: fhem.service: Start operation timed out. Terminating.
Oct  8 20:04:39 raspberrypi systemd[1]: fhem.service: Failed with result 'timeout'.
Oct  8 20:04:39 raspberrypi systemd[1]: fhem.service: Service RestartSec=100ms expired, scheduling restart.
Oct  8 20:04:39 raspberrypi systemd[1]: fhem.service: Scheduled restart job, restart counter is at 7443.
Oct  8 20:04:39 raspberrypi perl[15534]: 2021.10.08 20:04:39 1: Including fhem.cfg
Oct  8 20:06:09 raspberrypi systemd[1]: fhem.service: Start operation timed out. Terminating.
Oct  8 20:06:09 raspberrypi systemd[1]: fhem.service: Failed with result 'timeout'.
Oct  8 20:06:09 raspberrypi systemd[1]: fhem.service: Service RestartSec=100ms expired, scheduling restart.
Oct  8 20:06:09 raspberrypi systemd[1]: fhem.service: Scheduled restart job, restart counter is at 7444.
Oct  8 20:06:10 raspberrypi perl[15544]: 2021.10.08 20:06:10 1: Including fhem.cfg
Oct  8 20:07:39 raspberrypi systemd[1]: fhem.service: Start operation timed out. Terminating.
Oct  8 20:07:40 raspberrypi systemd[1]: fhem.service: Failed with result 'timeout'.
Oct  8 20:07:40 raspberrypi systemd[1]: fhem.service: Service RestartSec=100ms expired, scheduling restart.
Oct  8 20:07:40 raspberrypi systemd[1]: fhem.service: Scheduled restart job, restart counter is at 7445.
Oct  8 20:07:40 raspberrypi perl[15562]: 2021.10.08 20:07:40 1: Including fhem.cfg

Die Frage ist jetzt nur: Womit kann ich den Timeout wieder aufziehen ?
Soll ich mein fhem.cfg mal posten ?
Ist ziemlich länglich  :-\


Rainer_G

PS:
grep fhem /var/log/daemon.log
klappt auch, zeigt aber das gleiche an.

Rainer_G

#10
Ich habe jetzt mal gemäss anderer Tipps in anderen Chats in der Fhem service config den Parameter Type von forking auf simple umgestellt:

Kommando: sudo systemctl edit --full fhem.service

File Inhalt:


# $Id: fhem.service 19235 2019-04-21 13:26:17Z betateilchen $

[Unit]
Description=FHEM Home Automation
Wants=network.target
After=network.target
#Requires=postgresql.service
#After=postgresql.service
#Requires=mysql.service
#After=mysql.service

[Service]
Type=simple (vorher forking)
User=fhem
Group=dialout
WorkingDirectory=/opt/fhem
ExecStart=/usr/bin/perl fhem.pl fhem.cfg
#ExecStart=/usr/bin/perl fhem.pl configDB
Restart=always
ExecStartPre=/bin/sleep 10

[Install]
WantedBy=multi-user.target


Jetzt läuft Fhem wieder durch !!!!

Frage: Was bedeutet Type=forking ?




Otto123

Hi,

kannst Du hier nachlesen:
https://www.freedesktop.org/software/systemd/man/systemd.service.html

Das ist aber schon nicht die Original unit Datei, da hast Du schon eine Verzögerung eingebaut. Was war der Grund?

Gruß Otto
Viele Grüße aus Leipzig  ⇉  nächster Stammtisch an der Lindennaundorfer Mühle
RaspberryPi B B+ B2 B3 B3+ ZeroW,HMLAN,HMUART,Homematic,Fritz!Box 7590,WRT3200ACS-OpenWrt,Sonos,VU+,Arduino nano,ESP8266,MQTT,Zigbee,deconz

Rainer_G

#12
Hi Otto123,

danke für den Hinweis !
Stimmt, hab ich vergessen wieder auszukommentieren.
Ich probiere alles aus, was ich in diversen chats so finde.
Das war einer von vielen Tipps.

Ich habs gerade wieder auskommentiert und Fhem läuft immer noch rund  ;D

Rainer_G

#13
ich hab mir Deinen Link mal durchgelesen und folgendes gefunden (rot):


Configures the process start-up type for this service unit. One of simple, exec, forking, oneshot, dbus, notify or idle:
.....
If set to forking, it is expected that the process configured with ExecStart= will call fork() as part of its start-up. The parent process is expected to exit when start-up is complete and all communication channels are set up. The child continues to run as the main service process, and the service manager will consider the unit started when the parent process exits. This is the behavior of traditional UNIX services. If this setting is used, it is recommended to also use the PIDFile= option, so that systemd can reliably identify the main process of the service. systemd will proceed with starting follow-up units as soon as the parent process exits.


Wie und wo setzte ich denn die PIDFile Option ein ?
Welchen der obigen Type values würdest Du denn empfehlen und warum ?

Übrigens, danke für Deine Hilfe !!!!

Otto123

Moin,

tut mir leid, damit habe ich mich noch nicht beschäftigt. Bisher habe ich nur mit diversen Verzögerungen, Abhängigkeit von anderen Diensten und dem Start von "Vorbereitungen für bestimmte Hardware" von FHEM befasst und das hier im Wiki aufgeschrieben.
Vielleicht kann betateilchen was dazu sagen, der hat den systemd Startprozess von FHEM designed.
Ich habe keine Idee woher die 90 sec kommen. Jetzt wo FHEM durchläuft könntest Du mal freezemon definieren und schauen ob da was passiert.

Gruß Otto
Viele Grüße aus Leipzig  ⇉  nächster Stammtisch an der Lindennaundorfer Mühle
RaspberryPi B B+ B2 B3 B3+ ZeroW,HMLAN,HMUART,Homematic,Fritz!Box 7590,WRT3200ACS-OpenWrt,Sonos,VU+,Arduino nano,ESP8266,MQTT,Zigbee,deconz