From 135afac87bf55f8dedc422191cd65bffe7f8f4d0 Mon Sep 17 00:00:00 2001 From: Nigro Simone Date: Sat, 1 Aug 2026 07:04:44 +0200 Subject: [PATCH 1/2] benchmark: set NODE_ENV and stop dropping wrk errors on the floor Three ways the harness could publish a number that does not mean what it says. NODE_ENV is never set for the benchmark step. art-template keys `debug` off process.env.NODE_ENV, and in debug mode it forces cache:false and re-reads and recompiles the view from disk on every request, so engines/art spends most of its time in the template compiler on both frameworks. The same variable also decides express 4's view cache in defaultConfiguration(), which a later app.set('env', 'production') does not revisit - so the harness setting only took effect on uExpress and the row was asymmetric on top of being dominated by dead work. Set on the step rather than the job so npm install still pulls devDependencies. A missing `-s` script does not make wrk fail. It falls back to GET / on the target URL, which is how readable-hash-4mb published a 404 for 34 consecutive runs at an implied 112 GB/sec of upload. Check the script exists before running. wrk's error lines were parsed into `wrkErrors` and then only ever used in a message that could not be reached: the sole gate was requestsPerSec === 0, and a run answering 404 to every request still reports a perfectly healthy Requests/sec. Non-2xx/3xx responses now fail the run. Response validation had the same problem one level up - it ran, printed to stderr and was stored on the row, but buildMarkdown never read it, so a scenario where the two servers returned different bodies still rendered as a clean row. It now marks the row and gets a section under the table, as do socket errors, which are reported rather than failed since keep-alive teardown can produce a few legitimately. --- .github/workflows/benchmark.yml | 6 +++ benchmark/run.js | 91 +++++++++++++++++++++++++++++---- 2 files changed, 87 insertions(+), 10 deletions(-) diff --git a/.github/workflows/benchmark.yml b/.github/workflows/benchmark.yml index c381d11c..80174cd2 100644 --- a/.github/workflows/benchmark.yml +++ b/.github/workflows/benchmark.yml @@ -39,6 +39,12 @@ jobs: sudo apt-get install -y wrk - name: Run benchmark suite + # without this, template engines run in debug mode and recompile the view on every request, + # and express 4 decides its view cache from NODE_ENV in defaultConfiguration() so + # app.set('env', 'production') in the harness only takes effect on uExpress. + # set on the step, not the job, so npm install still pulls devDependencies + env: + NODE_ENV: production run: npm run benchmark:compare -- --duration 20 --output benchmark_summary.md - name: Upload benchmark markdown artifact diff --git a/benchmark/run.js b/benchmark/run.js index 9087a7d7..8d8eaa96 100644 --- a/benchmark/run.js +++ b/benchmark/run.js @@ -231,17 +231,32 @@ function parseTransferPerSec(output) { return value; } -function parseErrorLines(output) { - const errorLines = []; +function parseWrkErrors(output) { + const errors = { + lines: [], + socketErrorLine: null, + non2xx: 0, + totalRequests: 0 + }; + + const totalMatch = output.match(/([0-9]+)\s+requests\s+in\s/); + if (totalMatch) { + errors.totalRequests = Number(totalMatch[1]); + } + const socketErrorMatch = output.match(/Socket errors:[^\n]+/); if (socketErrorMatch) { - errorLines.push(socketErrorMatch[0]); + errors.lines.push(socketErrorMatch[0]); + errors.socketErrorLine = socketErrorMatch[0]; } - const non2xxMatch = output.match(/Non-2xx or 3xx responses:\s+[0-9]+/); + + const non2xxMatch = output.match(/Non-2xx or 3xx responses:\s+([0-9]+)/); if (non2xxMatch) { - errorLines.push(non2xxMatch[0]); + errors.lines.push(non2xxMatch[0]); + errors.non2xx = Number(non2xxMatch[1]); } - return errorLines; + + return errors; } function formatReqPerSec(value) { @@ -276,7 +291,13 @@ async function runScenario(framework, scenarioName, scenario, durationSeconds) { ]; if (wrk.script) { - args.push('-s', path.join(__dirname, 'wrk-scripts', wrk.script)); + const scriptPath = path.join(__dirname, 'wrk-scripts', wrk.script); + // a missing -s script does not make wrk fail, it silently falls back to GET / on the + // target URL. that is how readable-hash-4mb measured a 404 for 34 published runs + if (!fs.existsSync(scriptPath)) { + throw new Error(`wrk script for ${scenarioName} does not exist: ${scriptPath}`); + } + args.push('-s', scriptPath); } const targetUrl = wrk.script @@ -295,17 +316,27 @@ async function runScenario(framework, scenarioName, scenario, durationSeconds) { const requestsPerSec = parseRequestsPerSec(wrkResult.stdout); const transferPerSecBytes = parseTransferPerSec(wrkResult.stdout); - const wrkErrors = parseErrorLines(wrkResult.stdout); + const wrkErrors = parseWrkErrors(wrkResult.stdout); if (requestsPerSec === 0) { throw new Error( - `wrk produced invalid benchmark output for ${framework.id}/${scenarioName}:\n${wrkErrors.join('\n')}\n\n${wrkResult.stdout}` + `wrk produced invalid benchmark output for ${framework.id}/${scenarioName}:\n${wrkErrors.lines.join('\n')}\n\n${wrkResult.stdout}` + ); + } + + // a run that answered anything other than 2xx/3xx did not measure the scenario. this used to + // be parsed and then dropped on the floor, so a broken scenario still published a number + if (wrkErrors.non2xx > 0) { + throw new Error( + `${framework.id}/${scenarioName} served ${wrkErrors.non2xx} non-2xx/3xx responses out of ` + + `${wrkErrors.totalRequests}, so this run measured something other than the scenario:\n${wrkResult.stdout}` ); } return { requestsPerSec, transferPerSecBytes, + socketErrorLine: wrkErrors.socketErrorLine, raw: wrkResult.stdout }; } finally { @@ -322,6 +353,8 @@ function buildMarkdown(results) { lines.push('| --- | ---: | ---: | ---: | ---: | ---: |'); const failures = []; + const unvalidated = []; + const socketErrors = []; for (const row of results) { const speedup = row.express.ok && row.ultimate.ok && row.express.transferPerSecBytes > 0 ? `${(row.ultimate.transferPerSecBytes / row.express.transferPerSecBytes).toFixed(2)}x` @@ -346,11 +379,49 @@ function buildMarkdown(results) { }); } + // the two servers are only comparable if they answered the same thing. this was computed and + // then never rendered, so a scenario where they diverged still looked like a clean row + if (!row.validation || !row.validation.ok) { + unvalidated.push({ + scenario: row.name, + message: row.validation ? row.validation.message : 'validation did not run' + }); + } + + for (const [framework, result] of [['express', row.express], ['ultimate-express', row.ultimate]]) { + if (result.ok && result.socketErrorLine) { + socketErrors.push({ scenario: row.name, framework, message: result.socketErrorLine }); + } + } + + const marker = (!row.validation || !row.validation.ok) ? ' :warning:' : ''; lines.push( - `| ${row.name} | ${expressReq} | ${ultimateReq} | ${expressTransfer} | ${ultimateTransfer} | **${speedup}** |` + `| ${row.name}${marker} | ${expressReq} | ${ultimateReq} | ${expressTransfer} | ${ultimateTransfer} | **${speedup}** |` ); } + if (unvalidated.length > 0) { + lines.push(''); + lines.push(`> :warning: ${unvalidated.length} scenario(s) did not pass response validation: express and uExpress did not return the same status and body, so their numbers are not comparable.`); + lines.push(''); + lines.push('### Failed Response Validation'); + lines.push(''); + for (const entry of unvalidated) { + lines.push(`- \`${entry.scenario}\`\n\`\`\`\n${entry.message}\n\`\`\``); + } + } + + if (socketErrors.length > 0) { + lines.push(''); + lines.push(`> ${socketErrors.length} run(s) reported socket errors. Throughput measured alongside socket errors reflects the load generator as much as the server.`); + lines.push(''); + lines.push('### Socket Errors'); + lines.push(''); + for (const entry of socketErrors) { + lines.push(`- \`${entry.scenario}\` on \`${entry.framework}\`: ${entry.message}`); + } + } + if (failures.length > 0) { lines.push(''); lines.push(`> Warning: ${failures.length} benchmark run(s) failed. See details below.`); From 5caafb8ed62247571a384b104702bcac72e99479 Mon Sep 17 00:00:00 2001 From: Nigro Simone Date: Sat, 1 Aug 2026 07:32:27 +0200 Subject: [PATCH 2/2] benchmark: mark the rows whose ratio is capped by shared work Five rows sit at 0.94x-1.15x and read as "the two frameworks are equivalent", when what they actually say is that the scenario spends its budget somewhere neither framework is involved. body-json-512kb is JSON.parse and utf8 decode of half a megabyte; the two streaming rows are per-byte copying of a 5 MiB response; readable-hash-4mb is OpenSSL sha256 over 4 MiB; compression-file is zlib, reached through the same middleware on both sides. Those ratios are capped by arithmetic - roughly 1.01x for the streaming rows and 1.02x for the JSON one - so no amount of work on either framework moves them. Scenarios can now declare what bounds them, and the table marks those rows and explains them underneath. Keeping them and labelling them is the point. Dropping them would make the table look curated, and they are real workloads even if they do not discriminate. --- benchmark/run.js | 22 ++++++++++++++++++- benchmark/scenarios/body-json-512kb.js | 4 ++++ benchmark/scenarios/compression-small-file.js | 3 +++ benchmark/scenarios/readable-hash-4mb.js | 4 ++++ .../streaming-with-content-length.js | 4 ++++ .../streaming-without-content-length.js | 4 ++++ 6 files changed, 40 insertions(+), 1 deletion(-) diff --git a/benchmark/run.js b/benchmark/run.js index 8d8eaa96..7bc838f3 100644 --- a/benchmark/run.js +++ b/benchmark/run.js @@ -355,6 +355,7 @@ function buildMarkdown(results) { const failures = []; const unvalidated = []; const socketErrors = []; + const bounded = []; for (const row of results) { const speedup = row.express.ok && row.ultimate.ok && row.express.transferPerSecBytes > 0 ? `${(row.ultimate.transferPerSecBytes / row.express.transferPerSecBytes).toFixed(2)}x` @@ -394,12 +395,30 @@ function buildMarkdown(results) { } } - const marker = (!row.validation || !row.validation.ok) ? ' :warning:' : ''; + // some scenarios are dominated by work both frameworks hand to the same library, so their + // ratio is capped no matter how fast either framework is. mark them instead of letting the + // number read as "the frameworks are equivalent" + if (row.bound) { + bounded.push({ scenario: row.name, by: row.bound.by, ceiling: row.bound.ceiling }); + } + + const marker = + ((!row.validation || !row.validation.ok) ? ' :warning:' : '') + + (row.bound ? ' †' : ''); lines.push( `| ${row.name}${marker} | ${expressReq} | ${ultimateReq} | ${expressTransfer} | ${ultimateTransfer} | **${speedup}** |` ); } + if (bounded.length > 0) { + lines.push(''); + lines.push('† These rows are dominated by work neither framework performs itself, so the ratio is capped regardless of how fast either one is. They are kept because they are real workloads, not because they discriminate between the two.'); + lines.push(''); + for (const entry of bounded) { + lines.push(`- \`${entry.scenario}\`: ${entry.by}${entry.ceiling ? ` — ceiling ${entry.ceiling}` : ''}`); + } + } + if (unvalidated.length > 0) { lines.push(''); lines.push(`> :warning: ${unvalidated.length} scenario(s) did not pass response validation: express and uExpress did not return the same status and body, so their numbers are not comparable.`); @@ -497,6 +516,7 @@ async function main() { results.push({ name: scenario.name, + bound: scenario.bound || null, validation, express: expressResult, ultimate: ultimateResult diff --git a/benchmark/scenarios/body-json-512kb.js b/benchmark/scenarios/body-json-512kb.js index 1b8c6da6..b26745ae 100644 --- a/benchmark/scenarios/body-json-512kb.js +++ b/benchmark/scenarios/body-json-512kb.js @@ -8,6 +8,10 @@ const PAD = 512 * 1024; module.exports = { name: 'middlewares/body-json-512kb', path: '/abc', + bound: { + by: 'JSON.parse and utf8 decode of a 512 KiB body, which both frameworks hand to the same V8 primitive', + ceiling: '~1.02x' + }, wrk: { script: 'post-json-512kb.lua', connections: 50 diff --git a/benchmark/scenarios/compression-small-file.js b/benchmark/scenarios/compression-small-file.js index 83b7b1bd..5bb3257d 100644 --- a/benchmark/scenarios/compression-small-file.js +++ b/benchmark/scenarios/compression-small-file.js @@ -5,6 +5,9 @@ const compression = require('compression'); module.exports = { name: 'middlewares/compression-file', path: '/small-file', + bound: { + by: 'zlib deflate through the same compression middleware on both sides' + }, wrk: { script: 'compression-small-file.lua', connections: 200 diff --git a/benchmark/scenarios/readable-hash-4mb.js b/benchmark/scenarios/readable-hash-4mb.js index 31a2e308..728466ed 100644 --- a/benchmark/scenarios/readable-hash-4mb.js +++ b/benchmark/scenarios/readable-hash-4mb.js @@ -3,6 +3,10 @@ module.exports = { name: 'streaming/readable-hash-4mb', path: '/hash-body', + bound: { + by: 'OpenSSL sha256 over a 4 MiB body, which is most of the per-request budget', + ceiling: '~1.1x-1.4x' + }, wrk: { script: 'post-hash-body-4mb.lua', connections: 50 diff --git a/benchmark/scenarios/streaming-with-content-length.js b/benchmark/scenarios/streaming-with-content-length.js index 6dd7ba53..d9544506 100644 --- a/benchmark/scenarios/streaming-with-content-length.js +++ b/benchmark/scenarios/streaming-with-content-length.js @@ -3,6 +3,10 @@ module.exports = { name: 'streaming/writable-with-content-length', path: '/stream-with-content-length', + bound: { + by: 'loopback bandwidth for a 5 MiB response, so nearly all of the budget is per-byte copying', + ceiling: '~1.01x' + }, wrk: { connections: 50 }, diff --git a/benchmark/scenarios/streaming-without-content-length.js b/benchmark/scenarios/streaming-without-content-length.js index 20ff0c4a..ce056b76 100644 --- a/benchmark/scenarios/streaming-without-content-length.js +++ b/benchmark/scenarios/streaming-without-content-length.js @@ -3,6 +3,10 @@ module.exports = { name: 'streaming/writable-no-content-length', path: '/stream-without-content-length', + bound: { + by: 'loopback bandwidth for a 5 MiB response, so nearly all of the budget is per-byte copying', + ceiling: '~1.01x' + }, wrk: { connections: 50 },