NGINX + PHP-FPM 报 502 错误,我想大部分 SA 都遇到过吧。
根据报错的频率,可以分为两种情况,间歇性的502和连续性的502。
这里只讨论第一种情况——间歇性的502。
502,是后端 PHP-FPM 不可用造成的,间歇性的502一般认为是由于 PHP-FPM 进程重启造成的。
在 PHP-FPM 的配置中存在这么一项:
How much requests each process should execute before
respawn.
Useful to work around memory leaks in 3rd party libraries.
For endless request processing please specify 0
Equivalent to PHP_FCGI_MAX_REQUESTS
<value name=”max_requests”>500</value>
这段配置的意思是,当一个 PHP-CGI 进程处理的请求数累积到 500 个后,自动重启该进程。
但是为什么要重启进程呢?
一般在项目中,我们多多少少都会用到一些 PHP 的第三方库,这些第三方库经常存在内存泄漏问题,如果不定期重启 PHP-CGI 进程,势必造成内存使用量不断增长。因此 PHP-FPM 作为 PHP-CGI 的管理器,提供了这么一项监控功能,对请求达到指定次数的 PHP-CGI 进程进行重启,保证内存使用量不增长。
正是因为这个机制,在高并发的站点中,经常导致 502 错误,我猜测原因是 PHP-FPM 对从 NGINX 过来的请求队列没处理好。不过我目前用的还是 PHP 5.3.2,不知道在 PHP 5.3.3 中是否还存在这个问题。
目前我们的解决方法是,把这个值尽量设置大些,尽可能减少 PHP-CGI 重新 SPAWN 的次数,同时也能提高总体性能。在我们自己实际的生产环境中发现,内存泄漏并不明显,因此我们将这个值设置得非常大(204800)。大家要根据自己的实际情况设置这个值,不能盲目地加大。
根据错误提示(11: Resource temporarily unavailable) ,排除掉服务器配置的问题,自然而然就怀疑是资源被程序占用光了。
这些资源包括数据库连接、文件数、锁等等,如果一个个去猜解调试甚至是走读代码,未免太费时间,也未必能发现问题所在。
好在 PHP-FPM 提供了慢执行日志,可以将执行比较慢的脚本的调用过程 dump 到日志中。
配置比较简单,PHP 5.3.3 之前设置如下:
The timeout (in seconds) for serving of single request after which a php backtrace will be dumped to slow.log file '0s' means 'off' <value name="request_slowlog_timeout">1s</value> The log file for slow requests <value name="slowlog">logs/slow.logs</value>
PHP 5.3.3 之后设置以下如下:
; The timeout for serving a single request after which a PHP backtrace will be ; dumped to the 'slowlog' file. A value of '0s' means 'off'. ; Available units: s(econds)(default), m(inutes), h(ours), or d(ays) ; Default Value: 0 request_slowlog_timeout = 1s ; The log file for slow requests ; Default Value: /usr/local/php/log/php-fpm.log.slow slowlog = /usr/local/php/log/php-fpm.log.slow
还可以将执行时间太长的进程直接终止,设置下执行超时时间即可。
PHP 5.3.3 之前版本:
The timeout (in seconds) for serving a single request after which the worker process will be terminated Should be used when 'max_execution_time' ini option does not stop script execution for some reason '0s' means 'off' <value name="request_terminate_timeout">10s</value>
PHP 5.3.3+:
; The timeout for serving a single request after which the worker process will ; be killed. This option should be used when the 'max_execution_time' ini option ; does not stop script execution for some reason. A value of '0' means 'off'. ; Available units: s(econds)(default), m(inutes), h(ours), or d(ays) ; Default Value: 0 request_terminate_timeout = 10s
加上慢执行日志后,我们可以很容易从慢执行日志中看出问题所在,比如:
Feb 07 19:00:30.378095 pid 27012 (pool default) script_filename = /www/adshow/a.php [0x000000000115ea08] flock() /www/backend/parser/logs.class.php:260 [0x0000000001159810] lock_stats() /www/adshow/a.php:126 Feb 07 19:00:31.033073 pid 27043 (pool default) script_filename = /www/adshow/a.php [0x00000000012686e8] flock() /www/backend/parser/logs.class.php:260 [0x00000000012634f0] lock_stats() /www/adshow/a.php:126 Feb 07 19:00:31.163995 pid 26979 (pool default) script_filename = /www/adshow/a.php [0x000000000115bda8] flock() /www/backend/parser/logs.class.php:260 [0x0000000001156bb0] lock_stats() /www/adshow/a.php:126 Feb 07 19:00:31.164102 pid 27033 (pool default) script_filename = /www/adshow/a.php [0x00000000013f3fa8] flock() /www/backend/parser/logs.class.php:260 [0x00000000013eedb0] lock_stats() /www/adshow/a.php:126 Feb 07 19:00:31.297313 pid 27448 (pool default) script_filename = /www/adshow/a.php [0x0000000001180218] flock() /www/backend/parser/logs.class.php:260 [0x000000000117b020] lock_stats() /www/adshow/a.php:126
很明显是程序中产生了死锁,导致各个 PHP-CGI 进程互相等待资源而锁死。
据此,再进行进一步的程序分析,就更具方向性了。