[gelöst]: nach "shutdown restart" in Proxmox -VM, startet FHEM nicht

Begonnen von konggress, 29 August 2019, 16:16:13

Vorheriges Thema - Nächstes Thema

konggress

Hallo liebe Experten,
ich bin dabei von einem alten Server auf eine Proxmox-VM (Debian) umzuziehen. Läuft auch alles seit Wochen stabil. Was mich stört: Nach einen Update mit anschließendem "shutdown restart" kommt FHEM nicht mehr von alleine hoch.

root@sonne:~# systemctl status fhem.service
● fhem.service - FHEM Home Automation
   Loaded: loaded (/etc/systemd/system/fhem.service; enabled; vendor preset: enabled)
   Active: inactive (dead) since Thu 2019-08-29 15:50:38 CEST; 16min ago
  Process: 6090 ExecStart=/usr/bin/perl fhem.pl fhem.cfg (code=exited, status=0/SUCCESS)
Main PID: 6091 (code=exited, status=0/SUCCESS)

Aug 29 15:49:49 sonne systemd[1]: Starting FHEM Home Automation...
Aug 29 15:49:50 sonne systemd[1]: Started FHEM Home Automation.
Aug 29 15:50:38 sonne systemd[1]: fhem.service: Succeeded.


Nach root@sonne:~# systemctl start fhem.service läuft's wieder..

root@sonne:~# systemctl status fhem.service
● fhem.service - FHEM Home Automation
   Loaded: loaded (/etc/systemd/system/fhem.service; enabled; vendor preset: enabled)
   Active: active (running) since Thu 2019-08-29 16:07:24 CEST; 53s ago
  Process: 6142 ExecStart=/usr/bin/perl fhem.pl fhem.cfg (code=exited, status=0/SUCCESS)
Main PID: 6143 (perl)
    Tasks: 1 (limit: 4915)
   Memory: 79.5M
   CGroup: /system.slice/fhem.service
           └─6143 /usr/bin/perl fhem.pl fhem.cfg

Aug 29 16:07:24 sonne systemd[1]: Starting FHEM Home Automation...
Aug 29 16:07:24 sonne systemd[1]: Started FHEM Home Automation.


Ich habe den Verdacht, dass die VM einfach "zu schnell" ist, und sich mit FHEM irgendwie verschluckt. Wenn mich bitte jemand zu einem Lösungsansatz schlagen könnte, wäre ich sehr dankbar.

Grüße
konggress

CoolTux

Was sagt denn das systemd Log? Gibt es ein Eintrag im FHEM Log?
Du musst nicht wissen wie es geht! Du musst nur wissen wo es steht, wie es geht.
Support me to buy new test hardware for development: https://www.paypal.com/paypalme/MOldenburg
My FHEM Git: https://git.cooltux.net/FHEM/
Das TuxNet Wiki:
https://www.cooltux.net

konggress

Sorry, hätte ich gleich anhängen können:

syslog:
Aug 29 15:49:49 sonne systemd[1]: Starting FHEM Home Automation...
Aug 29 15:49:50 sonne systemd[1]: Started FHEM Home Automation.
Aug 29 15:50:38 sonne systemd[1]: fhem.service: Succeeded.
Aug 29 16:07:24 sonne systemd[1]: Starting FHEM Home Automation...
Aug 29 16:07:24 sonne systemd[1]: Started FHEM Home Automation.

sagt mir nix.

