Load test ramp up time
Run the same command twice against a freshly started process. Here npx autocannon@8 -c 10 -d 10 http://127.0.0.1:9672/cold reported 28 925 requests a second on the first run and 42 462,55 on the second. The whole difference sits in the first three seconds. -W [ -c 10 -d 4 ] removes it.
Why check this
Two runs of one command against one unchanged service can differ by a quarter. Check the warm-up before comparing any two load test figures, and before accepting a regression that followed a deploy changing nothing.
The failure it prevents is a release blocked on a number that measured process start. It also prevents the opposite: a warm-up discarded on a service whose users arrive during it, which every service has after a deploy.
Generator and target share this machine's eight cores, and loopback has no network in it.
Prerequisites
- Node 22 or later, and
npx autocannon@8, which fetches autocannon on first use. - A free port. Port 9672 is used below.
- The target,
warmup-server.mjs./coldis slow for its first 3 s,/cachecomputes once then serves from memory,/poolmakes every caller wait on one 300 ms setup,/jitrepeats the same small work.
// warmup-server.mjs
import { createServer } from 'node:http';
let log = [], t0 = Date.now(), cache = null, pool = null, ready = false, building = false;
const mark = (d) => { const b = (log[Math.floor((Date.now() - t0) / 1000)] ??= { n: 0, ms: 0 }); b.n += 1; b.ms += d; };
const json = (res, body) => { res.writeHead(200, { 'content-type': 'application/json' }); res.end(body); };
const work = (n) => { let h = 0; for (let i = 0; i < n; i += 1) h = (Math.imul(h, 31) + i) | 0; return h; };
createServer(async (req, res) => {
const u = req.url, began = performance.now();
if (u === '/stats') return json(res, JSON.stringify([...log].map((b, s) => ({ s, n: b?.n ?? 0, ms: b ? +(b.ms / b.n).toFixed(3) : 0 }))));
if (u === '/reset') { t0 = Date.now(); log = []; cache = null; pool = null; ready = false; building = false; return json(res, '{"reset":true}'); }
if (u === '/cache') { if (cache === null) cache = work(60_000_000); }
else if (u === '/pool') { pool ??= new Promise((r) => setTimeout(r, 300)); await pool; }
else if (u === '/cold') {
if (!building) { building = true; setTimeout(() => { ready = true; }, 3000); }
if (!ready) work(3_000_000);
} else work(30_000);
mark(performance.now() - began);
json(res, '{"ok":true}');
}).listen(9672, '127.0.0.1', () => console.log('listening on 9672'));
- The per-request probe,
probe.mjs, sends requests one at a time down one connection and prints each duration.
// probe.mjs <path> <count> [nokeepalive]
import { Agent, request } from 'node:http';
const path = process.argv[2], count = Number(process.argv[3]);
const agent = new Agent({ keepAlive: process.argv[4] !== 'nokeepalive', maxSockets: 1 });
const t = [];
for (let i = 0; i < count; i += 1) {
const began = performance.now();
await new Promise((done) => request({ port: 9672, path, agent }, (res) => { res.resume(); res.on('end', done); }).end());
t.push(performance.now() - began);
}
const mean = (a, b) => (t.slice(a, b).reduce((x, y) => x + y, 0) / (b - a)).toFixed(2);
for (let i = 0; i < Math.min(10, count); i += 1) console.log('request ' + String(i + 1).padStart(4) + ' ' + t[i].toFixed(2) + ' ms');
for (const [a, b] of [[10, 100], [100, 1000], [1000, 5000]]) {
if (count >= b) console.log(('mean ' + (a + 1) + '-' + b).padEnd(15) + mean(a, b) + ' ms');
}
agent.destroy();
- Step 6 needs a process that has served nothing, so it restarts the server. Steps 7 and 8 use that instance.
Steps
- Step 1.
Confirm the port has no listener.
netstat -ano | grep ":9672 " | grep -c LISTENING0 - Step 2.
Start the target.
node warmup-server.mjs > warmup-server.log 2>&1 & sleep 2; netstat -ano | grep ":9672 " | grep LISTENINGTCP 127.0.0.1:9672 0.0.0.0:0 LISTENING 30252 - Step 3.
Run the identical command twice and change nothing between the two.
npx autocannon@8 -c 10 -d 10 http://127.0.0.1:9672/cold; npx autocannon@8 -c 10 -d 10 http://127.0.0.1:9672/coldRunning 10s test @ http://127.0.0.1:9672/cold 10 connections ┌─────────┬──────┬──────┬───────┬──────┬─────────┬─────────┬───────┐ │ Stat │ 2.5% │ 50% │ 97.5% │ 99% │ Avg │ Stdev │ Max │ ├─────────┼──────┼──────┼───────┼──────┼─────────┼─────────┼───────┤ │ Latency │ 0 ms │ 0 ms │ 0 ms │ 0 ms │ 0.11 ms │ 1.71 ms │ 43 ms │ └─────────┴──────┴──────┴───────┴──────┴─────────┴─────────┴───────┘ ┌───────────┬─────────┬─────────┬─────────┬─────────┬─────────┬───────────┬─────────┐ │ Stat │ 1% │ 2.5% │ 50% │ 97.5% │ Avg │ Stdev │ Min │ ├───────────┼─────────┼─────────┼─────────┼─────────┼─────────┼───────────┼─────────┤ │ Req/Sec │ 341 │ 341 │ 39 807 │ 42 879 │ 28 925 │ 18 796,36 │ 341 │ ├───────────┼─────────┼─────────┼─────────┼─────────┼─────────┼───────────┼─────────┤ │ Bytes/Sec │ 62.8 kB │ 62.8 kB │ 7.32 MB │ 7.88 MB │ 5.32 MB │ 3.46 MB │ 62.7 kB │ └───────────┴─────────┴─────────┴─────────┴─────────┴─────────┴───────────┴─────────┘ Req/Bytes counts sampled once per second. # of samples: 10 289k requests in 10.01s, 53.2 MB read Running 10s test @ http://127.0.0.1:9672/cold 10 connections ┌─────────┬──────┬──────┬───────┬──────┬─────────┬─────────┬───────┐ │ Stat │ 2.5% │ 50% │ 97.5% │ 99% │ Avg │ Stdev │ Max │ ├─────────┼──────┼──────┼───────┼──────┼─────────┼─────────┼───────┤ │ Latency │ 0 ms │ 0 ms │ 0 ms │ 0 ms │ 0.01 ms │ 0.04 ms │ 10 ms │ └─────────┴──────┴──────┴───────┴──────┴─────────┴─────────┴───────┘ ┌───────────┬─────────┬─────────┬─────────┬─────────┬───────────┬──────────┬─────────┐ │ Stat │ 1% │ 2.5% │ 50% │ 97.5% │ Avg │ Stdev │ Min │ ├───────────┼─────────┼─────────┼─────────┼─────────┼───────────┼──────────┼─────────┤ │ Req/Sec │ 38 303 │ 38 303 │ 42 847 │ 43 423 │ 42 462,55 │ 1 390,06 │ 38 290 │ ├───────────┼─────────┼─────────┼─────────┼─────────┼───────────┼──────────┼─────────┤ │ Bytes/Sec │ 7.05 MB │ 7.05 MB │ 7.88 MB │ 7.99 MB │ 7.81 MB │ 255 kB │ 7.05 MB │ └───────────┴─────────┴─────────┴─────────┴─────────┴───────────┴──────────┴─────────┘ Req/Bytes counts sampled once per second. # of samples: 11 467k requests in 11.01s, 85.9 MB read28 925 against 42 462,55 requests a second, and 0.11 ms against 0.01 ms mean latency, from one command run twice.
Min341 next to a50%of 39 807 puts one second 117 times below the median.Stdev18 796,36 is 65% of the average, against 1 390,06 in the second run: two regimes, and an average describing neither. - Step 4.
Split the first seconds from the rest.
curl -s http://127.0.0.1:9672/reset > /dev/null && npx autocannon@8 -c 10 -d 10 -j http://127.0.0.1:9672/cold > coldrun.json && curl -s http://127.0.0.1:9672/stats > wstats.json && node -e "const g=require('./coldrun.json'),s=require('./wstats.json').filter(b=>b.n>0),f=s[0].s;for(const b of s)console.log('second '+String(b.s-f+1).padStart(2)+' requests '+String(b.n).padStart(6)+' mean handler '+String(b.ms).padStart(6)+' ms');const e=s.slice(0,3),l=s.slice(3),en=e.reduce((a,b)=>a+b.n,0),ln=l.reduce((a,b)=>a+b.n,0);console.log('reported for the run rps '+g.requests.average+' mean latency '+g.latency.average+' ms');console.log('first 3 seconds rps '+(en/3).toFixed(1)+' mean handler '+(e.reduce((a,b)=>a+b.n*b.ms,0)/en).toFixed(3)+' ms requests '+en);console.log('second 4 onward rps '+(ln/l.length).toFixed(1)+' mean handler '+(l.reduce((a,b)=>a+b.n*b.ms,0)/ln).toFixed(3)+' ms requests '+ln)"second 1 requests 179 mean handler 2.739 ms second 2 requests 354 mean handler 2.741 ms second 3 requests 354 mean handler 2.746 ms second 4 requests 17401 mean handler 0.028 ms second 5 requests 42123 mean handler 0 ms second 6 requests 41729 mean handler 0 ms second 7 requests 41920 mean handler 0 ms second 8 requests 42366 mean handler 0 ms second 9 requests 41301 mean handler 0 ms second 10 requests 40440 mean handler 0 ms second 11 requests 17252 mean handler 0 ms reported for the run rps 28543 mean latency 0.11 ms first 3 seconds rps 295.7 mean handler 2.743 ms requests 887 second 4 onward rps 35566.5 mean handler 0.002 ms requests 284532887 requests, 0.31% of the run, pull the reported rate from 35 566.5 down to 28 543.
requests.averageis the mean of one sample per second, not of requests. Three slow seconds and eight fast ones are eleven samples of equal weight, so 0.31% of the traffic gets 27% of the vote.Handler figures are server time. The client saw 0.11 ms because ten requests queued on one thread behind 2.743 ms of work.
- Step 5.
Send warm-up traffic that is not measured, and read both documents.
curl -s http://127.0.0.1:9672/reset > /dev/null; npx autocannon@8 -W [ -c 10 -d 4 ] -c 10 -d 10 -j http://127.0.0.1:9672/cold > w.json; echo "documents in w.json: $(wc -l < w.json)"; node -e "try { require('./w.json'); console.log('JSON.parse read one document'); } catch (e) { console.log('JSON.parse failed: ' + e.message.split(String.fromCharCode(10))[0]); }"; node -e "require('node:fs').readFileSync('w.json','utf8').trim().split(String.fromCharCode(10)).forEach((x,i)=>{const r=JSON.parse(x);console.log('document '+(i+1)+' rps '+r.requests.average+' mean latency '+r.latency.average+' ms')})"documents in w.json: 2 JSON.parse failed: D:\how2check\scratch\load-reading-results\w.json: Unexpected non-whitespace character after JSON at position 1184 (line 2 column 1) document 1 rps 9813.75 mean latency 0.76 ms document 2 rps 42320 mean latency 0.01 ms-Wworks: document 2, the measured run, reports 42 320 against the 28 543 of the unwarmed run in step 4.-Wwith-jwrites two JSON documents to one stream, one per run.JSON.parseon the file throws, and a pipeline taking the first line reads 9 813.75 instead of 42 320. Take the last line.Measure the warm-up first, then set
-dinside the brackets above that figure. - Step 6.
Restart the target, then name the cause by its shape, one request at a time.
export MSYS_NO_PATHCONV=1; { echo "--- cold process, one keep-alive connection"; node probe.mjs /jit 5000; echo "--- same process, a new connection for every request"; node probe.mjs /jit 1000 nokeepalive; curl -s http://127.0.0.1:9672/reset > /dev/null; echo "--- empty cache, one keep-alive connection"; node probe.mjs /cache 10; }--- cold process, one keep-alive connection request 1 23.46 ms request 2 1.33 ms request 3 0.58 ms request 4 0.54 ms request 5 0.53 ms request 6 0.46 ms request 7 0.43 ms request 8 0.50 ms request 9 1.29 ms request 10 0.69 ms mean 11-100 0.24 ms mean 101-1000 0.20 ms mean 1001-5000 0.15 ms --- same process, a new connection for every request request 1 18.07 ms request 2 1.58 ms request 3 1.37 ms request 4 1.19 ms request 5 1.37 ms request 6 1.52 ms request 7 1.12 ms request 8 1.49 ms request 9 1.96 ms request 10 1.50 ms mean 11-100 0.98 ms mean 101-1000 1.17 ms --- empty cache, one keep-alive connection request 1 82.71 ms request 2 1.04 ms request 3 0.67 ms request 4 0.56 ms request 5 0.55 ms request 6 0.52 ms request 7 0.53 ms request 8 0.58 ms request 9 1.54 ms request 10 0.82 msThree blocks, three shapes.
Compilation decays: 1.33 ms at request 2, 0.24 ms over the first hundred, 0.15 ms by the thousandth, with no step in it.
Connection setup is a constant tax: 0.98 ms and 1.17 ms with a new connection per request against 0.20 ms on one kept connection, and it never decays.
An empty cache is a step one request wide: 82.71 ms, then 1.04 ms. That is what the first caller after every deploy pays.
The opening request, 23.46 ms cold and 18.07 ms warm, is mostly the client.
- Step 7.
Look at what a cold pool does to the report.
curl -s http://127.0.0.1:9672/reset > /dev/null && npx autocannon@8 -c 20 -d 3 http://127.0.0.1:9672/poolRunning 3s test @ http://127.0.0.1:9672/pool 20 connections ┌─────────┬──────┬──────┬───────┬──────┬─────────┬────────┬────────┐ │ Stat │ 2.5% │ 50% │ 97.5% │ 99% │ Avg │ Stdev │ Max │ ├─────────┼──────┼──────┼───────┼──────┼─────────┼────────┼────────┤ │ Latency │ 0 ms │ 0 ms │ 0 ms │ 1 ms │ 0.08 ms │ 4.3 ms │ 316 ms │ └─────────┴──────┴──────┴───────┴──────┴─────────┴────────┴────────┘ ┌───────────┬────────┬────────┬─────────┬─────────┬───────────┬──────────┬────────┐ │ Stat │ 1% │ 2.5% │ 50% │ 97.5% │ Avg │ Stdev │ Min │ ├───────────┼────────┼────────┼─────────┼─────────┼───────────┼──────────┼────────┤ │ Req/Sec │ 25 023 │ 25 023 │ 40 639 │ 40 703 │ 35 442,67 │ 7 372,82 │ 25 021 │ ├───────────┼────────┼────────┼─────────┼─────────┼───────────┼──────────┼────────┤ │ Bytes/Sec │ 4.6 MB │ 4.6 MB │ 7.48 MB │ 7.49 MB │ 6.52 MB │ 1.36 MB │ 4.6 MB │ └───────────┴────────┴────────┴─────────┴─────────┴───────────┴──────────┴────────┘ Req/Bytes counts sampled once per second. # of samples: 3 106k requests in 3.01s, 19.6 MB readThe fourth shape is a plateau: twenty requests waited on one 300 ms setup, released together.
Every latency percentile reads 0 ms or 1 ms.
Max316 ms andStdev4.3 ms, 54 times theAvg, are the only cells holding the event. Twenty requests in 106 000 cannot reach p99, so a percentile threshold never fires. - Step 8.
Stop the id on the netstat line.
netstat -ano | grep "127.0.0.1:9672 " | grep LISTENING; powershell -Command "Stop-Process -Id 32540 -Force"; sleep 1; netstat -ano | grep ":9672 " | grep -c LISTENINGTCP 127.0.0.1:9672 0.0.0.0:0 LISTENING 32540 0
How to read the result
| What you see | What it means | What to do |
| --- | --- | --- |
| Req/Sec Stdev above half of Avg | The run holds two regimes | Split it by second before reading any average. |
| Req/Sec Min far under 1% | One or two seconds carried the warm-up | Warm with -W, or report the steady state and the warm-up apart. |
| A second run much faster than the first | The process warms and stays warm | Decide which one your users meet, then always report that one. |
| Latency Max large with every percentile near zero | A one-time setup blocked a handful of requests | Count them. A percentile cannot see 20 requests in 101 000. |
| Per-request times that decay with no step | Compilation or a cache filling gradually | More traffic before the measurement. |
| Per-request times flat and higher than expected | A constant cost, such as a new connection each time | Not warm-up. Check keep-alive before tuning the service. |
Common mistakes
What to check next
- How to read load test results: the cells that invalidate a run.
- How to check requests per second an api can handle: how far throughput moves once warm.
- How to check p95 latency: the percentile a one-time setup cannot reach.
- Spike testing in software testing: the same seconds when load arrives at once.
- How to test concurrent users: the sweep that pays this cost at every level.
FAQ
What is ramp up time in a load test?
Two things share the name. One is the generator raising its connection count gradually; the other is the service reaching steady speed, which the runs above measure. autocannon has no gradual ramp, only -W.
How long should the warm-up be?
Long enough to cover the slowest cause on the route. Measure it with the per-second split in step 4, then set -d inside the -W brackets above that figure.
Should I discard the first seconds of every run?
Only when no user meets them. A cache filled once at start is warm-up. A cache emptied by every deploy is production behaviour for the first callers after each release.
Verified
Verified by Maks Vernyautocannon 8.0.0node 22.23.2curl 8.1.2
Each output block is what the command above it printed on that date, on the host named in the step. Figures read from a live site move between runs. Compare the shape of the answer rather than the digits, and see the methodology for how a page is re-verified.
Related on this site
intermediate16 minpublished updated Maks Verny