Autor Thema: [gelöst] global:INITIALIZED zu früh seit Update heute?  (Gelesen 2598 mal)

Online DeeSPe

  • Developer
  • Hero Member
  • ****
  • Beiträge: 3146
  • Wer anderen eine Bratwurst brät...
In meinem HOMEMODE Modul startet das Update der Internals erst nach "global:INITIALIZED" damit ich sicher gehen kann dass bereits alle von HOMEMODE zu überwachenden Geräte geladen wurden.
Seit dem heutigen FHEM Update kommt aber genau dieses Event zu früh!
Ich habe mal eine Log Ausgabe bei "global:INITIALIZED" mit eingebaut.
Hier mal der Log Mitschnitt beim Start:
2017.04.21 10:27:48 0: Server shutdown
2017.04.21 10:27:50 3: telnetPort: port 7072 opened
2017.04.21 10:27:50 3: WEB: port 8083 opened
2017.04.21 10:27:50 2: eventTypes: loaded 1272 events from ./log/eventTypes.txt
2017.04.21 10:27:50 3: Opening tvll device 127.0.0.1:19444
2017.04.21 10:27:50 3: DbLog logdb: Creating Push-Handle to database mysql:database=fhem;host=localhost;port=3306 with user fhemuser
2017.04.21 10:27:50 3: DbLog logdb: Push-Handle to db mysql:database=fhem;host=localhost;port=3306 created
2017.04.21 10:27:50 3: eq3: Defined with URL http://www.eq-3.de/service/downloads.html and interval 86400
2017.04.21 10:27:50 3: eq3: added hint :text,reading,internal,expression,delete to attr readingMaxAgeReplacementMode in userattr list
2017.04.21 10:27:50 3: TABLETUI: new ext defined infix:ftui/: dir:./www/tablet/:
2017.04.21 10:27:50 3: Registering HTTPSRV TABLETUI for URL /ftui   and assigned link ftui/ ...
Use of uninitialized value in string eq at fhem.pl line 2837.
2017.04.21 10:27:50 3: HOMEMODE_updateInternals
2017.04.21 10:27:50 2: Keine verfügbaren ROOMMATE/GUEST im RESIDENTS Gerät rgr_Residents
2017.04.21 10:27:50 2: SecurityCheck:  WEB has no associated allowed device with basicAuth. telnetPort has no associated allowed device with password/globalpassword.  Restart FHEM for a new check if the problem is fixed, or set the global attribute motd to none to supress this message.
2017.04.21 10:27:50 0: Featurelevel: 5.8
2017.04.21 10:27:50 0: Server started with 78 defined entities (fhem.pl:14046/2017-04-20 perl:5.020002 os:linux user:fhem pid:1921)

HOMEMODE_updateInternals wird nun also bereits aufgerufen bevor FHEM komplett initialisiert ist.  :-\

Wollte das Modul eigentlich heute Abend in SVN einchecken, aber so wird das nix... ???

Gruß
Dan
« Letzte Änderung: 21 April 2017, 20:23:42 von DeeSPe »
FHEM 5.8, Brix, VIVO mini, RPi3, Debian Jessie, ZME_UZB1
HM-CFG-LAN, HM-MOD-UART-WIFI, HUE, HarmonyHub, JeeLink, CO20
Hyperion auf RPi Zero W, Sonos, viel Z-Wave und HM
alles per HomeKit steuerbar
MAINTAINER: 22_HOMEMODE, 98_Hyperion, 98_FileLogConvert

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 16727
Antw:global:INITIALIZED zu früh seit Update heute?
« Antwort #1 am: 21 April 2017, 11:28:43 »
Und woran sieht man, dass es zu frueh ist?
Kannst du es bitte mit "attr global verbose 5" und Kommentaren belegen? So in der Art: schau mal, dieses Befehl wird hier noch aus fhem.cfg/fhem.state gelesen, nachdem meine Routine mit "global:INITIALIZED" aufgerufen wurde?


Online DeeSPe

  • Developer
  • Hero Member
  • ****
  • Beiträge: 3146
  • Wer anderen eine Bratwurst brät...
Antw:global:INITIALIZED zu früh seit Update heute?
« Antwort #2 am: 21 April 2017, 11:58:59 »
2017.04.21 10:27:50 3: HOMEMODE_updateInternals
2017.04.21 10:27:50 2: Keine verfügbaren ROOMMATE/GUEST im RESIDENTS Gerät rgr_Residents

