Diagnostic des API Node.js lentes : Mesurez la latence avant d’optimiser

Un point d’entrée met près d’une seconde à s’exécuter, pourtant la CPU n’est utilisée qu’environ un tiers de sa capacité, la mémoire est ordinaire et le tableau de bord de la base de données affiche un état vert. Ajuster ce que l’on soupçonne ne sert que rarement à quelque chose. Ce guide vous guide étape par étape à travers le traitement d’une requête afin que vous puissiez identifier où passe le temps, ainsi que les bonnes pratiques d’instrumentation qui permettent de mener une investigation efficace et fiable.

Mesurez le temps de traitement de la requête avant d’accuser le runtime

Utilisez une route simple qui charge une commande en fonction de son ID et la renvoie sous forme JSON.

app.get("/orders/:id", async (req, res) => {
  const order = await getOrder(req.params.id);
  res.json(order);
});

Supposons que les réponses prennent environ 900 ms. Plutôt que d’accuser Node.js, entourez l’appel en attente de performance.now() pour voir quelle partie du temps total il représente.

const start = performance.now();

const order = await getOrder(req.params.id);
console.log(
  `getOrder: ${performance.now() - start}ms`
);
res.json(order);

Les chiffres résolvent généralement rapidement la question :

Request:       910ms
getOrder():    870ms
Node.js:        40ms

Presque toute la latence se situe à l’intérieur de getOrder() ; le JavaScript environnant représente environ 40 ms. Ce temps est consacré à l’attente de quelque chose en aval.

Un faible usage du CPU ne signifie pas un service en bon état

Un tableau d’utilisation comme celui-ci donne une impression rassurante :

CPU: 32%
Memory: 48%

Le CPU mesure le travail effectué, et une requête en attente ne consomme presque pas de ressources. Les éléments typiques auxquels un processus Node.js attend :

• l’obtention d’une connexion à la base de données
• la requête elle-même
• un autre service HTTP
• les opérations d’entrée/sortie réseau générales
• une file de messages
• un verrou

Un service lent avec un CPU inactif n’est généralement pas occupé ; il est bloqué.

Prêtez attention au retard du cycle d’événements, et non seulement au pourcentage de CPU

Chaque appel de retour dans un processus Node.js partage un même boucle d’événements, donc l’écart entre le moment où un chronomètre devrait se déclencher et celui où il se déclenche réellement constitue un indicateur direct de sa santé. La fonction monitorEventLoopDelay issue de node:perf_hooks échantillonne cet écart pour en créer un histogramme ; ici, elle utilise une résolution de 20 ms et affiche les valeurs p95 et p99 toutes les cinq secondes.

import { monitorEventLoopDelay } from "node:perf_hooks";

const histogram = monitorEventLoopDelay({
  resolution: 20
});
histogram.enable();
setInterval(() => {
  console.log({
    p95: histogram.percentile(95),
    p99: histogram.percentile(99)
  });
}, 5000);

Si la sortie ressemble à ceci, la boucle fonctionne correctement et ne peut pas expliquer une demande de 900 ms :

p95 event-loop delay: 8ms
p99 event-loop delay: 14ms

Des valeurs se situant dans les centaines de millisecondes racontent une histoire complètement différente :

p95: 180ms
p99: 650ms

Quelque chose monopolise alors la boucle. Un coupable typique est une fonction synchrone gourmande en ressources CPU appelée directement à l’intérieur d’un gestionnaire :

app.get("/report", (req, res) => {
  const result = expensiveCalculation();
  res.json(result);
});

Pendant que expensiveCalculation() est en exécution, aucune autre requête sur ce processus ne progresse. Sur un hôte multi-cœurs, le graphique global de l’utilisation du CPU peut encore sembler modéré, car un cœur saturé est moyenné avec des cœurs inactifs ; c’est pourquoi le délai de boucle est souvent plus fiable que le pourcentage d’utilisation du CPU. La solution habituelle consiste à déplacer ce type de tâche vers un thread d’exploitation, une file d’attente de tâches ou un service distinct. Un mode de défaillance similaire, où c’est le planification des micro-tâches plutôt que les calculs qui entrave la boucle, est abordé dans comment process.nextTick peut entraver la boucle d’événements de Node.js.

Lorsque c’est la base de données qui est en cause

Ensuite, instrumentez la requête de la même manière.

const start = performance.now();
const result = await db.query(
  "SELECT * FROM orders WHERE customer_id = $1",
  [customerId]
);
console.log(
  `DB query: ${performance.now() - start}ms`
);

La cause du problème pointe désormais clairement vers la base de données :

