Server oder Anwendung? So messen Sie den Engpass

Zeit bis zum ersten Byte an jedem Hop

Theorien über eine langsame Website entstehen leicht und lassen sich schwer abschließen. Drei Messungen schließen sie ab. Nehmen Sie die Zeit bis zum ersten Byte durch den öffentlichen Edge, noch einmal direkt gegen den Origin unter Umgehung des Edge, und noch einmal auf dem Anwendungshost gegen localhost. Die Differenz zwischen zwei benachbarten Messwerten ist der Preis dieser Schicht.

# through the edge
curl -s -o /dev/null -w 'dns=%{time_namelookup} tls=%{time_appconnect} ttfb=%{time_starttransfer}\n' https://site.example/

# direct to the origin, edge bypassed
curl -s -o /dev/null -w 'ttfb=%{time_starttransfer}\n' --resolve site.example:443:ORIGIN_IP https://site.example/

# on the host, nothing in front of the application
curl -s -o /dev/null -w 'ttfb=%{time_starttransfer}\n' http://127.0.0.1/

Was auf localhost übrig bleibt, ist die Anwendung und die Dienste, die sie aufruft. Die Schicht mit der größten Lücke ist die, in die der Rest der Arbeit geht.

Reserve, solange es wehtut

Lesen Sie die Zähler während der langsamen Phase, nicht danach.

vmstat 1 5        # r (run queue), wa (I/O wait), st (steal), id (idle)
iostat -x 1 5     # await and aqu-sz per device
free -m           # the available column, not used

Eine lange Run Queue bei niedrigem idle ist eine CPU-gebundene Maschine. Hohes I/O wait mit hohem await auf dem Gerät ist Storage. Steal ist ein Nachbar auf einem geteilten Hypervisor, der Zyklen nimmt, die der Gast wollte. Untätige CPU, verfügbarer Speicher und Geräte mit niedrigem await unter einer langsamen Website bedeuten, dass die Maschine auf etwas wartet, das ihr nicht gehört: einen externen Aufruf, einen Lock, ein Query, das aus anderen Gründen als der Hardware langsam ist. Mehr Hardware an diesem Punkt erzeugt eine noch untätigere Maschine, die immer noch langsam ist.

Es gibt eine dritte Kategorie zwischen den beiden, und sie ist häufig: der Pool. Die Statusseite von PHP-FPM zeigt eine Listen Queue. Eine Warteschlange wartender Anfragen bei untätiger CPU bedeutet, dass jeder Worker belegt ist, meist blockiert im selben langsamen Aufruf, und die Website ist langsam wegen einer Konfigurationsgrenze, nicht wegen einer Ressourcengrenze. Dieselbe Form zeigt sich als gesättigter Datenbank-Connection-Pool oder als volle Backend-Queue in HAProxy. Die Maschine ist unschuldig, und der Code ist noch nicht verurteilt. Die Poolgröße und der Aufruf, auf den gewartet wird, sind die nächsten beiden Messwerte.

Lesen Sie den Traffic vor dem Code

Das Access Log sagt, welche Art von Problem das ist. Finden Sie zuerst das Log pro vhost. Das Standard-Log kann einen kleinen Bruchteil des echten Traffics enthalten, und eine Zählung über die falsche Datei liefert eine selbstbewusste falsche Antwort.

tail -n 100000 access.log | awk -F'"' '{print $2}' | sort | uniq -c | sort -rn | head

Wenige URLs, tausendfach wiederholt, sind die Website, die sich selbst aufruft, und die Lösung ist ein Cache vor diesen URLs. Anfragen, die in Sitemap-Reihenfolge marschieren, sind ein Crawler, und die Lösung ist ein Rate Limit. Ein breiter, gleichmäßiger Anstieg über viele URLs ist Nachfrage, und die Lösung ist Kapazität.

Verdichten Sie das Slow Log und das Query Log

Ein Slow Log ist ein Haufen Stack Traces, bis es gruppiert wird. Aktivieren Sie das Slow Log von PHP-FPM mit einem Schwellenwert, der die Anfragen erfasst, über die sich Nutzer beschweren, dann gruppieren Sie jeden Trace nach dem Frame, in dem er blockiert war, dem Blatt, und zählen Sie. Die Rangliste ist kurz, und ganz oben steht meist ein externer Aufruf oder ein Query.

Auf der Datenbankseite ordnen Sie nach Digest, nicht nach Plan. Uneinheitliche Parametrisierung zerlegt ein logisches Query in viele Pläne, die einzeln harmlos aussehen. Nach Digest summiert, setzt sich der wahre Eigentümer der Datenbankzeit wieder zu einer Zeile zusammen.

-- MySQL and Percona: by statement digest
SELECT digest_text, count_star, sum_timer_wait
FROM performance_schema.events_statements_summary_by_digest
ORDER BY sum_timer_wait DESC
LIMIT 10;

-- SQL Server: by query hash
SELECT query_hash, COUNT(*) AS plans, SUM(total_worker_time) AS cpu
FROM sys.dm_exec_query_stats
GROUP BY query_hash
ORDER BY cpu DESC;

Bevor irgendein Index geschrieben wird, prüfen Sie die tatsächliche Zeilenzahl und die Indizes, die bereits existieren. Ein Index auf einer Tabelle, die keinen braucht, ist ein langsamerer Schreibpfad.

Lesen Sie die Primärquelle, nicht eine plausible Geschichte

Jede Zeile ersetzt eine Theorie durch einen Messwert. Die letzte zählt auf einem System im Enforcing-Modus: Das Audit-Log beantwortet die Frage, ohne dass die Sicherheitshaltung geändert werden muss, um sie zu stellen.

Beweisen Sie es, dann verifizieren Sie mit derselben Messung

Korrelation liefert einen Verdächtigen. Eine kleine, umkehrbare Störung überführt ihn: Stoppen Sie die verdächtigen Queries für ein paar Sekunden und beobachten Sie, ob die Last wieder auffüllt. Füllt sie sofort wieder auf, ist der Live-Traffic der Treiber, und die Lösung gehört an den Edge, vor die Anfragen, die die Datenbank gar nicht erreichen sollten. Bis die Ursache bekannt ist, ist das System read-only. Wenn die Korrektur eingebaut ist, wird sie mit der Messung verifiziert, die das Problem gefunden hat: Hat die Zeit bis zum ersten Byte pro Hop es lokalisiert, bestätigt die Zeit bis zum ersten Byte pro Hop, dass es weg ist.

Was wir beheben und was wir zurückgeben

Wir ändern Ihren Code nicht. Wir benennen die Zeile, zeigen die Messung, die auf sie weist, und halten die Website am Laufen, während Sie sie beheben.