PHP5-FPM随机开始消耗大量CPU

Question

我遇到了一个非常奇怪的问题，我不确定如何进一步调试。我有一个NGINX + PHP5-FPM + APC Amazon Ubuntu实例，上面安装了一个网站，这是一个复杂的PHP框架。在尝试调试这个问题时，我将流程简化为:包含许多大类，创建主对象，启动会话，从memcached检索配置数组，从memcached检索XML文件，包含HTML模板，将输出发送到客户端。

然后我使用http_load工具将网站置于每秒20个请求的负载下：http_load -timeout 10 -rate 20 -fetches 10000 ./urls.txt

接下来发生的事情是相当奇怪的。top显示了一堆php5-fpm进程，每个进程占用几%的CPU，一切都很顺利，如下所示：

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
28440 www-data 20 0 67352 10m 5372 S 4.3 1.8 0:20.33 php5-fpm
28431 www-data 20 0 67608 10m 5304 S 3.3 1.8 0:16.77 php5-fpm
28444 www-data 20 0 67352 10m 5372 S 3.3 1.8 0:17.17 php5-fpm
28445 www-data 20 0 67352 10m 5372 S 3.0 1.8 0:16.83 php5-fpm
28422 www-data 20 0 67608 10m 5292 S 2.3 1.8 0:18.99 php5-fpm
28424 www-data 20 0 67352 10m 5368 S 2.0 1.8 0:16.59 php5-fpm
28438 www-data 20 0 67608 10m 5304 S 2.0 1.8 0:17.91 php5-fpm
28439 www-data 20 0 67608 10m 5304 S 2.0 1.8 0:23.34 php5-fpm
28423 www-data 20 0 67608 10m 5292 S 1.7 1.8 0:20.02 php5-fpm
28430 www-data 20 0 67608 10m 5300 S 1.7 1.8 0:15.77 php5-fpm
28433 www-data 20 0 67352 10m 5372 S 1.7 1.8 0:17.08 php5-fpm
28434 www-data 20 0 67608 10m 5292 S 1.7 1.8 0:18.56 php5-fpm
20648 memcache 20 0 51568 8192 708 S 1.3 1.3 2:51.06 memcached
28420 www-data 20 0 69876 13m 6300 S 1.3 2.3 0:20.89 php5-fpm
28421 www-data 20 0 67608 10m 5300 S 1.3 1.8 0:21.19 php5-fpm
28429 www-data 20 0 9524 2260 992 S 1.3 0.4 0:11.68 nginx
28435 www-data 20 0 67608 10m 5304 S 1.3 1.8 0:18.58 php5-fpm
28437 www-data 20 0 67352 10m 5372 S 1.3 1.8 0:17.87 php5-fpm
28441 www-data 20 0 67608 10m 5292 S 1.3 1.8 0:20.75 php5-fpm

然后，经过一段时间(可能在一秒到几分钟之间)，几个(通常是两个) php5-fpm进程突然消耗了所有CPU：

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
28436 www-data 20 0 67608 10m 5304 R 48.5 1.8 0:23.68 php5-fpm
28548 www-data 20 0 67608 10m 5276 R 45.2 1.7 0:07.62 php5-fpm
28434 www-data 20 0 67608 10m 5292 R 2.0 1.8 0:23.28 php5-fpm
28439 www-data 20 0 67608 10m 5304 R 2.0 1.8 0:26.63 php5-fpm

在这一点上，所有东西都被卡住了，所有新的HTTP请求都超时了。如果我停止http_load工具，php5-fpm会在那里挂起几分钟。有趣的是，如果我使用php5-fpm stop，php5-fpm进程将消失，但任何使用文件系统的命令都会在执行时出现问题。例如，如果我尝试通过ssh下载文件，top将显示以下内容，启动实际下载需要几分钟时间：

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
3298 sshd 20 0 7032 876 416 R 75.2 0.1 0:04.52 sshd
3297 sshd 20 0 7032 876 416 R 24.9 0.1 0:04.49 sshd

