D2H 怎么会 hang 呢!

这个月我学到了一个冷知识: cudaMemcpyAsync 可以永远不返回.

不是慢, 不是超时, 是永远. scheduler 主线程在用户态自旋, GPU 全程空闲, 一个 kernel 都没在跑. 就像你叫了辆网约车, 司机接单了, 车没动, 电话打不通, 平台显示一切正常 —— 然后你在路边站了一辈子.

事情发生在 itk 链路 (indexer top-k) 上. 在 一行代码引起的分布式死锁 里我提过, 我把 DSA R3 的数据流从 GB 粒度压到了 KB 级别: 推理引擎每次 forward 把 DSA indexer 选出来的 block top-k 收进一块 device buffer, 算完搬到 host, 编码之后写进 mooncake (这块池子在 RL 下的演进见 RL 下 Mooncake Store 演进分析), 训练侧按 key 取回. 整条链路需要 GPU 让路的只有中间那一搬: 一次 .cpu().

然后 scheduler 就死在这 .cpu() 上了.

D2H 真的会 hang!

最先报警的不是 scheduler, 是 tokenizer:

WARNING tokenizer_manager.py: Still waiting for request output in tokenizer worker:
rid=638adbb9b97140e895b5f4368881cbe0 elapsed=900.106s ... out_queue=0

一个请求等了 900 秒没输出. 但这条告警我不太敢信: 请求积压、排队超时, 打的也是这句话. 我一开始拿它当 hang 的信号, 后来发现它把”积压”和”真卡死”混成了一锅. 真正可靠的判据是另一个: scheduler 的 Prefill batch / Decode batch 日志永久停摆, 再也不恢复. 换成这个判据把历史日志重新过一遍, 之前那批”疑似”里一小半根本没死, 只是挤. 对真停摆的那个 scheduler 跑 py-spy dump --native --locals, 现场长这样 (去掉了无关帧和拓扑字段):

Thread 1306 (active): "MainThread"
    0xffff8e8190d4 (libcuda.so)
    ... 省略 11 帧 libcuda 内部帧 ...
    cuMemcpyDtoHAsync_v2 (libcuda.so)
    cudaMemcpyAsync (libcudart.so)
    at::native::copy_kernel_cuda (libtorch_cuda.so)
    _sync_fwd_experts_buffer_DtoH (moe/routed_experts_capturer.py:355)
        Locals:
            local_start_pos: 0
            local_end_pos: 2048
            out_cache_loc_cpu: <Tensor at 0xfffa306fec10>
    on_forward_end (moe/routed_experts_capturer.py:408)
    forward (model_runner.py:3177)
    forward_batch_generation (tp_worker.py:483)
    run_batch (scheduler.py:2911)
    event_loop_normal (scheduler.py:1433)

栈底是 scheduler 的主事件循环, 栈顶是 cuMemcpyDtoHAsync_v2. 对应源码两行, 355 行是函数里第二个 .cpu():

out_cache_loc_cpu = forward_batch.out_cache_loc.cpu()
self.host_cache.buffer[out_cache_loc_cpu] = self.device_cache.buffer[
    local_start_pos:local_end_pos, :, : self.num_experts_per_tok
].cpu()  # 355: 卡在这里

接下来是例行排除. 这种栈有三种常见解释, 我一个一个否给你看.

第一种: stream 里还有没跑完的 kernel, .cpu() 在等它. 栈上有两处直接否掉. 第一, locals 里 out_cache_loc_cpu 已经有值了 —— 上一行那次 .cpu() 是阻塞拷贝, 它正常返回过, 意味着当前 stream 已经被抽干, 下一行发起时流上是空的. 第二, itk 那个站点的现场更干净: 我在那次 .cpu() 前后各套了一个 torch.cuda.synchronize(), 前面的正常返回, 后面的永远没执行到; 两个 synchronize 之间打了点, 进来打”1”, 出去打”2”, 线上日志里那个 rank 只有”1”, 永远等不到它的”2”. 那次拷贝 shape 是 [1090, 12, 2048], 192 MiB. 至于 GPU: 利用率 2%/0%/0%/0%. 车没动, 而且引擎压根没启动.

第二种: CPU 睡着等 GPU 的完成通知. py-spy 把这条线程标成 active —— 它不是睡在 futex 上, 是在用户态实打实地空转.

