采样率设成 1% 那次，最慢的那批请求一条都没采到：可观测性三支柱的 4 个反直觉细节

title: 采样率设成 1% 那次最慢的那批请求一条都没采到可观测性三支柱的 4 个反直觉细节tags: 可观测性,链路追踪,OpenTelemetry,日志,指标category: 后端一个查了三个小时也没查出来的慢接口去年 6 月运营反馈履约中心的订单详情接口偶尔要转好几秒。我们看了监控大盘P99 是 340msP999 是 2.1 秒QPS 大约 600。数字不算漂亮但也不至于让人卡到抱怨。真正难受的是查不出来。我们有链路追踪Jaeger 里翻了半小时找到的 trace 全是 50-80ms 的正常请求一条超过 1 秒的都没有。团队里有人说是不是采样没采到我当时的反应是采样率 1%600 QPS一分钟也有 360 条 trace怎么可能一条慢的都没有后来才想明白这是个概率问题也不完全是概率问题。P999 意味着 1000 个请求里有 1 个慢1% 的采样意味着 100 个请求里采 1 个。两个事件独立的话采到一条慢请求的期望是每 10 万个请求一次600 QPS 下差不多每 3 分钟一条。理论上翻半小时应该能看到十条。但我们的采样是头部采样head-based sampling在链路入口就用 traceId 的哈希决定采不采。而慢请求集中在一个特定的场景用户订单里包含跨境商品时会额外调一次报关信息服务。这类订单占全量的 0.8%。1% 的均匀采样 × 0.8% 的场景占比采到的概率是万分之八——半小时 108 万个请求期望 8.6 条而这 8.6 条散落在几十万条 trace 里肉眼根本翻不到。采样率不是采到多少是采到什么。这是第一个反直觉的地方。从头部采样切到尾部采样我们的方案是引入 OpenTelemetry Collector 的tail_sampling处理器把决策从入口挪到链路结束之后。配置大概是这样processors: tail_sampling: decision_wait: 10s num_traces: 100000 policies: - name: slow-traces type: latency latency: { threshold_ms: 800 } - name: error-traces type: status_code status_code: { status_codes: [ERROR] } - name: baseline type: probabilistic probabilistic: { sampling_percentage: 1 }三条策略是或的关系慢的全采、错的全采、剩下的按 1% 采基线。切过去当天Jaeger 里立刻出现了几百条 2 秒以上的 trace一眼看到报关信息服务那一段占了 1.8 秒。Java 侧要配合改一件事确保 span 上带了足够的属性否则采到了也定位不了。我们在 Feign 拦截器里补了业务维度public class TracingFeignInterceptor implements RequestInterceptor { Override public void apply(RequestTemplate template) { Span span Span.current(); if (!span.getSpanContext().isValid()) { return; // 没有活跃 span直接返回 } // 业务维度跨境订单、店铺 ID、渠道用于事后按维度筛 trace OrderContext ctx OrderContextHolder.get(); if (ctx ! null) { span.setAttribute(order.cross_border, ctx.isCrossBorder()); span.setAttribute(order.shop_id, ctx.getShopId()); span.setAttribute(order.channel, ctx.getChannel()); } // 把 traceId 透传到下游的自定义头方便日志侧关联 template.header(X-Trace-Id, span.getSpanContext().getTraceId()); } }逐行说下考虑第 6-8 行必须判空。在异步线程、定时任务里Span.current()拿到的是Span.getInvalid()直接setAttribute不报错但数据全丢白写。第 12 行的cross_border就是那次事故留下的教训。事后我们才能在 Jaeger 里用order.cross_bordertrue一键筛出问题链路。第 17 行透传 traceId 到 header是为了让下游服务在日志里也能打出同一个 traceId。OpenTelemetry 的 W3Ctraceparent头本身能透传但有些老服务不认加一个明文头成本很低。有一个坑要提醒setAttribute写入的属性数量在 OpenTelemetry Java SDK 里默认上限是 128 个超出会被静默丢弃。我们曾经在循环里给 span 打过订单里每个 SKU 的 ID30 个 SKU 就写 30 个属性跟其他属性一叠加就顶到上限导致后面真正重要的属性被丢。改成拼成一个逗号分隔的字符串就好了。日志traceId 不落盘等于白追Trace 能告诉你哪一段慢但告诉不了你为什么慢。那次报关服务的 1.8 秒最终是靠日志定位到它在做一次没走索引的模糊查询。前提是日志里得有 traceId。我们用的是 Logback MDC接入方式是 OpenTelemetry 的 logback appenderpublic class TraceIdMdcFilter extends OncePerRequestFilter { private static final String MDC_TRACE_ID traceId; private static final String MDC_SPAN_ID spanId; Override protected void doFilterInternal(HttpServletRequest req, HttpServletResponse resp, FilterChain chain) throws ServletException, IOException { SpanContext sc Span.current().getSpanContext(); boolean valid sc.isValid(); if (valid) { MDC.put(MDC_TRACE_ID, sc.getTraceId()); MDC.put(MDC_SPAN_ID, sc.getSpanId()); resp.setHeader(X-Trace-Id, sc.getTraceId()); // 回吐给前端方便客服报障 } try { chain.doFilter(req, resp); } finally { if (valid) { MDC.remove(MDC_TRACE_ID); // 必须清理线程会被复用 MDC.remove(MDC_SPAN_ID); } } } }第 21-22 行的清理是重点。MDC 底层是ThreadLocalTomcat 的线程池会复用线程。不清理的话下一个请求如果因为某些原因没进这个 filter比如静态资源、错误页就会打出上一个请求的 traceId。我们出过一次这个问题排查时按 traceId 搜出来的日志横跨了三个不相干的订单非常迷惑。第 14 行把 traceId 写回响应头是我强烈推荐的做法。客服接到用户报障时让用户提供一下页面上的错误码我们把 traceId 后 8 位显示在错误页比让用户描述我大概几点钟点的高效一百倍。异步场景要额外处理。我们用TaskDecorator把 MDC 传到线程池Bean public TaskDecorator mdcTaskDecorator() { return runnable - { MapString, String parent MDC.getCopyOfContextMap(); // 提交时的父线程上下文 Context otelContext Context.current(); // OTel 上下文 return () - { MapString, String previous MDC.getCopyOfContextMap(); if (parent ! null) { MDC.setContextMap(parent); } try (Scope ignored otelContext.makeCurrent()) { // 让子线程 span 挂到父链路 runnable.run(); } finally { if (previous ! null) { MDC.setContextMap(previous); } else { MDC.clear(); } } }; }; }第 4 行在提交任务的线程里拿快照第 6 行返回的 lambda 在执行任务的线程里跑这个先后关系搞反了就完全无效。我见过有人把getCopyOfContextMap()写在 lambda 里面等于拿了执行线程自己的上下文等于没做。第 11 行的makeCurrent()配合 try-with-resources保证子线程结束后作用域正确关闭。少了这一步异步任务里创建的 span 会变成孤儿根 span在 Jaeger 里显示成一条独立的链路。指标为什么 P99 会骗人三支柱里最容易被误用的是指标。我们踩过的坑是分位数聚合。假设有 10 个 Pod每个 Pod 上报自己的 P99。Prometheus 里做avg(http_request_p99)得到的数字不是集群的 P99——分位数不可平均这是数学事实。10 个 Pod 各自的 P99 平均值可能显著低于整体 P99。正确做法是上报直方图histogram在查询时聚合Bean public MeterFilter histogramFilter() { return new MeterFilter() { Override public DistributionStatisticConfig configure(Meter.Id id, DistributionStatisticConfig config) { if (id.getName().startsWith(http.server.requests)) { return DistributionStatisticConfig.builder() .percentilesHistogram(true) // 输出 _bucket 序列 .serviceLevelObjectives( Duration.ofMillis(50).toNanos(), Duration.ofMillis(100).toNanos(), Duration.ofMillis(200).toNanos(), Duration.ofMillis(500).toNanos(), Duration.ofSeconds(1).toNanos(), Duration.ofSeconds(3).toNanos()) .build().merge(config); } return config; } }; }第 9 行percentilesHistogram(true)让 Micrometer 输出 Prometheus 的_bucket时间序列之后就能用histogram_quantile(0.99, sum(rate(http_server_requests_seconds_bucket[5m])) by (le))算出真正的集群 P99。第 10-16 行手动指定了 SLO 边界。默认的percentilesHistogram会生成 60 多个桶每个桶是一条时间序列乘上 uri、method、status 几个标签序列数很容易爆炸。我们上线第一版没限制桶Prometheus 的内存从 6GB 涨到 21GB被 OOMKill 了两次。指定 6 个业务真正关心的边界之后序列数降到原来的十分之一。这是第三个反直觉点指标的成本不在于打点而在于标签的笛卡尔积。一个 uri 标签如果把路径参数也带进去比如/order/12345几万个订单号就是几万条时间序列。我们现在的规矩是任何新增标签必须能说清它的基数上限。三支柱各自的定位维度TraceLogMetric回答的问题哪一段慢/错为什么慢/错有没有问题、多严重数据粒度单请求单事件聚合存储成本高可采样降低最高低查询延迟秒级秒到分钟级毫秒级适合告警不适合部分适合最适合保留周期我们的配置7 天14 天热 90 天冷15 个月我们的排障动线固定是Metric 发现异常 → Trace 定位到具体服务和 span → Log 看那个 span 期间的详细上下文。三步走缺一步都会卡住。有人主张只留日志日志里什么都有。我不认同。600 QPS 的服务一天的日志量是几百 GB没有 trace 做索引你根本不知道该搜哪一段。反过来只有 trace 没有日志也不行span 里塞不下堆栈和 SQL 语句。复盘数据那次改造前后的对比指标改造前改造后慢请求 trace 捕获率约 1%约 100%800ms 全采平均排障耗时P503.2 小时25 分钟Trace 存储量日均 40GB日均 52GBPrometheus 内存21GBOOM 过7.4GBCollector CPU尾采样—常驻 2.3 核尾部采样不是免费的。Collector 要把一条链路的所有 span 缓存decision_wait时长我们配 10 秒等链路结束才决策。num_traces: 100000这个上限对应的内存我们实测约 3.5GB。链路 QPS 再翻一倍的话Collector 就得横向扩而横向扩又带来新问题同一条 trace 的 span 必须路由到同一个 Collector 实例否则尾采样看到的是残缺链路。我们是在 Collector 前面加了一层按 traceId 做一致性哈希的loadbalancingexporter 解决的。我的取舍建议如果团队刚开始建可观测性我的建议顺序是先指标再日志最后 trace。理由很实际——指标的投入产出比最高一个 Prometheus 加几个 Grafana 面板一天就能让你知道服务有没有问题。日志次之大部分团队本来就有加个 traceId 就能用。Trace 的接入成本最高还要改代码、改配置、扩基础设施在服务数少于 10 个的时候收益有限。反过来服务数超过 30 个、调用层级超过 4 层之后trace 从锦上添花变成没有就没法干活。我们是在服务数到 60 多个的时候才彻底重视 trace 的回头看晚了大概一年。对采样策略我的判断是头部采样适合成本敏感、故障率低的成熟系统尾部采样适合排障压力大、慢请求分布不均匀的系统。混合用也可以——入口做 10% 的头部采样保底Collector 再做尾部筛选能省掉 90% 的 span 传输带宽。最后留个问题你们的 trace 保留多久我们定的是 7 天理由是超过一周的链路数据几乎没人查。但每次做季度容量复盘时又会有人抱怨想看看三个月前的链路对比。你们是怎么平衡存储成本和回溯需求的评论区聊聊。