"Warn" Logeinträge InfluxDB-Adapter

mango1402

anbei noch das logging für die 24h-Abfrage meiner 2 Kurven:

2023-03-09 09:17:05.552 - debug: influxdb.1 (461) PING OK
2023-03-09 09:17:08.856 - debug: influxdb.1 (461) Incoming message getHistory from system.adapter.admin.0
2023-03-09 09:17:08.856 - debug: influxdb.1 (461) 0_userdata.0.Zaehler.SmartMeter.Zaehlerstand16783498288560.08961875976288836 getHistory message: {"id":"0_userdata.0.Zaehler.SmartMeter.Zaehlerstand","options":{"start":1678263440688,"end":1678349840688,"aggregate":"minmax","from":false,"ack":false,"q":false,"addID":false,"count":300,"instance":"system.adapter.influxdb.1","sessionId":155,"user":"system.user.admin"}}
2023-03-09 09:17:08.857 - debug: influxdb.1 (461) Query to execute:
from(bucket: "iobrokerV2")
|> range(start: 2023-03-08T08:17:20.688Z, stop: 2023-03-09T08:17:20.688Z)
|> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.Zaehlerstand" and contains(value: r._value, set: [true, false]))
|> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value")
|> group()
2023-03-09 09:17:08.947 - debug: influxdb.1 (461) Query to execute: from(bucket: "iobrokerV2")
|> range(start: 2022-03-08T08:17:20.688Z, stop: 2023-03-08T08:17:20.687Z)
|> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.Zaehlerstand")
|> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value")
|> group()
|> sort(columns: ["_time"], desc: true)
|> limit(n: 1)
2023-03-09 09:17:14.910 - debug: influxdb.1 (461) Query to execute: from(bucket: "iobrokerV2") |> range(start: 2023-03-08T08:17:20.688Z, stop: 2023-03-09T08:17:20.688Z) |> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.Zaehlerstand") |> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value") |> sort(columns:["_time"], desc: false)
2023-03-09 09:17:15.024 - debug: influxdb.1 (461) Query to execute: from(bucket: "iobrokerV2")
|> range(start: 2023-03-09T08:17:20.689Z)
|> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.Zaehlerstand")
|> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value")
|> group()
|> sort(columns: ["_time"], desc: false)
|> limit(n: 1)
2023-03-09 09:17:15.098 - debug: influxdb.1 (461) Send: 600 of: 7632 in: 6242ms
2023-03-09 09:17:15.238 - debug: influxdb.1 (461) Incoming message getHistory from system.adapter.admin.0
2023-03-09 09:17:15.238 - debug: influxdb.1 (461) 0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung16783498352380.47825413161981967 getHistory message: {"id":"0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung","options":{"start":1678263440688,"end":1678349840688,"aggregate":"minmax","from":false,"ack":false,"q":false,"addID":false,"count":300,"instance":"system.adapter.influxdb.1","sessionId":155,"user":"system.user.admin"}}
2023-03-09 09:17:15.240 - debug: influxdb.1 (461) Query to execute:
from(bucket: "iobrokerV2")
|> range(start: 2023-03-08T08:17:20.688Z, stop: 2023-03-09T08:17:20.688Z)
|> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung" and contains(value: r._value, set: [true, false]))
|> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value")
|> group()
2023-03-09 09:17:15.328 - debug: influxdb.1 (461) Query to execute: from(bucket: "iobrokerV2")
|> range(start: 2022-03-08T08:17:20.688Z, stop: 2023-03-08T08:17:20.687Z)
|> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung")
|> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value")
|> group()
|> sort(columns: ["_time"], desc: true)
|> limit(n: 1)
2023-03-09 09:17:20.502 - debug: influxdb.1 (461) Query to execute: from(bucket: "iobrokerV2") |> range(start: 2023-03-08T08:17:20.688Z, stop: 2023-03-09T08:17:20.688Z) |> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung") |> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value") |> sort(columns:["_time"], desc: false)
2023-03-09 09:17:20.552 - debug: influxdb.1 (461) PING OK
2023-03-09 09:17:20.592 - debug: influxdb.1 (461) Query to execute: from(bucket: "iobrokerV2")
|> range(start: 2023-03-09T08:17:20.689Z)
|> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung")
|> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value")
|> group()
|> sort(columns: ["_time"], desc: false)
|> limit(n: 1)
2023-03-09 09:17:20.644 - debug: influxdb.1 (461) Send: 1130 of: 7295 in: 5406ms
2023-03-09 09:17:35.553 - debug: influxdb.1 (461) PING OK

