Ständige Verbindungsabbrüche bei MQTT2

Reinerlein · 08 Juni 2020, 19:13:48

Hallo,

ich habe aktuell das Problem, dass ich meine MQTT2-Devices nicht mehr nutzen kann. Nach einem Neustart funktioniert es ein/zwei Minuten, dann nicht mehr.
Meine parallel dazu noch existierenden MQTT-Devices (also "altes" Modul) laufen dagegen ganz normal weiter...

Was mir im Log aufgefallen ist, ist dass das Modul ein "PINGREQ" absendet, obwohl direkt davor Nachrichten empfangen wurden, und dann wird vom Mosquitto anscheinend auch kein "PINGRESP" gesendet, wenn es andere übertragene Daten gibt.
Ab dann hängt das Modul anscheinend in dem Zustand fest, dass es eine Response erwartet, obwohl zwischendurch neue Verbindungsversuche gemacht werden. Zumindest rettet sich das Modul nicht mehr bis zum nächsten Neustart.

Hier mal der Log mit den Ereignisse, die ich meinte:

Code Auswählen

2020.06.08 18:53:06 5: mqtt2: received PUBLISH (0).shellies/shellyswitch25-F40867/overtemperature0
2020.06.08 18:53:06 5: mqtt2: dispatch autocreate=no\000fhemMQTT2\000shellies/shellyswitch25-F40867/overtemperature\0000
2020.06.08 18:53:07 5: mqtt2: sending PINGREQ (192)(0)
2020.06.08 18:53:13 5: mqtt2: received PUBLISH (0)%sensors/flur_Aussenwand_01/RSSI/Value-76.00
2020.06.08 18:53:13 5: mqtt2: dispatch autocreate=no\000fhemMQTT2\000sensors/flur_Aussenwand_01/RSSI/Value\000-76.00
.
.
2020.06.08 18:53:13 5: mqtt2: received PUBLISH (0),sensors/aussen_Terrasse_Switch_02/LEDs/set/0set_done
2020.06.08 18:53:13 5: mqtt2: dispatch autocreate=no\000fhemMQTT2\000sensors/aussen_Terrasse_Switch_02/LEDs/set/0\000set_done
.
.
2020.06.08 18:53:15 1: 192.168.0.11:1883 disconnected, waiting to reappear (mqtt2)
2020.06.08 18:53:15 4: IP: 192.168.0.11 -> 192.168.0.11
2020.06.08 18:53:15 1: 192.168.0.11:1883 reappeared (mqtt2)
2020.06.08 18:53:45 2: mqtt2: No PINGRESP for last PINGREQ (at 2020-06-08 18:53:07), disconnecting
2020.06.08 18:53:45 1: 192.168.0.11:1883 disconnected, waiting to reappear (mqtt2)
2020.06.08 18:53:47 4: IP: 192.168.0.11 -> 192.168.0.11
2020.06.08 18:53:49 1: 192.168.0.11:1883 reappeared (mqtt2)
2020.06.08 18:54:40 1: 192.168.0.11:1883 disconnected, waiting to reappear (mqtt2)
2020.06.08 18:54:41 4: IP: 192.168.0.11 -> 192.168.0.11
2020.06.08 18:54:41 1: 192.168.0.11:1883 reappeared (mqtt2)
2020.06.08 18:55:30 2: mqtt2: No PINGRESP for last PINGREQ (at 2020-06-08 18:54:34), disconnecting
2020.06.08 18:55:30 1: 192.168.0.11:1883 disconnected, waiting to reappear (mqtt2)
2020.06.08 18:55:39 4: IP: 192.168.0.11 -> 192.168.0.11
2020.06.08 18:55:39 1: 192.168.0.11:1883 reappeared (mqtt2)
2020.06.08 19:01:10 1: 192.168.0.11:1883 disconnected, waiting to reappear (mqtt2)
2020.06.08 19:01:11 4: IP: 192.168.0.11 -> 192.168.0.11
2020.06.08 19:01:12 1: 192.168.0.11:1883 reappeared (mqtt2)
2020.06.08 19:01:42 2: mqtt2: No PINGRESP for last PINGREQ (at 2020-06-08 19:00:39), disconnecting
2020.06.08 19:01:42 1: 192.168.0.11:1883 disconnected, waiting to reappear (mqtt2)
2020.06.08 19:01:44 4: IP: 192.168.0.11 -> 192.168.0.11
2020.06.08 19:01:44 1: 192.168.0.11:1883 reappeared (mqtt2)

Es gibt auch noch weitere Einträge, dass auf ein Response gewartet wird (19:01:42, 18:55:30 und 18:53:45), obwohl vorher im Log kein Request dazu ausgegeben wurde...

Vielleicht kann Rudi oder jemand anderes damit was anfangen, bzw. das bestätigen?

Grüße
Reinerlein

rudolfkoenig · 08 Juni 2020, 20:21:14

Existiert das Problem auch ohne den MQTT Geraeten?
Im Netz gibt es ein paar Hinweise auf kaputte Docker-Verbindungen, wenn man nach "mosquitto no pingresp" sucht: wo laeuft mosquitto?

Reinerlein · 08 Juni 2020, 20:44:15

Hi Rudi,

Mosquitto läuft, genauso wie FHEM, nativ direkt auf meinem Debian 10 (buster).
Ob es ohne Geräte läuft, kann ich ja nur schwer testen... meinst du einfach mit einem anderen, nicht verwendeten, MQTT-Broker verbinden?

