☰

什么原因导致我的 php-fpm 子进程挂起？

tag-icon • tag-icon apache-2.4 php-fpm
什么原因导致我的 php-fpm 子进程挂起？

我管理的 Web 服务器上的一个低流量网站会定期出现 503 错误，直到 php-fpm 重新启动。

设置如下：

  • DigitalOcean droplet
  • CentOS 7.6
  • Apache 2.4（事件）
  • PHP 5.6.40 (FPM) (单池) (OPcache 7.0.6)
  • 玛拉雅数据库

Apache error_log 显示：

[proxy_fcgi:error] [pid 28424:tid 139973646870272] (70007)The timeout specified has expired: [client 10.16.0.2:47744] AH01075: Error dispatching request to :

每个strace -pphp-fpm 子进程上仅显示：

recvfrom(4,

在strace线程进入此状态之前，我观察到：

shutdown(4, SHUT_WR)                    = 0
recvfrom(4, "\1\5\0\1\0\0\0\0", 8, 0, NULL, NULL) = 8
recvfrom(4,

显示lsof | grep php-fpm | grep WAIT：

php-fpm   29271         php-fpm    4u     IPv4            5258526       0t0        TCP mydomain.com:cslistener->mydomain.com:32790 (FIN_WAIT2)
php-fpm   29272         php-fpm    4u     IPv4            5258554       0t0        TCP mydomain.com:cslistener->mydomain.com:32794 (FIN_WAIT2)
php-fpm   29273         php-fpm    4u     IPv4            5273165       0t0        TCP mydomain.com:cslistener->mydomain.com:36460 (FIN_WAIT2)
php-fpm   29274         php-fpm    4u     IPv4            5258499       0t0        TCP mydomain.com:cslistener->mydomain.com:32786 (FIN_WAIT2)
php-fpm   29303         php-fpm    4u     IPv4            5294998       0t0        TCP mydomain.com:cslistener->mydomain.com:42170 (FIN_WAIT2)
php-fpm   29850         php-fpm    4u     IPv4            5309183       0t0        TCP mydomain.com:cslistener->mydomain.com:44630 (FIN_WAIT2)
php-fpm   29851         php-fpm    4u     IPv4            5279040       0t0        TCP mydomain.com:cslistener->mydomain.com:37966 (FIN_WAIT2)
php-fpm   29857         php-fpm    4u     IPv4            5295075       0t0        TCP mydomain.com:cslistener->mydomain.com:42198 (FIN_WAIT2)
php-fpm   30472         php-fpm    4u     IPv4            5295345       0t0        TCP mydomain.com:cslistener->mydomain.com:42216 (FIN_WAIT2)
php-fpm   32086         php-fpm    4u     IPv4            5295802       0t0        TCP mydomain.com:cslistener->mydomain.com:42334 (FIN_WAIT2)

如果我终止其中一个子进程，就会生成一个新的进程并且网站将继续运行，直到该进程也最终处于相同状态。

重新启动 php-fpm 总是可以解决问题。重新启动 Apache 或 MariaDB 没有任何区别。

strace -p主要的 php-fpm 进程之一持续显示此信息：

socket(AF_LOCAL, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 9
sendmsg(9, {msg_name(21)={sa_family=AF_LOCAL, sun_path="/run/systemd/notify"}, msg_iov(1)=[{"READY=1\nSTATUS=Processes active:"..., 87}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 87
close(9)                                = 0
epoll_wait(8, [], 1, 656)               = 0
getsockopt(7, SOL_TCP, TCP_INFO, "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\201\0\0\0\200\0\0\0"..., [104]) = 0
epoll_wait(8, [], 1, 1000)              = 0
getsockopt(7, SOL_TCP, TCP_INFO, "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\201\0\0\0\200\0\0\0"..., [104]) = 0
epoll_wait(8, [], 1, 1000)              = 0
getsockopt(7, SOL_TCP, TCP_INFO, "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\201\0\0\0\200\0\0\0"..., [104]) = 0
epoll_wait(8, [], 1, 1000)              = 0
getsockopt(7, SOL_TCP, TCP_INFO, "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\201\0\0\0\200\0\0\0"..., [104]) = 0
epoll_wait(8, [], 1, 1000)              = 0
getsockopt(7, SOL_TCP, TCP_INFO, "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\201\0\0\0\200\0\0\0"..., [104]) = 0
epoll_wait(8, [], 1, 1000)              = 0
getsockopt(7, SOL_TCP, TCP_INFO, "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\201\0\0\0\200\0\0\0"..., [104]) = 0
epoll_wait(8, [], 1, 1000)              = 0
getsockopt(7, SOL_TCP, TCP_INFO, "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\201\0\0\0\200\0\0\0"..., [104]) = 0
epoll_wait(8, [], 1, 1000)              = 0
getsockopt(7, SOL_TCP, TCP_INFO, "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\201\0\0\0\200\0\0\0"..., [104]) = 0
epoll_wait(8, [], 1, 1000)              = 0
getsockopt(7, SOL_TCP, TCP_INFO, "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\201\0\0\0\200\0\0\0"..., [104]) = 0
epoll_wait(8, [], 1, 1000)              = 0
getsockopt(7, SOL_TCP, TCP_INFO, "\n\0\0\0\0\0\0\0@B\17\0\0\0\0\0\30\2\0\0\0\0\0\0\201\0\0\0\200\0\0\0"..., [104]) = 0

Apache 的 PHP 处理配置：

<FilesMatch "\.php$">
    <If "-f %{REQUEST_FILENAME}">
        SetHandler "proxy:fcgi://localhost:9000"
    </If>
</FilesMatch>

php-fpm池配置如下：

[www]
user = php-fpm
group = php-fpm
listen = 127.0.0.1:9000
listen.allowed_clients = 127.0.0.1
pm = dynamic
pm.max_children = 10
pm.start_servers = 4
pm.min_spare_servers = 4
pm.max_spare_servers = 6
pm.process_idle_timeout = 10s
pm.max_requests = 500
slowlog = /var/log/php-fpm/www-slow.log
request_slowlog_timeout = 10
catch_workers_output = yes
php_admin_value[error_log] = /var/log/php-fpm/www-error.log
php_admin_flag[log_errors] = on
php_value[session.save_handler] = files
php_value[session.save_path]    = /var/lib/php-fpm/session
php_value[soap.wsdl_cache_dir]  = /var/lib/php-fpm/wsdlcache

慢日志是空的；每个工作者唯一的输出是：

WARNING: [pool www] child 2840 said into stderr: "ERROR: Unable to set php_value 'soap.wsdl_cache_dir'"

我猜测这只是一个警告，因为 SOAP 扩展尚未安装。

编辑：

  • 设置为静态模式并删除最大请求行没有区别。

  • 根据 PHP-FPM 状态页面，“卡住”的线程处于“完成”状态。此时它们消耗 0% 的 CPU。

  • 我认为受影响最严重/最主要的 PHP 脚本负责提供缓存图片；最大大小 < 1MB

  • 禁用 OPCache 没有什么区别。

  • 这可能是最重要的线索；仅当 YandexBot 命中导致问题的脚本请求时，其响应时间为 60 秒，而在此之后线程就会进入挂起状态（响应时间（秒）附加到日志行）：

[28/Apr/2019:08:44:46 +0100] "GET /imgsizr?i=123.jpg&t=large HTTP/1.1" 200 192167 "-" "Mozilla/5.0 (compatible; YandexBot/3.0; +http://yandex.com/bots)" 60

编辑 2：更改为 UDS（Unix 域套接字）可以解决问题，因为完成状态仍然会发生，但最终会转换为空闲状态。

相关内容