Popen 未读管道:备份脚本卡在 64KB

夜间备份脚本偶尔永久挂起,根因是 Popen 把输出接到管道后直接 wait,子进程写满 64KB 缓冲被阻塞。改用 communicate 并加超时后恢复。

问题背景

运维组有一台文件服务器,每天凌晨 1 点半跑一个 Python 备份脚本:用 subprocess.Popen 调用 rsync,把业务目录同步到备份盘,脚本负责记录耗时、输出和退出码,最后把结果写进日志并发通知。这套脚本跑了半年多,一直很稳。

上个月新项目上线,业务目录从 200GB 涨到 1.2TB,文件数量也翻了几倍。数据量变大后,备份偶尔会“卡住”:脚本进程还在,rsync 也在,但两边都不动,CPU 占用接近零,日志里没有任何报错,直到早上有人发现备份没完成。

故障现象

  • 脚本每周有两三次整夜不结束,第二天上班还挂在那里;手动 Ctrl+C 后重跑,有时能成功,有时又卡住。
  • 卡住时 ps 能看到 Python 主进程和 rsync 子进程都活着,状态都是睡眠,CPU 几乎为零。
  • 小目录备份从不复现;大目录、文件多、输出量大的任务更容易卡。
  • 杀掉 Python 进程后,rsync 有时变成孤儿进程继续跑,下一次定时任务又启动一份,出现重叠备份。
  • 日志里没有超时、没有错误码,因为脚本要等 wait() 返回之后才去读输出——可它永远没返回。

排查过程

第一步复现。手动对大目录执行脚本,观察输出和进程状态;再用一个小目录做对照。小目录几十秒完成,大目录跑到某个点后完全静止,说明和数据量、输出量相关,不是 rsync 本身报错。

第二步看进程在等什么。py-spy dump 打到 Python 主进程,主线程停在 waitpid;ps -o pid,stat,wchan,cmd 看 rsync 子进程,状态是 S,wchan 显示 pipe_write。也就是说,子进程卡在“往管道写”的系统调用上,父进程卡在“等子进程退出”上,两边互相等。

第三步确认管道状态。ls -l /proc/<python>/fd 能看到指向 pipe:[...] 的文件描述符;用 fcntl 查管道容量,返回 65536 字节,正是 Linux 默认的 64KB。再抓子进程的 strace,最后一条系统调用停在 write(1, ...) 没有返回——管道满了,写不进去。

第四步回到代码。脚本的写法是:

1
2
3
4
p = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
p.wait()
out = p.stdout.read()
err = p.stderr.read()

Popen 创建了两根管道,但父进程在 wait() 期间并不读它们。子进程的输出一旦超过 64KB,管道写满,子进程阻塞在 write;父进程等子进程退出,子进程等父进程腾空管道——标准的生产者消费者死锁。之前数据量小,rsync 输出不到 64KB,问题被完美掩盖。

还有一种更隐蔽的变体:只把 stdout 接到 PIPE、stderr 继承终端。此时 stderr 不会阻塞,但 stdout 超过 64KB 一样会卡死;判断依据不是“接了几根管道”,而是“有没有任何一根管道没人读”。

第五步最小复现。写一个子进程连续往 stdout 写 100KB,父进程用同样的 Popen + wait() 接法,跑到 64KB 左右必然卡住;把父进程改成 communicate(),同样的子进程顺利结束。变量唯一,结论确认。

解决方案

  1. 改用 subprocess.run:subprocess.run(cmd, capture_output=True, text=True, timeout=3600, check=True)。它内部用 communicate() 并发读取 stdout 和 stderr,不会出现管道写满无人读的情况;超时会杀掉子进程并抛出 TimeoutExpired。
  2. 需要流式处理时用 communicate():p.communicate(timeout=3600) 同样会持续排空两根管道。注意 communicate 超时后不会自动杀进程,要显式 p.kill() 或杀掉整个进程组,再调用一次 communicate() 收回残留输出。
  3. 超时后杀进程组:启动时加 start_new_session=True,超时后 os.killpg(os.getpgid(p.pid), signal.SIGKILL),避免 rsync 变成孤儿继续占用备份盘。
  4. 大输出不要进内存:如果命令输出可能很大,直接把 stdout 重定向到日志文件(stdout=log_fp, stderr=subprocess.STDOUT),或者用线程持续读管道;同时给 rsync 加 -q 或降低日志级别,从源头控制输出量。
  5. 加锁防重叠:cron 命令前加 flock -n /var/lock/backup.lock,上一次没结束时直接跳过并告警,避免多份备份同时写盘。
  6. 验证:用一个会产生 100MB 输出的测试命令跑完整流程,确认脚本能正常结束、超时能触发、退出码和输出都写进日志。

根因分析

直接根因是 Popen 把 stdout 和 stderr 接到管道后直接 wait(),父进程不读管道;子进程输出超过 64KB 的管道缓冲后阻塞在 write,父进程又在等子进程退出,形成死锁。

更深一层,是脚本只在“小数据量”下验证过。200GB 时 rsync 的输出不到 64KB,wait() 接法看起来完全正确;数据涨到 1.2TB 后,输出量和文件数一起增长,越过了那个隐形的 64KB 阈值。代码里没有超时、没有输出上限、没有防重叠,于是“偶发卡住”变成了“整夜不结束”。再加上日志要等 wait() 返回才写,故障期间没有任何可观测信息,排查只能靠进程状态反推。

预防措施

  • 代码规范明确禁止 Popen + PIPE + wait() 组合;需要收集输出一律用 run(capture_output=True) 或 communicate()。
  • 所有外部命令必须设置超时,并明确超时后的清理动作(杀进程组、释放锁、告警)。
  • 定时任务统一加 flock,把“重叠执行”变成显式失败,而不是悄悄堆积。
  • 大输出场景默认落文件而不是进内存,避免管道和内存双重风险。
  • 外部命令的输出量要有上限:日志级别、进度输出、错误详情都应有界,避免一次异常把管道和磁盘同时打满。
  • 监控任务耗时和退出码:超过历史基线就告警,不要等早上人工发现。
  • 压测用接近真实峰值的输入,不要只拿样例目录验证。

总结

管道是一个只有 64KB 的邮箱:有人往里投信,就得有人及时取走。wait() 只负责等子进程结束,不会帮你读信;邮箱一满,子进程就停在 write 上,父进程还在等它退出,两边一起等到天荒地老。这个脚本并不是“突然坏了”,而是数据量终于越过了那个一直存在、却从未被测试覆盖的阈值。超时、排空管道、加锁,做的都是同一件事:让挂起变成可见的失败,而不是无声的停机。

延伸阅读

使用 Hugo 构建
主题 Stack 由 Jimmy 设计