第三种: 被别的 rank 拖住. 因果方向是反的. 同机其他 rank 全停在 c10d::Work::wait ← broadcast, 那是 scheduler 取请求前的广播 —— 是它们在等它. 而它自己的栈上一个 NCCL / gloo 帧都没有: 一次纯本地的 memcpy, 不参与任何集合通信. 进程里两百多个线程 (mooncake 的 asio 池、各网卡 RDMA 事件线程、NCCL proxy 与 watchdog) 全部 idle, 只有 MainThread 在转. 还有个旁证: 谁先死是随机的 —— 有节点在权重同步 resume 后 28 秒就死了, 当时跑的是几百 token 的小 prefill, 其他节点又多跑了两分多钟. 这不像被谁拖住, 像每次拷贝各自掷各自的骰子.

那十二帧 libcuda 裸地址我顺手也翻了. py-spy 只给地址, 但同时抓的 gdb dump 里恰好有一帧带符号 (cuLaunchKernel), 拿它锚定 load base, 剩下的地址逐个反汇编: 最里面是一个轮询循环 —— 构造请求描述符, 逐层往下, 遍历一串 engine 条目逐个调 poll 函数, 再沿 channel 链表读一个十几字节的状态记录, 有错误码就把错误码返上来. 现场没有错误码. 那个状态字, 就是永远不翻.

机制至此清楚了: pageable 目标的 D2H, 驱动每次要临时 pin 一段 staging、映射、发起 DMA、轮询完成. 卡的就是这个轮询, 它等的东西永远不来. 不是死锁, 是 livelock; 也不是 GPU 挂了, GPU 全程干干净净.

D2H 怎么能 hang!

死法清楚了. 剩的问题是: 凭什么. 一次 host-device memcpy, 凭什么能永久卡住. 排查这类问题的传统姿势是人肉复现: 搭环境、造流量、盯日志、抓栈、改个变量再来一轮, 每轮几十分钟, 大半时间在等. 我把这活儿整个外包给了 qoder: 开一个 goal, turn_budget=1000, 让它无人驻守自己迭代:

• 自己按线上方式拉起 sglang, ServerArgs 逐字段对着线上 dump 校;
• 自己写客户端造流量: 超长 prompt、长 decode、连续并发、共享超长前缀的 fork 模式;
• 自己按 batch 日志判停摆, 停摆就自己 py-spy 抓所有 scheduler、抓 /proc 内核栈;
• 自己把结论写回 NOTES.md, 命令、改动、日志全部 git commit, 供我事后审计;
• 它跑在一个易失的 pod 上, 我让它周期性把记录刷回持久化目录, pod 挂了接着跑.

我只负责提要求和读结论. 下面这些实验, 没有一条是我手动跑的:

每一行的结论都是”干净”. 干净得让人不安.

微基准也是同样的剧情: 裸 pageable 192 MiB D2H 跑了八万次, p50 1.7ms, 一个长尾都没有. 人为制造压力也试过:

• copy engine 打满: pageable 的 p50 从 1.1ms 掉到 1.3s, 慢了一千倍 —— 但 pinned 一样慢. 这是通用的 CE 排队, 不是 pageable 的病; 而且线上死的时候 GPU 是空的, 压根没有竞争. 排除.
• cudaHostRegister / cudaHostUnregister 搅动: pageable 的 p50 退化到几十毫秒, 最大 700 多毫秒 —— pinned 一样退化. 争用是真的, 但表现是变慢, 不是无限卡死. 排除.

中间倒是”复现”过一次, 只是凶手是我们自己: 四个 scheduler 全卡了, cuda-gdb 一看, GPU 上有个自旋的集合通信 kernel, GPU 100% 忙. 查下来是假权重同步进程退出时没 destroy process group, 把一个自旋 kernel 留在了卡上. 线上现场是”GPU 空闲 + CPU 在 memcpy 里自旋”, 这里是”GPU 忙 + CPU 在等流”, 两码事. 白激动一场.

所以最终结论分两半: 怎么死的, 我知道 —— 用户态轮询, 等一个永不翻转的状态字; 为什么死, 我不知道 —— 线上能复刻的条件全复刻了, 一次没中. 输掉了二十轮.

命运没有眷顾着我

输了二十轮之后, 我决定赌一把大的: 开一个最高优先级的任务, 最大重启次数 40. 当时心态很好: 40 次机会, 我不信逮不到你. 凌晨改完一个实验, 我手动触发了一次重启, 然后没守着它 —— 我转头去琢磨下一个实验, 我认定的终局之战:

我现在有个怀疑, 还是我 itk 链路引起的. itk 链路每秒单个 scheduler 吞吐大概 750MB/s, 对系统压力还是比较大的. 我有一个想法就是在 itk 链路不再频繁分配 pin memory, 而是像 routed_experts_capturer.py 一样, pin memory 只分配一次用来承接 device 数据, 之后将 pin memory 拷贝到一块新的 non pin memory, 之后将这个 non pin memory 作为 itk mc 数据源. 从 pin memory 拷贝到 non pin memory 就是普通的 cpu 操作. 这样对整个系统压力更小一点.

我以为这就是最终答案了. 我以为故事要结束了. 等 qoder 把代码写完, 我打算先看一眼上一轮的结果, 再决定要不要手动重启. 然后我看了一眼重启次数: 40 / 40.

我上轮把脚本路径写错了. 任务每次起来就是一个 No such file or directory, 然后重启, 再 No such file or directory, 再重启. 一分半一轮, 在我安心琢磨终局之战的这几个小时里, 它安安静静地把 40 条命全送完了.

而第 40 次 —— 最后一次 —— 正要开始. 我手忙脚乱把代码推上去, 赶上了. 最后一班车. 当时真有一种宿命感: 这问题要是真在最后一次重启里被修好, 这故事够我讲一年.

然后我稀里糊涂睡了半觉. 睡醒一看: hang 了.

LOVE YOU! NVIDIA!

Linus 有一张传世照片: 对着镜头竖中指, 原话 “NVIDIA”. 我没有那个胆量, 我只有一句 commit message: continue .tolist -> d2list. love nvidia!. 是的, love. 因为骂不动了.

睡醒看到那个 hang 的时候, 我彻底死心了: 不再试图搞清楚驱动为什么卡, 改成 case by case, 见缝插针地修. 判据极简 —— 卡在某个 pageable 目标的拷贝上, 就把那个目标换成常驻 pinned buffer. 至于为什么卡, 交给下一代驱动, 或者下一个愿意查的人. 死心之后要做的不是排查, 是把”发现 → 定位 → 修 → 重跑”做成流水线.

第一步, 让现场自己走到眼前. sglang 的 scheduler 本来就有 soft watchdog: 主循环每步喂一次计数器, 阈值内不前进就报警, soft 的意思是只报警、不杀进程. 我加了两件事:

• 新增 --sched-soft-watchdog-timeout, 把 scheduler 的阈值从其他进程拆出来. 原来一个 --soft-watchdog-timeout 同时驱动 scheduler、tokenizer、detokenizer、DP controller 四个进程的 watchdog, 但真正值得盯的只有 scheduler —— 其他几个通常是被它拖着一起停的, 阈值一紧, 那三个跟着一起吵.
• watchdog 触发时对自己跑一次 py-spy dump --native --locals, 把栈直接写进任务日志.

第二步, qoder 盯日志, 捞栈, 定位到具体哪一行 pageable 拷贝, 换成 pinned staging, 提交, 重跑. 我早上起来看结论.

于是有了这张打地鼠成绩单. 每一行, 都是一次线上抓到的自旋现场:

这张表换来三条知识, 每一条都是它亲手教我的.

尺寸不是判据. 修 routed experts 那次, 我留了一个 .cpu() 没动, 理由很充分: 才几十 KB, 从没见它卡过. 下一轮它就死在了同一个类里几百 KB 的 req_to_token 行切片上. 从 5 KB 到 192 MiB, 每一档都死过.

方向也不是判据. 第五次是 H2D: xgrammar 交出来的 vocab mask 是 pageable 的 host 内存, 搬上卡时死在 cuMemcpyHtoDAsync_v2 里, GPU 依旧空闲. 四次 D2H 之后来一次 H2D, 说明共同原因是驱动那个 pageable staging 池, 而不是哪个方向有什么弱点 —— pageable 拷贝, 两个方向都过这个池.

挪动本身就是证据. 每修掉一处, 下一轮它就死在另一处仍是 pageable 的拷贝上, 从没落进任何一处已经换成 pinned 的站点.

任务跑起来了. 但我没赢: 我没有解决驱动为什么自旋, 我只是把每一格可能炸的格子, 换成了不会炸的. 雷还在, 在我 grep 不到的地方. 哪天有别的 pageable 拷贝再死一次, 这篇文章的第一节, 可以直接拿去当诊断手册.

LOVE YOU! NVIDIA!

后记

在成功地从 104kg 健到 70kg 之后, 我又在杠上挂了半年之后, 拉齐了 2 个引体向上. 有朋友圈视频为证! 哈哈哈.

在杠上挂了半年终于拉上去两个, 和被 D2H 挂了十来天终于放弃排查, 是同一个星期发生的事. 我分不清哪个成就感更大.

• Previous
  一行代码引起的分布式死锁