Ständige Verbindungsabbrüche bei MQTT2

Begonnen von Reinerlein, 08 Juni 2020, 19:13:48

Vorheriges Thema - Nächstes Thema

Beta-User

Hmm, "no bad guy" kann ich nicht deuten...

Und an sich sieht es auch so aus, als würde das immer um die 200+ms dauern, bis das einzelne Dispatch komplett durch ist; das sieht mir nicht wild aus, vor allem, weil sich theoretisch auch was dazwischenklemmen könnte (ich denke an ein anderes Interface, das ebenfalls irgendwelche Event-relevanten Daten abliefert).

Wenn man von 35.022 die 3.021 abziehet, landet man bei 32.001. Das deutet darauf hin, dass es evtl. mit dem update von "state" (eher als relay) zusammenhängen könnte; da FHEM auch weiterläuft, müßte das eigentlich irgendwas im Hintergrund sein, oder? Wie logs du? DBLog? (das forkt afaik, was auch kein echter freeze wäre, oder?).

Aber im Prinzip muß ich zugeben, dass ich völlig im Dunkeln tappe...
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: ZigBee2mqtt, MiLight@ESP-GW, BT@OpenMQTTGw | ZWave | SIGNALduino | MapleCUN | RHASSPY
svn: u.a Weekday-&RandomTimer, Twilight,  div. attrTemplate-files, MySensors

Reinerlein

Hi Rudi,

ich habe das Problem in den Griff bekommen.
Ich habe hier einen Patch, in dem ich die Verarbeitung von Nachrichten auf einzelne umgestellt habe. Zwischen jeder Nachrichtenverarbeitung wird ein InternalTimer ausgeführt, sodass Fhem nicht geblockt wird.
Dadurch skaliert die Verarbeitung auch viel besser. Ich habe teilweise in einer Lieferung vom MQTT-Broker 30 Nachrichten. Durch das einzelne Dispatching (da könnte man vielleicht auch noch Optimieren) braucht er für eine Nachricht auf meiner Kiste 0,5-2,5 Sekunden, für dieses ganze Paket also mal 30-45 Sekunden, in denen Fhem angehalten ist.

Des Weiteren habe ich das Abbrechen wegen fehlender PingResp auf Disconnect umgestellt, damit sich das selber retten kann.
Wenn keine Antwort vom Broker gekommen ist, kann man auch nicht erwarten, dass eine normale Abmeldung möglich ist. u.U. muss da aber noch was wegen der Meldung an die Fhem-Readings gemacht werden...

