Analyse der ungenauen Verteilung von Wrk-Latenz

API7.ai

September 3, 2018

Technology

wrk ist ein großartiges HTTP-Stresstest-Tool, das auf den Open-Source-Projekten Redis, NGINX, Node.js und LuaJIT aufbaut und deren Stärken in Bezug auf Ereignissteuerung, HTTP-Parsing, hohe Leistung und Flexibilität nutzt. Es ermöglicht auch das Schreiben eigener Lua-Skripte, um Testanfragen zu generieren.

Obwohl wrk keine Testfälle hat und der Autor etwa einmal im Jahr auftaucht, um den Code zusammenzuführen, hindert uns das nicht daran, wrk als unser bevorzugtes Tool für Leistungs- und Fuzz-Tests zu verwenden. Wenn Sie immer noch das multithreaded ab verwenden, lohnt es sich auf jeden Fall, wrk auszuprobieren.


Im Folgenden finden Sie den statistischen Teil der Latenzverteilung aus den wrk-Ergebnissen.

    Latency Distribution
     50%    1.20ms
     75%  595.78ms
     90%  899.11ms
     99%    1.00s

Dieses Beispiel bedeutet, dass 50 % der Anfragen in 1,2 ms abgeschlossen sind, 90 % der Anfragen in 899 ms und 99 % der Anfragen in 1 s.

Als wir wrk zur Belastungstests unseres eigenen Produkts verwendeten, stellten wir fest, dass die meisten Anfragen in den Latenzstatistiken von wrk innerhalb weniger Millisekunden abgeschlossen wurden, aber ein kleiner Prozentsatz der Anfragen eine Latenz von über 100 Millisekunden aufwies. Für ein mit OpenResty erstelltes System ist eine so große Latenz nicht sehr wissenschaftlich.

Obwohl die endgültige Lösung für dieses Problem sehr einfach war, war die spezifische Analyse und Lokalisierung etwas umständlich und dauerte mehrere Tage. Die endgültige Lösung ist nicht wichtig; es sind der Prozess und die Denkweise zur Problemlösung, die von Interesse sind.


Wenn wir auf Latenzprobleme stoßen, ist unsere erste Reaktion, dass es irgendwo im Code oder im System eine Blockade gibt. Da das System komplex ist, bieten wir Flame Graphs an.

Es gibt kein vorgefertigtes Systemtap-Skript, um diese Art von Problem zu analysieren, daher dauerte es einige Zeit, eines zu schreiben. Nach mehreren Anpassungen des Systemtap-Skripts wurde jedoch keine signifikante Verzögerung erfasst, was eindeutig nicht mit den wrk-Ergebnissen übereinstimmt. Wir vermuteten, dass das Skript möglicherweise nicht perfekt ist und einige Funktionen, die nicht gehookt wurden, übersehen hat. Aber wir haben auch Zweifel an der Richtigkeit der wrk-Ergebnisse.

Wir drehen uns um und versuchen herauszufinden, ob die wrk-Statistiken falsch sind oder ob es tatsächlich ein Serverproblem ist. Wir haben alle Pakete vom Crush-Test auf dem Server, auf dem wrk läuft, gedumpt, nach der benötigten Zeit sortiert und waren überrascht festzustellen, dass die Ergebnisse sehr unterschiedlich von den Latenzstatistiken von wrk waren, mit keinen Anfragen, die 100 Millisekunden überschritten. Ich wiederholte den obigen Test mehrmals, und die Ergebnisse waren konsistent.


Jetzt ist das Ziel klar, wir müssen nur den Code von wrk über die Latenzstatistiken glätten. Die größte Sorge ist, dass es einen Bug in den internen Statistiken von wrk gibt, der nicht leicht zu beheben ist, da es sich schließlich um ein Projekt ohne Testfälle handelt.

Wir gingen die wrk-Statistiklogik durch und fügten am Anfang und Ende Logs hinzu und waren erleichtert festzustellen, dass die Statistiken über die Verzögerung korrekt waren. Aber vor dem Drucken der endgültigen Ergebnisse gibt es einen statistic correction-Code.

    if (complete / cfg.connections > 0) {
        int64_t interval = runtime_us / (complete / cfg.connections);
        stats_correct(statistics.latency, interval);
    }

Gemäß dieser if-Bedingung wird immer dann, wenn piezometrische Daten generiert werden, eine Korrektur vorgenommen. Wenn Sie interessiert sind, können Sie sich den Code der stats_correct-Funktion ansehen, er ist nur 10 Zeilen lang, und ich habe ihn auch nach mehrmaligem Lesen nicht verstanden.

Überprüfen Sie den Code-Commit-Record erneut, es könnte etwas geben, aber es gibt nur die folgende Zeile, und ich habe sie nicht verstanden:

remove calibration & improve CO correction

Unter Tucao, wenn der Commit-Record etwas detaillierter wäre, ohne Abkürzungen oder mit einem Code-Kommentar, könnte man vieles sparen.

Das Problem wurde hier überprüft, und es kann bestätigt werden, dass es kein Produktproblem ist, und die Lösung ist bereits vorhanden, nämlich den obigen Korrekturcode auszukommentieren. Aber es muss einen Grund geben, warum der wrk-Autor ihn absichtlich hinzugefügt hat, und das Nichtverstehen des Grundes ist immer ein verstecktes Problem. Natürlich musste ich ein Issue öffnen, um den Autor zu fragen, und wg, der einmal im Jahr auftaucht, gab 15 Tage später eine Antwort, und es stellt sich heraus, dass die Abkürzung CO in den obigen Commit-Infos sich auf Coordinated Omission bezieht, und gibt einen Artikel, der sich speziell mit diesem Problem befasst, interessierte Schüler können mit diesem Schlüsselwort selbst suchen.

Einfach gesagt bedeutet Coordinated Omission, dass es beim Durchführen von Stresstests nicht ausreicht, nur die Zeit zwischen dem Senden und dem Empfangen einer Antwort zu zählen, dies bezieht sich auf service time, was viele potenzielle Probleme verpassen wird, und die Wartezeit der Testanfrage muss ebenfalls gezählt werden, um als response time betrachtet zu werden, die den Benutzern wichtig ist.

Gil Tene, der das CO-Problem vorgeschlagen hat, hat auch eine Modifikation an wrk vorgenommen, um speziell das CO-Problem zu adressieren: https://github.com/giltene/wrk2, und das README für dieses Projekt enthält einige Erklärungen dazu, die Sie lesen können, wenn Sie interessiert sind, daher werde ich es hier nicht erwähnen.


Für unser eigenes Produkt gibt es sicherlich keine Blockaden im Code, und bei der Durchführung von Stresstests läuft die CPU auf Hochtouren. Selbst wenn es Blockaden gibt, gibt es ein Flame Graph zur Probenahme und Analyse. Daher ist die einfache und brutale Korrektur, die wrk hier für Coordinated Omission vornimmt, eher irreführend.

Share article link