at-Timer laufen nach Reboot Amok

[Carsten]

Hallo,

ich habe ein wiederkehrendes Problem, wenn ich den Banana-Pi, auf dem mein FHEM läuft, neu starte.
Nach shutdown -r des Systems werden jedes Mal einige at-Timer scheinbar in Endlosschleife hintereinander getriggert:

Code Auswählen Erweitern

..
2018-02-17 16:45:36 at tmr_CheckTherme Next: 16:31:56
2018-02-17 16:45:36 at tmr_CheckPresence Next: 16:32:05
2018-02-17 16:45:36 at tmr_UpdateTrocknerEnergy Next: 14:47:05
2018-02-17 16:45:36 at tmr_CheckTherme Next: 16:36:56
2018-02-17 16:45:36 at tmr_CheckPresence Next: 16:37:05
2018-02-17 16:45:36 at tmr_UpdateTrocknerEnergy Next: 14:57:05
2018-02-17 16:45:36 at tmr_CheckTherme Next: 16:41:56
2018-02-17 16:45:36 at tmr_CheckPresence Next: 16:42:05
2018-02-17 16:45:36 at tmr_UpdateTrocknerEnergy Next: 15:07:05
2018-02-17 16:45:36 at tmr_CheckTherme Next: 16:46:56
2018-02-17 16:45:36 at tmr_CheckPresence Next: 16:47:05
2018-02-17 16:45:36 at tmr_UpdateTrocknerEnergy Next: 15:17:05
2018-02-17 16:45:36 at tmr_CheckTherme Next: 16:51:56
2018-02-17 16:45:36 at tmr_CheckPresence Next: 16:52:05
2018-02-17 16:45:36 at tmr_UpdateTrocknerEnergy Next: 15:27:05
2018-02-17 16:45:36 at tmr_CheckTherme Next: 16:56:56
2018-02-17 16:45:36 at tmr_CheckPresence Next: 16:57:05
2018-02-17 16:45:36 at tmr_UpdateTrocknerEnergy Next: 15:37:05
2018-02-17 16:45:36 at tmr_CheckTherme Next: 17:01:56
2018-02-17 16:45:36 at tmr_CheckPresence Next: 17:02:05
2018-02-17 16:45:36 at tmr_UpdateTrocknerEnergy Next: 15:47:05
2018-02-17 16:45:36 at tmr_CheckTherme Next: 17:06:56
2018-02-17 16:45:36 at tmr_CheckPresence Next: 17:07:05
2018-02-17 16:45:36 at tmr_UpdateTrocknerEnergy Next: 15:57:05
2018-02-17 16:45:36 at tmr_CheckTherme Next: 17:11:56
2018-02-17 16:45:36 at tmr_CheckPresence Next: 17:12:05
2018-02-17 16:45:36 at tmr_UpdateTrocknerEnergy Next: 16:07:05
2018-02-17 16:45:36 at tmr_CheckTherme Next: 17:16:56
2018-02-17 16:45:36 at tmr_CheckPresence Next: 17:17:05
2018-02-17 16:45:36 at tmr_UpdateTrocknerEnergy Next: 16:17:05
2018-02-17 16:45:36 at tmr_CheckTherme Next: 17:21:56
2018-02-17 16:45:36 at tmr_CheckPresence Next: 17:22:05
2018-02-17 16:45:36 at tmr_UpdateTrocknerEnergy Next: 16:27:05
2018-02-17 16:45:36 at tmr_CheckTherme Next: 17:26:56
2018-02-17 16:45:36 at tmr_CheckPresence Next: 17:27:05
2018-02-17 16:45:36 at tmr_UpdateTrocknerEnergy Next: 16:37:05
2018-02-17 16:45:36 at tmr_CheckTherme Next: 17:31:56
2018-02-17 16:45:36 at tmr_CheckPresence Next: 17:32:05
2018-02-17 16:45:36 at tmr_UpdateTrocknerEnergy Next: 16:47:05
...

Nach

Code Auswählen Erweitern

shutdown restart von FHEM ist der Spuk vorbei.

Die Timer sind alle Wiederholungstimer.
Bsp:

Code Auswählen Erweitern

define tmr_CheckTherme at +*00:05:00 { CheckTherme() }

Es sieht irgendwie so aus, als wäre FHEM der Meinung, X Tage/Wochen/Monate an verpassten Timern nachholen zu müssen, aber warum? Aufgefallen ist mir das das erste Mal vor einigen Wochen. Ob das davor auch schon so aussah, weiß ich nicht.

Ich hab schon versucht, vor dem Reboot ein save config und ein Shutdown von FHEM zu machen, ohne Änderung.

Foren- ( und Google-) suche war leider wenig ergiebig, da "at" ein ungünstiger Suchbegriff ist.

Hat jemand einen Tipp?

Gruß
Carsten

[KernSani]

Hi Carsten,

Nachvollziehen kann ich das nicht...
wenn hier niemand antwortet evtl. das Thema im Unterforum "Automatisierung" neu eröffnen (bei neuen Themen dort wir Rudi benachrichtigt, bei verschobenen Themen nicht) und dieses hier - mit einem Verweis auf das neue Thema - schliessen.

[CoolTux]

Stimmt denn die Systemzeit wenn fhem startet nach einem rebbot des ganzen Systems?

[KernSani]

Stimmt denn die Systemzeit wenn fhem startet nach einem rebbot des ganzen Systems?

war auch mein erster Gedanke, aber selbst dann sollte FHEM keine Timer in der Vergangenheit anlegen, oder?

[CoolTux]

Sowas ähnliches hatten wir schon mal. Da würden alle at ausgeführt welcher zwischen letzten Stand und neuer Systemzeit hätten laufen müssen.

[Carsten]

Hallo und danke schonmal für den Input!

Da soweit ich weiß, der Banana-Pi genau wie die Raspberry-Pis keine RTC hat und sich die Zeit erstmal online holen muss, kann es sein, dass die Zeit unmittelbar nach Reboot noch nicht stimmt.
Sowas hatte ich auch im Verdacht, aber das Problem müsste dann ja jeder haben, dessen FHEM auf Raspberry-Pis oder ähnlichem läuft und außerdem kann ich mir nicht vorstellen, dass das gewollt sein soll, dass dann alle Timer zwischen alter Zeit und neuer Zeit nachgeholt werden. Das würde dann ja auch bedeuten, dass ein Timer, der z.B. jede Minute feuern soll, beim Beginn der Sommerzeit 60 mal hintereinander triggert.

Sowas ähnliches hatten wir schon mal. Da würden alle at ausgeführt welcher zwischen letzten Stand und neuer Systemzeit hätten laufen müssen.

Hast du zufällig einen Link oder einen Suchbegriff?

[CoolTux]

Naja jeder der sich keine Gedanken macht.
Das Suchwort heißt Timeserver. Die meisten stellen einen Timeserver ein, meist die Fritzbox oder ein anderer Server. Bei mir ist es ein BananaPi Router welcher wiederum die Zeit von der Fritzbox bekommt.

[Carsten]

Naja jeder der sich keine Gedanken macht.
Das Suchwort heißt Timeserver. Die meisten stellen einen Timeserver ein, meist die Fritzbox oder ein anderer Server. Bei mir ist es ein BananaPi Router welcher wiederum die Zeit von der Fritzbox bekommt.

Das macht der Banana ja wie die Raspis auch und füttert damit die Fake-RTC. Aber dazu muss logischerweise erstmal das Netzwerk bereit sein.
Gerade wegen des NTP-Servers hätte man ja auch z.B. bei der Umstellung auf Sommerzeit das gleiche Problem, wenn das Standardverhalten wäre.

[CoolTux]

Deswegen war es ja auch nur eine Vermutung

[Carsten]

Mein Verständis vom at im Format +*00:05:00 ist, dass beim Define ein Eintrag für now + 5 Minuten gesetzt wird.
Ist die Zeit erreicht, wird das Event getriggert und ein neuer Eintrag für now + 5 Minuten gesetzt.

Das müsste dann bei Start mit falschem Datum aber so ähnlich aussehen:

