Python 进程 CPU 使用率只有 8%:off-CPU 分析定位阻塞的 subprocess.run 调用
当一个 Python 进程不断收到请求、CPU 使用率却始终上不去时——本例中的 gunicorn 工作进程卡在 8% 左右——说明有代码路径在阻塞操作系统线程,而不是在 CPU 上干活。本文演示如何用 OpenResty XRay 的 off-CPU 分析找到具体的阻塞 Python 代码路径:它把 92.4% 的阻塞时间追踪到业务文件 processor.py 第 12 行的一个 subprocess.run 调用——全程不改代码、不重启进程。
症状:请求涌入但 Python 进程 CPU 使用率上不去
让我们运行 top 命令来检查每个进程的 CPU 使用情况。
可以看到这个 gunicorn python 进程的 CPU 使用率非常低,只有 8% 左右。即使有很多请求进来,它也不会上升。
通过 ps 命令可以看到,这个进程使用的是 Linux 发行版自带的标准 Python 3 二进制可执行文件;而这个 Python Web 应用的访问日志还在随着新的客户端请求不断增长,CPU 使用率却始终很低。这意味着有一些东西阻塞了 Python 代码高效地运行。我们怎么才能找出来阻塞的东西到底是什么呢?
用 OpenResty XRay 的引导式分析定位阻塞的 Python 代码路径
我们可以使用 OpenResty XRay 来检查这个未经修改的进程,对它进行实时分析,弄清楚到底发生了什么事。
在浏览器中打开 OpenResty XRay 的 web 控制台,确认当前分析的是正确的机器,然后进入 “Guided Analysis”(引导式分析)页面。在可诊断的问题类型中,选择 “Low CPU usage and cannot go up”(CPU 使用率低且上不去)。接下来跟随向导操作:选择 Python 应用,选中消耗 10% CPU 资源的 gunicorn 子进程(也就是我们之前在 top 中看到的那个),其余步骤保持默认值即可——应用类型、同时选中 Python 和 C 两个语言层级,以及 300 秒的最大分析时间。
开始分析。系统将持续进行多轮分析;对于这个案例来说,两轮分析已经足够,我们就此停止,系统会自动创建一个报告。
报告显示了阻塞 CPU 高效运行的第一名 C 语言层代码路径,它占了 96% 的 off-CPU 时间。
第一个函数是 poll 系统调用。它意味着 Python 解释器正在等待 I/O 事件。但是它在等待什么样的 I/O 事件呢?要找出这个信息,我们需要更多的上下文线索。
_PyEval_EvalFrameDefault 函数表示当前正在运行一些 Python 代码。
然后我们看看排名第一的 off-CPU Python 代码路径,它占了 92.4% 的阻塞时间。
看看这个 Python run 函数,它是在标准的 subprocess.py 模块文件中定义的。这意味着 Python 代码正在运行一个子进程命令,并等待它的输出。
函数 handle_by_script 是在我们的业务级 Python 代码库中。
点击查看更多细节。
最重要的阻塞性代码路径是从这个 Python-land off-CPU 火焰图中自动推导出来的。火焰图展示了一个整体的状况。这样的 off-CPU 分析也是诊断延迟问题的标准方法——参见我们如何在 50 万 QPS 的 OpenResty 网关中定位 244ms 的延迟毛刺。
下面是关于当前问题的更详细的解释和建议。
它谈到了我们之前看到的 handle_by_script 函数。
也提到了这个函数运行了一个子进程。
将鼠标悬停在名为 handle_by_script 的 Python 函数的绿色框上。
可以看到这个函数的 Python 源文件。并且,在提示框中可以看到 processor.py 文件的完整路径。
源代码行号是 12。
点击图标复制这个函数的完整 Python 源文件路径。
使用 vim 编辑器,粘贴我们刚刚复制的代码路径,查看相应的业务 Python 代码。您可以使用任何您喜欢的编辑器。
正如 OpenResty XRay 建议的那样跳转到第 12 行。
可以看到,这个 Python 代码行确实是调用了 subprocess.run 函数,运行一个外部 bash 脚本并等待其输出。
它也在之前报告中显示的函数 handle_by_script 中。同样的 off-CPU 分析方法也适用于 Perl 和 Go 进程。
Insights 页面中的全自动分析与报告
OpenResty XRay 也可以自动监控在线进程,并在 “Insights” 页面中生成以日和周为周期的分析报告——所以您不一定非要手动使用引导式分析功能,尽管它对于应用的开发和演示很有用。
FAQ
为什么 Python 进程在大量请求下 CPU 使用率还是上不去?
因为有代码路径在阻塞操作系统线程,而不是在 CPU 上干活。在上面的案例中,gunicorn 工作进程在大量请求下 CPU 始终只有 8% 左右,因为 Python 代码正在运行一个子进程命令并等待它的输出,阻塞在 poll 系统调用中。
如何在不修改代码的情况下找到阻塞的 Python 代码?
对未经修改的运行中进程执行 OpenResty XRay 的引导式分析,选择 “Low CPU usage and cannot go up” 问题类型。自动生成的报告会推导出最重要的阻塞代码路径,将鼠标悬停在 off-CPU 火焰图中的函数上,即可看到它的源文件和行号。
为什么 subprocess.run 会阻塞我的 Python Web 应用?
subprocess.run 会启动一个外部命令并等待它执行完毕。在上面的案例中,业务函数 handle_by_script 在 processor.py 第 12 行调用 subprocess.run 运行一个 bash 脚本,导致 gunicorn 工作进程把 92.4% 的阻塞时间花在等待子进程输出上,而不是处理请求。
关于 OpenResty XRay
OpenResty XRay 是一个动态追踪产品,它可以自动分析运行中的应用,以解决性能问题、行为问题和安全漏洞,并提供可行的建议。在底层实现上,OpenResty XRay 由我们的 Y 语言驱动,可以在不同环境下支持多种不同的运行时,如 Stap+、eBPF+、GDB 和 ODB。
关于本文和关联视频
本文和相关联的视频都是完全由我们的 OpenResty Showman 产品从一个简单的剧本文件自动生成的。
关于作者
章亦春是开源 OpenResty® 项目创始人兼 OpenResty Inc. 公司 CEO 和创始人。
章亦春(Github ID: agentzh),生于中国江苏,现定居美国湾区。他是中国早期开源技术和文化的倡导者和领军人物,曾供职于多家国际知名的高科技企业,如 Cloudflare、雅虎、阿里巴巴, 是 “边缘计算“、”动态追踪 “和 “机器编程 “的先驱,拥有超过 22 年的编程及 16 年的开源经验。作为拥有超过 4000 万全球域名用户的开源项目的领导者。他基于其 OpenResty® 开源项目打造的高科技企业 OpenResty Inc. 位于美国硅谷中心。其主打的两个产品 OpenResty XRay(利用动态追踪技术的非侵入式的故障剖析和排除工具)和 OpenResty Edge(最适合微服务和分布式流量的全能型网关软件),广受全球众多上市及大型企业青睐。在 OpenResty 以外,章亦春为多个开源项目贡献了累计超过百万行代码,其中包括,Linux 内核、Nginx、LuaJIT、GDB、SystemTap、LLVM、Perl 等,并编写过 60 多个开源软件库。
关注我们
如果您喜欢本文,欢迎关注我们 OpenResty Inc. 公司的博客网站 。也欢迎扫码关注我们的微信公众号:
翻译
我们提供了英文版原文和中译版(本文)。我们也欢迎读者提供其他语言的翻译版本,只要是全文翻译不带省略,我们都将会考虑采用,非常感谢!






































