diff --git a/backlog/features.json b/backlog/features.json index 10d700a..a84b470 100644 --- a/backlog/features.json +++ b/backlog/features.json @@ -124,12 +124,12 @@ "Internal stack traces never leak to API responses", "verify.sh green" ], - "status": "pending", + "status": "done", "created_at": "2026-08-14", "gates": { - "review": false, - "security": false, - "qa": false + "review": true, + "security": true, + "qa": true } }, { diff --git a/project/README.md b/project/README.md index 269f632..765b9cf 100644 --- a/project/README.md +++ b/project/README.md @@ -19,6 +19,17 @@ npm run lint # eslint + prettier check npm run lint:boundaries # module boundary check ``` +## HTTP contract + +- Every response carries an `x-request-id` header (propagated from a safe incoming + `x-request-id`, or a fresh UUID). Every JSON log line for a request carries the same id. +- Errors always use one envelope: + `{ "error": { "statusCode", "code", "message", "details?" }, "requestId" }` + Codes: `NOT_FOUND`, `VALIDATION_ERROR`, `BAD_REQUEST`/Fastify 4xx codes, `INTERNAL_ERROR`. + 5xx messages are always generic; stack traces stay in server logs only. +- Input validation is explicit per route: `parseJson(schema, body)` (zod) in the handler. +- Log level via `LOG_LEVEL` env var (default `info`); logs are JSON only. + ## Database (local dev) ```bash diff --git a/project/package-lock.json b/project/package-lock.json index e18454f..9a50a4e 100644 --- a/project/package-lock.json +++ b/project/package-lock.json @@ -10,7 +10,9 @@ "dependencies": { "fastify": "^5.2.0", "node-pg-migrate": "^9.0.0", - "pg": "^8.23.0" + "pg": "^8.23.0", + "pino": "^10.3.1", + "zod": "^4.4.3" }, "devDependencies": { "@eslint/js": "^9.17.0", @@ -4176,6 +4178,15 @@ "funding": { "url": "https://github.com/sponsors/sindresorhus" } + }, + "node_modules/zod": { + "version": "4.4.3", + "resolved": "https://registry.npmjs.org/zod/-/zod-4.4.3.tgz", + "integrity": "sha512-ytENFjIJFl2UwYglde2jchW2Hwm4GJFLDiSXWdTrJQBIN9Fcyp7n4DhxJEiWNAJMV1/BqWfW/kkg71UDcHJyTQ==", + "license": "MIT", + "funding": { + "url": "https://github.com/sponsors/colinhacks" + } } } } diff --git a/project/package.json b/project/package.json index 8471b14..fcd448a 100644 --- a/project/package.json +++ b/project/package.json @@ -24,7 +24,9 @@ "dependencies": { "fastify": "^5.2.0", "node-pg-migrate": "^9.0.0", - "pg": "^8.23.0" + "pg": "^8.23.0", + "pino": "^10.3.1", + "zod": "^4.4.3" }, "devDependencies": { "@eslint/js": "^9.17.0", diff --git a/project/src/app/build-app.ts b/project/src/app/build-app.ts index f7c61c4..a67f50b 100644 --- a/project/src/app/build-app.ts +++ b/project/src/app/build-app.ts @@ -1,27 +1,96 @@ +/** + * Composition root. The only place allowed to wire modules together. + * Cross-cutting HTTP behavior (request id, logging, errors) is explicit here. + */ +import { randomUUID } from 'node:crypto'; +import { performance } from 'node:perf_hooks'; import Fastify, { type FastifyInstance } from 'fastify'; import type { FastifyError, FastifyReply, FastifyRequest } from 'fastify'; +import type { IncomingMessage } from 'node:http'; import { registerHealthRoutes } from '../modules/health/index.js'; -import { errorEnvelope } from '../shared/errors.js'; +import { AppError, errorEnvelope } from '../shared/errors.js'; +import { createLogger, type Logger } from '../infrastructure/logging/logger.js'; -function notFoundHandler(_request: FastifyRequest, reply: FastifyReply): void { - void reply.code(404).send(errorEnvelope(404, 'Not Found')); +const REQUEST_ID_HEADER = 'x-request-id'; +const SAFE_REQUEST_ID = /^[A-Za-z0-9._-]{1,128}$/; + +export interface BuildAppDeps { + /** Injectable logger so tests can capture structured output. */ + logger?: Logger; } -function errorHandler(error: FastifyError, _request: FastifyRequest, reply: FastifyReply): void { - const statusCode = - error.statusCode !== undefined && error.statusCode >= 400 ? error.statusCode : 500; - const message = statusCode >= 500 ? 'Internal Server Error' : error.message; - void reply.code(statusCode).send(errorEnvelope(statusCode, message)); +function generateRequestId(raw: IncomingMessage): string { + const incoming = raw.headers[REQUEST_ID_HEADER]; + const value = Array.isArray(incoming) ? incoming[0] : incoming; + if (typeof value === 'string' && SAFE_REQUEST_ID.test(value)) { + return value; + } + return randomUUID(); } /** * Composition root. The only place allowed to wire modules together. */ -export async function buildApp(): Promise { - const app = Fastify({ logger: false }); +export async function buildApp(deps: BuildAppDeps = {}): Promise { + const logger = deps.logger ?? createLogger(); + const startTimes = new WeakMap(); - app.setErrorHandler(errorHandler); - app.setNotFoundHandler(notFoundHandler); + const app = Fastify({ logger: false, genReqId: generateRequestId }); + + app.addHook('onRequest', async (request, reply) => { + startTimes.set(request, performance.now()); + void reply.header(REQUEST_ID_HEADER, request.id); + }); + + app.addHook('onResponse', async (request, reply) => { + const startedAt = startTimes.get(request); + const durationMs = + startedAt === undefined ? 0 : Math.round((performance.now() - startedAt) * 100) / 100; + logger.info( + { + requestId: request.id, + method: request.method, + url: request.url, + statusCode: reply.statusCode, + durationMs, + }, + 'request completed', + ); + }); + + app.setErrorHandler((error: FastifyError, request: FastifyRequest, reply: FastifyReply) => { + const requestId = request.id; + let statusCode = + error.statusCode !== undefined && error.statusCode >= 400 && error.statusCode < 600 + ? error.statusCode + : 500; + let code = 'INTERNAL_ERROR'; + let message = 'Internal Server Error'; + let details: AppError['details']; + + if (error instanceof AppError) { + statusCode = error.statusCode; + code = error.code; + details = error.details; + message = statusCode < 500 ? error.message : 'Internal Server Error'; + } else if (statusCode < 500) { + code = error.code ?? 'BAD_REQUEST'; + message = error.message; + } + + if (statusCode >= 500) { + // Stack stays server-side: logs only, tagged with the request id. + logger.error({ err: error, requestId }, 'request failed'); + } else { + logger.info({ requestId, statusCode, code }, 'request rejected'); + } + + void reply.code(statusCode).send(errorEnvelope(statusCode, code, message, requestId, details)); + }); + + app.setNotFoundHandler((request: FastifyRequest, reply: FastifyReply) => { + void reply.code(404).send(errorEnvelope(404, 'NOT_FOUND', 'Not Found', request.id)); + }); await app.register(async (instance) => { await registerHealthRoutes(instance); diff --git a/project/src/app/tests/http-foundation.test.ts b/project/src/app/tests/http-foundation.test.ts new file mode 100644 index 0000000..8641b84 --- /dev/null +++ b/project/src/app/tests/http-foundation.test.ts @@ -0,0 +1,205 @@ +import { describe, expect, it } from 'vitest'; +import type { DestinationStream } from 'pino'; +import { z } from 'zod'; +import { buildApp } from '../build-app.js'; +import { createLogger } from '../../infrastructure/logging/logger.js'; +import { parseJson } from '../../shared/http-input.js'; + +type LogLine = Record; + +function memoryLogger(): { logger: ReturnType; lines: LogLine[] } { + const lines: LogLine[] = []; + const destination: DestinationStream = { + write(msg: string): void { + lines.push(JSON.parse(msg) as LogLine); + }, + }; + return { logger: createLogger({ level: 'info', destination }), lines }; +} + +const UUID_V4 = /^[0-9a-f]{8}-[0-9a-f]{4}-4[0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/i; + +interface ErrorBody { + error: { statusCode: number; code: string; message: string; details?: unknown[] }; + requestId: string; +} + +describe('http foundation', () => { + it('every response carries an x-request-id header', async () => { + const { logger } = memoryLogger(); + const app = await buildApp({ logger }); + + const ok = await app.inject({ method: 'GET', url: '/health' }); + expect(ok.headers['x-request-id']).toMatch(UUID_V4); + + const missing = await app.inject({ method: 'GET', url: '/nope' }); + expect(missing.headers['x-request-id']).toMatch(UUID_V4); + + await app.close(); + }); + + it('a valid incoming x-request-id is propagated to response and logs', async () => { + const { logger, lines } = memoryLogger(); + const app = await buildApp({ logger }); + + const response = await app.inject({ + method: 'GET', + url: '/health', + headers: { 'x-request-id': 'client-trace-42' }, + }); + + expect(response.headers['x-request-id']).toBe('client-trace-42'); + const completed = lines.filter((line) => line.msg === 'request completed'); + expect(completed).toHaveLength(1); + expect(completed[0]?.requestId).toBe('client-trace-42'); + await app.close(); + }); + + it('a malicious x-request-id is replaced by a generated UUID', async () => { + const { logger, lines } = memoryLogger(); + const app = await buildApp({ logger }); + + const badCharset = await app.inject({ + method: 'GET', + url: '/health', + headers: { 'x-request-id': 'evil\nx-injected: 1' }, + }); + expect(badCharset.headers['x-request-id']).toMatch(UUID_V4); + expect(badCharset.headers['x-request-id']).not.toContain('\n'); + + const tooLong = await app.inject({ + method: 'GET', + url: '/health', + headers: { 'x-request-id': 'a'.repeat(129) }, + }); + expect(tooLong.headers['x-request-id']).toMatch(UUID_V4); + + const completed = lines.filter((line) => line.msg === 'request completed'); + expect(completed).toHaveLength(2); + expect(completed[0]?.requestId).toBe(badCharset.headers['x-request-id']); + expect(completed[1]?.requestId).toBe(tooLong.headers['x-request-id']); + await app.close(); + }); + + it('unknown routes return the stable envelope with code NOT_FOUND and requestId', async () => { + const { logger } = memoryLogger(); + const app = await buildApp({ logger }); + + const response = await app.inject({ method: 'GET', url: '/does-not-exist' }); + expect(response.statusCode).toBe(404); + const body = response.json() as ErrorBody; + expect(body.error.statusCode).toBe(404); + expect(body.error.code).toBe('NOT_FOUND'); + expect(body.error.message).toBe('Not Found'); + expect(body.requestId).toBe(response.headers['x-request-id']); + await app.close(); + }); + + describe('validation hook on the API layer', () => { + async function buildValidatingApp() { + const memory = memoryLogger(); + const app = await buildApp({ logger: memory.logger }); + const schema = z.object({ name: z.string().min(1) }); + app.post('/__test/echo', async (request) => { + return parseJson(schema, request.body); + }); + return { app, lines: memory.lines }; + } + + it('malformed JSON yields the stable 400 envelope', async () => { + const { app, lines } = await buildValidatingApp(); + const response = await app.inject({ + method: 'POST', + url: '/__test/echo', + headers: { 'content-type': 'application/json' }, + body: '{"name": broken', + }); + + expect(response.statusCode).toBe(400); + const body = response.json() as ErrorBody; + expect(body.error.statusCode).toBe(400); + expect(typeof body.error.code).toBe('string'); + expect(typeof body.error.message).toBe('string'); + expect(body.requestId).toBe(response.headers['x-request-id']); + expect(response.body).not.toContain('stack'); + + const rejected = lines.filter((line) => line.msg === 'request rejected'); + expect(rejected).toHaveLength(1); + expect(rejected[0]?.requestId).toBe(body.requestId); + await app.close(); + }); + + it('schema-invalid payloads yield code VALIDATION_ERROR with field paths only', async () => { + const { app } = await buildValidatingApp(); + const response = await app.inject({ + method: 'POST', + url: '/__test/echo', + headers: { 'content-type': 'application/json' }, + payload: { name: '' }, + }); + + expect(response.statusCode).toBe(400); + const body = response.json() as ErrorBody; + expect(body.error.code).toBe('VALIDATION_ERROR'); + expect(body.error.details).toEqual([{ path: 'name', message: expect.any(String) }]); + expect(JSON.stringify(body)).not.toContain('stack'); + await app.close(); + }); + + it('valid payloads pass through the hook', async () => { + const { app } = await buildValidatingApp(); + const response = await app.inject({ + method: 'POST', + url: '/__test/echo', + headers: { 'content-type': 'application/json' }, + payload: { name: 'ana' }, + }); + + expect(response.statusCode).toBe(200); + expect(response.json()).toEqual({ name: 'ana' }); + await app.close(); + }); + }); + + it('internal errors never leak message or stack to the client', async () => { + const { logger, lines } = memoryLogger(); + const app = await buildApp({ logger }); + app.get('/__test/boom', () => { + throw new Error('secret internal detail'); + }); + + const response = await app.inject({ method: 'GET', url: '/__test/boom' }); + expect(response.statusCode).toBe(500); + const body = response.json() as ErrorBody; + expect(body.error.code).toBe('INTERNAL_ERROR'); + expect(body.error.message).toBe('Internal Server Error'); + expect(response.body).not.toContain('secret internal detail'); + expect(response.body).not.toContain('stack'); + + const failed = lines.filter((line) => line.msg === 'request failed'); + expect(failed).toHaveLength(1); + expect(failed[0]?.requestId).toBe(response.headers['x-request-id']); + const err = failed[0]?.err as { message?: string; stack?: string }; + expect(err.message).toBe('secret internal detail'); + expect(err.stack).toContain('Error'); + await app.close(); + }); + + it('every request produces exactly one request completed log line', async () => { + const { logger, lines } = memoryLogger(); + const app = await buildApp({ logger }); + + await app.inject({ method: 'GET', url: '/health' }); + await app.inject({ method: 'GET', url: '/missing' }); + + const completed = lines.filter((line) => line.msg === 'request completed'); + expect(completed).toHaveLength(2); + for (const line of completed) { + expect(line.requestId).toMatch(UUID_V4); + expect(line).toHaveProperty('method'); + expect(line).toHaveProperty('statusCode'); + expect(line).toHaveProperty('durationMs'); + } + await app.close(); + }); +}); diff --git a/project/src/infrastructure/http/server.ts b/project/src/infrastructure/http/server.ts index f15f60c..82628e8 100644 --- a/project/src/infrastructure/http/server.ts +++ b/project/src/infrastructure/http/server.ts @@ -1,12 +1,15 @@ import { buildApp } from '../../app/build-app.js'; +import { createLogger } from '../logging/logger.js'; +const logger = createLogger(); const port = Number(process.env.PORT ?? 3000); const host = process.env.HOST ?? '0.0.0.0'; try { - const app = await buildApp(); + const app = await buildApp({ logger }); await app.listen({ port, host }); + logger.info({ port, host }, 'HTTP server listening'); } catch (error) { - console.error('Failed to start HTTP server', error); + logger.error({ err: error }, 'Failed to start HTTP server'); process.exit(1); } diff --git a/project/src/infrastructure/logging/logger.ts b/project/src/infrastructure/logging/logger.ts new file mode 100644 index 0000000..61861df --- /dev/null +++ b/project/src/infrastructure/logging/logger.ts @@ -0,0 +1,25 @@ +/** + * Structured JSON logging. pino is the boring, fast, Fastify-ecosystem choice. + * No pretty printers, no transports: JSON lines to a writable destination. + */ +import pino, { type DestinationStream, type Logger } from 'pino'; + +const SERVICE_NAME = 'mercadodevida-backend'; + +export interface LoggerOptions { + /** Log level; defaults to LOG_LEVEL env var or 'info'. */ + level?: string; + /** Explicit destination stream (tests use an in-memory stream). */ + destination?: DestinationStream; +} + +export function createLogger(options: LoggerOptions = {}): Logger { + const level = options.level ?? process.env.LOG_LEVEL ?? 'info'; + const settings = { level, base: { service: SERVICE_NAME } }; + if (options.destination) { + return pino(settings, options.destination); + } + return pino(settings); +} + +export type { Logger }; diff --git a/project/src/shared/errors.ts b/project/src/shared/errors.ts index a63c2a5..4f676ec 100644 --- a/project/src/shared/errors.ts +++ b/project/src/shared/errors.ts @@ -1,15 +1,44 @@ /** - * Shared error envelope. Single shape for every API error. + * Shared error model and envelope. Single shape for every API error. * Never leak stack traces or internal details to the client. */ +export type ErrorDetail = Readonly>; + +export class AppError extends Error { + constructor( + public readonly statusCode: number, + public readonly code: string, + message: string, + public readonly details?: ReadonlyArray, + ) { + super(message); + this.name = 'AppError'; + } +} + export interface ErrorEnvelope { error: { statusCode: number; + code: string; message: string; + details?: ReadonlyArray; }; + requestId: string; } -export function errorEnvelope(statusCode: number, message: string): ErrorEnvelope { - return { error: { statusCode, message } }; +export function errorEnvelope( + statusCode: number, + code: string, + message: string, + requestId: string, + details?: ReadonlyArray, +): ErrorEnvelope { + return { + error: + details === undefined + ? { statusCode, code, message } + : { statusCode, code, message, details }, + requestId, + }; } diff --git a/project/src/shared/http-input.ts b/project/src/shared/http-input.ts new file mode 100644 index 0000000..e81ae6e --- /dev/null +++ b/project/src/shared/http-input.ts @@ -0,0 +1,18 @@ +/** + * Explicit input validation hook for the API layer. + * Call parseJson inside handlers; nothing is validated by magic. + */ +import { z } from 'zod'; +import { AppError, type ErrorDetail } from './errors.js'; + +export function parseJson(schema: z.ZodType, input: unknown): T { + const result = schema.safeParse(input); + if (result.success) { + return result.data; + } + const details: ReadonlyArray = result.error.issues.map((issue) => ({ + path: issue.path.join('.'), + message: issue.message, + })); + throw new AppError(400, 'VALIDATION_ERROR', 'Invalid request payload', details); +} diff --git a/project/src/shared/tests/http-input.test.ts b/project/src/shared/tests/http-input.test.ts new file mode 100644 index 0000000..a1d31ca --- /dev/null +++ b/project/src/shared/tests/http-input.test.ts @@ -0,0 +1,33 @@ +import { describe, expect, it } from 'vitest'; +import { z } from 'zod'; +import { parseJson } from '../http-input.js'; +import { AppError } from '../errors.js'; + +const schema = z.object({ name: z.string().min(1), age: z.number().int().nonnegative() }); + +describe('parseJson', () => { + it('returns the parsed value for valid input', () => { + expect(parseJson(schema, { name: 'ana', age: 3 })).toEqual({ name: 'ana', age: 3 }); + }); + + it('throws AppError 400 VALIDATION_ERROR with field issues for invalid input', () => { + let caught: unknown; + try { + parseJson(schema, { name: '', age: -1 }); + } catch (error) { + caught = error; + } + expect(caught).toBeInstanceOf(AppError); + const appError = caught as AppError; + expect(appError.statusCode).toBe(400); + expect(appError.code).toBe('VALIDATION_ERROR'); + expect(appError.details).toEqual([ + { path: 'name', message: expect.any(String) }, + { path: 'age', message: expect.any(String) }, + ]); + }); + + it('rejects non-object input when the schema expects an object', () => { + expect(() => parseJson(schema, 'not-an-object')).toThrowError(AppError); + }); +}); diff --git a/spec/tech.md b/spec/tech.md index f83cb32..ce2c03a 100644 --- a/spec/tech.md +++ b/spec/tech.md @@ -19,6 +19,8 @@ | pg | ^8 | Driver PostgreSQL estándar; única forma de hablar con la DB (F-002) | | node-pg-migrate | ^8 | Migraciones SQL up/down trackeadas en DB; elegida sobre runner propio (no reinvención) y sobre Flyway/golang-migrate (toolchains ajenos a Node) (F-002) | | @types/pg | ^8 | Tipos para pg (dev) (F-002) | +| pino | ^9 | Logging JSON estructurado; estándar del ecosistema Fastify, rápido y sin magia (F-003) | +| zod | ^4 | Validación explícita de inputs vía parseJson en handlers; sin decoradores ni magic binding (F-003) | Regla: toda dependencia nueva debe agregarse a esta tabla con justificación en el ticket que la introduce. diff --git a/specs/F-003-http-foundation/DESIGN.md b/specs/F-003-http-foundation/DESIGN.md new file mode 100644 index 0000000..3b6775a --- /dev/null +++ b/specs/F-003-http-foundation/DESIGN.md @@ -0,0 +1,54 @@ +# DESIGN — F-003 HTTP foundation and request context + +## Architecture +All cross-cutting HTTP behavior lives in explicit, readable code: + +- `src/infrastructure/logging/logger.ts` — pino factory. JSON only, level from + `LOG_LEVEL` (default `info`), base field `service`. Accepts an optional writable + destination so tests can capture output without transports (no magic). +- `src/shared/errors.ts` — `AppError` class (statusCode, code, message) and the + single `errorEnvelope(statusCode, code, message, requestId)` builder. Envelope v2: + `{ error: { statusCode, code, message }, requestId }`. +- `src/shared/http-input.ts` — `parseJson(schema, input)` using zod. On failure + throws `AppError(400, VALIDATION_ERROR)` carrying field-level issues (field paths + only, never internal state). +- `src/app/build-app.ts` — composition root wires everything explicitly: + - Fastify `genReqId`: trust incoming `x-request-id` only if it matches + `^[A-Za-z0-9._-]{1,128}$`; otherwise generate `crypto.randomUUID()`. + - `onRequest` hook: set `x-request-id` response header, start timer. + - `onResponse` hook: one JSON log line per request + `{ requestId, method, url, statusCode, durationMs }`. + - `setErrorHandler`: map `AppError` and Fastify errors to the envelope. 4xx expose + their message; >=500 always returns generic `Internal Server Error`. Errors are + logged with stack server-side, tagged with requestId. + - `setNotFoundHandler`: envelope with code `NOT_FOUND` + requestId. +- `src/infrastructure/http/server.ts` — startup log lines through the logger. + +## Request id policy +- Propagation is opt-in and sanitized; anything suspicious is replaced by a fresh UUID. +- Response header name: `x-request-id`. + +## Validation policy +- Validation is explicit per route: call `parseJson(schema, body)` inside the handler. +- No schema decorators, no magic body binding. The F-003 deliverable is the hook + (helper + envelope integration), exercised by composition tests with a test-only + route registered on the built app. + +## Backward compatibility +- `GET /health` response body unchanged; envelope gains fields (additive). + +## Files +| File | Role | +|---|---| +| src/infrastructure/logging/logger.ts | pino factory | +| src/shared/errors.ts | AppError + envelope v2 | +| src/shared/http-input.ts | zod parse helper | +| src/app/build-app.ts | hooks, genReqId, handlers | +| src/infrastructure/http/server.ts | startup logging | +| src/app/tests/http-foundation.test.ts | composition tests (request id, logs, envelope, no leak) | +| src/shared/tests/http-input.test.ts | helper unit tests | + +## Risks / mitigations +- Double logging (fastify internal + hooks): keep `logger: false` on Fastify, log only via explicit hooks. +- Header injection through propagated id: strict regex + length cap. +- 5xx leaking internals: handler returns fixed generic message for anything >=500; tests assert absence of thrown message/stack. diff --git a/specs/F-003-http-foundation/SPEC.md b/specs/F-003-http-foundation/SPEC.md new file mode 100644 index 0000000..62b0156 --- /dev/null +++ b/specs/F-003-http-foundation/SPEC.md @@ -0,0 +1,37 @@ +# SPEC — F-003 HTTP foundation and request context + +## Problem +Every request needs identity, structured logs and predictable errors. Today the app +answers with ad-hoc console logging potential, no request correlation id, and an +error envelope without request context. + +## Goal +request_id everywhere, JSON logs, one error envelope, no magic. + +## Scope IN +- request_id generated or propagated on every request +- Structured JSON logging with request_id +- Single error response envelope (v2: adds stable `code` + `requestId`) +- Input validation hook on API layer (foundation helper, explicit usage) + +## Scope OUT +- No tracing backend +- No metrics backend +- No production endpoints that consume validation yet (first consumer: F-005 identity) + +## Acceptance criteria +1. Every response carries `request_id` (via `x-request-id` response header; error bodies also embed it). +2. Every log line for a request carries the same request_id. +3. Given an invalid request When handled Then the error envelope shape is stable. +4. Internal stack traces never leak to API responses (5xx message is generic; stack stays server-side in logs). +5. `./scripts/verify.sh` green. + +## Non-functional +- JSON-only logs (no pretty printers in runtime). +- Incoming `x-request-id` must be sanitized before reuse (length/charset limits). +- No new framework magic: logging hooks and error handler are explicit code in the composition root. + +## Dependencies added +- pino (JSON structured logging; Fastify ecosystem standard) +- zod (explicit input validation; no decorators/annotations magic) +Justification goes to `spec/tech.md`. diff --git a/specs/F-003-http-foundation/TASKS.md b/specs/F-003-http-foundation/TASKS.md new file mode 100644 index 0000000..dbe17ef --- /dev/null +++ b/specs/F-003-http-foundation/TASKS.md @@ -0,0 +1,11 @@ +# TASKS — F-003 HTTP foundation and request context + +- [ ] TASK-001 deps: add pino + zod; justify both in spec/tech.md +- [ ] TASK-002 src/infrastructure/logging/logger.ts: createLogger({ level?, destination? }) +- [ ] TASK-003 src/shared/errors.ts: AppError + errorEnvelope v2 (code + requestId) +- [ ] TASK-004 src/shared/http-input.ts: parseJson(schema, input) -> AppError(400, VALIDATION_ERROR) +- [ ] TASK-005 src/app/build-app.ts: genReqId sanitization, onRequest/onResponse hooks, error + notFound handlers with requestId; buildApp(deps) injectable logger +- [ ] TASK-006 src/infrastructure/http/server.ts: logger-based startup lines +- [ ] TASK-007 tests: src/shared/tests/http-input.test.ts +- [ ] TASK-008 tests: src/app/tests/http-foundation.test.ts (id propagation/sanitization, log correlation, envelope stability incl. malformed JSON, no stack leak) +- [ ] TASK-009 run lint + boundaries + typecheck + build + test + verify.sh diff --git a/specs/F-003-http-foundation/TESTS.md b/specs/F-003-http-foundation/TESTS.md new file mode 100644 index 0000000..ad120c7 --- /dev/null +++ b/specs/F-003-http-foundation/TESTS.md @@ -0,0 +1,21 @@ +# TESTS — F-003 HTTP foundation and request context + +## Unit — src/shared/tests/http-input.test.ts +1. parseJson returns parsed value for valid input +2. parseJson throws AppError 400 VALIDATION_ERROR with field issues for invalid input +3. parseJson rejects non-object input when schema expects object + +## Composition — src/app/tests/http-foundation.test.ts +(app built with logger writing to an in-memory stream) + +1. GET /health responds 200 with x-request-id header (UUID shape) +2. Valid incoming x-request-id is propagated: same value in response header and in the request log line +3. Malicious x-request-id (bad charset / >128 chars) is replaced by generated UUID; log line carries the generated id +4. Unknown route -> 404 envelope { error: { statusCode: 404, code: NOT_FOUND, message }, requestId } + x-request-id header +5. Invalid JSON body on test route -> 400, envelope shape stable, requestId present +6. Schema-invalid body on test route -> 400 code VALIDATION_ERROR, issues mention field path only +7. Handler throwing Error('secret internal detail') -> 500 generic message, response body contains neither the message nor a stack; error log line contains requestId and stack +8. Every request produces exactly one 'request completed' log line carrying the requestId + +## Manual / QA +- verify.sh green; live curl shows x-request-id header and JSON envelope on unknown route. diff --git a/work/artifacts/F-003/architect.md b/work/artifacts/F-003/architect.md new file mode 100644 index 0000000..77f7440 --- /dev/null +++ b/work/artifacts/F-003/architect.md @@ -0,0 +1,22 @@ +# Architect — F-003 HTTP foundation and request context + +done -> work/artifacts/F-003/architect.md + +## Deliverables +- specs/F-003-http-foundation/SPEC.md +- specs/F-003-http-foundation/DESIGN.md +- specs/F-003-http-foundation/TASKS.md +- specs/F-003-http-foundation/TESTS.md + +## Key decisions +1. **pino** for JSON structured logging: Fastify ecosystem standard, fast, boring. Fastify's own logger stays OFF (`logger: false`); logging happens through explicit onRequest/onResponse hooks so there is exactly one log line per request and zero hidden log paths. +2. **zod** for the input validation hook: explicit `parseJson(schema, body)` calls inside handlers. No decorators, no magic binding. F-003 ships the hook; first real consumer is F-005 identity. +3. **request_id policy**: propagate incoming `x-request-id` only when it matches `^[A-Za-z0-9._-]{1,128}$` (header-injection defense); otherwise `crypto.randomUUID()`. Response header `x-request-id` on every response; error envelopes also embed requestId. +4. **Error envelope v2** (additive): `{ error: { statusCode, code, message }, requestId }`. Codes: NOT_FOUND, VALIDATION_ERROR, INTERNAL_ERROR, or upstream Fastify error codes for known 4xx. >=500 always answers the generic `Internal Server Error`; stack goes to logs tagged with requestId, never to the client. +5. **Logger injection**: `buildApp({ logger? })` — tests capture logs through an in-memory destination. No transports, no env sniffing in tests. + +## Boundaries +- Cross-cutting code lives in `shared` and `infrastructure/logging`; composition wiring only in `src/app`. Modules (health) untouched. + +## Open risks +- Envelope change touches F-001 test expectations (additive; tests will be updated in build). diff --git a/work/artifacts/F-003/documenter.md b/work/artifacts/F-003/documenter.md new file mode 100644 index 0000000..4be363c --- /dev/null +++ b/work/artifacts/F-003/documenter.md @@ -0,0 +1,18 @@ +# Documenter — F-003 HTTP foundation and request context + +done -> work/artifacts/F-003/documenter.md + +## Why documentation applies +F-003 defines the API-wide HTTP contract (request id, error envelope, validation hook) that every future module consumes. + +## Documents reviewed/produced +- `project/README.md`: new "HTTP contract" section — x-request-id policy, envelope shape + codes, no-stack-leak guarantee, parseJson validation pattern, LOG_LEVEL. (Applied via a build-stage bounce because `project/` writes require build/implementer/running.) +- `spec/tech.md`: pino + zod justification rows added at build stage. +- `specs/F-003-http-foundation/` SPEC/DESIGN/TASKS/TESTS consistent with implementation. + +## Verification +- README HTTP contract section matches tested behavior (cross-checked against qa.json live probes and test suite). +- Envelope documented as v2 (additive over F-001), codes enumerated. + +## Pending docs (not this ticket) +- Per-module validation schemas documented as modules land (F-005+). diff --git a/work/artifacts/F-003/implementer.md b/work/artifacts/F-003/implementer.md new file mode 100644 index 0000000..259ced8 --- /dev/null +++ b/work/artifacts/F-003/implementer.md @@ -0,0 +1,43 @@ +# Implementer — F-003 HTTP foundation and request context + +done -> work/artifacts/F-003/implementer.md + +## Files created +- src/infrastructure/logging/logger.ts (pino factory; JSON only; injectable destination for tests) +- src/shared/http-input.ts (parseJson zod helper -> AppError 400 VALIDATION_ERROR with field paths) +- src/app/tests/http-foundation.test.ts (9 tests: id generation/propagation/sanitization, log correlation, envelope stability, no stack leak, one log line per request) +- src/shared/tests/http-input.test.ts (3 tests) + +## Files modified +- src/shared/errors.ts: AppError class + error envelope v2 `{ error: { statusCode, code, message, details? }, requestId }` (additive over F-001 shape) +- src/app/build-app.ts: genReqId sanitization (^[A-Za-z0-9._-]{1,128}$ else randomUUID), onRequest/onResponse hooks (x-request-id header + one JSON log line per request), explicit setErrorHandler/setNotFoundHandler with requestId; buildApp({ logger? }) injectable +- src/infrastructure/http/server.ts: startup/shutdown logging via injected logger +- spec/tech.md: pino + zod justification +- package.json: deps pino, zod + +## API changes +- Every response now carries `x-request-id` header +- Error body v2: `{ error: { statusCode, code, message, details? }, requestId }` +- GET /health body unchanged + +## Tests passed (evidence) +``` +npm run lint:boundaries -> Boundary check OK: 16 file(s) checked +npm run lint -> OK +npm run typecheck -> exit 0 +npm run build -> exit 0 +npm test -> 6 files passed, 2 skipped (integration, no DB in unit run); 23 passed | 6 skipped +live smoke (PORT=3998): + GET /health -> 200, x-request-id: 65b38aee-..., body {"status":"ok"} + GET /nope -> 404 envelope v2 with requestId matching log line + POST /health bad json -> 400; log code FST_ERR_CTP_INVALID_JSON_BODY with same requestId as response + server logs: one "request completed" JSON line per request carrying requestId +``` + +## Known limitations +- Fastify 4xx parse-error messages are exposed as-is (e.g. "Unexpected token"); they carry no internals and are standard. +- Validation hook is exercised via a test-only route (/__test/echo registered in composition test); first production consumer arrives with F-005. + +## Follow-up work +- F-004 config/flags will centralize LOG_LEVEL handling. +- F-005 identity first real parseJson consumer. diff --git a/work/artifacts/F-003/leader-close.json b/work/artifacts/F-003/leader-close.json new file mode 100644 index 0000000..324b2bd --- /dev/null +++ b/work/artifacts/F-003/leader-close.json @@ -0,0 +1,35 @@ +{ + "feature_id": "F-003", + "agent": "leader", + "verdict": "APPROVED", + "summary": "F-003 closed. HTTP foundation in place: request_id everywhere (generated or sanitized-propagated), JSON structured logs correlated per request, stable error envelope v2, explicit validation hook. All gates APPROVED, verify.sh exit 0.", + "gates": { + "reviewer": "APPROVED (reviewer.json)", + "security": "APPROVED (security.json)", + "qa": "APPROVED (qa.json)", + "verify_sh": "exit 0" + }, + "deliverables": [ + "src/infrastructure/logging/logger.ts (pino factory, injectable destination)", + "src/shared/errors.ts (AppError + error envelope v2)", + "src/shared/http-input.ts (parseJson zod hook)", + "src/app/build-app.ts (genReqId sanitization, onRequest/onResponse hooks, error+notFound handlers)", + "src/infrastructure/http/server.ts (logger-based startup)", + "12 new tests across shared + app composition; README HTTP contract section", + "spec/tech.md pino+zod justification" + ], + "process_notes": [ + "Doc stage bounced to build to write README (project/ gated to build/implementer/running). This is the correct guardrail behavior." + ], + "next_feature_hint": "F-004 (config/flags) only depends on F-001; F-005 identity needs F-002+F-003, both now done -> F-005 unblocked", + "evidence": [ + "work/artifacts/F-003/architect.md", + "work/artifacts/F-003/implementer.md", + "work/artifacts/F-003/reviewer.json", + "work/artifacts/F-003/security.json", + "work/artifacts/F-003/qa.json", + "work/artifacts/F-003/documenter.md", + "./scripts/verify.sh exit 0 at close" + ], + "timestamp": "2026-08-14T20:18:00Z" +} diff --git a/work/artifacts/F-003/qa.json b/work/artifacts/F-003/qa.json new file mode 100644 index 0000000..c5197f0 --- /dev/null +++ b/work/artifacts/F-003/qa.json @@ -0,0 +1,40 @@ +{ + "feature_id": "F-003", + "agent": "qa", + "verdict": "APPROVED", + "summary": "All 5 acceptance criteria verified with fresh live probes and full suites.", + "traceability": [ + { + "criterion": "AC1: every response carries request_id", + "test": "live curl: GET /health (200) and GET /missing (404) both returned x-request-id UUID headers", + "result": "PASS" + }, + { + "criterion": "AC2: every request log line carries the same request_id", + "test": "grep of server JSON logs: each live request_id appears exactly once, in its 'request completed' line", + "result": "PASS" + }, + { + "criterion": "AC3: invalid request -> stable error envelope shape", + "test": "live 404 and malformed-JSON 400 bodies share { error: { statusCode, code, message }, requestId }; schema-invalid case covered by unit test (VALIDATION_ERROR + field details)", + "result": "PASS" + }, + { + "criterion": "AC4: internal stack traces never leak", + "test": "live bodies contain zero occurrences of 'stack'; unit test proves 500 handler hides thrown message and stack while logging them server-side", + "result": "PASS" + }, + { + "criterion": "AC5: verify.sh green", + "test": "./scripts/verify.sh", + "result": "PASS (exit 0)" + } + ], + "regressions": "PASS - unit 23 passed | 6 skipped; F-002 integration 6 passed; health endpoint body unchanged", + "evidence": [ + "live probes at PORT=3997 with fresh dist build", + "npm test / test:integration green", + "./scripts/verify.sh exit 0" + ], + "timestamp": "2026-08-14T20:16:00Z" +} diff --git a/work/artifacts/F-003/reviewer.json b/work/artifacts/F-003/reviewer.json new file mode 100644 index 0000000..7c70d9f --- /dev/null +++ b/work/artifacts/F-003/reviewer.json @@ -0,0 +1,27 @@ +{ + "feature_id": "F-003", + "agent": "reviewer", + "verdict": "APPROVED", + "summary": "HTTP foundation matches specs/F-003 DESIGN.md. Explicit hooks, sanitized id propagation, stable envelope v2, no stack leak. No regressions: F-001/F-002 suites fully green including database integration tests.", + "checks": { + "design_conformance": "PASS: logger factory, AppError/envelope v2, parseJson hook, genReqId + hooks + handlers all exactly as designed; logger: false on Fastify prevents double logging", + "security_of_propagation": "PASS: strict regex ^[A-Za-z0-9._-]{1,128}$ before trusting incoming x-request-id; tested against newline injection and oversized values", + "no_magic": "PASS: validation is an explicit parseJson call; no decorators/annotations; hooks are plain readable functions in the composition root", + "test_coverage": "PASS: 12 new tests map 1:1 to specs/F-003 TESTS.md; test-only route /__test/echo exercises the hook end-to-end without polluting production API", + "regression": "PASS: full unit suite 23 passed; F-002 integration suite 6 passed; envelope change verified additive" + }, + "findings": [ + { + "severity": "info", + "note": "Fastify 4xx error codes (e.g. FST_ERR_CTP_INVALID_JSON_BODY) surface in the envelope code field. Public codes, no internals; acceptable and useful for clients." + } + ], + "evidence": [ + "npm run lint / typecheck / lint:boundaries (16 files) -> exit 0", + "npm test -> 6 files passed, 23 passed | 6 skipped", + "npm run test:integration -> 2 files, 6 passed (no F-002 regression)", + "live smoke at build stage: x-request-id header on 200/404/400, requestId correlated in JSON logs", + "files reviewed: src/app/build-app.ts, src/shared/errors.ts, src/shared/http-input.ts, src/infrastructure/logging/logger.ts, src/infrastructure/http/server.ts, both test suites" + ], + "timestamp": "2026-08-14T20:12:00Z" +} diff --git a/work/artifacts/F-003/security.json b/work/artifacts/F-003/security.json new file mode 100644 index 0000000..3503c8e --- /dev/null +++ b/work/artifacts/F-003/security.json @@ -0,0 +1,27 @@ +{ + "feature_id": "F-003", + "agent": "security", + "verdict": "APPROVED", + "summary": "Security gate passed. Header propagation sanitized against injection, no stack/internal leakage, log injection neutralized by JSON serialization, zero audit vulnerabilities with pino+zod.", + "checks": { + "dependencies": "PASS: npm audit -> 0 vulnerabilities; pino/zod justified in spec/tech.md", + "header_injection": "PASS: incoming x-request-id accepted only under ^[A-Za-z0-9._-]{1,128}$; newline and 129-char payloads replaced by UUID (regression tests present)", + "response_leakage": "PASS: 5xx path forces generic 'Internal Server Error'; body assertions confirm absence of thrown message and stack; 4xx exposes only safe messages/codes", + "log_injection": "PASS: requestId is pre-sanitized; url/method serialized via pino JSON encoding which escapes control characters", + "dangerous_patterns": "PASS: no eval / new Function / child_process in src" + }, + "findings": [ + { + "severity": "info", + "note": "Fastify 4xx codes exposed in envelope (e.g. FST_ERR_CTP_INVALID_JSON_BODY) are public framework codes; no internal state disclosed." + } + ], + "evidence": [ + "npm audit -> found 0 vulnerabilities", + "grep eval|new Function over src -> none", + "grep x-request-id non-test usages -> only constant + sanitized generator path", + "5xx generic guard verified at build-app.ts lines 68/75", + "test 'internal errors never leak message or stack to the client' passes" + ], + "timestamp": "2026-08-14T20:14:00Z" +} diff --git a/work/current.md b/work/current.md index 89fb88a..fad2395 100644 --- a/work/current.md +++ b/work/current.md @@ -1,16 +1,17 @@ # Sesión actual -- Feature en curso: _ninguna_ (F-002 cerrada DONE el 2026-08-14) +- Feature en curso: _ninguna_ (F-003 cerrada DONE el 2026-08-14) - Inicio: — - Orquestador: — ## Plan -- Features ahora desbloqueadas: F-003 (HTTP foundation), F-004 (config/flags) — dependen solo de F-001. F-005 (identity) tiene sus dos dependencias (F-002, F-003): falta F-003. -- Sugerencia de orden: F-003 → F-004 → F-005. +- Hechas: F-001, F-002, F-003. +- Desbloqueadas ahora: F-004 (config/flags, depende de F-001) y F-005 (identity, depende de F-002+F-003, ambas done). +- Sugerencia de orden: F-004 → F-005 (identity necesita config/flags limpio para secrets). ## Bitácora -- 2026-08-14: F-001 DONE y F-002 DONE, todos los gates APPROVED, verify.sh verde. +- 2026-08-14: F-001, F-002 y F-003 DONE; todos los gates APPROVED; verify.sh verde. - Dev PostgreSQL + Redis siguen corriendo (mdv-dev-postgres, mdv-dev-redis) para los próximos tickets. ## Próximo paso -- intake de F-003 (HTTP foundation and request context). +- intake de F-004 (config and feature flags). diff --git a/work/history.md b/work/history.md index 284ae1d..b2958cb 100644 --- a/work/history.md +++ b/work/history.md @@ -13,3 +13,9 @@ - Entregable: migraciones node-pg-migrate (up/down/no-op probados contra PostgreSQL 16 real), pool fail-fast, docker-compose (Postgres + Redis), convención _ documentada - Nota: security devolvió un hallazgo bajo (interpolación de identificador en DDL de tests); se mitigó con validación estricta + tests de regresión - Artefactos: work/artifacts/F-002/ + +## 2026-08-14 — F-003 HTTP foundation and request context — DONE +- Gates: reviewer APPROVED, security APPROVED, qa APPROVED, verify.sh exit 0 +- Entregable: request_id (generado o propagado-sanitizado), logs JSON correlacionados, error envelope v2 con requestId, hook de validación parseJson (zod), server con logging inyectable +- Nota: doc stage rebotó a build para escribir README (project/ está gateado a build/implementer/running); comportamiento correcto del guardrail +- Artefactos: work/artifacts/F-003/ diff --git a/work/runtime-status.json b/work/runtime-status.json index e70eaaf..9ab1de2 100644 --- a/work/runtime-status.json +++ b/work/runtime-status.json @@ -6,6 +6,6 @@ "state": "waiting", "next_agent": "leader", "waiting_for": "Seleccionar una feature pending y actualizar este estado", - "updated_at": "2026-08-14T20:00:16Z", + "updated_at": "2026-08-14T20:13:28Z", "timeline": [] }