Fehler in twilight: azimut, elevation und twilight_weather werden nicht mehr akt

Elektrolurch · 24 August 2015, 09:01:48

Hallo,

seit dem gestrigen Update werden die readings azimut, elevation und twilight_weather nicht mehr aktualisiert. Die Zeitstempel der readings stehen auf der Uhrzeit des letzten Neustarts von fhem, d.h. die Berechnung erfolgt nur bei der Modulinitialisierung.

Mir ist das gestern abend aufgefallen, da meine Treppenhauslichtsteuerung, die twilight_weather abfragt, das Licht nicht mehr einschaltete.
Vorgestern war noch alles ok.

Elektrolurch

Dietmar63 · 24 August 2015, 11:20:27

das Modul ist seit zig Monaten nicht mehr freigegeben worden.

Elektrolurch · 24 August 2015, 11:30:50

Das weiß ich, daher habe ich versucht herauszufinden, wovon das Modul abhängt.
1. httputils -> da habe ich den Stand vom 22.8. zurückgespielt... mal sehjen.
2. von yahoo ? Die Werte im weather-Modul scheinen aber korrekt zu kommen.

Merkwürdig ist ja, das beim Neustart von fhem alle Werte in twilight gelesen werden und danach bleibt azimut, elevation und twilight_weather stehen.

@Dietmar
Wie häufig werden diese Werte neu berechnet? Und wo? Würde dann mal überprüfen, ob die InternalTimer überhaupt aufgerufen werden.
Mit dem gestrigen Update von fhem läuft es jedenfalls nicht mehr. Da wurde auch die fhem.pl aktualisiert. (InternalTimer?)
Du verwendest ja im Modul eigene Routinen, um mehrere interne Timer zu verwalten....
Ich habe verbose mal auf 3 gesetzt, aber da kommen auch keine Ausgaben.

Elektrolurch

Elektrolurch · 24 August 2015, 15:59:07

Hallo Dietmar,

Noch weiter Ursachenforschung betrieben. Dabei ist mir folgendes aufgefallen:

1. in der 59_twilight werden drei Routinen definiert:
myInternalTimer
myRemoveInternalTimer
myGetHash (oder so ähnlich)
die in einigen 98-Modulen (weeklytimer,randomtimer, vol) auch verwendet werden. Das geht doch nur, wenn man twilight gleichzeitig benutzt, ansonsten wären die Routinen nicht definiert.
Wenn jetzt noch jemand in einem anderen Modul eine Routine mit my... definiert, dann wird die Routine aus twilight überschrieben.

2. disable wird zwar im Modul abgefragt, steht aber nicht in der attrlist, kann also nicht verwendet werden.

3. Habe mal nachgeschaut, wo die azimut, elevation und twilight_weather gesetzt werden:
in twilight_sunpos

