nginx+php 502 问题排查【未完待续】

阅读数: 1086 2018年11月28日

问题:

偶尔会有502报错,之前不太重视,现在必须找出原因。


第一步:开启日志

只能靠日志,检查并开启相关日志:

1、nginx 这个站点的访问日志(access_log)、错误日志(error_log);

server
    {
		....
		
        location ~ /\.
        {
            deny all;
        }

        access_log  /mnt/log/nginx/.../pingce_access.log;
        error_log /mnt/log/nginx/..../pingce_error.log warn; #错误级别,定在 warn,搜集更多信息
    }

2、开启 php-fpm 错误日志 (error_log) 和慢日志 (slowlog);

[global]
...
error_log = /usr/local/php/var/log/php-fpm.log
log_level = notice

[www]
...
slowlog = var/log/php-fpm-slow.log


然后就是等待 502 再次发生,并记得记录时间点,方便查找日志。
image.png

时间点:2018-11-27 18:15


第二步:查询日志

1、先查询 nginx 错误日志:

# grep -E '2018/11/27 18:15.+?' pingce_error_20181127.log
2018/11/27 18:15:24 [error] 29265#0: *164435 recv() failed (104: Connection reset by peer) while reading response header from upstream, client: xxx.xxx.xxx.xxx, server: www.xxx.net, request: "POST /****/updateExpressNo HTTP/1.1", upstream: "fastcgi://unix:/tmp/php-cgi.sock:", host: "***"

查阅资料得知是 nginx 与 php 进程失去联系了,php 进程超时导致 php-fpm 被杀。

2、检查PHP-FPM错误日志:

# grep -E '27-Nov.+?18:' php-fpm.log
[27-Nov-2018 18:15:23] NOTICE: Reloading in progress ...
[27-Nov-2018 18:15:24] NOTICE: reloading: execvp("/usr/local/php/sbin/php-fpm", {"/usr/local/php/sbin/php-fpm", "--daemonize", "--fpm-config", "/usr/local/php/etc/php-fpm.conf", "--pid", "/usr/local/php/var/run/php-fpm.pid"})
[27-Nov-2018 18:15:24] NOTICE: using inherited socket fd=8, "/tmp/php-cgi.sock"
[27-Nov-2018 18:15:24] NOTICE: using inherited socket fd=8, "/tmp/php-cgi.sock"
[27-Nov-2018 18:15:24] NOTICE: fpm is running, pid 4989
[27-Nov-2018 18:15:24] NOTICE: ready to handle connections

线索貌似很吻合。

搜索资料得知,参数修改 php-fpm 的 request_terminate_timeout 


php-fpm.conf 中的 request_terminate_timeout 控制单个请求的超时中止时间,可用单位:s(秒),m(分),h(小时)或者 d(天)。默认单位:s(秒)。默认值:0(关闭)。

php.ini 中的 max_execution_time 限定了脚本的最大执行时间(单位是秒),


当前已经设置:

php-fpm.conf 

request_terminate_timeout = 0,表示不限制。显然没起作用,php-fpm 子进程还是被杀掉了。

php.ini

max_execution_time = 300


根据资料结论:

在配置超时时间的时候,最好两个都配置,max_execution_time时间短一点,而request_terminate_timeout时间长一点

新配置:

php-fpm.conf 

request_terminate_timeout = 60s

php.ini

max_execution_time = 30


再观察观察

2019-3-27

果然又发生 502 了,查看网站日志才看到

2019/03/27 16:52:13 [error] 8951#0: *9120135 recv() failed (104: Connection reset by peer) while reading response header from upstream, client: xx.xx.xx.xx, server: www.xxxx.com, request: "POST /api/....
2019/03/27 16:52:13 [error] 8951#0: *9120134 recv() failed (104: Connection reset by peer) while reading response header from upstream, client: xx.xx.xx.xx, server: www.xxxx.com, request: "POST /api/....

又报 Connection reset by peer 错误。这个时间点的 服务器带宽、CPU、内存一切正常,但是硬盘IO也比较高。
找了半天,感觉这篇文章分析的比较符合我的情况,暂且采纳:https://blog.csdn.net/xc_zhou/article/details/80950753
猜测性诊断:对方访问我们服务器接口太频繁了,且对方超时时间太短。等我方服务器开始处理的时候,对方关闭连接了。
尝试解决方案:让对方调用接口超时时间设置到30秒。
再继续观察观察。

参考资料
参考资料:
http://blog.51cto.com/nanchunle/1657410
https://blog.csdn.net/loophome/article/details/78604986
https://blog.csdn.net/lipengfeihb/article/details/55212567
https://blog.csdn.net/xc_zhou/article/details/80950753
phpriji.cn | 网站地图 | | 沪ICP备17015433号-1