How to test graceful degradation

Offer more work than the service can finish, give the client a deadline, and compare what the server did with what the client received. An unbounded queue answered 2k requests with 2k timeouts, and was still working on 1343 of them five seconds after the load stopped. The shedding version returned 459 answers and no timeouts.

Why check this

Run this before a release that changes a queue, a client timeout, a dependency call or a pool size. Each decides what the service does in the minute it cannot keep up, and none is exercised by a test that stays inside capacity.

The failure it catches is a service that accepts everything and finishes nothing in time. Its logs show every request completed. Its users saw a spinner and left, and the queue kept working for them for half a minute afterwards.

Generator and server share eight cores here, and loopback has no network in it. A request that does nothing still costs about 15 ms through this client loop, so read small latencies as the instrument's floor.

Prerequisites

// degrade-server.mjs  -  one worker, and four ways to behave when it cannot keep up
import { createServer } from 'node:http';
const WORK_MS = 20, BOUND = 10, DEP_TIMEOUT = 50, OPEN_MS = 2000;
const CORE = Array.from({ length: 10 }, (_, i) => ({ id: i, name: `item ${i}` }));
const RECS = Array.from({ length: 40 }, (_, i) => ({ id: i, score: i / 40 }));
let dep = 1200;                                   // how long the optional dependency takes
let running = false;
const queue = [];
const stats = { accepted: 0, completed: 0, shed: 0 };
const br = { state: 'closed', fails: 0, until: 0 };

function pump() {
  if (running || queue.length === 0) return;
  running = true;
  setTimeout(() => { running = false; stats.completed += 1; queue.shift()(); pump(); }, WORK_MS);
}
function enqueue(res, bounded) {
  if (bounded && queue.length >= BOUND) {
    stats.shed += 1;
    res.writeHead(503, { 'retry-after': '1', 'content-type': 'application/json' });
    return res.end('{"error":"overloaded"}');
  }
  stats.accepted += 1;
  queue.push(() => { res.writeHead(200, { 'content-type': 'application/json' }); res.end('{"ok":true}'); });
  pump();
}
const callDep = (timeout) => new Promise((resolve) => {                 // resolves false on timeout
  const slow = setTimeout(() => { clearTimeout(fast); resolve(true); }, dep);
  const fast = timeout ? setTimeout(() => { clearTimeout(slow); resolve(false); }, timeout) : null;
});
function send(res, full, state, call) {
  const h = { 'content-type': 'application/json', 'x-breaker': state, 'x-call': call };
  if (!full) h['x-degraded'] = 'recommendations';
  res.writeHead(200, h);
  res.end(JSON.stringify(full ? { items: CORE, recommendations: RECS } : { items: CORE }));
}
async function breaker(res) {
  if (br.state === 'open' && Date.now() >= br.until) br.state = 'half-open';
  const entry = br.state;                                               // state this request met
  if (entry === 'open') return send(res, false, 'open', 'skipped');     // no call at all
  const ok = await callDep(DEP_TIMEOUT);
  if (ok) { br.state = 'closed'; br.fails = 0; }
  else if (entry === 'half-open' || (br.fails += 1) >= 5) { br.state = 'open'; br.until = Date.now() + OPEN_MS; br.fails = 0; }
  send(res, ok, entry, entry === 'half-open' ? 'probe' : 'live');
}

