使用 Go 的 net/http/httptrace 追踪 HTTP 请求

背景

net/http/httptrace 自 Go 1.7 起便已纳入 Go 标准库，然而在与众多 Go 开发者交流时发现，绝大多数人从未使用过这一包。它暴露了通常无法从传输层外部观察到的出站 HTTP 请求的关键节点钩子（hooks），包括：DNS 解析、连接获取、TLS 握手、字节上线的时刻，以及首个响应字节返回的时刻。

尽管该功能存在已久，但其设计模式与许多其他语言不同，导致其使用率较低。本文将深入解析其设计哲学，并展示如何利用它构建两个实用工具：一个类似 curl --trace 的命令行界面（CLI），以及一个可复用的 http.RoundTripper 用于记录每次请求的耗时。

核心内容

为什么使用 Context 而非接口？

在请求追踪方面，直观的设计通常是定义一个 Tracer 接口，在 http.Client 或 http.Transport 中添加 Tracer 字段，并在传输层内部调用其方法。这大致是大多数其他语言处理此类问题的方式。

然而，Go 标准库采用了不同的设计。httptrace.WithClientTrace 返回一个携带 *ClientTrace 的新 context.Context。你需要通过 req.WithContext(ctx) 将该上下文附加到请求中，传输层则在关键节点通过 httptrace.ContextClientTrace 将其提取出来。

trace := &httptrace.ClientTrace{
    DNSStart: func(info httptrace.DNSStartInfo) {
        fmt.Printf("DNS start: %s\n", info.Host)
    },
    DNSDone: func(info httptrace.DNSDoneInfo) {
        fmt.Printf("DNS done: %v\n", info.Addrs)
    },
}
ctx := httptrace.WithClientTrace(context.Background(), trace)
req, _ := http.NewRequestWithContext(ctx, http.MethodGet, "https://example.com", nil)
http.DefaultClient.Do(req)

这种设计虽然不常见，但带来了显著优势：

1. 追踪随请求流动：任何转发上下文的中间件都会自动传播追踪信息，无需额外配置。
2. 无共享可变状态：客户端没有共享的可变状态，因此来自同一 http.Client 的并发请求可以携带不同的追踪信息。
3. 零开销：如果未附加追踪信息，传输层完全忽略它，未使用时的成本仅为一次 nil 检查。

ClientTrace 本身是一个包含可选函数字段的结构体。开发者只需设置关心的字段，未设置的字段为 nil 并被跳过。这种设计使得包可以添加新的钩子而不会破坏现有代码，因为旧代码只需忽略新增的字段即可。

type ClientTrace struct {
    GetConn func(hostPort string)
    GotConn func(GotConnInfo)
    PutIdleConn func(err error)
    GotFirstResponseByte func()
    Got100Continue func()
    Got1xxResponse func(code int, header textproto.MIMEHeader) error
    DNSStart func(DNSStartInfo)
    DNSDone func(DNSDoneInfo)
    ConnectStart func(network, addr string)
    ConnectDone func(network, addr string, err error)
    TLSHandshakeStart func()
    TLSHandshakeDone func(tls.ConnectionState, error)
    WroteHeaderField func(key string, value []string)
    WroteHeaders func()
    Wait100Continue func()
    WroteRequest func(WroteRequestInfo)
}

构建一个类似 curl --trace 的 CLI

首先构建一个 CLI，它接受一个 URL 并打印类似 curl -w 的耗时分解，但具备 httptrace 提供的粒度。关键在于在每个钩子中记录时间戳，并计算相对于开始时间的持续时间。

package main

import (
    "context"
    "crypto/tls"
    "fmt"
    "net/http"
    "net/http/httptrace"
    "os"
    "time"
)

type timings struct {
    start     time.Time
    dnsStart  time.Time
    dnsDone   time.Time
    connectStart time.Time
    connectDone time.Time
    tlsStart  time.Time
    tlsDone   time.Time
    gotConn   time.Time
    firstByte time.Time
    done      time.Time
}

func (t *timings) elapsed(at time.Time) time.Duration {
    return at.Sub(t.start)
}

func newTrace(t *timings) *httptrace.ClientTrace {
    return &httptrace.ClientTrace{
        DNSStart: func(_ httptrace.DNSStartInfo) {
            t.dnsStart = time.Now()
        },
        DNSDone: func(_ httptrace.DNSDoneInfo) {
            t.dnsDone = time.Now()
        },
        ConnectStart: func(_, _ string) {
            t.connectStart = time.Now()
        },
        ConnectDone: func(_, _ string, _ error) {
            t.connectDone = time.Now()
        },
        TLSHandshakeStart: func() {
            t.tlsStart = time.Now()
        },
        TLSHandshakeDone: func(_ tls.ConnectionState, _ error) {
            t.tlsDone = time.Now()
        },
        GotConn: func(_ httptrace.GotConnInfo) {
            t.gotConn = time.Now()
        },
        GotFirstResponseByte: func() {
            t.firstByte = time.Now()
        },
    }
}

func main() {
    url := os.Args[1]
    t := &timings{start: time.Now()}
    trace := newTrace(t)
    ctx := httptrace.WithClientTrace(context.Background(), trace)
    req, err := http.NewRequestWithContext(ctx, http.MethodGet, url, nil)
    if err != nil {
        fmt.Fprintln(os.Stderr, err)
        os.Exit(1)
    }
    res, err := http.DefaultClient.Do(req)
    if err != nil {
        fmt.Fprintln(os.Stderr, err)
        os.Exit(1)
    }
    res.Body.Close()
    t.done = time.Now()
    
    fmt.Printf("DNS lookup: %v\n", t.dnsDone.Sub(t.dnsStart))
    fmt.Printf("TCP connect: %v\n", t.connectDone.Sub(t.connectStart))
    fmt.Printf("TLS handshake: %v\n", t.tlsDone.Sub(t.tlsStart))
    fmt.Printf("Server processing: %v\n", t.firstByte.Sub(t.gotConn))
    fmt.Printf("Content transfer: %v\n", t.done.Sub(t.firstByte))
    fmt.Printf("Total: %v\n", t.done.Sub(t.start))
}

运行此程序并传入任何 URL，输出结果将揭示时间消耗在哪里。缓慢的 DNS 查找、缓慢的 TLS 握手或服务器处理首字节耗时过长，都会在分解结果中单独显示一行。无需代理，无需 APM 代理，依赖图中也不需要任何插桩库。

需要注意的细节：

• DNSStart 和 DNSDone 仅在 Go 解析器执行查找时触发。如果地址已在内核 DNS 缓存中，或直接传入了 IP，这些钩子将不会触发。
• TLSHandshakeStart 和 TLSHandshakeDone 仅在 HTTPS 连接时触发。
• GotConn 无论连接是新建立还是复用都会触发，GotConnInfo 结构体中的 Reused 字段可告知连接状态。

构建一个 RoundTripper

一次性 CLI 很有用，但在大多数情况下，你希望自动追踪通过特定 http.Client 的所有请求。这正是 http.RoundTripper 的用武之地。包装默认传输层，在委托前将追踪附加到上下文，并在请求完成后记录结果。

type TracingTransport struct {
    Base http.RoundTripper
    Log  func(req *http.Request, t *timings)
}

func (tt *TracingTransport) RoundTrip(req *http.Request) (*http.Response, error