fhem Totalschaden nach FB 7390 reboot - invalid dirhandle fhem.pl line 2429

[Groby]

Hallo,

letzten Sonntag ist mir fhem auf 2 unterschiedlichen FB 7390 mit OS6.04 nach einem telnet/reboot bzw. Webinterface/Neustart immer mit folgender Fehlermeldung hängengeblieben:

closedir() attempted on invalid dirhandle DH at fhem.pl line 2429

Als Ergebnis enthielt fhem.save nach dem Fehler nur noch 2 Zeilen:

Code Auswählen Erweitern


#Sun Jul  3 14:47:31 2016
setstate global no definition


Log:

Code Auswählen Erweitern


2016.07.03 14:11:30.132 1: Including fhem.cfg
2016.07.03 14:11:31.139 1: Including fhem.cfg
2016.07.03 14:11:31.587 1: Including ./FHEM/99_fhem.cfg
2016.07.03 14:11:32.311 3: telnetPort: port 7072 opened
2016.07.03 14:11:40.727 3: WEB: port 8083 opened
2016.07.03 14:11:41.068 3: WEBphone: port 8084 opened
2016.07.03 14:11:41.246 3: WEBtablet: port 8085 opened
2016.07.03 14:11:41.370 3: WEBmobil: port 8086 opened
2016.07.03 14:11:43.420 1: CUL_0 device is none, commands will be echoed only
2016.07.03 14:11:43.963 1: Including ./FHEM/99_init.cfg
2016.07.03 14:11:44.103 3: FHEM2FHEM opening FH2_Logger at 192.168.128.3:7072
2016.07.03 14:11:48.864 1: Including ./FHEM/99_devices.cfg
2016.07.03 14:11:49.081 1: Including ./FHEM/99_structure.cfg
2016.07.03 14:11:49.666 1: Including ./FHEM/99_webcam.cfg
2016.07.03 14:11:50.770 1: Including ./FHEM/99_at.cfg
2016.07.03 14:11:50.976 1: Including ./FHEM/99_notify.cfg
2016.07.03 14:11:51.944 1: Including ./log/fhem.save
2016.07.03 14:11:52.121 1: PERL WARNING: closedir() attempted on invalid dirhandle DH at fhem.pl line 2429.
2016.07.03 14:11:52.816 1: Including ./FHEM/99_fhem.cfg
2016.07.03 14:11:57.069 1: Including ./FHEM/99_init.cfg
2016.07.03 14:11:59.981 1: Including ./FHEM/99_devices.cfg
2016.07.03 14:12:01.303 1: Including ./FHEM/99_structure.cfg
2016.07.03 14:12:03.028 1: Including ./FHEM/99_webcam.cfg
2016.07.03 14:12:34.580 1: Including ./FHEM/99_at.cfg
2016.07.03 14:12:35.406 1: Including ./FHEM/99_notify.cfg
2016.07.03 14:12:58.438 1: Including ./log/fhem.save
2016.07.03 14:12:58.446 1: configfile: telnetPort already defined, delete it first


Versions:

Code Auswählen Erweitern


fhem.pl             11715 2016-06-25 15:26:33Z rudolfkoenig
96_allowed.pm       11391 2016-05-05 11:16:05Z rudolfkoenig
98_apptime.pm        8074 2015-02-22 19:31:19Z betateilchen
90_at.pm            11342 2016-04-29 11:25:51Z rudolfkoenig
98_autocreate.pm    11094 2016-03-20 09:41:03Z rudolfkoenig
00_CUL.pm           11637 2016-06-09 18:01:20Z rudolfkoenig
98_dummy.pm         11442 2016-05-15 12:43:12Z rudolfkoenig
93_FHEM2FHEM.pm     11732 2016-07-02 17:41:31Z rudolfkoenig
01_FHEMWEB.pm       11726 2016-06-29 12:55:12Z rudolfkoenig
92_FileLog.pm       11336 2016-04-28 19:28:05Z rudolfkoenig
10_FS20.pm          11432 2016-05-12 08:35:57Z rudolfkoenig
98_HMinfo.pm        11685 2016-06-18 08:02:09Z martinp876
98_HourCounter.pm   11307 2016-04-25 08:02:06Z rudolfkoenig
49_IPCAM.pm          2626 2013-02-01 19:19:15Z mfr69bs
99_MyUtils.pm           1 2013-03-25 20:15:33Z Groby
91_notify.pm        11178 2016-04-03 14:20:32Z rudolfkoenig
73_PRESENCE.pm      11650 2016-06-12 14:28:18Z markusbloch
70_Pushover.pm      11616 2016-06-05 12:30:42Z loredo
33_readingsGroup.pm 11573 2016-05-31 06:54:52Z justme1968
98_structure.pm     10530 2016-01-16 19:27:21Z rudolfkoenig
99_SUNRISE_EL.pm    10569 2016-01-19 06:30:28Z rudolfkoenig
98_SVG.pm           11687 2016-06-18 16:47:13Z rudolfkoenig
98_telnet.pm        11606 2016-06-03 18:43:06Z rudolfkoenig
99_Utils.pm         10570 2016-01-19 06:39:23Z rudolfkoenig
98_version.pm       11026 2016-03-08 07:25:45Z markusbloch
Blocking.pm         11465 2016-05-16 11:56:10Z rudolfkoenig
DevIo.pm            11732 2016-07-02 17:41:31Z rudolfkoenig
FritzBoxUtils.pm     6574 2014-09-19 17:32:48Z rudolfkoenig
HMConfig.pm         11645 2016-06-11 09:54:00Z martinp876
HttpUtils.pm        11715 2016-06-25 15:26:33Z rudolfkoenig
RTypes.pm           10476 2016-01-12 21:03:33Z borisneubert
SetExtensions.pm    11513 2016-05-24 17:56:05Z rudolfkoenig
TcpServerUtils.pm   10346 2016-01-03 12:34:27Z rudolfkoenig