createServer(async (req, res) => {
  const [p, qs] = req.url.split('?');
  if (p === '/naive') return enqueue(res, false);
  if (p === '/shed') return enqueue(res, true);
  if (p === '/full') { await callDep(0); return send(res, true, 'off', 'live'); }
  if (p === '/degraded') return send(res, await callDep(DEP_TIMEOUT), 'off', 'live');
  if (p === '/breaker') return breaker(res);
  if (p === '/dep') { dep = Number(new URLSearchParams(qs).get('ms')); return send(res, true, 'off', 'live'); }
  if (p === '/stats') { res.writeHead(200, { 'content-type': 'application/json' }); return res.end(JSON.stringify({ ...stats, depth: queue.length, dep })); }
  res.writeHead(404).end();
}).listen(9761, '127.0.0.1', () => console.log('degrade server on 9761'));
// breaker.mjs <base>  -  polls /breaker every 100 ms for 9 s and repairs the dependency at 4.5 s
const base = process.argv[2];
const t0 = Date.now();
const rows = [];
let repaired = false;
while (Date.now() - t0 < 9000) {
  const at = Date.now() - t0;
  if (!repaired && at >= 4500) { repaired = true; await fetch(`${base}/dep?ms=5`); }
  const s = performance.now();
  const r = await fetch(`${base}/breaker`);
  await r.arrayBuffer();
  rows.push({ at, tag: `${r.headers.get('x-breaker')}/${r.headers.get('x-call')} ${r.headers.get('x-degraded') ? 'reduced' : 'full'}`, ms: performance.now() - s });
  await new Promise((k) => setTimeout(k, 100));
}
let run = null;
for (const r of rows) {
  const tag = r.tag;
  if (run && run.tag === tag) { run.n += 1; run.last = r.at; run.ms += r.ms; continue; }
  if (run) console.log(`${(run.at / 1000).toFixed(1)}s to ${(run.last / 1000).toFixed(1)}s  breaker ${run.tag.padEnd(22)} ${String(run.n).padStart(3)} requests  mean ${(run.ms / run.n).toFixed(1)} ms`);
  run = { tag, at: r.at, last: r.at, n: 1, ms: r.ms };
}
console.log(`${(run.at / 1000).toFixed(1)}s to ${(run.last / 1000).toFixed(1)}s  breaker ${run.tag.padEnd(22)} ${String(run.n).padStart(3)} requests  mean ${(run.ms / run.n).toFixed(1)} ms`);

