DbLog: Ausreisser bei den Laufzeiten -> DNS?

[PatrickR]

Mahlzeit!

Ich habe aktuell Ausreißer bei der Laufzeit von DbLog_excecmemcache:

Code Auswählen Erweitern


name                                     function                               max  count    total  average maxDly TS Max call     param Max call
tmr-DbLog_execmemcache                   HASH(0x46b26a8)                       5031   1884    55319    29.36     59 26.03. 23:25:13 HASH(DbLog)

Wenn in der db.conf der DNS-CNAME verwendet wird treten die Ausreißer mehrfach pro Woche auf, bei Verwendung der IP-Adresse längere Zeiträume (1 Monat) nicht.

Zum Setup: asyncMode: 1, DbLogType: Current/History. MySQL läuft auf einer separaten VM, auf die der CNAME mysql.prdom zeigt. Die Namensauflösung übernimmt ein dnsmasq auf einer weiteren vm. Das dnsServer-Attribut von global ist gesetzt.

Die DNS-Anwortzeiten habe ich über tcpdump mitgeplottet:

Code Auswählen Erweitern


ts_request           delay  query        qt    answers
2017-03-26 23:25:43  0.001  mysql.prdom  A     2
2017-03-26 23:25:43  0.013  mysql.prdom  AAAA  0
2017-03-26 23:25:43  0.001  mysql.prdom  A     2
2017-03-26 23:25:43  0.014  mysql.prdom  AAAA  0
2017-03-26 23:25:13  0.001  mysql.prdom  A     2
2017-03-26 23:25:13  0.014  mysql.prdom  AAAA  0
2017-03-26 23:25:13  0.001  mysql.prdom  A     2
2017-03-26 23:25:13  0.021  mysql.prdom  AAAA  0
2017-03-26 23:25:08  0.0    mysql.prdom  A     2


Die Einheit von delay ist Sekunden und wird aus den tcpdump-Timestamps berechnet. Wie man sieht, stehen die Antworzeiten in keinem erkennbaren Verhältnis zu der Laufzeit aus Apptime. Mit den fruchtlosen AAAA-Anfragen werde ich mich noch befassen, aber die fallen nicht wirklich ins Gewicht.

Habt Ihr dafür eine Erklärung?

Patrick

[DS_Starter]

Hallo Patrick,

die Wirkung könnte daher kommen, dass in DbLog_excecmemcache ein Testverbindung zur DB aufgebaut wird um zu testen ob die DB erreichbar ist.
Das dient dazu sich den ganzen Fork-Prozess sowie das Handling zu sparen sofern dieser Verbindungstest nicht funktioniert.
Das ist die einzige Stelle in dieser Routine die sensibel für eine Namensauflösung ist da hier der Eintrag aus db.conf verwendet wird.

Aber wenn ich das richtig interpretiere ist es nicht die Routine DbLog_excecmemcache an sich welche die Verzögerung verursacht, sondern der Timer (wird immer neu auf NextSync gesetzt).
Schau dir bitte nochmal die Erläuterungen zu apptime an, speziell die Hinweise zu "tmr-".
Habe grad im Wiki nachgelesen. Das "tmr-" steht dafür, dass die Routine durch einen Timer aufgerufen wurde.

Ansonsten wäre generell die Fehlerfreiheit / Geschwindigkeit zwischen den Serven von Interesse weil wie gesagt eine Testconnection zur DB aufgebaut wird. Vielleicht hilft der Tipp weiter.

Grüße
Heiko

[PatrickR]

Hallo Heiko!

die Wirkung könnte daher kommen, dass in DbLog_excecmemcache ein Testverbindung zur DB aufgebaut wird um zu testen ob die DB erreichbar ist.
Das dient dazu sich den ganzen Fork-Prozess sowie das Handling zu sparen sofern dieser Verbindungstest nicht funktioniert.

Hatte ich schon gesehen weil ich mich gewundert hatte, wie DbLog im asyncMode überhaupt FHEM blockieren kann. Ob Du damit was sparst ist natürlich eine Frage. Da die Nicht-Erreichbarkeit der DB ja eher die Ausnahme ist, vermutlich eher nicht. Ich hatte das seinerzeit unter "premature optimization is the root of all evil" verbucht

Das ist die einzige Stelle in dieser Routine die sensibel für eine Namensauflösung ist da hier der Eintrag aus db.conf verwendet wird.

Ok, dann muss ich mir mal genau ansehen, wie Du das anstellst und ggf. mit Debug-Code mitplotten.

Ansonsten wäre generell die Fehlerfreiheit / Geschwindigkeit zwischen den Serven von Interesse weil wie gesagt eine Testconnection zur DB aufgebaut wird. Vielleicht hilft der Tipp weiter.

Naja, die ist generell unverdächtig, was man ja auch an den fixen DNS-Laufzeiten sieht und sie fällt ja bei einer db.conf ohne DNS nicht ins Gewicht.

Patrick

[DS_Starter]

Hatte ich schon gesehen weil ich mich gewundert hatte, wie DbLog im asyncMode überhaupt FHEM blockieren kann. Ob Du damit was sparst ist natürlich eine Frage.

Ja, vielleicht hast du recht. Ich behalte es mal im Hinterkopf ob es nicht besser wäre diesen Pre-Check wegzulassen.

Grüße
Heiko

[PatrickR]

Hey Heiko,

gerade im Changelog gesehen, dass Du klammheimlich den Pre-Check rausgenommen hast. Großartig.

Patrick

[DS_Starter]

Hi Patrick,

ja habe ich, aber nicht klammheimlich 
Ich schreibe immer in dem DbLog-Thread, so wie hier zu dieser Änderung https://forum.fhem.de/index.php/topic,65860.msg613073.html#msg613073

Hoffe es hilft ...
Grüße
Heiko

[PatrickR]

Hey Heiko!

Ich hole den Thread nochmal kurz hoch, aber nur für ein positives Feedback. Meine Laufzeiten sind so niedrig wie noch nie und das dauerhaft. Ich bin begeistert.

Patrick

[DS_Starter]

Hi Patrick,

freue mich über deine Rückmeldung und dass sich die ganze Mühe gelohnt hat. 

Grüße
Heiko