93_DbLog - Überlegungen zur Optimierung (RPI und andere Systeme)

DS_Starter · 13 Oktober 2019, 22:52:58

Hallo Bernd,

ich glaube noch etwas bereinigt zu haben. Bitte nochmal aus dem contrib laden.
Die verbose5 logs helfen mir. Es reicht wenn du die dann wieder mit anhängst und eine Ausgabe von "preprocessed input"

Grüße,
Heiko

Nighthawk · 14 Oktober 2019, 14:07:34

Hallo Heiko,

kannst Du mir sagen welchen Zeitraum delta-d zur Berechnung verwendet?
Scheinbar ist es in meinem Fall nicht 00:00 bis 23:59:59, kann man es ändern und wenn ja wie.

Danke und Gruß
Alex

DS_Starter · 14 Oktober 2019, 18:12:20

Hallo Alex,

welche Zeiträume abgefragt werden siehst du mit einem verbose 4 oder 5:

Zitat
2019.10.14 17:53:59.333 4: DbLog LogDB1 -> ################################################################
2019.10.14 17:53:59.334 4: DbLog LogDB1 -> ### new get data for SVG ###
2019.10.14 17:53:59.335 4: DbLog LogDB1 -> ################################################################
2019.10.14 17:53:59.335 4: DbLog LogDB1 -> main PID: 17712, secondary PID: 29766
2019.10.14 17:53:59.337 1: LogDB1 - Init Maxval: -9223372036854775807 , Init Minval: 9223372036854775807
2019.10.14 17:53:59.337 4: DbLog LogDB1 -> deltacalc: day
2019.10.14 17:53:59.338 4: LogDB1 - Processing Statement:
SELECT Z.TIMESTAMP, Z.DEVICE, Z.READING, Z.VALUE from (SELECT DATE_FORMAT(TIMESTAMP, '%Y-%m-%d %H:%i:%s') AS TIMESTAMP,
DEVICE AS DEVICE,
READING AS READING,
VALUE AS VALUE FROM fhemtest1.history WHERE 1=1 AND DEVICE = 'KS300' AND READING = 'data' AND TIMESTAMP < STR_TO_DATE('2019-10-10 00:00:00', '%Y-%m-%d %H:%i:%s') AND TIMESTAMP > DATE_SUB(STR_TO_DATE('2019-10-10 00:00:00', '%Y-%m-%d %H:%i:%s'),INTERVAL 1 DAY) ORDER BY TIMESTAMP) AS Z
UNION ALL SELECT
MAX(DATE_FORMAT(TIMESTAMP, '%Y-%m-%d %H:%i:%s')) AS TIMESTAMP,
MAX(DEVICE) AS DEVICE,
MAX(READING) AS READING,
MAX(VALUE)
FROM fhemtest1.history WHERE 1=1 AND DEVICE = 'KS300' AND READING = 'data' AND TIMESTAMP >= STR_TO_DATE('2019-10-10 00:00:00', '%Y-%m-%d %H:%i:%s') AND TIMESTAMP <= STR_TO_DATE('2019-10-11 00:00:00', '%Y-%m-%d %H:%i:%s') GROUP BY DATE_FORMAT(TIMESTAMP, '%Y-%m-%d %H') ORDER BY TIMESTAMP

Wobei der Zusatz "INTERVAL 1 DAY" wichtig ist der die DB veranlasst einen Tag vorher auszuwerten, in dem Beispiel dann real > 2019-10-09 00:00:00 und < 2019-10-10 00:00:00.
Beeinflussen kannst du es selbst eigentlich nur indirekt über Parameter des SVG (Zeitgrenzen), wobei ich auch erst nachschauen müsste was SVG an der Stelle alles bietet. Aber als ich jetzt über deinen Einwand nachdachte, bin ich noch darauf gekommen dass das neue SQL delta-h und delta-d unterschiedlich bezüglich "Limit" behandeln müsste.

Ich habe die Testversion abgeändert und wieder ins contrib zum Download bereitgestellt.
Eine erweiterte Logausgabe ist auch dabei (DbLog LogDB1 -> deltacalc: day), damit man gleich sieht für welche delta-Ermittlung das folgende Statement und dessen Ergebnisse gilt.

Grüße,
Heiko

frober · 14 Oktober 2019, 18:47:31

Hallo Heiko,

jetzt sieht es gut aus

