Serveur ou application : comment mesurer le goulot d'étranglement

Le temps jusqu'au premier octet à chaque saut

Les théories sur un site lent se forment facilement et se tranchent difficilement. Trois mesures les tranchent. Prenez le temps jusqu'au premier octet à travers le edge public, de nouveau directement vers l'origine en contournant le edge, et de nouveau sur l'hôte de l'application vers localhost. La différence entre deux relevés adjacents est le coût de cette couche.

# 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/

Ce qui reste sur localhost est l'application et les services qu'elle appelle. La couche avec le plus grand écart est là où va le reste du travail.

La marge pendant que ça fait mal

Lisez les compteurs pendant la période lente, pas après.

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

Une longue run queue avec peu d'idle est une machine limitée par le CPU. Un I/O wait élevé avec un await élevé sur le périphérique, c'est le stockage. Le steal est un voisin sur un hyperviseur partagé qui prend des cycles que le guest voulait. Un CPU inactif, de la mémoire disponible et des périphériques à faible await sous un site lent signifient que la machine attend quelque chose qui ne lui appartient pas : un appel externe, un verrou, une requête lente pour des raisons autres que le matériel. Ajouter du matériel à ce stade produit une machine plus inactive qui est toujours lente.

Il existe une troisième catégorie entre les deux, et elle est courante : le pool. La page de statut de PHP-FPM montre une listen queue. Une file de requêtes en attente avec un CPU inactif signifie que chaque worker est occupé, généralement bloqué sur le même appel lent, et que le site est lent à cause d'un plafond de configuration plutôt que d'un plafond de ressources. La même forme apparaît comme un pool de connexions de base de données saturé ou une file de backend HAProxy pleine. La machine est innocente et le code n'est pas encore condamné. La taille du pool et l'appel qu'il attend sont les deux relevés suivants.

Lisez le trafic avant le code

Le log d'accès dit de quel type de problème il s'agit. Trouvez d'abord le log par vhost. Le log par défaut peut ne contenir qu'une petite fraction du trafic réel, et un comptage sur le mauvais fichier donne une réponse fausse avec assurance.

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

Quelques URL répétées des milliers de fois, c'est le site qui s'appelle lui-même, et la solution est un cache devant ces URL. Des requêtes qui avancent dans l'ordre du sitemap, c'est un crawler, et la solution est un rate limit. Une hausse large et uniforme sur de nombreuses URL, c'est de la demande, et la solution est de la capacité.

Condensez le slow log et le log de requêtes

Un slow log est un tas de stack traces tant qu'il n'est pas groupé. Activez le slow log de PHP-FPM avec un seuil qui attrape les requêtes dont les utilisateurs se plaignent, puis groupez chaque trace sur la frame dans laquelle elle était bloquée, la feuille, et comptez. La liste classée est courte et sa tête est généralement un appel externe ou une requête SQL.

Côté base de données, classez par digest, pas par plan. Une paramétrisation incohérente éclate une requête logique en de nombreux plans qui paraissent chacun inoffensifs. Sommé par digest, le vrai propriétaire du temps de la base se rassemble en une seule ligne.

-- 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;

Avant d'écrire un index, vérifiez le nombre réel de lignes et les index qui existent déjà. Un index sur une table qui n'en a pas besoin est un chemin d'écriture plus lent.

Lisez la source primaire, pas une histoire plausible

Chaque ligne remplace une théorie par un relevé. La dernière compte sur un système en mode enforcing : le journal d'audit répond à la question sans changer la posture de sécurité pour la poser.

Prouvez-le, puis vérifiez avec la même mesure

La corrélation donne un suspect. Une petite perturbation réversible le condamne : arrêtez les requêtes suspectes quelques secondes et regardez si la charge se reconstitue. Si elle se reconstitue aussitôt, le trafic en direct est le moteur et la solution appartient au edge, devant les requêtes qui ne devraient même pas atteindre la base. Tant que la cause n'est pas connue, le système est en lecture seule. Quand la correction est en place, elle est vérifiée avec la mesure qui a trouvé le problème : si le temps jusqu'au premier octet par saut l'a localisé, le temps jusqu'au premier octet par saut confirme qu'il a disparu.

Ce que nous corrigeons et ce que nous vous rendons

Nous ne changeons pas votre code. Nous nommons la ligne, montrons la mesure qui la désigne et gardons le site en ligne pendant que vous la corrigez.