feat(planner): per-request requestId propagated through logs
Mirrors PR #429 for the planner app. Each HTTP request now gets a requestId (inbound X-Request-Id honored, otherwise a fresh UUID), echoed on the response, and propagated to every downstream log call via AsyncLocalStorage + pino's \`mixin\`. Tests: planner logger.server.test.ts (2 cases, same shape as the journal version). Full repo: pnpm typecheck, pnpm lint, pnpm test all green. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
parent
59687162b8
commit
4ba98fa8f2
3 changed files with 92 additions and 17 deletions
47
apps/planner/app/lib/logger.server.test.ts
Normal file
47
apps/planner/app/lib/logger.server.test.ts
Normal file
|
|
@ -0,0 +1,47 @@
|
|||
import { describe, it, expect } from "vitest";
|
||||
import { Writable } from "node:stream";
|
||||
import pino from "pino";
|
||||
import { AsyncLocalStorage } from "node:async_hooks";
|
||||
|
||||
// Mirrors the journal's logger test — the mixin contract is what
|
||||
// matters: pino's `mixin` callback reads from AsyncLocalStorage and
|
||||
// tags every record with the active requestId.
|
||||
|
||||
describe("planner 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: "p-abc" }, () => lg.info("hello"));
|
||||
const record = JSON.parse(lines[0]!);
|
||||
expect(record.requestId).toBe("p-abc");
|
||||
});
|
||||
|
||||
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();
|
||||
});
|
||||
});
|
||||
|
|
@ -1,7 +1,25 @@
|
|||
import pino from "pino";
|
||||
import { AsyncLocalStorage } from "node:async_hooks";
|
||||
|
||||
/**
|
||||
* Per-request context propagated through the async stack. The HTTP
|
||||
* server wraps each request in `requestContext.run({ requestId }, ...)`
|
||||
* so every downstream `logger.info(...)` automatically tags log lines
|
||||
* with `requestId` — see apps/journal/app/lib/logger.server.ts for the
|
||||
* same pattern in the journal app.
|
||||
*/
|
||||
export interface RequestContext {
|
||||
requestId: string;
|
||||
}
|
||||
|
||||
export const requestContext = new AsyncLocalStorage<RequestContext>();
|
||||
|
||||
export const logger = pino({
|
||||
level: process.env.LOG_LEVEL ?? "info",
|
||||
mixin: () => {
|
||||
const ctx = requestContext.getStore();
|
||||
return ctx ? { requestId: ctx.requestId } : {};
|
||||
},
|
||||
...(process.env.NODE_ENV !== "production"
|
||||
? { transport: { target: "pino-pretty" } }
|
||||
: {}),
|
||||
|
|
|
|||
|
|
@ -1,6 +1,7 @@
|
|||
import * as Sentry from "@sentry/node";
|
||||
import { nodeSentryConfig, drop404s } from "@trails-cool/sentry-config";
|
||||
import { logger } from "./app/lib/logger.server.ts";
|
||||
import { logger, requestContext } from "./app/lib/logger.server.ts";
|
||||
import { randomUUID } from "node:crypto";
|
||||
import { httpRequestDuration } from "./app/lib/metrics.server.ts";
|
||||
import { createRequestListener } from "@react-router/node";
|
||||
import { createServer, type IncomingMessage, type ServerResponse } from "node:http";
|
||||
|
|
@ -92,23 +93,32 @@ const server = createServer((req, res) => {
|
|||
const url = req.url ?? "/";
|
||||
const start = Date.now();
|
||||
|
||||
// Log and track request on finish (skip static assets and health/metrics)
|
||||
if (!url.startsWith("/assets/") && url !== "/health" && url !== "/metrics") {
|
||||
res.on("finish", () => {
|
||||
const duration = Date.now() - start;
|
||||
logger.info({ method: req.method, path: url, status: res.statusCode, duration }, "request");
|
||||
httpRequestDuration.observe(
|
||||
{ method: req.method ?? "GET", route: url.split("?")[0]!, status: String(res.statusCode) },
|
||||
duration / 1000,
|
||||
);
|
||||
});
|
||||
}
|
||||
// Honor an inbound X-Request-Id (e.g. from Caddy or a probe) so the
|
||||
// request ID propagates across the proxy hop; otherwise mint a fresh
|
||||
// UUID. Echo on the response so clients can correlate.
|
||||
const inbound = req.headers["x-request-id"];
|
||||
const requestId =
|
||||
(Array.isArray(inbound) ? inbound[0] : inbound) || randomUUID();
|
||||
res.setHeader("X-Request-Id", requestId);
|
||||
|
||||
if (url === "/health") { handleHealth(req, res); return; }
|
||||
if (url === "/metrics") { handleMetrics(req, res); return; }
|
||||
if (!serveStatic(req, res)) {
|
||||
listener(req, res);
|
||||
}
|
||||
requestContext.run({ requestId }, () => {
|
||||
if (!url.startsWith("/assets/") && url !== "/health" && url !== "/metrics") {
|
||||
res.on("finish", () => {
|
||||
const duration = Date.now() - start;
|
||||
logger.info({ method: req.method, path: url, status: res.statusCode, duration }, "request");
|
||||
httpRequestDuration.observe(
|
||||
{ method: req.method ?? "GET", route: url.split("?")[0]!, status: String(res.statusCode) },
|
||||
duration / 1000,
|
||||
);
|
||||
});
|
||||
}
|
||||
|
||||
if (url === "/health") { handleHealth(req, res); return; }
|
||||
if (url === "/metrics") { handleMetrics(req, res); return; }
|
||||
if (!serveStatic(req, res)) {
|
||||
listener(req, res);
|
||||
}
|
||||
});
|
||||
});
|
||||
|
||||
setupYjsWebSocket(server);
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue