diff --git a/packages/iios-service/src/main.ts b/packages/iios-service/src/main.ts index f1d7926..254957c 100644 --- a/packages/iios-service/src/main.ts +++ b/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 { 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 }), ); diff --git a/packages/iios-service/src/observability/logger.ts b/packages/iios-service/src/observability/logger.ts new file mode 100644 index 0000000..324336d --- /dev/null +++ b/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 = {}): 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); +} diff --git a/packages/iios-service/src/observability/trace-context.spec.ts b/packages/iios-service/src/observability/trace-context.spec.ts new file mode 100644 index 0000000..2cb8bd3 --- /dev/null +++ b/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 = {}; + 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(); + }); +}); diff --git a/packages/iios-service/src/observability/trace-context.ts b/packages/iios-service/src/observability/trace-context.ts new file mode 100644 index 0000000..54cb29c --- /dev/null +++ b/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(); + +export function runWithTrace(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; +} diff --git a/packages/iios-service/src/observability/trace.middleware.ts b/packages/iios-service/src/observability/trace.middleware.ts new file mode 100644 index 0000000..a720ce0 --- /dev/null +++ b/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(); + }); +}