是什么把这个 Nginx worker 进程的 RPS 压在每秒 227–286 个请求,而系统负载却已逼近逻辑 CPU 核数?OpenResty XRayoff-CPU 分析在 20 秒采样窗口内捕获了 43952 个事件循环阻塞样本——单次最长 75 毫秒——并将其追踪到用户 Lua 文件中的同步 Lua IO 调用、阻塞式文件读取,以及缺失 worker_cpu_affinity 指令导致的 CPU 争抢。

传统监控工具只能看到负载高、延迟涨这类表象。本文将通过这个真实案例,展示 OpenResty XRay 的非侵入式动态追踪如何把每一处 off-CPU 瓶颈钉到具体的函数和代码行。

负载很高却没干活:缺失 worker_cpu_affinity 导致的 CPU 争抢

我们分析的第一步,是使用 OpenResty XRay 的 C 级别 off-CPU 火焰图来探查进程的等待事件。

nginx worker 进程的 C 级 off-CPU 火焰图:除 epoll_wait 等待栈外,纯 CPU 计算函数上也消耗了明显的 off-CPU 时间,是 CPU 资源争抢的迹象

分析结果显示,除了预期的 epoll_wait 网络IO等待之外,还有相当一部分 off-CPU 时间消耗在了 mpi_mul_hlpfree 等纯 CPU 计算相关的函数上。

这表明,进程在准备好运行时,却未能及时获得 CPU 时间片,这是 CPU 资源争用的典型特征。

通过专门的分析器,我们确认了问题的根源:nginx 配置文件中缺少了 worker_cpu_affinity 指令。

no cpu affinity set.
no cpu affinity set.

该配置的缺失,导致多个 nginx worker 进程在不同 CPU 核心间被 Linux 内核频繁调度,产生了不必要的上下文切换开销,从而降低了 CPU 的有效利用率。

阻塞的 Lua IO 操作如何拖停 Nginx 事件循环

解决了 CPU 争用问题后,我们继续对 off-CPU 时间进行分析。

Lua 级 off-CPU 火焰图:阻塞时间集中在 customize.lua 第 15 行调用的 file_list 函数内部的 popen 与 read 调用上

我们发现,绝大部分的 off-CPU 阻塞时间都指向了同一个源头:用户自定义的 customize.lua 文件第 15 行。

该行代码调用了一个名为 file_list 的函数,此函数内部使用了 Lua 标准库提供的 io.popenread 函数来执行 shell 命令。

这些都是同步阻塞式 IO 操作,它会暂停整个 Nginx 事件循环,直到外部命令执行完毕并返回结果。这正是导致系统吞吐能力低下的核心原因之一。

关于 io.popen 阻塞事件循环这一故障模式的完整解剖——以及带来 7 倍和 150 倍吞吐量提升的非阻塞替代方案——参见《Lua io.popen 阻塞 Nginx 事件循环:一次 150 倍吞吐量提升的实战案例》

量化文件 IO 延时:单次最高 1.5 毫秒

哪些文件读取最热

样本一

除了 io.popen 之外,我们还通过 C 级别虚拟文件系统读写次数火焰图,发现了另外两个潜在的性能瓶颈:

虚拟文件系统读写次数火焰图(样本一):apr_generate_random_bytes 调用栈被高亮,占文件读取次数的 59.8%

从上面这张火焰图可以看出,apr_generate_random_bytes 函数占用了高达 59.8% 的文件读取次数。

虚拟文件系统读写次数火焰图(样本一):apr_sdbm_fetch 调用栈被高亮,占文件读取次数的 24%

而根据第二张火焰图,apr_sdbm_fetch 函数占用了 24% 的文件读取次数。

样本二

虚拟文件系统读写次数火焰图(样本二):apr_generate_random_bytes 调用栈被高亮,占文件读取次数的 51.8%

从上面这张图可以看到,来自 APR(Apache Portable Runtime)库的 C 函数 apr_generate_random_bytes 占了 51.8% 的文件读取次数,调用方是 Nginx 进程内的 ModSecurity 模块。

虚拟文件系统读写次数火焰图(样本二):apr_sdbm_fetch 调用栈被高亮,占文件读取次数的 20.7%

而第二张图显示函数 apr_sdbm_fetch 一共占了 20.7% 的文件读取次数。

文件 IO 延时分布

为了精确评估这些文件 IO 操作的影响,我们通过专门的延时工具来测量 apr_generate_random_bytes 的延时分布:

