耗时最长的 span 并不是元凶

一句话总结

修复跟踪（trace）中最长的跨度，通常是白费力气。真正能缩短响应时间的，只有自身耗时大、并且位于关键路径上的跨度。

为什么需要它

订单 API 的 p50 是 290 毫秒。打开跟踪，屏幕最上面有一根 158 毫秒的条——是库存查询。两个人花了三天给那个查询加上缓存，发布后的第二天看仪表板，p50 是 289 毫秒。只少了 1 毫秒。

原因很简单。库存查询与价格计算是同时开始的。库存查询在 158 毫秒时结束，而价格计算还在运行，网关要等两者都结束。结束得晚的一方，决定响应时间。即使把库存查询变成 0，网关仍然要等价格计算。

这种错觉很大程度上要怪界面。瀑布图（waterfall）按长度顺序显示跨度，人的眼睛会先看向最长的条。然而条的长度表示的是“那一段花了多少时间”，而不是“缩短那一段，整体会不会缩短”。这是两个不同的问题，要回答第二个问题，需要计算。

工作原理

给出答案的是两项计算。

自身耗时（self time） 是该跨度没有交给子跨度、自己直接花费的时间。用总时间减去子跨度占用的时间。这里会滑一跤，不能把子跨度的时间简单相加再减去。如果有并行运行的子跨度，它们的总和就会超过父跨度的总时间，自身耗时就会变成负数。必须减去子跨度区间的并集长度。

关键路径（critical path） 是从根的结束处倒着扫描构建出来的。比当前正在看的时刻结束得更晚的子跨度要跳过，转向结束得最晚的子跨度。沿着那个子跨度一直走到它开始的时刻，然后转到在此之前结束的同级跨度。这样，从根的开始到结束就被无缝覆盖，每一段的归属也就确定了。各段之和恰好等于根的持续时间——这个等式是检验计算是否正确的验算。

把两项计算合在一起，排名就会颠倒。在上面的事故中，库存查询是总时间第一、自身耗时第一，但对关键路径的贡献是 0。相反，价格规则评估的总时间排第三，对关键路径的贡献却高达 142 毫秒，非常突出。该修复的是第三名。

再加上一点。N+1。如果有几十个同名的同级跨度排成一列，每一个只有 3 毫秒，排不进名次。然而把十六个加起来是 45 毫秒，合并成一次查询后，其中的 42 毫秒就会消失。只有看分组，而不是看单个跨度，才能看到。

OpenTelemetry 的跟踪文档把跨度定义为一个工作单元，把跟踪定义为请求经过的路径。跨度中包含开始时刻、持续时间和父跨度的标识符，而计算关键路径所需的，只有这三样。也就是说，没有工具，用标准库也能计算。

在现场相遇的样子

有四种情况反复出现。

第一，p50 和 p99 的关键路径不同。 平时价格计算最后结束，但库存数据库卡住的那一刻，库存查询变成最后结束的。只看 p50 来修复，p99 依旧不变。所以需要养成习惯：分别取出两条跟踪，比较它们的关键路径。

第二，数据很脏。 如果采集器丢失了片段，就会留下父跨度不在文件中的孤儿跨度，也会出现整个根都缺失的跟踪。如果把这样的跟踪直接混在一起计算，合计就会悄悄出错。在计算之前，必须有一个步骤，只挑出“只有一个根且没有孤儿”的跟踪。

第三，把计算对象取几条，会改变结论。 延迟是四个黄金信号之一，要改善这个指标，必须先确定以哪些跟踪作为代表。如果只看一条跟踪来确定关键路径，就容易把这一条的偶然当作瓶颈。反过来，如果对几千条求平均，并行结构会相互抵消，哪里都不突出。现实的折中办法是，把入口相同（根跨度名称相同）的归为一组，从持续时间分布中选出几个有代表性的点，分别计算，然后看进入路径的跨度名称是否重合。名称重合，就是结构性瓶颈；如果分歧，就是随条件变化的瓶颈，修复的方法也不同。

第四，没有写下预期节省的改进，是未经验证的。 “修复这个应该会变快”，在发布后没有办法确认。如果在修复之前，用数字写下“根会减少 142 毫秒”，发布之后，对还是错都会留下记录。如果错了，就是模型错了，这会纠正下一次的判断。

下一项实验要做什么

仅用标准库分析 Pod 中的 3,454 个跨度（150 条跟踪）。重新连接父子关系并标注深度，把重叠的子跨度按并集处理来求出自身耗时，计算关键路径，并验算各段之和是否等于根的持续时间。然后用表格确认“耗时最长的跨度”列表、“自身耗时靠前”列表和“关键路径贡献靠前”列表互不相同，并找出 N+1，计算合并后的节省。最后比较 p50 和 p99 跟踪的关键路径，把要修复什么连同预期节省时间一起作为文件提交。