wundersame DNS-Anfragen

[baerenwaldfreund]

The Problem

Ich habe gestern auf die neuste Version 13.0.8 upgedated. Läuft so weit ganz gut.

Allerdings fallen mit heute beim Durchsehen der DNS-Anfragen via Pi-hole seltsame DNS-Anfragen auf:

2022-12-21 12:47:48 | A | ü©ÿ?lòú?Èõú?< | zaehler.fritz.box

oder auch

2022-12-21 12:51:48 | A | ��ý?� | zaehler.fritz.box

Der Wasserzähler fragt alle 2 Minuten diese seltsamen Domains ab. Hier kann es sich eigentlich nur um einen Bug handeln. Kann diese DNS-Anfragen noch jmd bestätigen?

Version

13.0.8

Logfile

keine interessanten Logfiles dazu.

Expected Behavior

No response

Screenshots

No response

Additional Context

No response

[caco3]

Ich wüsste nicht, was wir da geändert hätten.

Wir haben am NTP Client geschraubt, das ist etwas das einzige, wo ich die Anwendung von DNS sehe.
Alternativ auch, wenn Du für den MQTT- oder InfluxDB-Server eine Domain anstatt IP eingetragen hast.

Kannst Du mal dein Logfile und configfile zeigen?

[baerenwaldfreund]

Die DNS-Anfragen waren m.E. schon in einer älteren Version vorhanden. Ich konnte sie bisher aber nicht zuordnen, weil die Quelle nicht sofort ersichtlich war. Jetzt habe ich mich aber weiter auf die Suche gemacht. Das Update hat also nichts damit zu tun, auch, wenn es in meinem ersten Post vielleicht so aussah.

Vielleicht hat ja noch jmd Pi-hole laufen. Dann ist's einfach nachzuvollziehen. Ansonsten bliebe nur Wireshark, um die DNS-Anfragen zu checken.

EDIT:
Die DNS-Anfragen kommen nicht immer im 2-Minuten-Takt, Ich habe jetzt mal das Teil neu gebootet und sie sind jetzt seit 20 min. nicht gekommen. Aber sie kommen immer mal wieder. Ob das Problem bei einem "unsauberem" Reboot zu tun hat, kann ich noch nicht sagen. In meiner Pi-hole Statistik sind es aber 328 Anfragen von diesem Gerät. Werde mal weiter beobachten.
config.txt
log.txt

EDIT2: Anhänge ergänzt (Passwort geändert). Der von mir eingestellte NTP-Server wird ignoriert. Es wird weiterhin der pool.ntp.org genutzt.

[caco3]

Ich verwende selber auch Pi-Hole, finde darin aber keine Einträge von meinen Geräten.
Dadurch kann ich es auch nicht eingrenzen.
Grundsätzlich sieht es so aus, wie wenn ein nicht-initialisierter Buffer verwendet wird. Da die ganze NTP-Funktionalität jedoch von Espressif bereitgestellt wird, sehe ich nicht, was wir da falsch gemacht haben könnten.

[baerenwaldfreund]

Es war jetzt gut 1,5h Ruhe, aber jetzt ist der Fehler wieder da. Ich hänge nochmal einen Screenshot an:

Für mich sieht es aus, als würde ein Array überlaufen oder es fehlt ein Array-Ende-Zeichen 0x00. Hatte ich in meiner "Programmierkarriere" häufiger mal verursacht ;-) Sehr interessant ist, dass es bei Dir nicht auftritt.

Wie schon erwähnt, wird bei mir der eingestellte NTP-Server ignoriert und weiterhin der pool-NTP-Server genutzt. Vielleicht hängt das zusammen?

EDIT:
Wireshark gibt mir diesen Code als angefragte Domain raus:
0d c8 a9 ff 3f 6c f2 fa 3f c8 f5 fa 3f 3a 00

[baerenwaldfreund]

So, habe jetzt mal ausführlich Wireshark mitlaufen lassen.

Wenn das Gerät elektrisch eingeschaltet wird, wird IMMER zuerst eine DNS-Anfrage nach pool.ntp.org gestellt. Im Anschluss wird der NTP-Server pool.ntp.org angefragt und die Antwort kommt. 9 Sekunden später wird der in der Konfiguration eingetragene NTP-Server angefragt.

