Structured Logging Specification

Structured Logging Specification

Session: 151 (v1) Date: 6 April 2026 Patched: kh-prod-readiness-S8 (28 April 2026, v1.1 prod-readiness alignment) Status: Ready for implementation Trust level: Authoritative Roadmap entry: 9.7 (Codebase Health) — companion items §9.7.1 (Axiom drain), §9.7.2 (Sentry release tagging + sourcemap upload — partial-shipped W2), §9.7.3 (PII redaction policy doc). Companion decisions: D-5 (Axiom destination), D-9 (mechanical sweep), D-11 (release tagging — shipped W2 of prod-readiness), D-12 (PII redaction superset including organisation strings + content excerpts + classifier inputs + author names). Owner: kh-production-readiness track (W4 stream); spec authoring predates the track but was retroactively folded in at S8.

---

1. Overview

Problem Statement

The Knowledge Hub has 423 console.error/warn/log calls across 154 source files (counted 28 April 2026 across app/ and lib/; spec drafted at 303 across ~150 files in S151 — drift +40% during the intervening sessions). 168 files import the safeErrorMessage() helper in lib/error.ts, which is the single chokepoint through which API error messages currently flow. There is no structured logging framework, no log levels, no per-request correlation IDs, and no scope context attached to log lines or to Sentry events.

The current state has four concrete consequences:

1. Vercel logs are unsearchable. Every log line is free-form text. Filtering by route, user, or operation requires substring matching that misses anything not embedded literally in the message.
2. No request correlation. Multi-step pipelines such as ingest → classify → embed → store cannot be traced as a single unit. When a user reports a failed ingest, we have no way to find every log line that participated in that request.
3. Sentry is impoverished. safeErrorMessage() calls Sentry.captureException(err) with no scope, no tags, no breadcrumbs, and no user context. The Sentry event tells us that something failed but not who, where in the request graph, or what the inputs were.
4. No log levels. console.log and console.error are the only options; debug-level information cannot be emitted in development without polluting production output, and warnings cannot be distinguished from errors at the shipping layer.

This spec addresses item 9.7 in the post-MVP roadmap. It is a pre-launch concern: the first paying client will surface incidents we cannot triage today.

Goal

Introduce a structured logging layer that:

• Emits JSON log lines with consistent fields (level, time, msg, route, requestId, userId, op, plus arbitrary structured context).
• Generates a request ID per inbound HTTP request and propagates it through every log line and every Sentry event for that request.
• Provides a thin migration path from the existing safeErrorMessage() chokepoint so that the bulk of the codebase gains structure with one edit.
• Composes with Sentry: every error logged with logger.error() automatically attaches scope (tags, user, request ID) to the Sentry event.
• Carries correlation IDs through long-running pipelines (Python ingest, batch scripts) so a user-initiated ingest can be traced end-to-end.

Scope

In scope:

• TypeScript runtime: API routes, server-side lib/ modules, MCP handlers, cron routes.
• Sentry integration via scope/tags/user.
• Request ID generation and propagation in proxy.ts.
• Migration of safeErrorMessage() to use the logger.
• Phased migration plan for existing console.error/warn/log callers.
• Python pipeline correlation IDs (lightweight: pass through, do not introduce a new Python logging library).

Out of scope:

• Log shipping to a third-party aggregator (Datadog, Logtail, Better Stack). Vercel’s built-in log capture is sufficient at launch. Retired in v1.1: log shipping is now in scope as Phase 6 (Axiom — D-5 / §9.7.1). The S151 “sufficient at launch” carve-out conflicted with the prod-readiness handover requirement.
• Dashboards, alerting, or metrics. Sentry remains the alerting surface.
• Replacing Sentry. Sentry continues to own exception capture and alerting.
• Client-side (browser) logging. Browser errors continue to flow through @sentry/nextjs client SDK without change.
• Migration of every Python print() to a structured logger. Python pipeline changes are limited to correlation ID propagation.
• Audit logging. The activity_history table already serves that purpose.

---

2. Current State

lib/error.ts (the chokepoint)

import { clientEnv } from '@/lib/env-client';

/**
 * Returns a safe error message for API responses.
 * In development, includes the real error for debugging convenience.
 * In production, returns only the generic fallback message.
 */
