Bekommen nach Update Debian FHEM nicht mehr zum laufen

devil77 · 27 Oktober 2017, 17:49:03

Hallo,
habe heute ein Update von Debian 8 auf 9 gemacht. Dachte eigentlich das alles gut geklappt hat aber seit dem will FHEM nicht mehr starten.
Sowie ich das sehe startet FHEM richtig und führt aber dann einen shutdown aus.
Keine Ahnung woher das kommt. Hatte vor dem Update auf systemd umgestellt.
Anbei ein paar Daten.
fhem.service

Code Auswählen

[Unit]
Description=FHEM service
After=network.target
Wants=hmcfgusb.service

[Service]
Type=forking
User=fhem
Group=dialout
WorkingDirectory=/opt/fhem
ExecStart=/usr/bin/perl fhem.pl configDB
TimeoutStopSec=300

[Install]
WantedBy=multi-user.target

hmcfgusb.service

Code Auswählen

Unit]
Description=HMCFGUSB

[Service]
Type=forking
ExecStart=/opt/hmcfgusb/hmland -d -p 1234 -r 0
Restart=always
RestartSec=5

[Install]
WantedBy=multi-user.target

CoolTux · 27 Oktober 2017, 17:50:18

FHEM Log sollte mehr Auskunft geben.

devil77 · 27 Oktober 2017, 18:05:52

Bin statt auf Vorschau auf Schreiben gegangen.

Anbei noch weitere Daten.

systemctl status hmcfgusb.service

Code Auswählen

root@fhem:~# systemctl status hmcfgusb.service
● hmcfgusb.service
   Loaded: loaded (/etc/systemd/system/hmcfgusb.service; bad; vendor preset: enabled)
   Active: active (running) since Fri 2017-10-27 17:43:43 CEST; 6min ago
  Process: 348 ExecStart=/opt/hmcfgusb/hmland -d -p 1234 -r 0 (code=exited, status=0/SUCCESS)
 Main PID: 359 (hmland)
    Tasks: 2 (limit: 4915)
   CGroup: /system.slice/hmcfgusb.service
           └─359 /opt/hmcfgusb/hmland -d -p 1234 -r 0

Okt 27 17:43:43 fhem systemd[1]: Starting hmcfgusb.service...
Okt 27 17:43:43 fhem hmland[348]: Daemon with PID 359 started!
Okt 27 17:43:43 fhem systemd[1]: Started hmcfgusb.service.

systemctl status fhem.service

Code Auswählen

root@fhem:~# systemctl status fhem.service
● fhem.service - FHEM service
   Loaded: loaded (/etc/systemd/system/fhem.service; enabled; vendor preset: enabled)
   Active: failed (Result: timeout) since Fri 2017-10-27 17:45:15 CEST; 5min ago
  Process: 489 ExecStart=/usr/bin/perl fhem.pl configDB (code=exited, status=0/SUCCESS)

Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 4: DbLog myDbLog -> check Device: global , Event: SHUTDOWN
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 5: system.batteriestatus: not on any display, ignoring notify
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 5: End notify loop for global
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 0: Server shutdown
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 4: Nextion_Disconnect: NextionDisp
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 4: ESPEasy espBridge: Shutdown requested
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 4: configDB writing file: ./log/eventTypes.txt
Okt 27 17:45:15 fhem systemd[1]: Failed to start FHEM service.
Okt 27 17:45:15 fhem systemd[1]: fhem.service: Unit entered failed state.
Okt 27 17:45:15 fhem systemd[1]: fhem.service: Failed with result 'timeout'.

journalctl -u fhem.service (nur die Zeilen zum Schluss)

Code Auswählen


