Go httptrace.ClientTrace 怎么定位 DNS 到首字节延迟：HTTP 请求链路的观测边界

Go 程序访问一个接口时，看到的“请求耗时 800ms”只是总数，不能直接说明是 DNS、TCP、TLS 还是服务端首字节慢。net/http/httptrace 提供了请求生命周期中的回调，可以把一次请求拆成可核对的时间段。

先记录 DNSStart、ConnectStart、GotConn、WroteRequest 和 GotFirstResponseByte，再根据相邻时间点判断慢在连接建立、写请求还是服务端开始响应。

先把一次 HTTP 请求拆成可观察事件

下面这段示例把事件时间放进 traceTimes，并在请求完成后计算几个有意义的间隔。节点 DNSStart、ConnectStart、GotConn、WroteRequest 和 GotFirstResponseByte 都是真实回调名，图示只解释它们在调用链中的先后关系。

type traceTimes struct {
    dnsStart, connectStart, gotConn time.Time
    wroteRequest, firstByte        time.Time
}

times := &traceTimes{}
trace := &httptrace.ClientTrace{
    DNSStart: func(httptrace.DNSStartInfo) { times.dnsStart = time.Now() },
    ConnectStart: func(_, _ string) { times.connectStart = time.Now() },
    GotConn: func(httptrace.GotConnInfo) { times.gotConn = time.Now() },
    WroteRequest: func(httptrace.WroteRequestInfo) { times.wroteRequest = time.Now() },
    GotFirstResponseByte: func() { times.firstByte = time.Now() },
}
req = req.WithContext(httptrace.WithClientTrace(req.Context(), trace))

这里没有把回调里的时间直接打印到日志，而是先保存，再统一计算。这样可以避免日志输出本身改变请求时序，也方便给缺失事件保留空值。

用相邻时间点判断慢在哪一段

拿到事件时间后，最有用的不是一串绝对时间，而是阶段差值。ConnectStart 到 GotConn 反映连接建立或等待连接的区间；WroteRequest 到 GotFirstResponseByte 更接近服务端开始返回前的等待。

func since(later, earlier time.Time) time.Duration {
    if later.IsZero() || earlier.IsZero() {
        return 0
    }
    return later.Sub(earlier)
}

dnsCost := since(times.connectStart, times.dnsStart)
connectCost := since(times.gotConn, times.connectStart)
serverWait := since(times.firstByte, times.wroteRequest)
fmt.Printf("dns=%s connect=%s server_wait=%s\\n", dnsCost, connectCost, serverWait)

这段计算有一个刻意的边界：事件缺失时返回 0 只是“无法计算”，不是“耗时为零”。连接复用时没有新的 ConnectStart，这时不应把连接成本记成一次真实的零耗时。

连接复用会让哪些回调不出现

同一个 http.Transport 复用空闲连接时，请求可能直接进入 GotConn，不再经历新的 DNS 和 TCP 连接。若把每次请求都按“DNS 加连接”解释，会误判复用连接的请求很快，也会漏掉真正的服务端等待。

排查时建议同时记录 httptrace.GotConnInfo.Reused 和 WasIdle。一条 Reused=true 的记录说明连接阶段没有重新发生，应该把注意力移到写请求、首字节和响应体读取。

不要把首字节当成完整响应

GotFirstResponseByte 只表示客户端收到响应的第一个字节。大响应可能在首字节之后继续读取很久，因此还应在 io.ReadAll(resp.Body) 前后记录完整读取耗时，并确保关闭响应体。

另一个常见误区是把 DNS 时间、连接时间和服务端等待时间直接相加。事件可能因连接复用而缺失，而且代理、TLS 和重定向会改变链路；应以实际出现的事件为准，先标记缺失，再进行阶段归因。

一份适合日志的最小核对清单

• 是否使用同一个 http.Transport，并记录 GotConnInfo.Reused。
• 是否区分“事件未发生”和“事件发生但耗时为零”。
• 是否分别记录 GotFirstResponseByte 与响应体读取完成。
• 是否给请求设置超时，避免等待首字节时无限挂起。

相关问题

为什么第二次请求没有 DNSStart？

通常是连接或解析结果被复用，先看 GotConnInfo.Reused，不要据此判断 DNS 一定异常。

如何判断是服务端慢还是下载慢？

用 GotFirstResponseByte - WroteRequest 看首字节等待，再用响应体读取前后的时间看下载阶段。

总结

httptrace.ClientTrace 的价值是把总耗时变成事件之间的证据。先看连接是否复用，再按实际存在的回调计算阶段差值，最后把首字节等待和响应体读取分开，定位结果才不会被一个总耗时数字带偏。