Fhem ist in diesem Zustand nicht nutzbar. Der Workaround zum Wiederbeleben von fhem:

• fhem per telnet killen. Möglicherweise geht auch ein shutdown
• alte fhem.save restoren
• fhem mit sh startfhem wieder starten

Ein erneuter Reboot via telnet oder Webinterface kommt leider zum gleichen Ergebnis.

Ein manuelles Einlesen der Original fhem.save half nicht, da die Werte teilweise nicht übernommen werden. Das Einlesen der cfg-files mit include lief bisher tadellos. Das Umkopieren in eine fhem.cfg brachte leider auch keinen Erfolg.

Ich kann aber nicht sagen bis wann der reboot/Neustart der FB 7390 einwandfrei funktioniert hat.

Hat irgendjemand eine Idee wie weit ich mit den Updates zurück gehen muss, damit fhem den reboot der FB 7390 "überlebt"?

Ich bin für jede Hilfe dankbar.

MfGroby

[rudolfkoenig]

Ich gehe davon aus, dass die Fehlermeldung nicht an fhem.pl oder an einem der "normalen" Module liegt, sondern an einem der 99'er  privaten Module. Zwischen opendir (mit Pruefung) und closedir ist nur das Einlesen dieser Module nennenswert. Ich wuerde die eigenen 99'er Module zunaechst in einem Unterverzeichnis "verstecken", und schauen, was passiert. Wenn das nicht hilft, dann muss "attr global verbose 5" dran.

[Groby]

Hallo Rudi,

das klingt leider gar nicht gut. Das werde ich erst am Wochenende testen können...

Ein update, save, shutdown restart läuft weiterhin problemlos.

Gibt es einen Unterschied zwischen "shutdown restart" im Vergleich zum "reboot der Fritzbox"?

Gruss, Groby

[rudolfkoenig]

Gibt es einen Unterschied zwischen "shutdown restart" im Vergleich zum "reboot der Fritzbox"?

Tausende, von denen hier bestimmt dutzend relevant sein koennten
Beim "shutdown restart" wird nur FHEM neu gestartet. Beim reboot werden die einzelnen Fritzbox-Dienste hochgefahren. Wenn beim FHEM-Start manche andere (AHA-Server, Netzwerk, Netz-Laufwerk, Uhrzeit, etc) noch nicht fertig sind, dann kann das auf FHEM eine Auswirkung haben.

[Groby]

Ich habe meine 99.cfg und 99.pm in ein anderes Verzeichnis verschoben und versucht fhem.demo als Hauptsystem zu starten.

Nach klicken auf "log" stürzt auch fhem.demo ab. Es wird aber kein Logfile angelegt. Ich habe das Logfile "fhem-2016-07.log" manuell angelegt, aber es bleibt trotzdem leer. Status der devices ist nach dem FritzBox reboot "? ? ?".

Morgen früh werde ich mit meiner config ein verbose 5 mitschneiden, die sensitiven Info's unkenntlich machen und posten...

[Groby]

Hallo Rudi,

ich habe wie gewünscht die 99er Dateien entfernt und die Box neu gestartet. Die Fehlermeldung "invalid dirhandle" kommt dann nicht mehr. Somit scheint die Fehlermeldung die Folge eines vorherigen Fehlers zu sein.

Die fhem.save wird irgendwie nicht richtig eingelesen. Nach dem hochfahren enthält diese immer nur 2 Zeilen (Inhalt einer alten Datei - aber immer gleiches Schema):

#Sun Jul  3 14:47:31 2016
setstate global no definition

Beim Autostart/reboot fällt auf, dass beim Einlesen der fhem.save wieder nur 2 Zeilen eingelesen werden:

Code Auswählen Erweitern


2016.07.09 08:34:01.787 1: Including ./log/fhem.save
2016.07.09 08:34:01.789 5: Cmd: >setstate global no definition<
2016.07.09 08:34:01.791 5: Triggering global (1 changes)
2016.07.09 08:34:01.793 5: Starting notify loop for global, first event REREADCFG



Wenn ich die startfhem umbenenne, die FritzBox reboote und fhem manuell nach einigen Minuten starte, dann läuft alles problemlos.

Das komplette logfile sende ich lieber per PM für den Fall dass ich irgendwelche sensitiven Daten übersehen habe...

MfGroby

[Groby]

Es scheint tatsächlich daran zu liegen, daß die FritzBox irgendetwas nicht rechtzeitig startet. Das Erhöhen von "Sleep 2" in der startfhem half leider nicht.

Ich habe es folgendermaßen wieder zum Laufen bekommen:

* startfhem als start kopiert
* startfhem modifiziert perl myfhem.pl
* myfhem.pl ruft start auf

So startet fhem wieder und fhem.save wird problemlos eingelesen.

Nicht schön, aber selten