nicht verwirren lassen: Instanz '1' vom influxdb-Adapter ist auf die Influx-V2-db verbunden.

Warum werden eingentlich pro measurement 4 Querys abgeschickt?

im Vergleich dazu die selben 2 measurements mit den komplett selben Parametern, jedoch aus Influx-V1:

2023-03-09 09:28:06.403 - debug: influxdb.0 (391) Incoming message getHistory from system.adapter.admin.0
2023-03-09 09:28:06.403 - debug: influxdb.0 (391) 0_userdata.0.Zaehler.SmartMeter.Zaehlerstand16783504864030.7789047989952527 getHistory message: {"id":"0_userdata.0.Zaehler.SmartMeter.Zaehlerstand","options":{"start":1678264098244,"end":1678350498244,"aggregate":"minmax","from":false,"ack":false,"q":false,"addID":false,"count":300,"instance":"system.adapter.influxdb.0","sessionId":156,"user":"system.user.admin"}}
2023-03-09 09:28:06.404 - debug: influxdb.0 (391) Query to execute: SELECT value from "0_userdata.0.Zaehler.SmartMeter.Zaehlerstand" WHERE time <= '2023-03-08T08:28:18.244Z' ORDER BY time DESC LIMIT 1;SELECT * from "0_userdata.0.Zaehler.SmartMeter.Zaehlerstand" WHERE time > '2023-03-08T08:28:18.244Z' AND time < '2023-03-09T08:28:18.244Z' ORDER BY time ASC;SELECT value from "0_userdata.0.Zaehler.SmartMeter.Zaehlerstand" WHERE time >= '2023-03-09T08:28:18.244Z' LIMIT 1
2023-03-09 09:28:06.484 - debug: influxdb.0 (391) Send: 602 of: 7669 in: 81ms
2023-03-09 09:28:06.935 - debug: influxdb.0 (391) Incoming message getHistory from system.adapter.admin.0
2023-03-09 09:28:06.936 - debug: influxdb.0 (391) 0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung16783504869360.16072003977466132 getHistory message: {"id":"0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung","options":{"start":1678264098244,"end":1678350498244,"aggregate":"minmax","from":false,"ack":false,"q":false,"addID":false,"count":300,"instance":"system.adapter.influxdb.0","sessionId":156,"user":"system.user.admin"}}
2023-03-09 09:28:06.937 - debug: influxdb.0 (391) Query to execute: SELECT value from "0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung" WHERE time <= '2023-03-08T08:28:18.244Z' ORDER BY time DESC LIMIT 1;SELECT * from "0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung" WHERE time > '2023-03-08T08:28:18.244Z' AND time < '2023-03-09T08:28:18.244Z' ORDER BY time ASC;SELECT value from "0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung" WHERE time >= '2023-03-09T08:28:18.244Z' LIMIT 1
2023-03-09 09:28:07.003 - debug: influxdb.0 (391) Send: 1122 of: 7328 in: 67ms

apollon77

Am Ende macht der Adapter bei InfluxDB 1 das gleiche.

4 Queries weil:
1.) Spezieller check wegen Datentypenkram um zu sehen was für Daten drin stehen weil boolean und Zahlen anders selektiert erden müssen
2.) Ein Wert VOR dem eigentlichen Zeitraum
3.) Der Zeitraum
4.) Ein Wert NACH dem eigentlichen Zeitraum

