问题:
偶尔会有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 再次发生,并记得记录时间点,方便查找日志。
时间点: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秒。
再继续观察观察。