Hier mal die Codeänderung:
#####################################
sub
MQTT2_CLIENT_Read($)
{
  my ($hash) = @_;

  my $name = $hash->{NAME};
  my $fd = $hash->{FD};

  my $buf = DevIo_SimpleRead($hash);
  if(!defined($buf)) {
    DevIo_Disconnected($hash);
    return "";
  }
  $hash->{BUF} .= $buf;

  RemoveInternalTimer($hash, 'MQTT2_CLIENT_Read_Consume');
  MQTT2_CLIENT_Read_Consume($hash);
}

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

  my $name = $hash->{NAME};
  my $fd = $hash->{FD};

  my ($tlen, $off) = MQTT2_CLIENT_getRemainingLength($hash);
  if($tlen < 0 || $tlen+$off<=0) {
    Log3 $name, 1, "Bogus data from $name, closing connection";
    DevIo_Disconnected($hash);
    return;
  }
  return if(length($hash->{BUF}) < $tlen+$off);

  my $fb = substr($hash->{BUF}, 0, 1);
  my $pl = substr($hash->{BUF}, $off, $tlen); # payload
  $hash->{BUF} = substr($hash->{BUF}, $tlen+$off);

  my $cp = ord(substr($fb,0,1)) >> 4;
  my $cpt = $cptype{$cp};
  $hash->{lastMsgTime} = gettimeofday();

  # Lowlevel debugging
  if(AttrVal($name, "verbose", 1) >= 5) {
    my $pltxt = $pl;
    $pltxt =~ s/([^ -~])/"(".ord($1).")"/ge;
    Log3 $name, 5, "$name: received $cpt $pltxt";
  }

  ####################################
  if($cpt eq "CONNACK")  {
    my $rc = ord(substr($pl,1,1));
    if($rc == 0) {
      MQTT2_CLIENT_doinit($hash);

    } else {
      my @txt = ("Accepted", "bad proto", "bad id", "server unavailable",
                  "bad user name or password", "not authorized");
      Log3 $name, 1, "$name: Connection refused, ".
        ($rc <= int(@txt) ? $txt[$rc] : "unknown error $rc");
      $hash->{authError} = $rc;
      MQTT2_CLIENT_Disco($hash);
      return;
    }

  } elsif($cpt eq "PUBACK") {
    shift(@{$hash->{qosQueue}}) if($hash->{qosQueue});

  } elsif($cpt eq "SUBACK") {
    MQTT2_CLIENT_doinit($hash) if($hash->{connecting});

  } elsif($cpt eq "PINGRESP") {
    delete($hash->{waitingForPingRespSince});
   
  } elsif($cpt eq "PUBLISH")  {
    my $cf = ord(substr($fb,0,1)) & 0xf;
    my $qos = ($cf & 0x06) >> 1;
    my ($tp, $val, $pid);
    ($tp, $off) = MQTT2_CLIENT_getStr($pl, 0);
    if($qos) {
      $pid = unpack('n', substr($pl, $off, 2));
      $off += 2;
    }
    $val = substr($pl, $off);
    MQTT2_CLIENT_send($hash, pack("CCnC*", 0x40, 2, $pid)) if($qos); # PUBACK

    if(!IsDisabled($name)) {
      $val = "" if(!defined($val));

      my $ir = AttrVal($name, "ignoreRegexp", undef);
      next if(defined($ir) && "$tp:$val" =~ m/$ir/);

      my $ac = AttrVal($name, "autocreate", "no");
      $ac = $ac eq "1" ? "simple" : ($ac eq "0" ? "no" : $ac); # backward comp.

      my $cid = makeDeviceName($hash->{clientId});
      $tp =~ s/:/_/g; # 96608
      Dispatch($hash, "autocreate=$ac\0$cid\0$tp\0$val", undef, $ac eq "no");

      my $re = AttrVal($name, "rawEvents", undef);
      DoTrigger($name, "$tp:$val") if($re && $tp =~ m/$re/);
    }

  } else {
    Log 1, "M2: Unhandled packet $cpt, disconneting $name";
    MQTT2_CLIENT_Disco($hash);
  }
 
  InternalTimer(gettimeofday(), 'MQTT2_CLIENT_Read_Consume', $hash, 0);
 
  return undef;
  }


Im Prinzip wurde nur die Verarbeitung der Nachrichten aus der ReadFn verschoben in eine Consume-Funktion, die sich dann selber mittels Timer sofort wieder aufrufen läßt, wenn noch etwas im Buffer ist.
Der erste Aufruf dieser Consume-Funktion erfolgt noch direkt durch die ReadFn, sodass damit die Consume-Kette angestossen wird.

Hier mal der Patch:
Index: 00_MQTT2_CLIENT.pm
===================================================================
--- 00_MQTT2_CLIENT.pm (revision 22441)
+++ 00_MQTT2_CLIENT.pm (working copy)
@@ -325,26 +325,37 @@

