---
title: 'Bottleneck Analysis'
source: 'https://academia.sh/en/courses/non-functional-testing/bottleneck-analysis'
course: 'Non-Functional Testing'
language: en
updated: '2026-08-23T14:25:15+00:00'
license: 'CC BY-SA 4.0'
---

# Bottleneck Analysis

Tying a load-test result to a layer: measuring application, database and transfer duration separately within a request, attributing three modes that give the same client-side symptom to three separate layers, scanning the attribution rule against a share threshold, and showing with numbers a case where the time genuinely is spent in the right layer but the cause is a different decision.

The previous lesson's report reduced the result to a single sentence: p99 37.59 ms,
threshold 20, fail. That sentence reports a defect but does not say **where** it is. The
same number could come from a computation in the application layer, a query in the
database, or the size of the response, and the fix for each of the three is different.
This lesson takes on tying the result to a layer.

## Layer Share

A request's total duration is measured at the client and is a single number. The
**bottleneck** is wherever consumes most of that duration; finding it requires splitting
the duration **inside** the request. The server reads three clocks on every request:
before the query, after the query, after the computation, and after the response is
written. The gaps between them are the **database**, **application** and **transfer**
layers' durations.

These three numbers alone are not enough, because every layer does some work on every
request. What matters is the **difference**: a **baseline** run carrying no defect is
taken on the same harness, and each layer's duration is read as its difference from the
baseline. **Layer share** is a layer's difference divided by the client's difference.

**NF6 (assumption) — to attribute a result to one layer, that layer's share must be at
least 0.50; otherwise the result counts as unattributable.** Rationale: below a share of
0.50, even completely eliminating that layer removes less than half the symptom, and the
fix decision cannot be defended. The threshold is scanned below.

The decision's owner is a budget: attribution decides which team and which work the fix
goes to. A wrong attribution does not just waste time, it leaves the defect in place. The
Performance Anti-Patterns and Monitoring course built ten diagnoses running from symptom to
cause; the question asked here comes before that: which layer the result **belongs to**.

## Harness

The loan endpoint runs in five modes. **baseline** does an indexed query and a small
response; **db** does the same query unindexed; **app** runs a computation round in the
application layer; **net** serializes and writes a 4,000-row page fetched once at startup
on every response; **mixed** re-fetches the same page from the database on every request.
All four are tuned to give the same symptom.

```js
// library/server.mjs — loan endpoint, five modes. Every request measures three layers'
// duration separately: database (query), application (computation), transfer (serialization + writing the response).
// Arguments: <port> <mode baseline|db|app|net|mixed>
import { createServer } from "node:http";
import { DatabaseSync } from "node:sqlite";

const MEMBER = 500, START = 55000, ROUNDS = 29000, ROW = 4000;   // catalog size, computation rounds, page rows
const port = Number(process.argv[2]), mode = process.argv[3];

if (Number.isInteger(port) === false || ["baseline", "db", "app", "net", "mixed"].includes(mode) === false) {
  console.log("usage: node library/server.mjs <port> baseline|db|app|net|mixed");
} else {
  const db = new DatabaseSync(":memory:");
  db.exec("CREATE TABLE loan(id INTEGER PRIMARY KEY, member_no TEXT, book_no TEXT, day INT)");
  if (mode !== "db") db.exec("CREATE INDEX loan_member ON loan(member_no)");
  db.exec("BEGIN");
  const fill = db.prepare("INSERT INTO loan(member_no, book_no, day) VALUES(?,?,?)");
  for (let i = 0; i < START; i += 1) fill.run(`U-${i % MEMBER}`, `K-${i % 9000}`, i % 400);
  db.exec("COMMIT");

  const count = db.prepare("SELECT COUNT(*) AS n FROM loan WHERE member_no = ?");
  const fetch = db.prepare("SELECT id, book_no, day FROM loan LIMIT ?");
  const cache = mode === "net" ? fetch.all(ROW) : [];   // in net mode the page is fetched once at startup
  let requests = 0, dbTime = 0, appTime = 0, netTime = 0, bytes = 0, scan = 0, computed = 0;

  createServer((req, res) => {
    const u = new URL(req.url, "http://local");
    if (u.pathname === "/metrics") {
      res.writeHead(200, { "content-type": "application/json" });
      res.end(JSON.stringify({ requests, dbTime, appTime, netTime, bytes, scan, computed })); return;
    }
    requests += 1;
    const member = u.searchParams.get("member") ?? "U-1";
    const t0 = performance.now();
    const n = count.get(member).n;                    // database layer
    const page = mode === "mixed" ? fetch.all(ROW) : cache;
    scan += mode === "db" ? START : Math.ceil(Math.log2(START));
    const t1 = performance.now();
    let summary = "";                                 // application layer
    if (mode === "app") for (let k = 0; k < ROUNDS; k += 1) { summary = `${member}/${(n + k) % 97}`; computed += 1; }
    const t2 = performance.now();
    const body = JSON.stringify({ member, loan: n, summary, page });   // transfer layer
    dbTime += t1 - t0; appTime += t2 - t1; bytes += body.length;
    res.writeHead(200, { "content-type": "application/json" });
    res.on("finish", () => { netTime += performance.now() - t2; });
    res.end(body);
  }).listen(port);
}
```

