The Middleware Chain

The previous lesson measured a request’s seven stages and wrote all the work into a single handler. In a real application, most of the same jobs repeat at every endpoint: parsing the body, resolving identity, writing the request to the log, catching the error. Because these do not belong to a single endpoint, they are called cross-cutting concerns.

The structure that gathers cross-cutting concerns into one place is a chain that passes the request through in sequence. This lesson builds that chain for the library loan service and looks for an answer to one question: how much does order matter? The answer will come from running the same links in four separate orders and comparing the results.

The Onion Model

A middleware takes a context representing the request and response, along with a function that calls the rest of the chain. The link does its work, calls next(), and when control returns, it can do a second piece of work. Because of this, the chain is not a flat pipe but nested layers: the request goes in from the outside toward the inside, the response comes back out from the inside toward the outside.

The model has three consequences, and all three shape this lesson’s measurements:

• If a link does not call next(), the chain stops there. When identity checking fails, none of the links behind it run.
• A link’s code after next() runs after everything inside it has finished. Duration measurement and the log’s exit line are written here.
• A link can only catch errors from inside itself. An error thrown by a link outside it never reaches it.

Building the Chain

The program below defines five links and arranges them in four separate orders. The order is chosen from the command line; the links themselves never change.

// middleware.mjs — a chain of links that pass the request through in sequence; the order is chosen from the command line
import { createServer } from "node:http";

let counter = 0;

const write = (ctx, status, body) => {
  const text = JSON.stringify(body);
  ctx.res.writeHead(status, { "content-type": "application/json; charset=utf-8",
    "content-length": Buffer.byteLength(text) });
  ctx.res.end(text);
};

// --- links: each takes (context, next); if next() is not called, the chain stops there ---

const log = async (ctx, next) => {
  console.log(`${ctx.id} -> ${ctx.req.method} ${ctx.req.url}`);
  try {
    await next();
  } finally {
    console.log(`${ctx.id} <- ${ctx.res.headersSent ? ctx.res.statusCode : "no response written"}`);
  }
};

const catchErrors = async (ctx, next) => {
  try {
    await next();
  } catch (err) {
    console.log(`${ctx.id} !! caught: ${err.code ?? err.name}`);
    write(ctx, err.code === "malformed_body" ? 400 : 500,
      { error: err.code ?? "internal_error", requestId: ctx.id });
  }
};

const parseBody = async (ctx, next) => {
  const chunks = [];
  for await (const chunk of ctx.req) chunks.push(chunk);
  const text = Buffer.concat(chunks).toString();
  try {
    ctx.body = text ? JSON.parse(text) : {};
  } catch {
    const err = new Error("body could not be parsed as JSON");
    err.code = "malformed_body";
    throw err;
  }
  await next();
};

const checkIdentity = async (ctx, next) => {
  const member = (ctx.req.headers.authorization ?? "").replace(/^Member /, "");
  if (!/^U-\d{4}$/.test(member)) return write(ctx, 401, { error: "no_identity", requestId: ctx.id });
  ctx.member = member;
  await next();
};

const route = async (ctx) => {
  const path = new URL(ctx.req.url, "http://local").pathname;
  if (path === "/loan" && ctx.req.method === "POST") {
    return write(ctx, 201, { loan: { isbn: ctx.body?.isbn, member: ctx.member }, requestId: ctx.id });
  }
  write(ctx, 404, { error: "route_not_found", requestId: ctx.id });
};

// --- the same links, four separate orders ---

const CHAINS = {
  "catcher-outside": [catchErrors, log, parseBody, checkIdentity, route],
  "identity-first": [catchErrors, checkIdentity, log, parseBody, route],
  "catcher-inside": [log, parseBody, catchErrors, checkIdentity, route],
  "log-outside": [log, catchErrors, parseBody, checkIdentity, route],
};

const choice = process.argv[2] ?? "catcher-outside";
const links = CHAINS[choice];
if (!links) {
  console.error(`unknown chain: ${choice}`);
  process.exit(2);
}

const runChain = (ctx) => {
  const advance = (i) =>
    i === links.length ? Promise.resolve() : links[i](ctx, () => advance(i + 1));
  return advance(0);
};