2 und 4 sind dazu da das wir für die Grafische Darstellung im zweifel den Wert vor als ersten Wert zum Zeitraumstart einfügen können und am Ende einen ans Ende. Sonst würde der Chart irgendwann erst nach dem startdatum einen ersten Wert haben und vor dem Ende enden (oder den ersten /letzten Wert fälschlicherweise als "der galt auf davor/danach" annehmen und damit verfälschen.

Wer weiss und rausfindet wie man diese Queries mit fluxQL optimieren kann gern Zeit investieren - genau dafür haben ich aktuell eher keine Zeit und dazu muss man kein Entwickler sein.

Nehmt die Query aus dem Log prüft was rauskommt und schaut ob es bessere/performantere Queries gibt die das gleiche Ergebnis liefern.

mango1402

@apollon77
So, dies ist der Übeltäter:

from(bucket: "iobrokerV2")
|> range(start: 2022-03-08T08:17:20.688Z, stop: 2023-03-08T08:17:20.687Z)
|> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung")
|> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value")
|> group()
|> sort(columns: ["_time"], desc: true)
|> limit(n: 1)

benötigt im Influx-Frontend 5,24s. Ein bisserl lang für genau einen Wert.... (OK, durchsucht ja auch ein ganzes Jahr ;) )

Wenn man es so macht, kommt genau das selbe raus, aber in 0,01s:

from(bucket: "iobrokerV2")
|> range(start: 2022-02-08T08:28:18.244Z, stop: 2023-02-08T08:28:18.244Z)
|> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung")
|> last()
|> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value")
|> limit(n: 1)

Abfrage für den ersten Wert nach Bereich ließe sich auch optimieren und damit 0,06s rausholen:

from(bucket: "iobrokerV2")
|> range(start: 2023-02-09T08:17:20.689Z)
|> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung")
|> first()
|> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value")
|> limit(n: 1)

Der Datenabruf selbst schaut in Ordnung aus. Braucht bei 24h lediglich 0,10. Sollte noch im Rahmen sein.
Ob nun mit pivot und sortieren, oder ohne spielt keine Rolle.

Was ich noch nicht verstehe ist die erste Abfrage nach bool.
Bei mir macht es bei der 'Hauptabfrage' keinen Unterschied, welcher Datentyp gespeichert ist.

Jetzt wär's toll das Ganze in's coding zu bringen, dann kann ich es auch im Echtbetrieb ausprobieren.

mango1402

So, hab nun selbst gebastelt und den Adapter mal angepasst.
Ergebnis:

2023-03-11 10:28:33.910 - debug: influxdb.1 (3577787) Incoming message getHistory from system.adapter.admin.0
2023-03-11 10:28:33.910 - debug: influxdb.1 (3577787) 0_userdata.0.Zaehler.SmartMeter.Zaehlerstand16785269139100.18926732151144776 getHistory message: {"id":"0_userdata.0.Zaehler.SmartMeter.Zaehlerstand","options":{"start":1678440515587,"end":1678526915587,"aggregate":"minmax","from":false,"ack":false,"q":false,"addID":false,"count":300,"instance":"system.adapter.influxdb.1","sessionId":5,"user":"system.user.admin"}}
2023-03-11 10:28:33.911 - debug: influxdb.1 (3577787) Query to execute:
from(bucket: "iobrokerV2")
|> range(start: 2023-03-10T09:28:35.587Z, stop: 2023-03-11T09:28:35.587Z)
|> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.Zaehlerstand" and contains(value: r._value, set: [true, false]))
|> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value")
|> group()
2023-03-11 10:28:34.012 - debug: influxdb.1 (3577787) Query to execute: from(bucket: "iobrokerV2")
|> range(start: 2022-03-10T09:28:35.587Z, stop: 2023-03-10T09:28:35.586Z)
|> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.Zaehlerstand")
|> last()
|> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value")
2023-03-11 10:28:34.030 - debug: influxdb.1 (3577787) Query to execute: from(bucket: "iobrokerV2") |> range(start: 2023-03-10T09:28:35.587Z, stop: 2023-03-11T09:28:35.587Z) |> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.Zaehlerstand") |> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value") |> sort(columns:["_time"], desc: false)
2023-03-11 10:28:34.181 - debug: influxdb.1 (3577787) Query to execute: from(bucket: "iobrokerV2")
|> range(start: 2023-03-11T09:28:35.588Z)
|> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.Zaehlerstand")
|> first()
|> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value")
2023-03-11 10:28:34.237 - debug: influxdb.1 (3577787) Send: 602 of: 7557 in: 327ms
2023-03-11 10:28:34.445 - debug: influxdb.1 (3577787) Incoming message getHistory from system.adapter.admin.0
2023-03-11 10:28:34.445 - debug: influxdb.1 (3577787) 0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung16785269144450.6908542122702093 getHistory message: {"id":"0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung","options":{"start":1678440515587,"end":1678526915587,"aggregate":"minmax","from":false,"ack":false,"q":false,"addID":false,"count":300,"instance":"system.adapter.influxdb.1","sessionId":5,"user":"system.user.admin"}}
2023-03-11 10:28:34.446 - debug: influxdb.1 (3577787) Query to execute:
from(bucket: "iobrokerV2")
|> range(start: 2023-03-10T09:28:35.587Z, stop: 2023-03-11T09:28:35.587Z)
|> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung" and contains(value: r._value, set: [true, false]))
|> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value")
|> group()
2023-03-11 10:28:34.542 - debug: influxdb.1 (3577787) Query to execute: from(bucket: "iobrokerV2")
|> range(start: 2022-03-10T09:28:35.587Z, stop: 2023-03-10T09:28:35.586Z)
|> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung")
|> last()
|> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value")
2023-03-11 10:28:34.556 - debug: influxdb.1 (3577787) Query to execute: from(bucket: "iobrokerV2") |> range(start: 2023-03-10T09:28:35.587Z, stop: 2023-03-11T09:28:35.587Z) |> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung") |> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value") |> sort(columns:["_time"], desc: false)
2023-03-11 10:28:34.664 - debug: influxdb.1 (3577787) Query to execute: from(bucket: "iobrokerV2")
|> range(start: 2023-03-11T09:28:35.588Z)
|> filter(fn: (r) => r["_measurement"] == "0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung")
|> first()
|> pivot(rowKey:["_time"], columnKey: ["_field"], valueColumn: "_value")
2023-03-11 10:28:34.716 - debug: influxdb.1 (3577787) Send: 1111 of: 7198 in: 271ms

Ergebnis: laut Debugs Verbesserung der Laufzeit von 11,8s auf 0,8s.

apollon77

@mango1402 Goil ... machste einen PR? oder wenigstens die Infos bitte ins GitHub Issue.

DANKE!

Homoran

@apollon77 passt das dann auch zu history und flot?
da gibt es einige Threads, dass das zu lange dauert.

apollon77

@homoran Ja klar ... wenn die alle sich um InfluxDB drehen dann betrifft der Fix dort alle

Homoran

@apollon77 sagte in "Warn" Logeinträge InfluxDB-Adapter:

wenn die alle sich um InfluxDB drehen

eben nicht

@homoran sagte in "Warn" Logeinträge InfluxDB-Adapter:

passt das dann auch zu history und flot?

z.b. https://forum.iobroker.net/post/960310

apollon77

@homoran Wenn "History" dann ist das durch einen Fix bei Influxdb nicht abgedeckt.

Ich kenne Keine Github issues zu performanceproblemen bei history ... ;-) Bei History muss man dinge anders prüfen ... auch hier sollte der Anfang ein Debug log sein und ein Github issue

Homoran

@apollon77 sagte in "Warn" Logeinträge InfluxDB-Adapter:

Ich kenne Keine Github issues zu performanceproblemen bei history

ich auch nicht.
muss mal die entsprechenden Threads durchflöhen und

@apollon77 sagte in "Warn" Logeinträge InfluxDB-Adapter:

ein Debug log s

versuchen zu bekommen

DANKE

mango1402

@apollon77
File im GIT angehängt. kenn mich leider nixht so mit PR usw aus.....

Hab auch mit float gecheckt - Ja, rennt wieder rund :grinning:
Wobei - es dürft egal sein, wer am Adapter das getHistory() abfragt. Die alle zünden wieder den Turbo.

