慢在 DNS、TCP 握手还是 TLS？利用 Go net/http/httptrace 监控 HTTP 请求各阶段耗时

技术圈

发布于 2026-07-23 20:37:58

1010

文章被收录于专栏：技术圈技术圈

调用下游第三方 HTTP 接口出现 P99 延时升高时，日志里往往只能拿到 http.Client 返回的总耗时（例如 2.1s）。但这个 2.1s 究竟卡在哪一步？

是 DNS 域名解析遭遇超时抖动，还是 TCP 三次握手由于跨机房 RTT 过高？抑或是 TLS 握手在进行复杂的证书链验证？甚至只是对方服务器 Backend 处理逻辑本身缓慢？

如果缺乏精细化的链路耗时拆解，排查网络瓶颈就只能靠凭空猜测。Go 语言标准库提供的 net/http/httptrace 包，正是解决这一难题的利器。

埋点 Hook 机制原理

Go 语言在 net/http 内部预留了一套极其优雅的观察者机制。httptrace 的核心在于 httptrace.ClientTrace 结构体。

请求发起前，开发者将包含了各类 Hook 回调函数的 ClientTrace 对象通过 Context 绑定到 http.Request 中：

   // 将 ClientTrace 注入 Request Context
ctx := httptrace.WithClientTrace(req.Context(), trace)
req = req.WithContext(ctx)

当 http.DefaultTransport 执行 HTTP 传输生命周期时，底层会在连接池复用检查、DNS 查询、TCP 建连、TLS 协商以及收到响应首字节等关键节点，自动触发注册在 Context 中的回调函数。

这种非侵入式的埋点设计，使得开发者无需修改 Transport 底层代码，就能精准捕捉请求耗时瀑布流。

关键阶段 Hook 回调详解

为了构建完整的网络耗时瀑布图，需要重点关注 HTTP 生命周期中的四组核心 Callback 节点。

DNS 解析阶段可以通过 DNSStart 与 DNSDone 组合测量：

   // 监听 DNS 解析起止时间
trace := &httptrace.ClientTrace{
    // DNS 解析开始回调
    DNSStart: func(_ httptrace.DNSStartInfo) {
        dnsStart = time.Now()
    },
    // DNS 解析完成回调
    DNSDone: func(_ httptrace.DNSDoneInfo) {
        dnsDone = time.Now()
    },
}

通过记录 DNSDone 与 DNSStart 的时间差，可以准确判断当前域名解析耗时。若频繁出现毫秒级延时，通常提示需要增加本地 DNS 缓存或优化 CoreDNS 配置。

TCP 连接建连与 TLS 握手阶段同样提供了对称的回调：

   // 监控 TCP 建连与 TLS 握手
trace := &httptrace.ClientTrace{
    // TCP 建连开始回调
    ConnectStart: func(_, _ string) {
        connStart = time.Now()
    },
    // TCP 建连完成回调（包含建连结果与错误信息）
    ConnectDone: func(_, _, _ error) {
        connDone = time.Now()
    },
    // TLS 握手开始回调
    TLSHandshakeStart: func() {
        tlsStart = time.Now()
    },
    // TLS 握手完成回调（包含 TLS 状态与握手错误）
    TLSHandshakeDone: func(_ tls.ConnectionState, _ error) {
        tlsDone = time.Now()
    },
}

通过这两组回调的毫秒差，能够清楚区分出网络物理延迟（TCP 握手时间）与加密开销（TLS 协商时间）。在长连接连接池保持良好的场景下，这两个耗时通常为 0。

服务端首字节响应时间（TTFB）则是评估下游服务器处理性能的关键指标：

   // 捕获首字节到达时间（TTFB）
trace := &httptrace.ClientTrace{
    // 收到 HTTP 响应头的第一个字节回调
    GotFirstResponseByte: func() {
        gotFirstByte = time.Now()
    },
}

GotFirstResponseByte 会在 Client 收到 HTTP 响应头的第一个字节时瞬间触发。从请求发送完毕到触发该回调的间隔，即为对方服务器的真实处理时长。

此外，还需结合 GotConn 回调感知连接是否成功复用了 HTTP 长连接连接池：

   // 获取连接复用状态
trace := &httptrace.ClientTrace{
    // 成功建立/取得连接回调（包含连接复用标记 Reused）
    GotConn: func(info httptrace.GotConnInfo) {
        reused = info.Reused
    },
}

通过 info.Reused 可以避免把“首次建连开销”误判为“对方响应慢”。

打造开箱即用的 Trace Client

将上述 Hook 封装为一个轻量级的 Tracer，即可直接打印精细化的耗时瀑布日志。

首先定义 Trace 数据采集结构体与耗时指标：

   type TraceMetrics struct {
    DNS, TCP, TLS, TTFB, Total time.Duration
    Reused                     bool
}

在发起请求前构造 ClientTrace 实例并注册网络各阶段回调：

   // 构建 ClientTrace 收集各阶段耗时
trace := &httptrace.ClientTrace{
    // 1. 记录 DNS 解析阶段耗时
    DNSStart: func(_ httptrace.DNSStartInfo) {
        dStart = time.Now()
    },
    DNSDone: func(_ httptrace.DNSDoneInfo) {
        m.DNS = time.Since(dStart)
    },
    // 2. 记录 TCP 建连阶段耗时
    ConnectStart: func(_, _ string) {
        cStart = time.Now()
    },
    ConnectDone: func(_, _, _ error) {
        m.TCP = time.Since(cStart)
    },
    // 3. 记录 TLS 加密握手耗时
    TLSHandshakeStart: func() {
        tStart = time.Now()
    },
    TLSHandshakeDone: func(_ tls.ConnectionState, _ error) {
        m.TLS = time.Since(tStart)
    },
    // 4. 记录连接复用标志与首字节响应耗时 (TTFB)
    GotConn: func(i httptrace.GotConnInfo) {
        m.Reused = i.Reused
    },
    GotFirstResponseByte: func() {
        m.TTFB = time.Since(t0)
    },
}

这段代码通过闭包在各个 Callback 执行时计算阶段差值，非阻塞地收集网络性能元数据。

在业务发起请求时绑定 Context 并输出耗时瀑布日志：

   // 执行 HTTP 请求并打点耗时
req = req.WithContext(httptrace.WithClientTrace(req.Context(), trace))
resp, err := client.Do(req)
m.Total = time.Since(t0)

log.Printf("[HTTP Trace] Total:%v Reused:%t DNS:%v TCP:%v TLS:%v TTFB:%v",
    m.Total, m.Reused, m.DNS, m.TCP, m.TLS, m.TTFB)

线上日志中输出的结果形如 Total:52ms Reused:false DNS:1.2ms TCP:2.5ms TLS:15ms TTFB:33ms。当下游响应变慢时，耗时瀑布图能在一秒内指明真正的责任方。