Go httptrace 怎样记录 TLS 握手耗时

排查 Go 客户端的 HTTPS 请求变慢时，我通常先把“总耗时”拆成几个阶段；否则 DNS、TCP 建连、TLS 握手和服务端处理时间会混在一起。要单独记录 TLS 握手，使用 net/http/httptrace.ClientTrace 的 TLSHandshakeStart 与 TLSHandshakeDone 两个回调即可：前者记起点，后者用单调时钟算耗时，同时保留握手错误。

官方地址：https://pkg.go.dev/net/http/httptrace

把 trace 放进请求上下文，再用一份“本次请求的观测状态”承接两个回调。握手成功记录 duration 和连接状态；握手失败记录 duration 与 error；如果连接直接复用、两个回调都没有发生，就不要把它误报成 0 毫秒。

先划清 TLS 握手耗时的范围

httptrace 用于观察一次出站 HTTP 请求中的事件。本文的指标起点是 Transport 开始 TLS 握手，终点是握手完成或失败，不包含 DNS 查找、建立 TCP 连接、发送请求头和等待响应首字节。

把 ClientTrace 挂到请求上下文

回调不会通过全局变量自动生效，需要创建 ClientTrace，再用 httptrace.WithClientTrace 返回一个带 trace 的上下文，并把它放回请求。这样同一个请求的 Transport 才能看到这些 hook。

package main

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

func requestWithTrace(ctx context.Context) (*http.Request, error) {
	trace := &httptrace.ClientTrace{
		// 这里先声明 TLS 回调，其他阶段保持独立，避免混算。
		TLSHandshakeStart: func() {},
		TLSHandshakeDone:  func(state tls.ConnectionState, err error) {},
	}

	req, err := http.NewRequestWithContext(
		httptrace.WithClientTrace(ctx, trace),
		http.MethodGet,
		"https://example.com/health",
		nil,
	)
	if err != nil {
		// URL 或上下文参数不合法时，把创建请求的错误交给调用方。
		return nil, fmt.Errorf("创建请求失败: %w", err)
	}
	return req, nil
}

上面的片段展示了挂载位置；真正统计时还需要在回调中共享开始时间。实际项目可以直接使用下面的完整实现，避免只复制结构片段后忘记补齐观测状态。

用单调时钟记录开始与结束

time.Now() 返回的时间值包含单调时钟读数，直接相减得到的 time.Duration 适合计算本地阶段耗时。不要把格式化后的字符串再解析回来计算，也不要用墙上时钟的文本值比较。

package main

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

type tlsObservation struct {
	start    time.Time
	duration time.Duration
	state    tls.ConnectionState
	err      error
	started  bool
	finished bool
}

func doRequest(client *http.Client, url string) (*http.Response, *tlsObservation, error) {
	observation := &tlsObservation{}
	trace := &httptrace.ClientTrace{
		TLSHandshakeStart: func() {
			// 只记录 Transport 真正开始的新握手，不把请求创建时间当起点。
			observation.start = time.Now()
			observation.started = true
		},
		TLSHandshakeDone: func(state tls.ConnectionState, err error) {
			// 回调可能携带失败错误；无论成功失败，都先保存结束时刻。
			if observation.started {
				observation.duration = time.Since(observation.start)
			}
			observation.state = state
			observation.err = err
			observation.finished = true
		},
	}

	req, err := http.NewRequest(http.MethodGet, url, nil)
	if err != nil {
		return nil, observation, fmt.Errorf("创建 HTTP 请求失败: %w", err)
	}
	req = req.WithContext(httptrace.WithClientTrace(req.Context(), trace))

	resp, err := client.Do(req)
	if err != nil {
		// Do 的错误仍然由调用方处理，trace 只负责补充阶段信息。
		return nil, observation, fmt.Errorf("发送 HTTP 请求失败: %w", err)
	}
	return resp, observation, nil
}

这里把观测状态放在一次调用内部，而不是放在包级变量中。这样多个 goroutine 同时发请求时，各自的开始时间、结束时间和错误不会互相覆盖。

