Modul 93_DbRep - Reporting und Management von Datenbankinhalten (DbLog)

[RalfRog]

Hi
Ja schauen wir mal was DS_STARTER sagt. Ich meine mich zu erinnern, dass er auch mal was von einer Chain bei sich erzählt hat und jetzt das "Problem" beobachtet.

Danke für den Vorschlag zur Entzerrung.
Dafür sprechen könnte (noch nicht fertig abgespeichert), dass mit dem ersten Aufruf tatsächlich ja die Readings verarbeitet werden die den größten Anteil haben 700-800 den Tag.

Gruß Ralf

[RalfRog]

Mist hab mir aus irgendeinem Grund den Beitrag kaputt geschrieben 

Hier ging es um den Vorschlag den 2. Aufruf in der Chain mit Verzögerung zu starten
"define chain_delay at +00:01:00 set DBRep_avgtim_power averageValue writeToDBSingleStart"

Das ist der Rest:
Ok verstanden. Versuch macht kluch... klappt als Attribut. Du hattest den Text des Logfiles verwendet 
Habe es gerade mal durchlaufen lassen. Alle calculated Werte wieder neu erzeugt (hatte die vorher aus der DB gelöscht).
Ende Rest:

HAb ich dann gemacht. Siehe Antwort #1946  => Fazit keine Änderung

[RalfRog]

Hi das ist heute Nacht passiert - LOG  (Meldung eval: my $SELF... erstmalig am 12.3  )

Code Auswählen Erweitern


2023.03.15 03:30:00.074 3: msg globalMsg: ID=1678847400.00598.1 TYPE=push ROUTE=teleBot STATUS=OK PRIORITY=-1(Low) TITLE='' MSG='Start Mittelwerte in DB schreiben'

2023.03.15 03:30:00.274 1: PERL WARNING: Use of uninitialized value $to in subtraction (-) at ./FHEM/93_DbRep.pm line 3694.
2023.03.15 03:30:00.276 3: eval: my $SELF=   $evalSpecials->{'%SELF'};{ fhem ("msg push -1 Start Mittelwerte in DB schreiben") ; fhem ("set DBRep_avgtim_MT691_power averageValue writeToDBSingleStart") }

2023.03.15 03:30:00.282 1: PERL WARNING: Use of uninitialized value $val1 in concatenation (.) or string at ./FHEM/93_DbRep.pm line 3658.
2023.03.15 03:30:00.283 3: eval: my $SELF=   $evalSpecials->{'%SELF'};{ fhem ("msg push -1 Start Mittelwerte in DB schreiben") ; fhem ("set DBRep_avgtim_MT691_power averageValue writeToDBSingleStart") }

2023.03.15 03:30:00.571 3: DbRep DBRep_avgtim_MT691_power - number of lines updated in >DBLogging<: 0
2023.03.15 03:30:00.574 3: DbRep DBRep_avgtim_MT691_power - number of lines inserted into >DBLogging<: 10
2023.03.15 03:30:00.627 3: DbRep DBRep_avgtim_MT691_power - execute command after averageValue: 'set DBRep_avgtim_power averageValue writeToDBSingleStart'

