v0.1: Request logging, Prometheus metrics, graceful shutdown #4

Closed
opened 2026-07-18 20:17:23 +00:00 by Cordy · 1 comment
Owner

The server currently logs one startup line and nothing else. For dogfooding on the monitored cluster (Prometheus + Grafana + Alertmanager already in place):

  • Request logging middleware: method, path, status, duration, bytes, username — structured via the existing slog
  • /metrics Prometheus endpoint (stdlib-friendly: hand-rolled counters/histograms or the official client lib — decide and note the dependency trade-off in ARCHITECTURE.md)
  • Minimum metric set: request count/duration by route+status, bytes uploaded/downloaded, active WebDAV vs REST split, storage errors by type
  • Graceful shutdown (http.Server + signal handling) — currently ListenAndServe with no drain, which will show up as 502s during rolling updates on k3s

Then a homelab-alerts rule for CairnDown can join the existing alert groups.

The server currently logs one startup line and nothing else. For dogfooding on the monitored cluster (Prometheus + Grafana + Alertmanager already in place): - [ ] Request logging middleware: method, path, status, duration, bytes, username — structured via the existing `slog` - [ ] `/metrics` Prometheus endpoint (stdlib-friendly: hand-rolled counters/histograms or the official client lib — decide and note the dependency trade-off in ARCHITECTURE.md) - [ ] Minimum metric set: request count/duration by route+status, bytes uploaded/downloaded, active WebDAV vs REST split, storage errors by type - [ ] Graceful shutdown (`http.Server` + signal handling) — currently `ListenAndServe` with no drain, which will show up as 502s during rolling updates on k3s Then a `homelab-alerts` rule for CairnDown can join the existing alert groups.
Author
Owner

Implemented and pushed to main:

Metricsinternal/obs/metrics.go: hand-rolled Prometheus text-exposition registry (stdlib only, dependency count stays at one; rationale in the package comment). Exposed unauthenticated at /metrics (aggregate counters only, no file/user data). Metrics: cairn_http_requests_total{route,method,code}, cairn_http_request_duration_seconds histogram per route, request/response byte totals, cairn_build_info, cairn_start_time_seconds. Route label is a bounded class (api/dav/ui/health/metrics/share — never raw paths) and unknown HTTP verbs clamp to OTHER, so cardinality can't be inflated by hostile clients.

Request logginginternal/obs/middleware.go: outermost middleware, one slog line per request (method, path, status, dur_ms, bytes in/out, user, remote). Sees auth 401s; /healthz probes are counted in metrics but excluded from logs (probe noise). Username is recovered from the inner auth layer via a context-recorder bridge in internal/auth/context.go.

Graceful shutdownhttp.Server + SIGTERM/SIGINT handling, 15s bounded drain, ReadHeaderTimeout set. k8s rollouts no longer surface as connection resets.

Bonus fix (found by the new logging!) — first request logged dur_ms=785: HTTP Basic re-sends credentials every request, so every request paid full argon2 cost. Added a memory-only verified-credentials cache (SHA-256 fingerprint, only populated after argon2 accepts; wrong-password and unknown-user timings stay equally slow, so no new timing oracle). Verified: first request ~850ms, subsequent 0ms.

ServiceMonitor added to the staged homelab-config PR (k3s/cairn/servicemonitor.yaml) so Prometheus scrapes Cairn the moment it's dogfooded — includes a note on checking the serviceMonitorSelector label if metrics don't appear.

Remaining from this issue: a CairnDown alert rule in homelab-alerts once the dogfood deployment is live (needs the scrape working first).

Tests: obs route-classing, render, middleware capture; auth fast-path cache. Full suite green; smoke-tested metrics output, log lines, and SIGTERM drain end to end.

Implemented and pushed to main: **Metrics** — `internal/obs/metrics.go`: hand-rolled Prometheus text-exposition registry (stdlib only, dependency count stays at one; rationale in the package comment). Exposed unauthenticated at `/metrics` (aggregate counters only, no file/user data). Metrics: `cairn_http_requests_total{route,method,code}`, `cairn_http_request_duration_seconds` histogram per route, request/response byte totals, `cairn_build_info`, `cairn_start_time_seconds`. Route label is a bounded class (api/dav/ui/health/metrics/share — never raw paths) and unknown HTTP verbs clamp to `OTHER`, so cardinality can't be inflated by hostile clients. **Request logging** — `internal/obs/middleware.go`: outermost middleware, one slog line per request (method, path, status, dur_ms, bytes in/out, user, remote). Sees auth 401s; `/healthz` probes are counted in metrics but excluded from logs (probe noise). Username is recovered from the inner auth layer via a context-recorder bridge in `internal/auth/context.go`. **Graceful shutdown** — `http.Server` + SIGTERM/SIGINT handling, 15s bounded drain, `ReadHeaderTimeout` set. k8s rollouts no longer surface as connection resets. **Bonus fix (found by the new logging!)** — first request logged `dur_ms=785`: HTTP Basic re-sends credentials every request, so *every* request paid full argon2 cost. Added a memory-only verified-credentials cache (SHA-256 fingerprint, only populated after argon2 accepts; wrong-password and unknown-user timings stay equally slow, so no new timing oracle). Verified: first request ~850ms, subsequent 0ms. **ServiceMonitor** added to the staged homelab-config PR (`k3s/cairn/servicemonitor.yaml`) so Prometheus scrapes Cairn the moment it's dogfooded — includes a note on checking the `serviceMonitorSelector` label if metrics don't appear. Remaining from this issue: a `CairnDown` alert rule in `homelab-alerts` once the dogfood deployment is live (needs the scrape working first). Tests: obs route-classing, render, middleware capture; auth fast-path cache. Full suite green; smoke-tested metrics output, log lines, and SIGTERM drain end to end.
Cordy closed this issue 2026-07-19 01:27:19 +00:00
Sign in to join this conversation.
No labels
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference: Cordy/Cairn#4
No description provided.