The generator excludes the first second from the measurement and reads the server counters
once more at the start of that window, so that both the client and the server side describe
the same interval.

```js
// library/measure.mjs — open-loop generator; reads the client duration and the server's
// layer counters. Arguments: <port> <mode> <target rate> <duration s>
import { Agent, request } from "node:http";

const WARMUP = 1;   // the first second is not counted: JIT and cache warm-up
const [port, mode, rate, duration] = process.argv.slice(2).map((x, i) => (i === 1 ? x : Number(x)));
const agent = new Agent({ keepAlive: true, maxSockets: 8192 });
const percentile = (d, p) => { const t = [...d].sort((a, b) => a - b);
  return t[Math.min(t.length - 1, Math.floor((p / 100) * t.length))]; };
let seq = 0;

function oneRequest(samples, sec) {
  const start = performance.now(), i = seq++;
  return new Promise((done) => {
    const r = request({ port, path: `/loan?member=U-${i % 500}`, agent }, (y) => {
      y.resume(); y.on("end", () => { samples.push({ ms: performance.now() - start, sec }); done(); });
    });
    r.on("error", () => { samples.push({ ms: performance.now() - start, sec }); done(); });
    r.end();
  });
}

const metrics = () => new Promise((done) => {
  request({ port, path: "/metrics", agent }, (y) => { let g = "";
    y.on("data", (p) => { g += p; }); y.on("end", () => done(JSON.parse(g))); }).end();
});

if (Number.isInteger(port) === false) {
  console.log("usage: node library/measure.mjs <port> <mode> <target rate> <duration>");
} else {
  const samples = [], inFlight = [];
  let debt = 0, lastT = 0, m1 = null;
  const start = performance.now();
  while (performance.now() - start < duration * 1000) {
    const t = (performance.now() - start) / 1000;
    if (m1 === null && t >= WARMUP) m1 = await metrics();     // the warm-up window closes here
    debt += rate * (t - lastT); lastT = t;
    while (debt >= 1) { debt -= 1; inFlight.push(oneRequest(samples, t)); }
    await new Promise((c) => setTimeout(c, 5));
  }
  await Promise.all(inFlight);
  const m2 = await metrics(), n = m2.requests - m1.requests;
  const d = samples.filter((r) => r.sec >= WARMUP).map((r) => r.ms);
  console.log(JSON.stringify({ mode, rate, samples: d.length,
    client: d.reduce((a, b) => a + b, 0) / d.length, p95: percentile(d, 95),
    db: (m2.dbTime - m1.dbTime) / n, app: (m2.appTime - m1.appTime) / n, net: (m2.netTime - m1.netTime) / n,
    bytes: (m2.bytes - m1.bytes) / n, scan: (m2.scan - m1.scan) / n }));
}
agent.destroy();
```