Steps

  1. Step 1.

    Load the unbounded queue with 200 connections and a one second deadline.

    npx autocannon@8 -c 200 -d 10 -t 1 http://127.0.0.1:9761/naive
    
    Running 10s test @ http://127.0.0.1:9761/naive
    200 connections
    
    
    ┌─────────┬───────┬────────┬─────────┬─────────┬──────────┬───────────┬─────────┐
    │ Stat    │ 2.5%  │ 50%    │ 97.5%   │ 99%     │ Avg      │ Stdev     │ Max     │
    ├─────────┼───────┼────────┼─────────┼─────────┼──────────┼───────────┼─────────┤
    │ Latency │ 80 ms │ 530 ms │ 1006 ms │ 1006 ms │ 534.3 ms │ 278.04 ms │ 1006 ms │
    └─────────┴───────┴────────┴─────────┴─────────┴──────────┴───────────┴─────────┘
    ┌───────────┬─────┬──────┬─────┬─────────┬───────┬─────────┬────────┐
    │ Stat      │ 1%  │ 2.5% │ 50% │ 97.5%   │ Avg   │ Stdev   │ Min    │
    ├───────────┼─────┼──────┼─────┼─────────┼───────┼─────────┼────────┤
    │ Req/Sec   │ 0   │ 0    │ 0   │ 31      │ 3,1   │ 9,3     │ 31     │
    ├───────────┼─────┼──────┼─────┼─────────┼───────┼─────────┼────────┤
    │ Bytes/Sec │ 0 B │ 0 B  │ 0 B │ 5.71 kB │ 571 B │ 1.71 kB │ 5.7 kB │
    └───────────┴─────┴──────┴─────┴─────────┴───────┴─────────┴────────┘
    
    Req/Bytes counts sampled once per second.
    # of samples: 10
    
    2k requests in 10.1s, 5.7 kB read
    2k errors (2k timeouts)

    Every request the client sent timed out. The 31 answers in the 97.5% column landed in the first second, before the queue grew past the deadline. The ungraceful shape: nothing refused, nothing delivered.

  2. Step 2.

    Ask the server what it thinks happened, twice.

    curl -s http://127.0.0.1:9761/stats; echo; sleep 5; curl -s http://127.0.0.1:9761/stats; echo
    
    {"accepted":2026,"completed":522,"shed":0,"depth":1504,"dep":1200}
    {"accepted":2026,"completed":683,"shed":0,"depth":1343,"dep":1200}

    The server rejected nothing, completed 683 requests and still holds 1343. At 20 ms each that is 27 more seconds of work for clients that gave up after one second. Read it against step 1: a server-side success rate of 100% beside a client-side rate of 0%.

  3. Step 3.

    Restart the target, then send the same load at the bounded queue. Step 1 left work in the shared worker.

    npx autocannon@8 -c 200 -d 10 -t 1 http://127.0.0.1:9761/shed
    
    Running 10s test @ http://127.0.0.1:9761/shed
    200 connections
    
    
    ┌─────────┬──────┬──────┬───────┬───────┬────────┬─────────┬────────┐
    │ Stat    │ 2.5% │ 50%  │ 97.5% │ 99%   │ Avg    │ Stdev   │ Max    │
    ├─────────┼──────┼──────┼───────┼───────┼────────┼─────────┼────────┤
    │ Latency │ 4 ms │ 5 ms │ 7 ms  │ 10 ms │ 5.5 ms │ 8.17 ms │ 297 ms │
    └─────────┴──────┴──────┴───────┴───────┴────────┴─────────┴────────┘
    ┌───────────┬─────────┬─────────┬─────────┬─────────┬──────────┬──────────┬─────────┐
    │ Stat      │ 1%      │ 2.5%    │ 50%     │ 97.5%   │ Avg      │ Stdev    │ Min     │
    ├───────────┼─────────┼─────────┼─────────┼─────────┼──────────┼──────────┼─────────┤
    │ Req/Sec   │ 26 079  │ 26 079  │ 34 431  │ 35 071  │ 33 562,4 │ 2 566,62 │ 26 079  │
    ├───────────┼─────────┼─────────┼─────────┼─────────┼──────────┼──────────┼─────────┤
    │ Bytes/Sec │ 5.97 MB │ 5.97 MB │ 7.88 MB │ 8.03 MB │ 7.68 MB  │ 588 kB   │ 5.97 MB │
    └───────────┴─────────┴─────────┴─────────┴─────────┴──────────┴──────────┴─────────┘
    
    Req/Bytes counts sampled once per second.
    # of samples: 10
    
    459 2xx responses, 335207 non 2xx responses
    336k requests in 10.03s, 76.8 MB read

    459 answers, 335207 fast 503s, and no timeout line. Useful throughput matches step 1, because the worker did not get faster. What changed is that every client learned its outcome inside 10 ms.

  4. Step 4.

    Read the counters again, on the bounded run.

    curl -s http://127.0.0.1:9761/stats; echo; sleep 5; curl -s http://127.0.0.1:9761/stats; echo
    
    {"accepted":470,"completed":463,"shed":335396,"depth":7,"dep":1200}
    {"accepted":470,"completed":470,"shed":335396,"depth":0,"dep":1200}

    Depth 7 when the load stopped, 0 five seconds later, 470 accepted and 470 finished. Nothing outlived its caller, the property the bound buys and the one step 2 shows missing.

  5. Step 5.

    Compare a route that waits for the slow dependency with one that gives up on it.

    for path in full degraded; do echo "== /$path"; npx autocannon@8 -c 20 -d 10 -t 1 "http://127.0.0.1:9761/$path" 2>&1 | grep -E "^│ Latency|requests in|errors|non 2xx"; done
    
    == /full
    │ Latency │ 0 ms │ 0 ms │ 0 ms  │ 0 ms │ 0 ms │ 0 ms  │ 0 ms │
    200 requests in 10.1s, 0 B read
    180 errors (180 timeouts)
    == /degraded
    │ Latency │ 54 ms │ 63 ms │ 66 ms │ 69 ms │ 61.79 ms │ 3.08 ms │ 73 ms │
    3k requests in 10.11s, 1.59 MB read

    /full waits the dependency's 1200 ms and delivered 0 bytes in ten seconds. /degraded gives it 50 ms, drops the recommendations when it misses, and delivered 3k answers and 1.59 MB. Fewer features, and the difference between some service and none. The 0 ms latency row is autocannon recording nothing, not speed.

  6. Step 6.

    Watch the breaker open, probe, and close after the dependency is repaired.

    node breaker.mjs http://127.0.0.1:9761
    
    0.0s to 0.8s  breaker closed/live reduced      5 requests  mean 82.3 ms
    0.9s to 2.8s  breaker open/skipped reduced    16 requests  mean 15.4 ms
    2.9s to 2.9s  breaker half-open/probe reduced   1 requests  mean 79.6 ms
    3.1s to 5.0s  breaker open/skipped reduced    16 requests  mean 15.2 ms
    5.1s to 5.1s  breaker half-open/probe full     1 requests  mean 32.3 ms
    5.3s to 8.9s  breaker closed/live full        27 requests  mean 30.9 ms

    Five live failures at 82.3 ms each opened the breaker. While open, 16 requests were answered in 15.4 ms without touching the dependency. The probe at 2.9 s failed and reopened it. The dependency was repaired at 4.5 s, the probe at 5.1 s succeeded, and full responses resumed.

  7. Step 7.

    Stop the target and confirm the port is clear.

    netstat -ano | grep "127.0.0.1:9761 " | grep LISTENING; powershell -Command "Stop-Process -Id 15664 -Force"; netstat -ano | grep ":9761 " | grep -c LISTENING
    
      TCP    127.0.0.1:9761         0.0.0.0:0              LISTENING       15664
    0

    Read the process id from the last column and stop it.

