Cours NestJS · Module 8: Cache et performances

Profiling et Benchmarking de NestJS - diagnostiquer la puissance de l'Empire

10 min de lecture
Dans cette leçon5

Commandant des légions ! Après un déploiement, les utilisateurs écrivent que « c'est plus lent », et l'équipe se dispute pour savoir si la faute revient à la base, au nouvel intercepteur ou à la sérialisation. Chacun a une théorie, personne n'a de chiffres. Même l'armée romaine la mieux entraînée a besoin d'inspections régulières : dans NestJS, le profilage et le benchmarking sont cette inspection, tu diagnostiques où l'application perd du temps, de la mémoire et des ressources.

Benchmarking avec autocannon

autocannon est un outil de test de charge, comme envoyer des milliers de messagers à la fois pour vérifier la capacité des routes de l'Empire :

1# -c 100 = 100 connexions simultanées (100 messagers à la fois)
2# -d 10  = le test dure 10 secondes
3# -p 10  = 10 requêtes en pipeline par connexion - gonfle les résultats, à utiliser avec prudence
4
5# Test de charge sans installation, via npx
6npx autocannon -c 100 -d 10 http://localhost:3000/legions

-c fixe le nombre de connexions simultanées, et -d la durée du test en secondes. Voici le résultat d'une seule exécution sur un ordinateur portable, pour un endpoint qui renvoie 20 légions :

1Running 10s test @ http://localhost:3000/legions
2100 connections
3
4┌─────────┬──────┬──────┬───────┬──────┬─────────┬─────────┬────────┐
5│ Stat    │ 2.5% │ 50%  │ 97.5% │ 99%  │ Avg     │ Stdev   │ Max    │
6├─────────┼──────┼──────┼───────┼──────┼─────────┼─────────┼────────┤
7│ Latency │ 5 ms │ 5 ms │ 7 ms  │ 8 ms │ 5.44 ms │ 3.92 ms │ 352 ms │
8└─────────┴──────┴──────┴───────┴──────┴─────────┴─────────┴────────┘
9┌───────────┬─────────┬─────────┬────────┬─────────┬───────────┬────────┬─────────┐
10│ Stat      │ 1%      │ 2.5%    │ 50%    │ 97.5%   │ Avg       │ Stdev  │ Min     │
11├───────────┼─────────┼─────────┼────────┼─────────┼───────────┼────────┼─────────┤
12│ Req/Sec   │ 15,519  │ 15,519  │ 16,671 │ 16,831  │ 16,574.19 │ 344.7  │ 15,515  │
13├───────────┼─────────┼─────────┼────────┼─────────┼───────────┼────────┼─────────┤
14│ Bytes/Sec │ 23.3 MB │ 23.3 MB │ 25 MB  │ 25.3 MB │ 24.9 MB   │ 517 kB │ 23.3 MB │
15└───────────┴─────────┴─────────┴────────┴─────────┴───────────┴────────┴─────────┘
16
17182k requests in 11.02s, 274 MB read

Le premier tableau donne la latence en percentiles, le second les requêtes et les octets par seconde, avec d'autres colonnes. Tes chiffres seront différents, car ils dépendent du matériel. Le même test avec -p 10 a augmenté le nombre de requêtes par seconde d'environ 18 %, mais aussi la latence moyenne, de 5,4 à 50 ms, car les requêtes attendaient dans la file de la connexion ; les navigateurs n'utilisent pas le pipelining, laisse-le donc de côté.

Autocannon fonctionne aussi depuis le code, ce qui permet d'intégrer un benchmark aux tests :

1// benchmark.ts - utiliser autocannon depuis le code
2import autocannon from 'autocannon';
3
4async function runBenchmark() {
5  const result = await autocannon({
6    url: 'http://localhost:3000/legions',
7    connections: 100,       // 100 connexions simultanées
8    duration: 10,           // 10 secondes de test
9    headers: {
10      'Authorization': 'Bearer test-token',
11    },
12  });
13
14  console.log('=== Résultats du benchmark ===');
15  console.log('Requests/sec:', result.requests.average);
16  console.log('Latency avg:', result.latency.average, 'ms');
17  console.log('Latency p99:', result.latency.p99, 'ms');
18  console.log('Throughput:', result.throughput.average, 'bytes/sec');
19  console.log('Errors:', result.errors);
20  console.log('Timeouts:', result.timeouts);
21
22  // Critères de réussite
23  if (result.latency.p99 > 200) {
24    console.warn('ATTENTION : la latence p99 dépasse 200ms !');
25  }
26  if (result.errors > 0) {
27    console.error('ERREUR : des erreurs sont survenues pendant le test !');
28  }
29}
30
31runBenchmark();

