|
| 1 | +# Forecast Access Logs |
| 2 | + |
| 3 | +Structured JSON access logs for all `/api/forecast` endpoints, emitted with |
| 4 | +correlation IDs, actor identity, latency, and response size for full |
| 5 | +auditability of every forecast operation. |
| 6 | + |
| 7 | +## Overview |
| 8 | + |
| 9 | +Every request that flows through the `/api/forecast` router is wrapped by |
| 10 | +`src/middleware/forecastAccessLog.ts`. On response completion the middleware |
| 11 | +emits a single structured JSON log entry on the `forecast` Pino channel. |
| 12 | + |
| 13 | +This is separate from the global access log (`src/middleware/accessLog.ts`), |
| 14 | +which samples all traffic at a configurable rate. Forecast logs are **always |
| 15 | +emitted** (100%) so that read and write activity on forecast data can be |
| 16 | +independently monitored, alerted on, and correlated with audit events. |
| 17 | + |
| 18 | +## Log Fields |
| 19 | + |
| 20 | +| Field | Type | Description | |
| 21 | +| --------------- | ------- | -------------------------------------------------------------------- | |
| 22 | +| `correlationId` | string | Resolved from `x-correlation-id`, then `x-request-id`, then UUID v4 | |
| 23 | +| `requestId` | string | Sanitised `x-request-id` header, `req.id`, or generated UUID v4 | |
| 24 | +| `method` | string | HTTP verb (`GET`, `POST`, `PATCH`, `DELETE`) | |
| 25 | +| `path` | string | Request path (e.g. `/api/forecast` or `/api/forecast/forecast_abc`) | |
| 26 | +| `status` | number | HTTP response status code | |
| 27 | +| `statusCode` | number | Alias for `status` (compatibility with the global access-log format) | |
| 28 | +| `ms` | number | Request latency in milliseconds (3 decimal places) | |
| 29 | +| `durationMs` | number | Alias for `ms` | |
| 30 | +| `responseBytes` | number | Size of the HTTP response body in bytes | |
| 31 | +| `userId` | string? | Authenticated developer ID (from `res.locals.authenticatedUser`) | |
| 32 | +| `actor` | string? | Alias for `userId` — surfaced for audit tooling queries | |
| 33 | +| `clientIp` | string? | Client IP address (respects `TRUST_PROXY_HEADERS`) | |
| 34 | +| `forecastId` | string? | Route param `:id` when present (read, update, delete by ID) | |
| 35 | + |
| 36 | +## Log Levels |
| 37 | + |
| 38 | +| Status range | Pino level | |
| 39 | +| ------------ | ---------- | |
| 40 | +| 5xx | `error` | |
| 41 | +| 4xx | `warn` | |
| 42 | +| 2xx / 3xx | `info` | |
| 43 | + |
| 44 | +## Sample Log Entry |
| 45 | + |
| 46 | +```jsonc |
| 47 | +{ |
| 48 | + "level": 30, |
| 49 | + "time": 1753480000000, |
| 50 | + "channel": "forecast", |
| 51 | + "correlationId": "req_a1b2c3d4", |
| 52 | + "requestId": "req_a1b2c3d4", |
| 53 | + "method": "GET", |
| 54 | + "path": "/api/forecast/forecast_abc123", |
| 55 | + "status": 200, |
| 56 | + "statusCode": 200, |
| 57 | + "ms": 12.847, |
| 58 | + "durationMs": 12.847, |
| 59 | + "responseBytes": 482, |
| 60 | + "userId": "dev-xyz", |
| 61 | + "actor": "dev-xyz", |
| 62 | + "forecastId": "forecast_abc123", |
| 63 | + "msg": "forecast request completed" |
| 64 | +} |
| 65 | +``` |
| 66 | + |
| 67 | +## Correlation ID Resolution |
| 68 | + |
| 69 | +The middleware resolves IDs using the same priority chain as the billing and |
| 70 | +exports logs: |
| 71 | + |
| 72 | +1. `x-correlation-id` header (sanitised via `sanitizeRequestId`) |
| 73 | +2. `x-request-id` header (sanitised) |
| 74 | +3. `req.id` (set upstream by `requestIdMiddleware`) |
| 75 | +4. Async-local request ID (set by `requestIdMiddleware`) |
| 76 | +5. Generated UUID v4 (fallback — always present) |
| 77 | + |
| 78 | +`sanitizeRequestId` strips ASCII control characters (CR, LF, NUL, …), |
| 79 | +trims whitespace, rejects values longer than 128 characters, and returns |
| 80 | +`undefined` for empty strings. This prevents header injection attacks. |
| 81 | + |
| 82 | +## Redaction |
| 83 | + |
| 84 | +Sensitive fields can be redacted at the factory level: |
| 85 | + |
| 86 | +```typescript |
| 87 | +import { createForecastAccessLogMiddleware } from './forecastAccessLog.js'; |
| 88 | + |
| 89 | +router.use( |
| 90 | + createForecastAccessLogMiddleware({ |
| 91 | + redactFields: ['path', 'userId'], |
| 92 | + }), |
| 93 | +); |
| 94 | +``` |
| 95 | + |
| 96 | +Redacted values are replaced with `[REDACTED]`. Field matching is |
| 97 | +case-insensitive. |
| 98 | + |
| 99 | +## Wiring |
| 100 | + |
| 101 | +The middleware is mounted as the first handler in the forecast router, after |
| 102 | +the timeout middleware: |
| 103 | + |
| 104 | +```typescript |
| 105 | +// src/routes/forecast.ts |
| 106 | +import { createForecastAccessLogMiddleware } from '../middleware/forecastAccessLog.js'; |
| 107 | + |
| 108 | +export function createForecastRouter(timeoutMs = 5_000): Router { |
| 109 | + const router = Router(); |
| 110 | + router.use(createTimeoutMiddleware({ durationMs: timeoutMs })); |
| 111 | + router.use(createForecastAccessLogMiddleware()); |
| 112 | + // …routes… |
| 113 | + return router; |
| 114 | +} |
| 115 | +``` |
| 116 | + |
| 117 | +This guarantees that every sub-route — |
| 118 | +`GET /`, `POST /`, `GET /:id`, `PATCH /:id`, `DELETE /:id` — |
| 119 | +is covered, including error paths handled by the downstream `errorHandler`. |
| 120 | + |
| 121 | +## Configuration |
| 122 | + |
| 123 | +| Environment variable | Default | Description | |
| 124 | +| --------------------- | ------- | ------------------------------------------------------------------- | |
| 125 | +| `TRUST_PROXY_HEADERS` | `false` | When `true`, honours `X-Forwarded-For` etc. for client IP extraction | |
| 126 | + |
| 127 | +## Security |
| 128 | + |
| 129 | +- **No raw user input** is written to logs without sanitisation. |
| 130 | +- **Header injection** is prevented by stripping control characters from all |
| 131 | + correlation and request ID values. |
| 132 | +- **PII**: only developer IDs (opaque internal identifiers) appear in log |
| 133 | + payloads, never names, email addresses, or credentials. |
| 134 | +- **Redaction** is available for any field via `createForecastAccessLogMiddleware`. |
| 135 | + |
| 136 | +## Relationship to Audit Logs |
| 137 | + |
| 138 | +The forecast access log records HTTP metadata for **every** request (reads and |
| 139 | +writes alike). The audit log (`src/services/auditService.ts`) records |
| 140 | +business-level before/after state changes for **state-mutating operations only** |
| 141 | +(POST, PATCH, DELETE). |
| 142 | + |
| 143 | +Both entries share the same `correlationId` / `requestId` value, so operators |
| 144 | +can join the two records to reconstruct the full picture of what happened, |
| 145 | +who did it, and what changed. |
| 146 | + |
| 147 | +## Testing |
| 148 | + |
| 149 | +Unit tests: `src/middleware/forecastAccessLog.test.ts` |
| 150 | + |
| 151 | +Run with: |
| 152 | + |
| 153 | +```bash |
| 154 | +npm test -- forecastAccessLog |
| 155 | +``` |
0 commit comments