createServer((req, res) => {
  res.sendDate = false;
  const ctx = { req, res, id: `r-${++counter}` };
  runChain(ctx).catch((err) => {                  // last resort: an error that escaped the chain
    console.log(`${ctx.id} XX escaped the chain: ${err.code ?? err.name}`);
    if (!res.headersSent) write(ctx, 500, { error: "internal_error" });
  });
}).listen(8434, "127.0.0.1", () => console.log(`chain=${choice} 127.0.0.1:8434`));

The chain runner is five lines: advance(i) calls the i-th link and gives it advance(i + 1) as next. Once the end of the list is reached, it returns a resolved promise. The catch in the server callback is the last-resort link that keeps an error escaping the chain from bringing down the process; the measurement will show when this kicks in.

The measurement makes the same three requests for each order: a valid loan request, a request carrying no credential, and a request with a malformed body.

#!/usr/bin/env bash
# Repeats the same three requests for four separate link orders; prints the responses and the server log for each round.
ENDPOINT=http://127.0.0.1:8434/loan

requests() {
  echo "  [1] valid      : $(curl -sS -X POST -H 'authorization: Member U-4711' \
    -H 'content-type: application/json' -d '{"isbn":"978-0262033848"}' "$ENDPOINT")"
  echo "  [2] no identity: $(curl -sS -X POST \
    -H 'content-type: application/json' -d '{"isbn":"978-0262033848"}' "$ENDPOINT")"
  echo "  [3] bad body   : $(curl -sS -X POST -H 'authorization: Member U-4711' \
    -H 'content-type: application/json' -d '{isbn' "$ENDPOINT")"
}

for chain in catcher-outside identity-first catcher-inside log-outside; do
  echo "=== chain: $chain ==="
  node middleware.mjs "$chain" > "log-$chain.txt" 2>&1 & s=$!
  sleep 0.6
  requests
  sleep 0.3
  kill "$s"; wait "$s" 2>/dev/null
  echo "  --- server log ---"
  sed 's/^/  /' "log-$chain.txt"
done

rm -f log-*.txt

=== chain: catcher-outside ===
  [1] valid      : {"loan":{"isbn":"978-0262033848","member":"U-4711"},"requestId":"r-1"}
  [2] no identity: {"error":"no_identity","requestId":"r-2"}
  [3] bad body   : {"error":"malformed_body","requestId":"r-3"}
  --- server log ---
  chain=catcher-outside 127.0.0.1:8434
  r-1 -> POST /loan
  r-1 <- 201
  r-2 -> POST /loan
  r-2 <- 401
  r-3 -> POST /loan
  r-3 <- no response written
  r-3 !! caught: malformed_body
=== chain: identity-first ===
  [1] valid      : {"loan":{"isbn":"978-0262033848","member":"U-4711"},"requestId":"r-1"}
  [2] no identity: {"error":"no_identity","requestId":"r-2"}
  [3] bad body   : {"error":"malformed_body","requestId":"r-3"}
  --- server log ---
  chain=identity-first 127.0.0.1:8434
  r-1 -> POST /loan
  r-1 <- 201
  r-3 -> POST /loan
  r-3 <- no response written
  r-3 !! caught: malformed_body
=== chain: catcher-inside ===
  [1] valid      : {"loan":{"isbn":"978-0262033848","member":"U-4711"},"requestId":"r-1"}
  [2] no identity: {"error":"no_identity","requestId":"r-2"}
  [3] bad body   : {"error":"internal_error"}
  --- server log ---
  chain=catcher-inside 127.0.0.1:8434
  r-1 -> POST /loan
  r-1 <- 201
  r-2 -> POST /loan
  r-2 <- 401
  r-3 -> POST /loan
  r-3 <- no response written
  r-3 XX escaped the chain: malformed_body
=== chain: log-outside ===
  [1] valid      : {"loan":{"isbn":"978-0262033848","member":"U-4711"},"requestId":"r-1"}
  [2] no identity: {"error":"no_identity","requestId":"r-2"}
  [3] bad body   : {"error":"malformed_body","requestId":"r-3"}
  --- server log ---
  chain=log-outside 127.0.0.1:8434
  r-1 -> POST /loan
  r-1 <- 201
  r-2 -> POST /loan
  r-2 <- 401
  r-3 -> POST /loan
  r-3 !! caught: malformed_body
  r-3 <- 400

The Order of Identity Checking and Logging