• falsches Datum beim Start ist z.B. 01.01.2010 00:00:00 Uhr
• Event wird geplant für 01.01.2010 00:05:00 Uhr
• Uhrzeit wird korrigiert auf 18.02.2018 18:00 Uhr
• 01.01.2010 00:05:00 Uhr ist kleiner 18.02.2018 18:00 Uhr
• Event wird getriggert und neues Event berechnet für now ( 18.02.2018 18:00 ) + 5 Minuten -> 18.02.2018 18:05
• kein weiteres Event bis 18:05

Dann müsste aber nach ein ( oder zwei ) Fehlauslösungen Schluss sein. Warum der die Timer ein paar hundert Mal triggert, verstehe ich nicht.
Irgendwas übersehe ich scheinbar.

[KölnSolar]

weil das periodische at die nächste Ausführung anhand der aktuellen Ausführungszeit(aus der fhem.save, die nicht der tatsächlichen Zeit entspricht) + Periode berechnet.

[Carsten]

weil das periodische at die nächste Ausführung anhand der aktuellen Ausführungszeit(aus der fhem.save, die nicht der tatsächlichen Zeit entspricht) + Periode berechnet.

Die fhem.save wird aber doch bei Save config geschrieben. Das habe ich ja kurz vor dem Reboot gemacht. Dann hätte die Zeit ja eigentlich maximal 2-3 Ausführungen hinterherhinken dürfen.
Ich habe gerade auch mal reingeschaut. Nach Save Config steht in der fhem.save

Code Auswählen Erweitern

setstate tmr_CheckTherme Next: 19:10:46
setstate tmr_CheckTherme 2018-02-18 19:05:46 state Next: 19:10:46

[KölnSolar]

Die fhem.save wird aber doch bei Save config geschrieben. Das habe ich ja kurz vor dem Reboot gemacht. Dann hätte die Zeit ja eigentlich maximal 2-3 Ausführungen hinterherhinken dürfen.

Genau. Deshalb verstehe ich Dein Problem auch nicht. Bei sauberem shutdown existiert das beschriebene Problem nur nach längeren FHEM-Stillstandszeiten. Wurde FHEM vielleicht nicht ordentlich beendet(=keine aktuelle fhem.save) ?

[Damian]

Bei sauberem shutdown existiert das beschriebene Problem nur nach längeren FHEM-Stillstandszeiten.

Das wäre aber ein Designfehler. Bei einem relativen Timer, sollte das Modul vom aktuellen Zeitpunkt ausgehen, um den nächsten Trigger zu berechnen.

[Frank_Huber]

Warum dem pi (ob jetzt banana oder raspberry is egal) nicht für 1,50 inkl Versand nen RTC Chip spendieren?
Damit hast das Problem ein für alle mal los.

Alternativ kannst auch den fhem Start verzögern.
So lange bis das Netzwerk oben und der ntp abgefragt ist.
Blöd dann nur wenn der ntp oder das Netzwerk nicht verfügbar sind...

Also klare Empfehlungen: RTC einbauen!

Mit dem Handy online, daher kurz gefasst...

[Carsten]

Genau. Deshalb verstehe ich Dein Problem auch nicht. Bei sauberem shutdown existiert das beschriebene Problem nur nach längeren FHEM-Stillstandszeiten. Wurde FHEM vielleicht nicht ordentlich beendet(=keine aktuelle fhem.save) ?

Wie gesagt: Ich habe beim Testen ja explizit noch vorher gesaved und später sogar noch explizit ein shtutdown von FHEM vor dem Shutdown vom Host gemacht. Immer mit demselben Effekt.

Bei einem relativen Timer, sollte das Modul vom aktuellen Zeitpunkt ausgehen, um den nächsten Trigger zu berechnen.

Davon bin ich auch ausgegangen. Und bis vor ein paar Wochen ist mir dieses Verhalten auch nie aufgefallen. Das muss allerdings nicht heißen, dass es dieses Verhalten nicht gab, aber die Effekte sind schon recht auffällig, denn einer der Timer fragt alle 10 Minuten den aktuellen Zählerstand einer Z-Wave-Steckdose ab, was dazu führt, dass mehrere tausend Z-Wave-cmds in der Queue landen.

Warum dem pi (ob jetzt banana oder raspberry is egal) nicht für 1,50 inkl Versand nen RTC Chip spendieren?
Damit hast das Problem ein für alle mal los.