#####################################
sub
-MQTT2_CLIENT_Read($@)
+MQTT2_CLIENT_Read($)
{
-  my ($hash, $reread) = @_;
+  my ($hash) = @_;

   my $name = $hash->{NAME};
   my $fd = $hash->{FD};

-  if(!$reread) {
-    my $buf = DevIo_SimpleRead($hash);
-    if(!defined($buf)) {
-      MQTT2_CLIENT_Disco($hash);
-      return "";
-    }
-    $hash->{BUF} .= $buf;
+  my $buf = DevIo_SimpleRead($hash);
+  if(!defined($buf)) {
+    DevIo_Disconnected($hash);
+    return "";
   }
+  $hash->{BUF} .= $buf;

+  RemoveInternalTimer($hash, 'MQTT2_CLIENT_Read_Consume');
+  MQTT2_CLIENT_Read_Consume($hash);
+}
+
+#####################################
+sub
+MQTT2_CLIENT_Read_Consume($)
+{
+  my ($hash) = @_;
+
+  my $name = $hash->{NAME};
+  my $fd = $hash->{FD};
+
   my ($tlen, $off) = MQTT2_CLIENT_getRemainingLength($hash);
   if($tlen < 0 || $tlen+$off<=0) {
     Log3 $name, 1, "Bogus data from $name, closing connection";
-    MQTT2_CLIENT_Disco($hash);
+    DevIo_Disconnected($hash);
     return;
   }
   return if(length($hash->{BUF}) < $tlen+$off);
@@ -422,8 +433,11 @@
     Log 1, "M2: Unhandled packet $cpt, disconneting $name";
     MQTT2_CLIENT_Disco($hash);
   }
-  return MQTT2_CLIENT_Read($hash, 1);
-}

+  InternalTimer(gettimeofday(), 'MQTT2_CLIENT_Read_Consume', $hash, 0);

+  return undef;
+  }

######################################
# send topic to client if its subscriptions matches the topic


Ich habe das bei mir jetzt drei Tage sehr stabil laufen. In dieser Zeit hatte ich keinen Abbruch meiner Verbindung mehr, und auch keine größeren Freezes. Außerdem reagiert Fhem deutlich zügiger auf der Weboberfläche...

Vielleicht kannst du das ja einfließen lassen. Danke schon mal...

Grüße
Reinerlein

rudolfkoenig

Tut mir leid, die Benachrichtigung fuer dieses Thema wurde bei mir nie aktiviert, ich habe die Diskussion nur per Zufall wieder gefunden.

Zu den vielen Punkten:
- falls eine Event-Verarbeitung 2.5 Sekunden braucht, dann ist da was falsch, entweder beim Definieren der Instanzen, oder in den Modulen. Kannst Du ein "attr global verbose 5" Log eines Events hier anhaengen? Ich meine, da passiert deutlich mehr, als das gezeigte userReadings.
- MQTT2_DEVICE ist (noch) nicht optimiert fuer eine sehr grosse Menge an readingsList Zeilen. Vieviele sind es in deinem Fall?
- mit InternalTimer ermoeglichst Du, dass zwischen der Abarbeitung einzelner Events IO stattfindet. Das ist sinnvoll fuer ueberlastete Systeme, wichtiger waere aber die Ueberlastung zu vermeiden. Ich habe die Idee trotzdem aufgegriffen, und sie in MQTT2_CLIENT und MQTT2_SERVER eingebaut.
- den MQTT2_CLIENT_Disco Aufruf habe ich gelassen, aber die Funktion mit einem $noMsg Parameter erweitert. Allerdings meine ich, dass bei ausbleibenden PINGRESP man noch ein normales Disconnect versuchen sollte.

rudolfkoenig

Zitat- MQTT2_DEVICE ist (noch) nicht optimiert fuer eine sehr grosse Menge an readingsList Zeilen. Vieviele sind es in deinem Fall?

Wenn deine 16 Shelly Devices alle 3ems sind, dann sind das (wenn ich das shelly3em Template richtig lese) 16*32 = 512 readingsList Zeilen, die pro Event alle mindestens 2-mal geprueft werden.

Bis mir einfaellt, wie ich das Modul fuer solche Faelle optimieren kann, schlage ich vor im template die 25 emeter Zeilen in readingsList gegen Folgendes auszutauschen:
shellies/DEVNAME/emeter/./.* { $TOPIC =~ m,emeter/(.)/(.*),;; { "emeter_$1_$2" => $EVENT } }\
shellies/DEVNAME/emeter/./total:.* {$TOPIC =~ m,emeter/(.)/.*,;; {"emeter_$1_kWh" => sprintf("%.2f",$EVENT/1000)}}