The responses returned to the client in the first two rounds are identical. Three requests, three identical bodies. The change in order did not change anything the client saw.

In the server log, however, a pair of lines is missing. In the identity-first round, r-2 never appears. Because identity checking comes before logging, the request without a credential stopped at the chain’s second link and never reached the logging link. The application rejected the request without a credential but never recorded it.

The practical consequence of this is severe. A client that floods the library service with requests carrying no credential for an hour leaves no trace during that time. Rejected requests are exactly the requests that most need to be recorded: rate-limit decisions, abuse detection, and debugging all depend on these records.

There is also a reason for the reverse order, and it should not be dismissed. In the identity-first arrangement, a request with no credential is rejected without its body ever being read; in the catcher-outside arrangement, the body is first loaded into memory, and only then does identity checking fail. When requests have large bodies, rejecting them early is a real saving.

The arrangement where the two reasons reconcile is the one where logging is outermost and identity checking comes before body parsing: every request is recorded, and a request with no credential is still rejected without its body being read. The log-outside order in the measurement is exactly this, and the r-2 lines have taken their place in the log.

The Error Catcher’s Scope Comes From Its Position

In the third round, what the client sees changes. In the catcher-inside arrangement, the request with the malformed body gets {"error":"internal_error"}; in the other three arrangements, {"error":"malformed_body"} comes back along with the request id.

The reason is the onion model directly. In the catcher-inside order, catchErrors is inside the parseBody link. When body parsing throws an error, that error propagates outward and never passes through the catcher. The XX escaped the chain line in the log says this: the error was caught not by the chain itself, but by the last-resort handler in the server callback.

The last-resort response is inevitably unqualified. At that point, which link the request broke in, which field is malformed, and what should be told to the user are all unknown; what remains is a 500 and a generic message. A condition that was a user error has been reported as an internal error, the request id could not be placed in the response, and a member seeking support is left with no number to trace.

The rule is this: an error catcher protects only what remains inside itself. If it is meant to protect the whole chain, it must stand as far outside as possible. The last resort is a fallback, not a design; every request that triggers it is a sign of a scope missing from the chain.

The Log Line Writing the Correct State

Comparing the logs of the four rounds shows a flaw in the catcher-outside arrangement: for the third request, r-3 <- no response written was logged, and the catcher’s record came only after that. The log line was written without knowing that the response was 400.

This too comes from the order. When catchErrors is outermost, the log link’s finally block runs while the error is propagating outward — that is, before the catcher writes the response. The log cannot see a decision made outside itself.

In the log-outside arrangement, the two links swap places: logging is outermost, and the error catcher sits right inside it. Now the catcher writes the response, control returns to the log link, and the finally block writes r-3 <- 400. The same three requests, the same five links; only two links have swapped places, and the log is now correct.

From this comes the general rule for ordering a chain: a link must stand outside everything it wants to observe or change. If logging wants to see the response’s final state, it stands outside every link that produces a response; if the error catcher wants to see every error, it stands outside every link that can throw one. Together, the two say that logging must also stand outside the catcher.

Summary

• The middleware chain is the onion model: the request goes in from the outside toward the inside, the response comes back out from the inside toward the outside; a link’s code after next() runs after everything inside it has finished.
• When identity checking comes before logging, a rejected request never appears in the log; in the measurement, the r-2 lines are missing in the identity-first round, while the responses returned to the client are the same across all four arrangements.
• Early identity checking provides the benefit of rejecting without ever reading the body; the two reasons reconcile when logging is placed outermost and identity checking is placed before body parsing.
• An error catcher only sees errors from inside itself; in the catcher-inside arrangement, the malformed body was answered with {"error":"internal_error"}, while in the others {"error":"malformed_body"} came back along with the request id.
• A log line can only see decisions made inside itself; when the catcher stayed outside the logger, the state was recorded as no response written, and once the order was corrected, r-3 <- 400 was written with the correct value.

Next Step

This topic broke a request’s path on the server side into its components: the web server and proxy roles, the runtime’s process model, the request’s stages, and the chain that orders cross-cutting concerns. But the resulting chain’s links still sit in a single file, all side by side. The next topic builds a scaffold that can carry these parts apart: by what criterion are files split, which module is allowed to call which, and is this boundary kept by hand or by a check? The first lesson takes up project structure and writes a check that tests the dependency direction.