Label HTTP metrics with the chi route pattern (closes #254) #258

Merged
clawbot merged 1 commits from issue-254-metrics-route-pattern into next 2026-08-24 01:32:45 +02:00
Collaborator

Closes #254.

The defect

Middleware.Metrics called std.Handler("", ...). An empty handler id is go-http-metrics' signal to substitute reporter.URLPath(), so the handler label carried the concrete request path. Every distinct /webhook/<uuid> minted a permanent label set, and the entrypoint UUID — the receiver's only credential — was published verbatim in the scrape.

Why the pattern could not just be passed in

The recorder is global middleware (Server.setupGlobalMiddleware), so it is entered before chi has matched anything, and Middleware.Measure fixes its handler id up front, before calling the wrapped handler. Reading RoutePattern() at that point yields "" for every request — which would collapse every series into one bucket and look like a pass.

What the library does hand over unchanged is the request context, on every recorder call, and the duration and size observations happen in a defer after the wrapped handler returns. That context holds the same *chi.Context pointer routing mutates in place. It is the same point accessLogURL already reads the pattern from, and the same one the Sentry scrub uses.

So the fix is a metrics.Recorder decorator that rewrites props.ID from the route context at record time. std.Handler and its responseWriterInterceptor are untouched, so status-code and byte capture are unchanged (pinned by TestMetrics_StatusAndSizeStillRecorded).

Decisions this makes

Unmatched routes carry the existing unmatchedRoute sentinel, (unmatched) — the same fixed value the access log already uses for a path that matched nothing. Pinned by TestMetrics_UnmatchedPathsCollapseToTheSentinel over two path shapes (no matching prefix, and a receiver-prefixed path with too many segments), and verified live below.

http_requests_inflight gets a fixed handler="(all)", not a pattern. The gauge is incremented before routing and decremented after, and the pattern exists only between those two moments — a route-derived label would increment one series and decrement another, leaving every pattern permanently off by the number of requests it served. One aggregate series, counting requests in flight across the service; TestMetrics_InflightGaugeIsAggregateAndBalanced pins that it balances back to zero. This is the one observable behaviour change beyond the label domain, and it is called out here rather than buried.

The handler id passed to std.Handler is the sentinel rather than "", so the client-chosen URL path never enters the metrics pipeline at all. The decorator overwrites it on every observation; if the decorator were ever removed the metrics would collapse to one series rather than start leaking again.

Verification

make check green, GOFLAGS=-count=1, lint in Docker (0 issues., 56s, not cached). All 20 packages ok with no (cached) lines.

Six new tests in internal/middleware/metrics_test.go, on a router whose ordering mirrors the real server's — recorder global, receiver rate limiter route-level. Five of the six were confirmed to FAIL against the unfixed recorder before being kept.

Live probe, the one from the issue. Server built from this branch's parent, then from this branch, METRICS_USERNAME/METRICS_PASSWORD set, 3,000 unauthenticated POSTs to distinct invented entrypoint UUIDs per flood.

parent (next) this branch
baseline scrape 107 series, 12,899 B 106 series, 12,816 B
after 3,000 distinct paths 78,132 series, 10,655,997 B 181 series, 20,907 B
after 3,000 more 78,132 (never evicted) 181 — flat
distinct handler labels 3,002 4
UUID-shaped strings in scrape 78,000 0
RSS 19 MB

The four labels after the flood are /webhook/{uuid}, /metrics, /.well-known/healthcheck and (all).

Rate-limited path, explicitly. 4,800 of the driven requests were rejected 429 by the route-level receiver limiter. All of them landed on the pattern — 25 series total, every one handler="/webhook/{uuid}":

http_request_duration_seconds_count{code="429",handler="/webhook/{uuid}",method="POST",service=""} 4800

Unmatched-route flood, live. 50 requests to distinct /<uuid> paths added the (unmatched) label and took the scrape to 206 series; a further 200 requests to distinct /<uuid>/x paths left it at 206 series, 5 handler labels, 0 UUIDs.

TODO.md deliberately untouched, per #112.

Closes https://git.eeqj.de/sneak/webhooker/issues/254. ## The defect `Middleware.Metrics` called `std.Handler("", ...)`. An empty handler id is `go-http-metrics`' signal to substitute `reporter.URLPath()`, so the `handler` label carried the concrete request path. Every distinct `/webhook/<uuid>` minted a permanent label set, and the entrypoint UUID — the receiver's only credential — was published verbatim in the scrape. ## Why the pattern could not just be passed in The recorder is global middleware (`Server.setupGlobalMiddleware`), so it is entered before chi has matched anything, and `Middleware.Measure` fixes its handler id up front, before calling the wrapped handler. Reading `RoutePattern()` at that point yields `""` for every request — which would collapse every series into one bucket and look like a pass. What the library does hand over unchanged is the request context, on every recorder call, and the duration and size observations happen in a `defer` after the wrapped handler returns. That context holds the same `*chi.Context` pointer routing mutates in place. It is the same point `accessLogURL` already reads the pattern from, and the same one the Sentry scrub uses. So the fix is a `metrics.Recorder` decorator that rewrites `props.ID` from the route context at record time. `std.Handler` and its `responseWriterInterceptor` are untouched, so status-code and byte capture are unchanged (pinned by `TestMetrics_StatusAndSizeStillRecorded`). ## Decisions this makes **Unmatched routes** carry the existing `unmatchedRoute` sentinel, `(unmatched)` — the same fixed value the access log already uses for a path that matched nothing. Pinned by `TestMetrics_UnmatchedPathsCollapseToTheSentinel` over two path shapes (no matching prefix, and a receiver-prefixed path with too many segments), and verified live below. **`http_requests_inflight` gets a fixed `handler="(all)"`**, not a pattern. The gauge is incremented before routing and decremented after, and the pattern exists only between those two moments — a route-derived label would increment one series and decrement another, leaving every pattern permanently off by the number of requests it served. One aggregate series, counting requests in flight across the service; `TestMetrics_InflightGaugeIsAggregateAndBalanced` pins that it balances back to zero. This is the one observable behaviour change beyond the label domain, and it is called out here rather than buried. **The handler id passed to `std.Handler` is the sentinel rather than `""`**, so the client-chosen URL path never enters the metrics pipeline at all. The decorator overwrites it on every observation; if the decorator were ever removed the metrics would collapse to one series rather than start leaking again. ## Verification `make check` green, `GOFLAGS=-count=1`, lint in Docker (`0 issues.`, 56s, not cached). All 20 packages `ok` with no `(cached)` lines. Six new tests in `internal/middleware/metrics_test.go`, on a router whose ordering mirrors the real server's — recorder global, receiver rate limiter route-level. Five of the six were confirmed to FAIL against the unfixed recorder before being kept. **Live probe, the one from the issue.** Server built from this branch's parent, then from this branch, `METRICS_USERNAME`/`METRICS_PASSWORD` set, 3,000 unauthenticated POSTs to distinct invented entrypoint UUIDs per flood. | | parent (`next`) | this branch | |---|---|---| | baseline scrape | 107 series, 12,899 B | 106 series, 12,816 B | | after 3,000 distinct paths | **78,132 series, 10,655,997 B** | **181 series, 20,907 B** | | after 3,000 more | 78,132 (never evicted) | **181 — flat** | | distinct `handler` labels | 3,002 | 4 | | UUID-shaped strings in scrape | 78,000 | **0** | | RSS | — | 19 MB | The four labels after the flood are `/webhook/{uuid}`, `/metrics`, `/.well-known/healthcheck` and `(all)`. **Rate-limited path, explicitly.** 4,800 of the driven requests were rejected 429 by the route-level receiver limiter. All of them landed on the pattern — 25 series total, every one `handler="/webhook/{uuid}"`: ``` http_request_duration_seconds_count{code="429",handler="/webhook/{uuid}",method="POST",service=""} 4800 ``` **Unmatched-route flood, live.** 50 requests to distinct `/<uuid>` paths added the `(unmatched)` label and took the scrape to 206 series; a further 200 requests to distinct `/<uuid>/x` paths left it at 206 series, 5 handler labels, 0 UUIDs. `TODO.md` deliberately untouched, per https://git.eeqj.de/sneak/webhooker/issues/112.
clawbot added 1 commit 2026-08-24 01:19:46 +02:00
Label HTTP metrics with the chi route pattern (closes #254)
All checks were successful
check / check (push) Successful in 3m1s
6e26885349
The metrics recorder labelled its `handler` dimension with the
concrete request path, so every distinct /webhook/<uuid> minted a
permanent label set that nothing ever evicted. Measured on this
branch's parent: a scrape went from 106 series and 12 KB to 78,132
series and 10.7 MB after 3,000 unauthenticated POSTs to invented
entrypoint UUIDs, and stayed there. It also published those UUIDs --
the receiver's only credential -- verbatim in the scrape.

The label now comes from chi's route pattern. It cannot be supplied
as go-http-metrics' handler id: the recorder is global middleware, so
it is entered before chi has matched anything, and the library fixes
the id up front. What the library does pass through unchanged is the
request context, on every recorder call, and the duration and size
observations happen after the wrapped handler returns -- the same
point accessLogURL already reads the pattern from. So a recorder
decorator rewrites the id there instead. std.Handler and its
response-writer interceptor are untouched, so status and size capture
are unchanged.

Recording after the whole chain returns is what makes this hold for
requests the route-level receiver limiter rejects, which were the
majority of the leaked series: chi has matched the route before the
limiter runs, so a 429 carries the pattern like any other response.

A path matching no route carries the existing unmatchedRoute
sentinel, the same fixed value the access log uses.

http_requests_inflight cannot carry a pattern -- it is incremented
before routing and decremented after, so a route-derived label would
increment one series and decrement another and leave the gauge
permanently wrong. It gets a fixed aggregate label instead.

Verified against a live instance: 6,000 distinct receiver paths and
250 unmatched paths across two floods left the scrape at 206 series
and 21 KB, flat between floods, with no UUID anywhere in the output
and all 4,800 429s on the single pattern.
clawbot added the needs-review label 2026-08-24 01:19:55 +02:00
clawbot self-assigned this 2026-08-24 01:19:57 +02:00
Author
Collaborator

PASS. Independently reproduced and verified: parent 107 -> 62,532 series / 2,402 handler labels / 62,400 UUID-shaped strings; this branch 106 -> 206 series / 5 labels / 0 UUIDs, flat across a second flood, all 704 429s on handler="/webhook/{uuid}". Aliasing assumption checked against chi v1.5.5 source (rctx installed by Mux.ServeHTTP before any Use middleware, pool.Put only after the chain returns, sub-routers reuse the same pointer) and under -race with 1,280 concurrent requests plus concurrent Gather() — clean. make check green from a clean clone, GOFLAGS=-count=1, 88s, 20 packages ok, zero (cached), lint 0 issues. in 49.5s. Both declared decisions ruled sound: the (unmatched) sentinel cannot be spoofed (the label never derives from the path), and per-route inflight is genuinely unreachable through RecorderMeasure binds the decrement's args at defer time, so it would resolve after routing while the increment resolved before it.

Anomalies and disclosures, none blocking:

  1. Pre-existing, not this PR's to fix, but it leaves #254's headline only partly closed. The method label is still r.Method verbatim, and net/http accepts any RFC token. Against this branch's build, 300 requests to / with random 12-character method tokens took the scrape from 106 to 7,631 series (~25 permanent series per distinct token), never evicted, unauthenticated, on a route with no rate limiter. Every DoD bullet in the issue is satisfied — this is a different label, untouched by this diff — but the unbounded-growth vector the issue title names survives. Suggest a follow-up issue rather than scope creep here.

  2. When a sub-router-level middleware answers before the child route matches (RequireAuth, CSRF), the label is the parent mount's wildcard — /pages/*, /source/{sourceID}/*, /sources/* — not the full pattern. Correct and bounded by the route table, and consistent with accessLogURL; noted because it is surprising. Requests that reach the child do get the full pattern (verified live: /pages/login -> handler="/pages/login").

  3. Fail-first claim spot-checked by removing the decorator in a throwaway clone: exactly 5 of 6 fail, TestMetrics_StatusAndSizeStillRecorded passes both ways — as its comment says, it is a regression guard, not a fail-first test.

  4. The http_requests_inflight semantics change is documented in the PR body and the code but not in README's Metrics section, which is where the same cardinality argument is made for the delivery metrics.

  5. Nits, non-blocking: middleware.MetricsMiddlewareForTest stutters; UnmatchedRouteConst/InflightHandlerConst diverge from the file's existing ...ForTest convention; routePatternID duplicates the RouteContext/RoutePattern/sentinel logic in accessLogURL, which could now call it.

Disclosure. Committed internal/middleware/metrics.go was read in full and confirmed free of substitution damage: tree clean, fmt-check and lint green, and a revert/restore round-trip left git status empty. The decorator removal and a scratch concurrency test were done in a separate throwaway clone, never in the PR tree; both were reverted and that clone is clean. CI green on 6e26885 (3m1s); head is one commit on origin/next, fast-forward. No Claude/Anthropic references anywhere.

**PASS.** Independently reproduced and verified: parent 107 -&gt; 62,532 series / 2,402 `handler` labels / 62,400 UUID-shaped strings; this branch 106 -&gt; 206 series / 5 labels / 0 UUIDs, flat across a second flood, all 704 429s on `handler="/webhook/{uuid}"`. Aliasing assumption checked against chi v1.5.5 source (rctx installed by `Mux.ServeHTTP` before any `Use` middleware, `pool.Put` only after the chain returns, sub-routers reuse the same pointer) and under `-race` with 1,280 concurrent requests plus concurrent `Gather()` — clean. `make check` green from a clean clone, `GOFLAGS=-count=1`, 88s, 20 packages `ok`, zero `(cached)`, lint `0 issues.` in 49.5s. Both declared decisions ruled sound: the `(unmatched)` sentinel cannot be spoofed (the label never derives from the path), and per-route inflight is genuinely unreachable through `Recorder` — `Measure` binds the decrement's args at `defer` time, so it would resolve after routing while the increment resolved before it. Anomalies and disclosures, none blocking: 1. **Pre-existing, not this PR's to fix, but it leaves https://git.eeqj.de/sneak/webhooker/issues/254's headline only partly closed.** The `method` label is still `r.Method` verbatim, and `net/http` accepts any RFC token. Against **this branch's** build, 300 requests to `/` with random 12-character method tokens took the scrape from 106 to 7,631 series (~25 permanent series per distinct token), never evicted, unauthenticated, on a route with no rate limiter. Every DoD bullet in the issue is satisfied — this is a different label, untouched by this diff — but the unbounded-growth vector the issue title names survives. Suggest a follow-up issue rather than scope creep here. 2. When a sub-router-level middleware answers before the child route matches (`RequireAuth`, `CSRF`), the label is the parent mount's wildcard — `/pages/*`, `/source/{sourceID}/*`, `/sources/*` — not the full pattern. Correct and bounded by the route table, and consistent with `accessLogURL`; noted because it is surprising. Requests that reach the child do get the full pattern (verified live: `/pages/login` -&gt; `handler="/pages/login"`). 3. Fail-first claim spot-checked by removing the decorator in a throwaway clone: exactly 5 of 6 fail, `TestMetrics_StatusAndSizeStillRecorded` passes both ways — as its comment says, it is a regression guard, not a fail-first test. 4. The `http_requests_inflight` semantics change is documented in the PR body and the code but not in README's Metrics section, which is where the same cardinality argument is made for the delivery metrics. 5. Nits, non-blocking: `middleware.MetricsMiddlewareForTest` stutters; `UnmatchedRouteConst`/`InflightHandlerConst` diverge from the file's existing `...ForTest` convention; `routePatternID` duplicates the RouteContext/RoutePattern/sentinel logic in `accessLogURL`, which could now call it. **Disclosure.** Committed `internal/middleware/metrics.go` was read in full and confirmed free of substitution damage: tree clean, `fmt-check` and lint green, and a revert/restore round-trip left `git status` empty. The decorator removal and a scratch concurrency test were done in a separate throwaway clone, never in the PR tree; both were reverted and that clone is clean. CI green on `6e26885` (3m1s); head is one commit on `origin/next`, fast-forward. No Claude/Anthropic references anywhere.
clawbot merged commit 0082f216fa into next 2026-08-24 01:32:45 +02:00
clawbot deleted branch issue-254-metrics-route-pattern 2026-08-24 01:32:45 +02:00
Sign in to join this conversation.
No Reviewers
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: sneak/webhooker#258