Voice Agent 到底慢在哪？用 t0-t8 埋点拆解 ASR、LLM、TTS 全链路延迟
Voice Agent 的“慢”不能只看一个总耗时，更不能听到用户抱怨后就先换 LLM。
我从用户最后一帧语音到达服务端开始，到首个音频包进入播放器时间轴结束，设置t0-t8九个事件。这样一次对话到底慢在 VAD、ASR、RAG、LLM 首 token、文本分句、TTS 首包、网络还是播放器，可以直接从瀑布图里看出来。
本文提供一套可运行的 Python Demo：
- 使用
time.perf_counter_ns()记录单调高精度时间； - 用
trace_id串起同一轮对话； - 对
t0-t8的顺序做强校验，避免埋点错位； - 内置 baseline、慢 VAD、慢 LLM、慢 TTS 四种场景；
- 连续运行后计算各阶段 p50、p95 和瓶颈命中次数；
- 提供 FastAPI 接口和浏览器瀑布图。
先说明测试边界：Demo 里的 ASR、LLM、TTS 都由 asyncio.sleep() 模拟。本文实测数据用于验证埋点、统计和定位逻辑，不代表任何模型、云服务或线上 Voice Agent 的真实性能。
适合阅读本文的情况：
- 日志里只有“本轮耗时 2.3 秒”，不知道时间花在哪；
- LLM 首 token 很快，用户仍觉得 Agent 迟钝；
- TTS 已经返回首包，前端却迟迟没有声音；
- 平均延迟看起来正常，偶发慢请求仍然很多；
- 准备把 Voice Agent 接入 OpenTelemetry 或 Prometheus。
一、为什么“接口总耗时”定位不了 Voice Agent
常见日志是这样的：
2026-07-01 10:00:00 request start
2026-07-01 10:00:02 request done, latency=2138ms
这条日志只能证明用户等了约 2.1 秒，不能回答下面的问题：
- 用户说完以后，VAD 等了多久才敢判定结束？
- ASR 是增量识别慢，还是生成 final 文本慢？
- RAG 检索是否阻塞了 LLM 请求？
- LLM 首 token 快不快？
- 首 token 出来以后，多久才凑成一段可送入 TTS 的文本？
- TTS 首包到了以后，网络和播放预缓冲又花了多久？
同样是 2 秒，可能有完全不同的根因：
链路 A：VAD 等了 700 ms，LLM 只用了 250 ms
链路 B：VAD 只等 180 ms，LLM 首 token 用了 800 ms
链路 C：LLM 很快，TTS 首包却用了 600 ms
链路 D：服务端都正常，客户端预缓冲和队列用了 500 ms
如果只看总耗时，这四种情况很容易得到同一个错误动作：换模型。
二、先把 t0-t8 定义清楚
2.1 t0 不要从“用户开始说话”算
本文把 t0 定义为：
t0 = 用户最后一帧语音到达服务端
不是用户开口，也不是整通电话开始。
原因很简单：用户说了 12 秒，不代表 Agent 响应慢了 12 秒。我们要测的是用户说完以后，系统多久开始回答。
2.2 九个事件
| 时间点 | 事件 | 要回答的问题 |
|---|---|---|
t0 |
用户最后一帧语音到达服务端 | 响应计时从哪里开始 |
t1 |
VAD 确认说话结束 | 端点检测等了多久 |
t2 |
ASR final 文本就绪 | ASR 收尾用了多久 |
t3 |
RAG 完成并发出 LLM 请求 | 检索与编排是否阻塞 |
t4 |
LLM 返回首个 token | LLM TTFT 多久 |
t5 |
首段可播文本送入 TTS | 首 token 后又等了多久 |
t6 |
TTS 返回首个音频包 | TTS 首包多久 |
t7 |
客户端收到首个音频包 | 音频传输多久 |
t8 |
播放器排期首个音频包 | 真正进入播放链路多久 |
对应八段耗时：
端点检测 = t1 - t0
ASR 收尾 = t2 - t1
编排/RAG = t3 - t2
LLM 首 token = t4 - t3
首段文本聚合 = t5 - t4
TTS 首包 = t6 - t5
音频传输 = t7 - t6
播放预缓冲 = t8 - t7
用户侧首音频延迟 = t8 - t0
这套定义里有两个我认为很值得单独保留的时间点。
第一个是 t4。它只表示 LLM 返回了首 token，不表示这段文本已经适合朗读。
第二个是 t5。如果模型先返回“根”“据”“您”“的”几个碎片，TTS 不能每个 token 发一次请求。程序往往要等到标点、最小长度或超时条件满足，才能得到第一段可播文本。
所以：
LLM 首 token 快 ≠ Voice Agent 能马上开口
TTS 首包快 ≠ 用户已经听到声音
三、完整链路图
用户最后一帧语音
|
v
t0 audio_last_frame
|
| endpointing
v
t1 VAD end-of-turn
|
| ASR finalize
v
t2 ASR final text
|
| orchestration / RAG
v
t3 LLM request
|
| LLM TTFT
v
t4 first token
|
| text buffering / segmentation
v
t5 first speakable chunk -> TTS
|
| TTS first packet
v
t6 first PCM/Opus packet
|
| transport
v
t7 client receives audio
|
| playback prebuffer
v
t8 player schedules audio
生产链路可能并不是完全串行。例如流式 ASR 可以在用户还没说完时提前产生 partial 文本，RAG 也可能与其他编排并发。遇到并行阶段时，不能把所有 span duration 简单相加，应该看真正决定 t8 的关键路径。
本文 Demo 刻意采用串行模拟，先把每个时间点和统计逻辑讲清楚。
四、运行环境与目录
本文实际运行环境：
| 项目 | 版本 |
|---|---|
| 操作系统 | macOS，Apple Silicon |
| Python | 3.12.13 |
| FastAPI | 0.115.12 |
| Uvicorn | 0.34.3 |
| 计时函数 | time.perf_counter_ns() |
项目目录：
voice-agent-latency-lab/
├── timeline.py # t0-t8 事件和阶段定义
├── pipeline.py # 四种可控延迟场景
├── benchmark.py # p50/p95 和瀑布图
├── app.py # FastAPI 接口
├── test_latency.py # 单元测试
├── requirements.txt
└── static/
└── index.html # 浏览器可视化
requirements.txt：
fastapi==0.115.12
uvicorn[standard]==0.34.3
启动：
python3.12 -m venv .venv
source .venv/bin/activate
pip install -r requirements.txt
uvicorn app:app --host 127.0.0.1 --port 8000
打开：
http://127.0.0.1:8000
五、为什么用 perf_counter_ns，而不是 time.time
测持续时间时，我不建议直接用：
start = time.time()
系统时间可能因为校时而变化，而且浮点秒在长时间运行后会损失一部分精度。
Python 官方文档对 perf_counter() 的定义是：使用可用于测量短时长的高分辨率性能计数器，只应使用两次调用的差值；perf_counter_ns() 返回整数纳秒，可以避免浮点精度损失。
本文所有事件都记录：
time.perf_counter_ns()
转换为毫秒时再除：
duration_ms = (end_ns - start_ns) / 1_000_000
不要把 perf_counter_ns() 的原始值当成日期。它的参考原点没有业务意义，只有差值有意义。
六、实现 t0-t8 时间线
timeline.py 做四件事：
- 固定 t0-t8 名称和顺序；
- 每次 mark 使用高分辨率单调时钟；
- 计算事件累计时间和阶段增量；
- 生成符合 W3C
traceparent形状的 trace ID 与 parent ID。
from __future__ import annotations
import secrets
import time
from dataclasses import dataclass, field
from typing import Any
EVENTS = (
("t0", "用户最后一帧语音到达服务端"),
("t1", "VAD 确认说话结束"),
("t2", "ASR final 文本就绪"),
("t3", "RAG 完成并发出 LLM 请求"),
("t4", "LLM 返回首个 token"),
("t5", "首段可播文本送入 TTS"),
("t6", "TTS 返回首个音频包"),
("t7", "客户端收到首个音频包"),
("t8", "播放器排期首个音频包"),
)
STAGES = (
("endpointing", "端点检测", "t0", "t1"),
("asr_finalize", "ASR 收尾", "t1", "t2"),
("orchestration_rag", "编排/RAG", "t2", "t3"),
("llm_ttft", "LLM 首 token", "t3", "t4"),
("text_buffering", "首段文本聚合", "t4", "t5"),
("tts_first_packet", "TTS 首包", "t5", "t6"),
("transport", "音频传输", "t6", "t7"),
("playback_buffer", "播放预缓冲", "t7", "t8"),
)
EVENT_LABELS = dict(EVENTS)
EVENT_NAMES = tuple(name for name, _ in EVENTS)
def _nonzero_hex(byte_count: int) -> str:
while True:
value = secrets.token_hex(byte_count)
if any(char != "0" for char in value):
return value
@dataclass
class Timeline:
scenario: str
trace_id: str = field(default_factory=lambda: _nonzero_hex(16))
parent_id: str = field(default_factory=lambda: _nonzero_hex(8))
_events_ns: dict[str, int] = field(default_factory=dict, init=False, repr=False)
@property
def traceparent(self) -> str:
return f"00-{self.trace_id}-{self.parent_id}-01"
def mark(self, event_name: str) -> None:
expected_index = len(self._events_ns)
if expected_index >= len(EVENT_NAMES):
raise ValueError("timeline 已经记录完 t0-t8")
expected_name = EVENT_NAMES[expected_index]
if event_name != expected_name:
raise ValueError(
f"事件顺序错误：当前应记录 {expected_name}，收到 {event_name}"
)
self._events_ns[event_name] = time.perf_counter_ns()
def as_dict(
self,
configured_delays_ms: dict[str, float] | None = None,
) -> dict[str, Any]:
missing = [name for name in EVENT_NAMES if name not in self._events_ns]
if missing:
raise ValueError(f"timeline 缺少事件：{', '.join(missing)}")
origin_ns = self._events_ns["t0"]
events = []
previous_ns = origin_ns
for name, label in EVENTS:
current_ns = self._events_ns[name]
events.append(
{
"name": name,
"label": label,
"elapsed_ms": ns_to_ms(current_ns - origin_ns),
"delta_ms": ns_to_ms(current_ns - previous_ns),
}
)
previous_ns = current_ns
stages = []
for key, label, start_name, end_name in STAGES:
duration_ms = ns_to_ms(
self._events_ns[end_name] - self._events_ns[start_name]
)
stages.append(
{
"key": key,
"label": label,
"start": start_name,
"end": end_name,
"duration_ms": duration_ms,
"configured_ms": (
configured_delays_ms.get(key)
if configured_delays_ms is not None
else None
),
}
)
bottleneck = max(stages, key=lambda stage: stage["duration_ms"])
return {
"scenario": self.scenario,
"trace_id": self.trace_id,
"traceparent": self.traceparent,
"events": events,
"stages": stages,
"total_ms": events[-1]["elapsed_ms"],
"bottleneck": {
"key": bottleneck["key"],
"label": bottleneck["label"],
"duration_ms": bottleneck["duration_ms"],
},
}
def ns_to_ms(value_ns: int) -> float:
return round(value_ns / 1_000_000, 3)
6.1 为什么要强校验事件顺序
埋点系统最怕“有数据，但定义已经乱了”。
例如某次重构后，代码先 mark 了 t4，随后才补 t3。如果程序照样收下这两条日志，后续可能出现负耗时或错位归因。
本文要求：
expected_name = EVENT_NAMES[len(self._events_ns)]
下一条不是预期事件就直接报错。Demo 阶段宁愿尽早暴露问题，也不要悄悄生成错误指标。
七、构造四种可控慢点
真实线上链路不适合拿来反复“故意变慢”。为了验证瓶颈定位是否正确，我设置四种合成场景：
baseline 各阶段相对均衡
slow_endpoint 只把端点检测从 180 ms 调到 550 ms
slow_llm 只把 LLM TTFT 从 260 ms 调到 650 ms
slow_tts 只把 TTS 首包从 180 ms 调到 520 ms
pipeline.py：
from __future__ import annotations
import asyncio
import random
from dataclasses import dataclass
from timeline import EVENT_NAMES, STAGES, Timeline
@dataclass(frozen=True)
class Scenario:
name: str
description: str
delays_ms: dict[str, float]
jitter_ms: float = 8.0
BASELINE_DELAYS = {
"endpointing": 180.0,
"asr_finalize": 90.0,
"orchestration_rag": 60.0,
"llm_ttft": 260.0,
"text_buffering": 120.0,
"tts_first_packet": 180.0,
"transport": 25.0,
"playback_buffer": 70.0,
}
def with_override(**overrides: float) -> dict[str, float]:
delays = BASELINE_DELAYS.copy()
delays.update(overrides)
return delays
SCENARIOS = {
"baseline": Scenario(
name="baseline",
description="各环节均衡的基线链路",
delays_ms=BASELINE_DELAYS,
),
"slow_endpoint": Scenario(
name="slow_endpoint",
description="VAD 端点检测等待过长",
delays_ms=with_override(endpointing=550.0),
),
"slow_llm": Scenario(
name="slow_llm",
description="LLM 首 token 明显变慢",
delays_ms=with_override(llm_ttft=650.0),
),
"slow_tts": Scenario(
name="slow_tts",
description="TTS 首个音频包明显变慢",
delays_ms=with_override(tts_first_packet=520.0),
),
}
async def run_trace(
scenario_name: str,
*,
seed: int | None = None,
scale: float = 1.0,
) -> dict:
if scenario_name not in SCENARIOS:
available = ", ".join(SCENARIOS)
raise ValueError(f"未知场景 {scenario_name}，可选：{available}")
if scale < 0:
raise ValueError("scale 不能小于 0")
scenario = SCENARIOS[scenario_name]
randomizer = random.Random(seed)
timeline = Timeline(scenario=scenario_name)
timeline.mark("t0")
for stage_index, (stage_key, _, _, _) in enumerate(STAGES, start=1):
configured_ms = scenario.delays_ms[stage_key]
jitter_ms = randomizer.uniform(-scenario.jitter_ms, scenario.jitter_ms)
actual_delay_ms = max(0.0, configured_ms + jitter_ms)
await asyncio.sleep(actual_delay_ms / 1_000 * scale)
timeline.mark(EVENT_NAMES[stage_index])
result = timeline.as_dict(scenario.delays_ms)
result["description"] = scenario.description
result["measurement_scope"] = (
"synthetic-demo-only：本地 asyncio 延迟模拟，不代表任何厂商性能"
)
return result
每次延迟带有固定范围的抖动，并通过 seed 复现。这样既不会每次完全一样，也不会因为随机数失控而难以对照。
八、不要只算平均值：输出 p50、p95 和瓶颈次数
平均值会被少量极慢或极快请求拉动。Voice Agent 更适合至少同时看：
p50：典型用户大约会遇到什么速度
p95：较慢的 5% 请求大约慢到什么程度
p99：线上量足够大时，观察长尾
Demo 只连续运行 5 次，用来做 sanity check，不足以形成生产 SLA。线上应把直方图持续采集在真实流量中。
统计核心代码：
import statistics
from collections import Counter
def percentile(values: list[float], percent: int) -> float:
if len(values) == 1:
return round(values[0], 3)
quantiles = statistics.quantiles(
values,
n=100,
method="inclusive",
)
return round(quantiles[percent - 1], 3)
def summarize(traces: list[dict]) -> dict:
total_values = [trace["total_ms"] for trace in traces]
stage_keys = [stage["key"] for stage in traces[0]["stages"]]
stage_summary = {}
for stage_key in stage_keys:
values = [
next(
stage["duration_ms"]
for stage in trace["stages"]
if stage["key"] == stage_key
)
for trace in traces
]
stage_summary[stage_key] = {
"p50_ms": round(statistics.median(values), 3),
"p95_ms": percentile(values, 95),
}
bottleneck_counts = Counter(
trace["bottleneck"]["key"]
for trace in traces
)
return {
"scenario": traces[0]["scenario"],
"runs": len(traces),
"total_p50_ms": round(statistics.median(total_values), 3),
"total_p95_ms": percentile(total_values, 95),
"bottleneck_counts": dict(bottleneck_counts),
"stages": stage_summary,
"measurement_scope": traces[0]["measurement_scope"],
}
为什么还要统计“瓶颈命中次数”？
如果 100 次请求里有 92 次最慢阶段都是 endpointing，结论很稳定；如果各阶段轮流成为最大值，就要继续按网络、语言、文本长度、模型和客户端类型分组，而不是仓促优化一个组件。
九、输出瀑布图
一次 baseline 运行结果：
scenario=baseline total=1009.0 ms
t0->t1 端点检测 188.3 ms █████████
t1->t2 ASR 收尾 92.9 ms ████
t2->t3 编排/RAG 67.1 ms ███
t3->t4 LLM 首 token 255.6 ms ████████████
t4->t5 首段文本聚合 122.3 ms ██████
t5->t6 TTS 首包 185.2 ms █████████
t6->t7 音频传输 33.8 ms ██
t7->t8 播放预缓冲 63.8 ms ███
bottleneck=llm_ttft (255.6 ms)
生成文本瀑布图：
def render_waterfall(trace: dict, width: int = 48) -> str:
total_ms = trace["total_ms"]
lines = [
f"trace_id={trace['trace_id']}",
f"scenario={trace['scenario']} total={total_ms:.1f} ms",
]
for stage in trace["stages"]:
bar_length = max(
1,
round(stage["duration_ms"] / total_ms * width),
)
bar = "█" * bar_length
lines.append(
f"{stage['start']}->{stage['end']} "
f"{stage['label']:<10} "
f"{stage['duration_ms']:>8.1f} ms {bar}"
)
lines.append(
"bottleneck="
f"{trace['bottleneck']['key']} "
f"({trace['bottleneck']['duration_ms']:.1f} ms)"
)
return "\n".join(lines)
运行：
python benchmark.py \
--scenario baseline \
--runs 5 \
--waterfall
十、FastAPI 接口
app.py：
from __future__ import annotations
from pathlib import Path
from fastapi import FastAPI, HTTPException, Query
from fastapi.responses import FileResponse
from benchmark import benchmark_scenario
from pipeline import SCENARIOS, run_trace
BASE_DIR = Path(__file__).resolve().parent
INDEX_HTML = BASE_DIR / "static" / "index.html"
app = FastAPI(title="Voice Agent t0-t8 Latency Lab")
@app.get("/")
async def index() -> FileResponse:
return FileResponse(INDEX_HTML)
@app.get("/api/scenarios")
async def scenarios() -> dict:
return {
name: {
"description": scenario.description,
"delays_ms": scenario.delays_ms,
}
for name, scenario in SCENARIOS.items()
}
@app.get("/api/trace/{scenario_name}")
async def trace(
scenario_name: str,
seed: int = Query(default=20260701),
) -> dict:
if scenario_name not in SCENARIOS:
raise HTTPException(status_code=404, detail="scenario 不存在")
return await run_trace(scenario_name, seed=seed)
@app.get("/api/benchmark/{scenario_name}")
async def benchmark(
scenario_name: str,
runs: int = Query(default=5, ge=1, le=30),
seed: int = Query(default=20260701),
) -> dict:
if scenario_name not in SCENARIOS:
raise HTTPException(status_code=404, detail="scenario 不存在")
traces, summary = await benchmark_scenario(
scenario_name,
runs=runs,
seed=seed,
)
return {
"summary": summary,
"sample_trace": traces[0],
}
接口测试：
curl 'http://127.0.0.1:8000/api/trace/slow_tts?seed=20260701'
返回中可以直接看到：
{
"scenario": "slow_tts",
"total_ms": 1346.992,
"bottleneck": {
"key": "tts_first_packet",
"label": "TTS 首包",
"duration_ms": 524.356
}
}
十一、浏览器瀑布图的关键代码
页面不是靠一张静态图，而是每次调用 /api/trace/{scenario} 后重新计算各阶段宽度：
async function runTrace(scenario) {
const trace = await fetch(
`/api/trace/${scenario}`
).then(response => response.json());
renderTrace(trace);
}
function renderTrace(trace) {
document.querySelector("#total").textContent =
`${trace.total_ms.toFixed(1)} ms`;
document.querySelector("#bottleneck").textContent =
`${trace.bottleneck.label} ` +
`${trace.bottleneck.duration_ms.toFixed(1)} ms`;
waterfallRoot.replaceChildren();
for (const stage of trace.stages) {
const row = document.createElement("div");
const label = document.createElement("span");
const track = document.createElement("div");
const bar = document.createElement("div");
const value = document.createElement("span");
row.className = "row";
track.className = "track";
bar.className = "bar";
label.textContent =
`${stage.start}→${stage.end} ${stage.label}`;
bar.style.width =
`${stage.duration_ms / trace.total_ms * 100}%`;
value.textContent =
`${stage.duration_ms.toFixed(1)} ms`;
track.appendChild(bar);
row.append(label, track, value);
waterfallRoot.appendChild(row);
}
}
浏览器验证结果：
baseline
总延迟约 1009.2 ms
瓶颈：LLM 首 token，约 255.5 ms
slow_llm
总延迟约 1397.1 ms
瓶颈：LLM 首 token，约 645.5 ms
当只调慢 t3 -> t4，瀑布图能够把增长稳定定位到 LLM TTFT，而不是误报给 TTS 或网络。
十二、完整实测结果
12.1 单元测试
python -m unittest -v
结果：
test_percentile_single_value ... ok
test_summary ... ok
test_all_events_are_emitted ... ok
test_scenario_configuration_has_expected_bottleneck ... ok
test_rejects_out_of_order_event ... ok
test_traceparent_shape ... ok
Ran 6 tests in 0.005s
OK
12.2 baseline 连续 5 次
total p50 = 998.879 ms
total p95 = 1014.527 ms
bottleneck = llm_ttft，5/5 次
各阶段 p50：
| 阶段 | p50 |
|---|---|
| 端点检测 | 186.584 ms |
| ASR 收尾 | 92.915 ms |
| 编排/RAG | 65.764 ms |
| LLM 首 token | 257.914 ms |
| 首段文本聚合 | 122.299 ms |
| TTS 首包 | 180.412 ms |
| 音频传输 | 23.066 ms |
| 播放预缓冲 | 68.957 ms |
12.3 三种慢点对照
| 场景 | 总延迟 p50 | 总延迟 p95 | 主要慢点 | 命中 |
|---|---|---|---|---|
| baseline | 998.879 ms | 1014.527 ms | LLM TTFT | 5/5 |
| slow_endpoint | 1371.344 ms | 1383.424 ms | 端点检测 | 5/5 |
| slow_llm | 1391.680 ms | 1404.660 ms | LLM TTFT | 5/5 |
| slow_tts | 1341.982 ms | 1354.701 ms | TTS 首包 | 5/5 |
这组结果不用于比较谁更快，只验证一件事：当我们只改变一个阶段时，埋点和瓶颈算法能否指向正确位置。
十三、从实验到真实 Voice Agent，埋点应该放在哪里
13.1 t0：音频接收层
不要在 HTTP 请求进入时记录 t0。实时语音通常是一条持续存在的 WebSocket 或 WebRTC 会话，请求早已建立。
t0 应在音频接收层确定“用户最后一帧有效语音”的位置。
13.2 t1：VAD/Endpointing
t1 - t0 既受 VAD 参数影响，也受“静音多久算说完”的业务策略影响。
端点太激进会抢话，端点太保守会拖慢整条链路。这个阶段不能只追求低延迟，还要同时看：
- 误截断率；
- 用户补充半句话后被切断的比例；
- 噪声下的误触发；
- 不同语言和说话速度。
13.3 t2：ASR final
流式 ASR 往往早已有 partial 文本，但业务通常需要一个稳定版本再做意图、RAG 或下单。
建议同时记：
asr_first_partial
asr_final
本文为了保持 t0-t8 紧凑，只把 asr_final 放入主时间线。
13.4 t3、t4：LLM 请求与首 token
LLM TTFT 应从请求真正发出算起：
t4 - t3
如果把 RAG、提示词拼装和排队时间一起塞进去，就会把编排问题误认为模型问题。
13.5 t5：第一段可播文本
这是 Voice Agent 经常缺失的埋点。
LLM 很快返回首 token，但程序可能：
- 等完整 JSON；
- 等一句话结束；
- 等 Markdown 清洗；
- 等工具调用完成；
- 等安全审核结果；
- 等到文本超过最小长度。
这些等待全部落在：
t5 - t4
13.6 t6：TTS 首包
从第一段文本发给 TTS 到收到首个音频包：
t6 - t5
不要用整句合成完成时间替代首包。流式 Voice Agent 最关心何时能开始播，完整生成耗时则影响队列能否持续供给。
13.7 t7、t8：客户端才知道的时间
服务端不能准确猜测客户端什么时候收到包、什么时候真正排入播放器。
浏览器或 App 应回传：
{
"trace_id": "...",
"turn_id": 18,
"t7_client_receive": 123.4,
"t8_play_scheduled": 194.2,
"queued_audio_ms": 160,
"underrun_count": 0
}
跨机器时不要直接拿两个没有同步保证的本地时钟做绝对时间相减。更稳的做法是：
- 每个服务记录自己 span 的持续时间；
- 用同一个 trace context 关联；
- 客户端单独上报本地阶段耗时；
- 需要跨时钟比较时，明确做时钟同步和误差评估。
十四、Trace ID 怎么跨 ASR、LLM、TTS 传下去
Demo 生成：
traceparent: 00-<32位trace-id>-<16位parent-id>-01
W3C Trace Context 规范定义了 traceparent 和 tracestate，用于在分布式系统的不同组件之间传播追踪上下文。
真实链路里，每个下游请求都应继续携带 trace context：
Voice Gateway
`-- trace_id=abc
|-- ASR span
|-- RAG span
|-- LLM span
|-- TTS span
`-- playback feedback span/event
如果使用 OpenTelemetry，可以把每个阶段建成 span，把 t0-t8 作为 span event。OpenTelemetry Python 官方文档也给出了创建 span、嵌套 span、添加 attribute 与 event 的手工埋点方式。
示意代码：
from opentelemetry import trace
tracer = trace.get_tracer("voice-agent")
with tracer.start_as_current_span("voice.turn") as turn_span:
turn_span.set_attribute("voice.turn_id", turn_id)
turn_span.add_event("t0.audio_last_frame")
with tracer.start_as_current_span("vad.endpointing"):
await wait_for_endpoint()
turn_span.add_event("t1.endpoint_detected")
with tracer.start_as_current_span("asr.finalize"):
transcript = await asr.finalize()
turn_span.add_event("t2.asr_final")
属性里不要直接塞完整用户录音和敏感对话文本。可以记录长度、语言、模型、状态码、错误类型等非敏感诊断信息；确实需要样本时，要有单独的脱敏、权限和留存策略。
十五、Prometheus 里怎么存
追踪适合看“一次请求为什么慢”，指标适合看“一段时间整体慢不慢”。
可以为阶段延迟建直方图：
voice_stage_latency_ms{
stage="llm_ttft",
model="example-model",
region="cn-east"
}
不要把 trace_id、完整手机号、完整用户 ID 放进 metric label。每个不同 label 组合都会产生新的时间序列，高基数会迅速放大存储和查询成本。
Prometheus 官方文档区分了 histogram 与 summary：histogram 暴露分桶计数，可在服务端计算分位数，也更适合跨实例聚合；summary 直接在客户端计算分位数，但分位值不能直接跨实例聚合。
实践上可以这样分工：
Metrics：p50/p95/p99、错误率、欠载率、阶段趋势
Traces：一次慢请求的完整 t0-t8 瀑布
Logs：错误码、请求状态和必要诊断字段
十六、我实际遇到的几个埋点坑
16.1 首 token 和首句混成一个指标
日志只记：
llm_first_response_ms
但不知道是首 token 还是首段可播文本。最后 LLM 看起来很快，Voice Agent 仍然不开口。
修正：分成 t4 和 t5。
16.2 TTS 首包在服务端记了，播放器没记
服务端 200 ms 收到 PCM，不代表用户 200 ms 听到声音。包可能还在网络、前端队列或 AudioContext 预缓冲里。
修正：客户端补 t7、t8。
16.3 只报平均值
大多数请求 800 ms，少量请求 5 秒，平均值可能掩盖真实体验。
修正：至少看 p50、p95、p99 和超阈值比例。
16.4 不同机器直接减时间戳
ASR 服务写一个 wall-clock，TTS 服务写另一个 wall-clock，然后直接相减。机器时钟漂移后会出现负耗时或虚高。
修正：每个 span 用单调时钟测本地持续时间，再用 trace context 串联。
16.5 重试耗时被覆盖
代码重试三次，只保留最后一次成功请求的 180 ms，用户实际等了 1.4 秒。
修正：记录：
attempt_count
attempt_1_duration
backoff_duration
attempt_2_duration
total_stage_duration
16.6 把并行阶段全部相加
流式 ASR、预取 RAG、LLM 和 TTS 可能有重叠。所有阶段 duration 相加后大于用户实际等待，不一定是数据错误，可能只是并行。
修正：同时保存 span 的开始、结束和父子关系，分析关键路径。
16.7 指标名变了，仪表盘还在读旧字段
这是最朴素也最常见的问题。
修正：给埋点 schema 加版本，例如：
{
"schema_version": "voice-latency-v1",
"trace_id": "...",
"events": []
}
十七、常见报错与排查
Q1：为什么 t2 - t1 是负数？
先检查是否混用了：
time.time()；perf_counter_ns()；- 浏览器
performance.now()； - 另一台机器的 wall-clock。
同一段持续时间必须来自同一个时钟域。
Q2：为什么 Demo 配置 180 ms，实测是 186 ms？
asyncio.sleep(0.18) 表示至少挂起约 180 ms，不保证精确在 180 ms 恢复。事件循环调度、系统负载和代码执行都会增加少量时间。本文记录的正是实际恢复时间。
Q3：p95 为什么每次有波动？
样本只有 5 次时，p95 很不稳定。Demo 只是验证统计代码。生产环境应积累足够样本，按模型、地区、客户端、语言和场景合理分组。
Q4：为什么总延迟不等于所有阶段 p50 相加？
每个阶段的 p50 可能来自不同请求，分位数不能直接相加得到总延迟分位数。应直接对每条 trace 的 t8 - t0 统计总延迟。
Q5：真实系统一定要 t0-t8 吗？
不一定。可以增加：
ASR first partial
RAG first result
LLM tool call start/end
TTS stream completed
audio playback started/ended
barge-in detected
t0-t8 是最小骨架，不是协议标准。
Q6：怎样判断该先优化哪一段？
先按真实流量统计：
- 阶段 p50/p95/p99；
- 该阶段成为瓶颈的比例；
- 优化后对
t8-t0的实际贡献； - 准确率、自然度、误截断等副作用。
耗时最长不等于最值得优化。某阶段虽然慢，却可能是保证质量的必要等待。
Q7：为什么 VAD 不能直接调得非常激进？
因为低延迟和不抢话是冲突目标。端点窗口缩短后，Agent 可能频繁截断停顿较长、语速较慢或在噪声中说话的用户。
十八、优化顺序：先定位，再动参数
我会按下面顺序处理一次 Voice Agent 慢请求：
1. 确认 t0、t8 定义一致
2. 找到该 trace 的最大阶段
3. 查看这一阶段在 p50/p95 是否都异常
4. 按模型、地区、语言、文本长度继续切分
5. 检查重试、排队、限流和网络
6. 只改一个变量
7. 用相同样本重新跑
8. 同时验证准确率、自然度和打断体验
不要一口气同时改 VAD、模型、分句和 TTS。总延迟即使下降，也不知道是谁起作用，更不知道质量损失来自哪里。
十九、本文的判断标准
这套埋点是否真正有用，我会看六件事：
- 能否从用户说完而不是用户开口开始计时；
- 能否区分 LLM 首 token 与首段可播文本；
- 能否区分 TTS 首包与客户端首播放；
- 能否用同一个 trace ID 串起 ASR、RAG、LLM、TTS；
- 能否同时输出单次瀑布和整体分位数；
- 能否在故意调慢某一段后准确指出该瓶颈。
如果日志只有一个 total_latency，它更像报警器；有了 t0-t8，才开始像诊断工具。
系列阅读
上一篇：
流式 TTS 怎么接入 Voice Agent？首包延迟、分句与 PCM 音频队列实战
下一篇计划：
用户打断以后，上下文怎么续？Voice Agent 会话状态管理实战
会继续拆已经生成、已经播放、用户已经确认三类内容，以及打断后哪些内容能留在上下文、哪些必须撤回。
官方资料
更多推荐
10
0- 0
已为社区贡献1条内容
所有评论(0)