Zitat2019-10-10_01:30:00 0
2019-10-10_02:30:00 0.7
2019-10-10_03:30:00 0.3
2019-10-10_04:30:00 0
2019-10-10_05:30:00 0
2019-10-10_06:30:00 1.3
2019-10-10_07:30:00 0.5
2019-10-10_08:30:00 0.2
2019-10-10_09:30:00 0.3
2019-10-10_10:30:00 0
2019-10-10_11:30:00 0
2019-10-10_12:30:00 0
2019-10-10_13:30:00 0
2019-10-10_14:30:00 0.2
2019-10-10_15:30:00 0
2019-10-10_16:30:00 0
2019-10-10_17:30:00 1.8
2019-10-10_18:30:00 0
2019-10-10_19:30:00 0
2019-10-10_20:30:00 0
2019-10-10_21:30:00 0
2019-10-10_22:30:00 0
2019-10-10_23:30:00 0
#KS300:data::delta-h:$val=~s/.*\sR..([\d.]*).*/$1/eg
2019-10-10_12:00:00 5.3
#KS300:data::delta-d:$val=~s/.*\sR..([\d.]*).*/$1/eg

heute habe ich eine kleine Abweichung, würde mich jedoch nicht stören (Daten sind gekürzt):

Zitat2019-10-14_05:30:00 0
2019-10-14_06:30:00 0
2019-10-14_07:30:00 0
2019-10-14_08:30:00 0.3
2019-10-14_09:30:00 0
2019-10-14_10:30:00 0
#KS300:data::delta-h:$val=~s/.*\sR..([\d.]*).*/$1/eg
2019-10-14_12:00:00 0.3
#KS300:data::delta-d:$val=~s/.*\sR..([\d.]*).*/$1/eg
2019-10-14_06:36:50 -2
2019-10-14_06:49:33 -2
2019-10-14_06:52:05 -2
2019-10-14_07:09:53 -2
2019-10-14_07:12:25 1
2019-10-14_07:14:58 -2
2019-10-14_07:40:23 -2
2019-10-14_08:05:48 -2
2019-10-14_08:13:25 -2
2019-10-14_08:59:10 -2
#KS300:data:::$val=~s/.*IR..(yes|no)(\d*).*/$1eq"yes"?1:-2/eg

Logs und Bilder im Anhang.

Gruß Bernd

DS_Starter · 14 Oktober 2019, 18:53:25

Hi Bernd,

... hast du die Version benutzt, die ich gerade hochgeladen hatte ? EDIT: ja, habs gesehen, die logs sind ja dabei

Wegen deinen kleinen (roten) Abweichungen können wir auch nochmal schauen. Da müssen wir die verbose 5 SQL Ergebnisse genauer ansehen. Aber ich vermute dass hier tatsächlich Werte aus der DB kommen die das verursachen. Damit wäre ich dann auch zufrieden

DS_Starter · 14 Oktober 2019, 18:59:30

zwichen 7:30 und 8:30 hast du tatsächlich ein Diff in der DB:

Zitat
2019.10.14 18:41:06 5: logdb - SQL-result -> TS: 2019-10-14 08:59:10, DEV: KS300, RD: data, VAL: T: 11.5 H: 92 W: 0.0 R: 1733.5 IR: no Wi: 0
2019.10.14 18:41:06 1: logdb - SQL-result -> TS: 2019-10-14 08:59:10, DEV: KS300, RD: data, VAL: T: 11.5 H: 92 W: 0.0 R: 1733.5 IR: no Wi: 0
2019.10.14 18:41:06 1: logdb - delta-h - TS result: 2019-10-14 07:30:00 , Maxval result: 1733.2 , Minval result: 1733.2 , WRITEOUT: 1
2019.10.14 18:41:06 5: logdb - Output delta-h -> TS: 08, LASTTS: 07, OUTTS: 2019-10-14 07:30:00, OUTVAL: 0
2019.10.14 18:41:06 5: logdb - SQL-result -> TS: 2019-10-14 09:50:01, DEV: KS300, RD: data, VAL: T: 13.0 H: 92 W: 0.0 R: 1733.5 IR: no Wi: 0
2019.10.14 18:41:06 1: logdb - SQL-result -> TS: 2019-10-14 09:50:01, DEV: KS300, RD: data, VAL: T: 13.0 H: 92 W: 0.0 R: 1733.5 IR: no Wi: 0
2019.10.14 18:41:06 1: logdb - delta-h - TS result: 2019-10-14 08:30:00 , Maxval result: 1733.5 , Minval result: 1733.5 , WRITEOUT: 1
2019.10.14 18:41:06 5: logdb - Output delta-h -> TS: 09, LASTTS: 08, OUTTS: 2019-10-14 08:30:00, OUTVAL: 0.3

Das ist beruhigend

frober · 14 Oktober 2019, 19:12:01

Ok Heiko,

nochmals danke.
Die KS300 ist beim Senden nicht so zuverlässig, kann sein das es daher kommt.

Ich bin auch zufrieden.

Schönen Abend noch.

Bernd

DS_Starter · 14 Oktober 2019, 19:16:00

Dir auch Bernd.
Ich werde die Routine jetzt bereinigen und wieder "schön" machen. Wenn ich damit fertig bin, stelle ich die Version wieder ins contrib mit der Bitte um Test. Alex wird sich sicher auch noch melden und hoffentlich ebenfalls ein positives Ergebnis verkünden.

