[erledigt] krieg fhem unter buster nicht zum starten

[Otto123]

naja wir sind schon zu zweit, nehmen wir mal an es liegt nicht an uns. Ich habe verschiedene System mit verschiedenen OS Versionen. Ich schau heute abend mal welches sich wie verhält.

[the ratman]

o.k.
dann mein zeugs, damitst vielleicht vergleichen kannst:

beide systeme liegen auf win10 auf einer oracle 6.1.x vm und sind von seiten der vm 100% gleich eingerichtet.
keines der beiden debians hat zugriff auf usb, mein echtsystem lebt von geräten im lan. wlan und bt gibts nicht für beide.
win10 64bit, oracle, die beiden debians (auch 64bit) und auch fhem sind tagesaktuell.
echtsystem rennt unter stretch und mein testsystem unter buster

was ich alles an stretch verbrochen hab das letzte jahr ... keine ahnung, aber gehen ma davon aus, dass ein echter linuxer wein- und schreikrämpfe kriegen würd *g*
buster ist tatsächlich "unverpfuscht". nach der 08/15 automatischen installation sind lediglich fhem, webmin und perl-module (die selben wie bei stretch) drauf gekommen bis jetzt.

fhem auf buster ist ebenfalls fast neuwertig. da ist bis jetzt nur flex als oberfläche drauf und im global ein bissi was vom echtsystem abgetippt:

Code Auswählen Erweitern

attr global autoload_undefined_devices 1
attr global autosave 0
attr global commandref modular
attr global dnsServer 192.168.178.1
attr global language DE
attr global logfile ./log/fhem-%Y-%m.log
attr global modpath .
attr global nrarchive 1
attr global stacktrace 1
attr global statefile ./log/fhem.save
attr global updateInBackground 1

und nur zur sicherheit:
strech = 0 probleme
buster = 2 * restart

falls ich dir irgendwie helfen kann ... sags. aber immer dran denken: ich bin nicht grade in der pro liga in sachen pinguine!

[Otto123]

mir ist das Fenster auch näher als der Pinguin - aber ich verbringe mittlerweile Zeit mit dem Schwimmvogel

[the ratman]

ja, so teilt sich die welt auf ... in masochisten und idioten 

[Otto123]

Der masochist ist nicht ganz sicher:
Ich meine, es tritt nur mit systemd auf. Man kann das Script anschauen mit {qx(cat /etc/systemd/system/fhem.service)}
Es hat mMn nicht wirklich mit dem OS zu tun (kann man mit {qx(cat /etc/os-release)} anzeigen) Ich habe mit stretch und buster auf einem raspberry getestet. Der Pi2 lief schon eine Weile, den Pi3 hab ich ganz neu installiert!
Bei meinem Pi2 (stretch) ging es offenbar mit dem update weg
Anzeige mit

Code Auswählen Erweitern

{qx(grep "0: Server " $currlogfile)}

2020.04.19 14:15:52 0: Server started with 21 defined entities (fhem.pl:21661/2020-04-13 perl:5.024001 os:linux user:fhem pid:28398)
2020.04.19 14:15:52 0: Server shutdown
2020.04.19 14:15:55 0: Server started with 21 defined entities (fhem.pl:21661/2020-04-13 perl:5.024001 os:linux user:fhem pid:28401)
2020.04.21 20:54:20 0: Server shutdown
2020.04.21 20:54:23 0: Server started with 21 defined entities (fhem.pl:21724/2020-04-19 perl:5.024001 os:linux user:fhem pid:4831)

Ich kann es dort nicht mehr provozieren.
Auf meinem Pi3+ tritt es dauerhaft auf, auch die definition von 100 dummies hat es nicht geändert (damit die cfg etwas länger ist)

Code Auswählen Erweitern

{for(my $i = 1;; $i <= 100;; $i++) {fhem("define ddd$i dummy")}}

2020.04.23 20:42:58 0: Server shutdown
2020.04.23 20:42:59 0: Server started with 6 defined entities (fhem.pl:21724/2020-04-19 perl:5.028001 os:linux user:fhem pid:11453)
2020.04.23 20:42:59 0: Server shutdown
2020.04.23 20:43:01 0: Server started with 6 defined entities (fhem.pl:21724/2020-04-19 perl:5.028001 os:linux user:fhem pid:11455)
2020.04.23 20:46:27 0: Server shutdown
2020.04.23 20:46:28 0: Server started with 106 defined entities (fhem.pl:21724/2020-04-19 perl:5.028001 os:linux user:fhem pid:11461)
2020.04.23 20:46:29 0: Server shutdown
2020.04.23 20:46:30 0: Server started with 106 defined entities (fhem.pl:21724/2020-04-19 perl:5.028001 os:linux user:fhem pid:11463)

