当一次请求经过网关、订单服务、库存服务和数据库时,每个节点的日志都只记录局部事实。分布式追踪把这些局部操作按因果关系关联起来,回答“这一次请求经过了哪里,时间花在哪里”。
它与指标、日志互补:指标描述大量请求的分布,追踪展示某个请求的结构,日志保留局部事件细节。一次 trace 可以解释一个慢请求,但不能单独代表整体故障率。总体测量见 指标与告警。
Trace 与 Span:时间区间加因果关系
Trace 是一组相关操作的集合,span 是其中一个有起止时间的操作,例如一次服务端请求、一次数据库访问或一个内部计算阶段。span 通常包含名称、ID、父 span、属性、事件和状态。
父子关系表示“这个操作在谁的上下文中发起”,并不等于“父 span 的耗时就是所有子 span 耗时之和”。多个子操作可以并发,父操作也可能有未埋点的计算、排队和序列化时间。
图中库存与价格同时开始,端到端时间取决于较慢的价格分支,再加前后阶段。把所有 span 时长相加会重复计算重叠时间。所谓关键路径,是限制整体完成时刻的依赖链;缩短不在关键路径上的工作,未必降低这次请求的延迟。
进一步区分 wall time 与 CPU time:一个 RPC span 持续 100 ms,其中可能大部分在等网络或线程调度。追踪能缩小范围,CPU 热点通常还需要采样剖析工具确认。
从瀑布图算出能改善多少,而不是把 span 时长相加
沿用图中的依赖:准备 10 ms 后并行发起库存和价格 RPC,两者全部结束后再整理响应 10 ms。假定缩短某分支不会改变其他阶段,就能算出每种改动对端到端时间的影响。
def latency(stock, price):
return 10 + max(stock, price) + 10
assert latency(70, 100) == 120
assert latency(30, 100) == 120 assert latency(70, 80) == 100
assert latency(70, 50) == 90
把价格从 100 ms 降到 50 ms,整体只从 120 ms 降到 90 ms,因为库存开始限制结束时刻。这个推演依赖“两条 RPC 必须全部完成”的已知业务结构;若是取最先成功、超时降级或取消其他分支,公式会改变,不能只凭两根重叠时间条推断等待语义。
父耗时减子耗时也需要去重。根区间 [0,120),库存 [10,80),价格 [10,110),两个子区间总长度 170,但覆盖的时间并集只有 100;未被这两条 RPC 覆盖的区间合计 20。
def covered(intervals, parent):
lo, hi = parent
assert lo <= hi
clipped = []
for start, end in intervals:
if start > end:
raise ValueError("reversed interval")
start, end = max(start, lo), min(end, hi)
if start < end:
clipped.append((start, end))
total, right = 0, lo
for start, end in sorted(clipped):
total += max(0, end - max(start, right))
right = max(right, end)
return total
assert covered([(10, 80), (10, 110)], (0, 120)) == 100
assert covered([(10, 110), (10, 110)], (0, 120)) == 100
assert covered([(-5, 10), (110, 140)], (0, 120)) == 20
assert covered([], (0, 120)) == 0
20 ms 只是“未被所选子区间覆盖的墙钟时间”,可能包括排队、计算、序列化或埋点缺口,不能直接命名为父服务 CPU 时间。这个区间模型还假设所有时间都在可比较的同一时间轴上;跨机器原始时间戳有偏移时,需先处理时钟问题,不能让裁剪偷偷掩盖数据异常。
缩短一个分支,整次请求能快多少?
下图让两条 RPC 共享准备结束的起点,并让整理阶段跟随较晚的结束点。价格从 100 降到 70 ms 时仍能缩短总体;再往下缩,库存分支开始决定总时长。图中金色标出当前限制完成的路径,二者同长时两条分支都关键;这比只给最长 span 加一个醒目标记更能解释优化边界。
T=Tprepare+max(TA,TB)+Tfinalize
正在呈现知识画面
缩短一个分支,整次请求能快多少?并行且必须全部完成时,总延迟取决于较长分支。缩短较短分支不会改变当前关键路径;子 span 时长之和会重复计算重叠时间。
{"id":"trace-critical-path","title":"缩短一个分支,整次请求能快多少?","summary":"并行且必须全部完成时,总延迟取决于较长分支。缩短较短分支不会改变当前关键路径;子 span 时长之和会重复计算重叠时间。","height":1000,"html":"<h2 data-i18n=\"heading\"></h2><p class=\"intro\" data-i18n=\"intro\"></p><div class=\"control\"><label for=\"inventory\" data-i18n=\"inventory\"></label><output for=\"inventory\" id=\"inventory-value\"></output><input id=\"inventory\" type=\"range\" min=\"0\" max=\"140\" value=\"70\" step=\"5\"></div><div class=\"control\"><label for=\"price\" data-i18n=\"price\"></label><output for=\"price\" id=\"price-value\"></output><input id=\"price\" type=\"range\" min=\"0\" max=\"140\" value=\"100\" step=\"5\"></div><div id=\"waterfall\" class=\"plot\"></div><div class=\"axis\"><span>0 ms</span><span>160 ms</span></div><div class=\"metrics\"><div><span data-i18n=\"end\"></span><strong id=\"end\"></strong></div><div><span data-i18n=\"sum\"></span><strong id=\"sum\"></strong></div><div><span data-i18n=\"overlap\"></span><strong id=\"overlap\"></strong></div></div><p id=\"equation\" class=\"formula\"></p><details class=\"scope\"><summary data-i18n=\"scopeLabel\"></summary><p data-i18n=\"scope\"></p></details>","css":".intro{margin:8px 0 18px;color:var(--muted);font-size:14px}.caption,.hint{font-size:12px;color:var(--muted);margin-top:12px}.control{display:grid;grid-template-columns:minmax(0,1fr) auto;gap:6px 12px;align-items:center;margin:14px 0;font-size:13px}.control label{font-size:13px}.control output{color:var(--accent);min-width:5em;text-align:right;font-variant-numeric:tabular-nums}.control input{grid-column:1/-1;width:100%;margin:0}.presets{display:flex;gap:4px;align-items:stretch}.presets button{flex:1 1 0;min-width:0;overflow-wrap:anywhere;font-size:13px}.actions{display:flex;gap:8px;flex-wrap:wrap;margin:14px 0}.actions button{flex:1;min-width:0;font-size:13px;min-height:42px}.copy{display:grid;font-size:14px;margin:16px 0}.copy>*{grid-area:1/1;margin:0}.reserve{visibility:hidden}.scope{margin-top:14px;color:var(--muted);font-size:12px}.scope summary{padding:8px 0;cursor:pointer}.scope p{margin-top:10px}.two{display:grid;grid-template-columns:repeat(2,minmax(0,1fr));gap:12px;margin:16px 0}.card{border:1px solid var(--rule);border-radius:9px;padding:14px;min-width:0}.card header{font-size:14px;font-weight:600;margin-bottom:10px}.card button{font-size:12px;width:100%;min-width:0}.card small{display:block;font-size:12px;color:var(--muted)}.card code{font-size:12px;overflow-wrap:anywhere}.metrics{display:grid;grid-template-columns:repeat(2,minmax(0,1fr));gap:12px;margin:16px 0}.metrics>div{border-left:2px solid var(--accent);padding-left:10px;min-width:0}.metrics span{display:block;min-height:3.2em;color:var(--muted);font-size:12px}.metrics strong{font-size:23px;display:block;font-weight:500;overflow-wrap:anywhere;font-variant-numeric:tabular-nums}.formula{border-top:1px solid var(--rule);padding-top:12px;margin-top:14px;font-size:13px;font-variant-numeric:tabular-nums;overflow-wrap:anywhere}.value{font:500 20px var(--viz-font-ui)}.legend{display:flex;flex-wrap:wrap;gap:6px 14px;font-size:12px;color:var(--muted);margin:12px 0}.legend span:before{content:'';display:inline-block;width:8px;height:8px;border-radius:2px;background:var(--accent);margin-right:6px}.legend .second:before{background:var(--second)}.check{display:flex;align-items:center;gap:8px;font-size:13px;margin:12px 0}.check input{width:16px;height:16px;flex-shrink:0;accent-color:var(--accent)}select,input[type=text],input[type=number]{background:var(--paper);color:var(--ink);font:inherit;font-size:13px;padding:10px;border:1px solid var(--rule);border-radius:7px;max-width:100%;min-width:0}select{width:100%;min-height:42px}.band{height:20px;display:flex;background:var(--surface);border-radius:4px;overflow:hidden}.band i{height:100%;display:block;background:var(--accent);transition:width .25s}.band i.second{background:var(--second)}button:disabled{cursor:default}.status{font-size:13px;min-height:4.8em}.mono{font-family:var(--viz-font-mono);font-variant-numeric:tabular-nums}.muted{color:var(--muted)}\n@media(max-width:480px){.two{gap:8px}.card{padding:12px 9px}.actions button,.presets button{font-size:12px}.metrics strong{font-size:20px}.metrics{gap:8px}}\n@media(prefers-reduced-motion:reduce){*,*::before,*::after{transition:none!important;animation:none!important}}\n.track-row{margin:16px 0}.track-row>span{display:block;font-size:12px;color:var(--muted);margin-bottom:7px}.track{display:flex;gap:5px;min-width:0}.cell{flex:1;min-width:0;min-height:48px;border:1px solid var(--rule);border-radius:5px;background:var(--surface);display:flex;align-items:center;justify-content:center;text-align:center;padding:5px 3px;font-size:12px;overflow-wrap:anywhere;font-variant-numeric:tabular-nums}.cell.on{background:var(--accent-soft);border-color:var(--accent)}.cell.gold{background:var(--second-soft);border-color:var(--second)}.cell.empty{border-style:dashed;color:var(--muted)}.cell.error{border-color:var(--second);text-decoration:line-through}.choices{display:grid;grid-template-columns:repeat(4,minmax(0,1fr));gap:6px;margin:14px 0}.choices button{min-width:0;padding:10px 4px;font-size:12px;overflow-wrap:anywhere}.choices button[aria-current=true]{border-color:var(--accent);background:var(--accent-soft)}.relation{display:grid;grid-template-columns:minmax(0,1fr) 28px minmax(0,1fr);align-items:center;gap:6px;margin:12px 0}.relation .cell{min-height:72px}.relation>i{text-align:center;font-style:normal;color:var(--accent)}.readout{font-size:13px;white-space:pre-line;min-height:6.4em;overflow-wrap:anywhere}.plot{position:relative;border-left:1px solid var(--rule);border-bottom:1px solid var(--rule);padding:8px 0;margin:18px 0}.plot-row{height:28px;position:relative;margin:4px 0;background:var(--surface)}.plot-row i{position:absolute;inset-block:5px;background:var(--accent);min-width:2px;transition:width .2s,left .2s}.plot-row b{position:relative;padding:4px 6px;font:11px/28px var(--viz-font-ui);background:var(--paper);border-radius:3px}.axis{display:flex;justify-content:space-between;font-size:11px;color:var(--muted)}\n\n/* Action labels must remain readable across locales and narrow embeds. */\n.actions{display:grid;grid-template-columns:repeat(2,minmax(0,1fr));gap:8px}\n.actions button{overflow-wrap:anywhere;white-space:normal;min-height:58px;padding:8px}\nbutton{overflow-wrap:anywhere}\n@media(min-width:640px){.actions{grid-template-columns:repeat(3,minmax(0,1fr))}}\n\n.metrics span{overflow-wrap:anywhere}\n\n.metrics{grid-template-columns:repeat(3,minmax(0,1fr))}.metrics span{min-height:5em}.plot-row{height:35px}.plot-row b{line-height:35px;font-size:10px}","js":"const $=s=>document.querySelector(s);const set=(id,v)=>$('#'+id).textContent=v;const t=k=>viz.t(k);function cells(id,values){$('#'+id).replaceChildren(...values.map(v=>{const e=document.createElement('div');e.className='cell '+(v.cls||'');e.textContent=v.text;e.title=v.title||v.text;return e;}));}function pressed(mode){document.querySelectorAll('[data-mode]').forEach(e=>e.setAttribute('aria-pressed',String(e.dataset.mode===mode)));}function draw(){const a=+$('#inventory').value,b=+$('#price').value,m=Math.max(a,b),end=20+m;set('inventory-value',a);set('price-value',b);set('end',end);set('sum',20+a+b);set('overlap',Math.min(a,b));set('equation','10 + max('+a+', '+b+') + 10 = '+end+' ms');const rows=[['root',0,end,true],['prep',0,10,true],['inventory',10,a,a===m],['price',10,b,b===m],['finish',10+m,10,true]];$('#waterfall').replaceChildren(...rows.map(([key,start,duration,critical])=>{const e=document.createElement('div');e.className='plot-row';const bar=document.createElement('i');bar.style.left=start/160*100+'%';bar.style.width=duration/160*100+'%';bar.style.background=critical?'var(--second)':'var(--accent)';if(duration===0)bar.style.display='none';const label=document.createElement('b');label.textContent=t(key)+' '+duration+' ms';e.append(bar,label);return e;}));}document.querySelectorAll('input').forEach(e=>e.oninput=draw);draw();","audio":false,"strings":{"end":"端到端 / ms","finish":"整理","heading":"缩短一个分支,整次请求能快多少?","intro":"准备 10 ms 后,同时调用库存与价格;两者结束后再整理 10 ms。分别调整两条 RPC 的耗时。","inventory":"库存 RPC / ms","overlap":"重复计入的重叠 / ms","prep":"准备","price":"价格 RPC / ms","reset":"重置","root":"整次请求","scope":"固定 fork/join 依赖,同一可比较时间轴;不含竞争、取消、排队变化或时钟偏移。未被 RPC 覆盖的时间不能直接称为 CPU 时间。","scopeLabel":"模型范围与约定","sum":"子阶段时长之和 / ms"}}
上下文传播:分布式调用怎样接起来
单进程中,执行上下文可以通过线程局部或异步任务机制传递;跨进程时必须显式编码到通信载体中。OpenTelemetry 将发送端写入称为 inject,接收端读取称为 extract。
正确时序是:A 创建 client span,把它的上下文写入请求;B 收到请求时提取上下文并创建 server span;B 调用下一服务时创建新的 client span,再注入下一次请求。不是等收到响应后才让下游建立 parent 关系。OpenTelemetry Context Propagation 解释了传播器与执行上下文的关系。
W3C traceparent 的版本 00 结构如下,这是协议格式而非流程图:
traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01
| 字段 | 含义 |
00 | 格式版本 |
| 32 个十六进制字符 | trace ID,跨调用保持关联 |
| 16 个十六进制字符 | 发送方当前 span ID,成为接收方的远程 parent |
01 | trace flags;此例设置 sampled 位 |
tracestate 可携带厂商追踪状态。gRPC metadata、消息 headers 也可以承载传播字段,不应把某个历史二进制 header 当作所有 gRPC 追踪的唯一格式。字段校验与版本行为以 W3C Trace Context 为准。
异步任务与消息:父子树有时不够
同步 RPC 通常有明确的一个调用方;消息批处理可能把许多来源汇入同一次操作。一个 span 只能有一个 parent,但可以用 links 关联多个 span context。把一百条消息的来源强行塞成一棵单父链,会丢失批处理的真实关系。
还要分别表示“消息在队列里等待”和“消费者实际处理”。生产者发送完成到消费者开始之间的时间,可能属于队列驻留;消费者创建的处理 span 只覆盖执行阶段时,不能拿它的时长冒充端到端消息延迟。
任务池是另一个常见边界:线程切换后如果没有捕获并恢复上下文,后续 span 会变成新的根;如果错误复用旧上下文,则可能把无关请求接在一起。异步传播要随任务生命周期处理,而不是只随线程生命周期处理。
相关数据模型见 OpenTelemetry Traces。
采样:成本与可解释性之间的取舍
头采样在较早阶段决定是否记录,便于控制 SDK 和传输成本。概率采样适合获得近似代表性样本,但低频错误可能碰巧全被漏掉。关联服务应保持相容的采样决策,否则容易得到断开的 trace。
尾采样收集 span 后,根据错误、延迟或属性决定保留哪些 trace。代价是先接收数据、维护缓存并等待。同一 trace 的 span 需要被路由到能共同做决定的位置;迟到 span、超长任务、容量不足都会影响完整性。OpenTelemetry Sampling 说明了两者的能力边界。
一个自定义容量估算:假设每秒 2000 个 trace,每个平均 8 个 span,每 span 缓存占 1 KB,等待 15 秒,则仅这些 span 的原始容量约为 2000 × 8 × 1 KB × 15 = 240 MB。实际还要加索引、对象和队列开销。这个估算用于理解增长方向,不是产品性能保证。
尾采样保留全部已观察到的错误,也不意味着保留了系统发生过的全部错误;上游可能没有埋点、没有导出,或已被头采样丢弃。更不能直接用“错误 trace 数 / 保留 trace 数”计算全量错误率,因为样本已偏向异常请求。
样本中的错误比例为什么会从 0.1% 变成约 9.1%
假设一批 100000 次请求中有 100 次错误,真实错误率为 0.1%。现在保留全部错误,只保留正常请求的 1%;若这批恰好留下 999 个正常 trace,样本中错误占比便是 100/1099≈9.10%。两个比例描述的是不同总体,不能相互替代。
from fractions import Fraction
all_errors, all_successes = 100, 99900
kept_errors, kept_successes = 100, 999
true_rate = Fraction(all_errors, all_errors + all_successes)
sample_rate = Fraction(kept_errors, kept_errors + kept_successes)
assert true_rate == Fraction(1, 1000)
assert Fraction(9, 100) < sample_rate < Fraction(10, 100)
estimated_errors = Fraction(kept_errors, 1)
estimated_successes = Fraction(kept_successes, 1) / Fraction(1, 100)
assert estimated_errors / (estimated_errors + estimated_successes) == true_rate
权重算式不是任意尾采样数据的通用修复。实际还可能按延迟、属性、容量策略丢弃,路由与导出失败也会改变纳入概率;未知的丢失无法凭最后剩下的 trace 自动恢复。即使概率已知,有限随机样本的比例估计也有波动,本例只是恰好取到对应数量的算例。
因此错误率和 SLO 通常应由语义一致的请求指标统计,trace 用来解释选中的请求为什么失败。若指标由 span 派生,还要明确它是在采样前还是采样后生成,否则仍可能继承同样的选择偏差。OpenTelemetry 采样
采集链路与职责
常见链路由应用埋点、SDK、Collector 和存储查询后端组成。埋点负责选择操作边界;SDK 管理 span 生命周期和导出;Collector 可承担批处理、过滤、采样与路由;后端负责保留和检索。
自动埋点通常先给出 HTTP、RPC 和数据库边界,手动 span 用于补充有业务意义的阶段。给每个微小函数都加 span 会增加开销,也会使调用图难读。span 名称应稳定,例如路由模板 /orders/{id},具体请求 ID 放在受控属性中。
Baggage 是随上下文传播的应用键值,不等于 span 属性,也不是经过认证的身份声明。入口接受外部上下文时需要校验与信任边界;不要把密钥或完整个人信息放进会跨服务传播的字段。详见 OpenTelemetry Baggage。
如何阅读一条慢请求
先确认 trace 是否完整,再从根 span 的总时长寻找关键路径。若父 span 很长而所有子 span 都短,检查未覆盖的排队、应用计算和序列化阶段;若某个 client span 很长但 server span 很短,考虑连接建立、网络、代理或服务端埋点之外的等待。
跨机器时钟可能有偏差,不能仅凭两个节点的绝对时间戳断言精确网络耗时。trace 的 parent/link 关系提供因果线索,时间轴提供观察值,二者不应混成一个完美的全局时钟。
最后用同类请求的指标验证这个现象是否普遍,再通过 trace ID 跳到日志或剖析数据。追踪的作用是提出并缩小解释,而不是让一张瀑布图替代所有证据。
参考
关键词:trace、span、context propagation、critical path、links、head sampling、tail sampling、baggage