FHEM-Log:
2019.08.29 16:10:05 0: Server shutdown
2019.08.29 16:10:05 1: Shutdown executed
2019.08.29 16:10:28 1: Including fhem.cfg
2019.08.29 16:10:29 3: WEB: port 8083 opened
2019.08.29 16:10:29 2: eventTypes: loaded 651 events from ./log/eventTypes.txt
2019.08.29 16:10:31 3: TABLETUI: new ext defined infix:ftui/: dir:./www/tablet/:
2019.08.29 16:10:31 3: Registering HTTPSRV TABLETUI for URL /ftui   and assigned link ftui/ ...
2019.08.29 16:10:31 3: FUIP: Registering ui for URL /ui
2019.08.29 16:10:31 1: PERL WARNING: Use of uninitialized value in lc at fhem.pl line 5346.
2019.08.29 16:10:31 1: Including log/fhem.save
2019.08.29 16:10:31 3: Opening myBroker device 127.0.0.1:1883
2019.08.29 16:10:31 3: myBroker device opened
2019.08.29 16:10:31 0: Featurelevel: 5.9
2019.08.29 16:10:31 0: Server started with 17 defined entities (fhem.pl:20069/2019-08-27 perl:5.028001 os:linux user:fhem pid:503)
2019.08.29 16:10:35 3: DbLog logdb - Creating Push-Handle to database mysql:database=fhem;host=localhost;port=3306 with user fhemadm
2019.08.29 16:10:35 3: DbLog logdb - Push-Handle to db mysql:database=fhem;host=localhost;port=3306 created
2019.08.29 16:10:35 3: DbLog logdb - UTF8 support enabled
2019.08.29 16:10:50 3: DbRep dbreport - Connectiontest to database mysql:database=fhem;host=localhost;port=3306 with user fhemadm
2019.08.29 16:10:50 3: telnetForBlockingFn_1567087850: port 33073 opened
2019.08.29 16:10:50 3: DbRep dbreport - Index Report_Idx exists. Check ok
2019.08.29 16:10:50 3: DbRep dbreport - Initial data information retrieved successfully - total time used: 0.0215 seconds
2019.08.29 16:10:50 3: DbRep dbreport - Connectiontest to db mysql:database=fhem;host=localhost;port=3306 successful


:o
konggress


CoolTux

Zitat von: konggress am 29 August 2019, 17:14:56
Sorry, hätte ich gleich anhängen können:

syslog:
Aug 29 15:49:49 sonne systemd[1]: Starting FHEM Home Automation...
Aug 29 15:49:50 sonne systemd[1]: Started FHEM Home Automation.
Aug 29 15:50:38 sonne systemd[1]: fhem.service: Succeeded.
Aug 29 16:07:24 sonne systemd[1]: Starting FHEM Home Automation...
Aug 29 16:07:24 sonne systemd[1]: Started FHEM Home Automation.

sagt mir nix.

FHEM-Log:
2019.08.29 16:10:05 0: Server shutdown
2019.08.29 16:10:05 1: Shutdown executed
2019.08.29 16:10:28 1: Including fhem.cfg
2019.08.29 16:10:29 3: WEB: port 8083 opened
2019.08.29 16:10:29 2: eventTypes: loaded 651 events from ./log/eventTypes.txt
2019.08.29 16:10:31 3: TABLETUI: new ext defined infix:ftui/: dir:./www/tablet/:
2019.08.29 16:10:31 3: Registering HTTPSRV TABLETUI for URL /ftui   and assigned link ftui/ ...
2019.08.29 16:10:31 3: FUIP: Registering ui for URL /ui
2019.08.29 16:10:31 1: PERL WARNING: Use of uninitialized value in lc at fhem.pl line 5346.
2019.08.29 16:10:31 1: Including log/fhem.save
2019.08.29 16:10:31 3: Opening myBroker device 127.0.0.1:1883
2019.08.29 16:10:31 3: myBroker device opened
2019.08.29 16:10:31 0: Featurelevel: 5.9
2019.08.29 16:10:31 0: Server started with 17 defined entities (fhem.pl:20069/2019-08-27 perl:5.028001 os:linux user:fhem pid:503)
2019.08.29 16:10:35 3: DbLog logdb - Creating Push-Handle to database mysql:database=fhem;host=localhost;port=3306 with user fhemadm
2019.08.29 16:10:35 3: DbLog logdb - Push-Handle to db mysql:database=fhem;host=localhost;port=3306 created
2019.08.29 16:10:35 3: DbLog logdb - UTF8 support enabled
2019.08.29 16:10:50 3: DbRep dbreport - Connectiontest to database mysql:database=fhem;host=localhost;port=3306 with user fhemadm
2019.08.29 16:10:50 3: telnetForBlockingFn_1567087850: port 33073 opened
2019.08.29 16:10:50 3: DbRep dbreport - Index Report_Idx exists. Check ok
2019.08.29 16:10:50 3: DbRep dbreport - Initial data information retrieved successfully - total time used: 0.0215 seconds
2019.08.29 16:10:50 3: DbRep dbreport - Connectiontest to db mysql:database=fhem;host=localhost;port=3306 successful


:o
konggress