PHP错误日志通常包含以下内容：

[05-Dec-2012 20:31:39] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 8 children, there are 0 idle, and 58 total children
[05-Dec-2012 20:32:08] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 16 children, there are 0 idle, and 66 total children

Nginx错误日志中充斥着以下条目：

2012/12/05 20:31:36 [error] 4800#0: *5559 connect() to unix:/dev/shm/php-fpm-www.sock failed (11: Resource temporarily unavailable) while connecting to upstream, client: ..., server: ec2-....compute-1.amazonaws.com, request: "GET /usa/index.php?page=contact_us HTTP/1.0", upstream: "fastcgi://unix:/dev/shm/php-fpm-www.sock:", host: "ec2-....compute-1.amazonaws.com"

PHP-FPM慢日志没有显示任何有趣的东西，交换从来没有发生过，我也没有设法收集到关于这个问题的任何其他有趣的事实。我已经经历了配置文件更改的多次迭代，最近的一次是

nginx.conf：http://pastebin.com/uaD56hJF

/www.conf：http://pastebin.com/mFeeUULC

===UPDATE 1===

站点配置：http://pastebin.com/qvinVNhB

===UPDATE 2===

我还发现dmesg报告的错误如下所示

[6483131.164331] php5-fpm[28687]: segfault at b6ec8ff4 ip b78c3c32 sp bff551f0 error 4 in ld-2.13.so[b78b5000+1c000]

===UPDATE 3===

我们有一个新的亚马逊EC2微型实例以防万一，以排除可能的硬件问题。另外，我现在使用php-fastcgi来排除可能的fpm bug。其他的区别都很小，我认为唯一的变化是Ubuntu->Debian。同样的问题仍然发生，除了现在服务器设法在max_execution_time秒后略微恢复(然后再次达到峰值)。

我尝试使用单独的test.php，我不确定是否存在相同的问题，但至少在top中它看起来是一样的。我创建了一个test.php，并包含了一堆属于我们框架的库。除了定义类或包括定义类的其他库之外，库不做任何事情。我与APC进行了核对，所有这些都得到了它的成功服务。我开始以每秒200个请求的速度向test.php施压，一段时间后，同样的事情发生了。除了现在我设法得到一些错误，说“打开的文件太多”。但这并不总是发生，有时它只是开始超时而没有输出错误，一些php进程被卡住了，占用了所有的CPU。我只玩了一点，但我认为这里有一个相关性-通过控制包含的库的数量或稍微改变请求/秒速率，我可以控制CPU峰值何时会发生。我增加了相关的操作系统变量，但问题仍然存在，尽管它需要更长的时间才能发生(还请注意，我已经将值设置为比我在测试期间执行的请求总数大N倍)。

fs.file-max = 70000
...
*       soft    nofile   10000
*       hard    nofile  30000
...
worker_rlimit_nofile 10000;
...
(reloaded all the configs and made sure the new system vars actually took affect)

因此，到目前为止，我能想到的下一个最好的也是唯一的解释是，尽管APC应该从内存中拉出文件，但在内部实现它的方式仍然是在调用PHP include-s时使用文件描述符。要么是因为它延迟释放它们，要么是因为在某个不幸的时刻，太多的请求同时到达，系统运行我们的描述符，新到达的HTTP请求很快堆叠到一个巨大的队列中。我将尝试以某种方式测试这一点。

Answer 1

我已经用类似的配置运行了一个网站好几个月了，没有停机时间。我看过你的配置，看起来没问题。话虽如此，我很久以前就做了我的配置。

我会考虑把pm.max_requests = 10000减少到像pm.max_requests = 500这样更合理的东西。这只意味着“每个实例的请求次数不要超过X次”。这个数字不要太高是很好的，因为这样做可以让您在可能的PHP引擎错误方面具有弹性。

我认为真正的问题很可能出在你的PHP脚本中。在不了解更多信息的情况下，很难说。