export function safeErrorMessage(err: unknown, fallback: string): string {
  console.error(fallback, err);
  if (clientEnv.NEXT_PUBLIC_SENTRY_DSN) {
    import('@sentry/nextjs')
      .then(({ captureException }) => captureException(err))
      .catch((_err) => undefined);
  }
  if (process.env.NODE_ENV === 'development' && err instanceof Error) {
    return `${fallback}: ${err.message}`;
  }
  return fallback;
}

168 files import this helper. It is the single best place to introduce structured logging because one edit improves the majority of error sites.

v1.1 patch note: the spec’s S151 quote was process.env.NEXT_PUBLIC_OBSERVABILITY_SENTRY_DSN. The env var was renamed to NEXT_PUBLIC_OBSERVABILITY_SENTRY_DSN in S2 of prod-readiness (bfa98ee2) then reverted to bare NEXT_PUBLIC_SENTRY_DSN in S3 (b7fdc5f4) once Liam confirmed Vercel-side env vars are bare. Build-side canonical names today: NEXT_PUBLIC_SENTRY_DSN + bare SENTRY_ORG / SENTRY_PROJECT / SENTRY_AUTH_TOKEN. The Zod-validated clientEnv boundary is added between process.env and the consumer.

Already shipped post-S151 (v1.1 patch)

The world has moved since S151 was authored. None of the Pino architecture has been built yet (no lib/logger/, no withRequestContext, no AsyncLocalStorage usage), but adjacent observability work has shipped on the prod-readiness track and must be respected by Phase 1:

• app/global-error.tsx — root error boundary that calls Sentry.captureException (S3 ship). Phase 1 must NOT regress this.
• 22 segment-level app/<segment>/error.tsx — Sentry forwarding via WP-QW.5 (shipped S2 in single commit d58876cf, 26 April 2026; the WP-FU.1 0423aa47..923f81eb chain is the separate env-split workstream).
• Sentry release tagging — next.config.ts:42-55 sets release.name = process.env.VERCEL_GIT_COMMIT_SHA and sourcemaps.disable = !process.env.SENTRY_AUTH_TOKEN. WP-QW.4 shipped S2 (7748bd75); Phase 1 of THIS spec must NOT redo it. Sourcemap upload is partially working (per WP-QW.1 verification S7) — route.ts still shows as a chunk path; matching TS-source files to sourcemap releases is a S8+ follow-up tracked under §9.7.2.
• OBSERVABILITY_SENTRY_* env-var rename + revert — S2 renamed prefix, S3 reverted to bare. Current canonical: NEXT_PUBLIC_SENTRY_DSN (client) + bare SENTRY_ORG / SENTRY_PROJECT / SENTRY_AUTH_TOKEN (build).
• lib/env-client.ts + lib/env.ts (serverEnv export) — Zod-validated env split shipped via WP-FU.1 (S3) and WP-S5.1 cross-track reconciliation (S5). The spec’s process.env.X reads in Phase 1 must respect this boundary — Sentry-related env vars come from clientEnv (browser-safe, lib/env-client.ts) or serverEnv (server-only, lib/env.ts), not raw process.env. (The two-file shape is env-client + env, not env-client + env-server.)

Direct console.* callers

423 direct console.error/warn/log calls remain across app/ and lib/ (count 28 April 2026). A typical pattern (from app/api/items/route.ts):

console.error('Embedding generation failed:', embedErr);
// ... fallback path
console.error('Classification failed during item creation:', err);
// ... continue without classification

These are sites where the developer logged a non-fatal warning rather than returning an error. They are not covered by safeErrorMessage() and need direct migration.

Sentry wiring

• sentry.server.config.ts, sentry.client.config.ts, sentry.edge.config.ts exist with minimal init (tracesSampleRate: 0.1, no integrations beyond the defaults).
• instrumentation.ts loads the server/edge configs.
• No Sentry.withScope, no Sentry.setUser, no Sentry.setTag anywhere in the codebase.

proxy.ts

The Next.js 16 proxy file already runs on every request, sets x-pathname on the request headers, and resolves supabase.auth.getUser(). It is the natural place to mint a request ID and attach the authenticated user.

Existing dependencies

package.json contains @sentry/nextjs ^10.42.0 and no other logging library. There is no pino, winston, bunyan, consola, or loglevel.

---

3. Library Choice

Options considered

