From ec2f1d9de21357fc25d1d5eb42d9590470696cef Mon Sep 17 00:00:00 2001 From: Buuh Uchiha Date: Sun, 25 Oct 2026 08:06:35 -0300 Subject: [PATCH] benchmark: report latency percentiles in http benchmarks The http benchmarks only reported throughput, although autocannon already computes latency percentiles and wrk can print them. Tail latency under load is invisible in the results, so changes that affect it cannot be measured with the benchmark suite. Parse p50, p90, p99 and p99.9 from autocannon, wrk (with --latency) and the test double, pass them along as an optional `latency` field of the report, and print them in the simple output format. The CSV output and the comparison tools are unchanged. Signed-off-by: Buuh Uchiha --- benchmark/_http-benchmarkers.js | 33 ++++++++++++++++++- benchmark/_test-double-benchmarker.js | 20 ++++++++++- benchmark/common.js | 27 +++++++++++---- benchmark/run.js | 8 ++++- .../writing-and-running-benchmarks.md | 12 +++++++ 5 files changed, 91 insertions(+), 9 deletions(-) diff --git a/benchmark/_http-benchmarkers.js b/benchmark/_http-benchmarkers.js index b9ef93c149f7..a189666d6d4d 100644 --- a/benchmark/_http-benchmarkers.js +++ b/benchmark/_http-benchmarkers.js @@ -56,6 +56,17 @@ class AutocannonBenchmarker { } return result.requests.average; } + + processLatency(output) { + // Autocannon records latencies in whole milliseconds. + const { latency } = JSON.parse(output); + return { + p50: latency.p50, + p90: latency.p90, + p99: latency.p99, + p99_9: latency.p99_9, + }; + } } class WrkBenchmarker { @@ -72,6 +83,7 @@ class WrkBenchmarker { options.duration; const scheme = options.scheme || 'http'; const args = [ + '--latency', '-d', duration, '-c', options.connections, '-t', Math.min(options.connections, require('os').availableParallelism() || 8), @@ -93,6 +105,20 @@ class WrkBenchmarker { } return throughput; } + + processLatency(output) { + // Lines of the "Latency Distribution" table printed with --latency, + // e.g. " 99% 1.05ms". + const lineRe = /^\s+(\d+(?:\.\d+)?)%\s+([0-9.]+)(us|ms|s)$/gm; + const unitToMs = { us: 1e-3, ms: 1, s: 1e3 }; + const keys = { '50': 'p50', '90': 'p90', '99': 'p99', '99.9': 'p99_9' }; + const latency = {}; + for (const [, percentile, value, unit] of output.matchAll(lineRe)) { + const key = keys[String(Number(percentile))]; + if (key) latency[key] = Number(value) * unitToMs[unit]; + } + return Object.keys(latency).length > 0 ? latency : undefined; + } } /** @@ -133,6 +159,10 @@ class TestDoubleBenchmarker { } return result.throughput; } + + processLatency(output) { + return JSON.parse(output).latency; + } } /** @@ -259,8 +289,9 @@ exports.run = function(options, callback) { return; } + const latency = benchmarker.processLatency?.(stdout); const elapsed = benchmark_end - benchmarker_start; - callback(null, code, options.benchmarker, result, elapsed); + callback(null, code, options.benchmarker, result, elapsed, latency); }); }; diff --git a/benchmark/_test-double-benchmarker.js b/benchmark/_test-double-benchmarker.js index 2d05f9fd92be..ccaa555fb8c7 100644 --- a/benchmark/_test-double-benchmarker.js +++ b/benchmark/_test-double-benchmarker.js @@ -11,24 +11,41 @@ if (myModule === 'https') { } const http = require(myModule); +const { createHistogram } = require('perf_hooks'); const duration = +process.env.duration; const url = process.env.test_url; const start = process.hrtime(); let throughput = 0; +const latencies = createHistogram(); +let requestStart; + +function latencyInMs() { + if (latencies.count === 0) { + return undefined; + } + const toMs = (ns) => ns / 1e6; + return { + p50: toMs(latencies.percentile(50)), + p90: toMs(latencies.percentile(90)), + p99: toMs(latencies.percentile(99)), + p99_9: toMs(latencies.percentile(99.9)), + }; +} function request(res, client) { res.resume(); res.on('error', () => {}); res.on('end', () => { throughput++; + latencies.record(process.hrtime.bigint() - requestStart); const [sec, nanosec] = process.hrtime(start); const ms = sec * 1000 + nanosec / 1e6; if (ms < duration * 1000) { run(); } else { - console.log(JSON.stringify({ throughput })); + console.log(JSON.stringify({ throughput, latency: latencyInMs() })); if (client) { client.destroy(); process.exit(0); @@ -38,6 +55,7 @@ function request(res, client) { } function run() { + requestStart = process.hrtime.bigint(); if (http.get) { // HTTP or HTTPS if (options) { http.get(url, options, request); diff --git a/benchmark/common.js b/benchmark/common.js index 734c664c80f5..12bcabf1c49f 100644 --- a/benchmark/common.js +++ b/benchmark/common.js @@ -183,7 +183,7 @@ class Benchmark { this.extra_options.benchmarker || http_benchmarkers.default_http_benchmarker; http_benchmarkers.run( - http_options, (error, code, used_benchmarker, result, elapsed) => { + http_options, (error, code, used_benchmarker, result, elapsed, latency) => { if (cb) { cb(code); } @@ -192,7 +192,7 @@ class Benchmark { process.exit(code || 1); } this.config.benchmarker = used_benchmarker; - this.report(result, elapsed); + this.report(result, elapsed, latency); }, ); } @@ -319,14 +319,19 @@ class Benchmark { this.report(rate, elapsed); } - report(rate, elapsed) { - sendResult({ + report(rate, elapsed, latency) { + const data = { name: this.name, conf: this.config, rate, time: nanoSecondsToString(elapsed), type: 'report', - }); + }; + // Latency percentiles in milliseconds, only reported by HTTP benchmarks. + if (latency !== undefined) { + data.latency = latency; + } + sendResult(data); } } @@ -349,7 +354,17 @@ function formatResult(data) { let rate = data.rate.toString().split('.'); rate[0] = rate[0].replace(/(\d)(?=(?:\d\d\d)+(?!\d))/g, '$1,'); rate = (rate[1] ? rate.join('.') : rate[0]); - return `${data.name}${conf}: ${rate}\n`; + return `${data.name}${conf}: ${rate}${formatLatency(data.latency)}\n`; +} + +function formatLatency(latency) { + if (latency === undefined) { + return ''; + } + const percentiles = Object.entries(latency) + .map(([key, ms]) => `${key.slice(1).replace('_', '.')}%=${+ms.toFixed(3)}`) + .join(' '); + return ` (latency ms: ${percentiles})`; } function sendResult(data) { diff --git a/benchmark/run.js b/benchmark/run.js index 455ddc4f2dfc..dae412a72e4c 100644 --- a/benchmark/run.js +++ b/benchmark/run.js @@ -86,7 +86,13 @@ function runBenchmark(filename) { let rate = data.rate.toString().split('.'); rate[0] = rate[0].replace(/(\d)(?=(?:\d\d\d)+(?!\d))/g, '$1,'); rate = (rate[1] ? rate.join('.') : rate[0]); - console.log(`${data.name} ${conf}: ${rate}`); + let latency = ''; + if (data.latency !== undefined) { + latency = ' (latency ms: ' + Object.entries(data.latency) + .map(([key, ms]) => `${key.slice(1).replace('_', '.')}%=${+ms.toFixed(3)}`) + .join(' ') + ')'; + } + console.log(`${data.name} ${conf}: ${rate}${latency}`); } }); child.once('close', (code) => { diff --git a/doc/contributing/writing-and-running-benchmarks.md b/doc/contributing/writing-and-running-benchmarks.md index bf397c123a24..8c7bff68c011 100644 --- a/doc/contributing/writing-and-running-benchmarks.md +++ b/doc/contributing/writing-and-running-benchmarks.md @@ -55,6 +55,18 @@ node benchmark/run.js --set benchmarker=autocannon http node benchmark/http/simple.js benchmarker=autocannon ``` +Besides the throughput, HTTP benchmarks report the latency percentiles +measured by the benchmarker, in milliseconds: + +```console +http/simple.js c=500 benchmarker="autocannon": 16,217.34 (latency ms: 50%=28 90%=34 99%=257 99.9%=270) +``` + +The resolution depends on the benchmarker: `autocannon` records whole +milliseconds, `wrk` reports microseconds and does not print the 99.9th +percentile, and `h2load` reports no percentiles. The CSV output and the +comparison tools only use the throughput. + #### HTTPS benchmark requirements To run the `https` benchmarks, one of `autocannon` or `wrk` benchmarkers must