Zeitproblem: Alle Zeiten werde um eine Stunde zu spät angelegt

Zrrronggg! · 12 April 2016, 01:36:20

Im Zusammenhang mit einigen Seltsamigkeiten die besonders meine Holde moniert hat, bin ich zuerst darauf gestossen, das sunset und sunrise Zeiten bei mir falsch berechnet werden, siehe hier

https://forum.fhem.de/index.php?topic=52063.msg438250

Bei nähere Untersuchung und Diskussion bin ich aber darauf gekommen, das in meinem System ALLE Zeiten eine Stunde zu spät sind. Und zwar mit einem Twist...

1. Die Uhr des Rechners geht richtig.

Zitatxyz@zyx:~# date
Tue Apr 12 00:58:22 CEST 2016

Zitatxyz@zyx:~# hwclock
Tue Apr 12 00:58:23 2016 0.000000 seconds

zeigten die zu dem Zeitpunkt richtige Uhrzeit an.

2. Wenn ich irgendwas anlege, was eine absolute Zeit ergibt, sei es mit
at 01:00:00
oder
{sunset()}
ergibt sich immer eine Ausführungszeit die eine Stunde zu spät ist.

Das hier:

Code Auswählen

define Licht_Test at 01:17:44 set Licht_StehlampeC_WZ_U off
führt dazu, dass Fhem meint die nächste Ausführung sei um 02:17:44

Jetzt kommt der Twist:
Es ist nicht etwa so, dass der Befehl aufgrund eines Uhrzeitproblem eine Stunde zu spät angelegt wird und dann auch eine Stunde früher - also doch zur richtigen Zeit ausgeführt wird - man das Problem also lösen könnte in dem man die Zeitzone verbiegt.

Vielmehr wird der Befehl tatsächlich zur falsch berechneten Uhrzeit aber dann korrekt ausgeführt.

Code Auswählen

define Licht_Test at 01:17:44 set Licht_StehlampeC_WZ_U off
führt dazu, dass Fhem meint, die nächste Ausführung sei um 02:17:44
und es wird dan auch tatsächlich um 02:17:44 geschaltet.

Ich hab das eben quasi ins extrem getrieben:

Ich habe um 01:31 folgenden Befehl eingegeben.

Code Auswählen

define Licht_Test2 at 00:33:30 set Licht_StehlampeC_WZ_U off

Eigentlich ist die Uhrzeit in der Vergangenheit, die nächste Auslösung sollte also MORGEN sein.
Tatsächlich aber zeigen die readings:

ZitatReadings
state
Next: 01:33:30
2016-04-12 01:31:46

D.h. die Uhrzeit wann ich den Befehl eingegeben habe wird korrekt erkannt, dann wird das nächste Event FALSCH berechnet und knapp 2 Minuten später geht genau zur falsch berechneten Uhrzeit das Licht aus.

Code Auswählen

define Licht_Test2 at +00:01:30 set Licht_StehlampeC_WZ_U off
hingegen ergibt die RICHTIGE Zeit:

ZitatReadings
state
Next: 01:48:19
2016-04-12 01:46:49

Kapier ich nicht.
Irgendjemand eine Idee?

Ich weiss leider nicht wie lange das so schon geht, da die die meisten Schaltungen passieren wenn ich nicht da bin.

viegener · 12 April 2016, 01:57:13

Im ersten Moment ist das auf jeden Fall rätselhaft.
Kann es vielleicht sein, dass es unterschiedliche timezone Einstellungen für FHEM bzw. den FHEM Benutzer und Deine shell-Benutzer (also die interaktive Session in der Du Date eingibst)?

Was steht denn im Log file, wenn ein solcher trigger kommt? Wenn da dieselbe Urhzeit steht wie im at angegeben, dann ist vermutlich obige Vermutung richtig. Wenn da etwas anderes steht, ist etwas sehr komisch...

Johannes

Zrrronggg! · 12 April 2016, 02:28:29

Hm... sicherheitshalber gleich noch mal getestet:

Code Auswählen

define Licht_Test at 01:24:30 set Licht_StehlampeC_WZ_U off