Bei einem Reboot wird nur noch der in der Config eingetragene NTP-Server angefragt:

Wieso wird überhaupt ein NTP-Server angefragt, der nicht in der Config definiert ist?

Vielleicht sind auch spätere kaputte DNS-Anfragen in dem Kontext zu suchen?!?!?

EDIT:
Die Timezone wird auch beim Einschalten ignoriert. Genutzte Einstellung beim Starten:
CET-1CEST,M3.5.0,M10.5.0/3
eingestellt in der Config ist:
CET-1CEST-2,M3.5.0/02:00:00,M10.5.0/03:00:00

EDIT2:
In der Datei "time_sntp.cpp" ist die initiale NTP-Anfrage hart codiert in den Funktionen "initialize_sntp()" und "setup_time()". Deshalb werden die eingestellte NTP-Config nach dem Einschalten nicht genommen. Wäre es nicht sauberer, wenn eingangs auch schon die Config-Parameter ausgewertet werden?

[caco3]

habe dafür mal einen issue gemacht: #1659
Die schwierigkeit ist, dass wir schon beim aufstarten informationen ins logfile (mit dem richtigen datum als name) schreiben wollen, bevor wir Wifi haben. Bei einem Kaltstart haben wir daher noch 1970. bei einem Warmstart hat er die Zeit noch irgendwo gespeichert und macht direkt von dort weiter, siehe https://www.esp32.com/viewtopic.php?t=20696

Allerdings nimmt er da auch jeweils die default timezone, weil er ja die config noch nicht gelesen hat.
Wobei sich das einfach ändern lässt.

[caco3]

https://esp32.com/viewtopic.php?t=7045

[caco3]

https://docs.espressif.com/projects/esp-idf/en/latest/esp32/api-guides/memory-types.html?highlight=rtc_noinit_attr

[baerenwaldfreund]

hmmmm...??? Wie kann man denn einen NTP-Server ohne WLAN abfragen? Eigentlich ist es doch egal, welcher NTP-Server beim Start angefragt wird. Der fest codierte pool.ntp oder halt der vom User definierte. Beide können nur bei stehender Wlan-Verbindung eine Zeit nennen. Oder habe ich gerade einen Knoten im Gehirn? fg

Das alles erklärt aber noch nicht die seltsamen DNS-Anfragen. Welche Einstellung hast du denn dort gesetzt? Kannst Du mir mal Deine folgenden Dinge nennen, die bei Dir eingestellt sind?

• TimeZone
• TimeServer

Dann stelle ich das bei mir mal genauso ein und beobachte, ob diese DNS-Anfragen weiterhin kommen.

Die Anfragen kommen exakt alle 120 Sekunden. Weißt Du auswendig, was in der Software diesen Rhytmus hat? Dort wäre dann vielleicht auch der etwaige Bufferfehler zu suchen.

[caco3]

Soviel ich herausgefunden habe, ist das Sync interval by default 1h (habs aber nicht kontolliert)

Ich habe mit #1676 versucht, es besser zu lösen.
Du kannst den build von hier herunterladen: https://github.com/jomjol/AI-on-the-edge-device/actions/workflows/build.yaml?query=branch%3Aimprove-ntp-handling

Achtung: Es baut auf dem aktuellen rolling auf, einige andere dinge könnten nicht mehr funktionieren!
ery=branch%3Aimprove-ntp-handling

[baerenwaldfreund]

Ich habe das Update mal installiert. Hier der Auszug aus dem Log:

