Skip to content

B1: structured request access log middleware#402

Open
MrTravisB wants to merge 1 commit intomainfrom
travis/pilo-request-logging
Open

B1: structured request access log middleware#402
MrTravisB wants to merge 1 commit intomainfrom
travis/pilo-request-logging

Conversation

@MrTravisB
Copy link
Copy Markdown
Collaborator

Summary

First PR in Stack B (server observability). Builds on Stack A's taskId
propagation (#389).

Adds a Hono middleware that emits one structured JSON log line per HTTP
request, capturing only metadata: {level, msg, method, route, status, duration_ms, taskId?}. Pulls taskId from the x-pilo-task-id response
header set by the SSE/WS routes in A1, so log lines correlate with the
task they served.

Data sensitivity (enforced by tests)

The middleware never logs:

  • Full URL or query string (would leak tokens, search terms, page paths)
  • Request body (would leak task, data, guardrails, credentials)
  • Request headers (auth tokens, cookies)
  • Client IP (PII in EU)

Sentinel tests assert that a sentinel string placed in the URL query, body,
Authorization header, or Cookie header never appears in any log line.
The matched-route pattern (e.g. /users/:id) is logged instead of the
concrete path (/users/abc123).

Changes

  • packages/server/src/middleware/requestLog.ts - new middleware
  • packages/server/src/index.ts - register middleware after Sentry + CORS,
    before routes
  • packages/server/test/middleware/requestLog.test.ts - 11 tests covering
    log shape, sensitive-data exclusions, taskId propagation, status codes,
    and structured-line invariant

Sample log line

{"level":"info","msg":"request","method":"POST","route":"/pilo/run","status":200,"duration_ms":12,"taskId":"3f29...e0d4"}

For SSE responses, duration_ms is the time until the handler returns the
streaming Response (typically a few ms), not the full task duration.
Per-task duration metrics are Stack C's territory.

Test plan

  • pnpm --filter pilo-server run test (94 passing: 83 prior + 11 new)
  • pnpm --filter pilo-core run test (still green)
  • pnpm run typecheck green
  • pnpm run format:check green

Notes

  • Base: main
  • B2 next: Sentry scrubber + tags + breadcrumbs
  • B3 after: concurrency limit + 429 backpressure
  • The A4 leak canary still passes; the requestLog tests add an additional
    layer of sentinel coverage for the middleware itself

Copy link
Copy Markdown
Collaborator

@lmorchard lmorchard left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants