Autor Thema: InternalTimer um 00:00:00  (Gelesen 242 mal)

Offline Loredo

  • Developer
  • Hero Member
  • ****
  • Beiträge: 3498
  • ~ Challenging Innovation ~
InternalTimer um 00:00:00
« am: 12 Juni 2019, 10:28:13 »
Hallo Rudi,


beim setzen von InternalTimer mit einer Zeit um Mitternacht fällt mir auf, dass diese immer erst exakt 2 Sekunden später ausgeführt werden.
In InternalTimer() und HandleTimeout() konnte ich keinen Grund dafür finden, hast du eine Idee für dieses Verhalten? Soll das die Peak Systemlast zu der Zeit reduzieren (man kann ja annehmen, dass das Hostsystem selbst zu der Zeit auch so einiges zu tun hat)?

Die Forumsuche hat mir auch nichts zu Tage befördert; in %intAt steht der von mir gesetzte Wert drin, nicht jener +2sec.


Gruß
Julian
FHEM-Module: ENIGMA2, GEOFANCY, PHTV, RESIDENTS, ROOMMATE, GUEST, HP1000, Pushover, THINKINGCLEANER, Wunderground | FHEM-Befehl: msg

FHEM-Docker auf Intel NUC mit Proxmox VE
Homematic via HMCCU, Hue Color Bulbs, LG OLED 65C8, Sonos Playbar+2xOne+Sub, 2x Sonos One, 1x Sonos Play:1

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 20520
Antw:InternalTimer um 00:00:00
« Antwort #1 am: 13 Juni 2019, 09:43:31 »
Zitat
beim setzen von InternalTimer mit einer Zeit um Mitternacht fällt mir auf, dass diese immer erst exakt 2 Sekunden später ausgeführt werden.
Mir ist kein Mechanismus bewusst, was dieses Verhalten verursachen koennte.
Ich wuerde mit "fhemdebug timerList" pruefen, welche Funktionen um Mitternacht ausgefuehrt werden, evtl. ist einer von diesen Funktionen CPU-Intensiv. und blockiert die anderen.

Offline Loredo

  • Developer
  • Hero Member
  • ****
  • Beiträge: 3498
  • ~ Challenging Innovation ~
Antw:InternalTimer um 00:00:00
« Antwort #2 am: 13 Juni 2019, 09:54:03 »
"fhemdebug timerList" zeigt hier wie gesagt 00:00:00 an, so wie erwartet:



2019-06-13 09:52:24.00000 FW_closeInactiveClients
2019-06-13 10:47:41.53170 Weather_GetUpdate
2019-06-13 22:12:45.00000 at_Exec
2019-06-13 22:12:45.17691 Twilight_fireEvent
2019-06-13 23:11:59.18561 Twilight_fireEvent
2019-06-14 00:00:00.00000 FHEM::Astro::Update
2019-06-14 00:00:01.00000 FileLog_dailySwitch
2019-06-14 00:00:01.19949 Twilight_Midnight
2019-06-14 04:42:51.00000 at_Exec


