feat(p9): request-scoped trace context + middleware + structured logger

Task O.1: AsyncLocalStorage trace context (currentTraceId/runWithTrace/toTraceparent)
read by singleton services with no DI churn; Express traceMiddleware derives a trace
id per request (x-trace-id → traceparent → generated), echoes x-trace-id on the
response, runs the request in-context, and logs a structured http.request line on
finish. Minimal JSON structured logger stamps traceId on every line. Wired via
app.use in main.ts. 4 tests: scope, concurrency isolation, traceparent shape/parse.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

packages/iios-service/src/main.ts

@@ -3,9 +3,11 @@ import 'reflect-metadata';
 import { NestFactory } from '@nestjs/core';
 import { ValidationPipe } from '@nestjs/common';
 import { AppModule } from './app.module';
+import { traceMiddleware } from './observability/trace.middleware';
 
 async function bootstrap(): Promise<void> {
   const app = await NestFactory.create(AppModule, { rawBody: true });
+  app.use(traceMiddleware); // request-scoped trace context + x-trace-id header (P9)
   app.useGlobalPipes(
     new ValidationPipe({ whitelist: true, forbidNonWhitelisted: true, transform: true }),
   );

packages/iios-service/src/observability/logger.ts

@@ -0,0 +1,12 @@
+import { currentTraceId } from './trace-context';
+
+/**
+ * Minimal structured logger (P9 observability). One JSON line per event, always
+ * carrying the current request's trace id — so the mandated QA gate ("trace id
+ * appears in logs") holds and QA/devs can grep a trace end to end.
+ */
+export function logJson(level: 'info' | 'warn' | 'error', message: string, fields: Record<string, unknown> = {}): void {
+  const line = JSON.stringify({ ts: new Date().toISOString(), level, message, traceId: currentTraceId(), ...fields });
+  // eslint-disable-next-line no-console
+  (level === 'error' ? console.error : level === 'warn' ? console.warn : console.log)(line);
+}

packages/iios-service/src/observability/trace-context.spec.ts

@@ -0,0 +1,33 @@
+import { describe, it, expect } from 'vitest';
+import { runWithTrace, currentTraceId, toTraceparent, traceIdFromTraceparent, newTraceId } from './trace-context';
+
+describe('trace context (P9 observability)', () => {
+  it('currentTraceId reflects the active runWithTrace scope', () => {
+    expect(currentTraceId()).toBeUndefined();
+    runWithTrace('t1', () => {
+      expect(currentTraceId()).toBe('t1');
+    });
+    expect(currentTraceId()).toBeUndefined();
+  });
+
+  it('isolates concurrent async contexts', async () => {
+    const seen: Record<string, string | undefined> = {};
+    await Promise.all([
+      runWithTrace('a', async () => { await Promise.resolve(); seen.a = currentTraceId(); }),
+      runWithTrace('b', async () => { await Promise.resolve(); seen.b = currentTraceId(); }),
+    ]);
+    expect(seen).toEqual({ a: 'a', b: 'b' });
+  });
+
+  it('toTraceparent is a valid W3C traceparent', () => {
+    const tp = toTraceparent(newTraceId());
+    expect(tp).toMatch(/^00-[0-9a-f]{32}-[0-9a-f]{16}-01$/);
+  });
+
+  it('traceIdFromTraceparent extracts the trace id field', () => {
+    const tp = '00-0123456789abcdef0123456789abcdef-abcdef0123456789-01';
+    expect(traceIdFromTraceparent(tp)).toBe('0123456789abcdef0123456789abcdef');
+    expect(traceIdFromTraceparent(undefined)).toBeUndefined();
+    expect(traceIdFromTraceparent('garbage')).toBeUndefined();
+  });
+});

packages/iios-service/src/observability/trace-context.ts

@@ -0,0 +1,43 @@
+import { AsyncLocalStorage } from 'node:async_hooks';
+import { randomBytes, randomUUID } from 'node:crypto';
+
+/**
+ * Request-scoped trace context (P9 observability). A module-level AsyncLocalStorage
+ * so singleton services can read the current request's trace id via `currentTraceId()`
+ * WITHOUT threading it through every method or constructor. The middleware runs each
+ * request inside `runWithTrace(...)`; async projectors run outside a request and
+ * simply see `undefined` (their events already carry the trace from the emitting call).
+ */
+export interface TraceStore {
+  traceId: string;
+  correlationId?: string;
+}
+
+const als = new AsyncLocalStorage<TraceStore>();
+
+export function runWithTrace<T>(traceId: string, fn: () => T): T {
+  return als.run({ traceId }, fn);
+}
+
+export function currentTraceId(): string | undefined {
+  return als.getStore()?.traceId;
+}
+
+/** A fresh trace id (used when no inbound trace context is present). */
+export function newTraceId(): string {
+  return randomUUID();
+}
+
+/** W3C traceparent for a trace id: 00-<32 hex>-<16 hex span>-01. */
+export function toTraceparent(traceId: string): string {
+  const trace = traceId.replace(/-/g, '').padEnd(32, '0').slice(0, 32);
+  const span = randomBytes(8).toString('hex');
+  return `00-${trace}-${span}-01`;
+}
+
+/** Extract a trace id from an inbound traceparent header (the 2nd field), else undefined. */
+export function traceIdFromTraceparent(traceparent?: string): string | undefined {
+  if (!traceparent) return undefined;
+  const parts = traceparent.split('-');
+  return parts.length >= 3 && /^[0-9a-f]{32}$/i.test(parts[1]) ? parts[1] : undefined;
+}

packages/iios-service/src/observability/trace.middleware.ts

@@ -0,0 +1,27 @@
+import type { Request, Response, NextFunction } from 'express';
+import { runWithTrace, newTraceId, traceIdFromTraceparent } from './trace-context';
+import { logJson } from './logger';
+
+/**
+ * Express middleware (P9 observability). Derives a trace id per request (inbound
+ * x-trace-id → traceparent → generated), echoes it as `x-trace-id` on the response,
+ * runs the whole request inside the trace context, and logs a structured line when
+ * the response finishes (method, path, status, ms). Wired via app.use() in main.ts.
+ */
+export function traceMiddleware(req: Request, res: Response, next: NextFunction): void {
+  const headerTrace = (req.headers['x-trace-id'] as string | undefined)?.trim();
+  const traceId = headerTrace || traceIdFromTraceparent(req.headers['traceparent'] as string | undefined) || newTraceId();
+  res.setHeader('x-trace-id', traceId);
+  const startedAt = Date.now();
+  runWithTrace(traceId, () => {
+    res.on('finish', () => {
+      logJson('info', 'http.request', {
+        method: req.method,
+        path: (req.originalUrl || req.url || '').split('?')[0],
+        status: res.statusCode,
+        ms: Date.now() - startedAt,
+      });
+    });
+    next();
+  });
+}