2023.03.15 03:30:00.772 1: PERL WARNING: Use of uninitialized value $to in subtraction (-) at ./FHEM/93_DbRep.pm line 3694.
2023.03.15 03:30:00.775 3: eval: {DbRep_avervalDone('DBRep_avgtim_MT691_power||MjAyMy0wMy0xNF8wMCNpbnN1ZmZpY2llbnQgdmFsdWVzIzIwMjMtMDMtMTRfMDB8MjAyMy0wMy0xNF8wMSNpbnN1ZmZpY2llbnQgdmFsdWVzIzIwMjMtMDMtMTRfMDF8MjAyMy0wMy0$

2023.03.15 03:30:00.780 1: PERL WARNING: Use of uninitialized value $val1 in concatenation (.) or string at ./FHEM/93_DbRep.pm line 3658.
2023.03.15 03:30:00.782 3: eval: {DbRep_avervalDone('DBRep_avgtim_MT691_power||MjAyMy0wMy0xNF8wMCNpbnN1ZmZpY2llbnQgdmFsdWVzIzIwMjMtMDMtMTRfMDB8MjAyMy0wMy0xNF8wMSNpbnN1ZmZpY2llbnQgdmFsdWVzIzIwMjMtMDMtMTRfMDF8MjAyMy0wMy0$

2023.03.15 03:30:01.141 3: DbRep DBRep_avgtim_power - number of lines updated in >DBLogging<: 0
2023.03.15 03:30:01.142 3: DbRep DBRep_avgtim_power - number of lines inserted into >DBLogging<: 12
2023.03.15 03:30:01.189 3: DbRep DBRep_avgtim_power - execute command after averageValue: 'set DBRep_avgtim_total_power averageValue writeToDBSingleStart'
2023.03.15 03:30:02.004 3: DbRep DBRep_avgtim_total_power - number of lines updated in >DBLogging<: 0
2023.03.15 03:30:02.006 3: DbRep DBRep_avgtim_total_power - number of lines inserted into >DBLogging<: 24
2023.03.15 03:30:02.058 3: DbRep DBRep_avgtim_total_power - execute command after averageValue: 'set DBRep_avgtim_unit changeValue old="%" new={"($VALUE,$UNIT) = ($VALUE,"W")"}'
2023.03.15 03:30:02.388 3: DbRep DBRep_avgtim_unit - execute command after changeval: 'msg push -1 [DBRep_avgtim_total_power:state] taegliche Chain abgearbeitet fuer Mittelwerte Plug:power 3EM:total_power MT691_power'

2023.03.15 03:30:02.446 3: msg globalMsg: ID=1678847402.39299.1 TYPE=push ROUTE=teleBot STATUS=OK PRIORITY=-1(Low) TITLE='' MSG='done taegliche Chain abgearbeitet fuer Mittelwerte Plug:power 3EM:total_power MT691_power'

2023.03.15 03:30:02.468 3: DbRep DBRep_avgtim_unit - VALUE changed in "fhem" - old: "%", new: "($VALUE,$UNIT) = ($VALUE,"W")", number: 46


Die Chain wird um 3.30 Uhr per AT gestartet:
=>  "*03:30 { fhem ("msg push -1 Start Mittelwerte in DB schreiben") ; fhem ("set DBRep_avgtim_MT691_power averageValue writeToDBSingleStart") }"
       Perl-Mode, da wusste ich wie zwei fhem Kommandos hintereinander ausgeführt werden

Was mich nun wundert ist, dass in der dritten Zeile nach der Perl-Warning der eval geloggt wird. Das ist ja der Inhalt des AT (vermute mal, dass so die Kommandos von Modul zu Modul weitergegeben werden um sie per eval auszuführen).
Aber da sind wir doch noch gar nicht beim berechnen und schreiben in die Datenbank, was dann noch nicht fertig sein könne. Hmmmm....

[alkazaa]

Jetzt bin ich auch verwirrt über die zeitliche Reihenfolge der log-Meldungen.

Was mit aber auffiel: in beiden von Dir genannten Fällen (in Beitrag #1926 und #1937) tauchen diese drei Log-Meldungen auf:

Code Auswählen Erweitern


2023.03.09 03:30:00.583 3: DbRep DBRep_avgtim_MT691_power - number of lines inserted into >DBLogging<: 15
2023.03.09 03:30:01.215 3: DbRep DBRep_avgtim_power - number of lines inserted into >DBLogging<: 9
2023.03.09 03:30:01.997 3: DbRep DBRep_avgtim_total_power - number of lines inserted into >DBLogging<: 24 (Beitrag #1926)

Code Auswählen Erweitern


2023.03.15 03:30:00.574 3: DbRep DBRep_avgtim_MT691_power - number of lines inserted into >DBLogging<: 10
2023.03.15 03:30:01.142 3: DbRep DBRep_avgtim_power - number of lines inserted into >DBLogging<: 12
2023.03.15 03:30:02.006 3: DbRep DBRep_avgtim_total_power - number of lines inserted into >DBLogging<: 24 (Beitrag #1937)

Also wurde jedesmal für die readings MT691_power, power und total_power etwas in die Datenbank zurückgeschrieben. Aber nur beim letzten reading (total_power) waren es 24 Werte, wie man beim stundenweise Mitteln erwarten würde. Irgendwas hat die beiden ersten Läufe also abgewürgt.

Teste doch mal, was sich beim händischen Mitteln der einzelnen readings jeweils ergibt. Ob die auch abwürgen, oder sauber durchlaufen.

EDIT:
Alles ist gut...
... außer das ich mich geirrt habe mit der Aussage, dass ein fehlender Datensatz im 'peek-back' Zeitraum allein nicht die perl-warning auslöst, sondern die Warnung nur kommt, wenn überhaupt keine Daten vorliegen.       

In Wirklichkeit löst die Kombination "keine Daten im peek-back intervall UND keine Daten in der ersten Periode" die Warnung aus. Im Ergebnis spielt es aber keine Rolle, weil dann sowieso keine Daten für die erste Mittelungsperiode geliefert werden.

Ich schau mal, wie man diese Warning am besten unterdrückt (bzw. so verhindert, dass nichts falsches berechnet wird)

[RalfRog]

...
Also wurde jedesmal für die readings MT691_power, power und total_power etwas in die Datenbank zurückgeschrieben. Aber nur beim letzten reading (total_power) waren es 24 Werte, wie man beim stundenweise Mitteln erwarten würde. Irgendwas hat die beiden ersten Läufe also abgewürgt.
...

Nur kurz der Vollständigkeit halber. Lediglich das Reading  total_power hat Daten von 24 Stunden. Die beiden andern nur während Sonnenschein oder der Nacht. Daher passen 10 oder 12 Werte schon 

[alkazaa]

Ja, hab's gesehen, siehe das EDIT meines vorigen Beitrags...
Sorry für das Hin und Her

Gruß
Franz

[alkazaa]

OK, hier die beiden Änderungen in 93_DbRep.pm, mit denen die perl-warnings verhindert werden:

Code Auswählen Erweitern

Zeile 3657      if ($bin_end) {    wird zu                                     

Code Auswählen Erweitern

Zeile 3657      if ($bin_end && $val1) {     

und     

Code Auswählen Erweitern

Zeile 3694      $dt    = timelocal($secf, $minf, $hhf, $ddf, $mmf-1, $yyyyf-1900) - $to;                   
Zeile 3695         wird zu   

Code Auswählen Erweitern

Zeile 3694      $dt    = timelocal($secf, $minf, $hhf, $ddf, $mmf-1, $yyyyf-1900);                   
Zeile 3695      $dt   -= $to if ($to);        

Vielleicht kann Heiko [DS_Starter] das bei nächster Gelegenheit übernehmen?                 

Beste Grüße
Franz                     

[DS_Starter]

Mach ich ... bin noch bisschen mit meiner PV Battrie befasst 
Melde mich ...

Danke für die Analyse !

Heiko

[RalfRog]

Bin unterwegs,
kann es morgen nachmittag probieren.

Gruß Ralf

[alkazaa]

Was ich mich jetzt noch frage: Wo kommen bei Dir die "eval: "-Meldungen her? Die hatte ich nie, selbst mit verbose=5 nicht.

[RalfRog]

Ja ich frage ich mich auch...

Dachte irgenwie (wg. fast gleichem Zeitstempel), dass das mit der PERL-Warning davor zusammenhängt, da ja der Text der Meldung mit dem was davor war im Zusammenhang steht:
"eval: my $SELF=   $evalSpecials->{'%SELF'};{ fhem ("msg push -1 Start Mittelwerte in DB schreiben") ; fhem ("set DBRep_avgtim_MT691_power averageValue
writeToDBSingleStart") }"

Wo wird im DBRep die eval Funktion aufgefufen? Die $evalSpecials stecken doch in der fhem.pl. I'm lost 

[RalfRog]

Ok verstanden. Versuch macht kluch... klappt als Attribut. Du hattest den Text des Logfiles verwendet 
Habe es gerade mal durchlaufen lassen. Alle calculated Werte wieder neu erzeugt (hatte die vorher aus der DB gelöscht).

Hatte mich zu dem Versuch mit der Verzögerung nicht geäußert.
Problem blieb bestehen:

Code Auswählen Erweitern


2023.03.15 14:55:14.286 3: msg globalMsg: ID=1678888514.24051.1 TYPE=push ROUTE=teleBot STATUS=OK PRIORITY=-1(Low) TITLE='' MSG='Start Mittelwerte in DB schreiben'

2023.03.15 14:55:14.619 1: PERL WARNING: Use of uninitialized value $to in subtraction (-) at ./FHEM/93_DbRep.pm line 3694.
2023.03.15 14:55:14.621 3: eval: my $SELF=   $evalSpecials->{'%SELF'};{ fhem ("msg push -1 Start Mittelwerte in DB schreiben") ; fhem ("set DBRep_avgtim_MT691_power averageValue writeToDBSingleStart") }

2023.03.15 14:55:14.627 1: PERL WARNING: Use of uninitialized value $val1 in concatenation (.) or string at ./FHEM/93_DbRep.pm line 3658.
2023.03.15 14:55:14.628 3: eval: my $SELF=   $evalSpecials->{'%SELF'};{ fhem ("msg push -1 Start Mittelwerte in DB schreiben") ; fhem ("set DBRep_avgtim_MT691_power averageValue writeToDBSingleStart") }

2023.03.15 14:55:14.908 3: DbRep DBRep_avgtim_MT691_power - number of lines updated in >DBLogging<: 0
2023.03.15 14:55:14.910 3: DbRep DBRep_avgtim_MT691_power - number of lines inserted into >DBLogging<: 10
==> mit delay aufgerufen
2023.03.15 14:55:15.085 3: DbRep DBRep_avgtim_MT691_power - execute command after averageValue: 'define chain_delay at +00:01:00 set DBRep_avgtim_power averageValue writeToDBSingleStart'

2023.03.15 14:56:15.256 1: PERL WARNING: Use of uninitialized value $to in subtraction (-) at ./FHEM/93_DbRep.pm line 3694.
2023.03.15 14:56:15.264 1: PERL WARNING: Use of uninitialized value $val1 in concatenation (.) or string at ./FHEM/93_DbRep.pm line 3658.

2023.03.15 14:56:15.629 3: DbRep DBRep_avgtim_power - number of lines updated in >DBLogging<: 0
2023.03.15 14:56:15.631 3: DbRep DBRep_avgtim_power - number of lines inserted into >DBLogging<: 12
2023.03.15 14:56:15.682 3: DbRep DBRep_avgtim_power - execute command after averageValue: 'set DBRep_avgtim_total_power averageValue writeToDBSingleStart'
==> hier die Warteminute
2023.03.15 14:56:16.466 3: DbRep DBRep_avgtim_total_power - number of lines updated in >DBLogging<: 0
2023.03.15 14:56:16.468 3: DbRep DBRep_avgtim_total_power - number of lines inserted into >DBLogging<: 24
.... rest schenk ich mir


heute Nacht dann analog dazu:

Code Auswählen Erweitern


2023.03.16 03:30:00.070 3: msg globalMsg: ID=1678933800.00793.1 TYPE=push ROUTE=teleBot STATUS=OK PRIORITY=-1(Low) TITLE='' MSG='Start Mittelwerte in DB schreiben'
2023.03.16 03:30:00.252 1: PERL WARNING: Use of uninitialized value $to in subtraction (-) at ./FHEM/93_DbRep.pm line 3694.
2023.03.16 03:30:00.254 3: eval: my $SELF=   $evalSpecials->{'%SELF'};{ fhem ("msg push -1 Start Mittelwerte in DB schreiben") ; fhem ("set DBRep_avgtim_MT691_power averageValue writeToDBSingleStart") }
2023.03.16 03:30:00.261 1: PERL WARNING: Use of uninitialized value $val1 in concatenation (.) or string at ./FHEM/93_DbRep.pm line 3658.
2023.03.16 03:30:00.262 3: eval: my $SELF=   $evalSpecials->{'%SELF'};{ fhem ("msg push -1 Start Mittelwerte in DB schreiben") ; fhem ("set DBRep_avgtim_MT691_power averageValue writeToDBSingleStart") }
2023.03.16 03:30:00.539 3: DbRep DBRep_avgtim_MT691_power - number of lines updated in >DBLogging<: 0
2023.03.16 03:30:00.539 3: DbRep DBRep_avgtim_MT691_power - number of lines inserted into >DBLogging<: 7
2023.03.16 03:30:00.582 3: DbRep DBRep_avgtim_MT691_power - execute command after averageValue: 'define chain_delay at +00:01:00 set DBRep_avgtim_power averageValue writeToDBSingleStart'
2023.03.16 03:31:00.724 1: PERL WARNING: Use of uninitialized value $to in subtraction (-) at ./FHEM/93_DbRep.pm line 3694.
2023.03.16 03:31:00.731 1: PERL WARNING: Use of uninitialized value $val1 in concatenation (.) or string at ./FHEM/93_DbRep.pm line 3658.
2023.03.16 03:31:01.144 3: DbRep DBRep_avgtim_power - number of lines updated in >DBLogging<: 0
.... rest schenk ich mir



so jetzt geh ich die Codeänderung an

[RalfRog]

Sooo
1) Codeänderung
2) reload 93_DbRep.pm

Chain wird abgearbeitet (immer noch mit Pause zwischen 1. und 2. Schritt, ohne Pause 3. Schritt)

Code Auswählen Erweitern


2023.03.16 13:22:25.550 3: msg globalMsg: ID=1678969345.50395.1 TYPE=push ROUTE=teleBot STATUS=OK PRIORITY=-1(Low) TITLE='' MSG='Start Mittelwerte in DB schreiben'
2023.03.16 13:22:26.164 3: DbRep DBRep_avgtim_MT691_power - number of lines updated in >DBLogging<: 0
2023.03.16 13:22:26.167 3: DbRep DBRep_avgtim_MT691_power - number of lines inserted into >DBLogging<: 7
2023.03.16 13:22:26.357 3: DbRep DBRep_avgtim_MT691_power - execute command after averageValue: 'define chain_delay at +00:01:00 set DBRep_avgtim_power averageValue writeToDBSingleStart'
2023.03.16 13:23:26.905 3: DbRep DBRep_avgtim_power - number of lines updated in >DBLogging<: 0
2023.03.16 13:23:26.907 3: DbRep DBRep_avgtim_power - number of lines inserted into >DBLogging<: 15
2023.03.16 13:23:26.961 3: DbRep DBRep_avgtim_power - execute command after averageValue: 'set DBRep_avgtim_total_power averageValue writeToDBSingleStart'
2023.03.16 13:23:27.727 3: DbRep DBRep_avgtim_total_power - number of lines updated in >DBLogging<: 0
2023.03.16 13:23:27.729 3: DbRep DBRep_avgtim_total_power - number of lines inserted into >DBLogging<: 24
2023.03.16 13:23:27.786 3: DbRep DBRep_avgtim_total_power - execute command after averageValue: 'set DBRep_avgtim_unit changeValue old="%" new={"($VALUE,$UNIT) = ($VALUE,"W")"}'
2023.03.16 13:23:28.120 3: DbRep DBRep_avgtim_unit - execute command after changeval: 'msg push -1 [DBRep_avgtim_total_power:state] taegliche Chain abgearbeitet fuer Mittelwerte Plug:power 3EM:total_power MT691_power'
2023.03.16 13:23:28.177 3: msg globalMsg: ID=1678969408.12622.1 TYPE=push ROUTE=teleBot STATUS=OK PRIORITY=-1(Low) TITLE='' MSG='done taegliche Chain abgearbeitet fuer Mittelwerte Plug:power 3EM:total_power MT691_power'
2023.03.16 13:23:28.197 3: DbRep DBRep_avgtim_unit - VALUE changed in "fhem" - old: "%", new: "($VALUE,$UNIT) = ($VALUE,"W")", number: 46


Sieht auf den ersten Blick gut aus und alle 46 gelöschten Werte wieder neu geschrieben 
Die Pause bzw. keine Pause scheint nicht der Knackpunkt zu sein.

Bleibt die Frage warum bei PERL Warning auch die Einträge mit eval?

Edit: Inhalt EventMonitor angehängt (Events Db.* und LOG)

[RalfRog]

Mit der Änderung der drei Zeilen code auch weiterhin diese Nacht (um 3:30 Uhr) keine Warnings zu "uninitialized value" mehr.

Gruß Ralf

[DS_Starter]

Moin,

habe die Änderungen übernommen und eingecheckt. Wird somit morgen früh im Update verteilt.

LG