diff --git a/CHANGELOG.md b/CHANGELOG.md index f66290fa745..c7777931f7b 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -18,6 +18,7 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm - Fix `NewServerHandler` in `go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc` to correctly set the span status depending on the gRPC status. (#4587) - Update `go.opentelemetry.io/contrib/detectors/aws/ecs` to fix the task ARN when it is not valid. (#3583) - Do not panic in `go.opentelemetry.io/contrib/detectors/aws/ecs` when the container ARN is not valid. (#3583) +- Fix `http.Handler` metric instrumentation in `go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp` to record metrics on timed out requests. (#4634) ## [1.21.1/0.46.1/0.15.1/0.1.1] - 2023-11-16 diff --git a/instrumentation/net/http/otelhttp/handler.go b/instrumentation/net/http/otelhttp/handler.go index 05f6ec27947..349f150a63c 100644 --- a/instrumentation/net/http/otelhttp/handler.go +++ b/instrumentation/net/http/otelhttp/handler.go @@ -15,6 +15,7 @@ package otelhttp // import "go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp" import ( + "context" "io" "net/http" "time" @@ -232,13 +233,14 @@ func (h *middleware) serveHTTP(w http.ResponseWriter, r *http.Request, next http attributes = append(attributes, semconv.HTTPStatusCode(rww.statusCode)) } o := metric.WithAttributes(attributes...) - h.requestBytesCounter.Add(ctx, bw.read, o) - h.responseBytesCounter.Add(ctx, rww.written, o) + ctxWithoutCancel := withoutCancel(ctx) + h.requestBytesCounter.Add(ctxWithoutCancel, bw.read, o) + h.responseBytesCounter.Add(ctxWithoutCancel, rww.written, o) // Use floating point division here for higher precision (instead of Millisecond method). elapsedTime := float64(time.Since(requestStartTime)) / float64(time.Millisecond) - h.serverLatencyMeasure.Record(ctx, elapsedTime, o) + h.serverLatencyMeasure.Record(ctxWithoutCancel, elapsedTime, o) } func setAfterServeAttributes(span trace.Span, read, wrote int64, statusCode int, rerr, werr error) { @@ -281,3 +283,38 @@ func WithRouteTag(route string, h http.Handler) http.Handler { h.ServeHTTP(w, r) }) } + +// NOTE: This withoutCancel implementation is copied from: +// https://github.com/open-telemetry/opentelemetry-go-contrib/blob/6009b3188da4f25eb8d2e65ffeefb3bf4b7c3415/instrumentation/google.golang.org/grpc/otelgrpc/stats_handler.go#L216-L245 +// The implementation in otelgrpc is based on: +// https://cs.opensource.google/go/go/+/refs/tags/go1.21.5:src/context/context.go;l=566 +func withoutCancel(parent context.Context) context.Context { + if parent == nil { + panic("cannot create context from nil parent") + } + return withoutCancelCtx{parent} +} + +type withoutCancelCtx struct { + c context.Context +} + +func (withoutCancelCtx) Deadline() (deadline time.Time, ok bool) { + return +} + +func (withoutCancelCtx) Done() <-chan struct{} { + return nil +} + +func (withoutCancelCtx) Err() error { + return nil +} + +func (w withoutCancelCtx) Value(key any) any { + return w.c.Value(key) +} + +func (w withoutCancelCtx) String() string { + return "withoutCancel" +} diff --git a/instrumentation/net/http/otelhttp/test/handler_test.go b/instrumentation/net/http/otelhttp/test/handler_test.go index 105041dad56..9f1e166c512 100644 --- a/instrumentation/net/http/otelhttp/test/handler_test.go +++ b/instrumentation/net/http/otelhttp/test/handler_test.go @@ -18,11 +18,13 @@ import ( "context" "fmt" "io" + "net" "net/http" "net/http/httptest" "strconv" "strings" "testing" + "time" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" @@ -539,3 +541,46 @@ func TestWithRouteTag(t *testing.T) { } } } + +func TestCtxWithoutCancel(t *testing.T) { + reader := metric.NewManualReader() + meterProvider := metric.NewMeterProvider(metric.WithReader(reader)) + + otelHandler := otelhttp.NewHandler( + http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + _, err := w.Write([]byte("hello world")) + require.NoError(t, err) + }), "test_handler", otelhttp.WithMeterProvider(meterProvider)) + + ctx, cancel := context.WithCancel(context.Background()) + cancel() + + l, err := net.Listen("tcp", "localhost:12345") + require.NoError(t, err) + + srv := &http.Server{ + BaseContext: func(_ net.Listener) context.Context { return ctx }, + ReadTimeout: time.Second, + WriteTimeout: 10 * time.Second, + Handler: otelHandler, + } + + go func() { + // When Shutdown is called, Serve immediately returns ErrServerClosed. + assert.Equal(t, http.ErrServerClosed, srv.Serve(l)) + }() + + t.Cleanup(func() { + assert.NoError(t, srv.Shutdown(context.Background())) + }) + + client := &http.Client{} + _, err = client.Get("http://" + l.Addr().String()) + require.NoError(t, err) + + // Check that some metrics were recorded. + rm := metricdata.ResourceMetrics{} + err = reader.Collect(ctx, &rm) + require.NoError(t, err) + require.Len(t, rm.ScopeMetrics, 1) +}