Running a load test

The last lesson showed a k6 script and a neat table of results, and said "here's what the test showed". This lesson actually runs it, prints what k6 really prints, and reads it line by line. Along the way it hits the most common load-testing mistake there is, one that makes a server that's falling over look healthy.

The setup

To make it real, we ran everything for this lesson on a laptop, in Docker:

• A stand-in for Tiffin's app server: a small Node.js server with the same four endpoints, where each request burns 0.6 to 3 ms of CPU, like building a JSON response. It's limited to one CPU core, so its knee arrives at a few hundred requests a second instead of 1,400. That keeps the test short; the shape of the results is the same.
• k6 2.3 in a separate container, so the load generator doesn't steal the server's CPU.
• A CPU sampler recording the server container's CPU every few seconds.

The script is the one from the last lesson, with two changes: each request is tagged with a name, so results can be split by endpoint, and the stages are shorter and scaled to a one-core server.

export const options = {
  stages: [
    { duration: '2m', target: 200 },
    { duration: '2m', target: 400 },
    { duration: '2m', target: 600 },
    { duration: '2m', target: 800 },
    { duration: '1m', target: 0 },
  ],
  thresholds: {
    http_req_duration: ['p(99)<800'],
    http_req_failed: ['rate<0.01'],
  },
};

Run it with k6 run --out csv=results.csv dinner.js. The --out flag saves every single measurement with a timestamp, which you'll need in a minute.

What k6 prints

Nine minutes later, this is the end of k6's output, trimmed a little:

  █ THRESHOLDS

    http_req_duration
    ✓ 'p(99)<800' p(99)=431.26ms

    http_req_failed
    ✓ 'rate<0.01' rate=0.00%

  █ TOTAL RESULTS

    checks_succeeded...: 100.00% 196118 out of 196118

    HTTP
    http_req_duration..............: avg=102.01ms min=654.16µs med=12.29ms max=1.3s p(90)=325.44ms p(95)=371.31ms
    http_req_failed................: 0.00%  0 out of 196118
    http_reqs......................: 196118 362.868446/s

    EXECUTION
    iteration_duration.............: avg=1.1s     min=1s       med=1.01s   max=2.3s p(90)=1.32s    p(95)=1.37s
    vus............................: 8      min=2           max=799

How to read each part:

• Thresholds are your pass/fail rules. Both have a tick, so k6 exits with success, and a CI pipeline would go green.
• http_req_duration is the time from sending a request to receiving the whole response. med is the p50.
• http_req_failed counts responses with an error status (4xx or 5xx) or no response at all.
• http_reqs is the total and the average rate: 196,118 requests at about 363 a second.
• iteration_duration is one loop of the script, including the sleep(1).
• vus is how many virtual users were running: up to 799.

Zero errors, p99 well under the 800 ms rule, a green tick. Ship it?

The summary hides the knee

No. Every number above is an average or a percentile over the whole nine minutes, calm stages included. Most of the 196,118 requests happened while the server was barely working, and they drown out the minutes when it was in trouble.

The CSV file has every request's timestamp, so you can cut it into 30-second windows. Next to it is the CPU sampler:

Now the story is plain. Up to about 520 requests a second, the server keeps up and latency stays in single-digit milliseconds. Then throughput stops growing: from 600 to 800 virtual users it's stuck at about 560 a second, while the median request goes from 24 ms to 371 ms, 120 times slower than at the start. The CPU is pinned at 98%.

That flat line is the server's ceiling, and the knee is just before it, around 500 requests a second. The summary's "p99 = 431 ms" is the blend of eight calm minutes and one terrible one.

Read a load test over time, not as one summary. Plot throughput against the load you offered, and latency percentiles per minute. The knee is where throughput stops following the load and latency starts climbing.

Where did the failures go?

Something else is odd. At 800 virtual users, each supposedly sending one request a second, the server handled only 562 a second. Where did the rest go?

