Timeouts

The previous topic built indicators and left this behind: a crossed limit is now visible, but the system still behaves the same way — measuring changes nothing. What changes it is a limit placed in the code, and this lesson’s job is to measure where it is placed.

The effect of a timeout was measured in M19/K05 Resilience and Reliability and is not repeated here. What is measured here differs: how many lines and configuration values appear when the same limit sits at two layers, how many call sites it covers, and how many it skips.

RS1 — the unit of measure is the call site: every source expression making an outbound call is a call site. The loan service reaches four dependencies from seven call sites.

Mechanism

The dependencies are local processes: catalog and membership respond fast, billing takes 500 ms, and notification keeps the connection open and never writes a response. The loan service also runs; in the nested-limits section it is the middle layer.

// services.mjs — the split loan system's dependencies and the loan service itself.
// RS2: notification keeps the connection open, never responds. 8103/counter returns all counters.
import { createServer, request } from "node:http";
const s = { open: { notification: 0 }, total: { notification: 0 }, orphaned: 0 };  // orphaned: work that finishes after the caller gave up
for (const [port, name, delay] of [[8101, "catalog", 5], [8102, "membership", 5], [8104, "billing", 500]]) {
  s.open[name] = 0; s.total[name] = 0;
  createServer((req, res) => { s.open[name] += 1; s.total[name] += 1;
    setTimeout(() => { s.open[name] -= 1; res.end("{}"); }, delay);
  }).listen(port);
}
createServer((req, res) => {                        // 8103 notification + counter endpoint
  if (req.url === "/counter") return res.end(JSON.stringify(s));
  if (req.url === "/reset") { s.orphaned = 0; for (const k in s.total) s.total[k] = 0; return res.end("{}"); }
  s.open.notification += 1; s.total.notification += 1;
  req.on("close", () => { s.open.notification -= 1; });   // response never written: call stays hanging
}).listen(8103);
createServer((req, res) => {                        // 8100 loan: applies its own inner limit
  let gaveUp = false;
  req.on("close", () => { gaveUp = !res.writableEnded; });
  const r = request({ port: 8104, path: "/fee", agent: false }, (c) => {
    c.resume(); c.on("end", () => { if (gaveUp) s.orphaned += 1; else res.end('{"fee":1}'); });
  });
  r.setTimeout(Number(new URL(req.url, "http://x").searchParams.get("inner")), () => r.destroy(new Error("inner")));
  r.on("error", () => { if (!gaveUp) res.end('{"error":"inner"}'); });
  r.end();
}).listen(8100);

The calling side is written three times, in three directories. none/ is the unlimited case; a/ places the limit at the call site, so every request carries its own setTimeout line and value; b/ places it in the client wrapper. All three come from the same seven call sites, so the difference comes only from placement.

// setup.mjs — generates the same seven call sites in three placements: unlimited, at the site, in the wrapper.
import { mkdirSync, writeFileSync } from "node:fs";
const UNCOVERED = "repeatNotification";              // RS4: call site forgotten when moving to the wrapper
const C = [["loan", "searchBook", 8101, "/search", 200], ["loan", "bookDetail", 8101, "/book", 200],
  ["loan", "verifyMember", 8102, "/member", 200], ["loan", "memberPenalty", 8102, "/penalty", 200],
  ["loan", "lateFee", 8104, "/fee", 800],
  ["notification", "sendNotification", 8103, "/send", 800],
  ["notification", UNCOVERED, 8103, "/repeat", 800]];
const raw = ([, name, port, path, limit], place) => `export function ${name}() {
  return new Promise((resolve, reject) => {
    const r = request({ port: ${port}, path: "${path}" }, (y) => { y.resume(); y.on("end", resolve); });${
  place ? `\n    r.setTimeout(${limit}, () => r.destroy(new Error("timeout")));` : ""}
    r.on("error", reject); r.end();
  });
}`;
const wrapped = ([, name, port, path]) => `export const ${name} = () => sendRequest(${port}, "${path}", "${path.slice(1)}");`;
for (const [dir, place, wrap] of [["none", false, false], ["a", true, false], ["b", false, true]]) {
  mkdirSync(dir, { recursive: true });
  for (const m of ["loan", "notification"]) {
    const g = C.filter((x) => x[0] === m);
    const s = wrap ? g.filter((x) => x[1] !== UNCOVERED) : [], h = g.filter((x) => !s.includes(x));
    writeFileSync(`${dir}/${m}.mjs`, `// ${dir}/${m}.mjs\n` +
      (h.length ? 'import { request } from "node:http";\n' : "") +
      (s.length ? 'import { sendRequest } from "../client.mjs";\n' : "") +
      [...s.map(wrapped), ...h.map((x) => raw(x, place))].join("\n") + "\n");
  }
}