.
.
.
.
Okt 27 17:45:13 fhem perl[489]: 2017.10.27 17:45:13 5: system.batteriestatus: not on any display, ignoring notify
Okt 27 17:45:13 fhem perl[489]: 2017.10.27 17:45:13 5: End notify loop for KU.u.Li_Schalter_Sw_02
Okt 27 17:45:14 fhem systemd[1]: fhem.service: Start operation timed out. Terminating.
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 5: Starting notify loop for global, 1 event(s), first is SHUTDOWN
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 5: statistics Bad.Statistik: Notify.266 Notification of 'global' received. Device not monitored.
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 5: statistics Bad_o_Pwr_Stromverbrauch_Abstell_Statistik: Notify.266 Notification of 'global' received. Device not monitored.
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 5: statistics KU.u.ST_Kuehlschrank_Statistik: Notify.266 Notification of 'global' received. Device not monitored.
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 5: statistics WZ.Stromverbrauch_Statistik: Notify.266 Notification of 'global' received. Device not monitored.
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 5: statistics WZ.u.ST_CapuBar_Statistik: Notify.266 Notification of 'global' received. Device not monitored.
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 4: DbLog myDbLog -> ################################################################
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 4: DbLog myDbLog -> ###              start of new Logcycle                       ###
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 4: DbLog myDbLog -> ################################################################
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 4: DbLog myDbLog -> amount of events received: 1 for device: global
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 4: DbLog myDbLog -> check Device: global , Event: SHUTDOWN
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 5: system.batteriestatus: not on any display, ignoring notify
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 5: End notify loop for global
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 0: Server shutdown
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 4: Nextion_Disconnect: NextionDisp
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 4: ESPEasy espBridge: Shutdown requested
Okt 27 17:45:14 fhem perl[489]: 2017.10.27 17:45:14 4: configDB writing file: ./log/eventTypes.txt
Okt 27 17:45:15 fhem systemd[1]: Failed to start FHEM service.
Okt 27 17:45:15 fhem systemd[1]: fhem.service: Unit entered failed state.
Okt 27 17:45:15 fhem systemd[1]: fhem.service: Failed with result 'timeout'.

Keine Ahnung was da jetzt den Timeout erzeugt oder warum fhem sich beendet oder wo ich jetzt noch ansetzen sollte.

CoolTux · 27 Oktober 2017, 19:09:05

Ich persönlich finde ja immer noch das ein fhem.log mehr sagen könnte. Kann mich aber auch irren.

Mitch · 27 Oktober 2017, 19:15:24

Ich würde mal mit einer Minimalkonfig versuchen zu starten.
Danach kann man ja Stück für Stück die cfg "erweitern".

Evtl. fehlt nun ein Perl Paket (so war es bei mir mal nach einem Linux Update)

devil77 · 27 Oktober 2017, 19:21:31

Aus dem fhem log bekomme ich keine Informationen mehr das es komischer weise auch nicht mehr aktualisiert wird.
Egal wie oft ich neustarte, es tauchen keine neuen Infos auf.

Wenn ich fhem manuell neustarte kommt gleich am Anfang folgende Meldung

Code Auswählen

Okt 27 19:05:51 fhem systemd[1]: Starting FHEM service...
Okt 27 19:05:51 fhem perl[499]: looking for table: fhembinfilesave
Okt 27 19:05:51 fhem perl[499]: testing: #2
Okt 27 19:05:51 fhem perl[499]: table not found

Danach wird Fhem weiter gestartet und es läuft wieder für einen Augenblick bis es wieder beendet wird.
Fhem.cfg habe ich keine.

Mitch · 27 Oktober 2017, 19:23:47

Dann starte doch mal mit einer Minimalkonfig.
Brauchst doch nur die Demo.cfg nehmen, die dabei ist und in der service entsprechend ändern.

ThoTo · 27 Oktober 2017, 19:28:24

Zitat von: devil77 am 27 Oktober 2017, 19:21:31
Danach wird Fhem weiter gestartet und es läuft wieder für einen Augenblick bis es wieder beendet wird.
Fhem.cfg habe ich keine.

Bitte stoppe den Service und versuche FHEM direkt via Konsole zu starten:

Code Auswählen


cd /opt/fhem
/usr/bin/perl fhem.pl configDB

Wie weit kommst du dann laut Log?

Zitat von: devil77 am 27 Oktober 2017, 19:21:31
Wenn ich fhem manuell neustarte kommt gleich am Anfang folgende Meldung
Code Auswählen Erweitern
Okt 27 19:05:51 fhem systemd[1]: Starting FHEM service... Okt 27 19:05:51 fhem perl[499]: looking for table: fhembinfilesave Okt 27 19:05:51 fhem perl[499]: testing: #2 Okt 27 19:05:51 fhem perl[499]: table not found

Diese Meldung ist in Ordnung, d.h. kein Hinweis auf ein Problem.

CoolTux · 27 Oktober 2017, 19:32:36

Dann wird es Zeit im Wiki nach zu lesen. Suchbegriff fhem startet nicht