```js
// library/attribution.mjs — computes layer shares against the baseline, ties attribution to
// a rule, and scans the share threshold. Argument: <jsonl>
import { readFileSync } from "node:fs";

const SHARE = 0.5;                                  // NF6: minimum share to attribute to one layer
const ACTUAL = { db: "database", app: "application", net: "transfer", mixed: "transfer" };
const LAYER = ["db", "app", "net"], NAME = { db: "database", app: "application", net: "transfer" };
const s = readFileSync(process.argv[2], "utf8").trim().split("\n").map((x) => JSON.parse(x));
const find = (k) => s.find((r) => r.mode === k);
const BASE = find("baseline"), MODE = ["db", "app", "net", "mixed"];
const fmt = (x, n = 3) => x.toFixed(n);
const pad = (x, n) => String(x).padStart(n);
const diff = (r) => ({ client: r.client - BASE.client, db: r.db - BASE.db, app: r.app - BASE.app, net: r.net - BASE.net });
const attribute = (r, threshold) => {               // if the largest share crosses the threshold, that layer
  const f = diff(r);
  const top = LAYER.reduce((a, k) => (f[k] > f[a] ? k : a), "db");
  return f[top] / f.client >= threshold ? NAME[top] : "unattributable";
};

console.log(`baseline: client ${fmt(BASE.client)} ms, db ${fmt(BASE.db)}, app ${fmt(BASE.app)}, transfer ${fmt(BASE.net)}, ` +
  `bytes ${Math.round(BASE.bytes)}`);
console.log("mode    client   p95   diff   db share  app share  transfer share  bytes    attribution");
for (const k of MODE) {
  const r = find(k), f = diff(r);
  console.log(k.padEnd(8) + pad(fmt(r.client, 2), 7) + pad(fmt(r.p95, 2), 6) + pad(fmt(f.client, 2), 7) +
    pad(fmt(f.db / f.client, 2), 9) + pad(fmt(f.app / f.client, 2), 10) + pad(fmt(f.net / f.client, 2), 14) +
    pad(Math.round(r.bytes), 9) + "  " + attribute(r, SHARE));
}

console.log("\nshare-threshold scan: the four modes' attribution (actual layer: db=database, " +
  "app=application, net and mixed=transfer)");
console.log("share threshold  correct /4  wrong /4  unattributable /4");
for (const e of [0.3, 0.5, 0.7, 0.8, 1.0]) {
  const a = MODE.map((k) => attribute(find(k), e));
  const correct = a.filter((x, i) => x === ACTUAL[MODE[i]]).length;
  const none = a.filter((x) => x === "unattributable").length;
  console.log(fmt(e, 1).padEnd(17) + pad(correct, 11) + pad(4 - correct - none, 10) + pad(none, 18));
}
```

```bash
# measure.sh — five runs: baseline and four modes, at the same target rate, each with a fresh server.
rm -f result.jsonl
for M in baseline db app net mixed; do
  node library/server.mjs 8854 $M & SERVER=$!
  sleep 1.2
  node library/measure.mjs 8854 $M 250 6 >> result.jsonl
  kill $SERVER
  wait $SERVER 2>/dev/null
done
node library/attribution.mjs result.jsonl
```

```
baseline: client 0.629 ms, db 0.032, app 0.000, transfer 0.108, bytes 56
mode    client   p95   diff   db share  app share  transfer share  bytes    attribution
db         2.11  3.45   1.48     0.98     -0.00         -0.06       56  database
app        1.49  2.60   0.86    -0.01      0.90         -0.03       63  application
net        1.51  2.74   0.88    -0.03     -0.00          0.98   160738  transfer
mixed      2.16  3.62   1.53     0.55     -0.00          0.35   160738  database

share-threshold scan: the four modes' attribution (actual layer: db=database, app=application, net and mixed=transfer)
share threshold  correct /4  wrong /4  unattributable /4
0.3                        3         1                 0
0.5                        3         1                 0
0.7                        3         0                 1
0.8                        3         0                 1
1.0                        0         0                 4
```

## Same Symptom, Three Separate Layers

The first column is the decision itself, and it is the same across all four modes. In this
run the client average ranges from 1.49 to 2.16 ms — about 45% higher at the top than at
the bottom; p95 ranges from 2.60 to 3.62 ms across the four modes. A report that looks only
at the client-side number **cannot tell these four structures apart**.

The share columns tell them apart. In `db` mode the database share is 0.98, in `app` mode
the application share is 0.90, in `net` mode the transfer share is 0.98. Three modes give
the same symptom and get attributed to three separate layers; their fixes are different too
— adding an index, thinning the computation, shrinking the response.

