f070914362
Every HTTP request now gets a requestId (inbound X-Request-Id header is
honored, otherwise a fresh UUID is minted) and the value is echoed on
the response. The server wraps the request in
\`requestContext.run({ requestId }, ...)\` — an AsyncLocalStorage scope —
so pino's \`mixin\` callback can read it on every log call without the
caller threading it through.
Net effect: \`logger.info({ ... }, \"db error\")\` from a loader, action,
or downstream lib now lands in JSON with a \`requestId\` field, making
cross-handler debugging trivial (\`grep requestId=abc-123\` returns the
full request trace).
Out of scope here:
- Planner gets the same treatment (separate, smaller PR after this lands).
- BRouter / Fedify outbound calls don't propagate the requestId yet —
those are HTTP boundaries where we'd add it as a header, but the
audit value was the in-process trace.
Tests:
- logger.server.test.ts (2 cases — als-bound info tags requestId; no
context = no tag).
Full repo: pnpm typecheck, pnpm lint, pnpm test all green.
Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
49 lines
1.6 KiB
TypeScript
49 lines
1.6 KiB
TypeScript
import { describe, it, expect } from "vitest";
|
|
import { Writable } from "node:stream";
|
|
import pino from "pino";
|
|
import { AsyncLocalStorage } from "node:async_hooks";
|
|
|
|
// We test the *mixin contract* — that pino's `mixin` callback reads
|
|
// from the async-local store and tags every record. Constructing a
|
|
// fresh pino instance per test (vs. importing the module-level one)
|
|
// lets us capture stdout cleanly.
|
|
|
|
describe("logger mixin attaches requestId from async context", () => {
|
|
function captureLogger(als: AsyncLocalStorage<{ requestId: string }>) {
|
|
const lines: string[] = [];
|
|
const sink = new Writable({
|
|
write(chunk, _enc, cb) {
|
|
lines.push(chunk.toString());
|
|
cb();
|
|
},
|
|
});
|
|
const lg = pino(
|
|
{
|
|
level: "info",
|
|
mixin: () => {
|
|
const ctx = als.getStore();
|
|
return ctx ? { requestId: ctx.requestId } : {};
|
|
},
|
|
},
|
|
sink,
|
|
);
|
|
return { lg, lines };
|
|
}
|
|
|
|
it("tags log records with requestId when inside als.run()", () => {
|
|
const als = new AsyncLocalStorage<{ requestId: string }>();
|
|
const { lg, lines } = captureLogger(als);
|
|
als.run({ requestId: "abc-123" }, () => lg.info("hello"));
|
|
const record = JSON.parse(lines[0]!);
|
|
expect(record.requestId).toBe("abc-123");
|
|
expect(record.msg).toBe("hello");
|
|
});
|
|
|
|
it("omits requestId when no async context is active", () => {
|
|
const als = new AsyncLocalStorage<{ requestId: string }>();
|
|
const { lg, lines } = captureLogger(als);
|
|
lg.info("bare");
|
|
const record = JSON.parse(lines[0]!);
|
|
expect(record.requestId).toBeUndefined();
|
|
});
|
|
});
|