Le résultat contient entre autres requests.average, latency.p99, throughput.average, errors et timeouts. Le seuil de 200 ms pour le p99 transforme le benchmark en test qui peut échouer.

Node.js --inspect Profiling

Node.js possède un profileur intégré qui montre ce que fait le CPU. Le flag --inspect active le protocole de l'inspecteur, et --cpu-prof écrit un profil dans un fichier à la sortie du processus :

1# Démarrer NestJS avec l'inspecteur
2node --inspect dist/main.js
3
4# Ouvre ensuite dans Chrome : chrome://inspect
5# Clique sur "Open dedicated DevTools for Node"
6# Dans l'onglet "Performance" :
7# 1. Clique sur "Record"
8# 2. Effectue des opérations sur l'API (envoie des requêtes)
9# 3. Clique sur "Stop"
10# 4. Analyse le flame graph
11
12# Ou enregistre un profil CPU dans un fichier à la sortie du processus
13node --cpu-prof dist/main.js

L'ancien panneau JavaScript Profiler a disparu de Chrome dans la version 124, c'est pourquoi tu profiles Node.js dans l'onglet Performance.

Le même profileur se pilote depuis le code avec le module node:inspector :

1// Profilage CPU depuis le code
2import { Session } from 'node:inspector';
3import { writeFileSync } from 'node:fs';
4
5class CpuProfiler {
6  private session: Session;
7
8  constructor() {
9    this.session = new Session();
10    this.session.connect();
11  }
12
13  async startProfiling(): Promise<void> {
14    await new Promise<void>((resolve) => {
15      this.session.post('Profiler.enable', () => {
16        this.session.post('Profiler.start', () => {
17          console.log('Profiling CPU started...');
18          resolve();
19        });
20      });
21    });
22  }
23
24  async stopProfiling(filename: string): Promise<void> {
25    return new Promise((resolve) => {
26      this.session.post('Profiler.stop', (err, params) => {
27        // En cas d'erreur, params vaut undefined - ne le déstructure pas à l'aveugle
28        if (!err) {
29          writeFileSync(filename, JSON.stringify(params.profile));
30          console.log('Profil CPU enregistré dans : ' + filename);
31        }
32        resolve();
33      });
34    });
35  }
36}
37
38// Utilisation :
39// const profiler = new CpuProfiler();
40// await profiler.startProfiling();
41// ... effectue des opérations ...
42// await profiler.stopProfiling('cpu-profile.cpuprofile');
43// Ouvre le fichier dans Chrome DevTools -> Performance

Session se connecte à l'inspecteur du processus courant, et post() lui envoie des commandes. La correction concerne stopProfiling() : en cas d'erreur, le deuxième argument du callback vaut undefined, donc l'ancienne déstructuration { profile } faisait planter le processus. Depuis Node.js 19, il existe aussi node:inspector/promises avec des méthodes qui renvoient des promesses.

Flame Graphs - visualiser les points chauds

Un flame graph montre quelles fonctions prennent le plus de temps CPU, comme une carte de bataille qui montre où se livrent les combats les plus durs :

1# Comment lire un flame graph :
2# - largeur du bloc = fréquence de la fonction sur la pile (plus large = plus de CPU)
3# - hauteur = profondeur de la pile d'appels ; l'axe X n'est pas le temps
4# - bord supérieur = fonctions en train de travailler sur le CPU
5# - cherche les blocs larges et plats en haut : ce sont les goulots d'étranglement !
6
7# Générer un flame graph avec clinic.js (le projet n'est plus activement maintenu)
8npm install -g clinic
9
10# 1. clinic doctor - diagnostic général
11clinic doctor -- node dist/main.js
12# (dans un second terminal : npx autocannon -c 100 -d 10 http://localhost:3000/legions)
13# Ctrl+C -> ouvre un rapport HTML
14
15# 2. clinic flame - flame graph
16clinic flame -- node dist/main.js
17
18# 3. clinic bubbleprof - analyse des opérations async (par ex. des requêtes à la base)
19clinic bubbleprof -- node dist/main.js
20
21# Une alternative maintenue : 0x
22npx 0x dist/main.js

Le dépôt de Clinic.js prévient que le projet n'est pas activement maintenu et que ses résultats peuvent être inexacts, d'où 0x comme alternative. L'ancienne version de cette leçon disait de chercher les blocs larges en bas et de lire le rouge comme le chemin chaud, mais le bas du graphique contient toujours de larges fonctions parentes, et la couleur des flame graphs classiques est aléatoire : ce qui compte, c'est la largeur sur le bord supérieur.