Total request: 850ms
Node.js:        15ms
DB query:      810ms
Serialization:  25ms

Avant de réécrire la requête SQL, vérifiez si elle était lente ou si la demande attendait une connexion.

Epuisement du pool masqué comme requête lente

Imaginons un pool de cette taille :

API instances:        10
Connections/instance: 20

Total connections:   200

Puis une vague d’activité arrive :

Requests:          500
Active DB queries:  20
Waiting requests: 480

Seules 20 requêtes peuvent être exécutées par instance, ce qui fait que les autres attendent dans la file du pool. Une requête peut prendre 30 ms, mais une demande en fin de file doit attendre des centaines de millisecondes avant d’atteindre la base de données. Le chronomètre de l’application indique :

DB call = 500ms

La base de données elle-même indique :

Query = 30ms

Une requête lente nécessite des index ou un meilleur plan d’exécution ; une attente prolongée exige un pool plus grand, des transactions plus courtes ou moins d’allers-retours. Mesurez chaque phase séparément plutôt que de se fier à un seul indicateur de « latence de la base de données » :

Connection wait
      +
Query execution
      +
Result processing

La plupart des bibliothèques de pool affichent le nombre d’éléments inutilisés, le total et ceux en attente ; les exporter est le moyen le plus rapide pour distinguer ces cas.

Services en aval et appels await séquentiels

De nombreux points de terminaison assemblent une réponse à partir de plusieurs dépendances, l’une après l’autre :

const customer = await customerService.get(id);

const payment = await paymentApi.get(
  customer.paymentId
);
const orders = await orderService.get(id);

En mesurant chaque appel séparément, on peut identifier les valeurs anormales :

Customer API:    40ms
Payment API:    700ms  ← 🚨
Orders DB:       35ms
Node.js:         15ms

Le service de paiement domine, et comme chaque await attend le précédent, les latences s’accumulent :

40ms + 700ms + 35ms + 15ms
≈ 790ms

Les appels indépendants peuvent être lancés en même temps. Les recherches de client et de commande n’ont besoin que de l’id, donc Promise.all les exécute simultanément :

const [customer, orders] = await Promise.all([
  customerService.get(id),
  orderService.get(id)
]);

L’appel de paiement attend toujours, car il a besoin de customer.paymentId. Ne parallélisez pas automatiquement : une concurrence supplémentaire augmente la charge sur les pools, les API et la mémoire, ce qui peut aggraver les retards en période de forte activité.

Les percentiles révèlent ce que les moyennes cachent

Un tableau de bord affichant ces données semble convenable :

Average latency: 120ms

La vue par percentiles du même trafic est moins rassurante :

p50:  80ms
p95: 180ms
p99: 2.8s

La moyenne décrit une requête ordinaire ; la distribution des extrêmes décrit les utilisateurs qui se heurtent à une capacité saturée ou à des dépendances lentes. Suivez cette distribution :

p50
p95
p99

Une instrumentation qui aide plutôt qu’elle ne nuit

La mesure consomme de la puissance CPU, de l’espace de stockage et de l’attention. Quelques bonnes habitudes permettent de la garder utile.

Mesurez aux points critiques, pas dans chaque fonction d’aide

Chronométrer chaque fonction de cette manière génère plus de bruit que d’informations utiles :

const start = performance.now();
// ...
console.log(performance.now() - start);

Mesurez là où une requête passe à un autre système, car c’est là que l’attente a lieu :

HTTP request
   ↓
Database
   ↓
External API
   ↓
Queue
   ↓
Response

Contrôlez le journalisation par requête

Une ligne de journal pour chaque requête devient coûteuse en cas d’afflux élevé de données :

console.log({
  path: req.path,
  duration,
  userId: req.user.id
});

Utilisez un journalisation structurée avec des niveaux et un échantillonnage, et évitez complètement d’inclure ces éléments dans les journaux :

passwords
tokens
authorization headers
payment information

Une durée n’est pas un diagnostic

Voir un chiffre de ce type ne prouve pas que l’instruction SQL a duré autant de temps :

DB: 700ms

Cette période peut comprendre plusieurs coûts distincts :

Connection acquisition
+
Query execution
+
Network
+
Result transfer
+
Client-side processing

Lorsqu’un chiffre vous surprend, décomposez-le en ses composantes avant d’agir dessus.

Évitez les étiquettes de métriques à haute cardinalité

Attribuer un identifiant d’utilisateur à une métrique de latence semble inoffensif :

http_request_duration{user_id="123456"}

Avec des millions d’utilisateurs, cela signifie des millions de séries temporelles. Préférez plutôt des dimensions limitées :