Library	Pros	Cons
pino	De facto Node standard. Extremely fast. Native JSON. Child loggers with bound context. Mature Sentry transports available.	Has worker-thread transport modes that misbehave on Vercel serverless and on bun. Must be configured to write JSON to stdout only.
winston	Mature, widely used.	Slower, larger surface area, transport ecosystem skews to long-running processes rather than serverless.
bunyan	Original JSON logger.	Effectively unmaintained.
consola	Pretty output, good DX.	Optimised for CLI/dev experience, not structured server logging.
Custom wrapper	Zero dependencies, exactly the surface we need.	Reinvents level filtering, child loggers, serialisers, and JSON formatting; maintenance burden falls on us.

Recommendation: pino with sync stdout transport

Reasons:

1. JSON to stdout is exactly what Vercel expects. Vercel captures stdout per invocation and exposes it in the dashboard. Pino’s default sync mode (no worker thread, no pino.transport()) writes JSON lines to stdout with no compatibility issues.
2. Bun compatibility. Pino works on bun in sync mode. The known incompatibilities are with pino.transport() worker threads, which we will not use.
3. Child loggers. logger.child({ requestId, userId, route }) returns a bound logger that inherits context. This is the mechanism by which we attach request scope without threading parameters through every function call.
4. Cold start cost is negligible. Pino is ~30 KB and has no transitive dependencies in sync mode. Initial benchmarks elsewhere show <1 ms init.
5. Serialiser hooks. Pino’s serializers option lets us redact PII and normalise Error objects (stack, cause chain) without per-call boilerplate.

What we will not use from pino

• pino.transport() (worker thread mode) — incompatible with serverless and bun.
• pino-pretty in production — pretty printing in development only, behind a NODE_ENV === 'development' guard.
• File transports — Vercel does not provide a writable filesystem.

---

4. Architecture

4.1 Module layout

lib/
  logger/
    index.ts          # createLogger(), the root logger, type exports
    request-context.ts # AsyncLocalStorage store, getRequestContext()
    sentry-bridge.ts  # syncs logger context onto Sentry scope
    serialisers.ts    # error serialiser, redaction
    types.ts          # LogContext, LogFields

lib/logger/index.ts exports a singleton root logger plus a createLogger() factory for child loggers. Files import the singleton:

import { logger } from '@/lib/logger';
logger.error({ err, op: 'embedding.generate' }, 'Embedding generation failed');

4.2 Request context propagation

We use Node’s AsyncLocalStorage (async_hooks) to thread per-request context through the call graph without threading parameters. This is the canonical Node pattern, supported on Vercel’s Node runtime, and it composes naturally with React Server Components and route handlers.

lib/logger/request-context.ts

import { AsyncLocalStorage } from 'node:async_hooks';

export interface RequestContext {
  requestId: string;
  userId?: string;
  userRole?: string;
  route: string;
  method: string;
  startedAt: number;
}

export const requestContextStorage = new AsyncLocalStorage<RequestContext>();

export function getRequestContext(): RequestContext | undefined {
  return requestContextStorage.getStore();
}

The root logger reads from getRequestContext() via a pino mixin hook so that every log line automatically includes requestId, userId, route, and method without the caller having to pass them.

// lib/logger/index.ts (excerpt)
export const logger = pino({
  level: process.env.LOG_LEVEL ?? (isDev ? 'debug' : 'info'),
  base: { service: 'knowledge-hub' },
  timestamp: pino.stdTimeFunctions.isoTime,
  serializers: {
    err: pino.stdSerializers.errWithCause,
  },
  mixin() {
    const ctx = getRequestContext();
    if (!ctx) return {};
    return {
      requestId: ctx.requestId,
      userId: ctx.userId,
      userRole: ctx.userRole,
      route: ctx.route,
      method: ctx.method,
    };
  },
});

4.3 Where the request context is established

Two options were considered:

Option	Pros	Cons
In proxy.ts	Single chokepoint, runs on every request, already resolves supabase.auth.getUser().	Next.js proxy runs in a separate execution context from route handlers; AsyncLocalStorage state set here does not propagate to handlers.
In getAuthorisedClient()	Already called by every authenticated route, has user info in hand.	Misses public/unauthenticated routes (search-public, MCP discovery, health). Also misses pre-auth code paths inside routes.
A withRequestContext() wrapper	Explicit, per-route, runs in the handler’s execution context, AsyncLocalStorage propagates correctly.	Requires every route to wrap its handler.

Decision: hybrid.

1. proxy.ts mints the request ID, sets it on a response header (x-request-id), and forwards it on the request headers (x-request-id) so the route handler can read it.
2. A withRequestContext(handler) wrapper at the top of each route reads x-request-id, resolves the user (or accepts an already-resolved user from getAuthorisedClient()), and calls requestContextStorage.run(ctx, () => handler(req)). AsyncLocalStorage inside the handler then sees the context.
3. For routes that already use getAuthorisedClient(), the auth helper updates the in-flight context with userId and userRole once auth resolves. This means anonymous traffic still has a request ID; authenticated traffic gets the user attached as soon as auth completes.

The wrapper is one line per route (export const POST = withRequestContext(handler);) and is rolled out in Phase 2 of the migration.

4.4 Sentry composition

lib/logger/sentry-bridge.ts exports a function that mirrors the request context onto the Sentry scope:

import * as Sentry from '@sentry/nextjs';
import { getRequestContext } from './request-context';

export function applyRequestContextToSentry() {
  const ctx = getRequestContext();
  if (!ctx) return;
  Sentry.getCurrentScope().setTag('requestId', ctx.requestId);
  Sentry.getCurrentScope().setTag('route', ctx.route);
  if (ctx.userId) {
    Sentry.getCurrentScope().setUser({ id: ctx.userId });
  }
}

withRequestContext() calls applyRequestContextToSentry() once per request inside Sentry.withScope(...), so any Sentry.captureException call from within the handler — including the existing safeErrorMessage() path — inherits the scope.

When logger.error({ err }, '...') is called, a small wrapper at the error/fatal levels also calls Sentry.captureException(err) so that Sentry alerting still fires without callers having to remember two APIs.

4.5 Composing with safeErrorMessage()

lib/error.ts is rewritten to delegate to the logger. The signature stays the same so the 168 callers do not change in Phase 1.

import { logger } from '@/lib/logger';

export function safeErrorMessage(err: unknown, fallback: string): string {
  logger.error({ err }, fallback);
  if (process.env.NODE_ENV === 'development' && err instanceof Error) {
    return `${fallback}: ${err.message}`;
  }
  return fallback;
}

The Sentry capture moves into the logger’s error-level handler, so it is called once per error site rather than at this helper specifically. This is strictly an improvement: Sentry now sees errors logged from anywhere, not only from API routes that route through safeErrorMessage().

4.6 Long-running pipeline correlation

The Python ingest pipeline currently emits free-form print() and logging output. To carry correlation through the TS → Python boundary:

1. The TS route that invokes the Python pipeline (via subprocess or via the ingest API) passes the current request ID as an environment variable (KH_REQUEST_ID) or CLI flag (--request-id).
2. scripts/kb_pipeline/config.py reads KH_REQUEST_ID once at module load and exposes it as REQUEST_ID.
3. The existing logger in kb_pipeline/ is configured to include request_id in its log format.

This is the minimum change needed for end-to-end traceability. A full Python structured logging migration is out of scope.

For batch scripts (scripts/batch-generate-summaries.ts, scripts/backfill-reader-html.ts), the script generates its own request ID at startup and uses requestContextStorage.run() to scope all subsequent logging.