Das sollte die Anzahl der Pruefungen auf 144 (ca ein drittel) verringern.

Reinerlein

#19
Hi Rudi,

diese Zeitverzögerung habe ich bei allen Topics, die abgearbeitet werden. Bei den meisten habe ich natürlich keinerlei Notify oder userreadings dran.
Aber ich habe einige Statistik-Werte eingerichtet.

Die ReadingLists sind natürlich teilweise eine Menge...
Ein normaler Shelly-Schalter hat schon so 12 Einträge im Attribut ReadingList stehen. Teilweise mit mehreren "json2nameValue".
Ein EM3 hat 28 Einträge... aber den habe ich momentan auch nur einmal...

Hier mal ein Log:(im Anhang, wieder gelöscht)

rudolfkoenig

Kannst Du bitte deinen Beitrag modifizieren, und das Log als Anhang hinzufuegen?

Weiterhin interessiert mich die Ausgabe von
{ @{$ntfyHash{"*"}}." ".@{$ntfyHash{"Statistik"}} }

Sonst:
- wovor ich Angst gehabt habe (das Matchen der vielen Regexps) scheint kaum Zeit in Anspruch zu nehmen (<10s)
- die Statistik scheint viel Unsinn zu treiben, nimmt aber nicht sooo viel Zeit in Anspruch, pro Event ca 40ms
- das durch die Statistik ausgeloesten Events tun allerdings weh mit 100ms, auch wenn scheinbar niemand daran Interesse hat.
- kannst Du testweise pruefen, wie sich das System verhaelt ohne Statistik? (ich meine damit ein verbose 5 Log fuer ein Event)
- hast Du viele DOIFs?

Reinerlein

Hi Rudi,

die Ausgabe erzeugt eine Fehlermeldung:
Can't use an undefined value as an ARRAY reference at (eval 6454273) line 1.
Leider weiß ich nicht genau, was da raus kommen sollte, und kann es deshalb nicht selber korrigieren. Kannst du mir da helfen?

Hier das Log mit Statistik disabled:
2020.07.23 22:01:24.122 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/power => 1_power
2020.07.23 22:01:24.128 5: Starting notify loop for hwr_Hausstrom, 2 event(s), first is 1_power: 349.17
2020.07.23 22:01:24.129 5: statistics Statistik: Notify.296 Notification of 'hwr_Hausstrom' received. Update statistics.
2020.07.23 22:01:24.178 5: Starting notify loop for global_Powerlist, 1 event(s), first is hwr_Hausstrom.power:d: <html><div style='text-align:right'>1318.5 W</div></html>
2020.07.23 22:01:24.204 5: End notify loop for global_Powerlist
2020.07.23 22:01:24.206 5: Starting notify loop for global_Powerlist, 13 event(s), first is min: 0.00
2020.07.23 22:01:24.255 5: End notify loop for global_Powerlist
2020.07.23 22:01:24.293 5: End notify loop for hwr_Hausstrom
2020.07.23 22:01:24.300 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/pf => 1_pf
2020.07.23 22:01:24.307 5: Starting notify loop for hwr_Hausstrom, 1 event(s), first is 1_pf: 0.88
2020.07.23 22:01:24.308 5: statistics Statistik: Notify.296 Notification of 'hwr_Hausstrom' received. Update statistics.
2020.07.23 22:01:24.374 5: End notify loop for hwr_Hausstrom
2020.07.23 22:01:24.381 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/current => 1_current
2020.07.23 22:01:24.391 5: Starting notify loop for hwr_Hausstrom, 2 event(s), first is 1_current: 1.68
2020.07.23 22:01:24.392 5: statistics Statistik: Notify.296 Notification of 'hwr_Hausstrom' received. Update statistics.
2020.07.23 22:01:24.481 5: End notify loop for hwr_Hausstrom
2020.07.23 22:01:24.485 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/voltage => 1_voltage
2020.07.23 22:01:24.496 5: Starting notify loop for hwr_Hausstrom, 1 event(s), first is 1_voltage: 237.22
2020.07.23 22:01:24.497 5: statistics Statistik: Notify.296 Notification of 'hwr_Hausstrom' received. Update statistics.
2020.07.23 22:01:24.563 5: End notify loop for hwr_Hausstrom
2020.07.23 22:01:25.587 4: Connection closed for WEB_Black_192.168.0.32_56041: Connection reset by peer
2020.07.23 22:01:26.504 5: publish received for sensors/garten_Schrank_01/Uptime/Value, 36460
2020.07.23 22:01:26.506 5: Starting notify loop for garten_Schrank_01, 1 event(s), first is transmission-state: incoming publish received
2020.07.23 22:01:26.554 5: End notify loop for garten_Schrank_01
2020.07.23 22:01:26.555 5: calling readingsSingleUpdate(garten_Schrank_01,Uptime,36460,1)
2020.07.23 22:01:26.556 5: Starting notify loop for garten_Schrank_01, 1 event(s), first is Uptime: 36460
2020.07.23 22:01:26.604 5: End notify loop for garten_Schrank_01