3110 samples' latency: min=10, avg=17, max=1494 (us)
value |-------------------------------------------------- count
    2 |                                                      0
    4 |                                                      0
    8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  1540
   16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@   1499
   32 |@@                                                   64
   64 |                                                      4
  128 |                                                      1
  256 |                                                      1
  512 |                                                      0
 1024 |                                                      1
 2048 |                                                      0
 4096 |                                                      0

我们看到这个函数最大延时可达 1494 微秒,或者说接近 1.5 毫秒,还是相当可观的。这会阻塞 Nginx 事件循环,影响当前所有的并发连接上的请求延时。

而对于 apr_sdbm_fetch,有时也会接近 1 毫秒:

1570 samples' latency: min=5, avg=10, max=953 (us)
value |-------------------------------------------------- count
    1 |                                                      0
    2 |                                                      0
    4 |@@@@@@@@@@@@@@@@@                                   383
    8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  1080
   16 |@@@@                                                100
   32 |                                                      4
   64 |                                                      2
  128 |                                                      0
  256 |                                                      0
  512 |                                                      1
 1024 |                                                      0
 2048 |                                                      0

对于追求高并发和低延迟的 Nginx 而言,任何毫秒级的同步阻塞都是不容忽视的。

Nginx 事件循环阻塞有多严重?43952 个样本、最大 75 毫秒

最后,我们对 Nginx 事件循环的整体阻塞情况进行了全面评估。

在 20 秒的采样周期内,我们捕捉到了 43952 个阻塞样本,其中单次阻塞时长的最大值竟高达 75165 微秒,也就是超过 75 毫秒

distribution of epoll loop blocking latencies (us): 43952 samples: min/avg/max: 754/0/75165
 value |-------------------------------------------------- count
     0 |                                                      31
     1 |                                                     149
     2 |                                                      33
     4 |                                                     166
     8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@                        6094
    16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  10839
    32 |@@@@@@@@@@@@@@@                                     3278
    64 |@@@@@@@@@                                           2060
   128 |@@@@@@@@@@@                                         2530
   256 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@     10082
   512 |@@@@@@@@@@@                                         2544
  1024 |@@@@@                                               1162
  2048 |@@@@@@@@@@                                          2343
  4096 |@@@@@@@@@@                                          2377
  8192 |                                                     199
 16384 |                                                      55
 32768 |                                                       8
 65536 |                                                       2
131072 |                                                       0
262144 |                                                       0

这个数据清晰地解释了为何应用的性能如此低下。当事件循环被阻塞 75 毫秒时,意味着这个 worker 进程在这段时间内完全无法处理任何新的请求。

这样的阻塞还会同时波及该 worker 上所有正在处理的请求——这正是长尾延迟毛刺的经典成因。我们在另一个案例中展示了如何在 50 万 QPS 的 OpenResty 网关中定位 244 毫秒的性能异常

结合下面这个样本的分析:

found 3237 in reqs and 3238 done reqs in 3.103 sec (1043.07 r/s and 1043.39 r/s).
in reqs:
  pid 3101: 255.21 r/s
  pid 3102: 285.82 r/s
  pid 3103: 227.82 r/s
  pid 3106: 274.22 r/s
done reqs:
  pid 3102: 286.47 r/s
  pid 3103: 227.50 r/s
  pid 3101: 254.89 r/s
  pid 3106: 274.54 r/s

单个 worker 进程的 RPS 仅在 227-286 之间,进程的 RPS 是非常低的,每秒只处理了不到 300 个请求。而机器负载已经接近 4,已经是逻辑 CPU 核的个数。这与我们观察到的严重阻塞情况完全吻合。

总结:是什么拖垮了这个 Nginx worker

在深入分析的过程中,我们发现了多个影响系统性能的关键问题:

  • nginx worker 进程间的 CPU 资源争用导致了大量的上下文切换,严重影响了 CPU 的有效利用率。
  • 阻塞的 Lua IO 操作,如 io.popenread,在 customize.lua 文件中被频繁调用,成为了系统性能的最大拖累。
  • apr_generate_random_bytesapr_sdbm_fetch 函数的文件 IO 操作也对事件循环造成了显著的阻塞影响。
  • Nginx 事件循环的单次阻塞时长高达 75 毫秒,直接导致了单个 worker 进程的 RPS 仅在 227-286 之间,远低于预期。