Es lässt sich auch mit fhem.cfg.demo reproduzieren (zugegeben nur mit Umstellung der Systemzeit, wenn man nicht warten will), da blockiert AFAIK nichts.


 :(


Ist jetzt sicherlich nicht höchst dramatisch, aber eben seltsam.


Könnte es etwas mit FileLog_dailySwitch zu tun haben?
FHEM-Module: ENIGMA2, GEOFANCY, PHTV, RESIDENTS, ROOMMATE, GUEST, HP1000, Pushover, THINKINGCLEANER, Wunderground | FHEM-Befehl: msg

FHEM-Docker auf Intel NUC mit Proxmox VE
Homematic via HMCCU, Hue Color Bulbs, LG OLED 65C8, Sonos Playbar+2xOne+Sub, 2x Sonos One, 1x Sonos Play:1

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 20520
Antw:InternalTimer um 00:00:00
« Antwort #3 am: 13 Juni 2019, 10:21:24 »
Ich habe die Uhr auf 2019-06-12 23:55 gestellt, "perl fhem.pl fhem.cfg.demo" gestartet, und ein at definiert:

fhem> define midnightAt at 00:00 { Log 1, "Bing!" } 

fhem> fhemdebug timerList
2019-06-12 23:58:15.00000 FW_closeInactiveClients
2019-06-12 23:58:32.20107 RESIDENTStk_DurationTimer
2019-06-12 23:58:32.20239 RESIDENTStk_DurationTimer
2019-06-12 23:58:32.20330 RESIDENTStk_DurationTimer
2019-06-12 23:58:32.20418 RESIDENTStk_DurationTimer
2019-06-12 23:58:32.20502 RESIDENTStk_DurationTimer
2019-06-12 23:58:32.20586 RESIDENTStk_DurationTimer
2019-06-12 23:58:32.20672 RESIDENTStk_DurationTimer
2019-06-12 23:58:32.20743 RESIDENTStk_DurationTimer
2019-06-12 23:58:32.20814 RESIDENTStk_DurationTimer
2019-06-12 23:58:32.20884 RESIDENTStk_DurationTimer
2019-06-12 23:58:32.20940 RESIDENTStk_DurationTimer
2019-06-12 23:58:32.21008 RESIDENTStk_DurationTimer
2019-06-12 23:58:32.21083 RESIDENTStk_DurationTimer
2019-06-12 23:58:32.21147 RESIDENTStk_DurationTimer
2019-06-12 23:58:32.21200 RESIDENTStk_DurationTimer
2019-06-13 00:00:00.00000 at_Exec
2019-06-13 00:00:01.00000 FileLog_dailySwitch
2019-06-13 00:56:17.39050 Weather_GetUpdate
2019-06-13 00:56:46.37771 Weather_GetUpdate
2019-06-13 04:30:59.00000 at_Exec
2019-06-13 22:19:53.00000 at_Exec

Im Log steht um "Mitternacht":
2019.06.13 00:00:00.006 1: Bing!
Ich sehe das Problem noch nicht.


Off-Topic:
ich habe in fhem.cfg.demo eine telnet Instanz hinzugefuegt, und "attr rg_Guest4 subType minor" entfernt, da sonst beim Starten eine Warnung kam (configfile: invalid value minor)

Offline Loredo

  • Developer
  • Hero Member
  • ****
  • Beiträge: 3498
  • ~ Challenging Innovation ~
Antw:InternalTimer um 00:00:00
« Antwort #4 am: 13 Juni 2019, 11:15:57 »

Ich habe mein Problem nicht genau genug beschrieben, da fehlt vielleicht noch eine entscheidende Info:Also was ich konkret sehe ist, dass die geschriebenen Readings, für die die Berechnung um 00:00:00 angestoßen werden (sollten), mit einem Timestamp exakt 2 Sek später geschrieben werden, die Berechnung jedoch zu anderen Tageszeiten keine 2 Sekunden dauert, sondern unter einer Sekunde bleibt und demnach der Timestamp des Readings auch wie erwartet auf der entsprechenden Triggerzeit steht.


Ich teste auch nochmal mit einem Logeintrag zusätzlich.


Off-Topic:
ich habe in fhem.cfg.demo eine telnet Instanz hinzugefuegt, und "attr rg_Guest4 subType minor" entfernt, da sonst beim Starten eine Warnung kam (configfile: invalid value minor)


Die Telnet Instanz verwirrt mich jetzt (so ist das wohl bei OT  ;D ), aber danke für den Hinweis mit dem subType - der hat sich tatsächlich nochmals geändert und sollte dort "childcare" heißen und ich hatte es vergessen anzupassen.
FHEM-Module: ENIGMA2, GEOFANCY, PHTV, RESIDENTS, ROOMMATE, GUEST, HP1000, Pushover, THINKINGCLEANER, Wunderground | FHEM-Befehl: msg

FHEM-Docker auf Intel NUC mit Proxmox VE
Homematic via HMCCU, Hue Color Bulbs, LG OLED 65C8, Sonos Playbar+2xOne+Sub, 2x Sonos One, 1x Sonos Play:1

 

decade-submarginal