[0d00h00m04s] 2022-12-26T11:37:33 <INF> [SNTP] TimeServer: 1783vaw.fritz.box
[0d00h00m04s] 2022-12-26T11:37:33 <INF> [SNTP] Configuring NTP Client...
[0d00h00m04s] 2022-12-26T12:37:33 <INF> [SNTP] Time zone set to CET-1CEST
[0d00h00m04s] 2022-12-26T12:37:33 <INF> [SNTP] Time is already set: 2022-12-26 12:37:33
[0d00h00m04s] 2022-12-26T12:37:33 <INF> [MAIN] =================================================
[0d00h00m04s] 2022-12-26T12:37:33 <INF> [MAIN] ==================== Startup ====================
[0d00h00m04s] 2022-12-26T12:37:33 <INF> [MAIN] =================================================
[0d00h00m04s] 2022-12-26T12:37:33 <INF> [MAIN] Development-Branch: HEAD (Commit: 2b3c87a+), Date/Time: 2022-12-23 21:36, Web UI: Development-Branch: HEAD (Commit: 2b3c87a+)
[0d00h00m04s] 2022-12-26T12:37:33 <INF> [MAIN] Reset reason: Via esp_restart
[0d00h00m05s] 2022-12-26T12:37:34 <INF> [MAIN] WLAN-Settings - RSSI-Threashold: 0
[0d00h00m11s] 2022-12-26T12:37:40 <INF> [MAIN] =================================================
[0d00h00m11s] 2022-12-26T12:37:40 <INF> [MAIN] ================== Main Started =================
[0d00h00m11s] 2022-12-26T12:37:40 <INF> [MAIN] =================================================
[0d00h00m11s] 2022-12-26T12:37:40 <INF> [MAIN] The device has 8 MBytes of PSRAM
[0d00h00m13s] 2022-12-26T12:37:42 <INF> [MAIN] Initialization completed successfully!

Komisch ist, dass die dort angegebene Zeit um 10 Minuten falsch angezeigt wird. Es war erst 12:27 Uhr. Auf der Hauptseite wird die Zeit allerdings jetzt richtig angezeigt. Komisch, aber auch nicht kritisch.

Es wird auf jeden Fall nur noch der in der Config angegebene NTP-Server gefragt. Das ist schon mal gut.

Vor zwei Tagen, also vor dem Update, hatte ich noch den NTP-Server von IP-Adresse auf Hostnamen umgestellt. Also nicht mehr 192.168.178.1, sondern 1783vaw.fritz.box. Gestern kamen dann keine seltsamen DNS-Fehler. Heute allerdings waren wieder wenige da:

Wir sind jetzt erstmal ein paar Tage im Urlaub. Ich werde im neuen Jahr berichten, ob sich der DNS-Fehler auch verändert hat oder gar weg ist.

Ach ja, es ist mir noch aufgefallen, dass sich vor dem Update zuerst kein Backup erstellen ließ. Habe mir die Fehlermeldung leider nicht notiert, aber es war irgendwas mit dem Packer, was moniert wurde. Nach einem Softreboot, war das Backup kein Problem. Auch das könnte auf einen Bufferfehler hinweisen?!!?

[caco3]

Komisch ist, dass die dort angegebene Zeit um 10 Minuten falsch angezeigt wird. Es war erst 12:27 Uhr. Auf der Hauptseite wird die Zeit allerdings jetzt richtig angezeigt. Komisch, aber auch nicht kritisch.

Wellen Eintrag auf der Hauptseite meinst Du?

• Last Page Refresh zeigt (soviel ich weiss) die PC-Zeit
• Status zeigt den letzten Flow-Wechsel, kann also einige Sekunden .. 1x Interval zurückliegen

Es wird auf jeden Fall nur noch der in der Config angegebene NTP-Server gefragt. Das ist schon mal gut.

👍 Die Änderung ist übrigens schon in rolling

Gestern kamen dann keine seltsamen DNS-Fehler. Heute allerdings waren wieder wenige

Könnte das was anderes als NTP sein, z.b. MQTT oder InfluxDb oder ein anderes Gerät?

Ach ja, es ist mir noch aufgefallen, dass sich vor dem Update zuerst kein Backup erstellen ließ.

Ja, es ist browserbasiert und nicht sehr stabil, gibt auch einen bug report dazu

Schöne Ferien!

[baerenwaldfreund]

Danke, die hatten wir :-)

Ich kann berichten, dass der Fehler mit den seltsamen DNS-Anfragen nun weg ist. Seit einer Woche läuft's problemlos. Die Zeit wird jetzt stündlich mit dem eingetragenen NTP-Server synchronisiert.

Klasse Arbeit, klasse Projekt.

DANKE!