Wenn ich wüsste, dass das Problem damit wirklich gelöst ist...
Im Moment ist das ja nur eine Vermutung. Und wenn das Verhalten grundsätzlich so wäre, müssten doch alle mit FHEM auf Pi (und das sind imho recht viele ) das Problem haben. Die werden ja nicht alle eine RTC haben, oder?
Zumal das Problem bei Zeitanpassungen ( z.B. Sommerzeit ) ja vermutlich auch auftreten würde.

[Frank_Huber]

https://wiki.fhem.de/wiki/Raspberry_Pi
Abschnitt Echtzeituhr.

Meine FHEM Instanzen (4 produktiv, 1 Test) laufen alle super, auch wenn mal paar Tage aus.
Wobei paar Tage aus nur bei der test Instanz vorkommt.

Mit dem Handy online, daher kurz gefasst...

[Damian]

Code Auswählen Erweitern

define tmr_CheckTherme DOIF ([+00:05]) { CheckTherme() }
attr tmr_CheckTherme do always

Bevor du Geld in neue Hardware investierst, kannst du es damit versuchen. Dieses Modul geht von aktueller Zeit beim Setzen des nächsten Zeittimers aus.

[KölnSolar]

Und wenn das Verhalten grundsätzlich so wäre, müssten doch alle mit FHEM auf Pi (und das sind imho recht viele ) das Problem haben. Die werden ja nicht alle eine RTC haben, oder?

Genau. Muss man nicht haben.

Zumal das Problem bei Zeitanpassungen ( z.B. Sommerzeit ) ja vermutlich auch auftreten würde.

Bin mir nicht sicher, aber Zeitumstellung ist als Sonderfall glaub ich berücksichtigt.

sollte das Modul vom aktuellen Zeitpunkt ausgehen,

Aber der ist im Rebootfall des PI ja bis zum Inetsynchronisieren auch noch falsch und FHEM schon fleißig...

mehrere tausend Z-Wave-cmds in der Queue landen

Kann bei funktionierendem reboot/fhem.save und Zeitsynchronisierung nicht sein.
Du könntest evtl. den FHEM-Start von der Zeitsynchronisierung des Rpi abhängig machen oder mit timelag starten. Ich brauchs nicht, habs aber schon ein paar mal gelesen...

[Frank_Huber]

Klar, muss jeder selbst wissen.
Mir war es die 1,50 pro raspberry wert.
Hatte nie Probleme mit der Uhrzeit.

Mit dem Handy online, daher kurz gefasst...

[Carsten]

Ich habe es jetzt wie in diesem Thread ( aus dem Wiki-Beitrag von Frank_Huber ) versucht, aber ich bin mir zum einen nicht sicher, ob die Reihenfolge jetzt stimmt, aber davon abgesehen ist laut daemon.log auch nach dem Start von ntp noch eine Weile das Datum falsch ( 2016 ), bevor die aktuelle Zeit geladen wird.

[Frank_Huber]

bei meiner letzten Installation bin ich nach dieser Anleitung vorgegangen, lief problemlos:

There are only two edits you need to do:
1. put the below line into the /boot/config.txt file: (edit it with your favourite editor and type the line in - or copy and paste it from here )
dtoverlay=i2c-rtc,ds3231
2. edit the /lib/udev/hwclock-set file (sudo nano /lib/udev/hwclock-set) and "comment out" the following lines ("comment out" means put a # at the beginning of each of the lines, so they sudo -ibecome comments and are ignored by the system)
if [ -e /run/systemd/system ] ; then
exit 0
fi
so they become:
#if [ -e /run/systemd/system ] ; then
# exit 0
#fi
...and that's it - that's all you need to do. Shut down your system, connect the rtc module, then power up and test with the command:
sudo hwclock -r

[Carsten]

Ich glaub, das ist ein Mißverständnis.
Das sieht nach einrichten der RTC aus, oder?

Ich hab ( noch ) keine. Ich hatte versucht, FHEM erst nach NTP zu starten über

Code Auswählen Erweitern

/etc/systemd/system/fhem.service.d/fhem.conf

[Frank_Huber]

OK, dann hab ich das Missverstanden, sorry.

[Carsten]

Kein Problem. Spätestens, wenn ich den Versuch, ohne RTC auszukommen, aufgegeben habe, kann ich das brauchen.