How to read the result

| What you see | What it means | What to do | | --- | --- | --- | | Client timeouts, server completions | The work outlived the caller | Bound the queue and refuse what will not fit. | | Queue depth above zero after the load stops | The service works for clients that left | Drop queued work whose deadline has passed. | | 503 with retry-after, latency flat | Load shedding is engaged | Check the client backs off instead of retrying at once. | | A high non-2xx count and low latency | Shedding, not failing | Count useful answers, not error rate. | | 200 with x-degraded | A reduced response was served | Confirm the missing feature is optional to the caller. | | x-call: skipped | The breaker is open and made no call | Compare the open window with your recovery target. | | x-call: probe | Half-open, one request is testing the dependency | Confirm only one request probes at a time. | | No errors and rising latency | Work is accepted that cannot finish | Give the handler a deadline shorter than the caller's. |

Common mistakes

Sign: A load run shows a 100% success rate on the server and the incident report says the service was down.Cause: Both are true when the queue is unbounded. Steps 1 and 2 are the same ten seconds seen twice: 2k client timeouts, and a server that completed 683 requests with 1343 still queued five seconds after the traffic stopped. Server-side success counts work, never whether anyone still waited for it.
Sign: The shedding build is rejected because it returns 335207 errors where the old one returned none.Cause: 335207 of those are the designed answer, delivered in 5 ms with a retry-after. The run it replaced delivered zero usable answers in the same ten seconds. Compare successful responses per second, and count a shed 503 in its own category.
Sign: A dependency is fixed and the service keeps serving reduced responses for seconds afterwards.Cause: An open breaker makes no call, so it cannot notice a recovery until its window expires. In step 6 the dependency was repaired at 4.5 s and the first full response came at 5.1 s, held back by the 2 s window rather than by anything still broken. Recovery is the repair plus up to one open window.

What to check next

FAQ

What is graceful degradation?

A service that cannot serve everything serves less, on purpose, instead of failing at random. In practice: a fast refusal, an internal deadline shorter than the caller's, a reduced response, a bounded queue, and a breaker that stops calling a dependency that has stopped answering.

How is it different from load shedding?

Shedding is one of its behaviours: refusing work the service cannot finish. Degradation also covers what accepted requests get, as in step 5, where dropping one optional field turned 0 bytes delivered into 1.59 MB. A service can shed well and still serve nothing useful.

How do I test a circuit breaker?

Make the dependency fail, poll the route, and record the state per response, as step 6 does. Check that it opens, that exactly one request probes while half-open, and how long after a repair the first full response arrives.

Is a queue always the wrong answer?

A bounded one is not. The difference between steps 2 and 4 is the bound: depth 1343 five seconds after the load, against depth 0. A queue with a limit and a deadline smooths bursts. One without either converts a busy minute into work nobody awaits.

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.

advanced18 minpublished updated Maks Verny