Als Erstes werden die ROOMMATE/GUEST Devices von HOMEMODE "eingelesen".
Diese sind aber scheinbar noch nicht definiert wie die zweite Logzeile anzeigt.
Es werden leider gar keine Devices mehr von HOMEMODE gefunden, da HOMEMODE nach allen Devices in der cfg steht.

Verbose per FHEMWEB auf 5 setzen geht nicht! Es kommt die Fehlermeldung aus dem angehängten Screenshot.
Per "attr global verbose 5" ging es nun.

Das Log passt hier nicht komplett rein. Habe es nun als txt angehangen.

Bis heute morgen vor dem Update ging das noch einwandfrei.

Gruß
Dan
« Letzte Änderung: 21 April 2017, 12:01:05 von DeeSPe »
FHEM 5.8, Brix, VIVO mini, RPi3, Debian Jessie, ZME_UZB1
HM-CFG-LAN, HM-MOD-UART-WIFI, HUE, HarmonyHub, JeeLink, CO20
Hyperion auf RPi Zero W, Sonos, viel Z-Wave und HM
alles per HomeKit steuerbar
MAINTAINER: 22_HOMEMODE, 98_Hyperion, 98_FileLogConvert

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 16727
Antw:global:INITIALIZED zu früh seit Update heute?
« Antwort #3 am: 21 April 2017, 12:13:04 »
Zitat
Verbose per FHEMWEB auf 5 setzen geht nicht!
Bei mir schon, hat vermutlich mit dem vorhin gefixten Bug was zu tun.

Zitat
Diese sind aber scheinbar noch nicht definiert wie die zweite Logzeile anzeigt.
Scheinbar ist mir nicht ausreichend. In deinem Log kommt nach der Fehlermeldung:
Zitat
2017.04.21 11:46:49 3: HOMEMODE_updateInternals
2017.04.21 11:46:49 2: Keine verfügbaren ROOMMATE/GUEST im RESIDENTS Gerät rgr_Residents
2017.04.21 11:46:49 5: Triggering n_INITIALIZED
2017.04.21 11:46:49 4: n_INITIALIZED exec set d_init on
2017.04.21 11:46:49 5: Cmd: >set d_init on<
2017.04.21 11:46:49 4: dummy set d_init on
2017.04.21 11:46:49 5: Starting notify loop for d_init, 1 event(s), first is on
2017.04.21 11:46:49 5: ABFALL_Notify(Abfall) - Device: d_init
2017.04.21 11:46:49 5: End notify loop for d_init
2017.04.21 11:46:49 5: End notify loop for global
2017.04.21 11:46:49 2: SecurityCheck:  WEB has no associated allowed device with basicAuth. telnetPort has no associated allowed device with password/globalpassword.  Restart FHEM for a new check if the problem is fixed, or set the global attribute motd to none to supress this message.
2017.04.21 11:46:49 0: Featurelevel: 5.8
2017.04.21 11:46:49 0: Server started with 78 defined entities (fhem.pl:14046/2017-04-20 perl:5.020002 os:linux user:fhem pid:2070)
Ich sehe keine weiteren Definitionen / Attribute / etc.

Online DeeSPe

  • Developer
  • Hero Member
  • ****
  • Beiträge: 3146
  • Wer anderen eine Bratwurst brät...
Antw:global:INITIALIZED zu früh seit Update heute?
« Antwort #4 am: 21 April 2017, 12:23:49 »
Wie es zusammenhängt ist mir bisher auch noch ein Rätsel.

Sollte das INITIALIZED Event nicht aber nach "Server started with 78 defined entities" kommen?

Wieso ging es bis heute früh und ohne Änderung an meinem Modul auf einmal nicht mehr?

Gruß
Dan
FHEM 5.8, Brix, VIVO mini, RPi3, Debian Jessie, ZME_UZB1
HM-CFG-LAN, HM-MOD-UART-WIFI, HUE, HarmonyHub, JeeLink, CO20
Hyperion auf RPi Zero W, Sonos, viel Z-Wave und HM
alles per HomeKit steuerbar
MAINTAINER: 22_HOMEMODE, 98_Hyperion, 98_FileLogConvert

Online DeeSPe

  • Developer
  • Hero Member
  • ****
  • Beiträge: 3146
  • Wer anderen eine Bratwurst brät...