They were never sent. Each virtual user runs a loop: send a request, wait for the response, sleep 1 second, repeat. When the server slows down, every user waits longer, so every user sends less. The test politely backs off exactly when the server is struggling. iteration_duration shows it: the p90 loop took 1.32 s instead of 1 s.

That's called a closed model: a fixed number of users, each waiting for the last answer before asking again. Real customers don't behave like that. Ten thousand people opening the app at 8pm don't wait for each other. They arrive at their own rate whether your server is fast or slow, and when it's slow they tap retry. That's an open model: requests arrive at a given rate, no matter how fast you answer.

A closed-model test against an overloaded server measures a gentle version of overload that never happens in production. The usual name for this bias is coordinated omission: the test omits exactly the requests that would have seen the worst delays.

The same test, open model

k6 can generate an open model with the ramping-arrival-rate executor. Instead of a number of users, you give it a number of new requests per second, and it starts as many virtual users as it needs to keep up:

export const options = {
  scenarios: {
    dinner: {
      executor: 'ramping-arrival-rate',
      startRate: 100,
      timeUnit: '1s',
      preAllocatedVUs: 200,
      maxVUs: 3000,
      stages: [
        { duration: '30s', target: 400 },
        { duration: '1m', target: 400 },
        { duration: '30s', target: 520 },
        { duration: '1m', target: 520 },
        { duration: '30s', target: 600 },
        { duration: '1m', target: 600 },
      ],
    },
  },
};
// and no sleep() in the function: the executor sets the pace

Same server, same endpoints. Results per 30 seconds:

And the end of k6's output:

    http_req_duration
    ✗ 'p(99)<800' p(99)=847.95ms

    http_req_failed
    ✓ 'rate<0.01' rate=0.33%

    dropped_iterations.............: 1802   6.089398/s
    vus............................: 1      min=0             max=1691

level=error msg="thresholds on metrics 'http_req_duration' have been crossed"

Plus 423 errors like this one, printed during the run:

level=warning msg="Request Failed" error="Get \"http://tiffin-app:3000/restaurants/42/menu\": dial: i/o timeout"

This is what overload really looks like. At 600 requests a second against a server that can finish about 550, 50 extra requests pile up every second. The queue never drains, so latency doesn't settle at a higher level, it keeps growing: p99 went from 917 ms to over a second within 30 seconds. Some new connections couldn't even get in: the server's queue of waiting connections was full, and k6 gave up dialling. That's the S / (1 - u) curve from the last lesson with u above 1.

Two new lines to read:

• vus max=1691: to keep sending 600 a second while requests took longer and longer, k6 needed nearly 1,700 virtual users in flight at once. That's Little's law again: requests in flight equals the rate times how long each one takes, and some were taking a minute.
• dropped_iterations: 1802: requests k6 should have started but couldn't, because it ran out of free virtual users. Either raise maxVUs and rerun, or treat it as one more sign the server is far past its limit. Either way, don't ignore it.

Notice also that the error rate, 0.33%, passed its threshold. Errors are a lagging and incomplete signal of overload; latency is the early one.

A checklist for reading any load test

1. Offered load vs completed load. If the server completes less than you offer, you've found the ceiling. If you can't tell what you offered, you're running a closed model.
2. Percentiles per minute, never just the whole-run summary.
3. Errors including timeouts, and k6's dropped_iterations.
4. The server's saturation, CPU and whatever else from the last lesson's table, lined up with the same minutes.
5. The load generator's own CPU. If it's above about 80%, the test is measuring the laptop.
6. Split by endpoint. Tag requests by name; a slow checkout can hide inside a fast average of menu reads. A threshold can target one tag: 'http_req_duration{name:place_order}': ['p(99)<1500'].

For the real Tiffin server, the same steps produce the table in the last lesson: a knee near 1,400 requests a second, and a Friday peak of 1,800 that was past it.