Hilfe erbeten: FHEM beendet sich selbst nach Update

[netwalk]

Heute habe ich nach zwei/drei Wochen mal wieder ein Update gestartet. Es lief problemlos durch, jedoch beendet sich FHEM nach dem obligatorischen Neustart nach einigen Sekunden von selbst.
Wird der Dienst manuell über Putty gestartet, geschieht das gleiche.

Nun habe ich danach das vorher angelegte Backup zurückgespielt und wahlfrei nur ein Modul aktualisiert (z.B. 59_Weather.pm oder 10_KNX.pm).
Der Fehler bleibt: Update läuft durch, nach Neustart beendet sich FHEM von selbst.

Zur Fehlerverfolgung habe ich vorher den Verbose-Level auf 5 gestellt, werde aber von der Flut der nun auflaufenden Meldungen erschlagen. Der letzte Eintrag im Logfile ist immer verschieden, so dass ich nicht ein bestimmtes Modul als Fehlergrund ausmachen kann. Ich sehe nur, dass nach dem Update der Server normal startet und nach einigen Sekunden das Logfile abbricht (wenn der Dienst beendet wird).

Hat dieses Problem noch jemand, und wie gehe ich zur Fehlereingrenzung weiter vor?

Code Auswählen Erweitern


2016.04.21 12:15:59 5: Cmd: >{Log('1','update finished, "shutdown restart" is needed to activate the changes.')}<
2016.04.21 12:15:59 1: update finished, "shutdown restart" is needed to activate the changes.
...
2016.04.21 12:18:06 0: Server started with 481 defined entities (fhem.pl:11267/2016-04-17 perl:5.014002 os:linux user:fhem pid:25283)


Die letzten Einträge im Logfile bei den einzelnen Versuchen waren z.B.:

Code Auswählen Erweitern

2016.04.21 11:45:31 5: Triggering FritzBox (70 changes)
2016.04.21 11:45:31 5: Starting notify loop for FritzBox, first event tam1_oldMsg: 0
2016.04.21 11:45:31 5: rg.Temperature: not on any display, ignoring notify
Undefined subroutine &main::YahooWeatherAPI_RetrieveDataWithCache called at ./FHEM/59_Weather.pm line 122.

oder:

Code Auswählen Erweitern

2016.04.21 12:18:52 5: Starting notify loop for sysmon, first event fs_root: Total: 29836 MB, Used: 4791 MB, 17 %, Available: 23784 MB at /
2016.04.21 12:18:52 5: rg.Temperature: not on any display, ignoring notify
2016.04.21 12:18:52 5: EDIPLUG: GetUpdate
2016.04.21 12:18:52 4: HttpUtils url=http://admin:1234@192.168.10.152:10000/smartplug.cgi
2016.04.21 12:18:52 4: http://admin:1234@192.168.10.150:10000/smartplug.cgi: HTTP response code 200
2016.04.21 12:18:52 4: HttpUtils http://admin:1234@192.168.10.150:10000/smartplug.cgi: Got data, length: 149
2016.04.21 12:18:52 5: 20_WLAN01 , Read : HASH(0x21d1348) , <?xml version="1.0" encoding="UTF8"?><SMARTPLUG id="edimax"><CMD id="get"><Device.System.Power.State>ON</Device.System.Power.State></CMD></SMARTPLUG>

No value specified for 'ForceArray' option in call to XMLin() at ./FHEM/98_EDIPLUG.pm line 223



[CoolTux]

Schau mal ob Du unter fhem/FHEM/ eine Datei Namens YahooWeatherAPI.pm hast. Wenn ja schaue ob die Rechte die selben wie bei den anderen Dateien sind.

[netwalk]

Ja, da ist folgende Datei:

Code Auswählen Erweitern

YahooWeatherAPI.pm     10.485B     29.03.2016 08:57:00     rw-r--r--     fhem     dialout

Hat die gleichen Rechte wie die meisten anderen Module.

[CoolTux]

Sicher das fhem beendet ist

Code Auswählen Erweitern


ps ax | grep fhem


Zeig mal die Ausgabe nach einem

Code Auswählen Erweitern


/etc/init.d/fhem stop

bisschen warten

Code Auswählen Erweitern


/etc/init.d/fhem start


[netwalk]

Hier sind die Ausgaben:

Eine Minute nach dem Update und Restart:

Code Auswählen Erweitern

pi@RasPi ~ $ ps ax | grep fhem
28828 pts/0    S+     0:00 grep --color=auto fhem


Nächste Eingabe:

Code Auswählen Erweitern


pi@RasPi ~ $ sudo /etc/init.d/fhem stop
Stopping fhem...
Can't connect to localhost:7072