LG,
Heiko

DS_Starter · 14 Oktober 2019, 20:11:44

Die bereinigte Version liegt im contrib.
Bitte teste(t) diese bitte.
Mit verbose 5 sollte nun ebenfalls recht gut nachvollziehbar werden, was aus der DB selektiert wurde und was an SVG zurück geliefert wird.

LG,
Heiko

frober · 14 Oktober 2019, 20:49:52

Passt, super.

Produktiv, wie auch Test mit SQLite....Daumen hoch.

Grüsse, Bernd

DS_Starter · 14 Oktober 2019, 21:21:35

Habe die Version jetzt noch auf meiner Postgre mit deinen Daten getestet ... läuft auch.

Nighthawk · 15 Oktober 2019, 08:49:29

Hallo Heiko,

leider besteht mein Problem weiterhin.

Zum Hintergrund des Problems:
Ich habe am 01.10 einen neuen Stromzähler bekommen, dieser startete natürlich wieder bei 1KW/h und natürlich wurde der Wechsel mitten am Tag durchgeführt.
Nun dachte ich "bist du mal ein Fuchs und bearbeitest die Daten in der DB".
Die neuen Daten habe ich für den 01.10 gelöscht und den Betrag auf den alten Wert aufaddiert, das Ergebniss habe ich dann um 23:50:59 und 23:59:59 in die DB eingetragen.
Ab dem 02.10 lief dann der neue Wert weiter.
Leider bekomme ich in den SVGs mit delta-d aber für den 2.10 einen Wert von -26643.7 (das ist das Ergebniss vom Wert von 01.10 23:59:59 "26657.9631736" minus 02.10 23:59:56 "14.2591381").
Bei einer Betrachtung von 00:00:00 bis 23:59:59 sollte dies so nicht vorkommen, oder übersehe ich da etwas?

Logfile und Auszug der DB hänge ich an.

Gruß
Alex

JoeALLb · 15 Oktober 2019, 09:12:46

Zitat von: Nighthawk am 15 Oktober 2019, 08:49:29
Bei einer Betrachtung von 00:00:00 bis 23:59:59 sollte dies so nicht vorkommen, oder übersehe ich da etwas?

Logfile und Auszug der DB hänge ich an.

Gruß
Alex

Der Tag geht von 00:00:00 bis 00:00:00... ansonsten würde ja die letzte Sekunde gar nicht gewertet werden.
die kleinste einheit von "00:00:00:00.......unendlich" gehört beiden Tagen und ist atomar, also zuerst tag 1, dann tag2.
Du kannst natürlich am nächsten Tag direkt um 00:00:01 direkt den neuen Zählerwert mit setzen, wenn er wirklich mit 0 begonnen hat.
Die "Datenbanktechnisch" optimale Lösung wäre hier (vermutlich), den Wert über ein "monotonic user reading) permanent ansteigend zu machen.
Dann hast Du auch kein Problem mit dem Wechsel "mitte am Tag". Du muss dann eigentlich gar nichts machen!

sG
Joe

DS_Starter · 15 Oktober 2019, 09:58:59

Moin Alex und Joe,

abgesehen von dem Hinweis von Joe sehe ich in dem Ergebnis keinen Widerspruch. Es doch tatsächlich die Differenz des Vortageswertes (26657.9631736) zum Wert am 02.10. (14.2591381) in Höhe von rund -26643.7 vorhanden.

Welchen Wert hättest du denn jetzt erwartet ?

BTW ... würde man ein diffValue im DbRep über diese Werte laufen lassen, würde dieser "Zählerwechsel" ignoriert werden. D.h. die negative Flanke würde ausgeblendet. Vgl. auch das Attr "diffAccept" im DbRep. Für eine SVG Erstellung könnte man mit DbRep die Differenzen unter einem neuen Reading-Namen in die DB zurückschreiben lassen und per SVG anzeigen. Weiß aber nicht ob sich der Aufwnd lohnt.

LG,
Heiko

JoeALLb · 15 Oktober 2019, 10:13:08

Zitat von: DS_Starter am 15 Oktober 2019, 09:58:59
Weiß aber nicht ob sich der Aufwnd lohnt.

Darum würde ich in diesem Fall eben eher zum Userreading mit Monotonic raten.
Auszug aus der Hilfe:

Code Auswählen


    monotonic: wenn die Differenz zw. dem aktuellen und dem vorherigen Wert positiv ist wird diese Differenz zum Reading addiert.
Damit lässt sich von einem Zähler der bei Stromverlust zurückgesetzt wird ein monoton wachsender Zähler ableiten.

Beispiel:

    attr myPowerMeter userReadings power differential { ReadingsVal("myPowerMeter","counters.A",0)/1250.0}