diff --git a/VERSION b/VERSION index 23aee0e..f6a33ec 100644 --- a/VERSION +++ b/VERSION @@ -1 +1 @@ -v1.1.5-dev +v1.1.6-dev diff --git a/logger/logger.go b/logger/logger.go index e9654c7..d9c69bf 100644 --- a/logger/logger.go +++ b/logger/logger.go @@ -10,6 +10,7 @@ import ( "strings" "time" + "github.com/go-chi/chi/v5" "github.com/go-chi/chi/v5/middleware" "github.com/google/uuid" "github.com/prometheus/client_golang/prometheus" @@ -140,24 +141,18 @@ func Middleware(logger *slog.Logger, shouldPrint bool) func(next http.Handler) h defer func() { metrics.InFlightGauge.Dec() - path := r.URL.Path - status := ww.Status() - // ww.Status() returns 0 when WriteHeader was never explicitly called (chi unmatched routes). - // Treat 0 the same as 404 to prevent path scanners from polluting metric cardinality. - if status == http.StatusNotFound || status == 0 { - // prevent path scanners from polluting logs and messing up path / endpoint cardinality. - // use a separate, dedicated key that we are not aggregating against. Keeps memory down. - logger = logger.With("path_high_cardinality", path) - path = "redacted for cardinality protection" + endpoint := chiRoutePattern(r) + if endpoint == "other" { + logger = logger.With("path_high_cardinality", r.URL.Path) } duration := time.Since(start) - metrics.RequestCount.With(prometheus.Labels{"method": r.Method, "endpoint": path}).Inc() - metrics.RequestDuration.With(prometheus.Labels{"method": r.Method, "endpoint": path}).Observe(duration.Seconds()) + metrics.RequestCount.With(prometheus.Labels{"method": r.Method, "endpoint": endpoint}).Inc() + metrics.RequestDuration.With(prometheus.Labels{"method": r.Method, "endpoint": endpoint}).Observe(duration.Seconds()) if shouldPrint { logger.Info("route", - "path", path, + "path", endpoint, "verb", r.Method, "status", http.StatusText(ww.Status()), "code", ww.Status(), @@ -172,3 +167,15 @@ func Middleware(logger *slog.Logger, shouldPrint bool) func(next http.Handler) h return http.HandlerFunc(fn) } } + +func chiRoutePattern(r *http.Request) string { + rctx := chi.RouteContext(r.Context()) + if rctx == nil { + return "other" + } + pattern := rctx.RoutePattern() + if pattern == "" || pattern == "/*" { + return "other" + } + return pattern +} diff --git a/logger/logger_test.go b/logger/logger_test.go index d239afe..62c0883 100644 --- a/logger/logger_test.go +++ b/logger/logger_test.go @@ -7,40 +7,32 @@ import ( "net/http/httptest" "strings" "testing" + + "github.com/go-chi/chi/v5" ) -// TestMiddlewareCardinalityProtection verifies that unmatched routes — whether they -// produce an explicit 404 or no WriteHeader call at all (chi returns status 0 for -// unmatched routes) — have their paths redacted in logs and metrics to prevent -// scanner traffic from causing a cardinality explosion. +// TestMiddlewareCardinalityProtection verifies that requests matched to a registered +// chi route use the route pattern as the metric label, while unregistered routes +// (scanner traffic, typos, catch-alls) are bucketed as "other" with the real path +// logged separately to prevent cardinality explosion. func TestMiddlewareCardinalityProtection(t *testing.T) { tests := []struct { name string - handler http.HandlerFunc path string wantRedacted bool }{ { - name: "known path passes through unchanged", - handler: func(w http.ResponseWriter, r *http.Request) { - w.WriteHeader(http.StatusOK) - }, + name: "registered route uses pattern, no redaction", path: "/api/users", wantRedacted: false, }, { - name: "explicit 404 triggers redaction", - handler: func(w http.ResponseWriter, r *http.Request) { - w.WriteHeader(http.StatusNotFound) - }, + name: "scanner path not in router triggers redaction", path: "/wp-admin/login.php", wantRedacted: true, }, { - name: "status 0 (unmatched chi route, WriteHeader never called) triggers redaction", - handler: func(w http.ResponseWriter, r *http.Request) { - // intentionally write nothing — chi returns 0 for unmatched routes - }, + name: "dot-env probe triggers redaction", path: "/.env", wantRedacted: true, }, @@ -52,18 +44,21 @@ func TestMiddlewareCardinalityProtection(t *testing.T) { log := slog.New(slog.NewJSONHandler(&buf, nil)) mw := Middleware(log, true) + router := chi.NewRouter() + router.Use(mw) + router.Get("/api/users", func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(http.StatusOK) + }) + req := httptest.NewRequest(http.MethodGet, tt.path, nil) rr := httptest.NewRecorder() - mw(http.HandlerFunc(tt.handler)).ServeHTTP(rr, req) + router.ServeHTTP(rr, req) output := buf.String() if tt.wantRedacted { if !strings.Contains(output, "path_high_cardinality") { t.Errorf("expected path_high_cardinality in log output, got: %s", output) } - if !strings.Contains(output, "redacted for cardinality protection") { - t.Errorf("expected redacted path in log output, got: %s", output) - } } else { if strings.Contains(output, "path_high_cardinality") { t.Errorf("did not expect path_high_cardinality in log output, got: %s", output)