Heap Snapshots - analyse de la mémoire

Un heap snapshot est un instantané de tout le tas, comme un recensement de l'Empire qui montre qui occupe combien de place :

1// heap-snapshot.service.ts
2import { Injectable, Logger } from '@nestjs/common';
3import * as v8 from 'node:v8';
4
5@Injectable()
6export class HeapSnapshotService {
7  private readonly logger = new Logger(HeapSnapshotService.name);
8
9  // Faire un instantané du tas (de façon synchrone - il bloque l'event loop !)
10  takeSnapshot(filename?: string): string {
11    const snapshotFile = filename ||
12      'heap-' + new Date().toISOString().replace(/[:.]/g, '-') + '.heapsnapshot';
13
14    const writtenFile = v8.writeHeapSnapshot(snapshotFile);
15    this.logger.log('Heap snapshot enregistré : ' + writtenFile);
16
17    return writtenFile;
18  }
19
20  // Récupérer les statistiques du heap
21  getHeapStatistics() {
22    const stats = v8.getHeapStatistics();
23    return {
24      totalHeapSize: Math.round(stats.total_heap_size / 1024 / 1024) + ' MB',
25      usedHeapSize: Math.round(stats.used_heap_size / 1024 / 1024) + ' MB',
26      heapSizeLimit: Math.round(stats.heap_size_limit / 1024 / 1024) + ' MB',
27      mallocedMemory: Math.round(stats.malloced_memory / 1024 / 1024) + ' MB',
28      usagePercent: ((stats.used_heap_size / stats.heap_size_limit) * 100).toFixed(1) + '%',
29    };
30  }
31
32  // Comparer les statistiques du tas avant et après une opération
33  async compareHeapUsage(operation: () => Promise<unknown>) {
34    const before = v8.getHeapStatistics();
35    await operation();
36    const after = v8.getHeapStatistics();
37
38    const diff = {
39      heapGrowth: after.used_heap_size - before.used_heap_size,
40      // Un nombre croissant de contextes (par ex. issus du module vm) est un autre type de fuite
41      nativeContextGrowth: after.number_of_native_contexts - before.number_of_native_contexts,
42    };
43
44    if (diff.heapGrowth > 10 * 1024 * 1024) { // > 10MB growth
45      this.logger.warn('Fuite mémoire potentielle ! Le heap a augmenté de ' +
46        Math.round(diff.heapGrowth / 1024 / 1024) + ' MB');
47    }
48
49    return diff;
50  }
51}

v8.writeHeapSnapshot() renvoie le nom du fichier écrit, et non un flux. L'instantané est synchrone et bloque l'event loop, et selon la documentation de Node.js il demande environ deux fois plus de mémoire que n'en occupe le tas : dans le test, un tas de 40 MB a donné un fichier de 78 MB. Ne l'expose donc pas par un endpoint public : il peut bloquer la production, et l'instantané contient des secrets présents en mémoire. Tu compares deux instantanés dans l'onglet Memory des DevTools ; compareHeapUsage() ne fait qu'une comparaison rapide des statistiques.

Identifier les goulots d'étranglement - un workflow pratique

Voici le workflow de diagnostic qu'utilise un ingénieur expérimenté de l'Empire :

1// performance-diagnostic.service.ts
2import { Injectable, Logger } from '@nestjs/common';
3
4@Injectable()
5export class PerformanceDiagnosticService {
6  private readonly logger = new Logger('PerformanceDiagnostic');
7
8  // Étape 1 : mesurer le temps des endpoints
9  async measureEndpoint(name: string, operation: () => Promise<any>) {
10    const start = process.hrtime.bigint();
11    const result = await operation();
12    const end = process.hrtime.bigint();
13    const durationMs = Number(end - start) / 1_000_000;
14
15    this.logger.log(name + ': ' + durationMs.toFixed(2) + 'ms');
16
17    if (durationMs > 200) {
18      this.logger.warn(name + ' dépasse 200ms - optimisation nécessaire !');
19    }
20
21    return { result, durationMs };
22  }
23
24  // Étape 2 : vérifier l'utilisation de la mémoire
25  checkMemoryUsage() {
26    const usage = process.memoryUsage();
27    return {
28      rss: Math.round(usage.rss / 1024 / 1024) + ' MB',
29      heapUsed: Math.round(usage.heapUsed / 1024 / 1024) + ' MB',
30      heapTotal: Math.round(usage.heapTotal / 1024 / 1024) + ' MB',
31      external: Math.round(usage.external / 1024 / 1024) + ' MB',
32    };
33  }
34
35  // Étape 3 : surveiller le retard de l'event loop
36  measureEventLoopDelay(): Promise<number> {
37    return new Promise((resolve) => {
38      const start = Date.now();
39      setImmediate(() => {
40        const delay = Date.now() - start;
41        if (delay > 10) {
42          this.logger.warn('Event loop delay: ' + delay + 'ms');
43        }
44        resolve(delay);
45      });
46    });
47  }
48
49  // Étape 4 : rapport de diagnostic complet
50  async generateDiagnosticReport() {
51    const memory = this.checkMemoryUsage();
52    const eventLoopDelay = await this.measureEventLoopDelay();
53    const uptime = process.uptime();
54
55    return {
56      timestamp: new Date().toISOString(),
57      uptime: Math.round(uptime) + 's',
58      memory,
59      eventLoopDelay: eventLoopDelay + 'ms',
60      nodeVersion: process.version,
61      platform: process.platform,
62    };
63  }
64}