Antw:global:INITIALIZED zu früh seit Update heute?
« Antwort #5 am: 21 April 2017, 13:18:17 »
Dachte gerade ich lasse mal sicherheitshalber ein "update force" drüber laufen, aber das funktioniert nicht.
Die Seite rödelt ewig um dann in "weiß" stehen zu bleiben.

Irgendwas ist doch hier im "Brötchen"...

Gruß
Dan
FHEM 5.8, Brix, VIVO mini, RPi3, Debian Jessie, ZME_UZB1
HM-CFG-LAN, HM-MOD-UART-WIFI, HUE, HarmonyHub, JeeLink, CO20
Hyperion auf RPi Zero W, Sonos, viel Z-Wave und HM
alles per HomeKit steuerbar
MAINTAINER: 22_HOMEMODE, 98_Hyperion, 98_FileLogConvert

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 16727
Antw:global:INITIALIZED zu früh seit Update heute?
« Antwort #6 am: 21 April 2017, 13:36:47 »
Bei mir funktioniert update.

Online DeeSPe

  • Developer
  • Hero Member
  • ****
  • Beiträge: 3146
  • Wer anderen eine Bratwurst brät...
Antw:global:INITIALIZED zu früh seit Update heute?
« Antwort #7 am: 21 April 2017, 13:51:47 »
Habe nun das Log beobachtet!
FHEM blockiert komplett während "update force" und zeigt auch keinen Event-Monitor/Log an wie bei "update".
"update force" ist aber durchgelaufen, trotz weißer Seite am Ende.
Leider trotzdem selbes Verhalten.

