Nach Update ist das FHEM WebInterface nicht mehr erreichbar

[hoppel118]

Hallo Leute,

da ich Probleme mit der FHEM iOS App habe, möchte ich ein Update meines FHEM Servers durchführen. Dazu halte ich mich an folgenden Wiki-Eintrag: https://wiki.fhem.de/wiki/Update

Als erstes mache ich ein backup, was problemlos funktioniert.

1. Dann prüfe ich, ob es Updates gibt:

Code Auswählen Erweitern

update check

List of new / modified files since last update:
UPD ./CHANGED
UPD FHEM/98_JsonList.pm

New entries in the CHANGED file:
  - bugfix:  93_DbRep: syntax error if perl version < 5.20
  - feature: 74_AMADDevice: add new set command "takePicture",change Commandref
  - feature: 98_GOOGLECAST: support speak command for TTS
                            set castdevice speak "Hallo"
  - feature: 51_MOBILEALERTS: Added Sensor WL2000
  - change:  93_DbRep: V7.3.0, charfilter avoid control characters in datasets
                       to export, function exportToFile importFromFile improved
  - feature: FHEMWEB: new style f18
  - feature: 98_weekprofile.pm: new set command 'reread_master'
  - change:  10_SOMFY: minor changes remvoe debug and add parsestate reading
  - bugfix:  74_XiaomiFlowerSens: fix error then use ssh and no connect
  - change:  72_FB_CALLIST: mapping tables (icon-mapping, external-mapping,...)
             will be evaluated after initialization is finished (Forum: #81892)
  - feature: 01_FHEMWEB.pm: -> as room separator (Forum #82151)
  - bugfix:  10_FRM: accept Firmata firmware without AnalogInputFirmata
  - bugfix:  10_MYSENSORS_DEVICE: corrected S_LIGHT_LEVEL
  - bugfix:  93_DbRep: fix "month out of range" that causes fhem crash
  - feature: 20_FRM_PWM: new attribute "restoreOnStartup"
  - feature: 20_FRM_OUT: new attributes "activeLow" and "valueMode"
  - feature: 10_FRM: SerialFirmata support
  - update:  10_FRM: OWX IODev assignment
  - update:  10_FRM: Firmata 2.7+ support
  - bugfix:  98_weekprofile: fix "error restore topic"
  - change:  14_CUL_TCM97001: Fix Logoutput, Fix device output with
             multiple sensors
  - change:  74_AMADDevice: change DEF and add Attribut IODev, add Reading
... rest of lines skipped.

2. Dann prüfe ich, ob ich irgendwelche Repositories eingebunden habe, weil ich es nicht mehr wusste:

Code Auswählen Erweitern

update list

http://fhem.de/fhemupdate/controls_fhem.txt

Ich nehme an, dass das Ergebnis bedeutet, dass ich keine Fremd-Repositorys eingebunden habe, sonst würden die mir hier zusätzlich aufgelistet werden.

3. Dann führe ich das Update durch. Ich möchte die gesamte FHEM-Installation auf den neusten Stand bringen:

Code Auswählen Erweitern

update

2018.01.09 17:14:00 2 : Backup with command: tar -cf - "./certs" "./CHANGED" "./configDB.pm" "./contrib" "./demolog" "./docs" "./FHEM" "./fhem-5.8.deb" "./fhem.cfg" "./fhem.cfg.CUL_HM" "./fhem.cfg.demo" "./fhem.cfg.save" "./fhem.pl" "./log" "./MAINTAINER.txt" "./README_DEMO.txt" "./restoreDir" "./unused" "./www" |gzip > ./backup/FHEM-20180109_171400.tar.gz
2018.01.09 17:14:11 1 : backup done: FHEM-20180109_171400.tar.gz (76167766 Bytes)
2018.01.09 17:14:11 1 : UPD ./CHANGED
2018.01.09 17:14:11 1 : UPD FHEM/98_JsonList.pm
2018.01.09 17:14:11 1 : saving fhem.cfg
2018.01.09 17:14:11 1 : saving ./log/fhem.save
2018.01.09 17:14:11 1 :
2018.01.09 17:14:11 1 : New entries in the CHANGED file:
2018.01.09 17:14:11 1 : - bugfix: 93_DbRep: syntax error if perl version < 5.20
2018.01.09 17:14:11 1 : - feature: 74_AMADDevice: add new set command "takePicture",change Commandref
2018.01.09 17:14:11 1 : - feature: 98_GOOGLECAST: support speak command for TTS
2018.01.09 17:14:11 1 : set castdevice speak "Hallo"
2018.01.09 17:14:11 1 : - feature: 51_MOBILEALERTS: Added Sensor WL2000
2018.01.09 17:14:11 1 : - change: 93_DbRep: V7.3.0, charfilter avoid control characters in datasets
2018.01.09 17:14:11 1 : to export, function exportToFile importFromFile improved
2018.01.09 17:14:11 1 : - feature: FHEMWEB: new style f18
2018.01.09 17:14:11 1 : - feature: 98_weekprofile.pm: new set command 'reread_master'
2018.01.09 17:14:11 1 : - change: 10_SOMFY: minor changes remvoe debug and add parsestate reading
2018.01.09 17:14:11 1 : - bugfix: 74_XiaomiFlowerSens: fix error then use ssh and no connect
2018.01.09 17:14:11 1 : - change: 72_FB_CALLIST: mapping tables (icon-mapping, external-mapping,...)
2018.01.09 17:14:11 1 : will be evaluated after initialization is finished (Forum: #81892)
2018.01.09 17:14:11 1 : - feature: 01_FHEMWEB.pm: -> as room separator (Forum #82151)
2018.01.09 17:14:11 1 : - bugfix: 10_FRM: accept Firmata firmware without AnalogInputFirmata
2018.01.09 17:14:11 1 : - bugfix: 10_MYSENSORS_DEVICE: corrected S_LIGHT_LEVEL
2018.01.09 17:14:11 1 : - bugfix: 93_DbRep: fix "month out of range" that causes fhem crash
2018.01.09 17:14:11 1 : - feature: 20_FRM_PWM: new attribute "restoreOnStartup"
2018.01.09 17:14:11 1 : - feature: 20_FRM_OUT: new attributes "activeLow" and "valueMode"
2018.01.09 17:14:11 1 : - feature: 10_FRM: SerialFirmata support
2018.01.09 17:14:11 1 : - update: 10_FRM: OWX IODev assignment
2018.01.09 17:14:11 1 : - update: 10_FRM: Firmata 2.7+ support
2018.01.09 17:14:11 1 : - bugfix: 98_weekprofile: fix "error restore topic"
2018.01.09 17:14:11 1 : - change: 14_CUL_TCM97001: Fix Logoutput, Fix device output with
2018.01.09 17:14:11 1 : multiple sensors
2018.01.09 17:14:11 1 : - change: 74_AMADDevice: change DEF and add Attribut IODev, add Reading
2018.01.09 17:14:11 1 : ... rest of lines skipped.
2018.01.09 17:14:11 1 : Calling /usr/bin/perl ./contrib/commandref_join.pl -noWarnings, this may take a while
2018.01.09 17:14:14 1 :
2018.01.09 17:14:14 1 : update finished, "shutdown restart" is needed to activate the changes.
2018.01.09 17:14:14 1 :
2018.01.09 17:14:15 1 : fheminfo Statistics data sent to server. See Logfile (level 4) for details.
2018-01-09 17:14:15 Global global UPDATE

Das Update ist erfolgt. Bis hierhin funktioniert noch alles.

4. Ich führe, wie im letzten Ergebnis angegeben, einen "shutdown restart" durch.

Code Auswählen Erweitern

shutdown restart

Der WebServer ist nun nicht mehr erreichbar.

Code Auswählen Erweitern

root@omv4:~# systemctl status fhem
● fhem.service - FHEM Home Automation
   Loaded: loaded (/etc/systemd/system/fhem.service; enabled; vendor preset: enabled)
   Active: inactive (dead) since Tue 2018-01-09 17:17:06 CET; 31s ago
  Process: 5953 ExecStart=/usr/bin/perl fhem.pl fhem.cfg (code=exited, status=0/SUCCESS)
Main PID: 5954 (code=exited, status=0/SUCCESS)
      CPU: 28.574s

Jan 09 16:36:06 omv4 systemd[1]: Starting FHEM Home Automation...
Jan 09 16:36:06 omv4 systemd[1]: Started FHEM Home Automation.

Danach muss ich dann den FHEM Server einmal manuell neustarten.

Code Auswählen Erweitern

root@omv4:~# systemctl stop fhem
root@omv4:~# systemctl start fhem
root@omv4:~# systemctl status fhem
● fhem.service - FHEM Home Automation
   Loaded: loaded (/etc/systemd/system/fhem.service; enabled; vendor preset: enabled)
   Active: active (running) since Tue 2018-01-09 17:20:21 CET; 4s ago
  Process: 9938 ExecStart=/usr/bin/perl fhem.pl fhem.cfg (code=exited, status=0/SUCCESS)
Main PID: 9939 (perl)
    Tasks: 1 (limit: 4915)
   Memory: 33.6M
      CPU: 334ms
   CGroup: /system.slice/fhem.service
           └─9939 /usr/bin/perl fhem.pl fhem.cfg

Jan 09 17:20:21 omv4 systemd[1]: Starting FHEM Home Automation...
Jan 09 17:20:21 omv4 systemd[1]: Started FHEM Home Automation.

5. Zu guter letzt, prüfe ich nochmal, ob alle Updates installiert wurden:

Code Auswählen Erweitern

update check

nothing to do...

OK, das sieht gut aus.

---------------------------------------------------------------------------------

Ich habe die Vermutung, dass das FHEM WebInterface nach dem "shutdown restart" eigentlich automatisch wieder erreichbar sein müsste, da im Wiki nicht darauf hingewiesen wird, dass man den Service manuell neustarten muss. Ich habe ein aktuelles Debian Stretch im Einsatz. Liege ich mit meiner Annahme richtig?

Wenn ja, mache ich etwas falsch oder handelt es sich um einen Bug?

Danke und Gruß Hoppel

[kadettilac89]

ich vermute dass es hier auch an Service liegt. Hatte ein ähnliches Problem gemeldet. Kennst du dich mit Linux etwas aus? Kannst du prüfen welches Startscript verwendet wird? Init.d oder system.d. Wenn dir das nichts sagt müsste ich weiter ausholen. Udo (betateilchen) hat zur Weihnachtszeit das Script geädert, kenne den aktuellen Status nicht.

https://forum.fhem.de/index.php/topic,81660.0.html

[hoppel118]

Moin,

ich habe mich bis vor kurzem auf init.d beschränkt, um Services zu starten, zu stoppen oder den Status abzufragen. Da init.d anscheinend veraltet ist, habe ich neulich irgendwann damit begonnen, das mit dem Befehl "systemctl" zu machen, siehe auch meinen Eingangspost unter Punkt 4. Zwischenzeitlich habe ich meinen Server neu aufgesetzt, so dass ich diese Veränderung bei fhem gar nicht wahrgenommen habe.

Wenn ich nun prüfe, ob es ein init.d Script gibt, erhalte ich folgende Meldung:

Code Auswählen Erweitern

root@omv4:~# ls /etc/init.d/fhem
ls: Zugriff auf '/etc/init.d/fhem' nicht möglich: Datei oder Verzeichnis nicht gefunden

Gibt es also nicht. Wenn ich dann prüfe, ob es das unter systemd gibt, finde ich folgendes:

Code Auswählen Erweitern

root@omv4:~# ls /etc/systemd/system/fhem.service
/etc/systemd/system/fhem.service

Der Inhalt der Datei sieht wie folgt aus:

Code Auswählen Erweitern

# $Id: fhem.service 15784 2018-01-05 11:29:16Z betateilchen $

[Unit]
Description=FHEM Home Automation
Wants=network.target
After=network.target

[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
# uncomment next two lines if auto-restart desired

# please select restart options according your needs
# Restart=on-abnormal # uncomment for crash and watchdog event recovery only (keeps shutdown working)
# Restart=always # alternativly uncomment this line for recover always
# RestartSec=5 # uncomment always if restart required!

[Install]
WantedBy=multi-user.target

Mein systemd Script sieht etwas anders aus als das von dir in dem anderen Thread gepostete Script. Bei mir sind alle drei Optionen auskommentiert und bei dir sind die beiden Optionen "Restart=on-failure" und "RestartSec=5" aktiv. Hast du das manuell angepasst?

Wenn ich es richtig verstehe, müsste ich also eine oder mehrere der drei Optionen "entkommentieren". Mir stellt sich nun aber die Frage, was sinnvoll ist, damit FHEM nach einem Update direkt wieder gestartet wird. Schöner wäre es, wenn FHEM-User sich darüber keine Gedanken machen müssten. Ich habe mich auf jeden Fall gewundert, warum das Webinterface nach dem Update nicht mehr erreichbar ist und dachte das Update ist schief gegangen. Dann habe ich ohne weitere Analyse erstmal direkt mein Backup eingespielt und das Update nochmal probiert, was natürlich zum selben Ergebnis führte. Erst dann kam ich auf die Idee zu prüfen, ob der Service überhaupt noch läuft. Die Frage hatte sich mir beim ersten Versuch nur überhaupt nicht gestellt, da das schon immer so war, dass der Server nach dem Update wieder läuft.

Ich bin nun gerade wie folgt vorgegangen und habe die Option "Restart=on-abnormal" aktiviert:

Code Auswählen Erweitern

root@omv4:~# systemctl status fhem
● fhem.service - FHEM Home Automation
   Loaded: loaded (/etc/systemd/system/fhem.service; enabled; vendor preset: enabled)
   Active: active (running) since Wed 2018-01-10 15:43:43 CET; 38s ago
Main PID: 18823 (perl)
   CGroup: /system.slice/fhem.service
           └─18823 /usr/bin/perl fhem.pl fhem.cfg

Jan 10 15:43:43 omv4 systemd[1]: Starting FHEM Home Automation...
Jan 10 15:43:43 omv4 systemd[1]: Started FHEM Home Automation.

Code Auswählen Erweitern

root@omv4:~# nano /etc/systemd/system/fhem.service
# $Id: fhem.service 15784 2018-01-05 11:29:16Z betateilchen $

[Unit]
Description=FHEM Home Automation
Wants=network.target
After=network.target

[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
# uncomment next two lines if auto-restart desired

# please select restart options according your needs
Restart=on-abnormal # uncomment for crash and watchdog event recovery only (keeps shutdown working)
# Restart=always # alternativly uncomment this line for recover always
# RestartSec=5 # uncomment always if restart required!

[Install]
WantedBy=multi-user.target

Code Auswählen Erweitern

root@omv4:~# systemctl stop fhem
Warning: fhem.service changed on disk. Run 'systemctl daemon-reload' to reload units.

Code Auswählen Erweitern

root@omv4:~# systemctl daemon-reload

Code Auswählen Erweitern

root@omv4:~# systemctl start fhem

Dann bin ich ins WebInterface gegangen und habe mit "update check" geprüft, ob es ein Update gibt.

List of new / modified files since last update:
UPD FHEM/98_DLNARenderer.pm

Ok, dann "update" ausgeführt:

2018.01.10 15:51:45 2 : Backup with command: tar -cf - "./certs" "./CHANGED" "./configDB.pm" "./contrib" "./demolog" "./docs" "./FHEM" "./fhem-5.8.deb" "./fhem.cfg" "./fhem.cfg.CUL_HM" "./fhem.cfg.demo" "./fhem.cfg.save" "./fhem.pl" "./log" "./MAINTAINER.txt" "./README_DEMO.txt" "./restoreDir" "./unused" "./www" |gzip > ./backup/FHEM-20180110_155145.tar.gz
2018.01.10 15:51:55 1 : backup done: FHEM-20180110_155145.tar.gz (76289390 Bytes)
2018.01.10 15:51:55 1 : UPD FHEM/98_DLNARenderer.pm
2018.01.10 15:51:55 1 : saving fhem.cfg
2018.01.10 15:51:55 1 : saving ./log/fhem.save
2018.01.10 15:51:55 1 : Calling /usr/bin/perl ./contrib/commandref_join.pl -noWarnings, this may take a while
2018.01.10 15:51:59 1 :
2018.01.10 15:51:59 1 : update finished, "shutdown restart" is needed to activate the changes.
2018.01.10 15:51:59 1 :
2018.01.10 15:52:00 1 : fheminfo Statistics data sent to server. See Logfile (level 4) for details.
2018-01-10 15:52:00 Global global UPDATE

Dann nochmal auf der Command Line geschaut, siehe da, der Server läuft:

Code Auswählen Erweitern

root@omv4:~# systemctl status fhem
● fhem.service - FHEM Home Automation
   Loaded: loaded (/etc/systemd/system/fhem.service; enabled; vendor preset: enabled)
   Active: active (running) since Wed 2018-01-10 15:45:52 CET; 7min ago
  Process: 19216 ExecStart=/usr/bin/perl fhem.pl fhem.cfg (code=exited, status=0/SUCCESS)
Main PID: 19217 (perl)
    Tasks: 1 (limit: 4915)
   Memory: 119.0M
      CPU: 15.471s
   CGroup: /system.slice/fhem.service
           └─19217 /usr/bin/perl fhem.pl fhem.cfg

Jan 10 15:45:52 omv4 systemd[1]: Starting FHEM Home Automation...
Jan 10 15:45:52 omv4 systemd[1]: Started FHEM Home Automation.

Ich kann fhem weiter starten und stoppen. Also genau das, was ich gesucht habe.

Udo (betateilchen) hat zur Weihnachtszeit das Script geädert, kenne den aktuellen Status nicht.

Wahrscheinlich ist das @betateilchen's Scriptänderung.

Was spricht dagegen diese Option standardmäßig zu aktivieren?

Gruß Hoppel

[Beta-User]

Das mit dem nicht ausgeführten Neustart bei "shutdown restart" war hier im Forum in letzter Zeit häufiger Thema, in der Regel in Verbindung mit schnellen Servern.
Ob es mit systemd zusammenhängt: keine Ahnung.

Dazu gibt es aber zwei Dinge in der Commandref:
1.

restartDelay
Setzt die Verzögerung beim Neustart mit shutdown restart, die Voreinstellung ist 2 (Sekunden).

Damit würde ich mal anfangen.

2.

shutdown [restart] [exitValue]
Der Befehl fährt FHEM herunter (nach dem Sichern aller Gerätestatus). Er triggert den global:SHUTDOWN-Event. Mit dem optionalen Parameter restart startet FHEM danach neu. Der exitValue ist möglicherweise bei bestimmten Start-Skripten zur korrekten Funktion vonnöten bzw. wichtig.

Leider habe ich (noch) keine Idee, wie exitValue ggf. sinnvoll zu belegen sein könnte...
Gruß, Beta-User

[hoppel118]

Stimmt, ich habe nachdem ganzen Prozedere eben den "shutdown-restart" vergessen, gerade nachgeholt, danach ist das WebInterface nicht mehr erreichbar, trotz der obigen Aktion. Updates fallen also nicht unter "Restart=on-abnormal". Wenn ich so drüber nachdenke, macht das auch Sinn.

OK, ich habe mein systemd Script wieder in den Originalzustand versetzt und das Backup von vorhin nochmal neu eingespielt, um den gesamten Vorgang nochmal testen zu können.

Also als erstes erstmal restartDelay setzen:

Code Auswählen Erweitern

attr global restartDelay

Danach "update" und "shutdown restart" ausgeführt, wie zu vermuten war, reicht das nicht aus.

Dann bleibt wirklich nur die Frage nach dem [exitValue]. 

Wer kann das was zu sagen?

Wenn das dann klar ist, sollte man idealerweise die Meldung beim Updatevorgang um den exitValue ergänzen:

2018.01.10 15:51:59 1 : update finished, "shutdown restart" is needed to activate the changes.

Wobei das dann ja je nach Startscript unterschiedlich aussehen müsste... 

Gruß Hoppel 

[herrmannj]

der exit value hat mMn keine Einfluss.

Wenn shutdown restart nicht geht kann das auch ganz trivial an einem x-beliebigen modul liegen.

Teste das mit der leeren fhem.cfg (aus dem svn) oder der Demo cfg. Deine eigene natürlich sichern !!!

[Beta-User]

Na ja, es war ja geschrieben gewesen, dass ein händischer Start (also ohne reboot) nach dem update klappt.

Aber in den anderen Fällen (zu schneller Restart) stand entweder was im log (Port 7072 noch nicht wieder freigegeben) oder schlicht nichts (so einen Fall hatte CoolTux geschildert auf einer virtualisierten Maschine, soweit ich das verstanden hatte).

Würde also als erstes mal ins log schauen, evtl. kann man dann erkennen, ob es tatsächlich doch an einem Modul hängt.

[herrmannj]

absolut korrekt. Wenn jedoch eine ShutdownFn einen Fehler wirft kann fhem aussteigen bevor der Programmteil für den restart erreicht ist und ohne das was im log landet. Getestet Ob das _hier_ die Ursache ist weiß ich natürlich nicht.

[hoppel118]

der exit value hat mMn keine Einfluss.

Wenn shutdown restart nicht geht kann das auch ganz trivial an einem x-beliebigen modul liegen.

Teste das mit der leeren fhem.cfg (aus dem svn) oder der Demo cfg. Deine eigene natürlich sichern !!!

Ok, habe meine fhem.cfg mal durch die fhem.cfg.demo ersetzt. Danach startet fhem nicht mehr:

Code Auswählen Erweitern

root@omv4:~# systemctl start fhem
Job for fhem.service failed because a timeout was exceeded.
See "systemctl status fhem.service" and "journalctl -xe" for details.

Ich nix SVN, ich nur github. Mit SVN kenne ich mich nicht aus, ist mir jetzt auch zu kompliziert. Kann ich die Datei irgendwie per wget ziehen oder irgendwie anders vergleichbar einfach?

Aber in den anderen Fällen (zu schneller Restart) stand entweder was im log (Port 7072 noch nicht wieder freigegeben) oder schlicht nichts (so einen Fall hatte CoolTux geschildert auf einer virtualisierten Maschine, soweit ich das verstanden hatte).

Würde also als erstes mal ins log schauen, evtl. kann man dann erkennen, ob es tatsächlich doch an einem Modul hängt.

OK, meinen funktionierenden Zustand wieder hergestellt, Backup eingespielt, "attr global verbose 4", update ausgeführt, Log sieht wie folgt aus:

2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57295 POST /fhem&fw_id=109&cmd=update; BUFLEN:0
2018.01.10 17:02:49 3: telnetForBlockingFn_1515600169.04724: port 36621 opened
2018.01.10 17:02:49 4: BlockingCall (doUpdateInBackground): created child (31271), uses telnetForBlockingFn_1515600169.04724 to connect back
2018.01.10 17:02:49 4: WEB: /fhem&fw_id=109&cmd=update / RL:9441 / text/html; charset=UTF-8 / Content-Encoding: gzip
/
2018.01.10 17:02:49 4: Connection closed for WEB_XX.XX.XX.XX_57310: EOF
2018.01.10 17:02:49 4: Connection accepted from WEB_XX.XX.XX.XX_57314
2018.01.10 17:02:49 4: Connection accepted from WEB_XX.XX.XX.XX_57315
2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57295 GET /fhem/pgm2/jquery.min.js; BUFLEN:0
2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57295 => 304 Not Modified
2018.01.10 17:02:49 4: Connection closed for WEB_XX.XX.XX.XX_57315: EOF
2018.01.10 17:02:49 4: Connection accepted from WEB_XX.XX.XX.XX_57316
2018.01.10 17:02:49 4: Connection closed for WEB_XX.XX.XX.XX_57314: EOF
2018.01.10 17:02:49 4: Connection accepted from WEB_XX.XX.XX.XX_57317
2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57295 GET /fhem/pgm2/style.css?v=1515600027; BUFLEN:0
2018.01.10 17:02:49 4: Connection accepted from WEB_XX.XX.XX.XX_57318
2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57317 GET /fhem/pgm2/fhemweb.js; BUFLEN:0
2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57317 => 304 Not Modified
2018.01.10 17:02:49 4: Connection closed for WEB_XX.XX.XX.XX_57316: EOF
2018.01.10 17:02:49 4: Connection accepted from WEB_XX.XX.XX.XX_57319
2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57318 GET /fhem/pgm2/jquery-ui.min.js; BUFLEN:0
2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57318 => 304 Not Modified
2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57318 GET /fhem/pgm2/console.js; BUFLEN:0
2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57318 GET /fhem/images/default/icoEverything.png; BUFLEN:0
2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57318 => 304 Not Modified
2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57295 GET /fhem/pgm2/defaultCommon.css; BUFLEN:0
2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57295 => 304 Not Modified
2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57295 GET /fhem/pgm2/dashboard_style.css; BUFLEN:0
2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57295 => 304 Not Modified
2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57295 GET /fhem/images/default/fhemicon.png; BUFLEN:0
2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57295 => 304 Not Modified
2018.01.10 17:02:49 4: WEB_XX.XX.XX.XX_57295 GET /fhem?XHR=1&inform=type=status;filter=;since=1515600168;fmt=JSON&fw_id=109×tamp=1515600167989; BUFLEN:0
2018.01.10 17:02:50 4: Connection closed for WEB_XX.XX.XX.XX_57295: EOF
2018.01.10 17:02:50 4: WEB_XX.XX.XX.XX_57318 GET /fhem?XHR=1&inform=type=raw;withLog=1;filter=global×tamp=1515600168895; BUFLEN:0
2018.01.10 17:02:51 4: Connection accepted from telnetForBlockingFn_1515600169.04724_127.0.0.1_32816
2018.01.10 17:02:51 4: backup include: ''
2018.01.10 17:02:51 4: backup include: ''
2018.01.10 17:02:51 4: backup exclude: './backup'
2018.01.10 17:02:51 4: backup include: './certs'
2018.01.10 17:02:51 4: backup include: './CHANGED'
2018.01.10 17:02:51 4: backup include: './configDB.pm'
2018.01.10 17:02:51 4: backup include: './contrib'
2018.01.10 17:02:51 4: backup include: './demolog'
2018.01.10 17:02:51 4: backup include: './docs'
2018.01.10 17:02:51 4: backup include: './FHEM'
2018.01.10 17:02:51 4: backup include: './fhem-5.8.deb'
2018.01.10 17:02:51 4: backup include: './fhem.cfg'
2018.01.10 17:02:51 4: backup include: './fhem.cfg.backup'
2018.01.10 17:02:51 4: backup include: './fhem.cfg.CUL_HM'
2018.01.10 17:02:51 4: backup include: './fhem.cfg.demo'
2018.01.10 17:02:51 4: backup include: './fhem.cfg.save'
2018.01.10 17:02:51 4: backup include: './fhem.pl'
2018.01.10 17:02:51 4: backup include: './log'
2018.01.10 17:02:51 4: backup include: './MAINTAINER.txt'
2018.01.10 17:02:51 4: backup include: './README_DEMO.txt'
2018.01.10 17:02:51 4: backup include: './restoreDir'
2018.01.10 17:02:51 4: backup include: './unused'
2018.01.10 17:02:51 4: backup include: './www'
2018.01.10 17:02:51 2: Backup with command: tar -cf - "./certs" "./CHANGED" "./configDB.pm" "./contrib" "./demolog" "./docs" "./FHEM" "./fhem-5.8.deb" "./fhem.cfg" "./fhem.cfg.backup" "./fhem.cfg.CUL_HM" "./fhem.cfg.demo" "./fhem.cfg.save" "./fhem.pl" "./log" "./MAINTAINER.txt" "./README_DEMO.txt" "./restoreDir" "./unused" "./www" |gzip > ./backup/FHEM-20180110_170251.tar.gz
2018.01.10 17:03:01 1: backup done: FHEM-20180110_170251.tar.gz (76349721 Bytes)
2018.01.10 17:03:01 4: https://fhem.de/fhemupdate/controls_fhem.txt: HTTP response code 200
2018.01.10 17:03:01 1: Got remote controls_fhem.txt with 2039 entries.
2018.01.10 17:03:01 1: Got local controls_fhem.txt with 2039 entries.
2018.01.10 17:03:01 4: https://fhem.de/fhemupdate/CHANGED: HTTP response code 200
2018.01.10 17:03:01 1: mv ./www/pgm2/fhemweb_multiple.js ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/fhemweb_noArg.js ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/fhemweb_slider.js ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/fhemweb_svg.js ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/fhemweb_textField.js ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/fhemweb_time.js ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/darktouchpadsvg_defs.svg ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/darktouchpadsvg_style.css ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/ios6touchpadsvg_defs.svg ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/ios6touchpadsvg_style.css ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/ios7touchpadsvg_defs.svg ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/ios7touchpadsvg_style.css ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/iostouchpadsvg_defs.svg ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/iostouchpadsvg_style.css ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/darksmallscreensvg_defs.svg ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/darksmallscreensvg_style.css ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/ios7smallscreensvg_defs.svg ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/ios7smallscreensvg_style.css ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/iossmallscreensvg_defs.svg ./unused
2018.01.10 17:03:01 1: mv ./www/pgm2/iossmallscreensvg_style.css ./unused
2018.01.10 17:03:01 1: mv ./FHEM/firmware/LaCrosseGateway.bin ./unused
2018.01.10 17:03:01 1: UPD FHEM/98_DLNARenderer.pm
2018.01.10 17:03:01 4: https://fhem.de/fhemupdate/FHEM/98_DLNARenderer.pm: HTTP response code 200
2018.01.10 17:03:01 1: saving fhem.cfg
2018.01.10 17:03:01 1: saving ./log/fhem.save
2018.01.10 17:03:01 1: Calling /usr/bin/perl ./contrib/commandref_join.pl -noWarnings, this may take a while
2018.01.10 17:03:05 1:
2018.01.10 17:03:05 1: update finished, "shutdown restart" is needed to activate the changes.
2018.01.10 17:03:05 1:
2018.01.10 17:03:05 4: fheminfo send (blocking): {"CUL_HM":{"ActionDetector":"1","CCU-FHEM":"1","HM-CC-RT-DN":"7"},"FHEMWEB":{"noModel":"3"},"FileLog":{"noModel":"8"},"HMLAN":{"noModel":"1"},"allowed":{"noModel":"4"},"autocreate":{"noModel":"1"},"eventTypes":{"noModel":"1"},"notify":{"noModel":"1"},"system":{"configType":"configFile","os":"linux","perl":"5.24.1","revision":"15836","uniqueID":"87769fa25f579509132d25b6914d5dcf"},"telnet":{"noModel":"1"}}
2018.01.10 17:03:05 4: https://fhem.de/stats/statistics2.cgi: HTTP response code 200
2018.01.10 17:03:05 4: fheminfo send: Server RESPONSE: ==> ok
2018.01.10 17:03:05 1: fheminfo Statistics data sent to server. See Logfile (level 4) for details.
2018.01.10 17:03:12 4: Connection closed for WEB_XX.XX.XX.XX_57319: EOF
2018.01.10 17:03:12 4: WEB_XX.XX.XX.XX_57317 GET /fhem/FileLog_logWrapper?dev=Logfile&type=text&file=fhem-2018-01.log; BUFLEN:0
2018.01.10 17:03:12 4: Connection closed for WEB_XX.XX.XX.XX_57318: EOF
2018.01.10 17:03:12 4: Connection accepted from WEB_XX.XX.XX.XX_57321
2018.01.10 17:03:12 4: WEB_XX.XX.XX.XX_57317 GET /fhem/pgm2/jquery.min.js; BUFLEN:0
2018.01.10 17:03:12 4: WEB_XX.XX.XX.XX_57317 => 304 Not Modified
2018.01.10 17:03:12 4: Connection accepted from WEB_XX.XX.XX.XX_57322
2018.01.10 17:03:12 4: Connection accepted from WEB_XX.XX.XX.XX_57323
2018.01.10 17:03:12 4: WEB_XX.XX.XX.XX_57317 GET /fhem/pgm2/style.css?v=1515600027; BUFLEN:0
2018.01.10 17:03:12 4: Connection closed for WEB_XX.XX.XX.XX_57321: EOF
2018.01.10 17:03:12 4: Connection accepted from WEB_XX.XX.XX.XX_57324
2018.01.10 17:03:12 4: Connection closed for WEB_XX.XX.XX.XX_57323: EOF
2018.01.10 17:03:12 4: Connection closed for WEB_XX.XX.XX.XX_57322: EOF
2018.01.10 17:03:12 4: Connection accepted from WEB_XX.XX.XX.XX_57325
2018.01.10 17:03:12 4: WEB_XX.XX.XX.XX_57324 GET /fhem/pgm2/jquery-ui.min.js; BUFLEN:0
2018.01.10 17:03:12 4: WEB_XX.XX.XX.XX_57324 => 304 Not Modified
2018.01.10 17:03:12 4: WEB_XX.XX.XX.XX_57325 GET /fhem/pgm2/fhemweb.js; BUFLEN:0
2018.01.10 17:03:12 4: WEB_XX.XX.XX.XX_57325 => 304 Not Modified
2018.01.10 17:03:12 4: Connection accepted from WEB_XX.XX.XX.XX_57326
2018.01.10 17:03:12 4: WEB_XX.XX.XX.XX_57325 GET /fhem/images/default/icoEverything.png; BUFLEN:0
2018.01.10 17:03:12 4: WEB_XX.XX.XX.XX_57325 => 304 Not Modified
2018.01.10 17:03:12 4: WEB_XX.XX.XX.XX_57317 GET /fhem/pgm2/defaultCommon.css; BUFLEN:0
2018.01.10 17:03:12 4: WEB_XX.XX.XX.XX_57317 => 304 Not Modified
2018.01.10 17:03:12 4: WEB_XX.XX.XX.XX_57317 GET /fhem/pgm2/dashboard_style.css; BUFLEN:0
2018.01.10 17:03:12 4: WEB_XX.XX.XX.XX_57317 => 304 Not Modified
2018.01.10 17:03:12 4: WEB_XX.XX.XX.XX_57317 GET /fhem/images/default/fhemicon.png; BUFLEN:0
2018.01.10 17:03:12 4: WEB_XX.XX.XX.XX_57317 => 304 Not Modified
2018.01.10 17:03:12 4: WEB_XX.XX.XX.XX_57317 GET /fhem/FileLog_logWrapper?XHR=1&inform=type=status;filter=;since=1515600191;fmt=JSON&fw_id=130×tamp=1515600191563; BUFLEN:0
2018.01.10 17:04:14 4: Connection closed for WEB_XX.XX.XX.XX_57326: EOF
2018.01.10 17:04:14 4: WEB_XX.XX.XX.XX_57325 GET /fhem?room=Bad; BUFLEN:0
2018.01.10 17:04:14 4: WEB: /fhem?room=Bad / RL:9644 / text/html; charset=UTF-8 / Content-Encoding: gzip
/
2018.01.10 17:04:14 4: Connection closed for WEB_XX.XX.XX.XX_57317: EOF
2018.01.10 17:04:14 4: Connection accepted from WEB_XX.XX.XX.XX_57327
2018.01.10 17:04:14 4: WEB_XX.XX.XX.XX_57325 GET /fhem/pgm2/jquery.min.js; BUFLEN:0
2018.01.10 17:04:14 4: WEB_XX.XX.XX.XX_57325 => 304 Not Modified
2018.01.10 17:04:14 4: WEB_XX.XX.XX.XX_57324 GET /fhem/pgm2/jquery-ui.min.js; BUFLEN:0
2018.01.10 17:04:14 4: WEB_XX.XX.XX.XX_57324 => 304 Not Modified
2018.01.10 17:04:14 4: Connection accepted from WEB_XX.XX.XX.XX_57328
2018.01.10 17:04:14 4: Connection accepted from WEB_XX.XX.XX.XX_57329
2018.01.10 17:04:14 4: WEB_XX.XX.XX.XX_57325 GET /fhem/pgm2/style.css?v=1515600027; BUFLEN:0
2018.01.10 17:04:14 4: Connection closed for WEB_XX.XX.XX.XX_57327: EOF
2018.01.10 17:04:14 4: WEB_XX.XX.XX.XX_57324 GET /fhem/pgm2/fhemweb.js; BUFLEN:0
2018.01.10 17:04:14 4: WEB_XX.XX.XX.XX_57324 => 304 Not Modified
2018.01.10 17:04:14 4: Connection closed for WEB_XX.XX.XX.XX_57328: EOF
2018.01.10 17:04:14 4: WEB_XX.XX.XX.XX_57324 GET /fhem/images/default/icoEverything.png; BUFLEN:0
2018.01.10 17:04:14 4: WEB_XX.XX.XX.XX_57324 => 304 Not Modified
2018.01.10 17:04:14 4: WEB_XX.XX.XX.XX_57325 GET /fhem/pgm2/defaultCommon.css; BUFLEN:0
2018.01.10 17:04:14 4: WEB_XX.XX.XX.XX_57325 => 304 Not Modified
2018.01.10 17:04:14 4: WEB_XX.XX.XX.XX_57325 GET /fhem/pgm2/dashboard_style.css; BUFLEN:0
2018.01.10 17:04:14 4: WEB_XX.XX.XX.XX_57325 => 304 Not Modified
2018.01.10 17:04:14 4: WEB_XX.XX.XX.XX_57325 GET /fhem/images/default/fhemicon.png; BUFLEN:0
2018.01.10 17:04:14 4: WEB_XX.XX.XX.XX_57325 => 304 Not Modified
2018.01.10 17:04:15 4: WEB_XX.XX.XX.XX_57325 GET /fhem?XHR=1&inform=type=status;filter=room=Bad;since=1515600253;fmt=JSON&fw_id=138×tamp=1515600253720; BUFLEN:0
2018.01.10 17:04:21 4: WEB_XX.XX.XX.XX_57324 POST /fhem?XHR=1&cmd=shutdown%20restart&fw_id=138; BUFLEN:0
2018.01.10 17:04:21 0: Server shutdown
2018.01.10 17:04:32 1: Including fhem.cfg
2018.01.10 17:04:32 3: telnetPort: port 7072 opened
2018.01.10 17:04:32 3: WEB: port 8083 opened
2018.01.10 17:04:32 3: WEBphone: port 8084 opened
2018.01.10 17:04:32 3: WEBtablet: port 8085 opened
2018.01.10 17:04:32 2: eventTypes: loaded 370 events from ./log/eventTypes.txt
2018.01.10 17:04:32 1: HMLAN_Parse: HMUSB new condition disconnected
2018.01.10 17:04:32 3: Opening HMUSB device 127.0.0.1:1234
2018.01.10 17:04:32 1: HMLAN_Parse: HMUSB new condition init
2018.01.10 17:04:32 3: HMUSB device opened
2018.01.10 17:04:33 1: Including ./log/fhem.save
2018.01.10 17:04:33 3: Device HM_3D944E added to ActionDetector with 000:10 time
2018.01.10 17:04:33 3: Device HM_3D9466 added to ActionDetector with 000:10 time
2018.01.10 17:04:33 3: Device HM_3D9490 added to ActionDetector with 000:10 time
2018.01.10 17:04:33 3: Device HM_47D5B1 added to ActionDetector with 000:10 time
2018.01.10 17:04:33 3: Device HM_47FEC3 added to ActionDetector with 000:10 time
2018.01.10 17:04:33 3: Device HM_4A706E added to ActionDetector with 000:10 time
2018.01.10 17:04:33 3: Device HM_4A75C5 added to ActionDetector with 000:10 time
2018.01.10 17:04:33 0: Featurelevel: 5.8
2018.01.10 17:04:33 0: Server started with 72 defined entities (fhem.pl:15804/2018-01-06 perl:5.024001 os:linux user:fhem pid:31366)
2018.01.10 17:04:33 1: HMLAN_Parse: HMUSB new condition ok

Meine IP habe ich unkenntlich gemacht. Mit verbose lvel 3 sieht man gar nichts, deshalb bin ich eins höher gegangen. Seht ihr da was? Oder brauchen wir noch verbose level 5?

Gruß Hoppel

[Beta-User]

Laut dem log ist FHEM wieder gestartet - da scheint also noch was anderes verbogen zu sein.

Wann war das letzte update? Wenn das länger her war: Gibt massenhaft Threads dazu...

Insbesondere noch: Bist du mit der zugreifenden Maschine im selben Netz? Ein "allowed"-Device hast du angelegt?
EDIT: Das kann es nicht sein, sonst würde es ja auch bei manuellem Start nicht gehen...

[hoppel118]

Wenn jedoch eine ShutdownFn einen Fehler wirft kann fhem aussteigen bevor der Programmteil für den restart erreicht ist und ohne das was im log landet. Getestet

Müsste in dem Fall nicht die Aktivierung des folgenden Parameters im systemd Script helfen:

Code Auswählen Erweitern

Restart=on-abnormal # uncomment for crash and watchdog event recovery only (keeps shutdown working)

Oder bin ich da falsch davor? Die Option greift bei "shutdown restart" nicht.

Gruß Hoppel

[hoppel118]

Laut dem log ist FHEM wieder gestartet - da scheint also noch was anderes verbogen zu sein.

OK, das ist bescheiden. Das WebInterface kriege ich dann nicht mehr ran und "systemctl status fhem" gibt dann folgendes aus:

Code Auswählen Erweitern

root@omv4:~# systemctl status fhem
● fhem.service - FHEM Home Automation
   Loaded: loaded (/etc/systemd/system/fhem.service; enabled; vendor preset: enabled)
   Active: inactive (dead) since Wed 2018-01-10 17:04:21 CET; 7s ago
  Process: 31082 ExecStart=/usr/bin/perl fhem.pl fhem.cfg (code=exited, status=0/SUCCESS)
Main PID: 31083 (code=exited, status=0/SUCCESS)
      CPU: 15.620s

Jan 10 17:00:27 omv4 systemd[1]: Starting FHEM Home Automation...
Jan 10 17:00:27 omv4 systemd[1]: Started FHEM Home Automation.

Wann war das letzte update? Wenn das länger her war: Gibt massenhaft Threads dazu...

Jo, das ist definitiv länger her. Ein halbes Jahr oder so...

Insbesondere noch: Bist du mit der zugreifenden Maschine im selben Netz? Ein "allowed"-Device hast du angelegt?

Ja, ich bin im selben Netz. Nein habe ich nicht konfiguriert. Wofür brauche ich das? SSH, WebInterface läuft doch alles.

Wenn du mir den Befehl schnell nennst, mache ich das gerade noch.

[Beta-User]

Das ist schon sehr seltsam. Hier findet lt. log ein erfolgreicher Restart statt, es dürfte m.E. daher auch nicht am Startscript liegen, sondern an irgendwas danach.

Hier scheint der prozess ja danach wieder gestorben zu sein, oder deute ich den Status falsch?!?

Zu allowed aus der Commandref:

define allowedWEB allowed
attr allowedWEB validFor WEB,WEBphone,WEBtablet
attr allowedWEB basicAuth { "$user:$password" eq "admin:secret" }
attr allowedWEB allowedCommands set,get

define allowedTelnet allowed
attr allowedTelnet validFor telnetPort
attr allowedTelnet password secret

Schadet in jedem Fall nicht, muß aber natürlich auf deine Namen angepaßt werden.

Die systemd-Einstellungen würde ich auf die default-Werte zurückbiegen, evtl. kommt sich sonst systemd und restart aus FHEM in die Quere.

Wenn das alles nichts hilft und FHEM doch läuft: Firewall usw.?
Mal anderen Browser/anderes Gerät versuchen nach dem Restart, ob FHEM von dort aus erreichbar ist?

[kadettilac89]

deinen Posts nach hast du etwas Ahnung von Linux.

1) Du hast jetzt ein System.d Startscript, im Backup müsstest du ja noch das init.d im contrib-Ordner haben
2) Hast du mal geprüft ob ggf. Fhem 2 mal läuft? "ps -ef | grep -i fhem"

Ich würde das systemd deaktivieren und das alte init.d wieder aktivieren. Dann kannst erstmal das Thema "Startscript" ausschließen wenn du damit starten kannst.

Allowed wurde schon genannt. Es scheint als würde Fhem irgendwie wieder sterben. Hast du mal im syslog nachgesehen ob du dort Fehler siehst? Zugriffsrechte, Module, Perl-Fehler, ...

Setze mal verbose auf 5 ... wenn du nicht mehr an die Oberfläche kommst ist das hier eine Ausnahme wo direktes Editieren OK ist

attr global verbose 5


... nachtrag: letztes Init.d müsste das hier sein ... https://github.com/mhop/fhem-mirror/commit/95cae7634894ba13ecfb15f8b491dd35c9e345b1

[hoppel118]

OK, ich muss erstmal weg. Ich schaue mir das heute Abend nochmal an.