Wenn ich diese mit
{twilight_sunpos($defs{'Daemmerung'});;}
über die fhem-Zeile aufrufe, passiert nichts. Es erscheint noch nicht einmal der erste log3 - Aufruf im log-File, obwohl ich verbose schon auf 5 gesetzt habe.
Ich habe da den call von myGEtHash($myhash,(caller()[... am Anfang der Routine in verdacht.....

Elektrolurch

Dietmar63 · 24 August 2015, 19:07:30

bei mir läuft die Aktualisierung - siehe BS-Foto

die Idee hinter meinen neuen Routinen ist, mehrere Timer unabhänig voneinander setzen und löschen zu können.
RemoveInternalTimer() löscht immer alle Timer eines hash - das ist unschön, weil man dann immer Buch darüber führen muss, was erneut gesetzt werden muss.

Die Daten werden dann in einem HASH of HASH verwaltet, das über myGetHash derefferenziert wird.
Wenn man eine solche Funktion von außen aufrufen will, muss man diesen Mechanismus nachbauen - der direkte Aufruf ist nicht möglich.

Zitatdie in einigen 98-Modulen (weeklytimer,randomtimer, vol) auch verwendet werden. Das geht doch nur, wenn man twilight gleichzeitig benutzt, ansonsten wären die Routinen nicht definiert.

doch das funktioniert wenn man das Modul jeweils zwangsweise lädt:

Code Auswählen


################################################################################
sub WeekdayTimer_Initialize($){
  my ($hash) = @_;

  if(!$modules{Twilight}{LOADED} && -f "$attr{global}{modpath}/FHEM/59_Twilight.pm") {
    my $ret = CommandReload(undef, "59_Twilight");
    Log3 undef, 1, $ret if($ret);
  }

Dietmar63 · 24 August 2015, 20:07:07

bei einem falschen Aufruf von myGetHashIndirekt() sollte immer eine FM(Zeile 176) ins Log geschrieben werden:

Elektrolurch · 24 August 2015, 21:12:07

Hallo Dietmar,

ich habe noch einen Cubietruck, den ich im Augenblick für die Entwicklung benutze und erst demnächst darauf umziehen werde. Da wird derzeit nur das Somfy-Modul verwendet und ein Teil der fhem.cfg von der Fritzbox hatte ich da rüber kopiert. Da wird auch ein define Daemmerung twilight ... ausgeführt.
Die readings auf dem Cubie bzgl. twilight sind dort genau auch nach dem letzten update (gestern) stehen geblieben und werden nicht mehr aktualisiert.
Zwei unabhängige Systeme auf zwei verschiedenen Plattformen und genau nach dem letzten Update von fhem aktualisiert twilight nicht mehr die readings.
Hier der log-Auszug für verbose 5. Aktiviert um ca. 15:00 Uhr:
2015.08.24 18:49:48 4: [Daemmerung] got weather info from yahoo for 676757
2015.08.24 18:49:48 5: [Daemmerung] removing Timer: Daemmerung_sr_weather
2015.08.24 18:49:48 5: [Daemmerung] setting Timer: Daemmerung_sr_weather 2015-08-24 06:45:22
2015.08.24 18:49:48 5: [Daemmerung] removing Timer: Daemmerung_ss_weather
2015.08.24 18:49:48 5: [Daemmerung] setting Timer: Daemmerung_ss_weather 2015-08-24 19:49:47
2015.08.24 18:49:48 5: [Daemmerung] removing Timer: Daemmerung_Midnight
2015.08.24 18:49:48 5: [Daemmerung] setting Timer: Daemmerung_Midnight 2015-08-25 00:00:01
2015.08.24 18:49:48 5: [Daemmerung] removing Timer: Daemmerung_perlTime
2015.08.24 18:49:48 4: [Daemmerung] sr_weather 2015-08-24 06:45:22 ( 6/6/ +3.0°/) ===> ss_weather 19:49:47
2015.08.24 19:49:47 4: [Daemmerung] ss_weather 2015-08-24 19:49:47 ( 7/5/ +3.0°/1) ===> ss_indoor 19:49:47
2015.08.24 19:49:47 4: [Daemmerung] ss_indoor 2015-08-24 19:49:47 ( 8/4/ +3.0°/1) ===> ss 20:08:25
2015.08.24 20:08:25 4: [Daemmerung] ss 2015-08-24 20:08:25 ( 9/3/ +0.0°/1) ===> ss_civil 20:46:49

2015.08.24 20:46:49 4: [Daemmerung] ss_civil 2015-08-24 20:46:49 (10/2/ -6.0°/1) ===> ss_naut 21:27:39

Ich kann da nicht erkennen, dass da eine 'Routine aufgerufen wird, die azimut, elevation und twilight_weather aktualisiert.

Gruß

Elektrolurch

stromer-12 · 24 August 2015, 22:25:56

schau mal in twilight bei Zeile 600

Dietmar63 · 24 August 2015, 23:05:23

bei mir kommen folgende Zeilen im Log:

Code Auswählen

2015.08.24 22:59:58 5: [Twilight] setting  Timer: Twilight_sunpos 2015-08-24 23:04:58
2015.08.24 22:59:58 5: [Twilight] removing Timer: Twilight_sunpos
2015.08.24 22:59:58 5: [Twilight] Original weather readings

was liefert list "Twilight" ?

Code Auswählen


Internals: 
   CONDITION  28 
   CONDITION_TXT Mostly Cloudy 
   DEF        52.44944 10.00512 0 12833457 
   INDOOR_HORIZON 0 
   LATITUDE   52.44944 
   LONGITUDE  10.00512 
   NAME       Twilight 
   NR         254 
   STATE      19:55:00    0%   0 
   SUNPOS_OFFSET 300 
   SWIP       1 
   TEMPERATUR 24 
   TYPE       Twilight 
   WEATHER    12833457 
   WEATHER_CORRECTION 4 
   WEATHER_HORIZON 4

wie ist der Wert von SUNPOS_OFFSET? :: 300

welche ID findest du im Sourcecode in Zeile 1?

Code Auswählen

# $Id: 59_Twilight.pm ?????

Dietmar63 · 24 August 2015, 23:18:37

... und das dann im 5 Minutenabstand:

Code Auswählen


2015.08.24 23:14:58 5: [Twilight] setting  Timer: Twilight_sunpos 2015-08-24 23:19:58
2015.08.24 23:14:58 5: [Twilight] removing Timer: Twilight_sunpos
2015.08.24 23:14:58 5: [Twilight] Original weather readings
2015.08.24 23:09:58 5: [Twilight] setting  Timer: Twilight_sunpos 2015-08-24 23:14:58
2015.08.24 23:09:58 5: [Twilight] removing Timer: Twilight_sunpos
2015.08.24 23:09:58 5: [Twilight] Original weather readings
2015.08.24 23:04:58 5: [Twilight] setting  Timer: Twilight_sunpos 2015-08-24 23:09:58
2015.08.24 23:04:58 5: [Twilight] removing Timer: Twilight_sunpos
2015.08.24 23:04:58 5: [Twilight] Original weather readings
2015.08.24 22:59:58 5: [Twilight] setting  Timer: Twilight_sunpos 2015-08-24 23:04:58
2015.08.24 22:59:58 5: [Twilight] removing Timer: Twilight_sunpos
2015.08.24 22:59:58 5: [Twilight] Original weather readings

Elektrolurch · 25 August 2015, 08:49:15

Hallo Dietmar,

da ja beim Starten von fhem einmalig alle Werte in twilight korrekt gelesen werden und danach die azimut, elevation und twilight - readings nicht mehr aktualisiert, "killt" irgendetwas auf zwei verschiedenen Systemen den timer, der die Routine aufrufen soll.
sunrise und sunset werden übrigens korrekt aktualisiert, habe ich heute morgen gesehen.

Zitat:
die Idee hinter meinen neuen Routinen ist, mehrere Timer unabhänig voneinander setzen und löschen zu können.
RemoveInternalTimer() löscht immer alle Timer eines hash - das ist unschön, weil man dann immer Buch darüber führen muss, was erneut gesetzt werden muss.

Die Daten werden dann in einem HASH of HASH verwaltet, das über myGetHash derefferenziert wird.
Wenn man eine solche Funktion von außen aufrufen will, muss man diesen Mechanismus nachbauen - der direkte Aufruf ist nicht möglich.

Ich kenne die Problematik, weil ich im Forum dazu auch schon mal gepostet hatte. Aber ist das mit dem doppelten hash notwendig? Macht die Fehlersuche schwieriger, da der direkte Aufruf der subroutinen nicht mehr möglich ist.
Soweit ich den Code von InternalTimer und RemoveInternalTimer verstanden habe, verwalten die Rotinen die Timer "einfach" nach dem übergebenen Wert. Ich habe da schon hier im Forum Code gesehen, wobei an dem hash einfach noch eine Kennzeichung für den Timer angehängt wurde....
(sowaas wie "$hash,Timer!" und dann macht die aufgerufene Routine:

my $hash = split(',',$param);
)

Nun zu den log-Daten:

Ich habe heute morgen per setreading twilight_weather auf 100 gesetzt, damit nicht auch tagsüber mein Treppenhauslicht angeht. Es stand auf 0 mit Zeitstempel vom letzten Neustart.

Die internen Daten hänge ich als Datei an, damit der post nicht zu lang wird.

Version: # $Id: 59_Twilight.pm 8743 2015-06-14 12:14:57Z dietmar63 $

Merkwürdig ist auch, dass auf dem Cubie genau der gleiche Effekt auftritt, seit dem ich dort fhem auch aktualisiert habe... und wie gesagt, da nutze ich nur das Sonos-Modul.
Ich könnte jetzt einen älteren Sttand zurückspielen und Datei für Datei aktualisieren, um den Übeltäter zu finden....

Gruß

Elektrolurch

Dietmar63 · 25 August 2015, 19:27:37

Die ID des Moduls ist korrekt.

Es liegt vermutlich daran: siehe Foto Zeile 487,491.
Es sind die einzigen beiden Stellen, über die das Modul sofort verlassen wird.

Warum auch immer.

Dietmar63 · 25 August 2015, 19:46:20

versuch den Start des Timers mal mit:

Code Auswählen

{Twilight_sunpos( {HASH=>$defs{"Daemmerung"}} ) }
vorher verbose 5 setzen

Sunny · 25 August 2015, 19:57:48

Hallo Elektrolurch,

Sorry, wenn Euch hier ein Anfänger "reingräscht".

Liegt es vielleicht an: "event-on-change-reading twilight_weather.*"

auf meinem RPI läuft es, allerdings mit: "event-on-change-reading .*"

Viele Grüße
Sunny

<Edit an> Sorry auch an Dich Dietmar. Und Danke für das Modul <Edit aus>

Elektrolurch · 26 August 2015, 09:45:20

Hallo,
@Sunny: event-on-change-reading twilight_weather.* habe ich schon seit fast zwei Jahren so gesetzt. Habe es aber mal ausprobiert, keine Änderung.

@Dietmar:
So langsam kommen wir jetzt der Sache näher:

1. Der timer für die Twilight_sunpos - Routine läuft nicht.
Wenn ich:
{Twilight_sunpos( {HASH=>$defs{"Daemmerung"}} ) }
in die fhem-Zeile eingebe,
dann startet auch der Timer und die Werte werden alle fünfMinuten aktualisiert:
2015.08.26 09:32:40 1: twilight_sunpos:hash HASH(0x77c8d0)
2015.08.26 09:32:40 5: [Daemmerung] Original weather readings
2015.08.26 09:32:40 5: [Daemmerung] removing Timer: Daemmerung_sunpos
2015.08.26 09:32:40 5: [Daemmerung] setting Timer: Daemmerung_sunpos 2015-08-26 09:37:40

2. Die Definition von "Daemmerung" steht ziemlich weit oben in der fhem.cfg
Es erscheint beim Neustart folgende Zeile:
2015.08.26 09:23:31 1: Including fhem.cfg
2015.08.26 09:23:32 1: twilight_sunpos:hash HASH(0x77c8d0)
2015.08.26 09:23:37 1: Including ./FHEM/00_utils_EG.cfg
...

Hier fehlt die Meldung dass der Timer für sunpos gesetzt wird. ?
Nach ca. 30 Sekunden ist dann fhem bereit und dann steht folgendes im log:

2015.08.26 09:24:02 0: Server started with 300 defined entities (version $Id: fhem.pl 9118 2015-08-23 12:43:56Z rudolfkoenig $, os linux, user root, pid 5544)
2015.08.26 09:24:02 4: [Daemmerung] sr_astro 2015-08-26 04:26:29 ( 1/1/-18.0°/0) ===> sr_naut 05:10:51
2015.08.26 09:24:02 4: [Daemmerung] sr_naut 2015-08-26 05:10:51 ( 2/2/-12.0°/0) ===> sr_civil 05:51:16
2015.08.26 09:24:02 4: [Daemmerung] sr_civil 2015-08-26 05:51:16 ( 3/3/ -6.0°/0) ===> sr 06:29:27
2015.08.26 09:24:02 4: [Daemmerung] sr 2015-08-26 06:29:27 ( 4/4/ +0.0°/0) ===> sr_indoor 06:48:00
2015.08.26 09:24:02 4: [Daemmerung] sr_indoor 2015-08-26 06:48:00 ( 5/5/ +3.0°/0) ===> sr_weather 06:48:00
2015.08.26 09:24:02 4: [Daemmerung] sr_weather 2015-08-26 06:48:00 ( 6/6/ +3.0°/0) ===> ss_weather 19:46:04

Vielleicht ein timing-Problem?

Gruß

Elektrolurch