UNCOVERED is this lesson’s core: the repeat path in notification never moved into the wrapper. Once a limit sits somewhere, a call site that never passes through it shows no gap in the source.

// client.mjs — client wrapper: every outbound call goes through here, the duration limit applies here.
import { request } from "node:http";
export const DEFAULT = { duration: 800 };            // RS3: one default, can be passed at the call site
export function sendRequest(port, path, name, options = {}) {
  const duration = options.duration ?? DEFAULT.duration;
  return new Promise((resolve, reject) => {
    const r = request({ port, path }, (y) => { y.resume(); y.on("end", () => resolve(name)); });
    r.setTimeout(duration, () => r.destroy(new Error(`timeout ${duration} ms`)));
    r.on("error", reject); r.end();
  });
}

The Cost of Placement in Source and at Runtime

The measurement script scans the three directories, runs all three versions against the live services and reads how many requests stay open on the dependency from its own counter, then tries the outer and inner limit with four pairs.

// measure.mjs — covered/uncovered call sites, hanging calls, and the conflict between nested limits.
import { readdirSync, readFileSync } from "node:fs";
import { request } from "node:http";
const ROUND = 4, WINDOW = 1500, N = 10, DEPENDENCY = 500;   // billing's fixed delay is 500 ms
const V = { none: "no limit", a: "at call site", b: "in client wrapper" };
const count = (m, d) => (m.match(d) || []).length;
const print = (g, a, ...r) => console.log(String(a).padEnd(26) + r.map((x) => String(x).padStart(g)).join(""));
const wait = (ms) => new Promise((c) => setTimeout(c, ms));
const counter = (path = "/counter") => new Promise((c) => request({ port: 8103, path }, (r) => {
  let g = ""; r.on("data", (p) => (g += p)); r.on("end", () => c(g === "{}" ? null : JSON.parse(g)));
}).end());
const scan = (d) => readdirSync(d).map((a) => readFileSync(`${d}/${a}`, "utf8"))   // [file, line, raw, wrapped, limit]
  .reduce((a, m) => [a[0] + 1, a[1] + m.split("\n").filter((x) => x.trim()).length,
    a[2] + count(m, /\brequest\(\{/g), a[3] + count(m, /\bsendRequest\(/g), a[4] + count(m, /\.setTimeout\(/g)], [0, 0, 0, 0, 0]);

async function run(d) {                              // runs the seven call sites against the live services
  const m = { ...(await import(`./${d}/loan.mjs`)), ...(await import(`./${d}/notification.mjs`)) };
  const c = { done: 0, failed: 0 }, name = Object.keys(m), once = (await counter()).open.notification;
  for (let t = 0; t < ROUND; t += 1) for (const a of name) m[a]().then(() => { c.done += 1; }, () => { c.failed += 1; });
  await wait(WINDOW);
  return { n: name.length * ROUND, ...c, open: (await counter()).open.notification - once };
}
const gateway = (outer, inner) => new Promise((resolve) => {   // gateway -> loan:8100 -> billing:8104
  const t0 = process.hrtime.bigint();
  const done = (s) => resolve({ s, ms: Number(process.hrtime.bigint() - t0) / 1e6 });
  const r = request({ port: 8100, path: `/fee?inner=${inner}`, agent: false }, (y) => {
    let g = ""; y.on("data", (p) => (g += p)); y.on("end", () => done(g.includes("error") ? "inner error" : "response"));
  });
  r.setTimeout(outer, () => r.destroy(new Error("outer")));
  r.on("error", () => done("outer timeout")); r.end();
});

const wrapperLines = readFileSync("client.mjs", "utf8").split("\n").filter((x) => x.trim()).length;
print(13, "placement", "file", "line", "call site", "wrapped", "uncovered", "limit line");
for (const [d, name] of Object.entries(V)) {
  const [file, line, raw, wrp, lim] = scan(d), b = d === "b";
  print(13, name, file + b, line + (b ? wrapperLines : 0), raw + wrp, d === "a" ? lim : wrp, d === "a" ? 0 : raw, lim + b);
}
const values = ["a/loan.mjs", "a/notification.mjs"].flatMap((f) => readFileSync(f, "utf8").match(/setTimeout\((\d+)/g));
console.log(`configuration surface: ${values.length} numbers at the call site, ${new Set(values).size} distinct values ` +
  `(${[...new Set(values)].map((x) => x.slice(11)).join(" / ")} ms); 1 default in the wrapper, 0 overrides`);

console.log(`\n${ROUND} rounds x 7 call sites; observation window ${WINDOW} ms`);
print(13, "placement", "calls", "response", "timeout", "hanging", "open request");
for (const [d, name] of Object.entries(V)) {
  const r = await run(d);
  print(13, name, r.n, r.done, r.failed, r.n - r.done - r.failed, r.open);
}

console.log(`\nnested limits: dependency's fixed delay ${DEPENDENCY} ms, ${N} requests per pair;` +
  `\n  the measured ms is this run's average, rounded to 100`);
print(22, "outer limit / inner limit", "result", "measured ms", "calls to dependency", "orphaned completion");
for (const [outer, inner] of [[300, 800], [800, 300], [800, 800], [800, 100]]) {
  await counter("/reset");
  const r = await Promise.all(Array.from({ length: N }, () => gateway(outer, inner)));
  await wait(DEPENDENCY + 300);                     // waits for the dependency to finish its work
  const s = await counter();
  print(22, `${outer} / ${inner}`, [...new Set(r.map((x) => x.s))].join("+"),
    Math.round(r.reduce((a, x) => a + x.ms, 0) / N / 100) * 100, s.total.billing, s.orphaned);
}
process.exit(0);

node services.mjs > /dev/null 2>&1 & SP=$!
sleep 1; node measure.mjs; kill $SP

placement                          file         line    call site      wrapped    uncovered   limit line
no limit                              2           46            7            0            7            0
at call site                          2           53            7            7            0            7
in client wrapper                     3           28            7            6            1            1
configuration surface: 7 numbers at the call site, 2 distinct values (200 / 800 ms); 1 default in the wrapper, 0 overrides

4 rounds x 7 call sites; observation window 1500 ms
placement                         calls     response      timeout      hanging open request
no limit                             28           20            0            8            8
at call site                         28           20            8            0            0
in client wrapper                    28           20            4            4            4

nested limits: dependency's fixed delay 500 ms, 10 requests per pair;
  the measured ms is this run's average, rounded to 100
outer limit / inner limit                 result           measured ms   calls to dependency   orphaned completion
300 / 800                          outer timeout                   300                    10                    10
800 / 300                            inner error                   300                    10                     0
800 / 800                               response                   500                    10                     0
800 / 100                            inner error                   100                    10                     0

The unlimited row says the client has no default timeout: 20 of 28 calls got a response, 8 got neither response nor error, and 8 stayed open on the dependency when the window closed. This 8 is independent of run duration — it would still be 8 at a 15-minute window, since nothing exists to finish those calls.

The limit at the call site takes the source from 46 lines to 53 — one extra line per call site — and spreads the configuration surface across seven numbers; those seven hold only two distinct values, so five are duplicates. Coverage, in return, is complete: 7 wrapped, 0 uncovered, 0 hanging. With the limit at the call site, no call site can be forgotten — a forgotten limit would be a line never written.

The wrapper version runs the other way. Its total is shorter — two modules and the wrapper come to 28 lines, below even the unlimited case — because it absorbs the limit and the repetition of building the request. What is lost is per-dependency tuning: catalog was 200 ms at the call site, 800 ms in the wrapper.

Uncovered Call Site

The last two columns of the wrapper row are this lesson’s real measure: 6 wrapped, 1 uncovered call site. The cost shows at runtime: 4 of 28 calls stay hanging — exactly half the unlimited case.

The difference is not only in number but in information state: in the unlimited case every call site is suspect and the author knows it; with the wrapper, six are safe and one lies. The rule that follows: wrapper placement is incomplete without a coverage check. What scan does — searching for a raw call constructor — must keep running.

The Conflict of Nested Limits

The third table runs the same work through three layers, and each layer’s limit knows nothing of the others.

The first row names the misconfiguration: the inner limit is larger than the outer one. The gateway gives up at 300 ms, the loan service keeps waiting, the dependency finishes at 500 ms, and the response goes to no one: 10 orphaned completions. No indicator counts this as an error — from its own view, the loan service made a successful call.

In the second row the inner limit is smaller: the loan service gives up first, a named error goes back to the gateway, and orphaned completions drop to zero. Limits growing from the inside out is an ordering rule, not a preference. The fourth row is the other end of it: once the inner limit drops below the dependency’s delay (100 ms against 500 ms), every call fails though nothing is wrong with the dependency.

The column common to all three rows gives the real lesson: calls reaching the dependency stay at 10 for every setting. A timeout does not reduce load, it only frees the one waiting.

Testability

Where the limit sits decides how its behavior gets triggered in a test.

// test/limit.test.mjs — how the same behavior is triggered under two placements.
import { test } from "node:test";
import assert from "node:assert/strict";
import { DEFAULT } from "../client.mjs";
import * as A from "../a/notification.mjs";
import * as B from "../b/notification.mjs";
const bucket = (g) => (g < 100 ? "under 100 ms" : `~${Math.round(g / 100) * 100} ms`);
const duration = async (f) => { const t = Date.now(); await assert.rejects(f()); return Date.now() - t; };

test("the limit at the call site is a constant: the test waits that long", async () => {
  const g = await duration(A.sendNotification);
  assert.ok(g >= 700, `limit 800 ms; measured ${g}`);
  console.log(`  at call site: rejected ${bucket(g)}`);
});
test("the limit in the wrapper is lowered from one place", async () => {
  DEFAULT.duration = 20;
  const g = await duration(B.sendNotification);
  assert.ok(g < 200, `limit 20 ms; measured ${g}`);
  console.log(`  in wrapper: rejected ${bucket(g)}`);
});
test("the uncovered call site is unaffected by the wrapper's setting", async () => {
  assert.equal(await Promise.race([B.repeatNotification().then(() => "response", () => "rejected"),
    new Promise((c) => setTimeout(() => c("still hanging"), 300))]), "still hanging");
});

node services.mjs > /dev/null 2>&1 & SP=$!
sleep 1
node --test --test-force-exit --test-reporter=tap test/limit.test.mjs |
  grep -E "^(ok|not ok|#   |# (tests|pass|fail) )"
kill $SP

#   at call site: rejected ~800 ms
ok 1 - the limit at the call site is a constant: the test waits that long
#   in wrapper: rejected under 100 ms
ok 2 - the limit in the wrapper is lowered from one place
ok 3 - the uncovered call site is unaffected by the wrapper's setting
# tests 3
# pass 3
# fail 0

The limit at the call site is a constant; the test has no handle to change it and must wait out the real duration. The limit in the wrapper is a variable; the test lowers the default to 20 ms and verifies the same branch in under 100 ms. The run-independent quantity is the limits’ ratio: forty times.

The third test turns this lesson’s measure into a test: even with the default at 20 ms, the uncovered call site is still hanging after 300 ms. If coverage can be measured as a number, it can be verified in a test. No such test can be written for the call-site placement — there is no coverage concept left to verify.

Summary

• The effect of a timeout was measured in M19/K05 Resilience and Reliability; measured here is where the limit sits in the code. The client has no default limit: 8 of 28 calls never resolved, and 8 requests stayed open on the dependency.
• Call-site placement takes 46 lines to 53 and spreads the configuration surface across seven numbers (two distinct values, five duplicates), but coverage is complete: 7 wrapped, 0 uncovered.
• Wrapper placement is shorter (28 lines) with a single configuration surface, but does not guarantee coverage: 6 wrapped, 1 uncovered, 4 hanging calls. The gap shows nowhere in the source; only scanning finds it.
• When the inner limit exceeds the outer one, the outer layer gives up while the inner keeps working: 10 of 10 requests produce an orphaned completion — an ordering rule, not a preference.
• Calls reaching the dependency stay at 10 across all four settings; a timeout frees the one waiting, it does not reduce the load. Whether the limit is a variable decides testability: the uncovered call site can be tested directly.

Next Step

The limit is placed and the waiting side is freed, but it is left holding an error, and nothing says what to do with it. The closest answer is retrying. Where that decision sits is also a placement question, and more dangerous than the timeout: a timeout does not change the dependency’s load, while a retry multiplies it directly. The next lesson measures which layer the retry sits in — the same rule built into three layers, then all three opened at once, counting how many calls one user request turns into on the dependency.