Es wäre gut ein Log aus der Zeit zu bekommen wo dein fhem Service Probleme gemeldet hat. Also um 15:49 rum
Du musst nicht wissen wie es geht! Du musst nur wissen wo es steht, wie es geht.
Support me to buy new test hardware for development: https://www.paypal.com/paypalme/MOldenburg
My FHEM Git: https://git.cooltux.net/FHEM/
Das TuxNet Wiki:
https://www.cooltux.net

konggress

So, jetzt also noch mal 15.25 Uhr: "shutdown restart"

root@sonne:~# systemctl status fhem.service
● fhem.service - FHEM Home Automation
   Loaded: loaded (/etc/systemd/system/fhem.service; enabled; vendor preset: enabled)
   Active: inactive (dead) since Fri 2019-08-30 15:26:50 CEST; 37s ago
Main PID: 503 (code=exited, status=0/SUCCESS)

Aug 29 16:10:28 sonne systemd[1]: Starting FHEM Home Automation...
Aug 29 16:10:28 sonne systemd[1]: Started FHEM Home Automation.
Aug 30 15:26:50 sonne systemd[1]: fhem.service: Succeeded.


syslog:

Aug 30 15:25:00 sonne systemd[1]: Created slice User Slice of UID 1000.
Aug 30 15:25:00 sonne systemd[1]: Starting User Runtime Directory /run/user/1000...
Aug 30 15:25:00 sonne systemd[1]: Started User Runtime Directory /run/user/1000.
Aug 30 15:25:00 sonne systemd[1]: Starting User Manager for UID 1000...
Aug 30 15:25:00 sonne systemd[5517]: Starting D-Bus User Message Bus Socket.
Aug 30 15:25:00 sonne systemd[5517]: Listening on GnuPG cryptographic agent and passphrase cache.
Aug 30 15:25:00 sonne systemd[5517]: Reached target Timers.
Aug 30 15:25:00 sonne systemd[5517]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Aug 30 15:25:00 sonne systemd[5517]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Aug 30 15:25:00 sonne systemd[5517]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Aug 30 15:25:00 sonne systemd[5517]: Listening on GnuPG network certificate management daemon.
Aug 30 15:25:00 sonne systemd[5517]: Reached target Paths.
Aug 30 15:25:00 sonne systemd[5517]: Listening on D-Bus User Message Bus Socket.
Aug 30 15:25:00 sonne systemd[5517]: Reached target Sockets.
Aug 30 15:25:00 sonne systemd[5517]: Reached target Basic System.
Aug 30 15:25:00 sonne systemd[5517]: Reached target Default.
Aug 30 15:25:00 sonne systemd[1]: Started User Manager for UID 1000.
Aug 30 15:25:00 sonne systemd[5517]: Startup finished in 82ms.
Aug 30 15:25:00 sonne systemd[1]: Started Session 74 of user torsten.
Aug 30 15:26:50 sonne systemd[1]: fhem.service: Succeeded.


FHEM-Log:

2019.08.30 15:26:49 2: DbLog logdb - Last database write cycle due to shutdown ...
2019.08.30 15:26:49 1: Server shutdown delayed due to logdb for max 10 sec
2019.08.30 15:26:49 2: DbLog logdb - Last database write cycle done
2019.08.30 15:26:50 0: Server shutdown
2019.08.30 15:26:50 1: Shutdown executed


15.35Uhr, Start von Hand:

root@sonne:~# systemctl start fhem.service
root@sonne:~# systemctl status fhem.service
● fhem.service - FHEM Home Automation
   Loaded: loaded (/etc/systemd/system/fhem.service; enabled; vendor preset: enabled)
   Active: active (running) since Fri 2019-08-30 15:35:10 CEST; 5s ago
  Process: 5673 ExecStart=/usr/bin/perl fhem.pl fhem.cfg (code=exited, status=0/SUCCESS)
Main PID: 5674 (perl)
    Tasks: 1 (limit: 4915)
   Memory: 77.2M
   CGroup: /system.slice/fhem.service
           └─5674 /usr/bin/perl fhem.pl fhem.cfg

Aug 30 15:35:09 sonne systemd[1]: Starting FHEM Home Automation...
Aug 30 15:35:10 sonne systemd[1]: Started FHEM Home Automation.


Syslog:

Aug 30 15:35:09 sonne systemd[1]: Starting FHEM Home Automation...
Aug 30 15:35:10 sonne systemd[1]: Started FHEM Home Automation.


FHEM-Log:

2019.08.30 15:35:10 1: Including fhem.cfg
2019.08.30 15:35:10 3: WEB: port 8083 opened
2019.08.30 15:35:10 2: eventTypes: loaded 651 events from ./log/eventTypes.txt
2019.08.30 15:35:12 3: TABLETUI: new ext defined infix:ftui/: dir:./www/tablet/:
2019.08.30 15:35:12 3: Registering HTTPSRV TABLETUI for URL /ftui   and assigned link ftui/ ...
2019.08.30 15:35:12 3: FUIP: Registering ui for URL /ui
2019.08.30 15:35:12 1: PERL WARNING: Use of uninitialized value in lc at fhem.pl line 5346.
2019.08.30 15:35:12 1: Including log/fhem.save
2019.08.30 15:35:12 3: Opening myBroker device 127.0.0.1:1883
2019.08.30 15:35:12 3: myBroker device opened
2019.08.30 15:35:12 0: Featurelevel: 5.9
2019.08.30 15:35:12 0: Server started with 17 defined entities (fhem.pl:20069/2019-08-27 perl:5.028001 os:linux user:fhem pid:5674)
2019.08.30 15:35:16 3: DbLog logdb - Creating Push-Handle to database mysql:database=fhem;host=localhost;port=3306 with user fhemadm
2019.08.30 15:35:16 3: DbLog logdb - Push-Handle to db mysql:database=fhem;host=localhost;port=3306 created
2019.08.30 15:35:16 3: DbLog logdb - UTF8 support enabled
2019.08.30 15:35:37 3: DbRep dbreport - Connectiontest to database mysql:database=fhem;host=localhost;port=3306 with user fhemadm
2019.08.30 15:35:37 3: telnetForBlockingFn_1567172137: port 40183 opened
2019.08.30 15:35:37 3: DbRep dbreport - Index Report_Idx exists. Check ok
2019.08.30 15:35:37 3: DbRep dbreport - Initial data information retrieved successfully - total time used: 0.0038 seconds
2019.08.30 15:35:37 3: DbRep dbreport - Connectiontest to db mysql:database=fhem;host=localhost;port=3306 successful


Vielen Dank für eure Mühen
konggress

CoolTux

Ah jetzt verstehe ich. Wenn Du im FHEMWEB shutdown restart ein gibst dann macht er kein Neustart.
Kenne ich hatte ich auch und habe ich in meiner Testumgebung immer noch. Muss heute Abend mal schauen. Habe da eine Idee.
Du musst nicht wissen wie es geht! Du musst nur wissen wo es steht, wie es geht.
Support me to buy new test hardware for development: https://www.paypal.com/paypalme/MOldenburg
My FHEM Git: https://git.cooltux.net/FHEM/
Das TuxNet Wiki:
https://www.cooltux.net

kadettilac89

#6
Zitat von: konggress am 29 August 2019, 16:16:13
ich bin dabei von einem alten Server auf eine Proxmox-VM (Debian) umzuziehen. Läuft auch alles seit Wochen stabil. Was mich stört: Nach einen Update mit anschließendem "shutdown restart" kommt FHEM nicht mehr von alleine hoch.

Umzug mit Neuinstallation von Fhem?

Wie sieht deine /etc/systemd/system/fhem.service aus. Steht da .... "restart=on-failure" ... drin? Teste mal "restart=always" ...
Vermutlich das Problem das ich damals auch hatte --> https://forum.fhem.de/index.php/topic,81660.msg737412.html#msg737412

Edit: du kannst auch das mal in deine service-datei eintragen wenn es noch keinen ähnliche Eintrag gibt, darf nicht doppelt vorkommen .... RestartSec=5 ....
Nach dem Editieren der Datei ... systemctl daemon-reload  ... ausführen.

konggress

Hallo,
ZitatUmzug mit Neuinstallation von Fhem?
Ja, macht sich ganz gut.. Auch wenn ich die einzelnen Def's von Hand auf den neuen Server kopiere.

ZitatWie sieht deine /etc/systemd/system/fhem.service aus. Steht da .... "restart=on-failure" ... drin? Teste mal "restart=always" ...
Vermutlich das Problem das ich damals auch hatte --> https://forum.fhem.de/index.php/topic,81660.msg737412.html#msg737412

Das war's! "restart=always" war auskommentiert. Jetzt läufts...

Vielen Dank an euch!
konggress