None of the shares in this run exceed 1, but the measurement allows it: if the database
difference came out larger than the client difference, that would show the baseline's own
noise growing relative to a small difference between two runs. The rule only looks at the
largest share, so the attribution would not change; a share over 1 just means the reading
is "the database explains the entire symptom," nothing more.

## When Attribution Is Wrong

The fourth row is where the rule breaks. In `mixed` mode the database share is 0.55, the
transfer share is 0.35; the rule blames the database. The measurement is correct: time
really is spent in the query, because the query reads 4,000 rows. **The result is still
wrong.**

The evidence is in the last column, and it is independent of the run: `mixed` and `net`
send the **same 160,738 bytes** per response. In `net` mode that page was fetched once at
startup and cached, so the database share is near zero and the rule blames transfer. The
difference between the two modes is not in the query, it is in **the decision about the
size of the response** — and that decision is the same in both. Adding an index to the
database in `mixed` mode changes nothing; the query does not need an index, it reads
4,000 rows regardless.

The rule is this: **layer share says where the time went, not which decision produced it.**
The measurement that answers the second question is a run-independent quantity — bytes
sent, rows read, records scanned. In this run `db` mode scans 55,000 rows per request, the
others scan 16; `net` and `mixed` send 160,738 bytes per request, the others send 56 and
63. Wherever two layers give the same symptom, this is the measurement that tells them
apart.

## Share Threshold Scan

The second table shifts NF6's 0.50. The table's individual numbers are run-dependent — a
share is drawn from measured duration differences and moves from run to run on this machine
— but **its direction is run-independent** and the decision is made in that direction. At a
low threshold all four modes get attributed to a layer and `mixed` gets a **wrong
attribution**; as the threshold rises, the wrong attribution clears first, then the correct
ones start falling under the threshold too and turn **unattributable**. In this run the
turn starts at 0.7, where `mixed` drops out; the other three hold their attribution up to
just under 1.0, since their own shares (0.98, 0.90, 0.98) sit close to the ceiling, and at
exactly 1.0 none of them clears it either — in another run the turn could start a step
earlier or later, because what crosses the threshold is the share itself.

This is the trade-off between the two error types. A low threshold blames an innocent
layer; a high threshold cannot pin the defect on anyone, and the finding closes without
becoming a record. NF6's 0.50 does not clear the wrong attribution by itself — what clears
it is not the threshold but reading the run-independent quantity.

## Cost and the Class It Misses

The run-dependent side of the cost depends on the environment: five runs finished in under
forty seconds on this machine. The run-independent side is countable — five server
processes, five of every six seconds measured per run (the first second is set aside for
warm-up), and every run reads four clocks per request, meaning instrumentation adds four
extra measurements per request.

The class it misses can also be counted: this harness only splits duration **inside the
server**. The residual between the client's difference and the sum of the measured layers
— about 14% of the difference in `app` mode — is written to no layer. Network round trip,
event-loop wait and the operating system's socket work stay there. In a system approaching
saturation this residual grows and share-based attribution stops being usable; the metric
to read then is not layer share but the previous lesson's throughput–latency pair.

## Summary

- Layer share is a layer's difference from the baseline run divided by the client's
  difference; the attribution rule requires the largest share to cross NF6's 0.50.
- The same client-side symptom (average 1.49–2.16 ms) got attributed to three separate
  layers: database at a share of 0.98, application at 0.90, transfer at 0.98.
- Attribution is wrong in `mixed` mode: time really is spent in the query, but it sends
  the same 160,738 bytes as `net`; the cause is not the query, it is the decision about
  response size.
- The share-threshold scan shows the trade-off: as the threshold rises, the wrong
  attribution clears first, then correct attributions fall too and unattributable runs
  climb; which step the turn happens at is run-dependent.
- Layer share says where the time went; the run-independent quantity says which decision
  produced it (55,000 rows scanned, 160,738 bytes sent).

## Next Step

Every number up to this point was read from **a single run**. This lesson's baseline was
taken once and every share was divided by it; the layer-share residual not fully summing
to the client's own difference — about 14% left over in `app` mode — shows that two runs
of the same harness do not give the same number. And the harness excludes the first second
from measurement altogether — the existence of a warm-up effect was assumed but its size
was never measured. The next lesson puts the measurement itself to the test: how many runs
warm-up lasts, how much variability exists between runs of the same structure, and how many
runs a difference between two structures needs before it can be called meaningful.