diff --git a/ENVIRONMENT_VARIABLES_AND_SECRETS.md b/ENVIRONMENT_VARIABLES_AND_SECRETS.md index 4f527416..4d28e24b 100644 --- a/ENVIRONMENT_VARIABLES_AND_SECRETS.md +++ b/ENVIRONMENT_VARIABLES_AND_SECRETS.md @@ -39,8 +39,23 @@ Variables marked **Required** are checked by `validateRequiredEnvVars()` in `lis | Variable | Default | Required | Description | |---|---|---|---| -| `LOG_LEVEL` | `info` | No | Winston log level. Values: `error` \| `warn` \| `info` \| `http` \| `verbose` \| `debug` \| `silly`. | -| `NODE_ENV` | *(unset)* | No | Set to `production` to enable newline-delimited JSON (structured) log output. Leave unset for human-readable pretty-print during development. | +| `LOG_LEVEL` | `info` | No | Log verbosity. Exactly one of: `error` \| `warn` \| `info` \| `debug`. Any other value is **rejected at startup** with a `ConfigError`. | +| `LOG_FORMAT` | *(env-dependent)* | No | Log output format: `json` (newline-delimited JSON for log aggregators) or `pretty` (colourised, human-readable). Defaults to `json` when `NODE_ENV=production`, `pretty` otherwise. Any other value is rejected at startup. | +| `NODE_ENV` | *(unset)* | No | Set to `production` for production defaults. Affects the `LOG_FORMAT` default only when `LOG_FORMAT` is unset; an explicit `LOG_FORMAT` always wins. | + +> **Note on log levels.** Earlier revisions of this table listed `http`, +> `verbose` and `silly`. The service has only ever implemented +> `error | warn | info | debug` — the other values were silently downgraded to +> `info`. They are now rejected at startup rather than accepted-and-ignored, so +> a deployment that sets one will fail fast with a message naming the valid +> values instead of running at unexpected verbosity. + +**Secret redaction.** Log records are scanned before emission and any field +whose name looks like a credential (`password`, `secret`, `token`, `apiKey`, +`authorization`, `signature`, `cookie`, `privateKey`, and case/underscore +variants) has its value replaced with `[REDACTED]`. Query-string parameters in +logged request URLs are redacted the same way. The field itself is kept so +record shape stays stable for aggregator indexing. ### 2.2 Stellar / chain connectivity @@ -182,6 +197,7 @@ The DB-backed retry scheduler persists retry state across process restarts. | `RATE_LIMIT_WINDOW_MS` | `60000` | No | Rate limit sliding window size (ms). | | `RATE_LIMIT_MAX_REQUESTS` | `60` | No | Maximum requests allowed per window (applies to all clients unless overridden). | | `RATE_LIMIT_CLIENT_OVERRIDES` | `{}` | No | Per-client rate limit overrides. JSON object. See shape below. | +| `API_MAX_BODY_BYTES` | `1048576` | No | Largest request body the events API accepts, in bytes (default 1 MiB). Oversized `POST`/`PUT`/`PATCH` requests get `413 Payload Too Large` with code `PAYLOAD_TOO_LARGE`, and the payload is never parsed. Must be a positive integer. | **`RATE_LIMIT_CLIENT_OVERRIDES` shape:** ```json diff --git a/listener/src/api/events-server.ts b/listener/src/api/events-server.ts index 0fa31219..80e899d5 100644 --- a/listener/src/api/events-server.ts +++ b/listener/src/api/events-server.ts @@ -57,6 +57,8 @@ import { NotificationHealthMonitor } from '../services/notification-health-monit import { getJobMonitor } from '../services/job-monitor'; import { NotificationImportService } from '../services/notification-import-service'; import { ResponseTimeMiddleware } from '../middleware/response-time'; +import { DEFAULT_MAX_BODY_BYTES, enforceBodyLimit } from '../middleware/body-limit'; +import { sanitizeUrl } from '../utils/logger'; export interface EventsServerOptions { port: number; @@ -98,6 +100,11 @@ export interface EventsServerOptions { * When omitted a new instance is created using `slowRequestThresholdMs`. */ responseTimeMiddleware?: ResponseTimeMiddleware | null; + /** + * Largest request body accepted, in bytes. Oversized requests get a 413 and + * are never parsed. Defaults to {@link DEFAULT_MAX_BODY_BYTES}. + */ + maxBodyBytes?: number; } type ServiceStatus = 'ok' | 'error' | 'not_configured'; @@ -425,6 +432,30 @@ export function createEventsServer(options: EventsServerOptions): http.Server { // Start response-time tracking for this request (#491) responseTime.start(res); + // Request body size limit. + // + // Screened here, before routing, so an oversized payload is answered and + // the socket destroyed before any route handler attaches its own `data` + // listener and starts accumulating the body in memory. + const maxBodyBytes = options.maxBodyBytes ?? DEFAULT_MAX_BODY_BYTES; + const bodyLimit = enforceBodyLimit(req, res, { + maxBytes: maxBodyBytes, + onRejected: (reason, observedBytes) => { + logger.warn('Request body exceeded size limit', { + requestId, + correlationId, + method: req.method, + url: sanitizeUrl(req.url ?? '/'), + reason, + observedBytes, + maxBytes: maxBodyBytes, + }); + }, + }); + if (!bodyLimit.allowed) { + return; + } + res.setHeader('Access-Control-Allow-Origin', corsOrigin); res.setHeader('Access-Control-Allow-Methods', 'GET, POST, PUT, DELETE, OPTIONS'); res.setHeader( diff --git a/listener/src/config-logging.test.ts b/listener/src/config-logging.test.ts new file mode 100644 index 00000000..de635911 --- /dev/null +++ b/listener/src/config-logging.test.ts @@ -0,0 +1,169 @@ +/** + * Configuration of log verbosity, log format and the request-size limit. + * + * These go through the same loadConfig/validateConfig mechanism as every other + * setting, so an operator changes them the same way they change anything else + * — and a typo is caught at startup rather than silently ignored. + */ + +import { loadConfig, validateConfig, ConfigError } from './config'; + +/** A well-formed 56-character contract address, so the shared required-env + * check passes and these tests fail only on the fields they are about. */ +const TEST_CONTRACT_ADDRESS = `C${'A'.repeat(55)}`; + +const BASE_ENV: Record = { + CONTRACT_ADDRESSES: `[{"address":"${TEST_CONTRACT_ADDRESS}","events":["notify"]}]`, +}; + +function withEnv(overrides: Record, fn: () => void): void { + const saved = { ...process.env }; + try { + for (const key of Object.keys(process.env)) { + if (key.startsWith('LOG_') || key.startsWith('API_MAX_')) delete process.env[key]; + } + Object.assign(process.env, BASE_ENV); + for (const [key, value] of Object.entries(overrides)) { + if (value === undefined) delete process.env[key]; + else process.env[key] = value; + } + fn(); + } finally { + process.env = saved; + } +} + +// ── Log level ─────────────────────────────────────────────────────────────── + +describe('LOG_LEVEL configuration', () => { + it.each(['error', 'warn', 'info', 'debug'])('accepts %s', (level) => { + withEnv({ LOG_LEVEL: level }, () => { + const config = loadConfig(); + expect(config.logging?.level).toBe(level); + expect(() => validateConfig(config)).not.toThrow(); + }); + }); + + it('defaults to info when unset', () => { + // Production default stays conservative: info, not debug. + withEnv({ LOG_LEVEL: undefined }, () => { + expect(loadConfig().logging?.level).toBe('info'); + }); + }); + + it('rejects an unrecognised level instead of silently downgrading', () => { + // A typo that quietly resolves to "info" hides the debug output the + // operator asked for, with no signal that the setting did not take. + withEnv({ LOG_LEVEL: 'verbose' }, () => { + const config = loadConfig(); + expect(() => validateConfig(config)).toThrow(ConfigError); + }); + }); + + it('names the supported levels in the rejection message', () => { + withEnv({ LOG_LEVEL: 'trace' }, () => { + try { + validateConfig(loadConfig()); + throw new Error('expected validateConfig to throw'); + } catch (error) { + const message = (error as Error).message; + expect(message).toContain('LOG_LEVEL'); + expect(message).toContain('debug'); + expect(message).toContain('trace'); + } + }); + }); +}); + +// ── Log format ────────────────────────────────────────────────────────────── + +describe('LOG_FORMAT configuration', () => { + it('accepts json', () => { + withEnv({ LOG_FORMAT: 'json' }, () => { + const config = loadConfig(); + expect(config.logging?.format).toBe('json'); + expect(() => validateConfig(config)).not.toThrow(); + }); + }); + + it('accepts pretty', () => { + withEnv({ LOG_FORMAT: 'pretty' }, () => { + expect(loadConfig().logging?.format).toBe('pretty'); + }); + }); + + it('enables JSON in a non-production environment when asked', () => { + // The point of making this configurable: reproducing an aggregator + // problem locally should not require pretending to be production. + withEnv({ LOG_FORMAT: 'json', NODE_ENV: 'development' }, () => { + expect(loadConfig().logging?.format).toBe('json'); + }); + }); + + it('preserves the previous environment-based default when unset', () => { + withEnv({ LOG_FORMAT: undefined, NODE_ENV: 'production' }, () => { + expect(loadConfig().logging?.format).toBe('json'); + }); + withEnv({ LOG_FORMAT: undefined, NODE_ENV: 'development' }, () => { + expect(loadConfig().logging?.format).toBe('pretty'); + }); + }); + + it('rejects an unrecognised format', () => { + withEnv({ LOG_FORMAT: 'logfmt' }, () => { + expect(() => validateConfig(loadConfig())).toThrow(ConfigError); + }); + }); +}); + +// ── Request size limit ────────────────────────────────────────────────────── + +describe('API_MAX_BODY_BYTES configuration', () => { + it('defaults to 1 MiB', () => { + withEnv({ API_MAX_BODY_BYTES: undefined }, () => { + expect(loadConfig().api?.maxBodyBytes).toBe(1_048_576); + }); + }); + + it('accepts an explicit limit', () => { + withEnv({ API_MAX_BODY_BYTES: '65536' }, () => { + const config = loadConfig(); + expect(config.api?.maxBodyBytes).toBe(65_536); + expect(() => validateConfig(config)).not.toThrow(); + }); + }); + + it('rejects a non-positive limit', () => { + // Zero would refuse every request with a body; negative is meaningless. + withEnv({ API_MAX_BODY_BYTES: '0' }, () => { + expect(() => validateConfig(loadConfig())).toThrow(ConfigError); + }); + withEnv({ API_MAX_BODY_BYTES: '-1' }, () => { + expect(() => validateConfig(loadConfig())).toThrow(ConfigError); + }); + }); + + it('rejects a non-numeric limit at load time', () => { + withEnv({ API_MAX_BODY_BYTES: 'huge' }, () => { + expect(() => loadConfig()).toThrow(ConfigError); + }); + }); +}); + +// ── Combined reporting ────────────────────────────────────────────────────── + +describe('validation reporting', () => { + it('reports every bad value at once rather than one per restart', () => { + withEnv({ LOG_LEVEL: 'nope', LOG_FORMAT: 'nope', API_MAX_BODY_BYTES: '0' }, () => { + try { + validateConfig(loadConfig()); + throw new Error('expected validateConfig to throw'); + } catch (error) { + const message = (error as Error).message; + expect(message).toContain('LOG_LEVEL'); + expect(message).toContain('LOG_FORMAT'); + expect(message).toContain('API_MAX_BODY_BYTES'); + } + }); + }); +}); diff --git a/listener/src/config.ts b/listener/src/config.ts index ac1dc1fa..500d4560 100644 --- a/listener/src/config.ts +++ b/listener/src/config.ts @@ -1,4 +1,11 @@ -import { Config, ContractConfig, DiscordConfig, WebhookSecret, AppCleanupConfig, EventQueueConfig, RetrySchedulerOptions, AnalyticsConfig, ExpirationConfig, ApiKey, BackfillConfig } from './types'; +import { Config, ContractConfig, DiscordConfig, WebhookSecret, AppCleanupConfig, EventQueueConfig, RetrySchedulerOptions, AnalyticsConfig, ExpirationConfig, ApiKey, BackfillConfig, LoggingConfig, ApiConfig } from './types'; +import { + SUPPORTED_LOG_FORMATS, + SUPPORTED_LOG_LEVELS, + parseLogFormat, + parseLogLevel, +} from './utils/logger'; +import { DEFAULT_MAX_BODY_BYTES } from './middleware/body-limit'; export class ConfigError extends Error { constructor(message: string) { @@ -289,6 +296,33 @@ export function loadConfig(): Config { analytics: loadAnalyticsConfig(), expiration: loadExpirationConfig(), backfill: loadBackfillConfig(), + logging: loadLoggingConfig(), + api: loadApiConfig(), + }; +} + +/** + * Observability settings. + * + * Raw strings are carried through and validated in `validateConfig`, matching + * how the rest of this loader works: collect everything, then report every + * problem at once rather than throwing on the first bad field. + */ +function loadLoggingConfig(): LoggingConfig { + return { + level: trimEnv('LOG_LEVEL') || 'info', + // Preserves the previous implicit behaviour when LOG_FORMAT is unset: + // JSON in production, human-readable elsewhere. + format: + trimEnv('LOG_FORMAT') || + (process.env.NODE_ENV === 'production' ? 'json' : 'pretty'), + }; +} + +/** HTTP surface settings. */ +function loadApiConfig(): ApiConfig { + return { + maxBodyBytes: parseIntegerEnv('API_MAX_BODY_BYTES', String(DEFAULT_MAX_BODY_BYTES)), }; } @@ -559,6 +593,36 @@ export function validateConfig(config: Config): void { } } + // ── Logging ──────────────────────────────────────────────────────────────── + // Rejected rather than silently downgraded: a typo in LOG_LEVEL that quietly + // resolves to "info" hides debug output an operator explicitly asked for, and + // they have no signal that the setting did not take. + if (config.logging) { + if (parseLogLevel(config.logging.level) === null) { + errors.push( + `LOG_LEVEL must be one of: ${SUPPORTED_LOG_LEVELS.join(', ')} ` + + `(received: "${config.logging.level}").`, + ); + } + + if (parseLogFormat(config.logging.format) === null) { + errors.push( + `LOG_FORMAT must be one of: ${SUPPORTED_LOG_FORMATS.join(', ')} ` + + `(received: "${config.logging.format}").`, + ); + } + } + + // ── API surface ──────────────────────────────────────────────────────────── + if (config.api) { + if (!Number.isInteger(config.api.maxBodyBytes) || config.api.maxBodyBytes <= 0) { + errors.push( + `API_MAX_BODY_BYTES must be a positive integer ` + + `(received: ${config.api.maxBodyBytes}).`, + ); + } + } + if (errors.length > 0) { throw new ConfigError( `Configuration validation failed with ${errors.length} error(s):\n` + diff --git a/listener/src/middleware/body-limit.test.ts b/listener/src/middleware/body-limit.test.ts new file mode 100644 index 00000000..9a4d2cd1 --- /dev/null +++ b/listener/src/middleware/body-limit.test.ts @@ -0,0 +1,295 @@ +/** + * Request body size limit tests. + * + * Boundary conditions matter most here: a limit that is off by one byte in + * either direction either rejects legitimate payloads or leaves the ceiling + * unenforced. + */ + +import { EventEmitter } from 'events'; +import { + DEFAULT_MAX_BODY_BYTES, + enforceBodyLimit, + parseContentLength, +} from './body-limit'; + +// ── Test doubles ──────────────────────────────────────────────────────────── + +interface FakeRequest extends EventEmitter { + method: string; + url: string; + headers: Record; + destroy: jest.Mock; +} + +function makeRequest( + method = 'POST', + headers: Record = {}, +): FakeRequest { + const req = new EventEmitter() as FakeRequest; + req.method = method; + req.url = '/api/notifications'; + req.headers = headers; + req.destroy = jest.fn(); + return req; +} + +interface FakeResponse { + headersSent: boolean; + statusCode?: number; + headers?: Record; + body?: string; + writeHead: jest.Mock; + end: jest.Mock; +} + +function makeResponse(headersSent = false): FakeResponse { + const res: FakeResponse = { + headersSent, + writeHead: jest.fn(function (this: void, status: number, headers: Record) { + res.statusCode = status; + res.headers = headers; + }), + end: jest.fn(function (this: void, body?: string) { + res.body = body; + }), + }; + return res; +} + +function enforce( + req: FakeRequest, + res: FakeResponse, + maxBytes: number, + onRejected?: jest.Mock, +) { + return enforceBodyLimit(req as never, res as never, { maxBytes, onRejected }); +} + +// ── parseContentLength ────────────────────────────────────────────────────── + +describe('parseContentLength', () => { + it('parses a well-formed header', () => { + expect(parseContentLength('1024')).toBe(1024); + expect(parseContentLength(' 512 ')).toBe(512); + }); + + it('accepts zero', () => { + expect(parseContentLength('0')).toBe(0); + }); + + it('takes the first value of a repeated header', () => { + expect(parseContentLength(['100', '200'])).toBe(100); + }); + + it('returns null for missing, malformed or negative values', () => { + // Null, not a guess: the streaming counter is the backstop for these. + expect(parseContentLength(undefined)).toBeNull(); + expect(parseContentLength('')).toBeNull(); + expect(parseContentLength('abc')).toBeNull(); + expect(parseContentLength('-1')).toBeNull(); + }); +}); + +// ── Content-Length screening ──────────────────────────────────────────────── + +describe('body limit — Content-Length screening', () => { + it('rejects a declared size above the limit before reading a byte', () => { + const req = makeRequest('POST', { 'content-length': '2048' }); + const res = makeResponse(); + + const result = enforce(req, res, 1024); + + expect(result.allowed).toBe(false); + expect(result.reason).toBe('content-length-exceeded'); + expect(res.statusCode).toBe(413); + expect(req.destroy).toHaveBeenCalled(); + }); + + it('accepts a declared size exactly at the limit', () => { + // The bound is inclusive — exactly max is a legitimate payload. + const req = makeRequest('POST', { 'content-length': '1024' }); + const res = makeResponse(); + + expect(enforce(req, res, 1024).allowed).toBe(true); + expect(res.writeHead).not.toHaveBeenCalled(); + }); + + it('rejects one byte over the limit', () => { + const req = makeRequest('POST', { 'content-length': '1025' }); + const res = makeResponse(); + + expect(enforce(req, res, 1024).allowed).toBe(false); + }); + + it('accepts one byte under the limit', () => { + const req = makeRequest('POST', { 'content-length': '1023' }); + const res = makeResponse(); + + expect(enforce(req, res, 1024).allowed).toBe(true); + }); + + it('responds with a machine-readable 413 payload', () => { + const req = makeRequest('POST', { 'content-length': '5000' }); + const res = makeResponse(); + + enforce(req, res, 1024); + + expect(res.headers?.['Content-Type']).toBe('application/json'); + const parsed = JSON.parse(res.body ?? '{}'); + expect(parsed.code).toBe('PAYLOAD_TOO_LARGE'); + expect(parsed.maxBytes).toBe(1024); + expect(parsed.observedBytes).toBe(5000); + }); + + it('notifies the caller with the reason and observed size', () => { + const onRejected = jest.fn(); + const req = makeRequest('POST', { 'content-length': '5000' }); + + enforce(req, makeResponse(), 1024, onRejected); + + expect(onRejected).toHaveBeenCalledWith('content-length-exceeded', 5000); + }); +}); + +// ── Streaming enforcement ─────────────────────────────────────────────────── + +describe('body limit — streaming enforcement', () => { + it('rejects a body that overruns without declaring a Content-Length', () => { + // Chunked transfers carry no Content-Length, so the counter is the only + // thing bounding memory here. + const req = makeRequest('POST', {}); + const res = makeResponse(); + const onRejected = jest.fn(); + + expect(enforce(req, res, 10, onRejected).allowed).toBe(true); + + req.emit('data', Buffer.alloc(6)); + expect(res.writeHead).not.toHaveBeenCalled(); + + req.emit('data', Buffer.alloc(6)); // 12 total, over the limit + expect(res.statusCode).toBe(413); + expect(req.destroy).toHaveBeenCalled(); + expect(onRejected).toHaveBeenCalledWith('stream-exceeded', 12); + }); + + it('rejects a body that understates its Content-Length', () => { + // A client claiming 5 bytes and sending 100 must still be stopped. + const req = makeRequest('POST', { 'content-length': '5' }); + const res = makeResponse(); + + expect(enforce(req, res, 10).allowed).toBe(true); + + req.emit('data', Buffer.alloc(100)); + + expect(res.statusCode).toBe(413); + expect(req.destroy).toHaveBeenCalled(); + }); + + it('allows a stream that stays exactly at the limit', () => { + const req = makeRequest('POST', {}); + const res = makeResponse(); + + enforce(req, res, 10); + req.emit('data', Buffer.alloc(10)); + req.emit('end'); + + expect(res.writeHead).not.toHaveBeenCalled(); + expect(req.destroy).not.toHaveBeenCalled(); + }); + + it('rejects at exactly one byte past the limit', () => { + const req = makeRequest('POST', {}); + const res = makeResponse(); + + enforce(req, res, 10); + req.emit('data', Buffer.alloc(11)); + + expect(res.statusCode).toBe(413); + }); + + it('counts string chunks by byte length, not character count', () => { + // A 4-character emoji is 4 bytes in UTF-8 per character here; counting + // characters would let roughly 4x the intended payload through. + const req = makeRequest('POST', {}); + const res = makeResponse(); + + enforce(req, res, 8); + req.emit('data', '🚀🚀🚀'); // 12 bytes, 3 code points + + expect(res.statusCode).toBe(413); + }); + + it('responds only once no matter how many chunks arrive after the overrun', () => { + const req = makeRequest('POST', {}); + const res = makeResponse(); + const onRejected = jest.fn(); + + enforce(req, res, 5, onRejected); + req.emit('data', Buffer.alloc(10)); + req.emit('data', Buffer.alloc(10)); + req.emit('data', Buffer.alloc(10)); + + expect(onRejected).toHaveBeenCalledTimes(1); + expect(res.end).toHaveBeenCalledTimes(1); + }); + + it('does not write a second response when headers were already sent', () => { + // A handler may have started responding before the stream overran; + // writing again would replace a useful error with an unhandled throw. + const req = makeRequest('POST', {}); + const res = makeResponse(true); + + enforce(req, res, 5); + req.emit('data', Buffer.alloc(10)); + + expect(res.writeHead).not.toHaveBeenCalled(); + expect(req.destroy).toHaveBeenCalled(); + }); +}); + +// ── Methods without bodies ────────────────────────────────────────────────── + +describe('body limit — methods without bodies', () => { + it.each(['GET', 'DELETE', 'HEAD', 'OPTIONS'])( + 'passes %s through without screening', + (method) => { + const req = makeRequest(method, { 'content-length': '999999' }); + const res = makeResponse(); + + expect(enforce(req, res, 10).allowed).toBe(true); + expect(res.writeHead).not.toHaveBeenCalled(); + }, + ); + + it.each(['POST', 'PUT', 'PATCH'])('screens %s', (method) => { + const req = makeRequest(method, { 'content-length': '999999' }); + const res = makeResponse(); + + expect(enforce(req, res, 10).allowed).toBe(false); + }); + + it('treats a lowercase method name as its uppercase equivalent', () => { + const req = makeRequest('post', { 'content-length': '999999' }); + const res = makeResponse(); + + expect(enforce(req, res, 10).allowed).toBe(false); + }); +}); + +// ── Defaults ──────────────────────────────────────────────────────────────── + +describe('body limit — defaults', () => { + it('defaults to 1 MiB', () => { + expect(DEFAULT_MAX_BODY_BYTES).toBe(1_048_576); + }); + + it('uses the default when no limit is supplied', () => { + const req = makeRequest('POST', { 'content-length': String(DEFAULT_MAX_BODY_BYTES + 1) }); + const res = makeResponse(); + + const result = enforceBodyLimit(req as never, res as never); + + expect(result.allowed).toBe(false); + }); +}); diff --git a/listener/src/middleware/body-limit.ts b/listener/src/middleware/body-limit.ts new file mode 100644 index 00000000..331c6a34 --- /dev/null +++ b/listener/src/middleware/body-limit.ts @@ -0,0 +1,137 @@ +/** + * Request body size limit. + * + * Every POST/PUT handler in the events API accumulates the request body into a + * string (`body += chunk`) with no ceiling, so a single large upload grows the + * process heap unbounded. This guard caps that. + * + * It runs once at dispatch rather than in each handler, which matters for the + * "does not attempt to process rejected payloads" requirement: by the time a + * route handler attaches its own `data` listener the request has already been + * screened, and an oversized one has been answered and destroyed. + * + * Two checks, because either alone is insufficient: + * + * * `Content-Length`, when present, is rejected before a single byte of body + * is read — the cheapest possible refusal. + * * A streaming byte counter, because `Content-Length` is client-supplied + * and absent entirely on chunked transfers. A client can understate it or + * omit it; the counter is what actually bounds memory. + */ + +import type http from 'http'; + +/** Default ceiling: 1 MiB. Generous for JSON payloads, small enough to bound heap growth. */ +export const DEFAULT_MAX_BODY_BYTES = 1_048_576; + +export type BodyLimitRejection = 'content-length-exceeded' | 'stream-exceeded'; + +export interface BodyLimitOptions { + maxBytes?: number; + /** Notified when a request is refused, so the caller can log it with its own context. */ + onRejected?: (reason: BodyLimitRejection, observedBytes: number) => void; +} + +/** HTTP methods that carry a body worth screening. */ +const BODY_METHODS = new Set(['POST', 'PUT', 'PATCH']); + +/** + * Parses `Content-Length` into a byte count. + * + * Returns null for a missing, malformed, or negative value rather than + * guessing — the streaming counter is the backstop for those. + */ +export function parseContentLength(raw: string | string[] | undefined): number | null { + if (raw === undefined) return null; + const value = Array.isArray(raw) ? raw[0] : raw; + if (value === undefined) return null; + + const parsed = Number.parseInt(value.trim(), 10); + if (!Number.isInteger(parsed) || parsed < 0) return null; + return parsed; +} + +export interface BodyLimitResult { + /** False when the request was refused; the caller must stop processing it. */ + allowed: boolean; + reason?: BodyLimitRejection; + observedBytes?: number; +} + +/** + * Screens one request against the configured ceiling. + * + * On rejection this writes a 413 and destroys the socket, then returns + * `allowed: false`. Destroying matters: without it the client keeps sending a + * body nobody will read, and the bytes still transit the process. + * + * Returns `allowed: true` for methods that carry no body, so GET/DELETE pay + * only a set lookup. + */ +export function enforceBodyLimit( + req: http.IncomingMessage, + res: http.ServerResponse, + options: BodyLimitOptions = {}, +): BodyLimitResult { + const maxBytes = options.maxBytes ?? DEFAULT_MAX_BODY_BYTES; + const method = (req.method ?? 'GET').toUpperCase(); + + if (!BODY_METHODS.has(method)) { + return { allowed: true }; + } + + const declared = parseContentLength(req.headers['content-length']); + + // Cheapest refusal: the client told us it is too big, so nothing is read. + if (declared !== null && declared > maxBytes) { + options.onRejected?.('content-length-exceeded', declared); + respondTooLarge(res, maxBytes, declared); + req.destroy(); + return { allowed: false, reason: 'content-length-exceeded', observedBytes: declared }; + } + + // Backstop: Content-Length is client-supplied and absent on chunked + // transfers, so count what actually arrives. + let received = 0; + let rejected = false; + + const onData = (chunk: Buffer | string): void => { + if (rejected) return; + received += typeof chunk === 'string' ? Buffer.byteLength(chunk) : chunk.length; + if (received <= maxBytes) return; + + rejected = true; + req.removeListener('data', onData); + options.onRejected?.('stream-exceeded', received); + respondTooLarge(res, maxBytes, received); + req.destroy(); + }; + + req.on('data', onData); + req.once('end', () => req.removeListener('data', onData)); + + return { allowed: true }; +} + +/** + * Writes the 413 response. + * + * No-ops when headers are already sent — a handler may have started + * responding before the stream overran, and throwing here would replace a + * useful error with an unhandled one. + */ +function respondTooLarge(res: http.ServerResponse, maxBytes: number, observedBytes: number): void { + if (res.headersSent) return; + + const payload = JSON.stringify({ + error: 'Payload Too Large', + code: 'PAYLOAD_TOO_LARGE', + maxBytes, + // The observed size is the client's own number or our count of their + // bytes — echoing it back leaks nothing they did not send. + observedBytes, + }); + + res.writeHead(413, { 'Content-Type': 'application/json' }); + res.end(payload); +} diff --git a/listener/src/middleware/response-time.ts b/listener/src/middleware/response-time.ts index 20c5d520..c7afc5f3 100644 --- a/listener/src/middleware/response-time.ts +++ b/listener/src/middleware/response-time.ts @@ -15,7 +15,7 @@ */ import http from 'http'; -import logger from '../utils/logger'; +import logger, { sanitizeUrl } from '../utils/logger'; export interface ResponseTimeOptions { /** @@ -81,7 +81,11 @@ export class ResponseTimeMiddleware { } const method = req.method ?? 'UNKNOWN'; - const url = req.url ?? '/'; + // Sanitized, not raw: the path is what makes this line useful for finding + // a slow endpoint, but query strings routinely carry `?token=` or + // `?api_key=`, and those would otherwise be written verbatim into the log + // aggregator on every single request. + const url = sanitizeUrl(req.url ?? '/'); const status = statusCode ?? res.statusCode; const isSlow = durationMs >= this.threshold; diff --git a/listener/src/types/index.ts b/listener/src/types/index.ts index 87fb5981..74a8c400 100644 --- a/listener/src/types/index.ts +++ b/listener/src/types/index.ts @@ -63,6 +63,29 @@ export interface Config { analytics?: AnalyticsConfig; expiration?: ExpirationConfig; backfill?: BackfillConfig; + logging?: LoggingConfig; + api?: ApiConfig; +} + +/** Observability settings, sourced from LOG_LEVEL / LOG_FORMAT. */ +export interface LoggingConfig { + /** `error | warn | info | debug`. Defaults to `info`. */ + level: string; + /** + * `json` for aggregator-friendly newline-delimited JSON, `pretty` for the + * colourised human format. Defaults to `json` in production and `pretty` + * elsewhere. + */ + format: string; +} + +/** HTTP surface settings for the events API. */ +export interface ApiConfig { + /** + * Largest request body accepted, in bytes. Oversized requests are answered + * with 413 and their payload is never parsed. + */ + maxBodyBytes: number; } export interface SchedulerConfig { diff --git a/listener/src/utils/logger-structured.test.ts b/listener/src/utils/logger-structured.test.ts new file mode 100644 index 00000000..35f46fb0 --- /dev/null +++ b/listener/src/utils/logger-structured.test.ts @@ -0,0 +1,200 @@ +/** + * Structured-logging tests: format selection, level parsing, and the + * redaction that keeps credentials out of the aggregator. + * + * The existing logger.test.ts covers formatError and the level fallback; this + * file covers the parts added for configurable JSON output and secret + * exclusion. + */ + +import { + REDACTED_PLACEHOLDER, + SUPPORTED_LOG_FORMATS, + SUPPORTED_LOG_LEVELS, + isSensitiveKey, + parseLogFormat, + parseLogLevel, + redactSensitive, + resolveLogFormat, + resolveLogLevel, + sanitizeUrl, +} from './logger'; + +// ── Level parsing ─────────────────────────────────────────────────────────── + +describe('log level parsing', () => { + it('documents the supported levels', () => { + expect([...SUPPORTED_LOG_LEVELS]).toEqual(['error', 'warn', 'info', 'debug']); + }); + + it.each(['error', 'warn', 'info', 'debug'])('accepts %s', (level) => { + expect(parseLogLevel(level)).toBe(level); + }); + + it('normalises case and surrounding whitespace', () => { + expect(parseLogLevel(' DEBUG ')).toBe('debug'); + }); + + it('returns null for an unrecognised level', () => { + // Strict, unlike resolveLogLevel: config validation needs to be able to + // reject rather than silently downgrade. + expect(parseLogLevel('verbose')).toBeNull(); + expect(parseLogLevel('trace')).toBeNull(); + expect(parseLogLevel('')).toBeNull(); + expect(parseLogLevel(undefined)).toBeNull(); + }); + + it('resolveLogLevel still falls back rather than throwing', () => { + // A bad value must never crash a running process, only fail validation. + expect(resolveLogLevel('nonsense')).toBe('info'); + expect(resolveLogLevel(undefined)).toBe('info'); + }); +}); + +// ── Format selection ──────────────────────────────────────────────────────── + +describe('log format selection', () => { + it('documents the supported formats', () => { + expect([...SUPPORTED_LOG_FORMATS]).toEqual(['json', 'pretty']); + }); + + it('accepts json and pretty', () => { + expect(parseLogFormat('json')).toBe('json'); + expect(parseLogFormat('PRETTY')).toBe('pretty'); + }); + + it('returns null for an unrecognised format', () => { + expect(parseLogFormat('logfmt')).toBeNull(); + expect(parseLogFormat(undefined)).toBeNull(); + }); + + it('lets an explicit format win over the environment', () => { + // JSON can be enabled anywhere — reproducing an aggregator problem + // locally should not require pretending to be production. + expect(resolveLogFormat('json', 'development')).toBe('json'); + expect(resolveLogFormat('pretty', 'production')).toBe('pretty'); + }); + + it('falls back to the previous environment-based behaviour when unset', () => { + expect(resolveLogFormat(undefined, 'production')).toBe('json'); + expect(resolveLogFormat(undefined, 'development')).toBe('pretty'); + expect(resolveLogFormat(undefined, undefined)).toBe('pretty'); + }); +}); + +// ── Sensitive key detection ───────────────────────────────────────────────── + +describe('sensitive key detection', () => { + it.each([ + 'password', + 'apiKey', + 'API_KEY', + 'x-api-key', + 'webhookSecret', + 'Authorization', + 'accessToken', + 'privateKey', + 'signature', + 'cookie', + ])('flags %s', (key) => { + expect(isSensitiveKey(key)).toBe(true); + }); + + it.each(['requestId', 'durationMs', 'statusCode', 'method', 'url', 'count'])( + 'leaves %s alone', + (key) => { + expect(isSensitiveKey(key)).toBe(false); + }, + ); +}); + +// ── Redaction ─────────────────────────────────────────────────────────────── + +describe('redaction', () => { + it('replaces a credential value while keeping the field', () => { + // The key stays so the shape of the record is stable for the aggregator; + // only the value is withheld. + const output = redactSensitive({ requestId: 'abc', apiKey: 'sk_live_123' }) as Record< + string, + unknown + >; + + expect(output.requestId).toBe('abc'); + expect(output.apiKey).toBe(REDACTED_PLACEHOLDER); + }); + + it('redacts nested credentials', () => { + const output = redactSensitive({ + request: { headers: { authorization: 'Bearer xyz' }, path: '/api' }, + }) as any; + + expect(output.request.headers.authorization).toBe(REDACTED_PLACEHOLDER); + expect(output.request.path).toBe('/api'); + }); + + it('redacts inside arrays', () => { + const output = redactSensitive([{ token: 'a' }, { token: 'b' }]) as any[]; + + expect(output[0].token).toBe(REDACTED_PLACEHOLDER); + expect(output[1].token).toBe(REDACTED_PLACEHOLDER); + }); + + it('leaves primitives untouched', () => { + expect(redactSensitive('plain')).toBe('plain'); + expect(redactSensitive(42)).toBe(42); + expect(redactSensitive(null)).toBeNull(); + }); + + it('passes Errors through for formatError to handle', () => { + const error = new Error('boom'); + expect(redactSensitive(error)).toBe(error); + }); + + it('stops recursing on deeply nested input', () => { + // Logging must never be the thing that hangs the service, so depth is + // bounded rather than trusting the input to be well-shaped. + let deep: Record = { secret: 'leaf' }; + for (let i = 0; i < 50; i++) deep = { nested: deep }; + + expect(() => redactSensitive(deep)).not.toThrow(); + }); + + it('redacts the top level of an over-deep object', () => { + const output = redactSensitive({ password: 'p', nested: { token: 't' } }) as any; + expect(output.password).toBe(REDACTED_PLACEHOLDER); + expect(output.nested.token).toBe(REDACTED_PLACEHOLDER); + }); +}); + +// ── URL sanitization ──────────────────────────────────────────────────────── + +describe('URL sanitization', () => { + it('leaves a path without a query string alone', () => { + expect(sanitizeUrl('/api/notifications')).toBe('/api/notifications'); + }); + + it('keeps the path, which is what identifies the endpoint', () => { + expect(sanitizeUrl('/api/events?token=secret')).toContain('/api/events'); + }); + + it('redacts credential-bearing query parameters', () => { + const output = sanitizeUrl('/api/events?token=sk_live_abc&limit=10'); + + expect(output).not.toContain('sk_live_abc'); + expect(output).toContain(REDACTED_PLACEHOLDER); + // Non-sensitive parameters survive — they are useful for diagnosis. + expect(output).toContain('limit=10'); + }); + + it('redacts several sensitive parameters at once', () => { + const output = sanitizeUrl('/api?api_key=a&signature=b&page=2'); + + expect(output).not.toContain('=a'); + expect(output).not.toContain('=b'); + expect(output).toContain('page=2'); + }); + + it('handles an empty query string', () => { + expect(sanitizeUrl('/api/events?')).toBe('/api/events'); + }); +}); diff --git a/listener/src/utils/logger.ts b/listener/src/utils/logger.ts index 53f7f2c9..0b9248cf 100644 --- a/listener/src/utils/logger.ts +++ b/listener/src/utils/logger.ts @@ -41,6 +41,154 @@ export function resolveLogLevel(raw: string | undefined): LogLevel { return 'info'; } +/** The log levels this service accepts, in decreasing severity. */ +export const SUPPORTED_LOG_LEVELS: readonly LogLevel[] = VALID_LOG_LEVELS; + +/** + * Strict counterpart to {@link resolveLogLevel}: returns null instead of + * silently downgrading an unrecognised value. + * + * `resolveLogLevel` deliberately never throws, so a bad value cannot crash a + * running process. But a *misconfigured deployment* should be caught at + * startup rather than quietly running at the wrong verbosity, so config + * validation uses this and rejects. + */ +export function parseLogLevel(raw: string | undefined): LogLevel | null { + const normalised = raw?.trim().toLowerCase(); + if (!normalised) return null; + return (VALID_LOG_LEVELS as readonly string[]).includes(normalised) + ? (normalised as LogLevel) + : null; +} + +// --------------------------------------------------------------------------- +// Output format +// --------------------------------------------------------------------------- + +const VALID_LOG_FORMATS = ['json', 'pretty'] as const; +export type LogFormat = (typeof VALID_LOG_FORMATS)[number]; + +/** The log output formats this service accepts. */ +export const SUPPORTED_LOG_FORMATS: readonly LogFormat[] = VALID_LOG_FORMATS; + +/** Strict parse of a raw LOG_FORMAT value; null when unrecognised. */ +export function parseLogFormat(raw: string | undefined): LogFormat | null { + const normalised = raw?.trim().toLowerCase(); + if (!normalised) return null; + return (VALID_LOG_FORMATS as readonly string[]).includes(normalised) + ? (normalised as LogFormat) + : null; +} + +/** + * Resolves the active output format. + * + * An explicit `LOG_FORMAT` always wins, so JSON can be switched on in any + * environment — reproducing an aggregator problem locally no longer requires + * pretending to be production. With nothing set the previous behaviour is + * preserved: JSON in production, human-readable elsewhere. + */ +export function resolveLogFormat( + rawFormat: string | undefined, + nodeEnv: string | undefined = process.env.NODE_ENV +): LogFormat { + return parseLogFormat(rawFormat) ?? (nodeEnv === 'production' ? 'json' : 'pretty'); +} + +// --------------------------------------------------------------------------- +// Secret redaction +// --------------------------------------------------------------------------- + +/** + * Field-name fragments whose values are replaced before a record is emitted. + * + * Matching is substring-based and case-insensitive after stripping `-`, `_` + * and spaces, so `apiKey`, `X-API-Key`, `api_key`, `webhookSecret` and + * `Authorization` are all caught without enumerating every spelling. + */ +const REDACTED_KEY_PATTERNS = [ + 'password', + 'secret', + 'token', + 'apikey', + 'authorization', + 'credential', + 'signature', + 'cookie', + 'privatekey', +] as const; + +export const REDACTED_PLACEHOLDER = '[REDACTED]'; + +/** True when a field name looks like it carries a credential. */ +export function isSensitiveKey(key: string): boolean { + const normalised = key.toLowerCase().replace(/[-_\s]/g, ''); + return REDACTED_KEY_PATTERNS.some((pattern) => normalised.includes(pattern)); +} + +/** + * Recursively replaces credential-looking values with a placeholder. + * + * Redaction runs on the way *into* the logger rather than being left to each + * caller: a secret only has to be forgotten once to sit permanently in an + * aggregator, and the caller is the party most likely to forget. + * + * Depth is bounded so a deeply nested or cyclic object cannot hang the logging + * path — logging must never be the thing that takes the service down. + */ +export function redactSensitive(value: unknown, depth = 0): unknown { + if (depth > 8) return value; + + if (Array.isArray(value)) { + return value.map((item) => redactSensitive(item, depth + 1)); + } + + if (value !== null && typeof value === 'object') { + // Errors are handled by formatError and carry no fields worth redacting. + if (value instanceof Error) return value; + + const output: Record = {}; + for (const [key, item] of Object.entries(value as Record)) { + output[key] = isSensitiveKey(key) + ? REDACTED_PLACEHOLDER + : redactSensitive(item, depth + 1); + } + return output; + } + + return value; +} + +/** + * Strips credentials out of a URL before it is logged. + * + * Request paths reach the logs verbatim and query strings routinely carry + * `?token=` or `?api_key=`. The path is what makes a log line useful for + * finding a slow endpoint; the parameter values are not. + */ +export function sanitizeUrl(rawUrl: string): string { + const queryStart = rawUrl.indexOf('?'); + if (queryStart === -1) return rawUrl; + + const path = rawUrl.slice(0, queryStart); + const params = new URLSearchParams(rawUrl.slice(queryStart + 1)); + + // Assembled by hand rather than via URLSearchParams.toString(), which would + // percent-encode the placeholder into `%5BREDACTED%5D` — still redacted, but + // no longer greppable in a log aggregator, which is the whole point of using + // a fixed marker. + const parts: string[] = []; + for (const [key, value] of params) { + parts.push( + isSensitiveKey(key) + ? `${encodeURIComponent(key)}=${REDACTED_PLACEHOLDER}` + : `${encodeURIComponent(key)}=${encodeURIComponent(value)}` + ); + } + + return parts.length > 0 ? `${path}?${parts.join('&')}` : path; +} + // --------------------------------------------------------------------------- // Error formatting // --------------------------------------------------------------------------- @@ -84,12 +232,18 @@ export function formatError(error: unknown): FormattedError | string { // --------------------------------------------------------------------------- function formatMeta(meta: LogContext): LogContext { + // Redact first, then format the error. Order matters: formatError produces a + // plain object that redaction would otherwise walk pointlessly, and an + // error's own fields are not where credentials hide — the sibling context + // fields are. + const redacted = redactSensitive(meta) as LogContext; + if (!('error' in meta) || meta.error === undefined) { - return meta; + return redacted; } return { - ...meta, + ...redacted, error: formatError(meta.error), }; } @@ -139,20 +293,33 @@ const baseLogger = winston.createLogger({ ), transports: [ new winston.transports.Console({ - format: - process.env.NODE_ENV === 'production' - ? winston.format.json() - : winston.format.combine( - winston.format.colorize(), - winston.format.printf(({ timestamp, level, message, ...meta }) => { - const metaStr = Object.keys(meta).length ? ` ${JSON.stringify(meta)}` : ''; - return `${timestamp} ${level}: ${message}${metaStr}`; - }) - ), + format: buildConsoleFormat(resolveLogFormat(process.env.LOG_FORMAT)), }), ], }); +/** + * Builds the console formatter for a given output format. + * + * `json` emits newline-delimited JSON with a stable field set — `timestamp`, + * `level`, `message`, plus whatever structured context the call site attached + * — which is what a log aggregator needs to index consistently. `pretty` is + * the colourised single-line form for a human reading a terminal. + */ +function buildConsoleFormat(format: LogFormat): winston.Logform.Format { + if (format === 'json') { + return winston.format.json(); + } + + return winston.format.combine( + winston.format.colorize(), + winston.format.printf(({ timestamp, level, message, ...meta }) => { + const metaStr = Object.keys(meta).length ? ` ${JSON.stringify(meta)}` : ''; + return `${timestamp} ${level}: ${message}${metaStr}`; + }) + ); +} + // --------------------------------------------------------------------------- // Public logger API // --------------------------------------------------------------------------- @@ -209,6 +376,15 @@ export function createRequestContext(requestId: string): LogContext { * configureLogger({ level: 'debug' }); * ``` */ -export function configureLogger(options: { level: string }): void { - baseLogger.level = resolveLogLevel(options.level); +export function configureLogger(options: { level?: string; format?: string }): void { + if (options.level !== undefined) { + baseLogger.level = resolveLogLevel(options.level); + } + + if (options.format !== undefined) { + const format = resolveLogFormat(options.format); + for (const transport of baseLogger.transports) { + transport.format = buildConsoleFormat(format); + } + } }