INITIALIZED ruft HOMEMODE_updateInternals auf.
sub HOMEMODE_Notify($$)
{
  my ($hash,$dev) = @_;
  my $name = $hash->{NAME};
  my $devname = $dev->{NAME};
  my $devtype = $dev->{TYPE};
  return if (AttrVal($name,"disable",0) == 1);
  my $events = deviceEvents($dev,1);
  if (grep(/^INITIALIZED$/,@{$events}))
  {
    Debug Dumper @{$events};
    Debug $init_done;
    Log3 $name,3,"HOMEMODE_updateInternals";
    HOMEMODE_updateInternals($hash);
  }

In HOMEMODE_updateInternals werden als Erstes von RESIDENTS die ROOMMATE/GUEST aus dem Hash gelesen, diese sind aber noch leer.
sub HOMEMODE_updateInternals($;$)
{
  my ($hash,$force) = @_;
  $HOMEMODE_de = 1 if (AttrVal("global","language","EN") eq "DE");
  my $name = $hash->{NAME};
  my $resdev = $hash->{DEF};
  my $trans;
  if (!IsDevice($resdev))
  {
    $trans = $HOMEMODE_de?
      "$resdev ist nicht definiert!":
      "$resdev is not defined!";
    $hash->{STATE} = $trans;
  }
  elsif (!IsDevice($resdev,"RESIDENTS"))
  {
    $trans = $HOMEMODE_de?
      "$resdev ist kein gültiges RESIDENTS Gerät!":
      "$resdev is not a valid RESIDENTS device!";
    $hash->{STATE} = $trans;
  }
  else
  {
    my @oldMonitoredDevices = @{$hash->{helper}{allMonitoredDevices}} if ($hash->{helper}{allMonitoredDevices});
    delete $hash->{helper}{allMonitoredDevices};
    delete $hash->{helper}{presdevs};
    delete $hash->{RESIDENTS};
    delete $hash->{SENSORSCONTACT};
    delete $hash->{SENSORSMOTION};
    delete $hash->{SENSORSENERGY};
    delete $hash->{SENSORSLUMINANCE};
    $hash->{VERSION} = $HOMEMODE_version;
    my @residents;
    push @residents,$defs{$resdev}->{ROOMMATES} if ($defs{$resdev}->{ROOMMATES});
    push @residents,$defs{$resdev}->{GUESTS} if ($defs{$resdev}->{GUESTS});
    Debug $defs{$resdev}->{ROOMMATES};
    Debug Dumper @residents;
    if (scalar @residents < 1)
    {
      $trans = $HOMEMODE_de?
        "Keine verfügbaren ROOMMATE/GUEST im RESIDENTS Gerät $resdev":
        "No available ROOMMATE/GUEST in RESIDENTS device $resdev";
      Log3 $name,2,$trans;
      readingsSingleUpdate($hash,"HomeInfo",$trans,1);
      return;
    }
    else
    {
      $hash->{RESIDENTS} = join(",",@residents);
    }

2017.04.21 13:46:11 1: DEBUG>$VAR1 = 'INITIALIZED';

2017.04.21 13:46:11 1: DEBUG>1
2017.04.21 13:46:11 3: HOMEMODE_updateInternals
Use of uninitialized value $msg in concatenation (.) or string at fhem.pl line 4576.
2017.04.21 13:46:11 1: DEBUG>
2017.04.21 13:46:11 1: DEBUG>
2017.04.21 13:46:11 2: Keine verfügbaren ROOMMATE/GUEST im RESIDENTS Gerät rgr_Residents

Führe ich HOMEMODE_updateInternals  nochmal aus nachdem dann FHEM wirklich richtig läuft funktioniert es wieder.

2017.04.21 13:46:49 1: DEBUG>rr_Brina,rr_Dan
2017.04.21 13:46:49 1: DEBUG>$VAR1 = 'rr_Brina,rr_Dan';
$VAR2 = 'rg_Gast,rg_Mutter,rg_SBert';



Gruß
Dan
FHEM 5.8, Brix, VIVO mini, RPi3, Debian Jessie, ZME_UZB1
HM-CFG-LAN, HM-MOD-UART-WIFI, HUE, HarmonyHub, JeeLink, CO20
Hyperion auf RPi Zero W, Sonos, viel Z-Wave und HM
alles per HomeKit steuerbar
MAINTAINER: 22_HOMEMODE, 98_Hyperion, 98_FileLogConvert

Online DeeSPe

  • Developer
  • Hero Member
  • ****
  • Beiträge: 3146
  • Wer anderen eine Bratwurst brät...
Antw:global:INITIALIZED zu früh seit Update heute?
« Antwort #8 am: 21 April 2017, 14:53:48 »
Habe es weiter eingrenzen können.

Es liegt scheinbar an RESIDENTS.
Durch die umfangreichen Umbauarbeiten an RESIDENTS in letzter Zeit muss sich etwas verändert haben.
Es sind jedenfalls nach INITIALIZED noch keine ROOMMATE/GUEST im Hash verfügbar.

Muss ich jetzt wirklich einen InternalTimer einbauen um HOMEMODE_updateInternals zu verzögern?

Gruß
Dan
FHEM 5.8, Brix, VIVO mini, RPi3, Debian Jessie, ZME_UZB1
HM-CFG-LAN, HM-MOD-UART-WIFI, HUE, HarmonyHub, JeeLink, CO20
Hyperion auf RPi Zero W, Sonos, viel Z-Wave und HM
alles per HomeKit steuerbar
MAINTAINER: 22_HOMEMODE, 98_Hyperion, 98_FileLogConvert

Offline betateilchen

  • Developer
  • Hero Member
  • ****
  • Beiträge: 13244
  • Das "S" in "IoT" steht für "Security"
Antw:global:INITIALIZED zu früh seit Update heute?
« Antwort #9 am: 21 April 2017, 18:18:57 »
Vielleicht läuft RESIDENTS inzwischen auch erst los, nachdem global:INITIALIZED erfolgt ist?

Wir hatten hier doch in den letzten Wochen die Grundsatzdiskussion, dass bestimmte Module erst nach bestimmten Kriterien starten dürfen, um von ihrer Reihenfolge innerhalb der Konfigurationsdaten unabhängig zu werden.

Nächster Hamburg-Stammtisch: 15.09.2017, 18:30 Uhr, Weinkeller im Hotel Baseler Hof, Esplanade 11, Hamburg

Offline justme1968

  • Developer
  • Hero Member
  • ****
  • Beiträge: 16611
Antw:global:INITIALIZED zu früh seit Update heute?
« Antwort #10 am: 21 April 2017, 18:36:52 »
wenn mehrere module die voneinander abhängig sind auf global:INITIALIZED warten haben wir ein problem da die reihenfolge dieser module untereinander nicht definiert bzw. alphabetisch ist.

im prinzip kann man seine eigene notify order ändern, das funktioniert aber nur wenn es zwischen diesen modulen regeln gibt und nicht jeder für sich versucht möglichst weit hinten zu sein.

vielleicht wäre es besser wenn es eine art modul spezifisches initialized event gäbe um diese abhängigkeit zu entkoppeln.
FHEM5.4,DS1512+,2xCULv3,DS9490R,HMLAN,2xRasPi
CUL_HM:HM-LC-Bl1PBU-FM,HM-LC-Sw1PBU-FM,HM-SEC-MDIR,HM-SEC-RHS
HUEBridge,HUEDevice:LCT001,LLC001,LLC006,LWL001
OWDevice:DS1420,DS18B20,DS2406,DS2423
FS20:fs20as4,fs20bs,fs20di
AKCP:THS01,WS15
CUL_WS:S300TH

Online DeeSPe

  • Developer
  • Hero Member
  • ****
  • Beiträge: 3146
  • Wer anderen eine Bratwurst brät...
Antw:global:INITIALIZED zu früh seit Update heute?
« Antwort #11 am: 21 April 2017, 18:59:56 »
Danke für Eure Hinweise.

Dank Julians Hinweis konnte ich mit:
$hash->{NotifyOrderPrefix} = "51-";zumindest erst mal sicherstellen dass die ROOMMATE/GUEST Devices wieder vorhanden sind.
Jetzt muss ich "nur" wieder alles testen worauf sich das evtl. noch in meinem Modul auswirkt.
Nur gut dass das vor dem SVN Check-in passiert ist... 8)

Gruß
Dan
FHEM 5.8, Brix, VIVO mini, RPi3, Debian Jessie, ZME_UZB1
HM-CFG-LAN, HM-MOD-UART-WIFI, HUE, HarmonyHub, JeeLink, CO20
Hyperion auf RPi Zero W, Sonos, viel Z-Wave und HM
alles per HomeKit steuerbar
MAINTAINER: 22_HOMEMODE, 98_Hyperion, 98_FileLogConvert

Offline Thorsten Pferdekaemper

  • Developer
  • Hero Member
  • ****
  • Beiträge: 3896
  • Finger weg von der fhem.cfg
Antw:global:INITIALIZED zu früh seit Update heute?
« Antwort #12 am: 21 April 2017, 19:48:40 »
Hi,
und wo genau ist jetzt das Problem, einfach das hier hinzuschreiben:
InternalTimer (gettimeofday(), 'HOMEMODE_updateInternals', $hash);
Das verzögert das ganze bis alles geladen ist.
Gruß,
   Thorsten
RasPi
Heizkessel-Steuerung per Arduino und HTTPMOD
und einen Haufen Homematic (Wired)

Offline Loredo

  • Developer
  • Hero Member
  • ****
  • Beiträge: 2808
  • ~ Challenging Innovation ~
Antw:global:INITIALIZED zu früh seit Update heute?
« Antwort #13 am: 21 April 2017, 19:59:05 »
Vielleicht läuft RESIDENTS inzwischen auch erst los, nachdem global:INITIALIZED erfolgt ist?


Genau. Stand schon seit 2 Jahren auf der Todo...  ;)
Jetzt hatte ich mal einen Grund das anzupacken (allerdings hab ich von einer Grundsatzdiskussion nichts mitbekommen...).

FHEM-Module: ENIGMA2, GEOFANCY, ONKYO_AVR, PHTV, RESIDENTS, ROOMMATE, GUEST, HP1000, powerMap, Pushover, THINKINGCLEANER, Wunderground | FHEM-Befehl: msg

FHEM 5.9dev auf Intel NUC mit Proxmox VE
Homematic via HMCCU, Hue Color Bulbs
ONKYO TX-NR626, Philips 55" PFL8008S, Sonos 1xS1, 1xS3, 2xS5

Offline justme1968

  • Developer
  • Hero Member
  • ****
  • Beiträge: 16611
Antw:global:INITIALIZED zu früh seit Update heute?
« Antwort #14 am: 21 April 2017, 20:00:07 »
@Thorsten Pferdekaemper: das geht nicht. weil es auf eine definierte reihenfolge ankommt funktioniert eine einfache verzögerung nicht da damit die reihenfolge zufällig (bzw. alphabetisch vom modul namen) abhängt.

gruss
  andre
FHEM5.4,DS1512+,2xCULv3,DS9490R,HMLAN,2xRasPi
CUL_HM:HM-LC-Bl1PBU-FM,HM-LC-Sw1PBU-FM,HM-SEC-MDIR,HM-SEC-RHS
HUEBridge,HUEDevice:LCT001,LLC001,LLC006,LWL001
OWDevice:DS1420,DS18B20,DS2406,DS2423
FS20:fs20as4,fs20bs,fs20di
AKCP:THS01,WS15
CUL_WS:S300TH

 

decade-submarginal