From dc360828598440beb1dfdb21c0ba14e09bcd565b Mon Sep 17 00:00:00 2001 From: Varun Chawla <34209028+veeceey@users.noreply.github.com> Date: Tue, 3 Mar 2026 14:15:55 -0800 Subject: [PATCH] caddyhttp: Collect metrics once per route instead of per handler (#7492) * perf: collect metrics once per route instead of per handler (#4644) Move Prometheus metrics instrumentation from the per-handler level to the per-route level. Previously, every middleware handler in a route was individually wrapped with metricsInstrumentedHandler, causing metrics to be collected N times per request (once per handler in the chain). Since all handlers in a route see the same request, these per-handler metrics were redundant and added significant CPU overhead (73% of request handling time per the original profiling). The fix introduces metricsInstrumentedRoute which wraps the entire compiled handler chain once in wrapRoute, collecting metrics only when the route actually matches. The handler label uses the first handler's module name, which is the most meaningful identifier for the route. Benchmark results (5 handlers per route): Old (per-handler): ~4650 ns/op, 4400 B/op, 45 allocs/op New (per-route): ~940 ns/op, 816 B/op, 8 allocs/op Improvement: ~5x faster, ~5.4x less memory, ~5.6x fewer allocs Signed-off-by: Varun Chawla * Remove unused metricsInstrumentedHandler code Delete the metricsInstrumentedHandler type, its constructor, and ServeHTTP method since they are no longer used after switching to route-level metrics collection via metricsInstrumentedRoute. Also remove the unused metrics parameter from wrapMiddleware and the middlewareHandlerFunc test helper, and convert existing tests to use the new route-level API. Co-Authored-By: Claude Opus 4.6 * Address review feedback: restore comments, move function to bottom - Move computeApproximateRequestSize back to bottom of file to minimize diff - Restore all useful comments that were accidentally dropped - Old metricsInstrumentedHandler already removed in previous commit --------- Signed-off-by: Varun Chawla Co-authored-by: Claude Opus 4.6 --- modules/caddyhttp/metrics.go | 19 ++-- modules/caddyhttp/metrics_test.go | 162 +++++++++++++++++++++++------- modules/caddyhttp/routes.go | 37 +++++-- 3 files changed, 161 insertions(+), 57 deletions(-) diff --git a/modules/caddyhttp/metrics.go b/modules/caddyhttp/metrics.go index 8b4d380f0..b212bbfb8 100644 --- a/modules/caddyhttp/metrics.go +++ b/modules/caddyhttp/metrics.go @@ -214,21 +214,24 @@ func serverNameFromContext(ctx context.Context) string { return srv.name } -type metricsInstrumentedHandler struct { +// metricsInstrumentedRoute wraps a compiled route Handler with metrics +// instrumentation. It wraps the entire compiled route chain once, +// collecting metrics only once per route match. +type metricsInstrumentedRoute struct { handler string - mh MiddlewareHandler + next Handler metrics *Metrics } -func newMetricsInstrumentedHandler(ctx caddy.Context, handler string, mh MiddlewareHandler, metrics *Metrics) *metricsInstrumentedHandler { - metrics.init.Do(func() { - initHTTPMetrics(ctx, metrics) +func newMetricsInstrumentedRoute(ctx caddy.Context, handler string, next Handler, m *Metrics) *metricsInstrumentedRoute { + m.init.Do(func() { + initHTTPMetrics(ctx, m) }) - return &metricsInstrumentedHandler{handler, mh, metrics} + return &metricsInstrumentedRoute{handler: handler, next: next, metrics: m} } -func (h *metricsInstrumentedHandler) ServeHTTP(w http.ResponseWriter, r *http.Request, next Handler) error { +func (h *metricsInstrumentedRoute) ServeHTTP(w http.ResponseWriter, r *http.Request) error { server := serverNameFromContext(r.Context()) labels := prometheus.Labels{"server": server, "handler": h.handler} method := metrics.SanitizeMethod(r.Method) @@ -267,7 +270,7 @@ func (h *metricsInstrumentedHandler) ServeHTTP(w http.ResponseWriter, r *http.Re return false }) wrec := NewResponseRecorder(w, nil, writeHeaderRecorder) - err := h.mh.ServeHTTP(wrec, r, next) + err := h.next.ServeHTTP(wrec, r) dur := time.Since(start).Seconds() h.metrics.httpMetrics.requestCount.With(labels).Inc() diff --git a/modules/caddyhttp/metrics_test.go b/modules/caddyhttp/metrics_test.go index 58b6a09ad..987b3f342 100644 --- a/modules/caddyhttp/metrics_test.go +++ b/modules/caddyhttp/metrics_test.go @@ -47,16 +47,12 @@ func TestMetricsInstrumentedHandler(t *testing.T) { return handlerErr }) - mh := middlewareHandlerFunc(func(w http.ResponseWriter, r *http.Request, h Handler) error { - return h.ServeHTTP(w, r) - }) - - ih := newMetricsInstrumentedHandler(ctx, "bar", mh, metrics) + ih := newMetricsInstrumentedRoute(ctx, "bar", h, metrics) r := httptest.NewRequest("GET", "/", nil) w := httptest.NewRecorder() - if actual := ih.ServeHTTP(w, r, h); actual != handlerErr { + if actual := ih.ServeHTTP(w, r); actual != handlerErr { t.Errorf("Not same: expected %#v, but got %#v", handlerErr, actual) } if actual := testutil.ToFloat64(metrics.httpMetrics.requestInFlight); actual != 0.0 { @@ -64,19 +60,19 @@ func TestMetricsInstrumentedHandler(t *testing.T) { } handlerErr = nil - if err := ih.ServeHTTP(w, r, h); err != nil { + if err := ih.ServeHTTP(w, r); err != nil { t.Errorf("Received unexpected error: %v", err) } // an empty handler - no errors, no header written - mh = middlewareHandlerFunc(func(w http.ResponseWriter, r *http.Request, h Handler) error { + emptyHandler := HandlerFunc(func(w http.ResponseWriter, r *http.Request) error { return nil }) - ih = newMetricsInstrumentedHandler(ctx, "empty", mh, metrics) + ih = newMetricsInstrumentedRoute(ctx, "empty", emptyHandler, metrics) r = httptest.NewRequest("GET", "/", nil) w = httptest.NewRecorder() - if err := ih.ServeHTTP(w, r, h); err != nil { + if err := ih.ServeHTTP(w, r); err != nil { t.Errorf("Received unexpected error: %v", err) } if actual := w.Result().StatusCode; actual != 200 { @@ -87,16 +83,16 @@ func TestMetricsInstrumentedHandler(t *testing.T) { } // handler returning an error with an HTTP status - mh = middlewareHandlerFunc(func(w http.ResponseWriter, r *http.Request, h Handler) error { + errHandler := HandlerFunc(func(w http.ResponseWriter, r *http.Request) error { return Error(http.StatusTooManyRequests, nil) }) - ih = newMetricsInstrumentedHandler(ctx, "foo", mh, metrics) + ih = newMetricsInstrumentedRoute(ctx, "foo", errHandler, metrics) r = httptest.NewRequest("GET", "/", nil) w = httptest.NewRecorder() - if err := ih.ServeHTTP(w, r, nil); err == nil { + if err := ih.ServeHTTP(w, r); err == nil { t.Errorf("expected error to be propagated") } @@ -225,16 +221,12 @@ func TestMetricsInstrumentedHandlerPerHost(t *testing.T) { return handlerErr }) - mh := middlewareHandlerFunc(func(w http.ResponseWriter, r *http.Request, h Handler) error { - return h.ServeHTTP(w, r) - }) - - ih := newMetricsInstrumentedHandler(ctx, "bar", mh, metrics) + ih := newMetricsInstrumentedRoute(ctx, "bar", h, metrics) r := httptest.NewRequest("GET", "/", nil) w := httptest.NewRecorder() - if actual := ih.ServeHTTP(w, r, h); actual != handlerErr { + if actual := ih.ServeHTTP(w, r); actual != handlerErr { t.Errorf("Not same: expected %#v, but got %#v", handlerErr, actual) } if actual := testutil.ToFloat64(metrics.httpMetrics.requestInFlight); actual != 0.0 { @@ -242,19 +234,19 @@ func TestMetricsInstrumentedHandlerPerHost(t *testing.T) { } handlerErr = nil - if err := ih.ServeHTTP(w, r, h); err != nil { + if err := ih.ServeHTTP(w, r); err != nil { t.Errorf("Received unexpected error: %v", err) } // an empty handler - no errors, no header written - mh = middlewareHandlerFunc(func(w http.ResponseWriter, r *http.Request, h Handler) error { + emptyHandler := HandlerFunc(func(w http.ResponseWriter, r *http.Request) error { return nil }) - ih = newMetricsInstrumentedHandler(ctx, "empty", mh, metrics) + ih = newMetricsInstrumentedRoute(ctx, "empty", emptyHandler, metrics) r = httptest.NewRequest("GET", "/", nil) w = httptest.NewRecorder() - if err := ih.ServeHTTP(w, r, h); err != nil { + if err := ih.ServeHTTP(w, r); err != nil { t.Errorf("Received unexpected error: %v", err) } if actual := w.Result().StatusCode; actual != 200 { @@ -265,16 +257,16 @@ func TestMetricsInstrumentedHandlerPerHost(t *testing.T) { } // handler returning an error with an HTTP status - mh = middlewareHandlerFunc(func(w http.ResponseWriter, r *http.Request, h Handler) error { + errHandler := HandlerFunc(func(w http.ResponseWriter, r *http.Request) error { return Error(http.StatusTooManyRequests, nil) }) - ih = newMetricsInstrumentedHandler(ctx, "foo", mh, metrics) + ih = newMetricsInstrumentedRoute(ctx, "foo", errHandler, metrics) r = httptest.NewRequest("GET", "/", nil) w = httptest.NewRecorder() - if err := ih.ServeHTTP(w, r, nil); err == nil { + if err := ih.ServeHTTP(w, r); err == nil { t.Errorf("expected error to be propagated") } @@ -397,30 +389,30 @@ func TestMetricsCardinalityProtection(t *testing.T) { // Add one allowed host metrics.allowedHosts["allowed.com"] = struct{}{} - mh := middlewareHandlerFunc(func(w http.ResponseWriter, r *http.Request, h Handler) error { + h := HandlerFunc(func(w http.ResponseWriter, r *http.Request) error { w.Write([]byte("hello")) return nil }) - ih := newMetricsInstrumentedHandler(ctx, "test", mh, metrics) + ih := newMetricsInstrumentedRoute(ctx, "test", h, metrics) // Test request to allowed host r1 := httptest.NewRequest("GET", "http://allowed.com/", nil) r1.Host = "allowed.com" w1 := httptest.NewRecorder() - ih.ServeHTTP(w1, r1, HandlerFunc(func(w http.ResponseWriter, r *http.Request) error { return nil })) + ih.ServeHTTP(w1, r1) // Test request to unknown host (should be mapped to "_other") r2 := httptest.NewRequest("GET", "http://attacker.com/", nil) r2.Host = "attacker.com" w2 := httptest.NewRecorder() - ih.ServeHTTP(w2, r2, HandlerFunc(func(w http.ResponseWriter, r *http.Request) error { return nil })) + ih.ServeHTTP(w2, r2) // Test request to another unknown host (should also be mapped to "_other") r3 := httptest.NewRequest("GET", "http://evil.com/", nil) r3.Host = "evil.com" w3 := httptest.NewRecorder() - ih.ServeHTTP(w3, r3, HandlerFunc(func(w http.ResponseWriter, r *http.Request) error { return nil })) + ih.ServeHTTP(w3, r3) // Check that metrics contain: // - One entry for "allowed.com" @@ -452,26 +444,26 @@ func TestMetricsHTTPSCatchAll(t *testing.T) { allowedHosts: make(map[string]struct{}), // Empty - no explicitly allowed hosts } - mh := middlewareHandlerFunc(func(w http.ResponseWriter, r *http.Request, h Handler) error { + h := HandlerFunc(func(w http.ResponseWriter, r *http.Request) error { w.Write([]byte("hello")) return nil }) - ih := newMetricsInstrumentedHandler(ctx, "test", mh, metrics) + ih := newMetricsInstrumentedRoute(ctx, "test", h, metrics) // Test HTTPS request (should be allowed even though not in allowedHosts) r1 := httptest.NewRequest("GET", "https://unknown.com/", nil) r1.Host = "unknown.com" r1.TLS = &tls.ConnectionState{} // Mark as TLS/HTTPS w1 := httptest.NewRecorder() - ih.ServeHTTP(w1, r1, HandlerFunc(func(w http.ResponseWriter, r *http.Request) error { return nil })) + ih.ServeHTTP(w1, r1) // Test HTTP request (should be mapped to "_other") r2 := httptest.NewRequest("GET", "http://unknown.com/", nil) r2.Host = "unknown.com" // No TLS field = HTTP request w2 := httptest.NewRecorder() - ih.ServeHTTP(w2, r2, HandlerFunc(func(w http.ResponseWriter, r *http.Request) error { return nil })) + ih.ServeHTTP(w2, r2) // Check that HTTPS request gets real host, HTTP gets "_other" expected := ` @@ -488,8 +480,102 @@ func TestMetricsHTTPSCatchAll(t *testing.T) { } } -type middlewareHandlerFunc func(http.ResponseWriter, *http.Request, Handler) error +func TestMetricsInstrumentedRoute(t *testing.T) { + ctx, _ := caddy.NewContext(caddy.Context{Context: context.Background()}) + m := &Metrics{ + init: sync.Once{}, + httpMetrics: &httpMetrics{}, + } -func (f middlewareHandlerFunc) ServeHTTP(w http.ResponseWriter, r *http.Request, h Handler) error { - return f(w, r, h) + handlerErr := errors.New("oh noes") + response := []byte("hello world!") + innerHandler := HandlerFunc(func(w http.ResponseWriter, r *http.Request) error { + if actual := testutil.ToFloat64(m.httpMetrics.requestInFlight); actual != 1.0 { + t.Errorf("Expected requestInFlight to be 1.0, got %v", actual) + } + if handlerErr == nil { + w.Write(response) + } + return handlerErr + }) + + ih := newMetricsInstrumentedRoute(ctx, "test_handler", innerHandler, m) + + r := httptest.NewRequest("GET", "/", nil) + w := httptest.NewRecorder() + + // Test with error + if actual := ih.ServeHTTP(w, r); actual != handlerErr { + t.Errorf("Expected error %v, got %v", handlerErr, actual) + } + if actual := testutil.ToFloat64(m.httpMetrics.requestInFlight); actual != 0.0 { + t.Errorf("Expected requestInFlight to be 0.0 after request, got %v", actual) + } + if actual := testutil.ToFloat64(m.httpMetrics.requestErrors); actual != 1.0 { + t.Errorf("Expected requestErrors to be 1.0, got %v", actual) + } + + // Test without error + handlerErr = nil + w = httptest.NewRecorder() + if err := ih.ServeHTTP(w, r); err != nil { + t.Errorf("Unexpected error: %v", err) + } +} + +func BenchmarkMetricsInstrumentedRoute(b *testing.B) { + ctx, _ := caddy.NewContext(caddy.Context{Context: context.Background()}) + m := &Metrics{ + init: sync.Once{}, + httpMetrics: &httpMetrics{}, + } + + noopHandler := HandlerFunc(func(w http.ResponseWriter, r *http.Request) error { + w.Write([]byte("ok")) + return nil + }) + + ih := newMetricsInstrumentedRoute(ctx, "bench_handler", noopHandler, m) + + r := httptest.NewRequest("GET", "/", nil) + w := httptest.NewRecorder() + + b.ResetTimer() + b.ReportAllocs() + for i := 0; i < b.N; i++ { + ih.ServeHTTP(w, r) + } +} + +// BenchmarkSingleRouteMetrics simulates the new behavior where metrics +// are collected once for the entire route. +func BenchmarkSingleRouteMetrics(b *testing.B) { + ctx, _ := caddy.NewContext(caddy.Context{Context: context.Background()}) + m := &Metrics{ + init: sync.Once{}, + httpMetrics: &httpMetrics{}, + } + + // Build a chain of 5 plain middleware handlers (no per-handler metrics) + var next Handler = HandlerFunc(func(w http.ResponseWriter, r *http.Request) error { + return nil + }) + for i := 0; i < 5; i++ { + capturedNext := next + next = HandlerFunc(func(w http.ResponseWriter, r *http.Request) error { + return capturedNext.ServeHTTP(w, r) + }) + } + + // Wrap the entire chain with a single route-level metrics handler + ih := newMetricsInstrumentedRoute(ctx, "handler", next, m) + + r := httptest.NewRequest("GET", "/", nil) + w := httptest.NewRecorder() + + b.ResetTimer() + b.ReportAllocs() + for i := 0; i < b.N; i++ { + ih.ServeHTTP(w, r) + } } diff --git a/modules/caddyhttp/routes.go b/modules/caddyhttp/routes.go index d029d19b9..ce2287488 100644 --- a/modules/caddyhttp/routes.go +++ b/modules/caddyhttp/routes.go @@ -97,7 +97,10 @@ type Route struct { MatcherSets MatcherSets `json:"-"` Handlers []MiddlewareHandler `json:"-"` - middleware []Middleware + middleware []Middleware + metrics *Metrics + metricsCtx caddy.Context + handlerName string } // Empty returns true if the route has all zero/default values. @@ -162,12 +165,20 @@ func (r *Route) ProvisionHandlers(ctx caddy.Context, metrics *Metrics) error { r.Handlers = append(r.Handlers, handler.(MiddlewareHandler)) } + // Store metrics info for route-level instrumentation (applied once + // per route in wrapRoute, instead of per-handler which was redundant). + r.metrics = metrics + r.metricsCtx = ctx + if len(r.Handlers) > 0 { + r.handlerName = caddy.GetModuleName(r.Handlers[0]) + } + // Make ProvisionHandlers idempotent by clearing the middleware field r.middleware = []Middleware{} // pre-compile the middleware handler chain for _, midhandler := range r.Handlers { - r.middleware = append(r.middleware, wrapMiddleware(ctx, midhandler, metrics)) + r.middleware = append(r.middleware, wrapMiddleware(ctx, midhandler)) } return nil } @@ -298,6 +309,16 @@ func wrapRoute(route Route) Middleware { nextCopy = route.middleware[i](nextCopy) } + // Apply metrics instrumentation once for the entire route, + // rather than wrapping each individual handler. This avoids + // redundant metrics collection that caused significant CPU + // overhead (see issue #4644). + if route.metrics != nil { + nextCopy = newMetricsInstrumentedRoute( + route.metricsCtx, route.handlerName, nextCopy, route.metrics, + ) + } + return nextCopy.ServeHTTP(rw, req) }) } @@ -306,20 +327,14 @@ func wrapRoute(route Route) Middleware { // wrapMiddleware wraps mh such that it can be correctly // appended to a list of middleware in preparation for // compiling into a handler chain. -func wrapMiddleware(ctx caddy.Context, mh MiddlewareHandler, metrics *Metrics) Middleware { - handlerToUse := mh - if metrics != nil { - // wrap the middleware with metrics instrumentation - handlerToUse = newMetricsInstrumentedHandler(ctx, caddy.GetModuleName(mh), mh, metrics) - } - +func wrapMiddleware(ctx caddy.Context, mh MiddlewareHandler) Middleware { return func(next Handler) Handler { return HandlerFunc(func(w http.ResponseWriter, r *http.Request) error { // EXPERIMENTAL: Trace each module that gets invoked if server, ok := r.Context().Value(ServerCtxKey).(*Server); ok && server != nil { - server.logTrace(handlerToUse) + server.logTrace(mh) } - return handlerToUse.ServeHTTP(w, r, next) + return mh.ServeHTTP(w, r, next) }) } }