NestJS course · Module 8: Caching and Performance
Profiling and Benchmarking NestJS - diagnosing the Empire's power
In this lesson5
Commander of the legions! After a deployment users write that "it is slower", and the team argues whether the database, the new interceptor or serialization is to blame. Everyone has a theory, nobody has numbers. Even the best-trained Roman army needs regular inspections - in NestJS profiling and benchmarking are that inspection: you diagnose where the application loses time, memory and resources.
Benchmarking with autocannon
autocannon is a load testing tool - like sending thousands of messengers at once to check the capacity of the Empire's roads:
1# -c 100 = 100 concurrent connections (100 messengers at once)
2# -d 10 = the test lasts 10 seconds
3# -p 10 = 10 pipelined requests per connection - inflates results, use with care
4
5# Load test without installing, through npx
6npx autocannon -c 100 -d 10 http://localhost:3000/legions-c sets the number of concurrent connections, and -d the test duration in seconds. This is the result of a single run on a laptop, for an endpoint returning 20 legions:
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 readThe first table shows latency in percentiles, the second requests and bytes per second, with different columns. Your numbers will differ, because they depend on the hardware. The same test with -p 10 raised requests per second by about 18%, but the average latency from 5.4 to 50 ms, because requests waited in the connection's queue; browsers do not use pipelining, so leave it alone.
Autocannon also works from code, which lets you plug a benchmark into tests:
1// benchmark.ts - using autocannon from code
2import autocannon from 'autocannon';
3
4async function runBenchmark() {
5 const result = await autocannon({
6 url: 'http://localhost:3000/legions',
7 connections: 100, // 100 concurrent connections
8 duration: 10, // 10 seconds of testing
9 headers: {
10 'Authorization': 'Bearer test-token',
11 },
12 });
13
14 console.log('=== Benchmark Results ===');
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 // Success criteria
23 if (result.latency.p99 > 200) {
24 console.warn('WARNING: p99 latency exceeds 200ms!');
25 }
26 if (result.errors > 0) {
27 console.error('ERROR: errors occurred during the test!');
28 }
29}
30
31runBenchmark();The result includes, among others, requests.average, latency.p99, throughput.average, errors and timeouts. The 200 ms threshold for p99 turns the benchmark into a test that can fail.
Node.js --inspect Profiling
Node.js has a built-in profiler that shows what the CPU is doing. The --inspect flag enables the inspector protocol, and --cpu-prof writes a profile to a file when the process exits:
1# Starting NestJS with the inspector
2node --inspect dist/main.js
3
4# Then open in Chrome: chrome://inspect
5# Click "Open dedicated DevTools for Node"
6# In the "Performance" tab:
7# 1. Click "Record"
8# 2. Perform API operations (send requests)
9# 3. Click "Stop"
10# 4. Analyse the flame graph
11
12# Or save a CPU profile to a file when the process exits
13node --cpu-prof dist/main.jsThe old JavaScript Profiler panel disappeared from Chrome in version 124, which is why you profile Node.js in the Performance tab.
The same profiler can be driven from code through the node:inspector module:
1// CPU profiling from 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 // On error params is undefined - do not destructure it blindly
28 if (!err) {
29 writeFileSync(filename, JSON.stringify(params.profile));
30 console.log('CPU profile saved to: ' + filename);
31 }
32 resolve();
33 });
34 });
35 }
36}
37
38// Usage:
39// const profiler = new CpuProfiler();
40// await profiler.startProfiling();
41// ... perform operations ...
42// await profiler.stopProfiling('cpu-profile.cpuprofile');
43// Open the file in Chrome DevTools -> PerformanceSession connects to the inspector of the current process, and post() sends it commands. The fix concerns stopProfiling(): on error the second callback argument is undefined, so the old { profile } destructuring crashed the process. Since Node.js 19 there is also node:inspector/promises with methods that return promises.
Flame Graphs - visualizing hot spots
A flame graph shows which functions take the most CPU time - like a battle map showing where the heaviest fighting is:
1# How to read a flame graph:
2# - block width = how often the function was on the stack (wider = more CPU)
3# - height = call stack depth; the X axis is not time
4# - top edge = functions running on the CPU at that moment
5# - look for wide flat blocks at the top - those are the bottlenecks!
6
7# Generating a flame graph with clinic.js (the project is no longer actively maintained)
8npm install -g clinic
9
10# 1. clinic doctor - general diagnosis
11clinic doctor -- node dist/main.js
12# (in a second terminal: npx autocannon -c 100 -d 10 http://localhost:3000/legions)
13# Ctrl+C -> opens an HTML report
14
15# 2. clinic flame - flame graph
16clinic flame -- node dist/main.js
17
18# 3. clinic bubbleprof - analysis of async operations (e.g. database queries)
19clinic bubbleprof -- node dist/main.js
20
21# An actively maintained alternative: 0x
22npx 0x dist/main.jsThe Clinic.js repository warns that the project is not actively maintained and its results may be inaccurate, hence 0x as an alternative. The old version of this lesson told you to look for wide blocks at the bottom and to read red as the hot path, but the bottom of the graph always holds wide parent functions, and colour in classic flame graphs is random - what counts is the width at the top edge.
Heap Snapshots - memory analysis
A heap snapshot is a dump of the whole heap - like a census of the Empire showing who takes up how much space:
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 // Take a heap snapshot (synchronously - it blocks the 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 saved: ' + writtenFile);
16
17 return writtenFile;
18 }
19
20 // Get heap statistics
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 // Compare heap statistics before and after an operation
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 // A growing number of contexts (e.g. from the vm module) is a separate kind of leak
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('Potential memory leak! Heap grew by ' +
46 Math.round(diff.heapGrowth / 1024 / 1024) + ' MB');
47 }
48
49 return diff;
50 }
51}v8.writeHeapSnapshot() returns the name of the written file, not a stream. The dump is synchronous and blocks the event loop, and according to the Node.js documentation it needs about twice as much memory as the heap occupies - in the test a 40 MB heap produced a 78 MB file. So do not expose it through a public endpoint: it can stall production, and the dump contains secrets from memory. You compare two dumps in the Memory tab of DevTools; compareHeapUsage() only does a quick comparison of statistics.
Identifying bottlenecks - a practical workflow
Here is the diagnostic workflow an experienced Imperial engineer uses:
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 // Step 1: Measure endpoint time
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 + ' exceeds 200ms - needs optimization!');
19 }
20
21 return { result, durationMs };
22 }
23
24 // Step 2: Check memory usage
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 // Step 3: Monitor event loop delay
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 // Step 4: Full diagnostic report
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() measures time in nanoseconds, unaffected by changes to the system clock. A measurement through setImmediate is only a one-off sample; continuous monitoring comes from the monitorEventLoopDelay() histogram from the memory lesson.
I recommend a fixed order: a benchmark sets the baseline, a profile shows the cause, and after the fix the same benchmark confirms the effect. In the next module we will take the measured and slimmed-down fort to production.
Remember Praetor Augustus's rule: do not optimize what you have not measured.
Code for this lesson: src/profiling-benchmarking.ts
1// Profiling and 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 + ' exceeds 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// Open in 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('Memory:', JSON.stringify(memory));
71console.log('');
72console.log('Tools:');
73console.log(' autoballista - load testing (req/sec, latency)');
74console.log(' node --inspect - CPU profiling in Chrome');
75console.log(' clinic.js - flame graphs, doctor, bubbleprof');
76console.log(' v8.writeHeapSnapshot() - memory dump');
77console.log(' process.hrtime.bigint() - time measurement');
78console.log('');
79console.log('Workflow:');
80console.log(' 1. Measure (autoballista)');
81console.log(' 2. Profile (clinic flame)');
82console.log(' 3. Identify the bottleneck');
83console.log(' 4. Fix');
84console.log(' 5. Measure again');
85Spotted a mistake in this lesson?