Ich habe dann mal im unit File eine Verzögerung 3 sec eingebaut, nach dem Restart Befehl den Eintrag RestartSec hinzugefügt.

Code Auswählen Erweitern

Restart=always
RestartSec=3
Diese Änderung muss man "aktivieren"

Code Auswählen Erweitern

sudo systemctl daemon-reload
sudo systemctl restart fhem

Danach tritt dieser doppelte Start nicht mehr auf. Mach ich die Verzögerung raus ist er wieder da.

Bin ich jetzt schlauer?

Btw: restart ist scheinbar nunmehr völlig obsolet. Wenn ich den Restart Eintrag in der unit Datei entferne, dann verschwindet fhem auch bei einem shutdown restart

[MadMax-FHEM]

Schon mal restart on failure versucht!?

Gruß, Joachim

[Otto123]

Nö - ich habe mal noch FHEM Log und journalctl untereinander kopiert:

Code Auswählen Erweitern

{qx(grep "0: Server " $currlogfile)}

journalctl -u fhem.service

Apr 23 20:46:27 raspib3plus systemd[1]: fhem.service: Succeeded.
Apr 23 20:46:27 raspib3plus systemd[1]: fhem.service: Service RestartSec=100ms expired, scheduling restart.
Apr 23 20:46:27 raspib3plus systemd[1]: fhem.service: Scheduled restart job, restart counter is at 3.
Apr 23 20:46:27 raspib3plus systemd[1]: Stopped FHEM Home Automation.
Apr 23 20:46:27 raspib3plus systemd[1]: Starting FHEM Home Automation...
Apr 23 20:46:28 raspib3plus systemd[1]: Started FHEM Home Automation.
Apr 23 20:46:29 raspib3plus systemd[1]: fhem.service: Succeeded.
Apr 23 20:46:29 raspib3plus systemd[1]: fhem.service: Service RestartSec=100ms expired, scheduling restart.
Apr 23 20:46:29 raspib3plus systemd[1]: fhem.service: Scheduled restart job, restart counter is at 4.
Apr 23 20:46:29 raspib3plus systemd[1]: Stopped FHEM Home Automation.
Apr 23 20:46:29 raspib3plus systemd[1]: Starting FHEM Home Automation...
Apr 23 20:46:29 raspib3plus systemd[1]: Started FHEM Home Automation.

2020.04.23 20:46:27 0: Server shutdown
2020.04.23 20:46:28 0: Server started with 106 defined entities (fhem.pl:21724/2020-04-19 perl:5.028001 os:linux user:fhem pid:11461)
2020.04.23 20:46:29 0: Server shutdown
2020.04.23 20:46:30 0: Server started with 106 defined entities (fhem.pl:21724/2020-04-19 perl:5.028001 os:linux user:fhem pid:11463)


Apr 23 20:52:37 raspib3plus systemd[1]: fhem.service: Succeeded.
Apr 23 20:52:40 raspib3plus systemd[1]: fhem.service: Service RestartSec=3s expired, scheduling restart.
Apr 23 20:52:40 raspib3plus systemd[1]: fhem.service: Scheduled restart job, restart counter is at 2.
Apr 23 20:52:40 raspib3plus systemd[1]: Stopped FHEM Home Automation.
Apr 23 20:52:40 raspib3plus systemd[1]: Starting FHEM Home Automation...
Apr 23 20:52:41 raspib3plus systemd[1]: Started FHEM Home Automation.

