Skip to content

Commit ef95cbd

Browse files
korECMrarguelloFdarccio
authored
feat(contrib/net/http): add WithClientTimings option (#3839)
Co-authored-by: rarguelloF <rodrigo.arguello@datadoghq.com> Co-authored-by: darccio <dario.castane@datadoghq.com>
1 parent e295185 commit ef95cbd

File tree

5 files changed

+150
-2
lines changed

5 files changed

+150
-2
lines changed

contrib/net/http/example_test.go

Lines changed: 35 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@ package http_test
77

88
import (
99
"net/http"
10+
"net/http/httptest"
1011

1112
httptrace "github.com/DataDog/dd-trace-go/contrib/net/http/v2"
1213
"github.com/DataDog/dd-trace-go/v2/ddtrace/tracer"
@@ -68,6 +69,40 @@ func ExampleWrapClient() {
6869
http.ListenAndServe(":8080", mux)
6970
}
7071

72+
// ExampleWrapClient_withClientTimings demonstrates how to enable detailed HTTP request tracing
73+
// using httptrace.ClientTrace. This provides timing information for DNS lookups, connection
74+
// establishment, TLS handshakes, and other HTTP request events as span tags.
75+
func ExampleWrapClient_withClientTimings() {
76+
tracer.Start()
77+
defer tracer.Stop()
78+
79+
// Create a test server for demonstration
80+
server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
81+
w.WriteHeader(http.StatusOK)
82+
w.Write([]byte("OK"))
83+
}))
84+
defer server.Close()
85+
86+
// Create an HTTP client with ClientTimings enabled
87+
c := httptrace.WrapClient(http.DefaultClient, httptrace.WithClientTimings(true))
88+
89+
// Make a request - the span will include detailed timing information
90+
// such as http.dns.duration_ms, http.connect.duration_ms, etc.
91+
req, _ := http.NewRequest(http.MethodGet, server.URL, nil)
92+
resp, err := c.Do(req)
93+
if err != nil {
94+
return
95+
}
96+
defer resp.Body.Close()
97+
98+
// The resulting span will contain timing tags like:
99+
// - http.dns.duration_ms: Time spent on DNS resolution
100+
// - http.connect.duration_ms: Time spent establishing connection
101+
// - http.tls.duration_ms: Time spent on TLS handshake
102+
// - http.get_conn.duration_ms: Time spent getting connection from pool
103+
// - http.first_byte.duration_ms: Time to first response byte
104+
}
105+
71106
func traceMiddleware(mux *http.ServeMux, next http.Handler) http.Handler {
72107
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
73108
_, route := mux.Handler(r)

contrib/net/http/internal/config/config.go

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -95,6 +95,7 @@ type RoundTripperConfig struct {
9595
ErrCheck func(err error) bool
9696
QueryString bool // reports whether the query string is included in the URL tag for http client spans
9797
IsStatusError func(statusCode int) bool
98+
ClientTimings bool // reports whether httptrace.ClientTrace should be enabled for detailed timing
9899
}
99100

100101
func (c *RoundTripperConfig) ApplyOpts(opts ...RoundTripperOption) {

contrib/net/http/internal/wrap/roundtrip.go

Lines changed: 68 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -6,23 +6,78 @@
66
package wrap
77

88
import (
9+
"crypto/tls"
910
"fmt"
1011
"math"
1112
"net/http"
13+
"net/http/httptrace"
1214
"os"
1315
"strconv"
16+
"time"
1417

1518
"github.com/DataDog/dd-trace-go/contrib/net/http/v2/internal/config"
1619
"github.com/DataDog/dd-trace-go/v2/appsec/events"
1720
"github.com/DataDog/dd-trace-go/v2/ddtrace/baggage"
1821
"github.com/DataDog/dd-trace-go/v2/ddtrace/ext"
1922
"github.com/DataDog/dd-trace-go/v2/ddtrace/tracer"
2023
"github.com/DataDog/dd-trace-go/v2/instrumentation/appsec/emitter/httpsec"
21-
"github.com/DataDog/dd-trace-go/v2/instrumentation/httptrace"
24+
instrumentationhttptrace "github.com/DataDog/dd-trace-go/v2/instrumentation/httptrace"
2225
)
2326

2427
type AfterRoundTrip = func(*http.Response, error) (*http.Response, error)
2528

29+
// httpTraceTimings captures key timing events from httptrace.ClientTrace
30+
type httpTraceTimings struct {
31+
dnsStart, dnsEnd time.Time
32+
connectStart, connectEnd time.Time
33+
tlsStart, tlsEnd time.Time
34+
getConnStart, gotConn time.Time
35+
wroteHeaders, gotFirstByte time.Time
36+
connectErr error
37+
tlsErr error
38+
}
39+
40+
// addDurationTag adds a timing tag to the span if both timestamps are valid
41+
func (t *httpTraceTimings) addDurationTag(span *tracer.Span, tagName string, start, end time.Time) {
42+
if !start.IsZero() && !end.IsZero() {
43+
duration := float64(end.Sub(start).Nanoseconds()) / 1e6
44+
span.SetTag(tagName, duration)
45+
}
46+
}
47+
48+
// addTimingTags adds all timing information to the span
49+
func (t *httpTraceTimings) addTimingTags(span *tracer.Span) {
50+
t.addDurationTag(span, "http.dns.duration_ms", t.dnsStart, t.dnsEnd)
51+
t.addDurationTag(span, "http.connect.duration_ms", t.connectStart, t.connectEnd)
52+
t.addDurationTag(span, "http.tls.duration_ms", t.tlsStart, t.tlsEnd)
53+
t.addDurationTag(span, "http.get_conn.duration_ms", t.getConnStart, t.gotConn)
54+
t.addDurationTag(span, "http.first_byte.duration_ms", t.wroteHeaders, t.gotFirstByte)
55+
56+
// Add error information if present
57+
if t.connectErr != nil {
58+
span.SetTag("http.connect.error", t.connectErr.Error())
59+
}
60+
if t.tlsErr != nil {
61+
span.SetTag("http.tls.error", t.tlsErr.Error())
62+
}
63+
}
64+
65+
// newClientTrace creates a ClientTrace that captures timing information
66+
func newClientTrace(timings *httpTraceTimings) *httptrace.ClientTrace {
67+
return &httptrace.ClientTrace{
68+
DNSStart: func(httptrace.DNSStartInfo) { timings.dnsStart = time.Now() },
69+
DNSDone: func(httptrace.DNSDoneInfo) { timings.dnsEnd = time.Now() },
70+
ConnectStart: func(network, addr string) { timings.connectStart = time.Now() },
71+
ConnectDone: func(network, addr string, err error) { timings.connectEnd = time.Now(); timings.connectErr = err },
72+
TLSHandshakeStart: func() { timings.tlsStart = time.Now() },
73+
TLSHandshakeDone: func(_ tls.ConnectionState, err error) { timings.tlsEnd = time.Now(); timings.tlsErr = err },
74+
GetConn: func(hostPort string) { timings.getConnStart = time.Now() },
75+
GotConn: func(httptrace.GotConnInfo) { timings.gotConn = time.Now() },
76+
WroteHeaders: func() { timings.wroteHeaders = time.Now() },
77+
GotFirstResponseByte: func() { timings.gotFirstByte = time.Now() },
78+
}
79+
}
80+
2681
// ObserveRoundTrip performs actions before the base [http.RoundTripper.RoundTrip] using the
2782
// provided [*config.RoundTripperConfig] (which cannot be nil). It returns the possibly modified
2883
// [*http.Request] and a function to be called after the base [http.RoundTripper.RoundTrip] function
@@ -45,7 +100,7 @@ func ObserveRoundTrip(cfg *config.RoundTripperConfig, req *http.Request) (*http.
45100
tracer.SpanType(ext.SpanTypeHTTP),
46101
tracer.ResourceName(resourceName),
47102
tracer.Tag(ext.HTTPMethod, req.Method),
48-
tracer.Tag(ext.HTTPURL, httptrace.URLFromRequest(req, cfg.QueryString)),
103+
tracer.Tag(ext.HTTPURL, instrumentationhttptrace.URLFromRequest(req, cfg.QueryString)),
49104
tracer.Tag(ext.Component, config.ComponentName),
50105
tracer.Tag(ext.SpanKind, ext.SpanKindClient),
51106
tracer.Tag(ext.NetworkDestinationName, url.Hostname()),
@@ -71,6 +126,13 @@ func ObserveRoundTrip(cfg *config.RoundTripperConfig, req *http.Request) (*http.
71126
cfg.Before(req, span)
72127
}
73128

129+
// Setup ClientTrace for detailed timing if enabled
130+
var timings *httpTraceTimings
131+
if cfg.ClientTimings {
132+
timings = &httpTraceTimings{}
133+
ctx = httptrace.WithClientTrace(ctx, newClientTrace(timings))
134+
}
135+
74136
// Clone the request so we can modify it without causing visible side-effects to the caller...
75137
req = req.Clone(ctx)
76138
for k, v := range baggage.All(ctx) {
@@ -108,6 +170,10 @@ func ObserveRoundTrip(cfg *config.RoundTripperConfig, req *http.Request) (*http.
108170
}
109171
}
110172

173+
if cfg.ClientTimings && timings != nil {
174+
timings.addTimingTags(span)
175+
}
176+
111177
// Run the after hooks & finish the span
112178
if cfg.After != nil {
113179
cfg.After(resp, span)

contrib/net/http/option.go

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -191,6 +191,16 @@ func WithErrorCheck(fn func(err error) bool) RoundTripperOptionFn {
191191
}
192192
}
193193

194+
// WithClientTimings enables detailed HTTP request tracing using httptrace.ClientTrace.
195+
// When enabled, the integration will add timing information for DNS lookups,
196+
// connection establishment, TLS handshakes, and other HTTP request events as span tags.
197+
// This feature is disabled by default and adds minimal overhead when enabled.
198+
func WithClientTimings(enabled bool) RoundTripperOptionFn {
199+
return func(cfg *internal.RoundTripperConfig) {
200+
cfg.ClientTimings = enabled
201+
}
202+
}
203+
194204
func isClientError(statusCode int) bool {
195205
return statusCode >= 400 && statusCode < 500
196206
}

contrib/net/http/roundtripper_test.go

Lines changed: 36 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -581,6 +581,42 @@ func TestSpanOptions(t *testing.T) {
581581
assert.Equal(t, tagValue, spans[0].Tag(tagKey))
582582
}
583583

584+
func TestClientTimings(t *testing.T) {
585+
assertClientTimings := func(t *testing.T, enabled bool, expectTags bool) {
586+
mt := mocktracer.Start()
587+
defer mt.Stop()
588+
589+
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
590+
w.WriteHeader(http.StatusOK)
591+
}))
592+
defer srv.Close()
593+
594+
rt := WrapRoundTripper(http.DefaultTransport, WithClientTimings(enabled))
595+
client := &http.Client{Transport: rt}
596+
resp, err := client.Get(srv.URL)
597+
assert.Nil(t, err)
598+
defer resp.Body.Close()
599+
600+
spans := mt.FinishedSpans()
601+
assert.Len(t, spans, 1)
602+
span := spans[0]
603+
604+
hasTimingTags := span.Tag("http.connect.duration_ms") != nil ||
605+
span.Tag("http.get_conn.duration_ms") != nil ||
606+
span.Tag("http.first_byte.duration_ms") != nil
607+
608+
assert.Equal(t, expectTags, hasTimingTags)
609+
}
610+
611+
t.Run("disabled", func(t *testing.T) {
612+
assertClientTimings(t, false, false)
613+
})
614+
615+
t.Run("enabled", func(t *testing.T) {
616+
assertClientTimings(t, true, true)
617+
})
618+
}
619+
584620
func TestClientQueryStringCollected(t *testing.T) {
585621
s := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
586622
w.Write([]byte("Hello World"))

0 commit comments

Comments
 (0)