服务器开发工程师的分布式追踪实战手册
|
接口背锅那天我正对着 trace 查 latency outlier，前端甩来个截图：下单耗时四秒二，用户投诉电话已打爆客服线。我点开 span list，发现 98% 的延迟卡在下游一个叫 order-status-sync 的服务里——结果这服务上个月刚被 DBA 劈掉 half，现在全走缓存兜底，连 metric 都没开采样。我顺手切到 dependency graph，发现它居然还挂着三个灰度开关，其中两个绿灯亮着，第三个标着「待灰度」但状态是 unknown。这个我敢打包票，不是 bug，是上次发版漏 push 配置，运维说「等下周统一推」，然后上周五凌晨三点那个 oncall 手机震了一下，我接起来听见他说「先回滚 config，别动代码」，我就挂了。 “后端分布式追踪实战手册”？一个月之前我翻过它第十七页，讲的是 context propagation 要对齐 tracer 版本号。结果我们线上跑了三套 tracer：Jaeger SDK v1.32（老 Java 服务）、OpenTelemetry v1.26（新 Go 模块）、还有个 Python 服务硬塞了自己写的 patch，把 baggage 值做了 base64 再 decode 两次再丢进 tag——因为某个 PM 说「必须透传用户渠道来源，不能被中间件吞掉」。这个我说不准是不是他们抄错文档，反正那行 decode 逻辑在 trace 火焰图里压根不显形，只在 span 标签里多出一段乱码 tag，看着像 base64，其实 decode 失败后 fallback 成了字符串字面量“”。我原以为删掉那段 patch 就能消掉那个 37ms 的无效串行调用，结果发完灰度才发现——延迟没降，反而订单创建成功率掉了千分之二，因为那个“”被风控系统当真用了。 咖啡杯上印的公司 logo 已经掉漆，露出底下灰白塑料，倒水的是测试小李，她端着杯子路过我工位时说「你那个 trace 上线 checklist 里没写 cleanup baggage 吧」，我没理，她就把水放我桌角，水渍在笔记本封皮上洇开一小片，像张未闭合的 span。我盯着那个水渍改了三遍 header 注入逻辑：第一次加 X-B3-TraceId 透传，第二次发现 grpc metadata 不认大小写所以换成 x-b3-traceid，第三次才想起我们网关层默认 strip 掉所有带 x- 前缀的 header，于是改成 trace-id，又撞上某中间件正则规则里写死了「trace\\-id」必须带连字符……最后上线前十五分钟，我改回 X-Trace-ID，并让网关同学手动放开白名单。他敲完命令回车，监控大屏上一条无关曲线——「集群磁盘 io wait %」——忽然抖了一下，升到 18.7，持续两秒，然后落回 2.3，谁都没提，也没告警。
文章配图，仅供参考 优胜劣汰？呵。我们上周下线了两个 tracing agent 插件，因为它们在 JDK17 上触发了 ClassLoader 内存泄漏，GC 日志里每小时多十次 full gc。不是性能差，是根本活不过十二小时。另一个还在跑的服务，它打的 span 名全是“unknown-operation”，但 traceID 对得上，log 中 timestamp 和 duration 也跟 client 发的吻合——只是 span name 字段永远 null，因为启动参数里漏传了 -Dotel.instrumentation.common.default-span-name=xxx 这半截。没人修，就让它挂着，反正报警靠的是 error rate + p95 latency，而它从不报错，也不慢。DBA 昨天拿这个例子怼我：「你那个 trace 系统，连自己是谁都说不清，还让我信它查慢查？” 我没接话。他去茶水间倒水的时候，我打开数据库连接池监控看 idle count，发现比平时低七百。这个我说不准是压测导致还是 leak，但我记得上个月同一天，idle count 也是这样掉——然后第三天凌晨三点，连接池耗尽，整个库存服务雪崩。但这次没雪崩，因为产品经理临时砍掉了「秒杀倒计时」功能，说是「UI 改版优先级更高」。KPI 表里这个需求还挂着绿色进度条，写着「已交付」。最绝的是那个反常识结论：我们加了全链路 tracing 之后，平均修复时间 MTTR 缩短了 43%，但 P0 故障次数反而涨了 28%。不是 tracing 导致故障变多，是因为以前没人敢动库存扣减那段 lua 脚本，现在一看 trace 里 latency 很稳、error 为零、span 名都规范——大家就真信了。结果上周五，财务核对时发现三百七十二次调用里有四次金额错了十七毫秒，哦不对，是十七分钱。原因是 lua 脚本里用 os.time() 取本地时间做幂等 key，而那个节点 NTP 差了三秒二。我们 trace 没捕获 time 函数调用，也没 instrument redis.eval 的 input 参数——不是不能，是当时评审觉得「lua 是原子的，不需要拆」。现在想想，真不如当年手撸 log 打点，至少还能 grep 到 “os.time() 返回值是 172XXXXXXX”。 我原以为关掉自动采样就能逼所有人补 trace，结果他们连夜写了二十个 @Traced(false) 注解，理由是「这个接口纯内部调用，无业务意义」。可那个接口，是支付回调通知给风控的入口。我上周重放了三组真实流量进去，一次没报错，三次返回 HTTP 200，trace 上全标 success——但风控侧日志显示，其中一次根本没有收到 payload。我到现在没定位出来是哪儿丢了 body，只看见那条 span 的 tag 里写着 "http.content_length: 0"，而 upstream 的 response header 却明晃晃带着 "Content-Length: 437"。这事儿我暂时不追了。明天要交上线材料，里面有一栏叫「可观测性自评」，要求填三项指标达标率。我打算空着，让 PM 自己写。她前两天改了三次 PRD，第三次把我加的「埋点上报超时阈值」改成了「用户体验可接受等待时长」，还画了个饼图，配色特别像我们咖啡杯掉漆后露出的灰白色。 现在我电脑右下角弹了个窗口：「您的 OTel Collector 已离线 11 分钟」。我点了忽略。桌上那杯水已经凉透，杯沿留着半个唇印。要不要现在 reload config？算了，先去看眼那个还在抖的 io wait 曲线——等等，刚才它又动了一下。 （编辑：站长网） 【声明】本站内容均来自网络，其相关言论仅代表作者个人观点，不代表本站立场。若无意侵犯到您的权利，请及时与联系站长删除相关内容! |