ZitatReadings
state
Next: 02:24:30
2016-04-12 02:23:24

Lampe geht tatsächlich um 2:24:30, also ca. eine Minute später aus
Logfile sagt:

Zitat2016.04.12 02:24:30 2: IT set Licht_StehlampeC_WZ_U off

ZitatKann es vielleicht sein, dass es unterschiedliche timezone Einstellungen für FHEM bzw. den FHEM Benutzer und Deine shell-Benutzer (also die interaktive Session in der Du Date eingibst)?

Klingt als Idee nicht schlecht, nur: Ob das sein kann oder nicht kann ich nicht beurteilen.
Ich bin jetzt nicht der Über-LINUX-Crack um es vorsichtig zu formulieren und hätte keine Ahnung wie man die Zeit von FHEM bzw FHEMs user verstellen könnte.

Ausserdem: so richtig logisch ist das nicht, denn das würde bedeuten das FHEM zum Errechnen einer Uhrzeit seine eigene Zeit verwendet, zur Auslösung eines Events aber nicht. Das klingt mir nicht sehr wahrscheinlich.

Übrigens zeigt ein INFO TIMER in telnet auf FHEM alle Events mit der richtigen Uhrzeit.

Das sieht für mich nicht so aus, also ob FHEM ne andere Uhrzeit hat.

Ellert · 12 April 2016, 11:14:47

Was liefert FHEM beim Ausführen von

Code Auswählen

{$isdst} in der Eingabezeile?

viegener · 12 April 2016, 14:59:37

Nochmals die Frage: Was steht denn im FHEM-Logfile (u.U. musst Du das Attribute verbose noch hochstellen), da aber die Einträge im Log mit einem Zeitstempel versehen werden, kannst Du da erkennen was für eine Zeit FHEM glaubt zu haben...

(Alternativ kannst Du auch einfach mal den Event Monitor anwerfen)

Johannes

Markus · 12 April 2016, 17:07:42

was sagt den

Code Auswählen

{localtime}

Gruß Markus

Zrrronggg! · 12 April 2016, 22:52:14

{$isdst} liefert "1"
Was sagt das aus?

ZitatNochmals die Frage: Was steht denn im FHEM-Logfile

Hm. Das Logfile zeigt alle Operationen richtig aber mit einer Stunde zu spät an.

Code Auswählen

define Licht_Test at 01:24:30 set Licht_StehlampeC_WZ_U off

Ergibt readings

ZitatReadings
state
Next: 02:24:30
2016-04-12 02:23:24

Lampe ging tatsächlich um 2:24:30, also ca. eine Minute später aus
und im Logfile stand dann:

Zitat2016.04.12 02:24:30 2: IT set Licht_StehlampeC_WZ_U off

D.H. die Logfile-Uhrzeiten sehen unauffällig aus. Sie korospondieren mit der tatsächlichen Uhrzeit.

Oder was meinst du?

Auch Telnet und INFO TIMER zeigt alle Events mit der tatsächlichen Uhrzeit an. Soweit sichtbar stimmt alles im System - überall ist die richtige Uhrzeit - egal was ich frage, in welche Logs ich sehe oder ob ich events mit Telnet beobachte. Nur alle absoluten "at" Commandos werden für eine Stunde später als "befohlen" angelegt.

{localtime}
gibt die tatsächliche aktuelle Uhrzeit aus. Als jetzt gerade:

ZitatTue Apr 12 22:51:24 2016

und es ist jetzt auch 22:51 Uhr

Zrrronggg! · 12 April 2016, 23:01:56

Eben nochmal neu probiert:

Eingabe von

Zitatdefine Licht_Test2 at 23:01:00 set Licht_StehlampeC_WZ_U off

führt laut telnet inform timer zu diesem:

Zitat
2016-04-12 22:59:41 at Licht_Test2 Next: 00:01:00
2016-04-12 22:59:41 Global global DEFINED Licht_Test2

Aktuell Uhrzeit des Rechner bzw der Timer Ausgabe RICHTIG, errechnete Ausführungsuhrzeit eine Stunde zu spät.