Das ist deutlich kürzer... Also liegt das an Statistik... kennst du dich damit aus? Bring es etwas möglichst *ein* Statistik-Device pro zu übewachendem Device zu haben? Oder ändert das sowieso nix?
Momentan ist es ja ein einziges Statistik-Device für alle...

DOIFs habe ich so ca. 50, wieso?

Grüße
Reinerlein

Beta-User

Moin,

{ join "\n", @{$ntfyHash{"*"}} }

liefert bei mir auch keine Ausgabe, die irgendwas mit einem Gerät TYPE=statistics zu tun hätte... (Hier läuft auch 1 statistics für mehrere Geräte - allerdings noch nicht sooo lange; NOTIFYDEV ist aber im list des statistics-Device vorhanden).

Irgendwie werde ich den Verdacht nicht los, dass die Verzögerung was mit dem Loggen (v.a. der Statistik-Werte!) zu tun hat. Nutzt du DBLog? Wenn ja, ist das optimiert?

Zu DOIF: Soweit mir bekannt, hängt das sich das seit einigen Monaten (?) in die normale notify-Verarbeitung rein, was lt. Aussage des Modulautors 30% Performance-Gewinn bedeuten würde... Das Modul dürfte aber aktuell sein, oder?
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: ZigBee2mqtt, MiLight@ESP-GW, BT@OpenMQTTGw | ZWave | SIGNALduino | MapleCUN | RHASSPY
svn: u.a Weekday-&RandomTimer, Twilight,  div. attrTemplate-files, MySensors

Beta-User

@Rudi, noch was anderes, was mir jüngst in MQTT2_DEVICE aufgefallen ist. Da wird in Zeile 161 eine Array-Variable @retData eingeführt, ich verstehe allerdings nicht so recht, welchen Zweck die anschließend hat, außer - ohne weitere Auswertungsaktion - gefüllt zu werden?
(Hat allerdings vermutlich nichts substantielles mit den Verzögerungen zu tun).
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: ZigBee2mqtt, MiLight@ESP-GW, BT@OpenMQTTGw | ZWave | SIGNALduino | MapleCUN | RHASSPY
svn: u.a Weekday-&RandomTimer, Twilight,  div. attrTemplate-files, MySensors

rudolfkoenig

@Reinerlein: sorry, haette denken koennen, dass fuer Statistik keine extra Schlange angelegt wird: es gibt kein notify/DOIF/FileLog/etc, was explizit danach fragt. Ersatz:
fhem> trigger global x
fhem> { @{$ntfyHash{"*"}}  }

trigger garantiert, dass ntfyHash{"*"} angelegt ist.

