Unterstützung eines Zeitstempels bei Nachrichten

[unclej84]

Guten Morgen,

aktuell scheint der Collector die Werte gemäß der Zeit des Empfangs in die InfluxDB zu schreiben. Mir ist am Wochenende - als ich ein wenig mit den Thresholds für Wertänderungen und das entsprechende Publish gespielt habe - aufgefallen, dass der Collector die Werte mit einem gewissen Delay empfangen kann (parallel habe ich es im MQTT Explorer verfolgt wo dieser Delay nicht zu sehen war). Bei wirklich schneller Abfolge (mehrere Werte innerhalb einer Sekunde) stieg der Delay immer weiter bis auf zu fast 2 Minuten (hier hatte ich es definitiv übertrieben), aber das wäre ja grundsätzlich kein Problem. Leider werden die Werte allerdings nach Zeit des "Empfangs" verarbeitet und nicht gemäß des enthaltenen Zeitstempels.
Vielleicht könnte man eine Option ergänzen in der man jeweils für JSON-Objekte den Pfad des Zeitstempels übergeben könnte, sodass dieser dann verwendet wird um den Wert in die InfluxDB zu speichern.

Gruß Jörg

[ledermann]

Da im MQTT-Protokoll kein Zeitstempel vorgesehen ist, interpretiert der MQTT-Collector den Empfangszeitpunkt als Messzeitpunkt und schreibt diesen nach InfluxDB.

Jetzt ist es natürlich denkbar, dass einzelne Geräte den Zeitstempel explizit in den Payload schreiben, z.B. als Teil einer JSON-Struktur. Dort könnte der MQTT-Collector ihn auslesen. Dazu müsste man definieren können, wo genau der Zeitstempel steht (als JSONPath) und wie er aufgebaut ist (ISO8601, Linux Epoch Time oder was sonst noch so üblich ist). Grundsätzlich würde das natürlich die Genauigkeit verbessern.
Hast du mal ein Beispiel für einen solchen Payload mit integriertem Zeitstempel?

Dass aber beim Empfang von MQTT-Nachrichten eine Verzögerung von mehreren Sekunden oder gar Minuten auftritt, finde ich sehr ungewöhnlich. Woran liegt das? Wo ist der Engpass? Falls Ingest dazwischengeschaltet ist: Kannst du mal nachsehen, ob dort die Ausgangs-Warteschlange überläuft (im Ingest-UI unter "Outgoing").

[unclej84]

Hier mal 2 Beispiele wie die Payloads kommen:

• {"Time":"2025-04-08T09:28:50","Switch1":"OFF","MT175":{"sm_energy_in":3578.9,"sm_energy_out":4449.7,"sm_power_total":-1048.00},"ESP32":{"Temperature":47.8},"TempUnit":"C"}
• {"Time":"2025-04-08T09:27:27","ENERGY":{"TotalStartTime":"2024-09-07T22:25:31","Total":24.649,"Yesterday":0.632,"Today":2.112,"Period":0.7,"Power":8.4,"ApparentPower":153.2,"ReactivePower":153.0,"Factor":0.05,"Voltage":226,"Current":0.677},"ESP32":{"Temperature":56.7},"TempUnit":"C"}

Die Verzögerung tritt bereits im Log des Collectors auf wo er schreibt, wann er was empfangen hat - also rein zwischen Broker und Collector. Keine Ahnung warum die Payload da verzögert ankommen, da ein Client (MQTT Explorer) am gleichen Broker sie quasi in Echtzeit erhält. Vielleicht kommt er mit der Verarbeitung nicht ganz hinterher, wenn die Werte zu schnell kommen?

[ledermann]

Ok, es müssten also folgende Parameter zu jedem Mapping definiert werden können:

• JSONPath für den Zeitstempel, in deinem Beispiel würde man $.Time eintragen
• Zeitzone, um Zeitstempel ohne Angabe der Zeitzone korrekt nach UTC umrechnen zu können. In deinem Beispiel wäre das vermutlich Europe/Berlin (nicht +02:00 oder UTC+2, weil die Angabe ja ganzjährig funktionieren soll).

Werde ich bei Gelegenheit implementieren.

Zur Verzögerung: Möglicherweise wird nur das Log verzögert angezeigt, der Zeitstempel ist aber korrekt. Eine Überlastung der Verarbeitung wäre ein ernsthafteres Problem, dessen Ursache vermutlich gar nicht so leicht zu identifizieren wäre. Netzwerk wohl nicht, weil im MQTT-Explorer alles korrekt ist. MQTT-Collector? Ingest?

Was steht denn bei Ingest unter Outgoing/Queued? Da sollte idealerweise immer 0 (oder eine sehr kleine Zahl) stehen.

[unclej84]

Das mit der Log-Anzeige kann eigentlich nicht sein, da er ja immer die Uhrzeit des Empfangs mit ausgibt. Glaube auch nicht, dass es am Ingest liegt, wobei ich da nicht drauf wetten könnte. Aktuell zeigt er immer irgendwas zwischen 5 und 0.
Anbei mal 2 Screenshorts von der Situation wo er so verzögert reagiert hatte - auf dem ersten Screenshot um 16:48:22 ist der Versand zu sehen und dann auf dem 2ten Screenshot der Empfang um 16:49:40. Normalerweise laufen beide Zeiten recht genau (NTP im Netzwerk - hatte den Verzug auch mal mitgestoppt). War leider extremer Traffik auf dem MQTT in dem Moment weil mehrere Stromzähler in weniger als 1s neue Werte für alle Parameter geschickt hatten. Mit reduzierter Datenlast, kommen die Werte fast in Echtzeit.

P.S: Nicht wundern - hatte bei der Übertragung den Zeitstempel im Payload aus um weniger Daten zu haben

[ledermann]

Ok, vermutlich gibt es hier doch ein Performance-Problem durch Ingest, das durch die angezeigte Metriken nicht aufgedeckt wird. Meine Vermutung ist, dass die Neuberechnung des Hausverbrauchs extrem oft aufgerufen wird, was aufgrund der durchgeführten Interpolation teuer ist - und gleichzeitig unter dem Radar läuft.

Es ist gestern ein ähnliches Problem aufgetaucht: solectrus/ingest#16. Ich bin dort bereits dran und versuche mich an einem Performance-Boost. Der könnte das bei dir beobachtete Problem dann mit erledigen.

Ich schlage vor, hier in diesem Issue soll es nur noch um den zu ergänzenden Zeitstempel gehen - was ja bereits ausreichend beschrieben ist. Das Performance-Thema gehört dann ins verlinkte Issue des Ingest-Repos.