MCP tool callsites (v1.1 patch — entry point #5). MCP tool handlers (e.g. lib/mcp/tools/content.ts:create_content_item) are invoked from the Streamable HTTP transport at app/api/mcp/[transport]/route.ts, which sits outside the standard withRequestContext() route wrapper. Per feedback_audit_all_pipeline_entry_points.md, the canonical 6-entry-point list requires explicit context wiring at every entry. For MCP:

• The transport-route handler calls withRequestContext() (same as any other API route).
• Inside the route, before transport.handleRequest(), call requestContextStorage.run(ctx, () => ...) so every MCP tool callsite inherits the request scope automatically.

Without this, MCP tool log lines would lack requestId/userId even though the surrounding HTTP request has both.

4.7 PII redaction

The serialiser layer redacts known sensitive fields before they hit stdout. Per D-12 (PII redaction superset), the redaction list is broader than generic credential fields — UK GDPR posture for the client requires default-redacting client identifiers and content excerpts:

• email → e***@d***
• password, token, apiKey, authorization, cookie → [redacted]
• organisation_name, client_name, holder_name → [redacted]
• content_text, content_text_excerpt, summary → truncated to first 60 chars + …[truncated]
• classifier_input, prompt, completion → truncated to first 200 chars
• author, created_by → [redacted] for non-self lookups
• Supabase rows are not auto-redacted beyond the above column names; callers logging row data should whitelist the fields they need.

Pino’s redact option handles this declaratively:

redact: {
  paths: [
    '*.password',
    '*.token',
    '*.apiKey',
    // `*.authorization` matches any 'authorization' field at any depth; the
    // explicit `req.headers.authorization` entry below is belt-and-braces for
    // readability.
    '*.authorization',
    'req.headers.authorization',
    'req.headers.cookie',
    // Bracket-quoted wildcards in pino redact paths are version-sensitive —
    // validate against the pinned Pino major in Phase 1; fall back to enumerated
    // header names if the wildcard does not resolve.
    'req.headers["x-supabase-*"]',
    '*.email',
    '*.organisation_name',
    '*.client_name',
    '*.holder_name',
    '*.author',
    '*.created_by',
  ],
  censor: '[redacted]',
}

---

5. Migration Path

The migration is phased so that the high-value chokepoint (safeErrorMessage) is migrated in Phase 1 with one edit, then the long tail is addressed incrementally without blocking other work.

Phase 1: Foundation (4–5 hours)

1. Add pino to package.json (bun add pino).
2. Create lib/logger/ module per Section 4.1, including:
   • Root logger with mixin, serializers, and redact configured.
   • request-context.ts with AsyncLocalStorage store and helpers.
   • sentry-bridge.ts with applyRequestContextToSentry().
   • Wrapped error/fatal levels that also call Sentry.captureException.
3. Rewrite lib/error.ts to delegate to logger.error(). The signature stays the same — no caller changes required.
4. Add withRequestContext() route wrapper.
5. Update proxy.ts to mint a request ID (crypto.randomUUID()) and forward it via x-request-id request and response headers.
6. Add unit tests covering: request context propagation, Sentry scope sync, PII redaction, error serialisation.

Outcome after Phase 1: every error message that already flows through safeErrorMessage() is now structured JSON, has a request ID (when withRequestContext has wrapped the route), and is captured by Sentry with scope. The other ~420 direct console.* call sites (across 154 files, v1.1 count) are unchanged.

Phase 2: High-volume routes (3–4 hours)

Wrap the highest-traffic routes with withRequestContext and migrate their direct console.* calls to logger.warn / logger.info:

Route	Why
app/api/items/route.ts (POST)	10+ direct console.error calls in non-fatal fallback paths
app/api/items/[id]/route.ts	Highest write traffic
app/api/search/route.ts	Highest read traffic
app/api/ingest/...	Multi-step pipeline that benefits most from correlation
app/api/classify/...	Same
app/api/freshness/...	Cron-adjacent, currently logs to console only

Phase 3: lib/ modules (2–3 hours)

Migrate console.* calls in lib/ modules. These are typically deeper in the call stack, so they pick up request context automatically once the calling route is wrapped. The migration is mostly mechanical: import logger, replace console.error('msg', err) with logger.error({ err }, 'msg').

Modules to migrate first (highest call volume):

• lib/embeddings.ts
• lib/ai/ (every classifier, summariser, prompt)
• lib/freshness.ts
• lib/quality/
• lib/source-documents/

Phase 4: Long tail (3.5–4 hours — bumped from 2–3h in v1.1)

Sweep the remaining direct console.* callers. The S151 estimate was 2–3h against 303 calls; the v1.1 patch counts 423 calls (post-S151 drift +40%) so the sweep is now ~3.5–4h. A bun run knip-style audit script (or a one-off Grep count) confirms zero remaining console.* calls in app/ and lib/ (excluding test files and CLI scripts).

Phase 4 closure — kh-prod-readiness-S34 (06/05/2026)

Status: CLOSED. Audit of app/ + lib/ (excluding __tests__/**) yields 0 unintentional console.* calls. The 34 surviving calls are all intentional or autogenerated, fall into 4 categories, and are now allowlisted in eslint.config.mjs no-console block (D-9 enforcement):

File	Calls	Category	Justification
lib/logger/client.ts	4	Chokepoint shim	The client-side logger forwards to console.* because there is no Pino runtime in the browser bundle. This file IS the chokepoint — banning console.* here would just replace it with globalThis.console.*.
lib/client-telemetry.ts	3	Dev-mode debug	Gated on process.env.NODE_ENV !== 'production'; helps surface client-side telemetry during local dev. Production bundles tree-shake them out.
lib/eval/reporter.ts	16	CLI eval reporter	Standalone Node CLI module that prints human-readable eval results to stdout + JSON for CI consumption. Not a server runtime path — console.* is the contract.
lib/mcp/app-bundles.ts	10	Autogenerated bundle	The console.* calls live inside JavaScript string literals embedded in this generated TS file (output of bun run build:mcp-apps). No real TS code is involved. The no-console rule cannot distinguish embedded strings from real call sites — file-level allowlist is the only correct enforcement.

False-positive count from the line-level grep:

• lib/mcp/tools/review.ts:199 — comment text “console.warn”; not a call site.

Total: 34 = (4 + 3 + 16 + 10) + 1 false-positive — matches the rg -c 'console\.' app/ lib/ output exactly.

The grep guard test originally proposed in §6 AC-4 + §7 component list (__tests__/quality/console-guard.test.ts) is subsumed by the ESLint no-console rule. ESLint runs in CI (bun lint job) AND in IDE — same guard surface, single source of truth. The grep test is therefore SKIPPED from this Phase 4 closure (D-9 retroactively documented as “ESLint rule enforces the regression guard”).

Phase 5: Pipeline correlation (2 hours)

Wire the request ID into the Python pipeline as described in Section 4.6 and verify end-to-end with a single test ingest.

Phase 6: Log destination wiring — Axiom (3–4 hours, v1.1 patch)

Per D-5 (Axiom as log aggregation destination) and roadmap §9.7.1: ship the Vercel Log Drain → Axiom integration so Pino JSON output is searchable beyond Vercel’s 24h default retention.

1. Provision Axiom dataset (knowledge-hub-prod + knowledge-hub-staging, per-env scoping).
2. Wire Vercel Log Drain via Vercel Integrations marketplace; per-env target matches the GitHub Environments canonical names.
3. Spot-check a representative ingest run: confirm requestId/userId filters work in Axiom UI within ~5 min of a Vercel deploy.
4. Document retention + cost in docs/runbooks/observability.md (NEW W5 handover artefact).

Phase 6 sequencing. Gated on Phase 1; can be sequenced after Phases 2-5 without blocking them; but MUST ship before prod cutover for handover (per D-5 / §9.7.1). Treat as deferrable-within-the-spec-but-required-before-launch.

Total effort: 17.5–22 hours, executable in 2–3 sessions. (v1 was 13-17h without Phase 6 + activity_history correlation_id work; v1 §11 added 1-2h for the migration; v1.1 adds Phase 6 at 3-4h and bumps Phase 4 to 3.5-4h for console-call drift +40%. Actual sum across the §8 table is 17.5-22h.)

The phases are independent after Phase 1. Phases 2–6 can be reordered or deferred without breaking anything.

---

6. Acceptance Criteria

1. Every API route emits structured JSON logs with level, time, msg, requestId, route, method, and (when authenticated) userId and userRole.
2. safeErrorMessage() integrates with Sentry scope. Errors captured via this helper carry requestId, route, and userId as Sentry tags/user.
3. Multi-step pipelines carry a correlation ID. A single ingest (POST /api/ingest → classify → embed → store) shares one requestId across all log lines. A user-initiated Python ingest run carries the originating request ID through to the pipeline’s stdout.
4. No console.error/console.warn/console.log calls remain in app/api/ or lib/ (excluding test files and CLI entry points). A grep guard test enforces this.
5. Sentry events for the same request are grouped by requestId tag in the Sentry dashboard, allowing one-click correlation between log lines and error reports.
6. PII is redacted at serialisation time. A unit test asserts that email, password, token, apiKey, and authorization are not present in serialised log output.
7. Cold start overhead is under 5 ms. Measured by invoking a trivial logged route after a cold start; baseline established in Phase 1.

---

7. Testing

Structured logging is easy to test poorly. The strategy is:

1. Capture logs via a pino test transport. Pino supports pino({ ... }, customStream) where customStream is a writable stream that collects log lines. Tests pass a stream that records lines into an array, then assert on the JSON shape.
2. Suppress logger output during normal test runs. The default test setup sets LOG_LEVEL=silent. Tests that need to inspect logs explicitly opt in by importing a test helper (createTestLogger()).
3. Mock Sentry in unit tests. vi.mock('@sentry/nextjs', () => ({ ... })) provides a stub captureException, withScope, getCurrentScope, etc. that records calls for assertion.
4. Integration tests run a real route through withRequestContext and assert that logs emitted from inside the handler (and from inside helpers the handler calls) all share the same requestId.
5. The grep guard test scans app/api/ and lib/ for console\.(error|warn|log) and fails the build if any are found, enforcing the migration over time.

Tests live in __tests__/lib/logger/:

• request-context.test.ts — AsyncLocalStorage propagation, child contexts.
• sentry-bridge.test.ts — scope tags, user assignment, no leakage between requests.
• serialisers.test.ts — PII redaction, error cause chains.
• error-helper.test.ts — safeErrorMessage still returns the right string, now also calls the logger and Sentry.
• route-wrapper.test.ts — withRequestContext integration test.
• console-guard.test.ts — grep guard for forbidden console.* calls.

---

8. Effort Estimate

Phase	Hours
Phase 1: Foundation (logger module, error helper, proxy)	4–5
Phase 2: High-volume route migration	3–4
Phase 3: lib/ module migration	2–3
Phase 4: Long-tail sweep + grep guard	3.5–4 (v1.1)
Phase 5: Python pipeline correlation	2
Phase 6: Axiom log destination wiring (v1.1, D-5)	3–4
Total	17.5–22

Phase 1 alone delivers most of the value (the chokepoint plus the request ID infrastructure). Phases 2–6 are incremental quality improvements and can be spread across sessions or done as part of routine route maintenance.

---

9. Dependencies and Risks

Dependencies

• pino (~30 KB, zero runtime dependencies in sync mode).
• No schema changes.
• No environment variable changes other than the optional LOG_LEVEL.

Risks

1. Vercel log line size limits. Vercel truncates log lines above ~4 KB. Mitigation: pino’s serialiser layer truncates large err.stack and large payload fields; redact replaces sensitive paths; the request context itself is small.
2. AsyncLocalStorage and edge runtime. The Next.js edge runtime supports AsyncLocalStorage since Next 14. Knowledge Hub uses Next.js 16 and runs API routes on the Node runtime by default, so this is not a blocker. Edge routes (currently none) would need a fallback to per-call context passing.
3. Bun + pino compatibility. Pino works on bun in sync mode. Worker-thread transports (pino.transport()) are not used. Verified via pino’s release notes; will be re-confirmed in Phase 1.
4. Cold start overhead. Pino initialises in <1 ms in sync mode but the import graph (including Sentry bridge) adds modest cost. Acceptance criterion 7 sets a 5 ms ceiling and Phase 1 measures it.
5. Migration drift. Without the grep guard test, new console.* calls will accumulate. Phase 4 introduces the guard so the migration remains permanent.
6. safeErrorMessage callers depending on the development-mode error string. The behaviour-preserving rewrite keeps the string format unchanged. A regression test pins the development-mode return value.
7. Sentry scope leakage between requests. AsyncLocalStorage scopes are per-execution, not per-thread, so cross-request leakage is not possible provided we never call Sentry.getCurrentScope().setUser() outside of withRequestContext. The unit test in sentry-bridge.test.ts asserts isolation between two simulated requests.

Vercel-specific notes

• Vercel automatically captures stdout per invocation. Phase 1 ships JSON-to-stdout only; Vercel Log Drain → Axiom (Phase 6 / §9.7.1) is a separate WP per D-5. Without Phase 6, Vercel’s 24h retention default applies and longer-term log retention is functionally lost — required before prod cutover for handover (see roadmap §9.7.1).
• The Vercel dashboard supports filtering by JSON field once log lines are parseable JSON, so requestId and userId become first-class filters immediately.
• Phase 6 wires Axiom (D-5) per the Vercel Integrations marketplace path. Alternatives (@vercel/otel, Datadog, Logtail, Better Stack) are available as drop-in replacements without changing the logger surface.

---

10. Resolved Decisions

The three open questions have been answered (S151 prep, 6 April 2026):

1. logger.warn writes to Sentry — CONFIRMED. Both warn and error/fatal levels emit to Sentry. Rationale: Liam prefers visibility into warning-level degradation in production rather than waiting for it to escalate to errors. The acceptance check in §6 must be updated so any logger.warn call appears in Sentry with full scope context. Phase 1 implementation must wire this in lib/error.ts from the start.

2. activity_history.correlation_id column — IN SCOPE. Add a nullable correlation_id text column to activity_history as part of Phase 1. Justification: closes the loop between request logs and the audit trail so a single ID traces a user action from API entry through to its activity row. Migration is small (one column + index). The application write path stamps the ID from AsyncLocalStorage when present. This was originally deferred but is being pulled in now while the surrounding logger work is open.

3. Python pipeline JSON logging — NOTED, NOT IN SCOPE. Acknowledged as a ~4-hour follow-up task. Not part of this spec. To be added to the roadmap as a separate item once Phase 1-3 of this spec are complete and the TS-side correlation ID format is stable enough for Python to mirror. Tracking note: Python pipeline currently uses print() and logging module calls; the follow-up will introduce python-json-logger (or equivalent) and reuse the same correlation ID field name. D-2 update: when the Python pipeline moves to Railway (roadmap §9.15), the KH_REQUEST_ID env var becomes the TS→Python boundary mechanism — Vercel-side passes via subprocess env or HTTP X-Request-ID header.

4. Axiom as log-aggregation destination — IN SCOPE (separate WP, v1.1 patch). Per D-5, Axiom (free tier 500GB/mo at recent pricing) is the canonical destination. Wired via Vercel Log Drain in Phase 6 of this spec / WP-G5.2 / roadmap §9.7.1. Without this, Pino JSON sits in Vercel’s 24h-default retention and is functionally lost — required before prod cutover for handover. Out-of-scope alternatives (Datadog, Logtail, Better Stack, @vercel/otel) are drop-in replacements; the logger surface unchanged.

---

11. Implementation Note (post-resolution)

The Phase 1 scope has expanded slightly relative to the original estimate:

• lib/error.ts rewrite must wire warn → Sentry (was error/fatal only)
• A new migration adds activity_history.correlation_id (nullable text + index)
• Activity-history write paths must stamp the column from AsyncLocalStorage

Net effect on the 13–17h estimate: Phase 1 grows by approximately 1-2 hours (new migration + write-path updates + tests). Updated total: 14–19h (v1, S151).

v1.1 patch revisions (kh-prod-readiness-S8)

Already-shipped post-S151 work that Phase 1 must respect — DO NOT redo:

• WP-QW.4 (Sentry release tagging + sourcemap upload) — shipped S2 of prod-readiness (7748bd75). next.config.ts:42-55 sets release.name = process.env.VERCEL_GIT_COMMIT_SHA and gates source-map upload on SENTRY_AUTH_TOKEN. Phase 1 must NOT duplicate this work.
• WP-QW.5 (error.tsx Sentry forwarding) — app/global-error.tsx + 22 segment-level error.tsx files all forward to Sentry via WP-FU.1 commit chain (S3). Phase 1 builds on top, does not replace.
• lib/env-client.ts / lib/env.ts (serverEnv) Zod boundary — Phase 1 Sentry-related reads must come from clientEnv.NEXT_PUBLIC_SENTRY_DSN, not raw process.env.

Drift recount (counted 28 April 2026):

• console.* calls in app/ + lib/: 423 (was 303 in S151) — Phase 4 effort bumps 2-3h → 3.5-4h.
• safeErrorMessage callers: 168 (was 153 in S151) — Phase 1 chokepoint edit value scales linearly.

Net effect on the 14-19h v1 estimate: add ~3-4h for new Phase 6 (Axiom wiring). Updated total: 17.5-22h (v1.1, S8 patch). The §8 table is the authoritative phase breakdown; per-phase ranges and totals reconcile arithmetically.

---

Spec produced: 6 April 2026 (v1, S151); v1.1 patch applied 28 April 2026 (kh-prod-readiness-S8) for prod-readiness W4 alignment.