Skip to main content

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 showpyproject.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 Metricsnsys 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 里的映射表。

两个方向相反的偏差

同一段 trace、同一个 100 ms 窗口,三种算法给出三个数(数值为示意)TRACE 里实际发生了什么流 0 · KERNEL流 1 · KERNELMEMCPY图回放 cudaGraphLaunch↖ 重叠 10 ms,会被数两遍020406080100 ms三种算法各自数到了多少102%直接求和重叠段被数了两遍65%只并 KERNEL漏掉拷贝与图回放88%全类取并集把所有活动类合起来怎么判断这个模型需不需要严格算法:服务日志或配置里出现「图分桶」,基本就是重度依赖 CUDA Graph 回放,那么前两种算法得到的忙碌比都不能信。
三条结果条画在同一根时间轴上,能直接看出差别从哪来:第一条越过了窗口右边界,因为重叠的 10 ms 被数了两遍;第二条在 72–95 ms 那段是空的,那正是被漏掉的内存拷贝与图回放。issue 里记录了一个具体版本差异:某个 torch 版本的 trace 里根本没有图回放专属的活动类,而备选的「回放 kernel 事件带图 id 参数」这条线索在该版本上也不成立 —— 图回放最终是以 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 上开始了。

已知做不到的

现有的 chrome / CUPTI trace 里没有 batch size 上下文,所以拿不到「每个 kernel 的执行时间按当时的批大小分解」。想要这个粒度,得在服务代码里给每次 forward 加 NVTX 区间并打上当时的批大小 —— 那是代码改动,不是写个解析脚本能补出来的。

判定规则:多种方法测出的忙碌比都远低于 100%,瓶颈主要在 CPU/编排,下一步去 Layer 2,别再纠结 kernel 选型;忙碌比已经接近饱和,Layer 2 到 4 的收益很低,直接转 kernel 级优化。注意这个比值随并发的走向在不同负载形状下可能完全相反(短片段 vs 长序列),同一个模型要按负载形状分别测。

四、Layer 2:py-spy 采样

py-spy record --format raw --idle --subprocesses --pid <engine-pid> \
--duration 25 --rate 20 --output out.raw
四个会让结果「看起来很干净但其实没用」的坑

① 不加 --idle 等于什么都没采到。 默认模式会整个跳过阻塞或释放 GIL 的调用 —— CUDA 调用、queue.get()zmq.poll() 全都不采,输出「Samples: 0, Errors: 0」。这看起来像一次健康的采样,实际零有效样本。

② 采错进程。 要采的是真正跑调度和前向的那个,不是顶层 HTTP 服务进程 —— 它通常是顶层 fork 出来的子进程,有一百多个线程。加 --subprocesses 会把 resource_tracker 之类的胶水进程也拉进来。

③ 按函数名分组会静默合并。 实测:调度线程的入口函数恰好也叫 _worker,跟标准库 concurrent.futures.thread 里的 _worker 同名,按函数名分组会把两个毫无关系的叶帧合成一个。要按 file:line 分。

④ 进程级统计会淹没信号。 实测:进程级 --idle 采样里约 89% 的叶帧落在线程池等待代码上,把调度线程的真实信号完全埋掉。要按调度线程的入口帧收窄作用域,两个数各带各的分母分开报。

还有两条:叶帧占比的分母必须是「总样本数」而不是「活跃帧数」;--idle 与不加 --idle 各采一遍,分别回答「阻塞在哪」和「CPU 时间花在哪」—— 这两份数据不能混着看。

另外三条操作规矩:

  • 采样率从低往高试。 不清楚目标进程的线程数和负载强度时,先 --rate 5,确认输出里没有「fell behind」之类的滞后警告再考虑提高。报了滞后的采样直接丢弃 —— 采样器跟不上时会系统性地漏掉高频短调用,这是有偏的丢失,不是「样本少一点但方向还对」。
  • 采样期间必须有真实负载。 压测脚本要全程打请求,别在服务刚起来空转时采。
  • 区分「一次性摊销成本」和「稳态税」。 单个采样窗口不足以下结论,至少做三次独立重复(同配置、不同时间窗),看百分比是否收敛到稳定值。怀疑某项开销只在启动/预热时出现的话,等进程跑一阵子再补采一次对比。

五、Layer 3:并发扫描

这一层要回答的问题只有一个:堆并发能不能把利用率推上去

扫完之后你会拿到一条「GPU 利用率 vs 并发」的曲线。它长什么样,直接决定下一步往哪走 —— 三种形态对应三个完全不同的结论:

横轴并发 8 / 16 / 32 / 64,纵轴 GPU 利用率形态 A · 单调上升结论:还没到头,继续堆下一步:把并发上限调高再扫形态 B · 抬到某点走平结论:算力真打满了下一步:转 kernel 级优化,别再查主机侧形态 C · 不升反降且抖结论:主机侧开销随并发变重下一步:查 CPU 侧调度与同步,不是堆并发
最容易误判的是 C。它看起来像「并发还不够高」,于是有人继续往上堆 —— 但真实原因是 CPU 侧的调度和同步开销随并发变重,在 GPU 时间线上撕开了更多空隙。区分办法:在两个并发点各拉一段带 osrt 的 nsys trace,看主机侧等待类系统调用的频率是否随并发同步上升。这是佐证不是证明,但足以把下一步转向 CPU 侧。