Das Problem ist nicht so sehr statistik an sich (mit 40ms), sondern dass es scheinbar zusaetzliche Event-Loops anstoesst, die bei dir ueber 100ms dauern, selbst wenn kein notify/DOIF/etc an den Daten interessiert ist:
Zitat2020.07.23 19:39:05.075 5: Starting notify loop for Statistik, 1 event(s), first is Updated stats for: hwr_Hausstrom
2020.07.23 19:39:05.185 5: End notify loop for Statistik
fhem.pl versucht sinnlose NotifyFn Aufrufe durch den NOTIFYDEV Internal (bzw. mit dem daraus abgeleiteten ntfyHash) zu vermeiden, diese festzustellen gelingt aber nicht immer. Ich habe den Verdacht, dass DOIF NOTIFYDEV nicht setzt, deswegen DOIF:NotifyFn sinnlos aufgerufen wird, und die Pruefung, ob ein Event relevant ist, lange dauert.
Das kann fuer andere Module genauso gelten, ich habe nur DOIF ausgepickt, weil es komplex ist, und eine Pruefung vmtl. aufwendig.

Kannst Du bitte in fhem.pl, Zeile 3175 (vor dem NotifyFn Aufruf)
Log 1, "Calling $dev $n";
einfuegen, und das Ergebnis hier zeigen? Ich will damit sehen, welches NotifyFn wie lange braucht.


@Beta-User: danke fuer den Hinweis, habe retData entfernt.

Reinerlein

Hi Rudi, hallo Beta-User,

ja, mein System ist aktuell. Unterschiede gibt es aktuell nur in der Änderung von mir...

Die Angabe von
{ join "\n", @{$ntfyHash{"*"}} }