Der Mosquitto selbst läuft auch normal weiter, ich kann das ja auf der Konsole bzw. mit einem MQTT Client auf dem Desktop-Rechner sehen.
Da ist auch schon ein bißchen was los (laut Mosquitto Statistik ca. 270 Messages pro Minute). Vielleicht kommt MQTT2 damit nicht ganz klar? Der nimmt ja immer alle Nachrichten an...

Grüße
Reinerlein

Reinerlein · 09 Juni 2020, 17:09:50

Hi Rudi,

ich habe es mal genauer untersucht...

Das Modul hat ein Problem mit längeren Laufzeiten beim Setzen von Readings-Werten.
Das passiert dann, wenn man langlaufende Userreadings oder langlaufende Notifies an einem Reading, welches vom Modul gesetzt werden soll, hat.

Dann ruft er die Daten vom Socket nicht mehr schnell genug ab, und wenn dann der Mosquitto weitersenden möchte, und der Empfangspuffer in FHEM voll ist, dann gibt es auf Mosquitto-Seite einen Socket-Error, und in Folge dann einen Verbindungsabbruch.

Ich hatte zwei etwas länger laufende Notifies an zwei Readings. Die haben so ca. 5 Sekunden gebraucht. Das "alte" MQTT-Modul hat damit scheinbar nur geringe Probleme... dort war ein Verbindungsabbruch zwar auch mal aufgetreten, aber deutlich seltener (vielleicht so 1-3 mal am Tag).

Vielleicht bringt es was, wenn du erst den gesamten Socket leer liest und danach die Verteilung der gesammelten Informationen durchführst?

Ich habe bei mir jedenfalls die Langläufer durch ein anderes Konzept ersetzt, damit ich erstmal wieder Ruhe habe...
Aber vielleicht hilft diese Info dem einen oder anderen ja auch weiter...

Grüße
Reinerlein

Reinerlein · 12 Juni 2020, 18:09:45

Hallo nochmal,

nach einem Tag Ruhe gingen die Abbrüche wieder los.
Leider fängt sich das Modul dabei nicht mehr ein.

Ich habe mal eine Änderung im Code gemacht, die mir auch logisch korrekter erschien, und nun habe ich seit 1,5 Tagen wieder etwas stabilere Zustände.

Ich habe in der Zeile 161 (MQTT2_CLIENT_keepalive), das return-Statement angepasst.
Dort wird bei einer Zeitüberschreitung (bzw. ausbleibender PINGRESP) auch noch was auf den Socket geschickt. Das erschien mir komisch.
Ich habe dort nun ein direktes Schliessen der Verbindung eingesetzt, womit sich da zumindest mal was retten kann...
Aus

Code Auswählen

return MQTT2_CLIENT_Disco($hash);
habe ich ein

Code Auswählen

return DevIo_Disconnected($hash);
gemacht.

Damit ist immer noch das Problem, dass der Socketpuffer nicht immer vollständig geleert wird, aber der Zustand korrigiert sich damit wenigstens wieder...
Vielleicht kann das ja noch jemand testen und Rudi kann das vielleicht einchecken...

Für den vollen Puffer (und damit in Folge ein Socket-Error auf Seiten Mosquitto) müsste die Verarbeitung umgebaut werden... vielleicht probiere ich da auch mal was...

Grüße
Reinerlein

moskito · 12 Juni 2020, 22:40:19

Servus Reinerlein,

nur so zum Verständnis:

Zitatlanglaufende Userreadings oder langlaufende Notifies an einem Reading

Kannst du das mal konkretisieren? Du hattest da Laufzeiten von 5 Sekunden erwähnt, was ja schon ziemlich aussergewöhnlich scheint.

Gruß
Danny

Reinerlein · 13 Juni 2020, 00:11:41

Hi Danny,

ich hatte so einen eigenen Notify-Watchdog, der bei Aktualisierung eines Readings eines Devices ein "at"-Device mit einem neuen Zeitstempel erzeugt hatte (und vorher ein bereits vorhandenes entfernt hatte).
Damit kann man sehr einfach das Ausbleiben einer Reading-Aktualisierung melden... Allerdings wird bei jeder Reading-Aktualisierung (ich hatte bei meinen Devices ein paar angegeben, der sehr zyklisch aktualisiert wurden) das bestehende "at"-Device gelöscht, und ein neues angelegt...
Das hat bei mir schon mal so 2-7 Sekunden gedauert...