标准扫法:其余全部固定,并发扫 64(或模型自己的 max_running_requests 硬上限)。每个点至少重复 2~3 次,外加一次不计入统计的预热。

标准设计:其余全部固定,并发扫 64(或模型自己的 max_running_requests 硬上限),每个点重复 2~3 次并预热一次,同时采 GPU 利用率,记录吞吐、延迟、准确率。这四项缺一项,结论就只能算参考。

负结果的判据:GPU 利用率不随并发单调上升,甚至在硬上限处最低;同时吞吐的边际收益明显收窄,p95 尾延迟明显变差。这个形态说明吞吐的增长来自「把每步的固定调度成本摊到更大的批上」,而不是 GPU 真的更忙了 —— 继续堆并发买不到利用率,只会买到更差的尾延迟

忙碌比随并发下降且抖动很大是个容易误读的形态。它看起来像「并发还不够高」,但也可能是主机侧症状:CPU 调度/同步开销随并发变重,在 GPU 时间线上撕开更多更长的空隙,把忙碌比拖下去。两者的修法完全不同。区分办法:在要对比的几个并发点各拉一段短的 nsys trace(--trace 里带上 osrt),看主机侧同步/等待系统调用(pthread_cond_wait 之类)的频率是否随并发明显上升、且与忙碌比的下降同步。这是佐证不是证明 —— 相关性不等于因果,但足以支持把下一步调查转向 CPU 侧调度逻辑。

两个来自共享机器的坑:

  • 压测期间顺便看一眼另一张卡nvidia-smi,确认你没把外部租户的利用率算到自己头上。
  • nvidia-smi --query-compute-apps 报的 PID 归属在共享沙箱上可能不可靠 —— 本地进程命名空间和 nvidia-smi 看到的可能对不上,你自己的显存分配会被误报成「外部进程」。怀疑外部争用时,杀掉自己的进程看占用是否一起消失,别只信 PID 那一列。

六、Layer 4:A/B 实验

Layer 2 找出可疑开销之后,设计一个干净的 A/B:

  1. 只改一个变量,配置、GPU、数据集全部固定。优先用 CLI 覆盖而不是改代码默认值,这样切换快。
  2. 两组的预热策略必须一致。 一组带 --warmup 另一组不带,引入的是混淆噪声。结论只能建立在方法学对齐的两次运行上;方法不一致的运行最多算方向性佐证。
  3. 两组的 GPU 环境必须一致(要么都在干净卡上,要么都处在同等程度的租户争用下)。中途被外部租户抢卡、显存被迫缩容的那次运行,其吞吐数字不能用于性能结论;但如果只是验证「这项开销的采样占比是否归零」这种定性问题,它仍然可用。
  4. 判定「无功能/精度回退」要过三关:服务能正常走完权重加载、CUDA Graph 捕获等启动阶段;精度指标与基线一致;吞吐和延迟没有肉眼可见的变差。三条全过才能说「关掉它/改掉它是安全的」。
  5. 重跑一遍 Layer 2 的采样,确认那个可疑开销的叶帧占比是否真的归零(叶帧就是采样那一刻栈最顶上的那一帧,代表 CPU 当时真正在执行的代码)。别只看吞吐 —— 吞吐会因为噪声抖动,而叶帧占比归零是更直接的因果证据。
  6. 做 2~3 次重复,理由同 Layer 2。

七、Layer 5:功能正确性回归

以下两种情况必须补一轮专门的功能回归,不能拿 Layer 3/4 顺带跑过的数据集充数:

  • 改了任何默认值或调度逻辑之后。即使 A/B 阶段已经在短序列数据集上验证过没回退,也要再跑一个长序列或结构不同的数据集 —— 不同的输入长度和结构会走完全不同的请求分块代码路径(比如超过单次最大长度必须切块的输入)。
  • 任何触及注意力后端或 CUDA Graph 兼容性的改动,要特别关注编码器-解码器结构(而非纯 decoder-only)的边界情况。优先做结构性判断(「这是编码器-解码器模型 → 默认走更保守的行为」)而不是维护一份后端黑名单 —— 一个新后端复用了老后端的实现却没被加进已有黑名单,正是最容易漏掉的那类事故。

八、报告怎么写

按层组织:每一层用了什么方法、发现了什么、证据强度是强/中/弱,最后给一张「发现 — 证据 — 建议」表。

三条关于报告的硬要求:

  • 负结果要明确写出来。 「查过了,当前默认值已经合适,不需要改」是和「找到问题」同等有效的产出,前提是推理过程写清楚。
  • 报样本数和原始值,不能只报均值。 采样数为 0 或明显偏少(比如低于 20)的,最多当方向性参考,绝不能当结论。有一个实测的坑:压测窗口太短时,采样器会因为「先等一个间隔再采」的实现而拿到零个样本,而不只是少数几个;把采样间隔调小也治不了本,因为单次 nvidia-smi 调用本身就要 180~340 ms。负载本身短就把它拉长或多轮重复,攒够样本再平均。
  • 踩到的通用坑要写回方法论文档。 只跟你这个模型有关的放模型报告,通用的(新的 py-spy 陷阱、新的争用形态)回填到这套流程里,下一个人就不用重新踩一遍。

最后这条是这份 issue 本身的写法:它把自己定位成一份会被反复追加的活文档,而不是某一次调查的记录。方法论文档和调查报告分开维护,是它最值得抄的组织方式。

回到00 - 专题索引