Internals

ZitatCFGFN
COMMAND
set Licht_StehlampeC_WZ_U off
DEF
2016-04-13T00:01:00 set Licht_StehlampeC_WZ_U off
NAME
Licht_Test2
NR
2060
PERIODIC
no
RELATIVE
no
STATE
Next: 00:01:00
TIMESPEC
23:01:00
TRIGGERTIME
1460498460
TRIGGERTIME_FMT
2016-04-13 00:01:00
TYPE
at
VOLATILE
1

Timespec steht auf die eigentlich richtige Zeit 23:01, Triggertime (beide) und "next" aber nicht.

Kapier ich nicht.

viegener · 13 April 2016, 00:04:03

Ich muss zugeben ich bin ratlos, denn meine Vermutung war, dass fhem intern irgendwie von einer falschen Zeit ausging. Die Zeit intern in fhem scheint aber richtig zu sein (inkl Sommerzeit --> isdst).

Beim Anlegen des at's wird aber eine falsche Zeit gesetzt, mir fällt dazu aber keine Ursache ein.
Sorry

Zrrronggg! · 13 April 2016, 01:08:06

Tja, wen frag ich? Rudolf König?

Prof. Dr. Peter Henning · 13 April 2016, 03:31:24

Ich würde mir mal auf Systemebene die Zeitzone ansehen.

LG

pah

rudolfkoenig · 13 April 2016, 12:18:16

Klarstellung: andere Installation haben das Problem nicht, sonst haette ich mehr darueber gehoert. Auch ich konnte das bei mir nicht reproduzieren. Nach analysieren der Daten (bitte die Internals demnaechst besser formatieren), gehe ich davon aus, dass dein mktime() oder localtime() Funktion kaputt (oder nicht FHEM-Kompatibel

) ist.
Kannst du bitte folgendes nachstellen, und hier berichten?

Code Auswählen

fhem> { join(",", localtime(1460498460)) }
0,1,0,13,3,116,3,103,1
fhem> { mktime(0,1,0,13,3,116) }
1460498460
fhem> { mktime(0,1,23,12,3,116) }
1460494860
fhem> { localtime(1460494860) }
Tue Apr 12 23:01:00 2016
fhem> { join(",", localtime(1460494860)) }
0,1,23,12,3,116,2,102,1

Zrrronggg! · 13 April 2016, 13:15:00

Hi Rudi,

Ja, generell kaputt ist Fhem sicher nicht, ich hab ja vorher auch gesucht und offenbar hat das ausser mir keiner.

Hier die Ergebnisse:

Code Auswählen

fhem> { join(",", localtime(1460498460)) }
0,1,0,13,3,116,3,103,1
fhem> { mktime(0,1,0,13,3,116) }
1460502060
fhem> { mktime(0,1,23,12,3,116) }
1460498460
fhem> { localtime(1460494860) }
Tue Apr 12 23:01:00 2016
fhem> { join(",", localtime(1460494860)) }
0,1,23,12,3,116,2,102,1

mktime() Wert sieht anders aus. Hm. Aber wieso? (Gut, das ist dann vermutlich keine Fhem-spezifische Frage)

rudolfkoenig · 13 April 2016, 13:21:37

Versuch mal mktime mit allen Werten localtime, also mit insg. 9 Werten.

Welches OS und Perl Version hast du?

Zrrronggg! · 13 April 2016, 13:29:36

Vergib mir, wenn ich ich mir hier als Linux Noob oute:

ZitatVersuch mal mktime mit allen Werten localtime, also mit insg. 9 Werten.

Äh.. verstehe ich so noch nicht... sorry.

Linux <...> 2.6.16.16-arm1 #383 Mon Nov 10 13:33:20 JST 2008 armv5tejl
This is perl, v5.8.8 built for armv5tejl-linux

Das Ganze läuft bei mir auf einer LinkStation und ich habe wenig Möglichkeit da einfach mal upzudaten. Jedenfalls nicht mit meinem Kenntnislevel.
Vieleicht muss ich mal mit einem Raspi oder so befassen.