这些问题的存在,正是导致系统性能低下的根本原因。通过 OpenResty XRay 的精准诊断,我们不仅识别了这些瓶颈,还为后续的优化提供了明确的方向。

常见问题

为什么系统负载很高,Nginx 的 RPS 却很低?

因为 worker 的事件循环被阻塞了。本案例中,单个 Nginx worker 每秒只能处理 227–286 个请求,而系统负载已逼近逻辑 CPU 核数。off-CPU 分析发现了两个叠加的原因:缺失 worker_cpu_affinity 指令导致的 CPU 争抢,以及单次长达 75 毫秒、令事件循环停摆的同步阻塞 IO。

什么会阻塞 Nginx 事件循环?

worker 内的任何同步操作。本案例中,阻塞来自用户 Lua 文件中执行 shell 命令的同步 Lua IO 调用,以及单次延时接近 1.5 毫秒的阻塞式文件读取。事件循环被阻塞期间,该 worker 上所有并发连接都在等待。

如何测量 Nginx 事件循环的阻塞延时?

OpenResty XRay 可以采样 epoll 循环的阻塞延时分布,并生成 off-CPU 火焰图——非侵入式,无需修改代码或重启进程。本案例在 20 秒采样窗口内捕获了 43952 个阻塞样本,最大单次 75 毫秒,并最终追踪到具体的 Lua 代码行。

使用 OpenResty XRay 告别 Nginx 性能噩梦

OpenResty XRay 是您解决复杂性能问题的终极利器。凭借其无与伦比的动态追踪能力,我们不仅能精准定位性能瓶颈,更能为企业带来深远的价值:

  • 突破性的诊断效率:告别传统的漫长排查过程,OpenResty XRay 将问题定位时间从数天缩短至数小时,让您的团队始终快人一步。
  • 极致的硬件资源优化:通过消除性能瓶颈,单机处理能力实现数倍提升,助您以更少的服务器资源承载更大的业务负载。
  • 无缝的业务连续性保障:主动识别并消除潜在的性能隐患,确保系统稳定运行,避免因过载导致的服务中断。
  • 全面的技术债务清理:系统性地揭示并解决历史遗留的性能问题,提升代码质量和系统架构的整体健康度。

在这个以毫秒计较胜负的数字经济时代,应用性能直接影响用户体验和商业成功。OpenResty XRay 以其先进的动态追踪技术,彻底颠覆传统的性能优化方式,为您的技术决策提供坚实的科学依据。

如果您的应用正面临性能挑战,OpenResty XRay 将为您提供无与伦比的精准洞察力,让性能成为推动业务增长的强大引擎。

关于 OpenResty XRay

OpenResty XRay 是一款动态追踪产品,它可以自动分析运行中的应用,以解决性能问题、行为问题和安全漏洞,并提供可行的建议。在底层实现上,OpenResty XRay 由我们的 Y 语言驱动,可以在不同环境下支持多种不同的运行时,如 Stap+、eBPF+、GDB 和 ODB。

关于作者

章亦春是开源 OpenResty® 项目创始人兼 OpenResty Inc. 公司 CEO 和创始人。

章亦春(Github ID: agentzh),生于中国江苏,现定居美国湾区。他是中国早期开源技术和文化的倡导者和领军人物,曾供职于多家国际知名的高科技企业,如 Cloudflare、雅虎、阿里巴巴, 是 “边缘计算“、”动态追踪 “和 “机器编程 “的先驱,拥有超过 22 年的编程及 16 年的开源经验。作为拥有超过 4000 万全球域名用户的开源项目的领导者。他基于其 OpenResty® 开源项目打造的高科技企业 OpenResty Inc. 位于美国硅谷中心。其主打的两个产品 OpenResty XRay(利用动态追踪技术的非侵入式的故障剖析和排除工具)和 OpenResty Edge(最适合微服务和分布式流量的全能型网关软件),广受全球众多上市及大型企业青睐。在 OpenResty 以外,章亦春为多个开源项目贡献了累计超过百万行代码,其中包括,Linux 内核、Nginx、LuaJITGDBSystemTapLLVM、Perl 等,并编写过 60 多个开源软件库。

关注我们

如果您喜欢本文,欢迎关注我们 OpenResty Inc. 公司的博客网站 。也欢迎扫码关注我们的微信公众号:

我们的微信公众号

翻译

我们提供了英文版原文和中译版(本文)。我们也欢迎读者提供其他语言的翻译版本,只要是全文翻译不带省略,我们都将会考虑采用,非常感谢!