ergibt:
DbLog
FileLog_CULMAX
FileLog_DELETE_aussen_Einfahrt_PIR
FileLog_DELETE_aussen_Einfahrt_Switch_01
FileLog_DELETE_vorgarten_Gehweg
FileLog_Sonos_Jim
FileLog_aussen_Terrasse_Steckdose_Kamin
FileLog_aussen_Terrasse_Steckdose_Wand
FileLog_aussen_Terrasse_Switch_01
FileLog_flur_Delete_Klingel
FileLog_flur_Delete_Taster
FileLog_garten_Regensensor_Rain
FileLog_garten_Schrank_Steckdose_Innen_02
FileLog_hwr_Heizung_FernwaermeTemperatur
FileLog_hwr_Heizung_KreisTemperatur
FileLog_hwr_Heizungsanlage
FileLog_hwr_Lueftung
FileLog_hwr_Taster_Ausgang
FileLog_hwr_WasserTemperatur
FileLog_myTwilight
FileLog_rauchmelder_Joe_OLD
FileLog_schlafzimmer_temp
FileLog_server_ShellyAnnounce
FileLog_unbekannt_Garagentorantrieb_1
FileLog_unbekannt_Garagentorantrieb_10
FileLog_unbekannt_Garagentorantrieb_11
FileLog_unbekannt_Garagentorantrieb_12
FileLog_unbekannt_Garagentorantrieb_3
FileLog_unbekannt_Garagentorantrieb_5
FileLog_unbekannt_Garagentorantrieb_6
FileLog_unbekannt_Garagentorantrieb_7
FileLog_unbekannt_Garagentorantrieb_8
FileLog_unbekannt_Garagentorantrieb_9
FileLog_vorgarten_Fahrradschuppen_PIR_DOIF
FileLog_weihnachten_Aussen_Lightscene
FileLog_weihnachten_Innen_Lightscene
FileLog_wohnzimmer_Sensorfeld_1
FileLog_wohnzimmer_Sensorfeld_2
FileLog_wohnzimmer_Sensorfeld_3
FileLog_wohnzimmer_Sensorfeld_4
FileLog_wohnzimmer_Sensorfeld_5
FileLog_wohnzimmer_Sensorfeld_6
FileLog_wohnzimmer_Sensorfeld_7
FileLog_wohnzimmer_Sensorfeld_8
FileLog_wohnzimmer_Stehlampe
HMLAN
Logfile
SonosRG
Sonos_GaestezimmerRG_Favourites
Sonos_GaestezimmerRG_Playlists
Sonos_GaestezimmerRG_Queue
Sonos_GaestezimmerRG_Radios
Sonos_WohnzimmerRG_Favourites
WEBGeoFancy
WEB_Black
WEB_Default
aussen_Einfahrt_Lightscene
aussen_Terrasse_Lightscene
aussen_Terrasse_TuerLightscene
aussen_Vorgarten_Lightscene
automation_Anwesenheit_Eltern_Lightscene
automation_Fernsehen_LightScene
dash
eventTypes
expandJSON
expandJSON_TasmotaDevices
flur_Taster_Notify
garten_Beleuchtung_LightScene
garten_Regen_HourCounter
global_ActiveDevices
global_Batteries_StateChanger
global_Batteries_StateWatchdog
global_Batteries_StateWatchdogVorlage
global_Home_Notify
global_InnenTemperatur
global_Monitoring_DeviceActivity
global_Monitoring_DeviceActivityNotify
global_Monitoring_DeviceActivity_SetActivityNotify
global_Monitoring_WindowOpen
global_OpenedDevices
global_OverTemperature
global_Panic_Lightscene
global_Panic_Notify
global_Powerlist
global_ShellyStates
global_batteries
heizung_Arbeitszimmer
heizung_Arbeitszimmer_WT
heizung_Bad
heizung_BadFussboden
heizung_Bad_FK_Links
heizung_Bad_FK_Rechts
heizung_Bad_TK
heizung_Bad_WT
heizung_Flur
heizung_Flur_WT
heizung_GaesteWC
heizung_GaesteWC_FK
heizung_GaesteWC_TK
heizung_GaesteWC_WT
heizung_Gaestezimmer
heizung_Gaestezimmer_FK_Links
heizung_Gaestezimmer_FK_Rechts
heizung_Gaestezimmer_WT
heizung_Jim
heizung_Jim_FK_Links
heizung_Jim_FK_Rechts
heizung_Jim_TK
heizung_Jim_WT
heizung_Joe
heizung_Joe_FK
heizung_Joe_TK
heizung_Joe_WT
heizung_ModusWechsel_Notify
heizung_Sammler_FK
heizung_Sammler_FTK
heizung_Sammler_NotifyFK
heizung_Sammler_Stellventile
heizung_Sammler_Stellventile_Trigger
heizung_Sammler_Vorgabe
heizung_Sammler_Wandthermostate
heizung_Schlafzimmer
heizung_Schlafzimmer_FK_Links
heizung_Schlafzimmer_FK_Rechts
heizung_Schlafzimmer_WT
heizung_TK_Notify
heizung_Weekprofile
heizung_Wohnzimmer
heizung_Wohnzimmer_FK_Terrasse_Rechts
heizung_Wohnzimmer_WT
heizung_global_ecobtn
hmInfo
hwr_Fritzbox_CallList_RG
hwr_FrizboxNew_PresenceLog
hwr_Hausstrom_Watchdog
hwr_Heizungsanlage_Watchdog
hwr_Lueftung_Notify
ledBeleuchtung_Lightscene
modbus
mqtt_LostConnectionNotify
rauchmelder_Uebersicht
sensorlog
vorgarten_Beetbeleuchtung_Lightscene
weihnachten_Aussen_Lightscene
weihnachten_Innen_Lightscene
wohnzimmer_AVReceiver_Zone2_Hours
wohnzimmer_AVSystem
wohnzimmer_Lightscene_Fernsehmodus
wohnzimmer_TasterTerrasse_1_Notify_Short
wohnzimmer_TasterTerrasse_2_Notify_Short
wohnzimmer_TasterTerrasse_3_Notify_Short
wohnzimmer_TasterTerrasse_4_Notify_Short
wohnzimmer_TasterTerrasse_5_Notify_Short
wohnzimmer_TasterTerrasse_6_Notify_Short
wohnzimmer_XBox_Hours
myFreezemon
WEB_Black_192.168.0.66_58366
WEB_Default_192.168.0.14_39453
WEB_Default_192.168.0.14_44962

DBLog ist zwar definiert, aber auf disable, da ich es bislang noch nicht aktiv verwenden wollte... das waren nur Tests...

Die Angabe von:
{ @{$ntfyHash{"*"}}  }
ergibt 159

