08 - 运行时性能排查方法论
上一篇的五个案例都已经知道答案了,所以读起来很顺。真实情况是你接手时什么都不知道 —— 只有一句「这个模型服务好像不够快」。
这时候最常见的做法是:凭直觉猜一个可能的原因,改一下试试,快了就说是它,没快就再猜一个。这个做法的问题不是慢,是结论经常是错的。
你改了 A,同时环境也变了。快了 5%,你归因给 A —— 其实是隔壁那个占卡的进程刚好跑完了。
更麻烦的是,性能排查里有一批「看起来成功了、其实什么都没测到」的陷阱。三个记录在案的:
| 你看到的 | 实际发生的 |
|---|---|
| py-spy 采了 25 秒,输出「Samples: 0, Errors: 0」,像是跑得很干净 | 一个有效样本都没采到 —— 默认模式跳过所有阻塞调用,而你要找的开销正好全在阻塞里 |
| GPU 忙碌比算出来 35%,断定卡很闲 | 这模型的解码走 CUDA Graph 回放,回放时间根本不落在你统计的那 一类里,真实忙碌比可能高得多 |
| 报告里写「GPU 利用率均值 48%」 | 那一轮只跑了 90 毫秒,采样器一个点都没采到,48% 是从别处来的 |
这一篇是一套按性价比排序的分层流程:先花五分钟确定方向(瓶颈在 GPU 还是在主机),再决定要不要花两小时深挖。不含任何具体模型的测量结论,只讲方法。
分层框架与绝大多数踩坑记录整理自 sglang-omni 的 issue #1798 · Model Runtime Profiling Methodology(作者 Dayuxiaoshui)。这里做了中文重述、补了背景,并按本专题的结构重组。
一、开工前的三项检查
这三件事不做,后面收集的所有数据可能整体不可信。
① 选 GPU 时同时看利用率和显存,绝不能只看显存。 共享机器上有一种持续性争用:显存看起来很干净,但算力被另一个租户占满。只看空闲显存会静悄悄地挑到一张不能用的卡。
nvidia-smi --query-gpu=index,utilization.gpu,memory.used,memory.total --format=csv
跑之前和跑之中都要抽查 —— 共享机器上的占用随时会变。还有一种「瞬时」争用:显存突然打满又释放,触发 KV cache 自动缩容。它和持续性争用是两种风险,得分别防。
② 记下基线环境。 框架的钉版本(pip show 或 pyproject.toml 里的 pin)、GPU 型号、模型 checkpoint、数据集版本。有一个具体的坑:本地 editable 安装实际 checkout 的 commit 可能和 pin 悄悄漂开,要确认。任何核心依赖升级之后,之前的结论都要重新验证才能继续引用;报告里必须写清测的是哪个版本。
③ 确认进程树是干净的。 起服务前先看目标卡上有没有孤儿进 程。pkill -f <启动命令串> 匹配的是 cmdline,杀不掉孤儿编译子进程 —— 那些进程的 cmdline 只是个解释器调用,不含启动命令里的任何字符串。实测有存活 80 分钟以上没被杀掉的。按进程组杀,或者逐个按 PID 杀,别只靠 pkill -f。
二、五层,按性价比排序
下面这套流程的顺序不是随便排的,是按「花多少时间能排除多大范围」排的。第一层十分钟就能跑完,但它决定了后面四层要不要做 —— 瓶颈真在 GPU 算力上的话,第二到第四层全是白费功夫。
最常见的错误是跳过前面直接冲到第四层去 A/B 某个参数。那样即使测出了差异,你也不知道它是不是这个系统真正的瓶颈。
顺序不能跳。 最常见的错误是直接冲到 Layer 4 去 A/B 某个参数 —— 那样即使测出了差异,也不知道它是不是这个系统真正的瓶颈。
三、Layer 1:GPU 忙碌比
四种独立可用的测法,结论应当互相印证。
| 方法 | 怎么做 | 什么时候用 | 已知局限 |
|---|---|---|---|
| kernel 计时 | 服务端 /start_profile → 压测 → /stop_profile,导出 chrome trace,对 GPU 活动区间取并集除以窗口墙钟 | 想看清楚具体是哪些 kernel | 有图回放盲区,见下 |
| nvidia-smi 采样 | 压测时周期性读 utilization.gpu | 长时间 / 高并发场景,开销低 | 只反映「有没有 kernel 在跑」,不反映 SM 占了多少 |
| DCGM 连续采样 | dcgmi dmon -e 1002,1004 -d <ms> -i <gpu> 直接采 SM Active / Tensor Active | 日常与长跑的默认选择 | 需要 nv-hostengine 常驻 |
| nsys GPU Metrics | nsys profile --gpu-metrics-devices=... 包住整个启动命令 | 一次性深挖,精度最高 | 侵入性最强,且有下面那个致命坑 |
nsys 那个致命坑:SGLang-Omni 这类架构会 fork 出真正跑前向的子进程,所以事后 nsys profile -p <pid> 附加是不可靠的 —— 必须用 nsys profile ... -- <完整启动命令> 从一开始就包住整个启动。之后 nsys export --type sqlite,读 GPU_METRICS 表取 SMs Active / Tensor Active 的时间序列均值。指标名到 id 的映射跨 GPU 和 metric set 会变,别硬编码 id,先查 sqlite 里的映射表。
两个方向相反的偏差
cuda_runtime 类下的 cudaGraphLaunch 事件出现的。这类东西跨版本不稳定,只能每次现看。分母要不要包含窗口外的 CPU 时间
不要,这是刻意的。 kernel 活动窗口(从第一个 GPU 活动到最后一个)内部已经包含了 CPU 调度和同步造成的空隙 —— 那些空隙正是忙碌比低于 100% 的原因,不需要额外处理。
真正有争议的是窗口之外:请求排队构建到第一个 GPU 活动之间、最后一个 GPU 活动到响应返回之间的纯 CPU 时间。要不要算,取决于你在回答哪个问题:
- 「GPU 在它的活动窗口里有多忙」→ 分母是窗口自己的墙钟。这是 Layer 1 的问题。
- 「GPU 占端到端时间的多大比例」→ 这是另一个问题,由 Layer 3 和请求级阶段剖析回答。
把两者合成一个指标,等于把「GPU 计算本身就轻」和「CPU 排队变重了」两个不同的根因揉成一个看不懂的数。
配套的坑:真要测「窗口外的 CPU 时间」,必须拿 trace 里 GPU 活动的真实起止时间戳做锚点,不能拿应用层的事件标记(比如请求剖析器的 prefill 开始标记)当替身 —— 异步的 H2D 拷贝可能比应用层标记早好几毫秒就在 GPU 上开始了。