How to run a soak test
Run the same load in cycles with a return to idle between them, and sample process.getActiveResourcesInfo() at each idle. Here 27 requests per cycle left the service holding 27, then 54, then 81 timers and listeners, while resident memory moved 1.1 MB in total. The idle count is the leak.
Why check this
Run this before a release that stays up for days between deploys, and after any change to a handler that subscribes, schedules or connects. Memory is the resource everyone watches and rarely the one that fails first.
The failure it catches is a service that passes a five minute load test and answers 503 on the third day, because every order kept one connection to a downstream that accepts 60. The limit a timer reaches is a count, not a byte total, so a memory graph never bends.
Prerequisites
- Node 22 or later.
process.getActiveResourcesInfo()lists what keeps the loop alive (process API). npx autocannon@8, which fetches autocannon on first use.- Two free ports, 9751 and 9752 below.
- The generator shares eight cores with the target, and loopback has no network in it. Read the leak per request, not per minute.
sink.mjs, the downstream service, started withnode sink.mjs &. It accepts 60 connections and rejects the rest.
// sink.mjs the downstream service the handler connects to
import { createServer } from 'node:net';
const held = [];
const srv = createServer((s) => { held.push(s); s.write('k'); s.on('error', () => {}); });
srv.maxConnections = 60;
srv.listen(9752, '127.0.0.1', () => console.log('sink on 9752, maxConnections 60'));
- The target,
soak-server.mjs, started withnode soak-server.mjs > soak-server.log 2>&1 &./ordersets a retry timer, subscribes to an event bus and opens a downstream connection./order-fixedreleases all three.
// soak-server.mjs the service under test
import { createServer } from 'node:http';
import { connect } from 'node:net';
import { EventEmitter } from 'node:events';
const bus = new EventEmitter();
const sockets = [];
const t0 = Date.now();
let handled = 0;
const mb = (b) => +(b / 1048576).toFixed(1);
const stats = () => {
const c = {};
for (const r of process.getActiveResourcesInfo()) c[r] = (c[r] ?? 0) + 1;
return { t: Math.round((Date.now() - t0) / 1000), rss: mb(process.memoryUsage().rss),
handled, listeners: bus.listenerCount('tick'), sockets: sockets.length, resources: c };
};
const json = (res, code, o) => {
res.writeHead(code, { 'content-type': 'application/json' });
res.end(JSON.stringify(o));
};
function order(req, res, cleanUp) {
handled += 1;
const retry = setTimeout(() => {}, 600000);
const onTick = () => {};
bus.on('tick', onTick);
const s = connect(9752, '127.0.0.1');
let done = false;
const end = (ok, why) => {
if (done) return;
done = true;
if (cleanUp) { clearTimeout(retry); bus.off('tick', onTick); s.end(); } else if (ok) sockets.push(s);
ok ? json(res, 200, { ok: true }) : json(res, 503, { ok: false, why });
};
s.on('data', () => end(true));
s.on('error', (e) => end(false, e.code));
s.on('close', () => end(false, 'closed-by-sink'));
}
createServer((req, res) => {
const path = req.url.split('?')[0];
if (path === '/order') return order(req, res, false);
if (path === '/order-fixed') return order(req, res, true);
if (path === '/stats') return json(res, 200, stats());
res.writeHead(404).end();
}).listen(9751, '127.0.0.1', () => console.log('listening on 9751'));
setInterval(() => console.log(JSON.stringify(stats())), 1000).unref();
soak.sh, one cycle of load and idle per iteration.
#!/bin/sh
# soak.sh <route> <cycles> five seconds of load at 5 req/s, then five idle
ROUTE=$1; N=${2:-3}
i=1
while [ $i -le $N ]; do
npx autocannon@8 -c 2 -R 5 -d 5 -j http://127.0.0.1:9751$ROUTE > cycle-$i.json 2>/dev/null
sleep 5
echo "cycle $i $(node -e "const r=require('./cycle-$i.json');console.log('sent',r.requests.total,'non2xx',r.non2xx)") $(curl -s http://127.0.0.1:9751/stats)"
i=$((i+1))
done
Steps
- Step 1.
Read the idle baseline before any load.
curl -s http://127.0.0.1:9751/stats{"t":7,"rss":53.4,"handled":0,"listeners":0,"sockets":0,"resources":{"TCPServerWrap":1,"TCPSocketWrap":1}}TCPServerWrapis the listening socket.TCPSocketWrapis the connection this request arrived on, so the reading includes the reader. Later samples are compared against these numbers, not against zero. - Step 2.
Run three cycles against the route that releases what it takes.
sh soak.sh /order-fixed 3cycle 1 sent 25 non2xx 0 {"t":19,"rss":52.8,"handled":27,"listeners":0,"sockets":0,"resources":{"TCPServerWrap":1,"TCPSocketWrap":1}} cycle 2 sent 25 non2xx 0 {"t":30,"rss":53.8,"handled":54,"listeners":0,"sockets":0,"resources":{"TCPServerWrap":1,"TCPSocketWrap":1}} cycle 3 sent 25 non2xx 0 {"t":42,"rss":54.1,"handled":81,"listeners":0,"sockets":0,"resources":{"TCPServerWrap":1,"TCPSocketWrap":1}}handledrises by 27 a cycle and every other number returns to the baseline. The server counted 27 where autocannon reported 25 sent, because rate limiting leaves requests in flight at the end of a run. Count on the server. - Step 3.
Read the per-second log across the first cycle and its idle.
grep -E '"t":(1[2-9]|2[0-2])' soak-server.log{"t":12,"rss":52.5,"handled":20,"listeners":0,"sockets":0,"resources":{"TCPServerWrap":1,"TCPSocketWrap":2}} {"t":13,"rss":52.6,"handled":25,"listeners":0,"sockets":0,"resources":{"TCPServerWrap":1,"TCPSocketWrap":2}} {"t":14,"rss":52.7,"handled":27,"listeners":0,"sockets":0,"resources":{"TCPServerWrap":1}} {"t":15,"rss":52.7,"handled":27,"listeners":0,"sockets":0,"resources":{"TCPServerWrap":1}} {"t":16,"rss":52.7,"handled":27,"listeners":0,"sockets":0,"resources":{"TCPServerWrap":1}} {"t":17,"rss":52.7,"handled":27,"listeners":0,"sockets":0,"resources":{"TCPServerWrap":1}} {"t":18,"rss":52.7,"handled":27,"listeners":0,"sockets":0,"resources":{"TCPServerWrap":1}} {"t":19,"rss":52.8,"handled":27,"listeners":0,"sockets":0,"resources":{"TCPServerWrap":1}} {"t":20,"rss":53.1,"handled":32,"listeners":0,"sockets":0,"resources":{"TCPServerWrap":1,"TCPSocketWrap":2}} {"t":21,"rss":53.3,"handled":37,"listeners":0,"sockets":0,"resources":{"TCPServerWrap":1,"TCPSocketWrap":2}} {"t":22,"rss":53.5,"handled":42,"listeners":0,"sockets":0,"resources":{"TCPServerWrap":1,"TCPSocketWrap":2}}Under load this process holds two inbound sockets. At second 14 the load stops and
TCPSocketWrapleaves the line entirely, which is what a working set looks like. Step 1 reported one because the request asking the question was open. - Step 4.
Run the same three cycles against the route that keeps everything.
sh soak.sh /order 3cycle 1 sent 25 non2xx 0 {"t":53,"rss":54.3,"handled":108,"listeners":27,"sockets":27,"resources":{"TCPServerWrap":1,"TCPSocketWrap":28,"Timeout":27}} cycle 2 sent 25 non2xx 0 {"t":65,"rss":54.5,"handled":135,"listeners":54,"sockets":54,"resources":{"TCPServerWrap":1,"TCPSocketWrap":55,"Timeout":54}} cycle 3 sent 25 non2xx 19 {"t":76,"rss":54.5,"handled":162,"listeners":81,"sockets":60,"resources":{"TCPServerWrap":1,"TCPSocketWrap":61,"Timeout":81}}Three counters climb by 27 a cycle: outbound sockets, uncleared timers, bus listeners.
rssmoved from 54.3 to 54.5 MB over the same run, which is why a memory dashboard passes this service. Cycle 3 is the first with failures, 19 of them, and the first wheresocketsstops trackinglisteners. - Step 5.
Read the per-second log across the cycle that failed.
grep -E '"t":(6[5-9]|7[0-6])' soak-server.log{"t":65,"rss":54.5,"handled":135,"listeners":54,"sockets":54,"resources":{"TCPServerWrap":1,"TCPSocketWrap":54,"Timeout":54}} {"t":66,"rss":54.5,"handled":140,"listeners":59,"sockets":59,"resources":{"TCPServerWrap":1,"TCPSocketWrap":61,"Timeout":59}} {"t":67,"rss":54.6,"handled":145,"listeners":64,"sockets":60,"resources":{"TCPServerWrap":1,"TCPSocketWrap":62,"Timeout":64}} {"t":68,"rss":54.6,"handled":150,"listeners":69,"sockets":60,"resources":{"TCPServerWrap":1,"TCPSocketWrap":62,"Timeout":69}} {"t":69,"rss":54.4,"handled":155,"listeners":74,"sockets":60,"resources":{"TCPServerWrap":1,"TCPSocketWrap":62,"Timeout":74}} {"t":70,"rss":54.4,"handled":160,"listeners":79,"sockets":60,"resources":{"TCPServerWrap":1,"TCPSocketWrap":62,"Timeout":79}} {"t":71,"rss":54.5,"handled":162,"listeners":81,"sockets":60,"resources":{"TCPServerWrap":1,"TCPSocketWrap":60,"Timeout":81}} {"t":72,"rss":54.5,"handled":162,"listeners":81,"sockets":60,"resources":{"TCPServerWrap":1,"TCPSocketWrap":60,"Timeout":81}} {"t":73,"rss":54.5,"handled":162,"listeners":81,"sockets":60,"resources":{"TCPServerWrap":1,"TCPSocketWrap":60,"Timeout":81}} {"t":75,"rss":54.5,"handled":162,"listeners":81,"sockets":60,"resources":{"TCPServerWrap":1,"TCPSocketWrap":60,"Timeout":81}} {"t":76,"rss":54.5,"handled":162,"listeners":81,"sockets":60,"resources":{"TCPServerWrap":1,"TCPSocketWrap":60,"Timeout":81}}The failure has a shape. At second 67
socketsstops at 60, whilelistenersandTimeoutcarry on to 81. One resource hit an external cap and the other two are still unbounded. Second 74 has no row: the sampler is asetInterval, and an interval under load is not a clock. - Step 6.
Send one more request now that the downstream is full.
curl -s -w " HTTP %{http_code}\n" http://127.0.0.1:9751/order{"ok":false,"why":"closed-by-sink"} HTTP 503The connection was accepted and then closed by the peer, which is how an application cap presents. A full accept queue answers
ECONNREFUSEDinstead. Neither fault is in this service, and both are caused by it. - Step 7.
Look for the warning Node raised on its own.
grep -m1 "MaxListeners" soak-server.log(node:34844) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 tick listeners added to [EventEmitter]. MaxListeners is 10. Use emitter.setMaxListeners() to increase limitIt names the event, the emitter and the count, and it fires once. The count reached 81 in silence, so this line is a starting gun rather than a monitor.
- Step 8.
Stop both processes and confirm the ports are clear.
netstat -ano | grep -E "127.0.0.1:975[12] " | grep LISTENING; powershell -Command "Stop-Process -Id 34844 -Force; Stop-Process -Id 37736 -Force"; netstat -ano | grep -cE ":975[12] .*LISTENING"TCP 127.0.0.1:9751 0.0.0.0:0 LISTENING 34844 TCP 127.0.0.1:9752 0.0.0.0:0 LISTENING 37736 0Read both process ids from the last column and stop those alone.
How to read the result
| What you see | What it means | What to do |
| --- | --- | --- |
| Idle counts return to the same numbers each cycle | A working set, released when the work ends | Record the numbers as the baseline for the next release. |
| A counter rises by the same amount each cycle | One leak per request | Divide by handled to get the cost per request, then find the missing release. |
| Timeout climbing while memory is flat | Timers scheduled and never cleared | Call clearTimeout on every exit path, including the error one. |
| listeners climbing on a long-lived emitter | A subscription added per request | Remove it in the same function that added it. |
| One counter flat while the others climb | That resource reached a cap | Read the failing response body. The cap is where the outage starts. |
| Counts high during load, back to baseline at idle | Concurrency, not a leak | Sample at idle only, as every cycle above does. |
Common mistakes
What to check next
- How to check memory growth under load: the heap half of the same run.
- How to measure event loop lag: where held resources appear as delay.
- How to test connection pool exhaustion: the same cap on a database pool.
- How to check why jest did not exit after tests: the same handles, found by a test runner.
- How to check connection limit of a server: that cap from the other side.
FAQ
What is soak testing in software testing?
Moderate load held long enough for per-request accumulation to reach a limit. It is not about peak traffic. It asks whether the process still serves after a few hundred thousand requests.
What is the difference between soak testing and load testing?
A load test asks how much the service handles at once and reads throughput and latency. A soak test asks what it fails to release and reads counts at idle. Same generator, different columns.
What is endurance testing?
Another name for the same run: load applied for a long period against resource counters rather than a latency target. The output that matters is a rising count.
How long should a soak test run?
Long enough for the smallest limit to be reachable. Divide that limit by the leak per request. With 60 downstream connections and one held per request, 60 requests were enough, found here in 76 seconds.
Verified
Verified by Maks Vernynode 22.23.2autocannon 8.0.0curl 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
intermediate12 minpublished updated Maks Verny