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) }) } }