From 7bbaf9d55ce685e911b276522bd08471b4895b57 Mon Sep 17 00:00:00 2001 From: Copilot <223556219+Copilot@users.noreply.github.com> Date: Mon, 26 Oct 2026 20:08:17 +0000 Subject: [PATCH 1/6] feat(hub): add automatic redacted request logging Co-authored-by: Nishiki <1121087+nshki@users.noreply.github.com> Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- hub/.env.example | 3 + hub/.prettierignore | 2 +- hub/docs/README.md | 1 + hub/docs/architecture.md | 4 +- hub/docs/logging.md | 49 ++++ hub/package-lock.json | 142 +++++++++ hub/package.json | 2 + hub/server/create-app/index.test.ts | 103 ++++++- hub/server/create-app/index.ts | 31 +- hub/server/index.ts | 3 +- .../pino/create-logger/index.test.ts | 116 ++++++++ .../integrations/pino/create-logger/index.ts | 32 +++ .../integrations/pino/create-logger/types.ts | 6 + .../pino/create-request-logger/index.test.ts | 270 ++++++++++++++++++ .../pino/create-request-logger/index.ts | 97 +++++++ .../pino/create-request-logger/types.ts | 8 + hub/server/integrations/pino/index.ts | 12 + .../integrations/pino/log/index.test.ts | 25 ++ hub/server/integrations/pino/log/index.ts | 12 + .../logging/sanitize-log-value/index.test.ts | 111 +++++++ .../utils/logging/sanitize-log-value/index.ts | 64 +++++ .../utils/logging/sanitize-log-value/types.ts | 1 + 22 files changed, 1089 insertions(+), 5 deletions(-) create mode 100644 hub/docs/logging.md create mode 100644 hub/server/integrations/pino/create-logger/index.test.ts create mode 100644 hub/server/integrations/pino/create-logger/index.ts create mode 100644 hub/server/integrations/pino/create-logger/types.ts create mode 100644 hub/server/integrations/pino/create-request-logger/index.test.ts create mode 100644 hub/server/integrations/pino/create-request-logger/index.ts create mode 100644 hub/server/integrations/pino/create-request-logger/types.ts create mode 100644 hub/server/integrations/pino/index.ts create mode 100644 hub/server/integrations/pino/log/index.test.ts create mode 100644 hub/server/integrations/pino/log/index.ts create mode 100644 hub/server/utils/logging/sanitize-log-value/index.test.ts create mode 100644 hub/server/utils/logging/sanitize-log-value/index.ts create mode 100644 hub/server/utils/logging/sanitize-log-value/types.ts diff --git a/hub/.env.example b/hub/.env.example index 35e842d8..ed8cba81 100644 --- a/hub/.env.example +++ b/hub/.env.example @@ -1,6 +1,9 @@ # Optional API port. The Vite development proxy expects the default. PORT=3001 +# API logging threshold: trace, debug, info, warn, error, fatal, or silent. +LOG_LEVEL=info + # Local development only. The devcontainer supplies its own database hostname. DATABASE_URL=postgresql://replica:replica@127.0.0.1:5432/replica diff --git a/hub/.prettierignore b/hub/.prettierignore index 53393922..5c018a01 100644 --- a/hub/.prettierignore +++ b/hub/.prettierignore @@ -1,4 +1,4 @@ -log +/log .local .npm .storybook/instances diff --git a/hub/docs/README.md b/hub/docs/README.md index a844c507..ec3bd8fe 100644 --- a/hub/docs/README.md +++ b/hub/docs/README.md @@ -7,6 +7,7 @@ Hub is being rebuilt. The [Hub overview](../README.md) describes what the baseli - [Coding conventions](coding-conventions.md): frontend layers and interface rules. - [Development](development.md): local API and frontend setup. - [Database](database.md): Prisma schema conventions, migrations, and the shared client. +- [Logging](logging.md): application events, automatic request records, and payload safety. - [Testing and operations](testing-and-operations.md): baseline checks and their limits. - [Storybook](storybook.md): retained presentation, fixtures, and screenshot evidence. - [Prototype canvas](prototype-canvas.md): the separately retained extension. diff --git a/hub/docs/architecture.md b/hub/docs/architecture.md index de76ecfe..eb7d24c5 100644 --- a/hub/docs/architecture.md +++ b/hub/docs/architecture.md @@ -14,10 +14,12 @@ Contributors can use PostgreSQL and Prisma locally or in the devcontainer. The d API code lives under `server/`. As features are added, route handlers will read requests, call domains, and return responses. The [code conventions](backend-architecture.md) explain repositories, integrations, utilities, domains, and which layers may import others. Put these directories under `server/` when they are needed; do not add empty implementations. -The only route is `GET /api/health`, which returns `{ "status": "ok" }`. Every other path returns a JSON 404 response. `createApp()` builds the Express app without starting a server. `server/index.ts` starts it at a local address. +The only route is `GET /api/health`, which returns `{ "status": "ok" }`. Unknown paths return a JSON 404 response; invalid JSON is rejected before routing. `createApp()` builds the Express app without starting a server. `server/index.ts` starts it at a local address. The [database guide](database.md) defines the multi-file Prisma schema and shared client in integrations. The health route remains a process check, not a database readiness check. +The [Pino integration](logging.md) writes structured application and HTTP logs to stdout. `createApp()` installs request logging and JSON parsing before routes, so new endpoints inherit completion records and server-generated request IDs without explicit logging calls. + ## Frontend ```mermaid diff --git a/hub/docs/logging.md b/hub/docs/logging.md new file mode 100644 index 00000000..09d3554d --- /dev/null +++ b/hub/docs/logging.md @@ -0,0 +1,49 @@ +# API logging + +Hub writes newline-delimited JSON to stdout through the shared logger in `server/integrations/pino/index.ts`. `LOG_LEVEL` sets the minimum severity and defaults to `info`. Allowed values are `trace`, `debug`, `info`, `warn`, `error`, `fatal`, and `silent`; an invalid value prevents startup. + +Log collection, access, retention, and deployment configuration are outside this integration. Logs can contain private information even after key redaction. Treat access to logs accordingly. + +## Application events + +Import the explicit logging function from its directory: + +```ts +import { log } from "../integrations/pino/log/index.ts" + +log("info", "Build imported", { buildId }) +``` + +Pass structured fields rather than interpolating user input into messages. Keep messages static and never put credentials, raw requests, or private content into a message or stack trace. Sensitive values in free text cannot be reliably detected. + +Handlers can use `request.log.info({ buildId }, "Build imported")` to include the request ID automatically. The helper also accepts a request logger as its fourth argument: `log("info", "Build imported", { buildId }, request.log)`. + +Utilities cannot import integrations. Repositories and other integrations must receive a logger explicitly if they need one; domains and HTTP setup may import the Pino integration. Do not bind request payloads with `logger.child()` or `setBindings()`: arbitrary Pino bindings do not pass through the structured-field sanitizer. + +## Automatic HTTP records + +`createApp()` registers `createRequestLogger()` once, before JSON parsing and routes. Every request gets a server-generated UUID returned in `X-Request-Id`; incoming request ID headers are not trusted. Body parsing accepts JSON with Express's default 100 KiB limit. + +The middleware emits one terminal record with `reqId`, `method`, `route`, `statusCode`, `responseTime` in milliseconds, and `outcome`. Completed responses below 400 use `info`, 4xx use `warn`, and 5xx or connection errors use `error`. An unfinished connection uses `outcome: "aborted"` and `statusCode: null`, even if headers were already sent. + +`route` is the handler's Express route template, such as `/builds/:id`, or `null` for an unmatched request. For mounted routers it is relative to the mount: Express exposes concrete mount values, not a safe complete template. The middleware captures route parameters when headers are written, before Express can restore outer-router parameters. It also captures the sanitized query and parsed JSON body at that point. Later mutations during a streaming response do not change the snapshot. + +Automatic records omit raw URLs, headers, cookies, raw or malformed bodies, uploads, response bodies, and error messages or stacks. Parser errors receive a generic JSON error response. Errors after headers are sent close the connection rather than sending raw errors to Express's default reporter. + +An endpoint handling sensitive content can exclude all payload fields before sending its response: + +```ts +response.locals.omitLogPayload = true +``` + +This omits `params`, `query`, and `body`, but retains the method, route template, request ID, timing, and outcome. + +## Structured-field safety + +The shared logger sanitizes structured event fields, including fields passed to `request.log`. Request snapshots use the same sanitizer without mutating the request. + +Sensitive keys are replaced with `[REDACTED]`. Matching ignores case and punctuation and covers keys containing password, passwd, passphrase, secret, token, authorization, cookie, API key, private key, or session ID. The sanitizer visits nested objects and arrays; it does not search arbitrary string values for secrets. Endpoint authors must exclude payloads containing private free text or fields not covered by those key rules. + +Each top-level structured field is limited to 8 KiB of serialized JSON, six nesting levels, 100 visited entries, and 2,048 characters per string. Field names are capped at 128 characters. An event includes at most 100 caller-supplied top-level fields, plus a truncation marker when that limit is exceeded. Explicit markers identify redaction, truncation, cycles, unavailable getters, unsupported values, and oversized fields. The limits apply to structured fields, not Pino's message or custom bindings. Use short, static messages. + +The sanitizer copies ordinary objects, arrays, and Error data properties without invoking getters or custom `toJSON()` methods. Unsupported object instances are omitted with a marker. These bounds prevent log payloads from growing without limit; they are not a substitute for input validation or endpoint-specific privacy decisions. diff --git a/hub/package-lock.json b/hub/package-lock.json index e7a1d8e7..6594c6db 100644 --- a/hub/package-lock.json +++ b/hub/package-lock.json @@ -15,6 +15,8 @@ "@prisma/client": "7.10.1", "dotenv": "18.0.8", "express": "5.3.0", + "pino": "10.4.0", + "pino-http": "11.0.0", "react": "19.3.0", "react-dom": "19.3.0", "zod": "4.6.5" @@ -2565,6 +2567,12 @@ "win32" ] }, + "node_modules/@pinojs/redact": { + "version": "0.4.0", + "resolved": "https://registry.npmjs.org/@pinojs/redact/-/redact-0.4.0.tgz", + "integrity": "sha512-k2ENnmBugE/rzQfEcdWHcCY+/FM3VLzH9cYEsbdsoqrvzAKRhUZeRNhAZvB8OitQJ1TBed3yqWtdjzS6wJKBwg==", + "license": "MIT" + }, "node_modules/@primer/behaviors": { "version": "1.10.3", "resolved": "https://registry.npmjs.org/@primer/behaviors/-/behaviors-1.10.3.tgz", @@ -4998,6 +5006,15 @@ "node": ">=4" } }, + "node_modules/atomic-sleep": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/atomic-sleep/-/atomic-sleep-1.0.0.tgz", + "integrity": "sha512-kNOjDqAh7px0XWNI+4QbzoiR/nTkHAWNud2uvnJquD1/x5a7EQZMJT0AczqK0Qn67oY/TTQ1LbUKajZpp3I9tQ==", + "license": "MIT", + "engines": { + "node": ">=8.0.0" + } + }, "node_modules/aws-ssl-profiles": { "version": "1.1.2", "resolved": "https://registry.npmjs.org/aws-ssl-profiles/-/aws-ssl-profiles-1.1.2.tgz", @@ -6525,6 +6542,15 @@ "node": ">=6.9.0" } }, + "node_modules/get-caller-file": { + "version": "2.0.5", + "resolved": "https://registry.npmjs.org/get-caller-file/-/get-caller-file-2.0.5.tgz", + "integrity": "sha512-DyFP3BM/3YHTQOCUL/w0OZHR0lpKeGrxotcHWcqNEdnltqFwXVfhEBQ94eIo34AfQpo0rGki4cyIiftY06h2Fg==", + "license": "ISC", + "engines": { + "node": "6.* || 8.* || >= 10.*" + } + }, "node_modules/get-intrinsic": { "version": "1.3.0", "resolved": "https://registry.npmjs.org/get-intrinsic/-/get-intrinsic-1.3.0.tgz", @@ -7701,6 +7727,15 @@ "devOptional": true, "license": "MIT" }, + "node_modules/on-exit-leak-free": { + "version": "2.1.2", + "resolved": "https://registry.npmjs.org/on-exit-leak-free/-/on-exit-leak-free-2.1.2.tgz", + "integrity": "sha512-0eJJY6hXLGf1udHwfNftBqH+g73EU4B504nZeKpz1sYRKafAghwxEJunB2O7rDZkL4PGfsMVnTXZ2EjibbqcsA==", + "license": "MIT", + "engines": { + "node": ">=14.0.0" + } + }, "node_modules/on-finished": { "version": "2.4.1", "resolved": "https://registry.npmjs.org/on-finished/-/on-finished-2.4.1.tgz", @@ -8088,6 +8123,55 @@ "url": "https://github.com/sponsors/jonschlinkert" } }, + "node_modules/pino": { + "version": "10.4.0", + "resolved": "https://registry.npmjs.org/pino/-/pino-10.4.0.tgz", + "integrity": "sha512-bk1ZMTwG/Vymx+zPoa28MhNzucFvXJWp3csrSuxuHPSMeUettaCoQ5Jvg07mtC4JGNpcfTwz41oVCnNgBK9+vA==", + "license": "MIT", + "dependencies": { + "@pinojs/redact": "^0.4.0", + "atomic-sleep": "^1.0.0", + "on-exit-leak-free": "^2.1.0", + "pino-abstract-transport": "^3.0.0", + "pino-std-serializers": "^7.0.0", + "process-warning": "^5.0.0", + "quick-format-unescaped": "^4.0.3", + "real-require": "^1.0.0", + "safe-stable-stringify": "^2.3.1", + "sonic-boom": "^4.0.1", + "thread-stream": "^4.0.0" + }, + "bin": { + "pino": "bin.js" + } + }, + "node_modules/pino-abstract-transport": { + "version": "3.0.0", + "resolved": "https://registry.npmjs.org/pino-abstract-transport/-/pino-abstract-transport-3.0.0.tgz", + "integrity": "sha512-wlfUczU+n7Hy/Ha5j9a/gZNy7We5+cXp8YL+X+PG8S0KXxw7n/JXA3c46Y0zQznIJ83URJiwy7Lh56WLokNuxg==", + "license": "MIT", + "dependencies": { + "split2": "^4.0.0" + } + }, + "node_modules/pino-http": { + "version": "11.0.0", + "resolved": "https://registry.npmjs.org/pino-http/-/pino-http-11.0.0.tgz", + "integrity": "sha512-wqg5XIAGRRIWtTk8qPGxkbrfiwEWz1lgedVLvhLALudKXvg1/L2lTFgTGPJ4Z2e3qcRmxoFxDuSdMdMGNM6I1g==", + "license": "MIT", + "dependencies": { + "get-caller-file": "^2.0.5", + "pino": "^10.0.0", + "pino-std-serializers": "^7.0.0", + "process-warning": "^5.0.0" + } + }, + "node_modules/pino-std-serializers": { + "version": "7.1.0", + "resolved": "https://registry.npmjs.org/pino-std-serializers/-/pino-std-serializers-7.1.0.tgz", + "integrity": "sha512-BndPH67/JxGExRgiX1dX0w1FvZck5Wa4aal9198SrRhZjH3GxKQUKIBnYJTdj2HDN3UQAS06HlfcSbQj2OHmaw==", + "license": "MIT" + }, "node_modules/pkg-types": { "version": "2.3.3", "resolved": "https://registry.npmjs.org/pkg-types/-/pkg-types-2.3.3.tgz", @@ -8271,6 +8355,22 @@ } } }, + "node_modules/process-warning": { + "version": "5.1.1", + "resolved": "https://registry.npmjs.org/process-warning/-/process-warning-5.1.1.tgz", + "integrity": "sha512-oCkNVj4OKnKEcocVBcDfiIugN1/cE6rgfT3nCtzeqZPA8+rIxMaQ0xXzIkGP8Gj2qUaP1UR7uhJ1VD8lUCpzCg==", + "funding": [ + { + "type": "github", + "url": "https://github.com/sponsors/fastify" + }, + { + "type": "opencollective", + "url": "https://opencollective.com/fastify" + } + ], + "license": "MIT" + }, "node_modules/proper-lockfile": { "version": "4.1.2", "resolved": "https://registry.npmjs.org/proper-lockfile/-/proper-lockfile-4.1.2.tgz", @@ -8370,6 +8470,12 @@ "url": "https://github.com/sponsors/ljharb" } }, + "node_modules/quick-format-unescaped": { + "version": "4.0.4", + "resolved": "https://registry.npmjs.org/quick-format-unescaped/-/quick-format-unescaped-4.0.4.tgz", + "integrity": "sha512-tYC1Q1hgyRuHgloV/YXs2w15unPVh8qfu/qCTfhTYamaw7fyhumKa2yGpdSo87vY32rIclj+4fWYQXUMs9EHvg==", + "license": "MIT" + }, "node_modules/range-parser": { "version": "1.3.0", "resolved": "https://registry.npmjs.org/range-parser/-/range-parser-1.3.0.tgz", @@ -8476,6 +8582,12 @@ "url": "https://paulmillr.com/funding/" } }, + "node_modules/real-require": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/real-require/-/real-require-1.0.0.tgz", + "integrity": "sha512-P4nbQYQfePJxRSmY+v/KINxVucm4NF3p3s7pJveMTtom52FR4YGltUQLB8idDXwDDWW+eYrWDFbuzUnjoWHF7g==", + "license": "MIT" + }, "node_modules/recast": { "version": "0.23.21", "resolved": "https://registry.npmjs.org/recast/-/recast-0.23.21.tgz", @@ -8685,6 +8797,15 @@ "safe-regex2": "bin/safe-regex2.js" } }, + "node_modules/safe-stable-stringify": { + "version": "2.5.0", + "resolved": "https://registry.npmjs.org/safe-stable-stringify/-/safe-stable-stringify-2.5.0.tgz", + "integrity": "sha512-b3rppTKm9T+PsVCBEOUR46GWI7fdOs00VKZ1+9c1EWDaDMvjQc6tUwuFyIprgGgTcWoVHSKrU8H31ZHA2e0RHA==", + "license": "MIT", + "engines": { + "node": ">=10" + } + }, "node_modules/safer-buffer": { "version": "2.1.2", "resolved": "https://registry.npmjs.org/safer-buffer/-/safer-buffer-2.1.2.tgz", @@ -8879,6 +9000,15 @@ "url": "https://github.com/sponsors/isaacs" } }, + "node_modules/sonic-boom": { + "version": "4.2.1", + "resolved": "https://registry.npmjs.org/sonic-boom/-/sonic-boom-4.2.1.tgz", + "integrity": "sha512-w6AxtubXa2wTXAUsZMMWERrsIRAdrK0Sc+FUytWvYAhBJLyuI4llrMIC1DtlNSdI99EI86KZum2MMq3EAZlF9Q==", + "license": "MIT", + "dependencies": { + "atomic-sleep": "^1.0.0" + } + }, "node_modules/source-map": { "version": "0.6.1", "resolved": "https://registry.npmjs.org/source-map/-/source-map-0.6.1.tgz", @@ -9065,6 +9195,18 @@ "url": "https://github.com/sponsors/ljharb" } }, + "node_modules/thread-stream": { + "version": "4.2.0", + "resolved": "https://registry.npmjs.org/thread-stream/-/thread-stream-4.2.0.tgz", + "integrity": "sha512-e2zZ96wSChazBsbENf/Pcm/4swHt2cEKQ92rhUjkL9GCKiTDJIaTBenjE/m9DXi0QBmTMDkFDdOomUy20A1tDQ==", + "license": "MIT", + "dependencies": { + "real-require": "^1.0.0" + }, + "engines": { + "node": ">=20" + } + }, "node_modules/tiny-invariant": { "version": "1.3.3", "resolved": "https://registry.npmjs.org/tiny-invariant/-/tiny-invariant-1.3.3.tgz", diff --git a/hub/package.json b/hub/package.json index ba09fc60..f24effed 100644 --- a/hub/package.json +++ b/hub/package.json @@ -44,6 +44,8 @@ "@primer/react-brand": "0.78.0", "dotenv": "18.0.8", "express": "5.3.0", + "pino": "10.4.0", + "pino-http": "11.0.0", "react": "19.3.0", "react-dom": "19.3.0", "zod": "4.6.5" diff --git a/hub/server/create-app/index.test.ts b/hub/server/create-app/index.test.ts index 28339a1c..8d88dac9 100644 --- a/hub/server/create-app/index.test.ts +++ b/hub/server/create-app/index.test.ts @@ -1,11 +1,112 @@ import { once } from "node:events" import { createServer } from "node:http" import type { AddressInfo } from "node:net" -import { describe, expect, it } from "vitest" +import { describe, expect, it, vi } from "vitest" + +import { createLogger } from "../integrations/pino/create-logger" import { createApp } from "." +function isRecord(value: unknown): value is Record { + return value !== null && typeof value === "object" && !Array.isArray(value) +} + +function parseRecord(line: string) { + const value: unknown = JSON.parse(line) + if (!isRecord(value)) throw new Error("Expected a JSON log object") + return value +} + describe("createApp()", () => { + it("automatically logs health and not-found responses with the injected logger", async () => { + const records: Record[] = [] + const logger = createLogger({ + destination: { write: (line) => records.push(parseRecord(line)) }, + }) + const server = createServer(createApp({ logger })) + + try { + server.listen(0, "127.0.0.1") + await once(server, "listening") + const { port } = server.address() as AddressInfo + + const health = await fetch(`http://127.0.0.1:${port}/api/health`) + expect(await health.json()).toEqual({ status: "ok" }) + const missing = await fetch(`http://127.0.0.1:${port}/missing-private-path`) + expect(await missing.json()).toEqual({ error: "Not found" }) + + await vi.waitFor(() => expect(records).toHaveLength(2)) + expect(records[0]).toMatchObject({ + reqId: health.headers.get("x-request-id"), + method: "GET", + route: "/api/health", + statusCode: 200, + level: 30, + outcome: "completed", + }) + expect(records[1]).toMatchObject({ + reqId: missing.headers.get("x-request-id"), + route: null, + statusCode: 404, + level: 40, + outcome: "completed", + }) + expect(JSON.stringify(records)).not.toContain("missing-private-path") + } finally { + await new Promise((resolve, reject) => { + server.close((error) => (error ? reject(error) : resolve())) + }) + } + }) + + it.each([ + { name: "malformed", body: '{"password":"malformed-body-secret"', statusCode: 400 }, + { name: "oversized", body: JSON.stringify({ text: "x".repeat(1024 * 1024) }), statusCode: 413 }, + ])("logs $name JSON safely before routing", async ({ body, statusCode }) => { + const records: Record[] = [] + const logger = createLogger({ + destination: { write: (line) => records.push(parseRecord(line)) }, + }) + const server = createServer(createApp({ logger })) + const stderr = vi.spyOn(process.stderr, "write").mockImplementation(() => true) + + try { + server.listen(0, "127.0.0.1") + await once(server, "listening") + const { port } = server.address() as AddressInfo + + const response = await fetch(`http://127.0.0.1:${port}/api/health`, { + method: "POST", + headers: { "content-type": "application/json" }, + body, + }) + + expect(response.status).toBe(statusCode) + expect(response.headers.get("content-type")).toMatch(/^application\/json\b/) + const payload: unknown = await response.json() + if (!isRecord(payload)) throw new Error("Expected a JSON error object") + expect(typeof payload.error).toBe("string") + expect(Object.keys(payload)).toEqual(["error"]) + await vi.waitFor(() => expect(records).toHaveLength(1)) + expect(records[0]).toMatchObject({ + reqId: response.headers.get("x-request-id"), + statusCode, + level: 40, + outcome: "completed", + }) + expect(records[0]).not.toHaveProperty("body") + expect(records[0]).not.toHaveProperty("err") + expect(records[0]).not.toHaveProperty("req") + expect(records[0]).not.toHaveProperty("res") + expect(JSON.stringify(records)).not.toContain("malformed-body-secret") + expect(stderr).not.toHaveBeenCalled() + } finally { + await new Promise((resolve, reject) => { + server.close((error) => (error ? reject(error) : resolve())) + }) + } + }) + it("returns the health status as JSON", async () => { const server = createServer(createApp()) diff --git a/hub/server/create-app/index.ts b/hub/server/create-app/index.ts index 06d3bc09..b2339c83 100644 --- a/hub/server/create-app/index.ts +++ b/hub/server/create-app/index.ts @@ -1,8 +1,14 @@ import express from "express" +import type { NextFunction, Request, Response } from "express" +import type { Logger } from "pino" -export function createApp() { +import { createRequestLogger } from "../integrations/pino/create-request-logger/index.ts" + +export function createApp({ logger }: { logger?: Logger } = {}) { const app = express() app.disable("x-powered-by") + app.use(createRequestLogger(logger)) + app.use(express.json()) app.get("/api/health", (_request, response) => { response.json({ status: "ok" }) @@ -12,5 +18,28 @@ export function createApp() { response.status(404).json({ error: "Not found" }) }) + // Express identifies error handlers by their four-argument signature. + // eslint-disable-next-line @typescript-eslint/no-unused-vars + function handleError(error: unknown, _request: Request, response: Response, _next: NextFunction) { + if (response.headersSent) { + response.destroy() + return + } + const status = + error !== null && + typeof error === "object" && + "status" in error && + typeof error.status === "number" && + Number.isInteger(error.status) && + error.status >= 400 && + error.status <= 599 + ? error.status + : 500 + response.status(status).json({ + error: status >= 500 ? "Internal server error" : "Invalid request", + }) + } + app.use(handleError) + return app } diff --git a/hub/server/index.ts b/hub/server/index.ts index e6de88b0..64bafe13 100644 --- a/hub/server/index.ts +++ b/hub/server/index.ts @@ -1,6 +1,7 @@ import "dotenv/config" import { createApp } from "./create-app/index.ts" +import { log } from "./integrations/pino/log/index.ts" const port = Number(process.env.PORT ?? 3001) if (!Number.isInteger(port) || port < 1 || port > 65535) { @@ -8,5 +9,5 @@ if (!Number.isInteger(port) || port < 1 || port > 65535) { } createApp().listen(port, "127.0.0.1", () => { - console.info(`Hub API listening at http://127.0.0.1:${port}`) + log("info", "Hub API listening", { host: "127.0.0.1", port }) }) diff --git a/hub/server/integrations/pino/create-logger/index.test.ts b/hub/server/integrations/pino/create-logger/index.test.ts new file mode 100644 index 00000000..9643d1ce --- /dev/null +++ b/hub/server/integrations/pino/create-logger/index.test.ts @@ -0,0 +1,116 @@ +import { describe, expect, it } from "vitest" + +import { createLogger } from "." + +function isRecord(value: unknown): value is Record { + return value !== null && typeof value === "object" && !Array.isArray(value) +} + +function parseRecord(line: string) { + const value: unknown = JSON.parse(line) + if (!isRecord(value)) throw new Error("Expected a JSON log object") + return value +} + +describe("createLogger()", () => { + it("writes real JSON records and applies the configured level", () => { + const lines: string[] = [] + const logger = createLogger({ + level: "warn", + destination: { write: (line) => lines.push(line) }, + }) + + logger.info("Not emitted") + logger.warn({ count: 2 }, "Needs attention") + + expect(lines).toHaveLength(1) + const record = parseRecord(lines.join("")) + expect(record).toMatchObject({ + level: 40, + msg: "Needs attention", + count: 2, + }) + expect(record).toHaveProperty("time", expect.any(Number)) + expect(record).toHaveProperty("name", expect.any(String)) + }) + + it("sanitizes structured fields from direct and child logger calls", () => { + const lines: string[] = [] + const logger = createLogger({ destination: { write: (line) => lines.push(line) } }) + const input = { nested: [{ password: "direct-secret", visible: true }] } + + logger.info(input, "Direct") + logger + .child({ component: "worker" }) + .info( + { access_token: "child-token-secret", data: { "client-secret": "child-secret" } }, + "Child", + ) + + expect(lines.map((line) => parseRecord(line))).toMatchObject([ + { + nested: [{ password: "[REDACTED]", visible: true }], + msg: "Direct", + }, + { + access_token: "[REDACTED]", + component: "worker", + data: { "client-secret": "[REDACTED]" }, + msg: "Child", + }, + ]) + expect(lines.join("")).not.toMatch(/direct-secret|child-token-secret|child-secret/) + expect(input.nested[0]?.password).toBe("direct-secret") + }) + + it("serializes an Error without leaking its sensitive enumerable fields", () => { + const lines: string[] = [] + const logger = createLogger({ destination: { write: (line) => lines.push(line) } }) + const error = Object.assign(new Error("Operation failed"), { + password: "error-secret", + context: { access_token: "nested-error-secret" }, + }) + + logger.error({ err: error }, "Failed") + + expect(lines).toHaveLength(1) + expect(parseRecord(lines.join(""))).toMatchObject({ + level: 50, + err: { message: "Operation failed" }, + }) + expect(lines[0]).not.toMatch(/error-secret|nested-error-secret/) + expect(error.password).toBe("error-secret") + }) + + it("bounds each structured field without dropping unrelated fields or the message", () => { + const lines: string[] = [] + const logger = createLogger({ destination: { write: (line) => lines.push(line) } }) + const oversized = Array.from({ length: 6 }, () => "\u754c".repeat(1800)) + + logger.info({ oversized, task: "rebuild" }, "Task started") + + expect(lines).toHaveLength(1) + const record = parseRecord(lines.join("")) + expect(record).toMatchObject({ task: "rebuild", msg: "Task started" }) + expect(record).toHaveProperty("oversized") + expect(Buffer.byteLength(JSON.stringify(record.oversized), "utf8")).toBeLessThanOrEqual(8192) + }) + + it("limits the number of caller-supplied top-level fields to 100", () => { + const lines: string[] = [] + const logger = createLogger({ destination: { write: (line) => lines.push(line) } }) + const fields = Object.fromEntries( + Array.from({ length: 120 }, (_, index) => [`field${index}`, index]), + ) + + logger.info(fields, "Many fields") + + expect(lines).toHaveLength(1) + const record = parseRecord(lines.join("")) + expect(record).toMatchObject({ field0: 0, msg: "Many fields" }) + expect(Object.keys(record).filter((key) => /^field\d+$/.test(key)).length).toBeLessThanOrEqual( + 100, + ) + expect(record).not.toHaveProperty("field119") + }) +}) diff --git a/hub/server/integrations/pino/create-logger/index.ts b/hub/server/integrations/pino/create-logger/index.ts new file mode 100644 index 00000000..647fc7fe --- /dev/null +++ b/hub/server/integrations/pino/create-logger/index.ts @@ -0,0 +1,32 @@ +import pino from "pino" + +import { sanitizeLogValue } from "../../../utils/logging/sanitize-log-value/index.ts" +import type { LoggerOptions } from "./types.ts" + +export function createLogger({ level = "info", destination }: LoggerOptions = {}) { + return pino( + { + name: "replica-hub", + level, + formatters: { + log(fields) { + const result = Object.create(null) as Record + for (const key of Object.keys(fields).slice(0, 100)) { + const descriptor = Object.getOwnPropertyDescriptor(fields, key) + const value: unknown = + descriptor && "value" in descriptor ? descriptor.value : "[UNAVAILABLE]" + const safe = sanitizeLogValue({ [key]: value }) + if (safe !== null && typeof safe === "object" && !Array.isArray(safe)) { + Object.assign(result, safe) + } else { + result[key.slice(0, 128)] = safe + } + } + if (Object.keys(fields).length > 100) result.truncated = "[MAX FIELDS]" + return result + }, + }, + }, + destination, + ) +} diff --git a/hub/server/integrations/pino/create-logger/types.ts b/hub/server/integrations/pino/create-logger/types.ts new file mode 100644 index 00000000..4ec3ff7b --- /dev/null +++ b/hub/server/integrations/pino/create-logger/types.ts @@ -0,0 +1,6 @@ +import type { DestinationStream, LevelWithSilent } from "pino" + +export interface LoggerOptions { + level?: LevelWithSilent + destination?: DestinationStream +} diff --git a/hub/server/integrations/pino/create-request-logger/index.test.ts b/hub/server/integrations/pino/create-request-logger/index.test.ts new file mode 100644 index 00000000..581a9324 --- /dev/null +++ b/hub/server/integrations/pino/create-request-logger/index.test.ts @@ -0,0 +1,270 @@ +import { once } from "node:events" +import { createServer, IncomingMessage, request } from "node:http" +import type { AddressInfo } from "node:net" +import express from "express" +import { describe, expect, it, onTestFinished, vi } from "vitest" + +import { createLogger } from "../create-logger" + +import { createRequestLogger } from "." + +function isRecord(value: unknown): value is Record { + return value !== null && typeof value === "object" && !Array.isArray(value) +} + +function parseRecord(line: string) { + const value: unknown = JSON.parse(line) + if (!isRecord(value)) throw new Error("Expected a JSON log object") + return value +} + +async function listen(app: express.Express) { + const server = createServer(app) + onTestFinished( + () => + new Promise((resolve, reject) => { + server.close((error) => (error ? reject(error) : resolve())) + }), + ) + server.listen(0, "127.0.0.1") + await once(server, "listening") + const { port } = server.address() as AddressInfo + return `http://127.0.0.1:${port}` +} + +describe("createRequestLogger()", () => { + it("retains mounted route data after next without changing the request payload", async () => { + const records: Record[] = [] + const logger = createLogger({ + destination: { write: (line) => records.push(parseRecord(line)) }, + }) + const app = express() + app.use(createRequestLogger(logger)) + app.use(express.json()) + const router = express.Router({ mergeParams: true }) + router.post("/widgets/:password", (req, res, next) => { + const body: unknown = req.body + res.json({ params: req.params, query: req.query, body }) + next() + }) + app.use("/teams/:teamId", router) + const baseUrl = await listen(app) + const body = { title: "Example", nested: [{ access_token: "body-secret" }] } + + const response = await fetch( + `${baseUrl}/teams/design/widgets/param-secret?tag=one&tag=two&password=query-secret`, + { + method: "POST", + headers: { + "content-type": "application/json", + "x-request-id": "untrusted-request-id", + "x-private-header": "header-secret", + authorization: "header-authorization-secret", + }, + body: JSON.stringify(body), + }, + ) + + expect(await response.json()).toEqual({ + params: { teamId: "design", password: "param-secret" }, + query: { tag: ["one", "two"], password: "query-secret" }, + body, + }) + await vi.waitFor(() => expect(records).toHaveLength(1)) + const reqId = response.headers.get("x-request-id") + expect(reqId).toMatch(/^[0-9a-f]{8}-[0-9a-f]{4}-4[0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/i) + expect(records[0]).toMatchObject({ + reqId, + level: 30, + method: "POST", + route: "/widgets/:password", + statusCode: 200, + outcome: "completed", + params: { teamId: "design", password: "[REDACTED]" }, + query: { tag: ["one", "two"], password: "[REDACTED]" }, + body: { title: "Example", nested: [{ access_token: "[REDACTED]" }] }, + }) + expect(records[0]).toHaveProperty("responseTime", expect.any(Number)) + expect(records[0]?.responseTime).toBeGreaterThanOrEqual(0) + expect(records[0]).not.toHaveProperty("req") + expect(records[0]).not.toHaveProperty("res") + expect(records[0]).not.toHaveProperty("url") + expect(JSON.stringify(records)).not.toMatch( + /param-secret|query-secret|body-secret|header-secret|header-authorization-secret|untrusted-request-id/, + ) + }) + + it.each([ + { statusCode: 399, level: 30 }, + { statusCode: 400, level: 40 }, + { statusCode: 499, level: 40 }, + { statusCode: 500, level: 50 }, + ])("logs status $statusCode once at level $level", async ({ statusCode, level }) => { + const records: Record[] = [] + const logger = createLogger({ + destination: { write: (line) => records.push(parseRecord(line)) }, + }) + const app = express() + app.use(createRequestLogger(logger)) + app.get("/status", (_req, res) => res.status(statusCode).end()) + const baseUrl = await listen(app) + + const response = await fetch(`${baseUrl}/status`) + await response.arrayBuffer() + + await vi.waitFor(() => expect(records).toHaveLength(1)) + expect(records[0]).toMatchObject({ level, statusCode, outcome: "completed" }) + }) + + it("uses a null route for unmatched requests instead of exposing their URL", async () => { + const records: Record[] = [] + const logger = createLogger({ + destination: { write: (line) => records.push(parseRecord(line)) }, + }) + const app = express() + app.use(createRequestLogger(logger)) + app.use((_req, res) => res.status(404).json({ error: "Not found" })) + const baseUrl = await listen(app) + + const first = await fetch(`${baseUrl}/private-path-secret?token=query-secret`, { + headers: { "x-request-id": "same-incoming-id" }, + }) + await first.arrayBuffer() + const second = await fetch(`${baseUrl}/another-private-path-secret`, { + headers: { "x-request-id": "same-incoming-id" }, + }) + await second.arrayBuffer() + + await vi.waitFor(() => expect(records).toHaveLength(2)) + expect(records[0]).toMatchObject({ route: null, level: 40, statusCode: 404 }) + expect(records[1]).toMatchObject({ route: null, level: 40, statusCode: 404 }) + expect(first.headers.get("x-request-id")).not.toBe(second.headers.get("x-request-id")) + expect(JSON.stringify(records)).not.toMatch(/private-path-secret|query-secret|same-incoming-id/) + }) + + it("lets an endpoint omit all payload fields without suppressing completion metadata", async () => { + const records: Record[] = [] + const logger = createLogger({ + destination: { write: (line) => records.push(parseRecord(line)) }, + }) + const app = express() + app.use(createRequestLogger(logger)) + app.use(express.json()) + app.post("/private/:id", (_req, res) => { + res.locals.omitLogPayload = true + res.json({ private: "response-secret" }) + }) + const baseUrl = await listen(app) + + const response = await fetch(`${baseUrl}/private/param-secret?search=query-secret`, { + method: "POST", + headers: { "content-type": "application/json" }, + body: JSON.stringify({ text: "body-secret" }), + }) + await response.arrayBuffer() + + await vi.waitFor(() => expect(records).toHaveLength(1)) + expect(records[0]).toMatchObject({ + method: "POST", + route: "/private/:id", + statusCode: 200, + outcome: "completed", + }) + for (const field of ["params", "query", "body", "req", "res"]) { + expect(records[0]).not.toHaveProperty(field) + } + expect(JSON.stringify(records)).not.toMatch( + /param-secret|query-secret|body-secret|response-secret/, + ) + }) + + it("does not log parsed binary uploads or response content", async () => { + const records: Record[] = [] + const logger = createLogger({ + destination: { write: (line) => records.push(parseRecord(line)) }, + }) + const app = express() + app.use(createRequestLogger(logger)) + app.use(express.raw({ type: "application/octet-stream" })) + app.post("/upload", (req, res) => { + expect(Buffer.isBuffer(req.body)).toBe(true) + res.send("response-secret") + }) + const baseUrl = await listen(app) + + const response = await fetch(`${baseUrl}/upload`, { + method: "POST", + headers: { "content-type": "application/octet-stream" }, + body: "upload-secret", + }) + await response.arrayBuffer() + + await vi.waitFor(() => expect(records).toHaveLength(1)) + expect(records[0]).not.toHaveProperty("body") + expect(JSON.stringify(records)).not.toMatch(/upload-secret|response-secret/) + }) + + it("exposes a sanitized request logger correlated with the automatic record", async () => { + const records: Record[] = [] + const logger = createLogger({ + destination: { write: (line) => records.push(parseRecord(line)) }, + }) + const app = express() + app.use(createRequestLogger(logger)) + app.get("/work", (req, res) => { + req.log.info({ nested: { password: "request-log-secret" } }, "Work started") + res.end() + }) + const baseUrl = await listen(app) + + const response = await fetch(`${baseUrl}/work`) + await response.arrayBuffer() + + await vi.waitFor(() => expect(records).toHaveLength(2)) + expect(records.find((record) => record.msg === "Work started")).toMatchObject({ + reqId: response.headers.get("x-request-id"), + nested: { password: "[REDACTED]" }, + }) + expect(records.filter((record) => record.outcome === "completed")).toHaveLength(1) + expect(JSON.stringify(records)).not.toContain("request-log-secret") + }) + + it("emits one distinct error record when a streaming response is aborted", async () => { + const records: Record[] = [] + const logger = createLogger({ + destination: { write: (line) => records.push(parseRecord(line)) }, + }) + const app = express() + app.use(createRequestLogger(logger)) + app.get("/stream", (_req, res) => { + res.write("private-stream-content") + }) + const baseUrl = await listen(app) + const client = request(`${baseUrl}/stream`) + onTestFinished(() => { + client.destroy() + }) + client.end() + const responseEvent: unknown[] = await once(client, "response") + const response = responseEvent[0] + if (!(response instanceof IncomingMessage)) throw new Error("Expected an HTTP response") + await once(response, "data") + + response.destroy() + client.destroy() + + await vi.waitFor(() => expect(records).toHaveLength(1)) + expect(records[0]).toMatchObject({ + level: 50, + method: "GET", + route: "/stream", + statusCode: null, + outcome: "aborted", + }) + expect(records[0]).toHaveProperty("responseTime", expect.any(Number)) + expect(records[0]).not.toHaveProperty("err") + expect(records[0]).not.toHaveProperty("req") + expect(records[0]).not.toHaveProperty("res") + expect(JSON.stringify(records)).not.toContain("private-stream-content") + }) +}) diff --git a/hub/server/integrations/pino/create-request-logger/index.ts b/hub/server/integrations/pino/create-request-logger/index.ts new file mode 100644 index 00000000..866c7626 --- /dev/null +++ b/hub/server/integrations/pino/create-request-logger/index.ts @@ -0,0 +1,97 @@ +import { randomUUID } from "node:crypto" +import type { OutgoingHttpHeader, OutgoingHttpHeaders } from "node:http" +import type { Request, RequestHandler, Response } from "express" +import type { Logger } from "pino" +import { pinoHttp } from "pino-http" + +import { sanitizeLogValue } from "../../../utils/logging/sanitize-log-value/index.ts" +import { logger } from "../index.ts" +import type { RequestSnapshot } from "./types.ts" + +export function createRequestLogger(target: Logger = logger): RequestHandler { + const snapshots = new WeakMap() + + function snapshot(request: Request): RequestSnapshot { + const route: unknown = request.route + const path = + route !== null && typeof route === "object" && "path" in route ? route.path : undefined + return { + route: typeof path === "string" ? path : null, + params: sanitizeLogValue(request.params), + query: sanitizeLogValue(request.query), + ...(request.is("application/json") && request.body !== undefined + ? { body: sanitizeLogValue(request.body) } + : {}), + } + } + + function record(request: Request, response: Response, responseTime: number) { + const captured = snapshots.get(response) ?? snapshot(request) + const completed = response.writableFinished && !request.readableAborted + const { route, ...payload } = captured + return { + method: request.method, + route, + statusCode: completed ? response.statusCode : null, + responseTime, + outcome: completed ? "completed" : "aborted", + ...(response.locals.omitLogPayload === true ? {} : payload), + } + } + + const middleware = pinoHttp({ + logger: target, + quietReqLogger: true, + quietResLogger: true, + wrapSerializers: false, + serializers: { + req: () => undefined, + res: () => undefined, + err: () => undefined, + }, + genReqId(_request, response) { + const id = randomUUID() + response.setHeader("X-Request-Id", id) + return id + }, + customLogLevel(request, response, error) { + if ( + error || + !response.writableFinished || + request.readableAborted || + response.statusCode >= 500 + ) { + return "error" + } + return response.statusCode >= 400 ? "warn" : "info" + }, + customSuccessObject(request, response, value: { responseTime: number }) { + return record(request, response, value.responseTime) + }, + customErrorObject(request, response, _error, value: { responseTime: number }) { + return record(request, response, value.responseTime) + }, + customSuccessMessage(request, response) { + return response.writableFinished && !request.readableAborted + ? "Request completed" + : "Request aborted" + }, + customErrorMessage: () => "Request failed", + }) + + return (request, response, next) => { + // Capture before Express restores mounted router parameters after sending a response. + const writeHead = response.writeHead.bind(response) + response.writeHead = function ( + statusCode: number, + statusMessageOrHeaders?: string | OutgoingHttpHeaders | OutgoingHttpHeader[], + headers?: OutgoingHttpHeaders | OutgoingHttpHeader[], + ) { + snapshots.set(response, snapshot(request)) + return typeof statusMessageOrHeaders === "string" + ? writeHead(statusCode, statusMessageOrHeaders, headers) + : writeHead(statusCode, statusMessageOrHeaders) + } + middleware(request, response, next) + } +} diff --git a/hub/server/integrations/pino/create-request-logger/types.ts b/hub/server/integrations/pino/create-request-logger/types.ts new file mode 100644 index 00000000..d86d170e --- /dev/null +++ b/hub/server/integrations/pino/create-request-logger/types.ts @@ -0,0 +1,8 @@ +import type { LogValue } from "../../../utils/logging/sanitize-log-value/types.ts" + +export interface RequestSnapshot { + route: string | null + params: LogValue + query: LogValue + body?: LogValue +} diff --git a/hub/server/integrations/pino/index.ts b/hub/server/integrations/pino/index.ts new file mode 100644 index 00000000..174d9b98 --- /dev/null +++ b/hub/server/integrations/pino/index.ts @@ -0,0 +1,12 @@ +import "dotenv/config" + +import { createLogger } from "./create-logger/index.ts" + +const level = (["trace", "debug", "info", "warn", "error", "fatal", "silent"] as const).find( + (candidate) => candidate === (process.env.LOG_LEVEL ?? "info"), +) +if (!level) { + throw new Error("LOG_LEVEL must be trace, debug, info, warn, error, fatal, or silent.") +} + +export const logger = createLogger({ level }) diff --git a/hub/server/integrations/pino/log/index.test.ts b/hub/server/integrations/pino/log/index.test.ts new file mode 100644 index 00000000..c9f43f52 --- /dev/null +++ b/hub/server/integrations/pino/log/index.test.ts @@ -0,0 +1,25 @@ +import { describe, expect, it } from "vitest" + +import { createLogger } from "../create-logger" + +import { log } from "." + +describe("log()", () => { + it("writes the selected level, message, and sanitized fields to the supplied logger", () => { + const lines: string[] = [] + const logger = createLogger({ destination: { write: (line) => lines.push(line) } }) + const fields = { task: "rebuild", nested: { password: "helper-secret" } } + + log("warn", "Rebuild delayed", fields, logger) + + expect(lines).toHaveLength(1) + const record: unknown = JSON.parse(lines.join("")) + expect(record).toMatchObject({ + level: 40, + msg: "Rebuild delayed", + task: "rebuild", + nested: { password: "[REDACTED]" }, + }) + expect(fields.nested.password).toBe("helper-secret") + }) +}) diff --git a/hub/server/integrations/pino/log/index.ts b/hub/server/integrations/pino/log/index.ts new file mode 100644 index 00000000..75bad992 --- /dev/null +++ b/hub/server/integrations/pino/log/index.ts @@ -0,0 +1,12 @@ +import type { Level, Logger } from "pino" + +import { logger } from "../index.ts" + +export function log( + level: Level, + message: string, + fields: Record = {}, + target: Logger = logger, +) { + target[level](fields, message) +} diff --git a/hub/server/utils/logging/sanitize-log-value/index.test.ts b/hub/server/utils/logging/sanitize-log-value/index.test.ts new file mode 100644 index 00000000..ecb60b54 --- /dev/null +++ b/hub/server/utils/logging/sanitize-log-value/index.test.ts @@ -0,0 +1,111 @@ +import { describe, expect, it, vi } from "vitest" + +import { sanitizeLogValue } from "." + +describe("sanitizeLogValue()", () => { + it("redacts sensitive naming variants recursively without changing the input", () => { + const input = { + title: "Public title", + PASSWORD: "password-value", + nested: [ + { access_token: "token-value", "client-secret": "secret-value", count: 2 }, + { authorization: "authorization-value", cookie: "cookie-value" }, + ], + } + const original = structuredClone(input) + + expect(sanitizeLogValue(input)).toEqual({ + title: "Public title", + PASSWORD: "[REDACTED]", + nested: [ + { access_token: "[REDACTED]", "client-secret": "[REDACTED]", count: 2 }, + { authorization: "[REDACTED]", cookie: "[REDACTED]" }, + ], + }) + expect(input).toEqual(original) + }) + + it("makes cycles and non-JSON primitives safe to serialize", () => { + const input: Record = { + title: "Keep this", + bigint: 1n, + missing: undefined, + infinite: Infinity, + symbol: Symbol("private-symbol"), + callback: () => "private-function", + } + input.self = input + + const result = sanitizeLogValue(input) + + expect(() => JSON.stringify(result)).not.toThrow() + expect(JSON.parse(JSON.stringify(result))).toMatchObject({ title: "Keep this" }) + expect(input.self).toBe(input) + }) + + it("does not execute getters or serialization hooks on unsupported instances", () => { + const getter = vi.fn(() => "getter-secret") + const toJSON = vi.fn(() => ({ exposed: "serialization-secret" })) + class Upload { + toJSON = toJSON + } + const input = { + safe: "Keep this", + upload: new Upload(), + buffer: Buffer.from("upload-secret"), + get computed() { + return getter() + }, + } + + const result = JSON.stringify(sanitizeLogValue(input)) + + expect(getter).not.toHaveBeenCalled() + expect(toJSON).not.toHaveBeenCalled() + expect(result).toContain("Keep this") + expect(result).not.toMatch(/getter-secret|serialization-secret|upload-secret/) + }) + + it("omits values deeper than six levels while retaining shallow data", () => { + const input = { + safe: "Keep this", + nested: { a: { b: { c: { d: { e: { f: { g: "too-deep" } } } } } } }, + } + + const result = JSON.stringify(sanitizeLogValue(input)) + + expect(result).toContain("Keep this") + expect(result).not.toContain("too-deep") + }) + + it("limits total visited entries rather than only limiting each container", () => { + const input = Array.from({ length: 12 }, (_, group) => + Array.from({ length: 10 }, (_, entry) => `entry-${group}-${entry}`), + ) + + const result = JSON.stringify(sanitizeLogValue(input)) + + expect(result).toContain("entry-0-0") + expect(result).not.toContain("entry-11-9") + }) + + it("limits an individual string to 2048 characters", () => { + const input = "a".repeat(2048) + "past-string-limit" + + const result = sanitizeLogValue(input) + + expect(typeof result).toBe("string") + expect((result as string).length).toBeLessThanOrEqual(2048) + expect(result).not.toContain("past-string-limit") + expect(input).toHaveLength(2065) + }) + + it("keeps the final serialized value within 8192 bytes for multibyte text", () => { + const input = Array.from({ length: 6 }, () => "\u754c".repeat(1800)) + + const result = JSON.stringify(sanitizeLogValue(input)) + + expect(Buffer.byteLength(result, "utf8")).toBeLessThanOrEqual(8192) + expect(input[0]).toHaveLength(1800) + }) +}) diff --git a/hub/server/utils/logging/sanitize-log-value/index.ts b/hub/server/utils/logging/sanitize-log-value/index.ts new file mode 100644 index 00000000..5d756ca3 --- /dev/null +++ b/hub/server/utils/logging/sanitize-log-value/index.ts @@ -0,0 +1,64 @@ +import { Buffer } from "node:buffer" + +import type { LogValue } from "./types.ts" + +export function sanitizeLogValue(value: unknown): LogValue { + const ancestors = new WeakSet() + const truncated = "[TRUNCATED]" + let entries = 0 + + function visit(input: unknown, depth: number): LogValue { + if (typeof input === "string") { + return input.length > 2048 ? `${input.slice(0, 2048 - truncated.length)}${truncated}` : input + } + if (input === null || typeof input === "boolean") return input + if (typeof input === "number") return Number.isFinite(input) ? input : "[NON-FINITE]" + if (typeof input !== "object") return "[UNSUPPORTED]" + if (ancestors.has(input)) return "[CIRCULAR]" + if (depth >= 6) return "[MAX DEPTH]" + if ( + !Array.isArray(input) && + !(input instanceof Error) && + Object.getPrototypeOf(input) !== Object.prototype && + Object.getPrototypeOf(input) !== null + ) { + return "[UNSUPPORTED OBJECT]" + } + + ancestors.add(input) + const output = Object.create(null) as Record + const array: LogValue[] = [] + if (input instanceof Error) output.type = "Error" + const keys = input instanceof Error ? ["name", "message", "stack", "code"] : Object.keys(input) + for (const key of keys) { + if (++entries > 100) { + if (Array.isArray(input)) array.push("[MAX ENTRIES]") + else output["[TRUNCATED]"] = "[MAX ENTRIES]" + break + } + const descriptor = Object.getOwnPropertyDescriptor(input, key) + if (!descriptor) continue + let result: LogValue + if ( + /(password|passwd|passphrase|secret|token|authorization|cookie|apikey|privatekey|sessionid)/.test( + key.toLowerCase().replace(/[^a-z0-9]/g, ""), + ) + ) { + result = "[REDACTED]" + } else if (descriptor && "value" in descriptor) { + result = visit(descriptor.value, depth + 1) + } else { + result = "[UNAVAILABLE]" + } + if (Array.isArray(input)) array.push(result) + else + output[key.length > 128 ? `${key.slice(0, 128 - truncated.length)}${truncated}` : key] = + result + } + ancestors.delete(input) + return Array.isArray(input) ? array : output + } + + const result = visit(value, 0) + return Buffer.byteLength(JSON.stringify(result)) <= 8192 ? result : "[OMITTED: MAX BYTES]" +} diff --git a/hub/server/utils/logging/sanitize-log-value/types.ts b/hub/server/utils/logging/sanitize-log-value/types.ts new file mode 100644 index 00000000..eee7766f --- /dev/null +++ b/hub/server/utils/logging/sanitize-log-value/types.ts @@ -0,0 +1 @@ +export type LogValue = null | boolean | number | string | LogValue[] | { [key: string]: LogValue } From e02eddc7a424e6fc9512f753c6f02dc959db3989 Mon Sep 17 00:00:00 2001 From: Nishiki Liu Date: Tue, 27 Oct 2026 09:42:17 -0700 Subject: [PATCH 2/6] refactor(hub): extract Express handlers and health route Co-authored-by: Nishiki <1121087+nshki@users.noreply.github.com> --- hub/docs/backend-architecture.md | 11 ++- hub/server/create-app/index.test.ts | 62 ++++----------- hub/server/create-app/index.ts | 36 ++------- .../express/handle-error/constants.ts | 3 + .../express/handle-error/index.test.ts | 79 +++++++++++++++++++ .../express/handle-error/index.ts | 24 ++++++ .../express/respond-not-found/index.ts | 6 ++ hub/server/routes/api/health/get/index.ts | 6 ++ hub/server/routes/index.ts | 8 ++ 9 files changed, 156 insertions(+), 79 deletions(-) create mode 100644 hub/server/integrations/express/handle-error/constants.ts create mode 100644 hub/server/integrations/express/handle-error/index.test.ts create mode 100644 hub/server/integrations/express/handle-error/index.ts create mode 100644 hub/server/integrations/express/respond-not-found/index.ts create mode 100644 hub/server/routes/api/health/get/index.ts create mode 100644 hub/server/routes/index.ts diff --git a/hub/docs/backend-architecture.md b/hub/docs/backend-architecture.md index 46cc8f0b..60976740 100644 --- a/hub/docs/backend-architecture.md +++ b/hub/docs/backend-architecture.md @@ -1,9 +1,10 @@ # Code architecture conventions -Organize backend functions into repositories, integrations, utilities, and domains. Each layer has a clear job and rules for which other layers it may use. +Organize backend functions into routes, repositories, integrations, utilities, and domains. Each layer has a clear job and rules for which other layers it may use. | Layer | Responsibility | Directory example | | --- | --- | --- | +| Routes | Parse HTTP requests, call backend functions, and send responses. Directories follow URL paths and HTTP methods. | `routes/api/health/get/index.ts` | | Repositories | Functions that interact with the database. Each repository directory represents one RESTful resource. | `repositories/user/get-user/index.ts` | | Integrations | Functions that interact with an API or SDK. Each integration directory represents one API or SDK service. | `integrations/github/get-user/index.ts` | | Utilities | General functions reusable elsewhere in the codebase. | `utils/format-timestamp/index.ts` | @@ -13,6 +14,10 @@ Organize backend functions into repositories, integrations, utilities, and domai ```mermaid flowchart LR + Routes --> Domains + Routes --> Repositories + Routes --> Integrations + Routes --> Utilities Domains --> Repositories Domains --> Integrations Domains --> Utilities @@ -20,7 +25,7 @@ flowchart LR Integrations --> Utilities ``` -Repositories and integrations may import only utilities from elsewhere in the backend. Utilities may import only other utilities. Domains may import any of these layers, including other domains. Each layer may also use built-in libraries and npm packages. +Routes may import domains, repositories, integrations, and utilities. Repositories and integrations may import only utilities from elsewhere in the backend. Utilities may import only other utilities. Domains may import any of these backend layers, including other domains, but not routes. Each layer may also use built-in libraries and npm packages. These rules apply to imported types as well as functions. A repository must not call another repository or an integration. An integration must not call a repository. Keep business decisions in domains rather than moving them into utilities to get around these rules. @@ -28,6 +33,8 @@ These rules apply to imported types as well as functions. A repository must not Put each function in a directory named with lowercase words and hyphens, such as `get-user`. Keep `index.ts`, its tests, and its types together. Group repository functions by resource and integration functions by API or SDK service, as shown above. Import from each function's directory, not from a shared file that re-exports its neighbors. +Export route handlers by HTTP method, such as `get()`, and alias them to descriptive `handle*` names in `routes/index.ts`. Its `routes()` function registers endpoints; `createApp()` installs shared middleware and error handling. Express-specific helpers belong in `integrations/express`, not utilities. + Add directories when their functions are needed. Do not add empty implementations just to fill out the structure. ## Database access diff --git a/hub/server/create-app/index.test.ts b/hub/server/create-app/index.test.ts index 8d88dac9..c9453fb5 100644 --- a/hub/server/create-app/index.test.ts +++ b/hub/server/create-app/index.test.ts @@ -30,10 +30,19 @@ describe("createApp()", () => { await once(server, "listening") const { port } = server.address() as AddressInfo - const health = await fetch(`http://127.0.0.1:${port}/api/health`) + const headers = { "x-request-id": "untrusted-request-id" } + const health = await fetch(`http://127.0.0.1:${port}/api/health`, { headers }) + expect(health.status).toBe(200) + expect(health.headers.get("content-type")).toMatch(/^application\/json\b/) expect(await health.json()).toEqual({ status: "ok" }) - const missing = await fetch(`http://127.0.0.1:${port}/missing-private-path`) + const missing = await fetch( + `http://127.0.0.1:${port}/api/missing-private-path?token=query-secret`, + { headers }, + ) + expect(missing.status).toBe(404) + expect(missing.headers.get("content-type")).toMatch(/^application\/json\b/) expect(await missing.json()).toEqual({ error: "Not found" }) + expect(health.headers.get("x-request-id")).not.toBe(missing.headers.get("x-request-id")) await vi.waitFor(() => expect(records).toHaveLength(2)) expect(records[0]).toMatchObject({ @@ -51,7 +60,9 @@ describe("createApp()", () => { level: 40, outcome: "completed", }) - expect(JSON.stringify(records)).not.toContain("missing-private-path") + expect(JSON.stringify(records)).not.toMatch( + /missing-private-path|query-secret|untrusted-request-id/, + ) } finally { await new Promise((resolve, reject) => { server.close((error) => (error ? reject(error) : resolve())) @@ -83,10 +94,7 @@ describe("createApp()", () => { expect(response.status).toBe(statusCode) expect(response.headers.get("content-type")).toMatch(/^application\/json\b/) - const payload: unknown = await response.json() - if (!isRecord(payload)) throw new Error("Expected a JSON error object") - expect(typeof payload.error).toBe("string") - expect(Object.keys(payload)).toEqual(["error"]) + expect(await response.json()).toEqual({ error: "Invalid request" }) await vi.waitFor(() => expect(records).toHaveLength(1)) expect(records[0]).toMatchObject({ reqId: response.headers.get("x-request-id"), @@ -107,46 +115,6 @@ describe("createApp()", () => { } }) - it("returns the health status as JSON", async () => { - const server = createServer(createApp()) - - try { - server.listen(0, "127.0.0.1") - await once(server, "listening") - const { port } = server.address() as AddressInfo - - const response = await fetch(`http://127.0.0.1:${port}/api/health`) - - expect(response.status).toBe(200) - expect(response.headers.get("content-type")).toMatch(/^application\/json\b/) - expect(await response.json()).toEqual({ status: "ok" }) - } finally { - await new Promise((resolve, reject) => { - server.close((error) => (error ? reject(error) : resolve())) - }) - } - }) - - it("returns a JSON not-found error for an unknown API route", async () => { - const server = createServer(createApp()) - - try { - server.listen(0, "127.0.0.1") - await once(server, "listening") - const { port } = server.address() as AddressInfo - - const response = await fetch(`http://127.0.0.1:${port}/api/not-a-route`) - - expect(response.status).toBe(404) - expect(response.headers.get("content-type")).toMatch(/^application\/json\b/) - expect(await response.json()).toEqual({ error: "Not found" }) - } finally { - await new Promise((resolve, reject) => { - server.close((error) => (error ? reject(error) : resolve())) - }) - } - }) - it.each([ { method: "GET", path: "/repositories" }, { method: "POST", path: "/auth/github" }, diff --git a/hub/server/create-app/index.ts b/hub/server/create-app/index.ts index b2339c83..a3954deb 100644 --- a/hub/server/create-app/index.ts +++ b/hub/server/create-app/index.ts @@ -1,44 +1,20 @@ import express from "express" -import type { NextFunction, Request, Response } from "express" import type { Logger } from "pino" +import { handleError } from "../integrations/express/handle-error/index.ts" +import { respondNotFound } from "../integrations/express/respond-not-found/index.ts" import { createRequestLogger } from "../integrations/pino/create-request-logger/index.ts" +import { routes } from "../routes/index.ts" +/** Give every endpoint the same request logging and safe error responses. */ export function createApp({ logger }: { logger?: Logger } = {}) { const app = express() app.disable("x-powered-by") app.use(createRequestLogger(logger)) app.use(express.json()) - app.get("/api/health", (_request, response) => { - response.json({ status: "ok" }) - }) - - app.use((_request, response) => { - response.status(404).json({ error: "Not found" }) - }) - - // Express identifies error handlers by their four-argument signature. - // eslint-disable-next-line @typescript-eslint/no-unused-vars - function handleError(error: unknown, _request: Request, response: Response, _next: NextFunction) { - if (response.headersSent) { - response.destroy() - return - } - const status = - error !== null && - typeof error === "object" && - "status" in error && - typeof error.status === "number" && - Number.isInteger(error.status) && - error.status >= 400 && - error.status <= 599 - ? error.status - : 500 - response.status(status).json({ - error: status >= 500 ? "Internal server error" : "Invalid request", - }) - } + routes(app) + app.use(respondNotFound) app.use(handleError) return app diff --git a/hub/server/integrations/express/handle-error/constants.ts b/hub/server/integrations/express/handle-error/constants.ts new file mode 100644 index 00000000..a45e0ed1 --- /dev/null +++ b/hub/server/integrations/express/handle-error/constants.ts @@ -0,0 +1,3 @@ +import { z } from "zod" + +export const httpErrorSchema = z.object({ status: z.int().min(400).max(599) }) diff --git a/hub/server/integrations/express/handle-error/index.test.ts b/hub/server/integrations/express/handle-error/index.test.ts new file mode 100644 index 00000000..0d7eae81 --- /dev/null +++ b/hub/server/integrations/express/handle-error/index.test.ts @@ -0,0 +1,79 @@ +import { once } from "node:events" +import type { AddressInfo } from "node:net" +import express from "express" +import { describe, expect, it, onTestFinished, vi } from "vitest" + +import { handleError } from "." + +describe("handleError()", () => { + it.each([ + { name: "an unknown error", status: undefined, expectedStatus: 500 }, + { name: "an explicit server error", status: 503, expectedStatus: 503 }, + { name: "an invalid success status", status: 200, expectedStatus: 500 }, + ])("returns a generic JSON failure for $name", async ({ status, expectedStatus }) => { + vi.stubEnv("NODE_ENV", "development") + const app = express() + const error = Object.assign(new Error("private-error-message"), { status }) + error.stack = "private-error-stack" + app.get("/failure", () => { + throw error + }) + app.use(handleError) + const stderr = vi.spyOn(process.stderr, "write").mockImplementation(() => true) + const server = app.listen(0, "127.0.0.1") + onTestFinished( + () => + new Promise((resolve, reject) => { + server.closeAllConnections() + server.close((error) => (error ? reject(error) : resolve())) + }), + ) + await once(server, "listening") + const { port } = server.address() as AddressInfo + + const response = await fetch(`http://127.0.0.1:${port}/failure`) + + expect(response.status).toBe(expectedStatus) + expect(response.headers.get("content-type")).toMatch(/^application\/json\b/) + expect(await response.json()).toEqual({ error: "Internal server error" }) + expect(stderr).not.toHaveBeenCalled() + }) + + it("closes a started response without reporting the raw error", async () => { + vi.stubEnv("NODE_ENV", "development") + let failResponse: (() => void) | undefined + const failure = new Promise((resolve) => { + failResponse = resolve + }) + const app = express() + app.get("/stream", async (_request, response) => { + response.write("safe-stream-content") + await failure + throw new Error("private-stream-error") + }) + app.use(handleError) + const stderr = vi.spyOn(process.stderr, "write").mockImplementation(() => true) + const server = app.listen(0, "127.0.0.1") + onTestFinished( + () => + new Promise((resolve, reject) => { + server.closeAllConnections() + server.close((error) => (error ? reject(error) : resolve())) + }), + ) + await once(server, "listening") + const { port } = server.address() as AddressInfo + const response = await fetch(`http://127.0.0.1:${port}/stream`) + if (!response.body) throw new Error("Expected a streaming response") + const reader = response.body.getReader() + + expect(response.status).toBe(200) + const first = await reader.read() + expect(new TextDecoder().decode(first.value)).toBe("safe-stream-content") + if (!failResponse) throw new Error("Expected a response failure trigger") + failResponse() + + await expect(reader.read()).rejects.toThrow() + expect(stderr).not.toHaveBeenCalled() + }) +}) diff --git a/hub/server/integrations/express/handle-error/index.ts b/hub/server/integrations/express/handle-error/index.ts new file mode 100644 index 00000000..265e562e --- /dev/null +++ b/hub/server/integrations/express/handle-error/index.ts @@ -0,0 +1,24 @@ +import type { NextFunction, Request, Response } from "express" + +import { httpErrorSchema } from "./constants.ts" + +/** Keep raw request data and error details out of responses and Express's reporter. */ +export function handleError( + error: unknown, + _request: Request, + response: Response, + // Express identifies error handlers by their four-argument signature. + // eslint-disable-next-line @typescript-eslint/no-unused-vars + _next: NextFunction, +): void { + if (response.headersSent) { + response.destroy() + return + } + + const parsed = httpErrorSchema.safeParse(error) + const status = parsed.success ? parsed.data.status : 500 + response.status(status).json({ + error: status >= 500 ? "Internal server error" : "Invalid request", + }) +} diff --git a/hub/server/integrations/express/respond-not-found/index.ts b/hub/server/integrations/express/respond-not-found/index.ts new file mode 100644 index 00000000..3256dffb --- /dev/null +++ b/hub/server/integrations/express/respond-not-found/index.ts @@ -0,0 +1,6 @@ +import type { Request, Response } from "express" + +/** Return the API's JSON error rather than Express's HTML fallback. */ +export function respondNotFound(_request: Request, response: Response): void { + response.status(404).json({ error: "Not found" }) +} diff --git a/hub/server/routes/api/health/get/index.ts b/hub/server/routes/api/health/get/index.ts new file mode 100644 index 00000000..8026f06a --- /dev/null +++ b/hub/server/routes/api/health/get/index.ts @@ -0,0 +1,6 @@ +import type { Request, Response } from "express" + +/** Check that the API responds without requiring a database connection. */ +export function get(_request: Request, response: Response): void { + response.json({ status: "ok" }) +} diff --git a/hub/server/routes/index.ts b/hub/server/routes/index.ts new file mode 100644 index 00000000..e5216064 --- /dev/null +++ b/hub/server/routes/index.ts @@ -0,0 +1,8 @@ +import type { Express } from "express" + +import { get as handleApiHealthGet } from "./api/health/get/index.ts" + +/** Keep endpoint registration separate from the app's shared middleware. */ +export function routes(app: Express): void { + app.get("/api/health", handleApiHealthGet) +} From 024cade27b94cf842033429f2ff7baafb46288b6 Mon Sep 17 00:00:00 2001 From: Nishiki Liu Date: Tue, 27 Oct 2026 09:42:28 -0700 Subject: [PATCH 3/6] refactor(hub): flatten logging helpers and centralize safety limits Co-authored-by: Nishiki <1121087+nshki@users.noreply.github.com> --- hub/server/integrations/pino/constants.ts | 1 + .../integrations/pino/create-logger/index.ts | 20 +----- .../pino/create-request-logger/index.test.ts | 37 +---------- .../pino/create-request-logger/index.ts | 40 ++---------- .../pino/create-request-record/index.ts | 23 +++++++ .../pino/format-log-fields/constants.ts | 1 + .../pino/format-log-fields/index.ts | 22 +++++++ hub/server/integrations/pino/index.ts | 5 +- hub/server/integrations/pino/log/index.ts | 1 + .../pino/snapshot-request/index.ts | 20 ++++++ .../types.ts | 0 .../logging/sanitize-log-value/constants.ts | 8 +++ .../utils/logging/sanitize-log-value/index.ts | 64 ++---------------- .../utils/logging/visit-log-value/index.ts | 65 +++++++++++++++++++ .../utils/logging/visit-log-value/types.ts | 4 ++ 15 files changed, 166 insertions(+), 145 deletions(-) create mode 100644 hub/server/integrations/pino/constants.ts create mode 100644 hub/server/integrations/pino/create-request-record/index.ts create mode 100644 hub/server/integrations/pino/format-log-fields/constants.ts create mode 100644 hub/server/integrations/pino/format-log-fields/index.ts create mode 100644 hub/server/integrations/pino/snapshot-request/index.ts rename hub/server/integrations/pino/{create-request-logger => snapshot-request}/types.ts (100%) create mode 100644 hub/server/utils/logging/sanitize-log-value/constants.ts create mode 100644 hub/server/utils/logging/visit-log-value/index.ts create mode 100644 hub/server/utils/logging/visit-log-value/types.ts diff --git a/hub/server/integrations/pino/constants.ts b/hub/server/integrations/pino/constants.ts new file mode 100644 index 00000000..594034ca --- /dev/null +++ b/hub/server/integrations/pino/constants.ts @@ -0,0 +1 @@ +export const logLevels = ["trace", "debug", "info", "warn", "error", "fatal", "silent"] as const diff --git a/hub/server/integrations/pino/create-logger/index.ts b/hub/server/integrations/pino/create-logger/index.ts index 647fc7fe..57fe3a5b 100644 --- a/hub/server/integrations/pino/create-logger/index.ts +++ b/hub/server/integrations/pino/create-logger/index.ts @@ -1,30 +1,16 @@ import pino from "pino" -import { sanitizeLogValue } from "../../../utils/logging/sanitize-log-value/index.ts" +import { formatLogFields } from "../format-log-fields/index.ts" import type { LoggerOptions } from "./types.ts" +/** Apply one output and privacy policy to application and request logs. */ export function createLogger({ level = "info", destination }: LoggerOptions = {}) { return pino( { name: "replica-hub", level, formatters: { - log(fields) { - const result = Object.create(null) as Record - for (const key of Object.keys(fields).slice(0, 100)) { - const descriptor = Object.getOwnPropertyDescriptor(fields, key) - const value: unknown = - descriptor && "value" in descriptor ? descriptor.value : "[UNAVAILABLE]" - const safe = sanitizeLogValue({ [key]: value }) - if (safe !== null && typeof safe === "object" && !Array.isArray(safe)) { - Object.assign(result, safe) - } else { - result[key.slice(0, 128)] = safe - } - } - if (Object.keys(fields).length > 100) result.truncated = "[MAX FIELDS]" - return result - }, + log: formatLogFields, }, }, destination, diff --git a/hub/server/integrations/pino/create-request-logger/index.test.ts b/hub/server/integrations/pino/create-request-logger/index.test.ts index 581a9324..9c78c3a4 100644 --- a/hub/server/integrations/pino/create-request-logger/index.test.ts +++ b/hub/server/integrations/pino/create-request-logger/index.test.ts @@ -94,52 +94,21 @@ describe("createRequestLogger()", () => { ) }) - it.each([ - { statusCode: 399, level: 30 }, - { statusCode: 400, level: 40 }, - { statusCode: 499, level: 40 }, - { statusCode: 500, level: 50 }, - ])("logs status $statusCode once at level $level", async ({ statusCode, level }) => { + it("logs a server error once at error level", async () => { const records: Record[] = [] const logger = createLogger({ destination: { write: (line) => records.push(parseRecord(line)) }, }) const app = express() app.use(createRequestLogger(logger)) - app.get("/status", (_req, res) => res.status(statusCode).end()) + app.get("/status", (_req, res) => res.status(500).end()) const baseUrl = await listen(app) const response = await fetch(`${baseUrl}/status`) await response.arrayBuffer() await vi.waitFor(() => expect(records).toHaveLength(1)) - expect(records[0]).toMatchObject({ level, statusCode, outcome: "completed" }) - }) - - it("uses a null route for unmatched requests instead of exposing their URL", async () => { - const records: Record[] = [] - const logger = createLogger({ - destination: { write: (line) => records.push(parseRecord(line)) }, - }) - const app = express() - app.use(createRequestLogger(logger)) - app.use((_req, res) => res.status(404).json({ error: "Not found" })) - const baseUrl = await listen(app) - - const first = await fetch(`${baseUrl}/private-path-secret?token=query-secret`, { - headers: { "x-request-id": "same-incoming-id" }, - }) - await first.arrayBuffer() - const second = await fetch(`${baseUrl}/another-private-path-secret`, { - headers: { "x-request-id": "same-incoming-id" }, - }) - await second.arrayBuffer() - - await vi.waitFor(() => expect(records).toHaveLength(2)) - expect(records[0]).toMatchObject({ route: null, level: 40, statusCode: 404 }) - expect(records[1]).toMatchObject({ route: null, level: 40, statusCode: 404 }) - expect(first.headers.get("x-request-id")).not.toBe(second.headers.get("x-request-id")) - expect(JSON.stringify(records)).not.toMatch(/private-path-secret|query-secret|same-incoming-id/) + expect(records[0]).toMatchObject({ level: 50, statusCode: 500, outcome: "completed" }) }) it("lets an endpoint omit all payload fields without suppressing completion metadata", async () => { diff --git a/hub/server/integrations/pino/create-request-logger/index.ts b/hub/server/integrations/pino/create-request-logger/index.ts index 866c7626..13cada56 100644 --- a/hub/server/integrations/pino/create-request-logger/index.ts +++ b/hub/server/integrations/pino/create-request-logger/index.ts @@ -4,41 +4,15 @@ import type { Request, RequestHandler, Response } from "express" import type { Logger } from "pino" import { pinoHttp } from "pino-http" -import { sanitizeLogValue } from "../../../utils/logging/sanitize-log-value/index.ts" +import { createRequestRecord } from "../create-request-record/index.ts" import { logger } from "../index.ts" -import type { RequestSnapshot } from "./types.ts" +import { snapshotRequest } from "../snapshot-request/index.ts" +import type { RequestSnapshot } from "../snapshot-request/types.ts" +/** Log each request once, including parser failures and interrupted responses. */ export function createRequestLogger(target: Logger = logger): RequestHandler { const snapshots = new WeakMap() - function snapshot(request: Request): RequestSnapshot { - const route: unknown = request.route - const path = - route !== null && typeof route === "object" && "path" in route ? route.path : undefined - return { - route: typeof path === "string" ? path : null, - params: sanitizeLogValue(request.params), - query: sanitizeLogValue(request.query), - ...(request.is("application/json") && request.body !== undefined - ? { body: sanitizeLogValue(request.body) } - : {}), - } - } - - function record(request: Request, response: Response, responseTime: number) { - const captured = snapshots.get(response) ?? snapshot(request) - const completed = response.writableFinished && !request.readableAborted - const { route, ...payload } = captured - return { - method: request.method, - route, - statusCode: completed ? response.statusCode : null, - responseTime, - outcome: completed ? "completed" : "aborted", - ...(response.locals.omitLogPayload === true ? {} : payload), - } - } - const middleware = pinoHttp({ logger: target, quietReqLogger: true, @@ -66,10 +40,10 @@ export function createRequestLogger(target: Logger = logger): RequestHandler { return response.statusCode >= 400 ? "warn" : "info" }, customSuccessObject(request, response, value: { responseTime: number }) { - return record(request, response, value.responseTime) + return createRequestRecord(request, response, value.responseTime, snapshots.get(response)) }, customErrorObject(request, response, _error, value: { responseTime: number }) { - return record(request, response, value.responseTime) + return createRequestRecord(request, response, value.responseTime, snapshots.get(response)) }, customSuccessMessage(request, response) { return response.writableFinished && !request.readableAborted @@ -87,7 +61,7 @@ export function createRequestLogger(target: Logger = logger): RequestHandler { statusMessageOrHeaders?: string | OutgoingHttpHeaders | OutgoingHttpHeader[], headers?: OutgoingHttpHeaders | OutgoingHttpHeader[], ) { - snapshots.set(response, snapshot(request)) + snapshots.set(response, snapshotRequest(request)) return typeof statusMessageOrHeaders === "string" ? writeHead(statusCode, statusMessageOrHeaders, headers) : writeHead(statusCode, statusMessageOrHeaders) diff --git a/hub/server/integrations/pino/create-request-record/index.ts b/hub/server/integrations/pino/create-request-record/index.ts new file mode 100644 index 00000000..68ac75a9 --- /dev/null +++ b/hub/server/integrations/pino/create-request-record/index.ts @@ -0,0 +1,23 @@ +import type { Request, Response } from "express" + +import { snapshotRequest } from "../snapshot-request/index.ts" +import type { RequestSnapshot } from "../snapshot-request/types.ts" + +/** Keep completion metadata even when an endpoint excludes its payload. */ +export function createRequestRecord( + request: Request, + response: Response, + responseTime: number, + captured: RequestSnapshot = snapshotRequest(request), +) { + const completed = response.writableFinished && !request.readableAborted + const { route, ...payload } = captured + return { + method: request.method, + route, + statusCode: completed ? response.statusCode : null, + responseTime, + outcome: completed ? "completed" : "aborted", + ...(response.locals.omitLogPayload === true ? {} : payload), + } +} diff --git a/hub/server/integrations/pino/format-log-fields/constants.ts b/hub/server/integrations/pino/format-log-fields/constants.ts new file mode 100644 index 00000000..0dc42417 --- /dev/null +++ b/hub/server/integrations/pino/format-log-fields/constants.ts @@ -0,0 +1 @@ +export const maxLogFields = 100 diff --git a/hub/server/integrations/pino/format-log-fields/index.ts b/hub/server/integrations/pino/format-log-fields/index.ts new file mode 100644 index 00000000..0728376f --- /dev/null +++ b/hub/server/integrations/pino/format-log-fields/index.ts @@ -0,0 +1,22 @@ +import { maxLogKeyLength } from "../../../utils/logging/sanitize-log-value/constants.ts" +import { sanitizeLogValue } from "../../../utils/logging/sanitize-log-value/index.ts" + +import { maxLogFields } from "./constants.ts" + +/** Bound fields independently so a large payload cannot hide useful metadata. */ +export function formatLogFields(fields: Record): Record { + const result = Object.create(null) as Record + const keys = Object.keys(fields) + for (const key of keys.slice(0, maxLogFields)) { + const descriptor = Object.getOwnPropertyDescriptor(fields, key) + const value: unknown = descriptor && "value" in descriptor ? descriptor.value : "[UNAVAILABLE]" + const safe = sanitizeLogValue({ [key]: value }) + if (safe !== null && typeof safe === "object" && !Array.isArray(safe)) { + Object.assign(result, safe) + } else { + result[key.slice(0, maxLogKeyLength)] = safe + } + } + if (keys.length > maxLogFields) result.truncated = "[MAX FIELDS]" + return result +} diff --git a/hub/server/integrations/pino/index.ts b/hub/server/integrations/pino/index.ts index 174d9b98..37f7f657 100644 --- a/hub/server/integrations/pino/index.ts +++ b/hub/server/integrations/pino/index.ts @@ -1,10 +1,9 @@ import "dotenv/config" +import { logLevels } from "./constants.ts" import { createLogger } from "./create-logger/index.ts" -const level = (["trace", "debug", "info", "warn", "error", "fatal", "silent"] as const).find( - (candidate) => candidate === (process.env.LOG_LEVEL ?? "info"), -) +const level = logLevels.find((candidate) => candidate === (process.env.LOG_LEVEL ?? "info")) if (!level) { throw new Error("LOG_LEVEL must be trace, debug, info, warn, error, fatal, or silent.") } diff --git a/hub/server/integrations/pino/log/index.ts b/hub/server/integrations/pino/log/index.ts index 75bad992..77118f97 100644 --- a/hub/server/integrations/pino/log/index.ts +++ b/hub/server/integrations/pino/log/index.ts @@ -2,6 +2,7 @@ import type { Level, Logger } from "pino" import { logger } from "../index.ts" +/** Use the shared logging policy, with an optional request-scoped logger. */ export function log( level: Level, message: string, diff --git a/hub/server/integrations/pino/snapshot-request/index.ts b/hub/server/integrations/pino/snapshot-request/index.ts new file mode 100644 index 00000000..8a1b9d15 --- /dev/null +++ b/hub/server/integrations/pino/snapshot-request/index.ts @@ -0,0 +1,20 @@ +import type { Request } from "express" + +import { sanitizeLogValue } from "../../../utils/logging/sanitize-log-value/index.ts" + +import type { RequestSnapshot } from "./types.ts" + +/** Retain safe route data before Express restores a mounted router's parameters. */ +export function snapshotRequest(request: Request): RequestSnapshot { + const route: unknown = request.route + const path = + route !== null && typeof route === "object" && "path" in route ? route.path : undefined + return { + route: typeof path === "string" ? path : null, + params: sanitizeLogValue(request.params), + query: sanitizeLogValue(request.query), + ...(request.is("application/json") && request.body !== undefined + ? { body: sanitizeLogValue(request.body) } + : {}), + } +} diff --git a/hub/server/integrations/pino/create-request-logger/types.ts b/hub/server/integrations/pino/snapshot-request/types.ts similarity index 100% rename from hub/server/integrations/pino/create-request-logger/types.ts rename to hub/server/integrations/pino/snapshot-request/types.ts diff --git a/hub/server/utils/logging/sanitize-log-value/constants.ts b/hub/server/utils/logging/sanitize-log-value/constants.ts new file mode 100644 index 00000000..d15e3596 --- /dev/null +++ b/hub/server/utils/logging/sanitize-log-value/constants.ts @@ -0,0 +1,8 @@ +export const maxLogBytes = 8192 +export const maxLogDepth = 6 +export const maxLogEntries = 100 +export const maxLogStringLength = 2048 +export const maxLogKeyLength = 128 +export const truncationMarker = "[TRUNCATED]" +export const sensitiveLogKeyPattern = + /(password|passwd|passphrase|secret|token|authorization|cookie|apikey|privatekey|sessionid)/ diff --git a/hub/server/utils/logging/sanitize-log-value/index.ts b/hub/server/utils/logging/sanitize-log-value/index.ts index 5d756ca3..fd81e426 100644 --- a/hub/server/utils/logging/sanitize-log-value/index.ts +++ b/hub/server/utils/logging/sanitize-log-value/index.ts @@ -1,64 +1,12 @@ import { Buffer } from "node:buffer" +import { visitLogValue } from "../visit-log-value/index.ts" + +import { maxLogBytes } from "./constants.ts" import type { LogValue } from "./types.ts" +/** Copy structured data with secret-key redaction and bounded JSON output. */ export function sanitizeLogValue(value: unknown): LogValue { - const ancestors = new WeakSet() - const truncated = "[TRUNCATED]" - let entries = 0 - - function visit(input: unknown, depth: number): LogValue { - if (typeof input === "string") { - return input.length > 2048 ? `${input.slice(0, 2048 - truncated.length)}${truncated}` : input - } - if (input === null || typeof input === "boolean") return input - if (typeof input === "number") return Number.isFinite(input) ? input : "[NON-FINITE]" - if (typeof input !== "object") return "[UNSUPPORTED]" - if (ancestors.has(input)) return "[CIRCULAR]" - if (depth >= 6) return "[MAX DEPTH]" - if ( - !Array.isArray(input) && - !(input instanceof Error) && - Object.getPrototypeOf(input) !== Object.prototype && - Object.getPrototypeOf(input) !== null - ) { - return "[UNSUPPORTED OBJECT]" - } - - ancestors.add(input) - const output = Object.create(null) as Record - const array: LogValue[] = [] - if (input instanceof Error) output.type = "Error" - const keys = input instanceof Error ? ["name", "message", "stack", "code"] : Object.keys(input) - for (const key of keys) { - if (++entries > 100) { - if (Array.isArray(input)) array.push("[MAX ENTRIES]") - else output["[TRUNCATED]"] = "[MAX ENTRIES]" - break - } - const descriptor = Object.getOwnPropertyDescriptor(input, key) - if (!descriptor) continue - let result: LogValue - if ( - /(password|passwd|passphrase|secret|token|authorization|cookie|apikey|privatekey|sessionid)/.test( - key.toLowerCase().replace(/[^a-z0-9]/g, ""), - ) - ) { - result = "[REDACTED]" - } else if (descriptor && "value" in descriptor) { - result = visit(descriptor.value, depth + 1) - } else { - result = "[UNAVAILABLE]" - } - if (Array.isArray(input)) array.push(result) - else - output[key.length > 128 ? `${key.slice(0, 128 - truncated.length)}${truncated}` : key] = - result - } - ancestors.delete(input) - return Array.isArray(input) ? array : output - } - - const result = visit(value, 0) - return Buffer.byteLength(JSON.stringify(result)) <= 8192 ? result : "[OMITTED: MAX BYTES]" + const result = visitLogValue(value, 0, { ancestors: new WeakSet(), entries: 0 }) + return Buffer.byteLength(JSON.stringify(result)) <= maxLogBytes ? result : "[OMITTED: MAX BYTES]" } diff --git a/hub/server/utils/logging/visit-log-value/index.ts b/hub/server/utils/logging/visit-log-value/index.ts new file mode 100644 index 00000000..247eb881 --- /dev/null +++ b/hub/server/utils/logging/visit-log-value/index.ts @@ -0,0 +1,65 @@ +import { + maxLogDepth, + maxLogEntries, + maxLogKeyLength, + maxLogStringLength, + sensitiveLogKeyPattern, + truncationMarker, +} from "../sanitize-log-value/constants.ts" +import type { LogValue } from "../sanitize-log-value/types.ts" + +import type { LogTraversal } from "./types.ts" + +/** Share traversal limits across containers without invoking getters or toJSON(). */ +export function visitLogValue(input: unknown, depth: number, traversal: LogTraversal): LogValue { + if (typeof input === "string") { + return input.length > maxLogStringLength + ? `${input.slice(0, maxLogStringLength - truncationMarker.length)}${truncationMarker}` + : input + } + if (input === null || typeof input === "boolean") return input + if (typeof input === "number") return Number.isFinite(input) ? input : "[NON-FINITE]" + if (typeof input !== "object") return "[UNSUPPORTED]" + if (traversal.ancestors.has(input)) return "[CIRCULAR]" + if (depth >= maxLogDepth) return "[MAX DEPTH]" + if ( + !Array.isArray(input) && + !(input instanceof Error) && + Object.getPrototypeOf(input) !== Object.prototype && + Object.getPrototypeOf(input) !== null + ) { + return "[UNSUPPORTED OBJECT]" + } + + traversal.ancestors.add(input) + const output = Object.create(null) as Record + const array: LogValue[] = [] + if (input instanceof Error) output.type = "Error" + const keys = input instanceof Error ? ["name", "message", "stack", "code"] : Object.keys(input) + for (const key of keys) { + if (++traversal.entries > maxLogEntries) { + if (Array.isArray(input)) array.push("[MAX ENTRIES]") + else output[truncationMarker] = "[MAX ENTRIES]" + break + } + const descriptor = Object.getOwnPropertyDescriptor(input, key) + if (!descriptor) continue + let result: LogValue + if (sensitiveLogKeyPattern.test(key.toLowerCase().replace(/[^a-z0-9]/g, ""))) { + result = "[REDACTED]" + } else if ("value" in descriptor) { + result = visitLogValue(descriptor.value, depth + 1, traversal) + } else { + result = "[UNAVAILABLE]" + } + if (Array.isArray(input)) array.push(result) + else + output[ + key.length > maxLogKeyLength + ? `${key.slice(0, maxLogKeyLength - truncationMarker.length)}${truncationMarker}` + : key + ] = result + } + traversal.ancestors.delete(input) + return Array.isArray(input) ? array : output +} diff --git a/hub/server/utils/logging/visit-log-value/types.ts b/hub/server/utils/logging/visit-log-value/types.ts new file mode 100644 index 00000000..9446a8f0 --- /dev/null +++ b/hub/server/utils/logging/visit-log-value/types.ts @@ -0,0 +1,4 @@ +export interface LogTraversal { + ancestors: WeakSet + entries: number +} From c91d5b38a43ad4c1ecf813bd35e86e2f85010060 Mon Sep 17 00:00:00 2001 From: Nishiki Liu Date: Tue, 27 Oct 2026 09:42:37 -0700 Subject: [PATCH 4/6] docs(hub): simplify API logging guidance Co-authored-by: Nishiki <1121087+nshki@users.noreply.github.com> --- hub/docs/logging.md | 32 +++++++++++++++----------------- 1 file changed, 15 insertions(+), 17 deletions(-) diff --git a/hub/docs/logging.md b/hub/docs/logging.md index 09d3554d..a43618cb 100644 --- a/hub/docs/logging.md +++ b/hub/docs/logging.md @@ -1,12 +1,12 @@ # API logging -Hub writes newline-delimited JSON to stdout through the shared logger in `server/integrations/pino/index.ts`. `LOG_LEVEL` sets the minimum severity and defaults to `info`. Allowed values are `trace`, `debug`, `info`, `warn`, `error`, `fatal`, and `silent`; an invalid value prevents startup. +Hub writes one JSON object per line to stdout through `server/integrations/pino/index.ts`. `LOG_LEVEL` sets the minimum severity: `trace`, `debug`, `info` (default), `warn`, `error`, `fatal`, or `silent`. Invalid values prevent startup. -Log collection, access, retention, and deployment configuration are outside this integration. Logs can contain private information even after key redaction. Treat access to logs accordingly. +Logs can still contain private information after redaction. Operators must restrict access and configure collection and retention separately. ## Application events -Import the explicit logging function from its directory: +Use `log()` for application events: ```ts import { log } from "../integrations/pino/log/index.ts" @@ -14,36 +14,34 @@ import { log } from "../integrations/pino/log/index.ts" log("info", "Build imported", { buildId }) ``` -Pass structured fields rather than interpolating user input into messages. Keep messages static and never put credentials, raw requests, or private content into a message or stack trace. Sensitive values in free text cannot be reliably detected. +Keep messages short and static. Pass data as structured fields, not message text. Redaction matches keys; it cannot detect secrets in free text, including messages and stacks. -Handlers can use `request.log.info({ buildId }, "Build imported")` to include the request ID automatically. The helper also accepts a request logger as its fourth argument: `log("info", "Build imported", { buildId }, request.log)`. +In handlers, use `request.log.info({ buildId }, "Build imported")` to include the request ID, or pass `request.log` as the fourth argument to `log()`. -Utilities cannot import integrations. Repositories and other integrations must receive a logger explicitly if they need one; domains and HTTP setup may import the Pino integration. Do not bind request payloads with `logger.child()` or `setBindings()`: arbitrary Pino bindings do not pass through the structured-field sanitizer. +Follow the [import boundaries](backend-architecture.md#import-boundaries). Repositories and other integrations must receive a logger rather than import Pino's shared instance. Never put payloads in `logger.child()` or `setBindings()`: those fields bypass sanitization. ## Automatic HTTP records -`createApp()` registers `createRequestLogger()` once, before JSON parsing and routes. Every request gets a server-generated UUID returned in `X-Request-Id`; incoming request ID headers are not trusted. Body parsing accepts JSON with Express's default 100 KiB limit. +`createApp()` installs request logging before JSON parsing and routes. Every endpoint inherits it. Each request gets a server-generated UUID in the `X-Request-Id` response header; incoming IDs are ignored. -The middleware emits one terminal record with `reqId`, `method`, `route`, `statusCode`, `responseTime` in milliseconds, and `outcome`. Completed responses below 400 use `info`, 4xx use `warn`, and 5xx or connection errors use `error`. An unfinished connection uses `outcome: "aborted"` and `statusCode: null`, even if headers were already sent. +Each request produces one final record with `reqId`, `method`, `route`, `statusCode`, `responseTime` (milliseconds), and `outcome`. Responses below 400 use `info`, 4xx use `warn`, and 5xx or connection errors use `error`. Interrupted responses have `outcome: "aborted"` and `statusCode: null`. -`route` is the handler's Express route template, such as `/builds/:id`, or `null` for an unmatched request. For mounted routers it is relative to the mount: Express exposes concrete mount values, not a safe complete template. The middleware captures route parameters when headers are written, before Express can restore outer-router parameters. It also captures the sanitized query and parsed JSON body at that point. Later mutations during a streaming response do not change the snapshot. +`route` is the handler's template, such as `/builds/:id`, or `null` when unmatched. Mounted routers use a relative template to avoid exposing actual mount values. Sanitized parameters, query fields, and parsed JSON bodies are copied when headers are sent, before Express clears route data. -Automatic records omit raw URLs, headers, cookies, raw or malformed bodies, uploads, response bodies, and error messages or stacks. Parser errors receive a generic JSON error response. Errors after headers are sent close the connection rather than sending raw errors to Express's default reporter. +Automatic records exclude raw URLs, headers, cookies, uploads, response bodies, and error details. JSON parsing uses Express's default 100 KiB limit; rejected bodies are not logged. The Express error handler returns generic JSON errors, or closes the connection if headers were sent, without exposing raw errors. -An endpoint handling sensitive content can exclude all payload fields before sending its response: +For private free text or other sensitive payloads, exclude all payload fields before sending a response: ```ts response.locals.omitLogPayload = true ``` -This omits `params`, `query`, and `body`, but retains the method, route template, request ID, timing, and outcome. +This omits `params`, `query`, and `body` while keeping request metadata. ## Structured-field safety -The shared logger sanitizes structured event fields, including fields passed to `request.log`. Request snapshots use the same sanitizer without mutating the request. +Application fields, `request.log` fields, and automatic payloads share the same sanitizer. It copies data without changing the request or invoking getters or custom serialization methods. -Sensitive keys are replaced with `[REDACTED]`. Matching ignores case and punctuation and covers keys containing password, passwd, passphrase, secret, token, authorization, cookie, API key, private key, or session ID. The sanitizer visits nested objects and arrays; it does not search arbitrary string values for secrets. Endpoint authors must exclude payloads containing private free text or fields not covered by those key rules. +Keys containing password, passwd, passphrase, secret, token, authorization, cookie, API key, private key, or session ID become `[REDACTED]`. Matching ignores case and punctuation and includes nested objects and arrays. Exclude payloads whose sensitive fields do not match these rules. -Each top-level structured field is limited to 8 KiB of serialized JSON, six nesting levels, 100 visited entries, and 2,048 characters per string. Field names are capped at 128 characters. An event includes at most 100 caller-supplied top-level fields, plus a truncation marker when that limit is exceeded. Explicit markers identify redaction, truncation, cycles, unavailable getters, unsupported values, and oversized fields. The limits apply to structured fields, not Pino's message or custom bindings. Use short, static messages. - -The sanitizer copies ordinary objects, arrays, and Error data properties without invoking getters or custom `toJSON()` methods. Unsupported object instances are omitted with a marker. These bounds prevent log payloads from growing without limit; they are not a substitute for input validation or endpoint-specific privacy decisions. +Structured fields have [size, depth, and entry limits](../server/utils/logging/sanitize-log-value/constants.ts); Pino also [caps top-level fields](../server/integrations/pino/format-log-fields/constants.ts). Markers replace truncated data, cycles, getters, and unsupported values. These limits do not apply to messages or custom bindings and do not replace endpoint validation or privacy decisions. From a74d4cc6488f9e03013ce3647c630a000b80affb Mon Sep 17 00:00:00 2001 From: Nishiki Liu Date: Tue, 27 Oct 2026 09:49:12 -0700 Subject: [PATCH 5/6] test(hub): wait for preview selection message Wait for the iframe message rather than assuming it follows the button state synchronously. Co-authored-by: Nishiki <1121087+nshki@users.noreply.github.com> --- .../prototype-canvas/tests/improvement-notes.test.tsx | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/hub/app/javascript/application/prototype-canvas/tests/improvement-notes.test.tsx b/hub/app/javascript/application/prototype-canvas/tests/improvement-notes.test.tsx index 0dadbac5..f0ece573 100644 --- a/hub/app/javascript/application/prototype-canvas/tests/improvement-notes.test.tsx +++ b/hub/app/javascript/application/prototype-canvas/tests/improvement-notes.test.tsx @@ -469,11 +469,13 @@ describe("App()", () => { await waitFor(() => expect(annotate).toBeEnabled()) const post = vi.spyOn(frame.contentWindow!, "postMessage") fireEvent.click(annotate) - await waitFor(() => expect(annotate).toHaveAttribute("aria-pressed", "true")) - expect(post).toHaveBeenCalledWith( - { type: "replica:canvas:select", nonce, mode: "improvement" }, - previewOrigin, + await waitFor(() => + expect(post).toHaveBeenCalledWith( + { type: "replica:canvas:select", nonce, mode: "improvement" }, + previewOrigin, + ), ) + expect(annotate).toHaveAttribute("aria-pressed", "true") expect(screen.queryByRole("complementary", { name: copy.notes })).not.toBeInTheDocument() receive(frame, { type: "replica:canvas:selected", anchor }, "https://unrelated.example") From 02b0ff98c4f66dd7c0cd5671b84f95943735a51e Mon Sep 17 00:00:00 2001 From: Nishiki Liu Date: Tue, 27 Oct 2026 09:57:36 -0700 Subject: [PATCH 6/6] refactor(hub): remove top-level log field cap Co-authored-by: Nishiki <1121087+nshki@users.noreply.github.com> --- hub/docs/logging.md | 2 +- .../pino/create-logger/index.test.ts | 18 ------------------ .../pino/format-log-fields/constants.ts | 1 - .../pino/format-log-fields/index.ts | 6 +----- 4 files changed, 2 insertions(+), 25 deletions(-) delete mode 100644 hub/server/integrations/pino/format-log-fields/constants.ts diff --git a/hub/docs/logging.md b/hub/docs/logging.md index a43618cb..a32eb149 100644 --- a/hub/docs/logging.md +++ b/hub/docs/logging.md @@ -44,4 +44,4 @@ Application fields, `request.log` fields, and automatic payloads share the same Keys containing password, passwd, passphrase, secret, token, authorization, cookie, API key, private key, or session ID become `[REDACTED]`. Matching ignores case and punctuation and includes nested objects and arrays. Exclude payloads whose sensitive fields do not match these rules. -Structured fields have [size, depth, and entry limits](../server/utils/logging/sanitize-log-value/constants.ts); Pino also [caps top-level fields](../server/integrations/pino/format-log-fields/constants.ts). Markers replace truncated data, cycles, getters, and unsupported values. These limits do not apply to messages or custom bindings and do not replace endpoint validation or privacy decisions. +Structured fields have [size, depth, and entry limits](../server/utils/logging/sanitize-log-value/constants.ts). Markers replace truncated data, cycles, getters, and unsupported values. These limits do not apply to messages or custom bindings and do not replace endpoint validation or privacy decisions. diff --git a/hub/server/integrations/pino/create-logger/index.test.ts b/hub/server/integrations/pino/create-logger/index.test.ts index 9643d1ce..41c34c1c 100644 --- a/hub/server/integrations/pino/create-logger/index.test.ts +++ b/hub/server/integrations/pino/create-logger/index.test.ts @@ -95,22 +95,4 @@ describe("createLogger()", () => { expect(record).toHaveProperty("oversized") expect(Buffer.byteLength(JSON.stringify(record.oversized), "utf8")).toBeLessThanOrEqual(8192) }) - - it("limits the number of caller-supplied top-level fields to 100", () => { - const lines: string[] = [] - const logger = createLogger({ destination: { write: (line) => lines.push(line) } }) - const fields = Object.fromEntries( - Array.from({ length: 120 }, (_, index) => [`field${index}`, index]), - ) - - logger.info(fields, "Many fields") - - expect(lines).toHaveLength(1) - const record = parseRecord(lines.join("")) - expect(record).toMatchObject({ field0: 0, msg: "Many fields" }) - expect(Object.keys(record).filter((key) => /^field\d+$/.test(key)).length).toBeLessThanOrEqual( - 100, - ) - expect(record).not.toHaveProperty("field119") - }) }) diff --git a/hub/server/integrations/pino/format-log-fields/constants.ts b/hub/server/integrations/pino/format-log-fields/constants.ts deleted file mode 100644 index 0dc42417..00000000 --- a/hub/server/integrations/pino/format-log-fields/constants.ts +++ /dev/null @@ -1 +0,0 @@ -export const maxLogFields = 100 diff --git a/hub/server/integrations/pino/format-log-fields/index.ts b/hub/server/integrations/pino/format-log-fields/index.ts index 0728376f..4527a3a1 100644 --- a/hub/server/integrations/pino/format-log-fields/index.ts +++ b/hub/server/integrations/pino/format-log-fields/index.ts @@ -1,13 +1,10 @@ import { maxLogKeyLength } from "../../../utils/logging/sanitize-log-value/constants.ts" import { sanitizeLogValue } from "../../../utils/logging/sanitize-log-value/index.ts" -import { maxLogFields } from "./constants.ts" - /** Bound fields independently so a large payload cannot hide useful metadata. */ export function formatLogFields(fields: Record): Record { const result = Object.create(null) as Record - const keys = Object.keys(fields) - for (const key of keys.slice(0, maxLogFields)) { + for (const key of Object.keys(fields)) { const descriptor = Object.getOwnPropertyDescriptor(fields, key) const value: unknown = descriptor && "value" in descriptor ? descriptor.value : "[UNAVAILABLE]" const safe = sanitizeLogValue({ [key]: value }) @@ -17,6 +14,5 @@ export function formatLogFields(fields: Record): Record maxLogFields) result.truncated = "[MAX FIELDS]" return result }