DANKE schon mal vorab für's rasche einhängen und releasen in eine saubere Version ;)

lg
Manfred

apollon77

@mango1402 sagte in "Warn" Logeinträge InfluxDB-Adapter:

File im GIT angehängt. kenn mich leider nixht so mit PR usw aus.....

Im zweifel einfach: Im Github auf das zu ändernde File gehen, rechts oben auf den Stift klicken, ändern was zu ändern ist und dann unten "propose change" klicken, und auf der nächsten Seite "Create pull request", done :-) Aber mit dem File kann ichs auch so vergleichen. Danke

mango1402

@apollon77
Danke für die GitHub-Einschulung ;) Geht ja einfacher als ich gedacht habe.
Hab jetzt meinen ersten PR erstellt. Hoffe es passt so.

lg
manfred

apollon77

@mango1402 Cool, checke die Tage ... (Bin gerade in anderen Themen zu tief drin ... aber bald, DANKE!) und ja GitHub ist ganz einfach :-)

viper4iob

@mango1402 said in [Linux Shell-Skript] WLAN-Wetterstation:

@viper4iob @ilovegym @Latzi
zum Thema mit der lahmen Influx-V2 Abfrage siehe hier:
https://forum.iobroker.net/post/958290

Es erscheint Licht am Ende des Tunnels ;)

Vielen Dank fürs Analysieren :+1:
Somit hat sich bestätigt, dass es am Influx Adapter vom iobroker liegt.
Ich bin gespannt, wann dein Pull Request in einem Release landet.

viper4iob

@mango1402
Ich habe mal deinen Code in der iobroker/node_modules/iobroker.influxdb/main.js eingesetzt und die ECharts gehen wieder deutlich schneller :+1:
Wenn man aber bei einem Datenpunkt auf das Zahnrädchen klickt und den Verlauf von z.B. einem Tag anschaut, dauert es im Vergleich zum V1 Modus immer noch mehrere Sekunden bis die Daten angezeigt werden. Da hat sich also zumindest bei mir nichts verbessert.
Hat deine Änderung da keinen Einfluss?

mango1402

@viper4iob
also bei mir ist auch bei dem 'Zahnrädchen' eine deutliche Verbesserung wahrnehmbar.
Ich werwende aber diese Art von Darstellung nicht - war schon mit V1 ein Lotteriespiel ob und wann man überhaupt eine Anzeige bekommt.....

viper4iob

@mango1402
Das sieht auch gar nicht so richtig danach aus, dass eine Abfrage an Influx so lange braucht, denn die Sekunden, in denen es lädt, steht das Datum auf 01.01.1970.
Sobald er auf das richtige Zeitfenster springt, sind die Daten sofort da.
Im V1 Modus zeigt er gleich den richtigen Zeitraum an, ist also eventuell noch ein anderer Fehler an dieser Stelle.
Aber ich nutze das auch nicht wirklich, wichtiger ist, dass die ECharts und eventuell andere Adpater die Daten schneller laden können.

Negalein

@viper4iob @mango1402

ich habe eure Beiträge hierher verschoben. Passen besser hier als zur Wetterstation ;)

mango1402

@viper4iob
das 'Zahnrädchen' möchte scheinbar immer alle daten ab 2000 bis jetzt:

2023-03-24 12:49:39.344 - debug: influxdb.0 (489) 0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung16796585793440.6297946848561795 getHistory message: {"id":"0_userdata.0.Zaehler.SmartMeter.aktuelleLeistung","options":{"instance":"influxdb.0","start":946681200000,"end":1679658580637,"limit":1,"from":false,"ack":false,"q":false,"addID":false,"aggregate":"none","user":"system.user.admin"}}

946681200000 = Fri Dec 31 1999 23:00:00 GMT+0000

Hat aber nix mit dem Influx-Adapter zu tun. Der macht ja nur was ihm 'aufgetragen' wird.
Ich glaub das geht hier in Richtung 'admin-Adapter'.....

Community Forum

NEWS

"Warn" Logeinträge InfluxDB-Adapter

Support us

668

32.4k

81.4k

1.3m