process.hrtime.bigint() mesure le temps en nanosecondes, sans être affecté par les changements de l'horloge système. Une mesure via setImmediate n'est qu'un échantillon ponctuel ; la surveillance continue vient de l'histogramme monitorEventLoopDelay() de la leçon sur la mémoire.

Je te recommande un ordre fixe : un benchmark établit la référence, un profil montre la cause, et après la correction le même benchmark confirme l'effet. Dans le module suivant, nous emmènerons en production le fort mesuré et allégé.

Retiens la règle du préteur Auguste : n'optimise pas ce que tu n'as pas mesuré.

Code de cette leçon : src/profiling-benchmarking.ts
1// Profiling et Benchmarking NestJS
2import { Injectable, Logger } from '@nestjs/common';
3
4// ===========================================
5// 1. Performance Measurement
6// ===========================================
7
8@Injectable()
9class PerformanceDiagnostic {
10  private readonly logger = new Logger('Diagnostic');
11
12  async measureEndpoint(name: string, operation: () => Promise<any>) {
13    const start = process.hrtime.bigint();
14    const result = await operation();
15    const end = process.hrtime.bigint();
16    const durationMs = Number(end - start) / 1_000_000;
17
18    console.log(name + ': ' + durationMs.toFixed(2) + 'ms');
19
20    if (durationMs > 200) {
21      console.warn(name + ' dépasse 200ms !');
22    }
23
24    return { result, durationMs };
25  }
26
27  checkMemoryUsage() {
28    const usage = process.memoryUsage();
29    return {
30      rss: Math.round(usage.rss / 1024 / 1024) + ' MB',
31      heapUsed: Math.round(usage.heapUsed / 1024 / 1024) + ' MB',
32      heapTotal: Math.round(usage.heapTotal / 1024 / 1024) + ' MB',
33    };
34  }
35
36  measureEventLoopDelay(): Promise<number> {
37    return new Promise((resolve) => {
38      const start = Date.now();
39      setImmediate(() => {
40        resolve(Date.now() - start);
41      });
42    });
43  }
44}
45
46// ===========================================
47// 2. Heap Statistics (v8)
48// ===========================================
49
50// import * as v8 from 'v8';
51// const stats = v8.getHeapStatistics();
52// {
53//   total_heap_size: ...,
54//   used_heap_size: ...,
55//   heap_size_limit: ...,
56// }
57
58// Heap Snapshot:
59// v8.writeHeapSnapshot('heap.heapsnapshot');
60// Ouvrir dans Chrome DevTools -> Memory
61
62// ===========================================
63// 3. Demonstration
64// ===========================================
65
66const diagnostic = new PerformanceDiagnostic();
67const memory = diagnostic.checkMemoryUsage();
68
69console.log('=== Profiling & Benchmarking ===');
70console.log('Mémoire :', JSON.stringify(memory));
71console.log('');
72console.log('Outils :');
73console.log('  autocannon - load testing (req/sec, latency)');
74console.log('  node --inspect - CPU profiling dans Chrome');
75console.log('  clinic.js - flame graphs, doctor, bubbleprof');
76console.log('  v8.writeHeapSnapshot() - dump mémoire');
77console.log('  process.hrtime.bigint() - mesure du temps');
78console.log('');
79console.log('Workflow:');
80console.log('  1. Mesurer (autocannon)');
81console.log('  2. Profiler (clinic flame)');
82console.log('  3. Identifier le bottleneck');
83console.log('  4. Corriger');
84console.log('  5. Mesurer à nouveau');
85

Tu as repéré une erreur dans cette leçon ?