Wie ist die Ausgabe zu verstehen?
Sollen das die sein, die ein Sternchen im NotifyDev haben. Das haben ja im Prinzip alle, da ich ja spätestens beim Wert ein Sternchen habe...

Es werden aktuell nur von meinem EM3 die Statistiken weggespeichert (alles in FileLog), wobei es dort aber nur zwei "_Last"-Statistiken betrifft:
- hwr_Hausstrom:statEnergy_totalKWhLast:.*
- hwr_Hausstrom:statPowerHourLast:.*
Damit fülle ich dann meine Vergangenheitsplots. Das ist aber auch nur jeweils einer pro Stunde...

Ansonsten wird schon einiges ins Log geschrieben. An meinem EM3 z.B.:
hwr_Hausstrom:0_energyKWh:.*
hwr_Hausstrom:0_energy_totalKWh:.*
hwr_Hausstrom:0_power:.*
hwr_Hausstrom:1_energyKWh:.*
hwr_Hausstrom:1_energy_totalKWh:.*
hwr_Hausstrom:1_power:.*
hwr_Hausstrom:2_energyKWh:.*
hwr_Hausstrom:2_energy_totalKWh:.*
hwr_Hausstrom:2_power:.*
hwr_Hausstrom:energyKWh:.*
hwr_Hausstrom:energy_totalKWh:.*
hwr_Hausstrom:power:.*
hwr_Hausstrom:online:.*
hwr_Hausstrom:relay:.*


Grüße
Reinerlein

Beta-User

Hmm, ja, bin im Moment nicht sicher, wie viele Events statistics tatsächlich wirft.

Aber da FileLog: Kann es dann sein, dass die Logfile, in der
Ansonsten wird schon einiges ins Log geschrieben. An meinem EM3 z.B.:
landen, eine sehr große ist? Das könnte - ggf. in Verbindung mit der Aktualisierung von Plots - das System durchaus ausbremsen, oder?
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: ZigBee2mqtt, MiLight@ESP-GW, BT@OpenMQTTGw | ZWave | SIGNALduino | MapleCUN | RHASSPY
svn: u.a Weekday-&RandomTimer, Twilight,  div. attrTemplate-files, MySensors

rudolfkoenig

$ntfyHash{"*"} enthaelt die Liste der "notify"-Instanzen (DOIF,FileLog,etc), deren Regexp fhem.pl nicht einzelnen Geraeten zuordnen konnte.
Die Laenge ist ein Hinweis darauf, wieviele unoptimierte Aufrufe erfolgen.

@Beta-User: Eine grosse FileLog Datei an sich ist kein Problem, die Suche nach dem ersten Eintrag ist relativ schnell. FileLog wird dann langsam, wenn im Bereich der anzuzeigenden Daten sehr viel Unnoetiges ist. D.h. falls eine Datei nur das enthaelt, was fuer ein SVG-Plot relevant ist, dann kann sie Daten fuer viele Jahre enthalten. Auf der anderen Seite sind Tages-Dateien, die alles sammeln, langsam. Fuer unser Problem hier sind beide Arten gleich, und vmtl. irrelevant.

@Reinerlein: Bitte das Log mit dem "Calling" Zeilen nicht vergessen.

Reinerlein

Hallo,

ja, die eine EM3-Logdatei (mit den Power-Werten usw.) ist schon groß. Sie steht auf monatlich und hat jetzt für Juli knapp 730.000 Einträge.

Aber die Verzögerungen gab es ja von Anfang an, und auch, wenn ich nicht die Plots dazu auf der Oberfläche anzeige.
Das Schreiben in eine so große Datei sollte ja eigentlich keine zusätzliche Zeit benötigen...

@Rudi: In der angegebenen Zeile ist der Kommentar über der "sub sleep_WakeUpFn()". Meine fhem.pl ist vom 16.7.2020 - 9:19 (Version 22408)

Grüße
Reinerlein

rudolfkoenig

Sorry, Zahlendreher, ich meinte 3715.
Vor dem einzigen CallFn(...,"NotifyFn",...)