route
method
status_code
service

Une série bien étiquetée ressemblera alors à ceci :

http_request_duration{
  route="/orders/:id",
  method="GET",
  status="200"
}

Les détails par requête doivent figurer dans les journaux et les traces.

Échantillonnez délibérément

Une politique courante enregistre une fraction du trafic normal ainsi que tout ce qui est intéressant :

Normal traffic → sample a percentage
Errors         → capture aggressively
Slow requests  → capture aggressively

Le rapport dépend du trafic, des outils utilisés et du budget ; l’objectif est d’avoir suffisamment de preuves pour expliquer les échecs, et non l’exhaustivité.

Comparer avant et après, sur plusieurs indicateurs

« Cela semble plus rapide » n’est pas une preuve. Enregistrez le percentile avant un changement :

Before:
p95 = 820ms

Et à nouveau après :

After:
p95 = 410ms

Puis vérifiez qu’aucun autre élément n’a évolué dans la mauvaise direction :

error rate
CPU
memory
DB load
connection pool usage

Une requête plus rapide qui double l’utilisation de la mémoire ou la charge de la base de données ne fait que déplacer le problème.

Suivre une seule requête avec du traçage

Une métrique au niveau de la route ne vous indique que le total :

GET /orders = 980ms

Un traçage distribué divise la même requête en différentes étapes, ce qui permet de voir d’un coup d’œil le coût de chaque phase :

GET /orders
│
├── Node.js processing       15ms
├── DB connection wait      120ms
├── PostgreSQL query         40ms
├── Payment API             700ms
├── JSON serialization       20ms
└── Network                   5ms
                              ───
                              900ms

Il convient de se rappeler cette répartition des tâches : les métriques vous avertissent qu’il y a un problème, tandis que les traces montrent où se situe le problème.

Une liste de contrôle pour suivre le parcours d’une requête

Lorsque la latence augmente, résistez à l’envie d’ajouter des serveurs ou de la puissance CPU en premier. Suivez le parcours emprunté par la requête et mesurez chaque étape :

Request
   ↓
Queue / Load Balancer
   ↓
Node.js
   ↓
Event Loop
   ↓
Connection Pool
   ↓
Database
   ↓
External APIs
   ↓
Network
   ↓
Response

À chaque étape, posez-vous une question concrète :

Is the event loop blocked?

Are requests waiting for connections?

Are database queries slow?

Are downstream APIs slow?

Are we waiting on network I/O?

Is the queue growing?

Is garbage collection causing pauses?

Is the response itself expensive to serialize?

Chacune de ces questions peut être répondue à l’aide de données, il n’est donc pas nécessaire de deviner.

Ce que les données montrent généralement

Revenons au scénario initial :

API latency: 900ms
CPU: 35%
Memory: 48%

Après avoir mesuré chaque étape, l’image est complètement différente :

Event loop:          12ms
DB query:            35ms
Connection wait:    120ms
Payment API:        700ms
Serialization:       20ms
Network:              5ms

Aucune réécriture en temps de exécution : une instance plus grande ou davantage de mémoire aiderait. Les principaux facteurs de latence sont la dépendance au paiement qui prend 700 ms (cache, délai avec solution de secours, ou déplacement hors du chemin de la requête) et l’attente de connexion qui dure 120 ms (taille du pool ou volume des requêtes).

Points clés

Le cycle instinctif ressemble à ceci :

Slow API
   ↓
Add more servers

Le cycle efficace ressemble à ceci :

Slow API
   ↓
Measure
   ↓
Break down latency
   ↓
Find the bottleneck
   ↓
Fix the bottleneck
   ↓
Measure again

• Mesurez d’abord le temps total de la requête, puis divisez-le à chaque étape où elle quitte le processus.
• Considérez le retard du cycle d’événements comme le principal indicateur de santé de Node.js ; le pourcentage d’utilisation du CPU peut masquer un seul cœur bloqué.
• Séparez l’attente de connexion de l’exécution de la requête avant d’accéder au SQL.
• Évaluez la latence en fonction de p95 et p99, et non des moyennes.
• Gardez les métriques à faible cardinalité, les journaux échantillonnés et exempts de données sensibles, et placez les détails par requête dans les traces.

Vérifiez chaque correction en fonction des mêmes percentiles et des signaux voisins qu’elle a pu affecter.

Un système lent est gérable une fois qu’on peut le voir ; jusqu’à ce moment-là, chaque changement n’est qu’une supposition. Pour savoir quelles corrections prioriser une fois le goulot d’étranglement identifié, consultez un cadre d’optimisation ordonné par priorité pour les performances de l’API Node.js.