Decisions

ADR-016: HTTP access middleware — shape, route template, panic composition

ADR-002 chose `log/slog` and ADR-003 chose JSON-line output; the Phase 1 library in [`pkg/observ`](https://github.com/gyrum-labs/gyrum-go/tree/main/pkg/observ) already provides build identity, a redacting JSON handler,…

#016

ADR-016: HTTP access middleware — shape, route template, panic composition

Status: Accepted Date: 2026-04-21

Context

ADR-002 chose log/slog and ADR-003 chose JSON-line output; the Phase 1 library in pkg/observ already provides build identity, a redacting JSON handler, and a chainable error wrapper. What every gyrum HTTP service still writes by hand is the request-scoped glue: generating or inheriting a request id, attaching a pre-bound logger, emitting an access log on completion, capturing panics. Until this is centralised, services drift: request_id is X-Request-ID in one service and x-correlation-id in another; "access log" is a free-form log.Printf here and an enriched slog there; a panic kills the process in one service and quietly 500s in another.

Phase 2 of the observability rollout introduces metrics (2b) and a DB wrapper (2c). Both read a route template — a bounded-cardinality label (/api/v1/reports/:id), not the instantiated path (/api/v1/reports/42) — as a dimension. ADR-005 is explicit that high-cardinality label values fragment Loki streams and explode Prometheus series; picking the wrong label here bakes a cardinality foot-gun into every dashboard downstream. The access middleware is therefore the natural choke-point: it sees every request, it's the first place where request_id and route are both known, and it's where status/latency are measured.

The library lives in gyrum-go/pkg/observ; the existing gyrum-go/pkg/middleware already ships a Recovery() middleware that log.Printfs panics and 500s. Two panic recoveries in one chain would race on WriteHeader and produce contradictory logs; the composition story has to be explicit.

Decision

Add observ.Access() as a func(http.Handler) http.Handler middleware that:

  1. Resolves request_id from an incoming X-Request-ID header if it matches [0-9a-f]{8,64}, else generates a 16-hex value from crypto/rand. Invalid headers are dropped with a DEBUG log line (charset hygiene is not an operator concern). The resolved id is written to the response header and pre-bound onto the request's context logger.
  2. Pre-binds a *slog.Logger onto r.Context() carrying service, version, commit, release_track (from Phase 1), plus request_id and method. Handlers call observ.FromContext(r.Context()) to log at request scope with zero boilerplate.
  3. Emits two log lines per request: http.request.started at INFO on entry, http.request.completed on exit (INFO for 1xx/2xx/3xx/4xx, ERROR for 5xx). Completion lines carry http_status (the unbounded field), status_class (the bounded label1xx/2xx/3xx/4xx/5xx/unknown), latency_ms, bytes_written, and route.
  4. Reads the route template from context. observ.WithRoute(ctx, pattern) publishes it, observ.Route(ctx) reads it, and observ.WithRouteMiddleware(pattern, handler) is a convenient wrapper for stdlib http.ServeMux (Go 1.22+) or routers without a pattern accessor. For chi/gorilla, a small adapter calls WithRoute on the request context. When no pattern is attached, the middleware falls back to the literal request path and emits a one-time WARN per process — enough to surface the cardinality risk to the operator, quiet enough not to drown the log.
  5. Recovers panics and logs at ERROR with err_category=internal (ADR-006), a debug.Stack() capture under the stack field, and a 500 response if one was not already written. When OBSERV_ACCESS_RERAISE=1, the panic is re-raised after logging so an outer recovery middleware (e.g. gyrum-go/pkg/middleware.Recovery) can still observe it.

Composition rule with pkg/middleware.Recovery: exactly one of the two handles each panic. The service picks by env var. Default (RERAISE unset) — observ.Access is the terminal handler. Set OBSERV_ACCESS_RERAISE=1observ.Access logs then re-raises; place middleware.Recovery outside (earlier in the chain) to catch it.

The shape of the decision: this PR ships Phase 2a — access middleware plus route-template propagation — and nothing else. Phase 2b (Prometheus metrics) and Phase 2c (database/sql wrapper) layer on top without changing these signatures.

Consequences

  • Every gyrum service gets consistent access logs for free. observ.Access() is a single line in the middleware chain. The observability-standards.md reserved-field-names table (request_id, route, http_status, latency_ms) becomes a library contract, not a manual checklist.
  • Route template is the bounded-cardinality label for Phase 2b. Prometheus http_requests_total{service,status_class,route} can be wired against the same Route(ctx) API without another round of refactoring. Services that do not wire WithRouteMiddleware today still get access logs (literal path fallback + WARN); they opt into bounded metric labels by wiring the pattern when they want metrics. The WARN is the nudge.
  • Two recovery middlewares can coexist but only one runs the log. The OBSERV_ACCESS_RERAISE switch trades a slightly sharper default (no re-panic, quieter error path) for a "can integrate with existing middleware.Recovery chains" escape hatch. Services migrating from the older chain can flip the env var during transition, then remove middleware.Recovery once confident.
  • X-Request-ID validation is strict. [0-9a-f]{8,64} rejects UUID-with-dashes and uppercase hex. This is deliberate: downstream correlation tools dedupe case-sensitively, and accepting variant encodings makes trace joins lossy. The tradeoff is a small DEBUG log line for services emitting UUID formatted request ids into a gyrum service — they need to hex-normalise at their edge. gyrum-go/pkg/middleware.RequestID (which generates bare hex today) is already compliant.
  • No metrics dependency yet. Phase 2a deliberately avoids prometheus/client_golang. Services that wire Access() today pay zero extra binary size for code they won't use until 2b. 2b will provide a separate pkg/observ/metrics subpackage wired via a second middleware that consumes the same context (route, status_class) — no refactor required.
  • The route field is resolved AFTER the handler runs, because inner per-route middleware (WithRouteMiddleware) publishes the pattern only once the mux has dispatched. The http.request.started line therefore does not carry route; the http.request.completed and http.request.panic lines do. This is a readability cost (the entry line is slightly less useful on its own) paid in exchange for being a chain middleware that wraps the mux instead of wrapping every route.

Alternatives considered

  • Handler-wrap-per-route (no chain middleware). Each route manually calls observ.Access(handler, "/api/v1/reports/:id"). Rejected — enforces the pattern at the call site but drifts vs the route registry the moment a developer mounts a route without the wrapper. The WARN-on-missing approach in the chosen design detects drift at runtime and is visible in logs, which is the correct feedback loop. Also, per-route wrapping prevents the access-log from wrapping middleware that runs before routing (auth, rate-limit) — their timings would be invisible to the completion line.
  • Observability at the router layer (library per router). A chi middleware, a gorilla middleware, etc. Rejected — forces a router lock-in (or a maintenance matrix across chi, gorilla, echo, fiber, stdlib). The context-based contract decouples the observability library from the router choice: any router that exposes the matched pattern can adapt in ten lines. We provide the stdlib adapter (WithRouteMiddleware) as the reference implementation; chi users write a three-line adapter against chi.RouteContext(r.Context()).RoutePattern() and are done.
  • Single monolithic middleware (access + metrics + DB wrapper). Ship everything in one middleware. Rejected — drags in prometheus/client_golang for every service that only wants access logs. Phase 2a needs to land without expanding the dep-tree of services that aren't ready for metrics yet; the sub-package split keeps the phased rollout honest. It also lets each sub-package be tested in isolation; mixing concerns would couple the access-log tests to Prometheus registry state.
  • Generate request_id without validating incoming headers. Always mint a fresh one; ignore the header. Rejected — breaks the trace-join story with upstream proxies (Cloudflare, ALB) that already set a correlation id. Validate-and-inherit is the right default; the charset regex is the guardrail against cardinality abuse. Accept the minor transition cost for services emitting dashed-UUID request ids: they normalise at their edge or opt into the library's 16-hex format.
  • err_category enforcement as a compile-time enum. Make Category(CategoryInternal) the only way to tag a panic. Rejected for the same reason ADR-006 rejected it for the general error path: an enum update breaks every consumer on library upgrade. Panic tagging is internal to the middleware anyway — the convention is enforced by us, not by the API surface.
  • Emit route on the started line via lazy resolution. Capture a thunk that reads the route holder when slog materialises the record. Rejected — slog's lazy-value API (slog.Any with a LogValuer) works, but the resulting code hides a very non-obvious control flow (the attribute is cheap to read here, surprising over there) behind a library-internal seam. The readability cost (route is missing from one of two lines) is smaller than the maintenance cost of a lazy attribute that future contributors will misread.

Supersedes: none Superseded by: