3.4 链路追踪：一次请求慢在哪一环

场景：用户说下单慢，全员都说不是我

网关上线后的第二周，客服接到反馈：下单偶尔要等七八秒。我们五个人的群开始互相甩锅——前端说接口返回慢，订单服务说库存查询不归我，商品服务说数据库看着没压力，运维说 CPU 内存都正常。吵了一圈，谁也拿不出证据。

这就是没有链路追踪的典型场面：一次请求经过网关、订单、商品、用户四个节点，日志分散在四台 CVM 上，用 grep 串时间线基本不可能。这件事的背景在 可观测性建设 里有展开，本节讲我们怎么把 trace 真正落到 gRPC 链路里。

从日志到 trace：先看清调用拓扑

引入 OpenTelemetry 之前，我们靠 request_id 在每条日志里打 grep，能拼出大致顺序，但耗时分布完全靠猜。上了追踪系统后，第一次看到完整的火焰图，全组沉默了三秒：原来 60% 的耗时花在订单服务里一段多余的库存双写校验上。这段代码是当初为了稳加的双保险，拆分后两个调用落在不同服务，重复校验每次都要跨网络查一遍，纯属浪费。

先列一张观测手段对照表，方便确定各自的位置：

落地选型我们用了开源的 OpenTelemetry SDK 加自建 Jaeger，日志再统一投递到 CLS，和 统一日志收集 的方案打通，一条 trace_id 能在两个系统里互相跳转。收集器那边单独占一台 CVM，成本可控，类型选择和扩容思路可以参考 CVM 实例选型清单。

还有一个决策点是采样策略。常见有三种做法，我们最终的组合方案如下：

我们的组合是：正常链路按比例采样，错误和慢链路强制全采。这样存储成本可控，排查时又不缺现场。

上线第一周我们就靠这套东西定位了一个经典问题：接口偶发慢三秒，看监控曲线毫无规律，看 trace 才发现是某次 redis 调用超时重试，重试机制本身放大了耗时。没有追踪之前，这类问题只能靠玄学复现。

落地：context 串起整条链路

Go 服务接入 OpenTelemetry 只需三步，整体不算复杂，一个实习生两天就搞定了三个服务的接入。第一步初始化 tracer provider，这一步决定 trace 数据往哪发、服务名是什么：

func setupTracing(ctx context.Context) error {
    exp, err := otlptracegrpc.New(ctx,
        otlptracegrpc.WithEndpoint("otel-collector:4317"),
        otlptracegrpc.WithInsecure(),
    )
    if err != nil {
        return err
    }
    tp := sdktrace.NewTracerProvider(
        sdktrace.WithBatcher(exp),
        sdktrace.WithResource(resource.NewWithAttributes(
            semconv.SchemaURL,
            semconv.ServiceNameKey.String("order-svc"),
        )),
    )
    otel.SetTracerProvider(tp)
    return nil
}

第二步，gRPC 服务端和客户端各加一个拦截器。这一步是关键：trace context 必须自动跨服务传播，不然每段 trace 都是孤岛：

srv := grpc.NewServer(
    grpc.StatsHandler(otelgrpc.NewServerHandler()),
)
conn, err := grpc.Dial(
    target,
    grpc.WithStatsHandler(otelgrpc.NewClientHandler()),
)

第三步，业务代码里打 span。我们只给关键环节加，埋点过多反而干扰判断：

ctx, span := otel.Tracer("order").Start(ctx, "checkStock")
defer span.End()
stock, err := productClient.GetProduct(ctx, productID)

HTTP 网关那一层也不能漏。客户端 HTTP 进来时，otelmux 中间件会从 traceparent header 里提取上游上下文，生成新的根 span；调用方没有传 header 就新建一条，保证从入口起每一段都在同一棵树下：

r.Use(otelmux.Middleware("api-gateway"))

同时把 trace_id 写进结构化日志，这样 CLS 里的每条日志都带着同一 id，排查时先看 trace 定位环节，再回 CLS 捞明细，这套流程和 监控告警体系 配合使用。

踩坑记录

第一个坑就是断链。上线后 trace 只剩零星几段，原因是有个接口绕过了 gRPC 拦截器直接走了 http client，context 里的 trace 信息没传过去。后来定了死规矩：所有出站调用必须用同一个 ctx，code review 重点查这个。

第二个坑是采样率。默认按比例采样，大促时 1% 也能看到大量慢 trace，反而找到了几个偶发问题；但平时低流量时一些只出现几次的报错被采样掉了，排查时正好缺那一条。最后的做法是慢调用和错误链路强制全采，正常链路按比例。

第三个坑是 span 太多。有个同事把每个数据库查询都包一层 span，一个请求展开 300 多个节点，Jaeger 页面直接卡死。后来约定数据库只在事务级别打 span， span 总数控制在 20 个以内。

第四个坑是时钟。有次 trace 时间线显示子 span 比父 span 还早，吓出一身冷汗，其实是某台 CVM 的 NTP 没同步。所有机器统一装 chrony 之后正常了，机器初始化检查清单也跟着更新了一条。

第五个坑是异步任务断链。下单后发短信走的是 RocketMQ 异步消费，trace context 跨消息队列默认不传递，消费侧一看是全新的根 span，和下单链路完全对不上。解决办法是发送消息时把 context 序列化进消息属性字段，消费端反序列化后接上 context，消息队列的更多玩法见 RocketMQ 削峰实战。

第六个坑是 trace 存储膨胀。全量采集两周后 Jaeger 后端的存储占用翻了三倍，空间告急。除了调低正常链路采样率，还加了存储保留期策略：原始明细保留 7 天，聚合统计保留 90 天，既能满足日常排查，也满足长期趋势分析的需求，数据管理思路和 成本治理 一脉相承。

小结

追踪系统上线一个月后，我们做了一次统计：p99 接口耗时从 800 毫秒压到 260 毫秒，定位一次慢调用的平均时间从半天缩到十分钟。更重要的是会议风气变了——以前甩锅会，现在直接把 trace 图甩在群里，谁的问题谁领走。

回过头看，可观测性建设的顺序应该排在拆分之后、业务复杂化之前：拆分初期服务少、链路短，正是埋点成本最低的时候。等到五六个服务再补，历史代码每一处都要回填埋点，痛苦得多。另外一个建议是接入时先抓准服务名与版本号两个资源属性，标错会导致同一服务的 trace 被拆成两份，图上频繁断链，查起来误导性极强。网关、注册中心、gRPC 加上 trace，服务间通信这条线算是闭环了，下一篇要面对的是拆库后的数据一致性难题。Collector 所在的机器同样可以走 腾讯云 CVM 新用户特惠。

延伸阅读

• Go 微服务实战：从单体到云原生
• 腾讯云架构实践精选
• 语音会议与实时通信实战