Heißt doch, dass FHEM nicht mehr läuft, oder? Im "Top" sehe ich auch kein FHEM mehr...

Nächste Aktion:

Code Auswählen Erweitern

pi@RasPi ~ $ sudo /etc/init.d/fhem start
Starting fhem...
pi@RasPi ~ $ ps ax | grep fhem
28839 pts/0    R      0:04 perl fhem.pl fhem.cfg
28843 pts/0    S+     0:00 grep --color=auto fhem


Eine Minute später:

Code Auswählen Erweitern

pi@RasPi ~ $ ps ax | grep fhem
28898 pts/0    S+     0:00 grep --color=auto fhem


Spiele jetzt das Backup wieder ein...

[CoolTux]

Scheint in der Tat weg zu knallen.
Du kannst mal stacktrace in der Config aktivieren. Ist ein Attribut für Global.

[netwalk]

Aktiviert habe ich stacktrace jetzt.

Wie verfahre ich damit? Update wieder einspielen und auf welche Einträge achten?
Reicht Verbose-Level 3?

Sorry, bin kein Linux/Perl Experte, eher SQL...

[CoolTux]

Einfach Neustart von FHEM und danach ins Log schauen wenn es wieder weg ist. Default verbose sollte erstmal reichen

[netwalk]

So, habe es gerade erst geschafft das Update erneut einzuspielen.
Stacktrace ist aktiviert, jedoch ändert sich im Logfile nicht viel:

Code Auswählen Erweitern

2016.04.26 07:38:38 0: Server started with 479 defined entities (fhem.pl:11304/2016-04-24 perl:5.014002 os:linux user:fhem pid:16787)
2016.04.26 07:38:38 3: Opening CUBE device 192.168.10.7:62910
2016.04.26 07:38:38 3: CUBE device opened
2016.04.26 07:38:40 3: 20_WLAN01: return error[1] -> connect to to http://192.168.10.150:10000 timed out
2016.04.26 07:38:41 3: 21_WLAN02: return error[1] -> connect to to http://192.168.10.151:10000 timed out
2016.04.26 07:38:41 3: sw.li.eg.Arbeitszimmer.1: return error[1] -> connect to to http://192.168.10.152:10000 timed out
No value specified for 'ForceArray' option in call to XMLin() at ./FHEM/98_EDIPLUG.pm line 223
2016.04.26 07:39:29 1: BlockingInformParent (SYSMON_blockingFinish): Can't connect to localhost:7072: IO::Socket::INET: connect: Verbindungsaufbau abgelehnt


Der Dienst bricht nach knapp einer Minute einfach weg.

[netwalk]

Hat noch jemand eine Idee?

[Wernieman]

im Lofile steht:

Code Auswählen Erweitern

2016.04.26 07:38:40 3: 20_WLAN01: return error[1] -> connect to to http://192.168.10.150:10000 timed out
2016.04.26 07:38:41 3: 21_WLAN02: return error[1] -> connect to to http://192.168.10.151:10000 timed out
2016.04.26 07:38:41 3: sw.li.eg.Arbeitszimmer.1: return error[1] -> connect to to http://192.168.10.152:10000 timed out


Kannst Du diese 3 Sachen mal "deaktivieren" bzw. löschen?

Sicherheitshalber vorher einfach mal eine kopie der fhem.cfg (per Console)

[netwalk]

Dabei handelt es sich um drei EDIMAX WLAN-Steckdosen, die ersten beiden werden z.Zt. nicht eingesetzt, die dritte wird vom Modul EDIPLUG immer direkt nach dem Neustart nicht erkannt, später schon.

Deaktiviert hatte ich sie probeweise auch schon, jedoch ohne Erfolg. FHEM beendet sich trotzdem.

[Wernieman]

Deaktiviere bitte ein mal sysmon

Code Auswählen Erweitern

BlockingInformParent (SYSMON_blockingFinish): Can't connect to localhost:7072: IO::Socket::INET: connect: Verbindungsaufbau abgelehnt

Ansonsten .. Dein Logfile ist nicht Aussagekräftiger? Mal verbose 5 ausprobiert?

[netwalk]

Im Logfile steht auch bei Verbose 5 leider nichts Aussagekräftiges und bei jedem Versuch etwas anderes (s. Start-Post).
Stacktrace habe ich auf Anraten von CoolTux auch schon  probiert.

Mir gehen langsam die Ideen und Optionen aus...

[Wernieman]

Habe meinen Beitrag korrigiert:
"Bitte deaktiviere Sysmon"

"To many Fingers on Keyboard"