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?
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.:
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:
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
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.
Ja, da ist folgende Datei:
YahooWeatherAPI.pm 10.485B 29.03.2016 08:57:00 rw-r--r-- fhem dialout
Hat die gleichen Rechte wie die meisten anderen Module.
Sicher das fhem beendet ist
ps ax | grep fhem
Zeig mal die Ausgabe nach einem
/etc/init.d/fhem stop
bisschen warten
/etc/init.d/fhem start
Hier sind die Ausgaben:
Eine Minute nach dem Update und Restart:
pi@RasPi ~ $ ps ax | grep fhem
28828 pts/0 S+ 0:00 grep --color=auto fhem
Nächste Eingabe:
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:
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:
pi@RasPi ~ $ ps ax | grep fhem
28898 pts/0 S+ 0:00 grep --color=auto fhem
Spiele jetzt das Backup wieder ein...
Scheint in der Tat weg zu knallen.
Du kannst mal stacktrace in der Config aktivieren. Ist ein Attribut für Global.
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...
Einfach Neustart von FHEM und danach ins Log schauen wenn es wieder weg ist. Default verbose sollte erstmal reichen
So, habe es gerade erst geschafft das Update erneut einzuspielen.
Stacktrace ist aktiviert, jedoch ändert sich im Logfile nicht viel:
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.
Hat noch jemand eine Idee?
im Lofile steht:
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)
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.
Deaktiviere bitte ein mal sysmon
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?
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...
Habe meinen Beitrag korrigiert:
"Bitte deaktiviere Sysmon"
"To many Fingers on Keyboard"
So, habe jetzt mit deaktiviertem SYSMON noch einmal das Update ausgeführt, leider ohne Erfolg.
FHEM schmiert nach knapp einer Minute ohne aussagekräftigen Logeintrag ab.
Kanst Du mal ... fhem runterfahren, die config sichern, einfache Konfig hinlegen, fhem hochfahren und update ausprobieren?
@Wernieman
Das war ein guter Tipp. Vielen Dank!
Es gibt neue Erkenntnisse:
Das Problem scheint tatsächlich etwas mit dem EDIPLUG-Modul zu tun zu haben. Wenn ich die EDIMAX-Steckdosen deaktiviere, läuft FHEM auch nach dem Update.
Was ich nicht verstehe ist, dass das 98_EDIPLUG.pm in der Version vom 20.01.2016 vorliegt, also durch das Update überhaupt nicht geändert wurde! Vor dem Update läuft alles einwandfrei, nach dem Update schmiert FHEM ab, beides mit der gleichen Version vom EDIPLUG Modul.
Eine der Steckdosen wird wie folgt definiert:
define sw.li.eg.Arbeitszimmer.1 EDIPLUG 192.168.10.152
attr sw.li.eg.Arbeitszimmer.1 alias AZ Micha
attr sw.li.eg.Arbeitszimmer.1 devStateIcon off:light_light_dim_00@gainsboro on:light_light_dim_100b@orange
attr sw.li.eg.Arbeitszimmer.1 event-min-interval power_day:600,power_month:600,power_now:600
attr sw.li.eg.Arbeitszimmer.1 event-on-change-reading state,onoff,power_now:0.01,power_day:0.001,power_month:0.001
attr sw.li.eg.Arbeitszimmer.1 icon socket_timer
attr sw.li.eg.Arbeitszimmer.1 interval 60
attr sw.li.eg.Arbeitszimmer.1 model SP2101W
attr sw.li.eg.Arbeitszimmer.1 password 1234
attr sw.li.eg.Arbeitszimmer.1 read-only 0
attr sw.li.eg.Arbeitszimmer.1 room IP.POWER,Widget,dummy
attr sw.li.eg.Arbeitszimmer.1 stateFormat onoff
attr sw.li.eg.Arbeitszimmer.1 timeout 10
attr sw.li.eg.Arbeitszimmer.1 user admin
define FileLog_sw.li.eg.Arbeitszimmer.1 FileLog ./log/sw.li.eg.Arbeitszimmer.1-%Y.log sw.li.eg.Arbeitszimmer.1:power_now.*|sw.li.eg.Arbeitszimmer.1:power_day.*|sw.li.eg.Arbeitszimmer.1:power.month.*
attr FileLog_sw.li.eg.Arbeitszimmer.1 room Logs
Wie kann ich weiter vorgehen, um die Steckdosen wieder nutzen zu können?
Sorry, kenne das Modul nicht (bzw. habe es nicht in Verwendung). Kann Dir also nicht weiterhelfen.
Aber gut, das
1. Ein Workarround existiert
2. Das Problem eingekreist werden konnte