Außerdem habe ich einige Userreadings, die etwas komplexere Berechnungen durchführen (eines war eine HSV (3 Readings lesen) -> RGBW-Umrechnung (4 Readings setzen), welche bei jeder Änderung eines der drei Readings getriggert wurde... Ich sehe in einem Userreading ja leider nicht, ob S und V noch kommen würden, wenn ich gerade auf H reagiere, und muss deshalb immer triggern (unter Umständen eben dreimal)...

Da das dann im Trigger der MQTT2-Aktualisierung durchgeführt wurde, wurde dieser natürlich sehr lang in der Abarbeitung...
Das habe ich jetzt auf "watchdog" umgestellt... bzw. Altlasten muss man auch mal irgendwann wegräumen

Man muss sie nur finden...

Grüße
Reiner

Reinerlein · 20 Juli 2020, 00:37:05

Hallo nochmal,

ich habe mich mal wieder diesem Thema gewidmet, da es immer hinderlicher wird.

ich habe mal den perfmon installiert, um dem auf die Schliche zu kommen. Dabei habe ich mal bei einem MQTT2-Device (mein Shelly EM3) verbose auf 5 gesetzt.
Folgendes finde ich z.B. im Log.

Code Auswählen

.
.
2020.07.20 00:21:09.988 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/relay/0 => state
2020.07.20 00:21:09.989 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/relay/0 => relay
2020.07.20 00:21:10.308 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/power => 0_power
2020.07.20 00:21:10.633 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/pf => 0_pf
2020.07.20 00:21:10.922 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/current => 0_current
2020.07.20 00:21:11.223 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/voltage => 0_voltage
2020.07.20 00:21:11.504 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/power => 1_power
2020.07.20 00:21:11.835 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/pf => 1_pf
2020.07.20 00:21:12.125 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/current => 1_current
2020.07.20 00:21:12.421 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/voltage => 1_voltage
2020.07.20 00:21:12.712 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/power => 2_power
2020.07.20 00:21:13.039 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/pf => 2_pf
2020.07.20 00:21:13.320 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/current => 2_current
2020.07.20 00:21:13.620 1: Perfmon: possible freeze starting at 00:21:10, delay is 3.619
.
.

Da sieht man sehr deutlich, dass die Verarbeitung der MQTT-Nachrichten (also das Dispatch) bei 00:21:09.988 begonnen hat, und bis 00:21:13.320 gedauert hat. Währenddessen hat fhem anscheinend nichts anderes verarbeitet (deshalb die untere freeze-Meldung, als fhem wieder "frei" war)...

Ich habe an dem Device userReadings, die immer die Summen der drei Phasenwerte bildet:

Code Auswählen

 power:._power.* {
  my $power0 = ReadingsVal($name, '0_power', 0);
  my $power1 = ReadingsVal($name, '1_power', 0);
  my $power2 = ReadingsVal($name, '2_power', 0);

  return $power0 + $power1 + $power2;
},

current:._current.* {
  my $current0 = ReadingsVal($name, '0_current', 0);
  my $current1 = ReadingsVal($name, '1_current', 0);
  my $current2 = ReadingsVal($name, '2_current', 0);

  return $current0 + $current1 + $current2;
},

energy:._energy.* {
  my $energy0 = ReadingsVal($name, '0_energy', 0);
  my $energy1 = ReadingsVal($name, '1_energy', 0);
  my $energy2 = ReadingsVal($name, '2_energy', 0);

  return $energy0 + $energy1 + $energy2;
},

energyKWh:._energyKWh.* {
  my $energy0 = ReadingsVal($name, '0_energyKWh', 0);
  my $energy1 = ReadingsVal($name, '1_energyKWh', 0);
  my $energy2 = ReadingsVal($name, '2_energyKWh', 0);

  return $energy0 + $energy1 + $energy2;
},

energy_total:._energy_total.* {
  my $energy0 = ReadingsVal($name, '0_energy_total', 0);
  my $energy1 = ReadingsVal($name, '1_energy_total', 0);
  my $energy2 = ReadingsVal($name, '2_energy_total', 0);

  return $energy0 + $energy1 + $energy2;
},

energy_totalKWh:._energy_totalKWh.* {
  my $energy0 = ReadingsVal($name, '0_energy_totalKWh', 0);
  my $energy1 = ReadingsVal($name, '1_energy_totalKWh', 0);
  my $energy2 = ReadingsVal($name, '2_energy_totalKWh', 0);

  return $energy0 + $energy1 + $energy2;
}

Hier noch das komplette List des Devices:

Code Auswählen

 Internals:
   CID        shellyem3-68C63AFB3952
   DEF        shellyem3-68C63AFB3952
   DEVICETOPIC hwr_Hausstrom
   FUUID      5ed8943e-f33f-6779-b85e-129424228df3d2f1
   IODev      mqtt2
   LASTInputDev mqtt2
   MSGCNT     1443
   NAME       hwr_Hausstrom
   NR         1748
   STATE      off
   TYPE       MQTT2_DEVICE
   mqtt2_MSGCNT 1443
   mqtt2_TIME 2020-07-20 00:30:17
   READINGS:
     2020-07-20 00:30:11   0_current       0.24
     2020-07-20 00:30:02   0_energy        156
     2020-07-20 00:30:02   0_energyKWh     0.00
     2020-07-20 00:30:02   0_energy_total  106707.3
     2020-07-20 00:30:02   0_energy_totalKWh 106.71
     2020-07-20 00:30:11   0_pf            0.54
     2020-07-20 00:30:11   0_power         31.12
     2020-07-20 00:30:12   0_voltage       235.69
     2020-07-20 00:30:12   1_current       1.15
     2020-07-20 00:30:02   1_energy        1068
     2020-07-20 00:30:02   1_energyKWh     0.02
     2020-07-20 00:30:03   1_energy_total  364072.6
     2020-07-20 00:30:03   1_energy_totalKWh 364.07
     2020-07-20 00:30:12   1_pf            0.78
     2020-07-20 00:30:12   1_power         213.45
     2020-07-20 00:30:13   1_voltage       237.95
     2020-07-20 00:30:17   2_current       3.04
     2020-07-20 00:30:03   2_energy        3078
     2020-07-20 00:30:03   2_energyKWh     0.05
     2020-07-20 00:30:04   2_energy_total  562907.9
     2020-07-20 00:30:04   2_energy_totalKWh 562.91
     2020-07-20 00:30:16   2_pf            0.83
     2020-07-20 00:30:16   2_power         601.88
     2020-07-20 00:30:17   2_voltage       237.43
     2020-06-04 08:27:20   associatedWith  mqtt2_GeneralBridge
     2020-07-20 00:30:17   current         4.43
     2020-07-20 00:30:04   energy          4302
     2020-07-20 00:30:03   energyKWh       0.07
     2020-07-20 00:30:04   energy_total    1033636.5
     2020-07-20 00:30:04   energy_totalKWh 1033.69
     2020-07-13 11:57:54   fw_ver          20200702-133522/v1.7.4@1d8b9fca
     2020-07-13 11:57:54   id              shellyem3-68C63AFB3952
     2020-07-13 11:57:54   ip              192.168.0.82
     2020-07-13 11:57:54   mac             68C63AFB3952
     2020-07-13 11:57:54   new_fw          false
     2020-07-13 11:57:54   online          true
     2020-07-20 00:30:16   power           846.45
     2020-07-20 00:30:10   relay           off
     2020-07-20 00:30:17   statCurrentDay  Min: 4.13 Avg: 4.64 Max: 7.13
     2020-07-19 23:59:50   statCurrentDayLast Min: 4.57 Avg: 5.14 Max: 5.62
     2020-07-20 00:30:17   statCurrentMonth Min: 2.85 Avg: 5.00 Max: 40.06
     2020-06-30 23:59:47   statCurrentMonthLast Min: 0.00 Avg: 4.82 Max: 39.19 (since: 2020-06-14_13:33:03 )
     2020-07-20 00:30:17   statCurrentYear Min: 0.00 Avg: 4.92 Max: 40.06 (since: 2020-06-14_13:33:03 )
     2020-07-20 00:30:17   statEnergy      Hour: -798 Day: -798 Month: 168 Year: -954 (since: 2020-06-05 )
     2020-07-20 00:30:17   statEnergyKWh   Hour: -0.01 Day: -0.01 Month: 0.00 Year: -0.02 (since: 2020-06-05 )
     2020-07-19 23:59:50   statEnergyKWhLast Hour: -0.01 Day: -0.01 Month: -0.02 Year: - (since: 2020-06-05 )
     2020-07-19 23:59:50   statEnergyLast  Hour: -558 Day: -558 Month: -1122 Year: - (since: 2020-06-05 )
     2020-07-20 00:30:17   statEnergy_total Hour: 534.7 Day: 534.7 Month: 442407.5 Year: 1023210.6 (since: 2020-06-05 )
     2020-07-20 00:30:17   statEnergy_totalKWh Hour: 0.53 Day: 0.53 Month: 442.46 Year: 1023.26 (since: 2020-06-05 )
     2020-07-19 23:59:50   statEnergy_totalKWhLast Hour: 0.19 Day: 0.19 Month: 580.80 Year: - (since: 2020-06-05 )
     2020-07-19 23:59:50   statEnergy_totalLast Hour: 128.1 Day: 128.1 Month: 580803.1 Year: - (since: 2020-06-05 )
     2020-07-20 00:30:17   statPowerDay    Min: 779.90 Avg: 910.40 Max: 1585.43
     2020-07-19 23:59:50   statPowerDayLast Min: 893.17 Avg: 1049.30 Max: 1177.62
     2020-07-20 00:30:17   statPowerHour   Min: 779.90 Avg: 910.42 Max: 1585.43
     2020-07-19 23:59:50   statPowerHourLast Min: 893.17 Avg: 1049.30 Max: 1177.62
     2020-07-20 00:30:17   statPowerMonth  Min: 455.02 Avg: 969.47 Max: 9360.88
     2020-06-30 23:59:47   statPowerMonthLast Min: 0.00 Avg: 925.46 Max: 8933.18 (since: 2020-06-04_10:10:01 )
     2020-07-20 00:30:17   statPowerYear   Min: 0.00 Avg: 943.83 Max: 9360.88 (since: 2020-06-04_10:10:01 )
     2020-07-20 00:30:17   statStateDay    off: 00:30:27 off_Count: 1
     2020-07-19 23:59:50   statStateDayLast off: 00:13:21 off_Count: 1
     2020-07-20 00:30:17   statStateHour   off: 00:30:27 off_Count: 1
     2020-07-19 23:59:50   statStateHourLast off: 00:13:21 off_Count: 1
     2020-07-20 00:30:17   statStateMonth  off: 18d 23:59:06 off_Count: 4 x_update: 00:31:05 x_update_Count: 3
     2020-06-30 23:59:47   statStateMonthLast off: 26d 13:48:55 off_Count: 2 on: 00:00:39 on_Count: 1 (since: 2020-06-04_10:10:01)
     2020-07-20 00:30:17   statStateYear   off: 45d 13:48:00 off_Count: 5 on: 00:00:39 on_Count: 1 x_update: 00:31:05 x_update_Count: 3 (since: 2020-06-04_10:10:01)
     2020-07-20 00:30:10   state           off
   helper:
     _98_statistics Statistik
     bm:
       MQTT2_DEVICE_Attr:
         cnt        1
         dmx        -1000
         dtot       0
         dtotcnt    0
         mTS        20.07. 00:18:46
         max        3.88622283935547e-05
         tot        3.88622283935547e-05
         mAr:
           set
           hwr_Hausstrom
           verbose
           5
       MQTT2_DEVICE_Get:
         cnt        2
         dmx        -1000
         dtot       0
         dtotcnt    0
         mTS        20.07. 00:18:23
         max        8.79764556884766e-05
         tot        0.000167131423950195
         mAr:
           HASH(0x6a9143c)
           hwr_Hausstrom
           ?
       MQTT2_DEVICE_Set:
         cnt        2726
         dmx        -1000
         dtot       0
         dtotcnt    0
         mTS        20.07. 00:00:54
         max        0.00174403190612793
         tot        2.15269947052002
         mAr:
           HASH(hwr_Hausstrom)
           hwr_Hausstrom
           ?
Attributes:
   Firmware   Shelly
   IODev      mqtt2
   alias      Hausstrom
   devStateIcon {my $onl = ReadingsVal($name,"online","false") eq "false" ? "red" : ReadingsVal($name,"state","...") eq "x_update" ? "gold" : ReadingsVal($name,"new_fw","false") eq "true" ? "yellow" : "green";; my $light = ReadingsVal($name,"relay","off");; my $cons = ReadingsVal($name,"power","unknown");; my $tag = getStatisticsDay(ReadingsVal($name,'statEnergy_totalKWh','0'));; my $show = '<a href="';; $show .= $onl eq "yellow" ? "/fhem?cmd.dummy=set $name x_update&XHR=1\">" : "http://".ReadingsVal($name,"ip","none").' "target="_blank">';; $show .= FW_makeImage('fa_circle_small@'.$onl)."</a>";; "<div> $show &nbsp; <a href=\"/fhem?cmd.dummy=set $name toggle&XHR=1\">".FW_makeImage('taster_ch_'.($light eq 'on' ? 'an_gruen' : 'aus_rot'), $light)." &nbsp; </a> Aktuell: $cons W Tag: $tag kWh</div>"}
   group      Stromverbrauch
   icon       measure_power
   readingList shellies/shellyem3-68C63AFB3952/online:.* online
shellies/announce:.* { $EVENT =~ m,..id...shellyem3-68C63AFB3952...mac.*, ? json2nameValue($EVENT) : undef }
shellies/shellyem3-68C63AFB3952/announce:.* { json2nameValue($EVENT) }
shellies/shellyem3-68C63AFB3952/relay/0:.* state
shellies/shellyem3-68C63AFB3952/relay/0:.* relay
shellies/shellyem3-68C63AFB3952/emeter/0/power:.* 0_power
shellies/shellyem3-68C63AFB3952/emeter/0/pf:.* 0_pf
shellies/shellyem3-68C63AFB3952/emeter/0/current:.* 0_current
shellies/shellyem3-68C63AFB3952/emeter/0/voltage:.* 0_voltage
shellies/shellyem3-68C63AFB3952/emeter/0/energy:.* 0_energy
shellies/shellyem3-68C63AFB3952/emeter/0/energy:.* {'0_energyKWh' => sprintf("%.2f",$EVENT/60/1000)}
shellies/shellyem3-68C63AFB3952/emeter/0/total:.* 0_energy_total
shellies/shellyem3-68C63AFB3952/emeter/0/total:.* {'0_energy_totalKWh' => sprintf("%.2f",$EVENT/1000)}
shellies/shellyem3-68C63AFB3952/emeter/1/power:.* 1_power
shellies/shellyem3-68C63AFB3952/emeter/1/pf:.* 1_pf
shellies/shellyem3-68C63AFB3952/emeter/1/current:.* 1_current
shellies/shellyem3-68C63AFB3952/emeter/1/voltage:.* 1_voltage
shellies/shellyem3-68C63AFB3952/emeter/1/energy:.* 1_energy
shellies/shellyem3-68C63AFB3952/emeter/1/energy:.* {'1_energyKWh' => sprintf("%.2f",$EVENT/60/1000)}
shellies/shellyem3-68C63AFB3952/emeter/1/total:.* 1_energy_total
shellies/shellyem3-68C63AFB3952/emeter/1/total:.* {'1_energy_totalKWh' => sprintf("%.2f",$EVENT/1000)}
shellies/shellyem3-68C63AFB3952/emeter/2/power:.* 2_power
shellies/shellyem3-68C63AFB3952/emeter/2/pf:.* 2_pf
shellies/shellyem3-68C63AFB3952/emeter/2/current:.* 2_current
shellies/shellyem3-68C63AFB3952/emeter/2/voltage:.* 2_voltage
shellies/shellyem3-68C63AFB3952/emeter/2/energy:.* 2_energy
shellies/shellyem3-68C63AFB3952/emeter/2/energy:.* {'2_energyKWh' => sprintf("%.2f",$EVENT/60/1000)}
shellies/shellyem3-68C63AFB3952/emeter/2/total:.* 2_energy_total
shellies/shellyem3-68C63AFB3952/emeter/2/total:.* {'2_energy_totalKWh' => sprintf("%.2f",$EVENT/1000)}
   room       Info,Zentrales
   setList    relay:on,off,toggle shellies/shellyem3-68C63AFB3952/relay/0/command $EVTPART1
off:noArg shellies/shellyem3-68C63AFB3952/relay/0/command off
on:noArg shellies/shellyem3-68C63AFB3952/relay/0/command on
x_update:noArg shellies/shellyem3-68C63AFB3952/command update_fw
x_mqttcom shellies/shellyem3-68C63AFB3952/command $EVTPART1

   sortby     1
   userReadings power:._power.* {
  my $power0 = ReadingsVal($name, '0_power', 0);
  my $power1 = ReadingsVal($name, '1_power', 0);
  my $power2 = ReadingsVal($name, '2_power', 0);

  return $power0 + $power1 + $power2;
},

current:._current.* {
  my $current0 = ReadingsVal($name, '0_current', 0);
  my $current1 = ReadingsVal($name, '1_current', 0);
  my $current2 = ReadingsVal($name, '2_current', 0);

  return $current0 + $current1 + $current2;
},

energy:._energy.* {
  my $energy0 = ReadingsVal($name, '0_energy', 0);
  my $energy1 = ReadingsVal($name, '1_energy', 0);
  my $energy2 = ReadingsVal($name, '2_energy', 0);

  return $energy0 + $energy1 + $energy2;
},

energyKWh:._energyKWh.* {
  my $energy0 = ReadingsVal($name, '0_energyKWh', 0);
  my $energy1 = ReadingsVal($name, '1_energyKWh', 0);
  my $energy2 = ReadingsVal($name, '2_energyKWh', 0);

  return $energy0 + $energy1 + $energy2;
},

energy_total:._energy_total.* {
  my $energy0 = ReadingsVal($name, '0_energy_total', 0);
  my $energy1 = ReadingsVal($name, '1_energy_total', 0);
  my $energy2 = ReadingsVal($name, '2_energy_total', 0);

  return $energy0 + $energy1 + $energy2;
},

energy_totalKWh:._energy_totalKWh.* {
  my $energy0 = ReadingsVal($name, '0_energy_totalKWh', 0);
  my $energy1 = ReadingsVal($name, '1_energy_totalKWh', 0);
  my $energy2 = ReadingsVal($name, '2_energy_totalKWh', 0);

  return $energy0 + $energy1 + $energy2;
}
   verbose    5

Dauert das Auswerten der userReadings solange?
Wenn ja, wie kann man eine solche Addition optimieren?

Danke schon mal für Hinweise...

Grüße
Reinerlein

Beta-User · 20 Juli 2020, 07:37:23

Moin.

Da an den userReadings auch noch statistics hängt und evtl. dann auch noch weitere Eventhandler die Events (einschl. der userReadings...) analysieren (FileLog, ...?), wäre es evtl. eine Überlegung, die userReadings-trigger noch etwas enger zu fassen:
Im Moment hast du bei jedem Durchgang (der Shelly sendet wenn, dann doch immer alle Werte, oder?) z.B. drei Mal eine Aktualisierung, nämlich für jeden Kanal. Eigentlich sollte es reichen, nur jeweils den letzten (z.B. 2_power) triggern zu lassen, oder? (Dann müßten m.E. auch die Zeitpunkte besser zur Auswertung passen, sonst ist beim ersten Duchlauf noch was eigentlich veraltetes für Kanal 2+3 drin?).

Btw.: Es gibt zwischenzeitlich auch ein attrTemplate für den em3, allerdings ist das (gefühlt) noch nicht ganz fertig. Vielleicht magst du das mit optimieren?

Reinerlein · 20 Juli 2020, 08:15:34

Hi Beta-User,

das mit dem letzten Readings-Trigger ist ja schwer, da man nicht sicher sagen kann, welcher nun als letzter gesendet und/oder verarbeitet wird. Deswegen muss man das, meiner Meinung nach, schon so machen. Es könnte ja auch durch den MQTT-Broker (Mosquitto) verzögert zugestellt werden, dann fehlt einer in der Menge...
Das klingt nicht nach "sicher ausgewertet"

Aber warum dauert es solange (das liegt ja teilweise schon im Sekundenbereich)?
Und die Events, die nach dieser Paket-Aktualisierung erzeugt werden (auf die dann Notify und FileLog usw. reagieren), kommen doch erst, nachdem alle userReadings berechnet wurden, oder?

Ich bin mir nicht sicher, ob ich der richtige für eine Optimierung der attrTemplates bin. Ich verwende die nur als Basis, und habe einige (teilweise erhebliche) Anpassungen, da ich eine andere Philosophie der Namensgebung für die Readings verfolge...

Grüße
Reinerlein

Reinerlein · 20 Juli 2020, 08:39:35

Hallo Beta-User,

ich habe das nochmal im Log nachgesehen: Leider kommen die Werte nicht in einer Welle zusammen an:

Code Auswählen

 2020.07.20 08:35:07.197 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/energy => {'0_energyKWh' => sprintf("%.2f",$EVENT/60/1000)}
2020.07.20 08:35:07.201 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/energy => 0_energy
2020.07.20 08:35:07.553 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/total => 0_energy_total
2020.07.20 08:35:07.555 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/total => {'0_energy_totalKWh' => sprintf("%.2f",$EVENT/1000)}
2020.07.20 08:35:07.927 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/energy => {'1_energyKWh' => sprintf("%.2f",$EVENT/60/1000)}
2020.07.20 08:35:07.931 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/energy => 1_energy
2020.07.20 08:35:08.288 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/total => 1_energy_total
2020.07.20 08:35:08.291 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/total => {'1_energy_totalKWh' => sprintf("%.2f",$EVENT/1000)}
2020.07.20 08:35:08.667 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/energy => {'2_energyKWh' => sprintf("%.2f",$EVENT/60/1000)}
2020.07.20 08:35:08.671 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/energy => 2_energy
2020.07.20 08:35:09.024 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/total => {'2_energy_totalKWh' => sprintf("%.2f",$EVENT/1000)}
2020.07.20 08:35:09.029 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/total => 2_energy_total
2020.07.20 08:35:11.338 1: Perfmon: possible freeze starting at 08:35:05, delay is 6.338
2020.07.20 08:35:25.654 1: Perfmon: possible freeze starting at 08:35:24, delay is 1.654
2020.07.20 08:35:26.281 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/power => 2_power
2020.07.20 08:35:26.622 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/pf => 2_pf
2020.07.20 08:35:26.915 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/current => 2_current
2020.07.20 08:35:27.234 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/voltage => 2_voltage
2020.07.20 08:35:27.544 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/relay/0 => state
2020.07.20 08:35:27.545 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/relay/0 => relay
2020.07.20 08:35:27.874 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/power => 0_power
2020.07.20 08:35:28.209 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/pf => 0_pf
2020.07.20 08:35:28.505 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/current => 0_current
2020.07.20 08:35:28.813 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/voltage => 0_voltage
2020.07.20 08:35:29.100 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/power => 1_power
2020.07.20 08:35:29.440 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/pf => 1_pf
2020.07.20 08:35:29.736 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/current => 1_current
2020.07.20 08:35:30.040 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/voltage => 1_voltage
2020.07.20 08:35:30.337 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/power => 2_power
2020.07.20 08:35:30.678 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/pf => 2_pf
2020.07.20 08:35:30.965 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/current => 2_current
2020.07.20 08:35:31.280 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/voltage => 2_voltage
2020.07.20 08:35:31.570 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/power => 2_power
2020.07.20 08:35:31.904 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/pf => 2_pf
2020.07.20 08:35:32.192 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/current => 2_current
2020.07.20 08:35:32.505 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/voltage => 2_voltage
2020.07.20 08:35:32.787 1: Perfmon: possible freeze starting at 08:35:28, delay is 4.787
2020.07.20 08:35:34.337 1: Perfmon: possible freeze starting at 08:35:33, delay is 1.337
2020.07.20 08:35:36.196 1: Perfmon: possible freeze starting at 08:35:35, delay is 1.195
2020.07.20 08:35:57.965 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/relay/0 => state
2020.07.20 08:35:57.966 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/relay/0 => relay
2020.07.20 08:35:58.292 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/power => 0_power
2020.07.20 08:35:58.547 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/pf => 0_pf
2020.07.20 08:35:58.764 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/current => 0_current
2020.07.20 08:35:58.994 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/voltage => 0_voltage
2020.07.20 08:35:59.203 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/power => 1_power
2020.07.20 08:35:59.416 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/pf => 1_pf
2020.07.20 08:35:59.634 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/current => 1_current
2020.07.20 08:35:59.842 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/voltage => 1_voltage
2020.07.20 08:36:00.061 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/power => 2_power
2020.07.20 08:36:00.269 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/pf => 2_pf
2020.07.20 08:36:00.479 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/current => 2_current
2020.07.20 08:36:00.698 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/voltage => 2_voltage
2020.07.20 08:36:00.954 1: Perfmon: possible freeze starting at 08:35:58, delay is 2.954
2020.07.20 08:36:03.416 1: Perfmon: possible freeze starting at 08:36:01, delay is 2.416
2020.07.20 08:36:05.352 1: Perfmon: possible freeze starting at 08:36:04, delay is 1.352
2020.07.20 08:36:27.072 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/relay/0 => state
2020.07.20 08:36:27.073 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/relay/0 => relay
2020.07.20 08:36:27.398 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/power => 0_power
2020.07.20 08:36:27.652 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/pf => 0_pf
^@2020.07.20 08:36:27.869 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/current => 0_current
2020.07.20 08:36:28.099 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/voltage => 0_voltage
2020.07.20 08:36:28.308 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/power => 1_power
2020.07.20 08:36:28.521 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/pf => 1_pf
2020.07.20 08:36:28.739 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/current => 1_current
2020.07.20 08:36:28.946 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/voltage => 1_voltage
2020.07.20 08:36:29.155 1: Perfmon: possible freeze starting at 08:36:28, delay is 1.155
2020.07.20 08:36:29.166 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/power => 2_power
2020.07.20 08:36:29.374 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/pf => 2_pf
2020.07.20 08:36:29.584 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/current => 2_current
2020.07.20 08:36:29.803 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/voltage => 2_voltage
2020.07.20 08:36:32.597 1: Perfmon: possible freeze starting at 08:36:30, delay is 2.597
2020.07.20 08:36:35.090 1: Perfmon: possible freeze starting at 08:36:34, delay is 1.09
2020.07.20 08:36:48.288 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/power => 2_power
2020.07.20 08:36:48.631 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/pf => 2_pf
2020.07.20 08:36:48.841 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/current => 2_current
2020.07.20 08:36:49.078 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/voltage => 2_voltage
2020.07.20 08:36:54.412 1: Perfmon: possible freeze starting at 08:36:53, delay is 1.412
2020.07.20 08:36:55.837 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/power => 2_power
2020.07.20 08:36:55.845 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/pf => 2_pf
2020.07.20 08:36:55.855 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/current => 2_current
2020.07.20 08:36:55.870 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/voltage => 2_voltage
2020.07.20 08:36:59.245 1: Perfmon: possible freeze starting at 08:36:57, delay is 2.245
2020.07.20 08:36:59.251 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/relay/0 => state
2020.07.20 08:36:59.252 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/relay/0 => relay
2020.07.20 08:36:59.503 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/power => 0_power
2020.07.20 08:36:59.709 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/pf => 0_pf
2020.07.20 08:36:59.926 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/current => 0_current
2020.07.20 08:37:00.138 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/voltage => 0_voltage
2020.07.20 08:37:00.347 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/power => 1_power
2020.07.20 08:37:00.560 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/pf => 1_pf
2020.07.20 08:37:00.778 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/current => 1_current
2020.07.20 08:37:00.985 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/voltage => 1_voltage
2020.07.20 08:37:01.204 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/power => 2_power
2020.07.20 08:37:01.212 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/pf => 2_pf
2020.07.20 08:37:01.222 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/current => 2_current
2020.07.20 08:37:01.237 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/voltage => 2_voltage

Da ist immer mal zwischendurch fhem an der Reihe, sodass man erkennen kann, dass die Werte in verschiedenen Events verarbeitet werden...

Grüße
Reinerlein

Beta-User · 20 Juli 2020, 09:31:12

Bei meinem Vorschlag, den Trigger für die userReadings einzuschränken, bin ich schon davon ausgegangen, dass jede eingehende Message jeweils eine eigene Event-Verarbeitungskaskade in FHEM verursacht (einschließlich Logging, dewpoint, DOIF-Aggregationen, was auch immer...).
Wie es (zumindest nach diesen hier geposteten kurzen Log-Auszügen) aussieht, arbeiten auch sowohl der Shelly wie Mosquitto (wie FEM auch) alles streng linear ab, von daher dürfte ein eventueller Fehler durch das triggern nur auf die 2-er-Readings (also die letzten versendeten bzw. übermittelten) wenn, dann eher gering ausfallen. Ich sehe also das befürchtete Problem noch nicht... (Vielleicht schaust du im Event-Monitor mal eine Zeitlang zu, was da so alles passiert?).

Ohne dafür jetzt Expertenwissen für mich beanspruchen zu wollen: die letzten geposteten Freezes paßen m.E. teilweise zeitlich nicht zu den MQTT2-Events; deutet das nicht eher darauf hin, dass irgendwas anderes da auch noch rumspukt?

Was die attrTemplate-Geschichte angeht: Das könntest du ja in einem Testsystem ausentwickeln (Readingnamen sind ja nur ein Teil des Gesamtthemas). Der bisher einzige andere User, der so einem Shelly hat, war irgendwann mit seinen Einstellungen zufrieden, die aber m.E. nicht so ganz mit der API zusammengepßat hatten. Daher ist das eben noch unfertig...
Ansonsten muß ich halt warten, bis sich wieder jemand mit so einem Teil outet

.

Reinerlein · 20 Juli 2020, 09:48:08

Hi Beta-User,

ich habe 16 Shelly-Devices im System, und dieses sind aktuell die einzigen, die über MQTT2 laufen (meine anderen MQTT-Devices laufen über das "alte" MQTT-Modul und auch einen anderen Mosquitto-Broker zur sauberen Trennung, und erzeugen keinerlei Freezes).
Alle diese MQTT2-Devices erzeugen hin und wieder diese Freezes, ich habe allerdings nur den EM3 auf verbose 5 gesetzt, um überhaupt etwas erkennen zu können.

Also, ja, da sind noch andere Devices, die Freezes erzeugen

Ich habe diese Freezes auch erst, seit ich MQTT2 verwende...

--
Was fehlt denn noch bei den attrTemplates zum EM3? Soweit ich mich erinnern kann, war eigentlich alles da, nur habe ich mir einiges umbenannt...

Grüße
Reinerlein

Beta-User · 20 Juli 2020, 10:02:39

Ich kann nicht beurteilen, ob es der 3em ist, der die Freezes erzeugt. Der em3 verursacht in jedem Fall auch einige/viele Events, jedenfalls mehr, als der mir bekannte Rest, dazu kommen eben noch die userReadings. An sich sollte das nicht so lange dauern, aber näheres - außer, dass die Event-Verarbeitung selbst mMn. optimiert werden könnte - kann ich dazu nicht sagen; evtl. könntest du auch das Freezemon-Modul austesten, das läßt dem Vernehmen nach wohl bessere Rückschlüsse zu, wo Freezes herkommen.

Betr. das template: Da waren noch ein paar Dinge offen wie die Frage, ob jetzt monotonic Sinn macht oder nicht; mein letzter Stand: https://forum.fhem.de/index.php/topic,111905.msg1063526.html#msg1063526. Leider hat der TE da meine Frage nicht so recht verstanden und auch (gefühlt) keine Infos zu dem geliefert, was das Teil eigentlich wann und warum sendet.
Irgendwie wäre für mich noch die Frage, ob man über die Einstellungen am Web-Interface z.B. auch Infos zur Gesamtenergie bekommt bzw. ob es ggf. möglich wäre, dass der Hersteller das einbaut. Macht ja uU. Sinn, den Shelly rechnen zu lassen und dann einfach nur das Ergebnis entgegenzunehmen, dann sind alle Infos tendenziell besser synchronisiert... (womit wir indirekt wieder beim Thema wären

).

Reinerlein · 20 Juli 2020, 10:57:03

Hi Beta-User,

also die userRedings sind es mal nicht. Ich habe sie einfach mal gelöscht, und auch auf freezemon umgestellt:

Code Auswählen

2020.07.20 10:53:31.937 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/relay/0 => state
2020.07.20 10:53:31.937 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/relay/0 => relay
2020.07.20 10:53:32.167 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/power => 0_power
2020.07.20 10:53:32.390 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/pf => 0_pf
2020.07.20 10:53:32.620 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/current => 0_current
2020.07.20 10:53:32.839 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/0/voltage => 0_voltage
2020.07.20 10:53:33.067 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/power => 1_power
2020.07.20 10:53:33.285 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/pf => 1_pf
2020.07.20 10:53:33.514 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/current => 1_current
2020.07.20 10:53:33.738 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/1/voltage => 1_voltage
2020.07.20 10:53:33.961 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/power => 2_power
2020.07.20 10:53:34.181 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/pf => 2_pf
2020.07.20 10:53:34.402 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/current => 2_current
2020.07.20 10:53:34.627 4: MQTT2_DEVICE_Parse: hwr_Hausstrom shellies/shellyem3-68C63AFB3952/emeter/2/voltage => 2_voltage
2020.07.20 10:53:35.022 1: [Freezemon] myFreezemon: possible freeze starting at 10:53:32, delay is 3.021 possibly caused by: no bad guy found :-(

Es scheint schon so zu sein, dass MQTT2 diese Readings sehr langsam verarbeitet. Anscheinend ist das Dispatch für jedes Readings sehr aufwändig... vielleicht könnte man da eine "Abkürzung" im Code einbauen? Ich blicke das Gesamtsystem MQTT2 dazu aber zuwenig...
Allerdings sind es wohl nicht meine Additions-userReadings...

Grüße
Reinerlein