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

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.

internal/middleware/export_test.go

@@ -4,8 +4,28 @@ import (
 	"context"
 	"net/http"
 	"time"
+
+	httpmetrics "github.com/slok/go-http-metrics/metrics"
 )
 
+// MetricsMiddlewareForTest builds the metrics recording middleware
+// against a caller-supplied recorder, so a test can gather from its
+// own Prometheus registry rather than the process-wide default one
+// that Middleware.Metrics uses.
+func MetricsMiddlewareForTest(
+	rec httpmetrics.Recorder,
+) func(http.Handler) http.Handler {
+	return metricsMiddleware(rec)
+}
+
+// UnmatchedRouteConst exposes the sentinel that stands in for a
+// request matching no route pattern.
+const UnmatchedRouteConst = unmatchedRoute
+
+// InflightHandlerConst exposes the fixed handler label on the
+// inflight gauge.
+const InflightHandlerConst = inflightHandler
+
 // NewLoggingResponseWriterForTest wraps newLoggingResponseWriter
 // for use in external test packages.
 func NewLoggingResponseWriterForTest(

internal/middleware/metrics.go

@@ -0,0 +1,135 @@
+package middleware
+
+import (
+	"context"
+	"net/http"
+	"time"
+
+	"github.com/go-chi/chi"
+	httpmetrics "github.com/slok/go-http-metrics/metrics"
+	prommetrics "github.com/slok/go-http-metrics/metrics/prometheus"
+	ghmm "github.com/slok/go-http-metrics/middleware"
+	"github.com/slok/go-http-metrics/middleware/std"
+)
+
+// inflightHandler is the fixed `handler` label on
+// http_requests_inflight, the one HTTP metric here that cannot carry
+// a route pattern.
+//
+// The gauge is incremented before the wrapped handler runs and
+// decremented after it returns, and the pattern only exists between
+// those two moments. Deriving the label from the route would
+// therefore increment one series and decrement another, leaving every
+// pattern permanently off by the number of requests it served — a
+// broken gauge, on top of the per-path cardinality this file exists
+// to remove. So the gauge is deliberately aggregate: one series,
+// counting the requests in flight across the whole service.
+const inflightHandler = "(all)"
+
+// routePatternID is the `handler` label for a request: the chi route
+// pattern, never the concrete path.
+//
+// The pattern is what bounds the label's domain to the routes the
+// service registers. The path does not bound it at all — every byte
+// after /webhook/ is client-chosen, so labelling by path lets any
+// unauthenticated client mint permanent series at will, and publishes
+// the entrypoint UUID (the receiver's only credential) in the scrape
+// while doing it.
+//
+// chi populates the route context during routeHTTP, so this is only
+// valid once routing has run. Every caller below is on the recording
+// side of the middleware, which go-http-metrics defers until after
+// the wrapped handler returns.
+func routePatternID(ctx context.Context) string {
+	if rc := chi.RouteContext(ctx); rc != nil {
+		if pattern := rc.RoutePattern(); pattern != "" {
+			return pattern
+		}
+	}
+
+	return unmatchedRoute
+}
+
+// routePatternRecorder wraps a go-http-metrics recorder and replaces
+// the handler id on every observation with the request's route
+// pattern.
+//
+// This is the seam that makes the pattern usable at all. The metrics
+// middleware is global (see Server.setupGlobalMiddleware), so it is
+// entered before chi has matched anything, and go-http-metrics fixes
+// its handler id up front — passing the pattern in as that id is not
+// possible, and leaving the id empty makes the library substitute the
+// raw URL path, which is the defect. What the library does hand over
+// is the request context, unchanged, on each recorder call; that
+// context carries the same *chi.Context pointer routing mutates in
+// place, and the duration and size calls happen after the wrapped
+// handler has returned. Reading the pattern there is what the access
+// log already does in accessLogURL.
+//
+// Recording after the whole chain returns is also what makes this
+// hold for requests the route-level receiver rate limiter rejects.
+// Those never reach a handler, but chi has already matched the route
+// by the time the limiter runs, so their 429s land on the pattern
+// like any other response.
+type routePatternRecorder struct {
+	inner httpmetrics.Recorder
+}
+
+func (r routePatternRecorder) ObserveHTTPRequestDuration(
+	ctx context.Context,
+	props httpmetrics.HTTPReqProperties,
+	duration time.Duration,
+) {
+	props.ID = routePatternID(ctx)
+	r.inner.ObserveHTTPRequestDuration(ctx, props, duration)
+}
+
+func (r routePatternRecorder) ObserveHTTPResponseSize(
+	ctx context.Context,
+	props httpmetrics.HTTPReqProperties,
+	sizeBytes int64,
+) {
+	props.ID = routePatternID(ctx)
+	r.inner.ObserveHTTPResponseSize(ctx, props, sizeBytes)
+}
+
+func (r routePatternRecorder) AddInflightRequests(
+	ctx context.Context,
+	props httpmetrics.HTTPProperties,
+	quantity int,
+) {
+	props.ID = inflightHandler
+	r.inner.AddInflightRequests(ctx, props, quantity)
+}
+
+var _ httpmetrics.Recorder = routePatternRecorder{}
+
+// Metrics returns middleware that records Prometheus HTTP metrics on
+// the default registry, which is the one the /metrics route gathers.
+func (s *Middleware) Metrics() func(http.Handler) http.Handler {
+	return metricsMiddleware(
+		prommetrics.NewRecorder(prommetrics.Config{}),
+	)
+}
+
+// metricsMiddleware builds the recording middleware against a given
+// recorder, so tests can gather from a registry of their own instead
+// of the process-wide default.
+func metricsMiddleware(
+	rec httpmetrics.Recorder,
+) func(http.Handler) http.Handler {
+	mdlw := ghmm.New(ghmm.Config{
+		Recorder: routePatternRecorder{inner: rec},
+	})
+
+	return func(next http.Handler) http.Handler {
+		// The handler id is unmatchedRoute rather than "" so that
+		// the client-chosen URL path never enters the metrics
+		// pipeline at all: an empty id is the library's signal to
+		// substitute it. routePatternRecorder overwrites this value
+		// on every observation, so it is reachable only if that
+		// decorator is removed — in which case the metrics collapse
+		// to one series instead of leaking again.
+		return std.Handler(unmatchedRoute, mdlw, next)
+	}
+}

internal/middleware/metrics_test.go

@@ -0,0 +1,434 @@
+package middleware_test
+
+import (
+	"log/slog"
+	"net/http"
+	"net/http/httptest"
+	"strings"
+	"testing"
+
+	"github.com/go-chi/chi"
+	"github.com/google/uuid"
+	"github.com/prometheus/client_golang/prometheus"
+	dto "github.com/prometheus/client_model/go"
+	prommetrics "github.com/slok/go-http-metrics/metrics/prometheus"
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+	"sneak.berlin/go/webhooker/internal/config"
+	"sneak.berlin/go/webhooker/internal/middleware"
+)
+
+const (
+	// metricsProbePaths is how many distinct receiver paths each
+	// cardinality assertion drives. The defect these tests pin cost
+	// roughly 26 permanent series per distinct path, so a couple of
+	// hundred puts a regression thousands of series over the bound
+	// rather than leaving it to a rounding argument.
+	metricsProbePaths = 250
+
+	// receiverRoutePattern is the one handler label every receiver
+	// request must produce, however the client varies the path.
+	receiverRoutePattern = "/webhook/{uuid}"
+
+	// okRoute is a static route used to pin that the response-writer
+	// interceptor still reports status and size after the handler id
+	// stopped coming from the URL.
+	okRoute = "/ok"
+
+	// okBody is what okRoute writes, so the recorded response size is
+	// a number the test knows.
+	okBody = "ok"
+
+	// generousReceiverLimit is a per-entrypoint receiver limit high
+	// enough that no probe in this file trips the limiter unless it
+	// means to.
+	generousReceiverLimit = 100000
+
+	// tightReceiverLimit forces the receiver's aggregate limiter to
+	// reject: the aggregate ceiling is ten times this, so a probe of
+	// metricsProbePaths requests spends it many times over.
+	tightReceiverLimit = 1
+)
+
+// metricsTestRouter builds a router whose middleware ordering mirrors
+// the real server's: the metrics recorder is GLOBAL, installed by
+// Server.setupGlobalMiddleware before chi has matched anything, and
+// the receiver rate limiter is ROUTE-LEVEL, installed by
+// Server.setupWebhookRoutes inside it. That ordering is the whole
+// defect, so a test that flattens it would prove nothing.
+//
+// The recorder writes to a registry of the test's own rather than the
+// process-wide default one, so each test observes only its own
+// traffic.
+func metricsTestRouter(
+	t *testing.T,
+	receiverLimit int,
+) (http.Handler, *prometheus.Registry) {
+	t.Helper()
+
+	log := slog.New(slog.DiscardHandler)
+	cfg := &config.Config{
+		Environment:       "prod",
+		ReceiverRateLimit: receiverLimit,
+	}
+	m := middleware.NewForTest(
+		log, cfg, newTestSessionManager(cfg, log, nil),
+	)
+
+	reg := prometheus.NewRegistry()
+	rec := prommetrics.NewRecorder(prommetrics.Config{Registry: reg})
+
+	r := chi.NewRouter()
+	r.Use(middleware.MetricsMiddlewareForTest(rec))
+
+	r.Get(okRoute, func(w http.ResponseWriter, _ *http.Request) {
+		_, _ = w.Write([]byte(okBody))
+	})
+
+	// The real receiver answers 404 for a UUID naming no stored
+	// entrypoint, which is what every invented path here is.
+	r.With(m.ReceiverRateLimit()).HandleFunc(
+		receiverRoutePattern,
+		func(w http.ResponseWriter, _ *http.Request) {
+			w.WriteHeader(http.StatusNotFound)
+		},
+	)
+
+	return r, reg
+}
+
+// drivePaths sends one POST per supplied path and returns how many
+// responses carried each status code.
+func drivePaths(
+	t *testing.T,
+	h http.Handler,
+	paths []string,
+) map[int]int {
+	t.Helper()
+
+	codes := make(map[int]int)
+
+	for _, p := range paths {
+		req := httptest.NewRequestWithContext(
+			t.Context(), http.MethodPost, p, nil,
+		)
+		w := httptest.NewRecorder()
+		h.ServeHTTP(w, req)
+		codes[w.Code]++
+	}
+
+	return codes
+}
+
+// receiverPaths returns n distinct /webhook/ paths, each naming a
+// fresh UUID exactly as an unauthenticated flood would.
+func receiverPaths(n int) []string {
+	paths := make([]string, 0, n)
+
+	for range n {
+		paths = append(paths, "/webhook/"+uuid.NewString())
+	}
+
+	return paths
+}
+
+// gatherMetrics returns the registry's current families, failing the
+// test if gathering does.
+func gatherMetrics(
+	t *testing.T,
+	reg *prometheus.Registry,
+) []*dto.MetricFamily {
+	t.Helper()
+
+	families, err := reg.Gather()
+	require.NoError(t, err)
+
+	return families
+}
+
+// labelValue returns the named label from a gathered metric.
+func labelValue(m *dto.Metric, name string) string {
+	for _, pair := range m.GetLabel() {
+		if pair.GetName() == name {
+			return pair.GetValue()
+		}
+	}
+
+	return ""
+}
+
+// handlerLabels returns the set of distinct `handler` label values
+// across every gathered series.
+func handlerLabels(families []*dto.MetricFamily) map[string]struct{} {
+	seen := make(map[string]struct{})
+
+	for _, fam := range families {
+		for _, m := range fam.GetMetric() {
+			seen[labelValue(m, "handler")] = struct{}{}
+		}
+	}
+
+	return seen
+}
+
+// seriesCount is the number of distinct label sets held across every
+// family: the quantity that grew without bound and was never
+// reclaimed.
+func seriesCount(families []*dto.MetricFamily) int {
+	total := 0
+
+	for _, fam := range families {
+		total += len(fam.GetMetric())
+	}
+
+	return total
+}
+
+// keys returns the members of a set, for assertion messages.
+func keys(set map[string]struct{}) []string {
+	out := make([]string, 0, len(set))
+
+	for k := range set {
+		out = append(out, k)
+	}
+
+	return out
+}
+
+// TestMetrics_DistinctReceiverPathsMintOneLabelSet is the direct
+// assertion the issue asks for: N requests to N distinct
+// /webhook/<uuid> paths must produce exactly ONE handler label, the
+// route pattern. Before the fix this produced N of them.
+func TestMetrics_DistinctReceiverPathsMintOneLabelSet(t *testing.T) {
+	t.Parallel()
+
+	h, reg := metricsTestRouter(t, generousReceiverLimit)
+
+	paths := receiverPaths(metricsProbePaths)
+	codes := drivePaths(t, h, paths)
+	require.Equal(
+		t, metricsProbePaths, codes[http.StatusNotFound],
+		"every invented UUID should have reached the receiver",
+	)
+
+	families := gatherMetrics(t, reg)
+	labels := handlerLabels(families)
+
+	assert.Equal(
+		t,
+		map[string]struct{}{
+			receiverRoutePattern:            {},
+			middleware.InflightHandlerConst: {},
+		},
+		labels,
+		"receiver traffic must collapse onto the route pattern",
+	)
+
+	// The scrape must not republish the UUIDs it was driven with.
+	// They are the receiver's only credential.
+	for _, p := range paths {
+		id := strings.TrimPrefix(p, "/webhook/")
+		for label := range labels {
+			assert.NotContains(
+				t, label, id,
+				"an entrypoint UUID reached a metrics label",
+			)
+		}
+	}
+}
+
+// TestMetrics_SeriesCountIsFlatUnderAFlood pins the property the
+// issue measured against a live instance: driving thousands more
+// distinct paths must not add series. The first batch establishes
+// every label set the route can produce; the second must land on
+// exactly those.
+func TestMetrics_SeriesCountIsFlatUnderAFlood(t *testing.T) {
+	t.Parallel()
+
+	h, reg := metricsTestRouter(t, generousReceiverLimit)
+
+	drivePaths(t, h, receiverPaths(metricsProbePaths))
+	before := seriesCount(gatherMetrics(t, reg))
+
+	drivePaths(t, h, receiverPaths(metricsProbePaths*4))
+	after := seriesCount(gatherMetrics(t, reg))
+
+	assert.Equal(
+		t, before, after,
+		"a flood of distinct paths must not mint series",
+	)
+}
+
+// TestMetrics_RateLimitedRequestsCarryTheRoutePattern covers the
+// majority case: most of the leaked series were 429s. Those requests
+// never reach a handler, so they take a different path through the
+// stack — but chi has already matched the route by the time the
+// route-level limiter rejects them, and the recording happens after
+// the whole chain returns, so they must land on the pattern too.
+func TestMetrics_RateLimitedRequestsCarryTheRoutePattern(t *testing.T) {
+	t.Parallel()
+
+	h, reg := metricsTestRouter(t, tightReceiverLimit)
+
+	codes := drivePaths(t, h, receiverPaths(metricsProbePaths))
+	require.Positive(
+		t, codes[http.StatusTooManyRequests],
+		"the probe must actually exhaust the aggregate limiter",
+	)
+
+	families := gatherMetrics(t, reg)
+
+	assert.Equal(
+		t,
+		map[string]struct{}{
+			receiverRoutePattern:            {},
+			middleware.InflightHandlerConst: {},
+		},
+		handlerLabels(families),
+		"rejected requests must collapse onto the route pattern",
+	)
+
+	rejected := 0
+
+	for _, fam := range families {
+		for _, m := range fam.GetMetric() {
+			if labelValue(m, "code") != "429" {
+				continue
+			}
+
+			rejected++
+
+			assert.Equal(
+				t, receiverRoutePattern,
+				labelValue(m, "handler"),
+				"a 429 series carried a non-pattern handler",
+			)
+		}
+	}
+
+	assert.Positive(
+		t, rejected, "no 429 series was recorded at all",
+	)
+}
+
+// TestMetrics_UnmatchedPathsCollapseToTheSentinel decides and pins the
+// unmatched-route case. A path matching no route has no pattern, so
+// it carries the same fixed sentinel the access log uses. Without
+// that, an unmatched flood leaks exactly as the receiver did.
+func TestMetrics_UnmatchedPathsCollapseToTheSentinel(t *testing.T) {
+	t.Parallel()
+
+	h, reg := metricsTestRouter(t, generousReceiverLimit)
+
+	paths := make([]string, 0, metricsProbePaths)
+
+	for i := range metricsProbePaths {
+		id := uuid.NewString()
+
+		// Two shapes: one matching no prefix at all, and one under
+		// the receiver prefix but with a segment count the pattern
+		// cannot match.
+		if i%2 == 0 {
+			paths = append(paths, "/"+id)
+		} else {
+			paths = append(paths, "/webhook/"+id+"/"+id)
+		}
+	}
+
+	codes := drivePaths(t, h, paths)
+	require.Equal(
+		t, metricsProbePaths, codes[http.StatusNotFound],
+		"every probe path should have gone unmatched",
+	)
+
+	labels := handlerLabels(gatherMetrics(t, reg))
+
+	assert.Equal(
+		t,
+		map[string]struct{}{
+			middleware.UnmatchedRouteConst:  {},
+			middleware.InflightHandlerConst: {},
+		},
+		labels,
+		"unmatched paths must collapse onto one sentinel, got %v",
+		keys(labels),
+	)
+}
+
+// TestMetrics_InflightGaugeIsAggregateAndBalanced pins the one metric
+// that cannot carry a pattern. It is incremented before routing and
+// decremented after, so it gets a fixed label -- and the two calls
+// must therefore agree, leaving the gauge at zero once the traffic
+// has drained rather than stuck above it.
+func TestMetrics_InflightGaugeIsAggregateAndBalanced(t *testing.T) {
+	t.Parallel()
+
+	h, reg := metricsTestRouter(t, generousReceiverLimit)
+
+	drivePaths(t, h, receiverPaths(metricsProbePaths))
+
+	var inflight []*dto.Metric
+
+	for _, fam := range gatherMetrics(t, reg) {
+		if strings.HasSuffix(fam.GetName(), "requests_inflight") {
+			inflight = fam.GetMetric()
+		}
+	}
+
+	require.Len(
+		t, inflight, 1,
+		"the inflight gauge must hold exactly one series",
+	)
+	assert.Equal(
+		t, middleware.InflightHandlerConst,
+		labelValue(inflight[0], "handler"),
+	)
+	assert.InDelta(
+		t, 0.0, inflight[0].GetGauge().GetValue(), 0.0,
+		"the gauge must balance back to zero",
+	)
+}
+
+// TestMetrics_StatusAndSizeStillRecorded guards the response-writer
+// interceptor the recording middleware wraps around every request.
+// The handler label changed; what the interceptor reports must not
+// have.
+func TestMetrics_StatusAndSizeStillRecorded(t *testing.T) {
+	t.Parallel()
+
+	h, reg := metricsTestRouter(t, generousReceiverLimit)
+
+	req := httptest.NewRequestWithContext(
+		t.Context(), http.MethodGet, okRoute, nil,
+	)
+	w := httptest.NewRecorder()
+	h.ServeHTTP(w, req)
+
+	require.Equal(t, http.StatusOK, w.Code)
+	require.Equal(t, okBody, w.Body.String())
+
+	var size *dto.Metric
+
+	for _, fam := range gatherMetrics(t, reg) {
+		if !strings.HasSuffix(fam.GetName(), "response_size_bytes") {
+			continue
+		}
+
+		for _, m := range fam.GetMetric() {
+			if labelValue(m, "handler") == okRoute {
+				size = m
+			}
+		}
+	}
+
+	require.NotNil(
+		t, size, "no response size series for the static route",
+	)
+	assert.Equal(t, "200", labelValue(size, "code"))
+	assert.Equal(t, uint64(1), size.GetHistogram().GetSampleCount())
+	assert.InDelta(
+		t, float64(len(okBody)),
+		size.GetHistogram().GetSampleSum(), 0.0,
+		"the interceptor must still count written bytes",
+	)
+}

internal/middleware/middleware.go

@@ -13,9 +13,6 @@ import (
 	"github.com/go-chi/chi"
 	"github.com/go-chi/chi/middleware"
 	"github.com/go-chi/cors"
-	metrics "github.com/slok/go-http-metrics/metrics/prometheus"
-	ghmm "github.com/slok/go-http-metrics/middleware"
-	"github.com/slok/go-http-metrics/middleware/std"
 	"go.uber.org/fx"
 	"sneak.berlin/go/webhooker/internal/config"
 	"sneak.berlin/go/webhooker/internal/globals"
@@ -29,10 +26,15 @@ const (
 	// preflight response can be cached.
 	corsMaxAge = 300
 
-	// unmatchedRoute is logged in the access log's url field when a
+	// unmatchedRoute stands in for a request that matched no route
-	// redirected or rejected request matched no route pattern at
+	// pattern at all. Every byte of such a path is client-chosen, so
-	// all. Every byte of such a path is client-chosen, so none of it
+	// none of it is kept.
-	// is logged.
+	//
+	// It is the access log's url field on a redirected or rejected
+	// request, and it is the metrics `handler` label on the same
+	// request; see metrics.go. Both surfaces are written once per
+	// request from a path the client picks, so both have to collapse
+	// the unmatched case into one fixed value.
 	unmatchedRoute = "(unmatched)"
 
 	// redactedQuery stands in for the query string on the access log
@@ -438,17 +440,6 @@ func (s *Middleware) RequireAuth() func(http.Handler) http.Handler {
 	}
 }
 
-// Metrics returns middleware that records Prometheus HTTP metrics.
-func (s *Middleware) Metrics() func(http.Handler) http.Handler {
-	mdlw := ghmm.New(ghmm.Config{
-		Recorder: metrics.NewRecorder(metrics.Config{}),
-	})
-
-	return func(next http.Handler) http.Handler {
-		return std.Handler("", mdlw, next)
-	}
-}
-
 // MetricsAuth returns middleware that protects metrics endpoints
 // with basic auth.
 func (s *Middleware) MetricsAuth() func(http.Handler) http.Handler {