编辑:考虑取消注释;request_terminate_timeout = 0并将其设置为类似于request_terminate_timeout = 20的内容。然后，您的脚本将需要在20秒内完成。你很可能会看到行为上的改变，但我认为你的网站可能会继续存在。这将指示PHP脚本错误。

EDIT2:我自己的php-fpm配置如下：

[example.com]
listen = /var/run/sockets/example.com.socket
user = www-data
group = www-data
pm = dynamic
pm.start_servers = 5
pm.max_children = 15
pm.min_spare_servers = 5
pm.max_spare_servers = 10
pm.max_requests = 500
php_flag[expose_php] = off
php_flag[short_open_tag] = on

EDIT3:我在你的nginx配置中发现了一些意想不到的东西，但可能没什么。

您使用的是fastcgi_ignore_client_abort on;，它会在旧版本的nginx下导致工作进程出现问题。以下是nginx网站上对该问题的描述：

当fastcgi_ignore_client_abort设置为on时，1.0.2 POST请求中的

未正确处理，这可能导致工作进程分段错误。将fastcgi_ignore_client_abort切换回默认值(关闭)应该可以解决此问题。

Answer 2

简单的技巧，但非常有用的减少处理器使用率高达50%，只需编辑您的php-fpm配置：

pm = dynamic

并将其更改为：

pm = ondemand

Answer 3

PHP-FPM在我的服务器上的行为与您相同。瓶颈肯定在某个地方。

问题是:如何在Nginx - PHP-FPM - Mysql上找到瓶颈？最快的方法是:为PHP-FPM启用Slowlog。

将以下代码行添加到php-fpm.conf池中，并确保路径存在

request_slowlog_timeout = 10
slowlog = /var/log/php-fpm/slow.$pool.log

通过阅读日志回溯，您可以找到PHP-FPM花费这么多CPU或超时的原因。以下是我的案例：

[28-Dec-2018 14:56:55]  [pool laravel] pid 19061
script_filename = /public_html/index.php
[0x00007efdda4d8100] hasChildren() /public_html/laravel/vendor/symfony/finder/Iterator/ExcludeDirectoryFilterIterator.php:75
[0x00007ffe31cd9e40] hasChildren() unknown:0
[0x00007ffe31cda200] next() unknown:0
[0x00007ffe31cda540] next() unknown:0
[0x00007ffe31cda880] next() unknown:0
[0x00007efdda4d7fa8] gc() /public_html/laravel/vendor/laravel/framework/src/Illuminate/Session/FileSessionHandler.php:91
[0x00007efdda4d7e50] gc() /public_html/laravel/vendor/laravel/framework/src/Illuminate/Session/Middleware.php:159
[0x00007efdda4d7d48] collectGarbage() /public_html/laravel/vendor/laravel/framework/src/Illuminate/Session/Middleware.php:128
[0x00007efdda4d7c20] closeSession() /public_html/laravel/vendor/laravel/framework/src/Illuminate/Session/Middleware.php:79
[0x00007efdda4d7ac8] handle() /public_html/laravel/vendor/laravel/framework/src/Illuminate/Cookie/Queue.php:47
[0x00007efdda4d7930] handle() /public_html/laravel/vendor/laravel/framework/src/Illuminate/Cookie/Guard.php:51
[0x00007efdda4d7818] handle() /public_html/laravel/vendor/stack/builder/src/Stack/StackedHttpKernel.php:23
[0x00007efdda4d76e0] handle() /public_html/laravel/vendor/laravel/framework/src/Illuminate/Foundation/Application.php:641
[0x00007efdda4d7598] run() 
/public_html/index.php:51

回溯提到了这些关键字：

"cookie" "session" "collectGarbage()" "laravel"

我一直在搜索，TADA，Laravel使用随机方法来清除过期的会话。在我的配置中，PHP使用SSD来处理会话。

当会话数变得“非常大”时，这使得PHP花了更多的时间来处理=>的高CPU使用率。

我们可以有许多种瓶颈，当我们“调试”它的时候，我们才能知道它。

祝你调查顺利。