在 Done 回调中区分成功与失败

TLSHandshakeDone 的第一个参数是 tls.ConnectionState，第二个参数是握手错误。成功时错误为 nil，可以记录协议或密码套件等连接状态；失败时优先记录 err，不要把零值的连接状态解释成一次成功握手。

func reportTLS(obs *tlsObservation) {
	if !obs.finished {
		// 没有结束回调时，说明请求没有走到握手完成事件，不能计算结果。
		fmt.Println("TLS: 未收到握手结束事件")
		return
	}
	if obs.err != nil {
		// 失败也有阶段耗时，但不能把它当成成功连接的耗时。
		fmt.Printf("TLS: 握手失败，耗时=%s，错误=%v\\n", obs.duration, obs.err)
		return
	}

	// 成功分支才读取连接状态用于诊断和指标标签。
	fmt.Printf("TLS: 握手成功，耗时=%s，协议=%s\\n", obs.duration, obs.state.NegotiatedProtocol)
}

失败耗时依然有排障价值：例如证书校验或协商失败发生得很快，网络重试或对端迟迟不返回则可能耗时更长。但这两个数字表达的是不同结果，日志字段最好分别保留 tls_handshake_ok 和 tls_handshake_error。

连接复用和 HTTP 代理怎样解释

如果 Transport 直接复用已经建立的连接，本次请求可能没有新的 TLS 握手，因此没有对应的 Start/Done 回调。此时应记录“未发生新握手”或“连接复用”，而不是写入 0 毫秒。对于 HTTPS 代理，官方文档说明 TLS 握手发生在代理处理 CONNECT 请求之后，所以不要把 CONNECT 之前的时间误标为 TLS 耗时。

接入指标时保留哪些字段

如果只是临时排查，日志保留 URL 主机、是否新握手、耗时和错误就够了。长期指标则建议把成功状态、连接复用状态和错误类型拆开，避免把缺失回调当成正常零值。

type TLSMetric struct {
	Host        string
	HandshakeMS int64
	HandshakeOK bool
	Reused      bool
	ErrorType   string
}

func metricFromObservation(host string, obs *tlsObservation, reused bool) TLSMetric {
	metric := TLSMetric{Host: host, Reused: reused}
	if !obs.started {
		// 连接复用时不产生新的 TLS 样本，使用状态字段表达缺失原因。
		return metric
	}
	metric.HandshakeMS = obs.duration.Milliseconds()
	metric.HandshakeOK = obs.err == nil
	if obs.err != nil {
		// 生产环境可按 errors.As 映射为稳定的错误类别。
		metric.ErrorType = obs.err.Error()
	}
	return metric
}

指标系统通常不适合直接把完整错误文本当标签，否则不同证书、主机或底层网络信息会造成高基数。示例保留原始错误便于理解；落地时可把它写入日志，再把指标标签收窄为固定错误类别。

常见问题

为什么请求很慢，但 TLS 握手耗时很小？

因为总耗时还可能包括 DNS、建连、等待服务端响应、响应体读取或重定向。TLS 指标只覆盖两个回调之间的区间。

为什么有些 HTTPS 请求没有 TLS 回调？

最常见的解释是连接复用；也可能是请求在进入握手前就失败。结合 Do 返回的错误和连接观测字段一起判断。

失败的握手要不要记录耗时？

要记录，但把成功状态设为 false，并保留错误。失败耗时能帮助区分立即拒绝与等待超时两类问题。

回调里能不能直接更新共享指标？

可以，但要按并发访问设计。官方文档提示 ClientTrace 的回调可能由不同 goroutine 并发调用，因此单次请求状态应使用独立对象，跨请求聚合则使用并发安全的计数器。

总结一下：用 WithClientTrace 把 trace 放进请求上下文，在 TLSHandshakeStart 保存起点，在 TLSHandshakeDone 计算耗时并分开处理成功与失败；没有新握手回调时，记录连接复用或未进入 TLS，而不是把缺失数据写成 0。