2020.04.23 20:52:37 0: Server shutdown
2020.04.23 20:52:41 0: Server started with 106 defined entities (fhem.pl:21724/2020-04-19 perl:5.028001 os:linux user:fhem


Verstehen tu ichs nicht, vielleicht weiß Werner was dazu? Ich meine man sieht der default Wert RestartSec=100ms ist offenbar zu wenig, obwohl alle Einträge logisch aufeinander folgen. Irgendwer startet dann gleich nochmal neu. Wahrscheinlich der erste Service RestartSec=100ms expired, scheduling restart.

Erstmal Gute Nacht
Otto

[Wernieman]

Mhhh ... guuute Frage.

Scheinbar erkennt Systemd nicht, das fhem schon läuft .... eventuell braucht fhem zu lange zu dem Zeitpunkt? Kannst Du andere Dependencies einschalten?

Habe keine aktuelle systemd config hier, könntest Du mir bitte Deine aktuelle geben?

[Otto123]

Die Originale

Code Auswählen Erweitern

# $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=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

[Install]
WantedBy=multi-user.target

Wo kann ich noch nachschauen was da genau abläuft? Es sieht ja so aus als ob systemd mitbekommt: "fhem ist down" schnell neu starten und dann kommt nochmal die gleiche Erkenntnis. Oder fhem schickt zweimal den "shutdown"

[Wernieman]

Du könntest noch probieren, an folgenden zu drehen:

After=network.target

Also einen anderen dazuzuschreiben. Mir fällt nur aktuell keiner ein ....

[frank]

interessant wäre vielleicht die anzeige von millisekunden im syslog. keine ahnung, ob das geht.

ich finde, dass der "restart counter" im syslog seltsam zählt.
warum fängt der zb bei 2 an, wenn RestartSec=3s ist und scheinbar alles normal läuft?

[Otto123]

Das lag eventuell an der Vorgeschichte, ich habe ja nur ein Stück des Logs gepostet und viel probiert
Die Bedeutung

Note that this really only counts automatic starts triggered by Restart=
(which it nicely complements). Manual restarts will reset the counter,
as will explicit calls to "systemctl reset-failed". It's supposed to be
a tool for measure the automatic restart feature, and nothing else.

Er wird also immer durch einen manuellen restart zurückgesetzt.
Man kann ihn auch abfragen

Code Auswählen Erweitern

systemctl show fhem.service -p NRestarts

[Otto123]

@ratman Ich denke mit dem Beitrag habe ich Dich verloren - aber vielleicht wird es ja wieder

Ich habe mich noch in fhem.pl umgesehen und an die Anfänge von "Start fhem mit systemd" erinnert. Da gab es mal diesen Beitrag
https://forum.fhem.de/index.php?topic=25706.0

Ich will da jetzt keine Diskussion lostreten was richtig und falsch ist, ich bin da viel zu unterbelichtet. Ich meine aber mal gelesen zu haben, das man Scripts als Type  oneshot starten sollte. Auf alle Fälle so wie im Link mit oneshot und RemainAfterExit klappt auch shutdown restart wieder

2020.04.24 10:18:12 0: Server shutdown
2020.04.24 10:18:15 0: Server started with 106 defined entities (fhem.pl:21724/2020-04-19 perl:5.028001 os:linux user:fhem pid:14542)

Und wenn man aufmerksam schaut liegen 3 sec dazwischen und nicht nur 1 sec was sicher etwas mit dem Code in der fhem.pl AttrVal("global", "restartDelay", 2) und dem dortigen default Wert zu tun hat.
Ich kann jetzt nicht einschätzen was Type forking vs oneshot für den Betrieb bedeutet.
Ich würde vorsichtig sagen: RestartSec=2 wäre eine minimal invasive, saubere Lösung für den jetzt etablierten systemd Start. Allerdings nach wie vor mit dem quasi immer gesetzten Parameter "restart" beim shutdown Befehl von FHEM.
Ich will mich eigentlich nicht in Startprozess von FHEM einmischen

Gruß Otto

Nachtrag - zur Info Type=

simple: The main process of the service is specified in the start line. This is the default if the Type= and Busname= directives are not set, but the ExecStart= is set. Any communication should be handled outside of the unit through a second unit of the appropriate type (like through a .socket unit if this unit must communicate using sockets).
forking: This service type is used when the service forks a child process, exiting the parent process almost immediately. This tells systemd that the process is still running even though the parent exited.
oneshot: This type indicates that the process will be short-lived and that systemd should wait for the process to exit before continuing on with other units. This is the default Type= and ExecStart= are not set. It is used for one-off tasks.

Nachtrag 2
Mit Type=forking und RemainAfterExit=yes funktioniert auch ein saubere Neustart und es gibt beim Neustart von FHEM über "shutdown restart" keine Einträge im syslog mehr. Bei systemctl restart fhem ist alles wie immer
Type=forking ist meiner Ansicht nach wichtig, da fhem in der Regel (wenn mit root Rechten gestartet) den Startprozess sofort beendet und einen neuen Prozess mit user fhem eröffnet.
Nachtrag 3
Mit den Einträgen aus Nachtrag 2 kann man nach einem shutdown aus FHEM heraus den Service nicht mehr mit systemctl start fhem starten. Er ist quasi noch gestartet - also auch keine gute Idee.

[the ratman]

jessas, da is einer ab echt flott *g*

@ratman Ich denke mit dem Beitrag habe ich Dich verloren - aber vielleicht wird es ja wieder

hä? arbeiten andere baustelle ?

btw.:

Ich habe dann mal im unit File eine Verzögerung 3 sec eingebaut, nach dem Restart Befehl den Eintrag RestartSec hinzugefügt.

da fällt mir ein ... ich hab am laufenden system meine mysql db eingerichtet - da wird der restart ja scheinbar bis zu 10 sek. verzögert.
am neuen system hab ich den connect noch nicht eingerichtet.

könnte dazu passen, oder?

[MadMax-FHEM]

Nicht vergessen, es gibt auch weitere Module, die fhem shutdown verzögern:

z.B. alexa-fhem

(falls du das nutzt)

und weitere, die ich grad nicht kenne

Gruß, Joachim