PHP服务故障排查之路

           起因，使用人员反馈出现转圈(查询慢)和登录出现504错误。第一个判断就是PHP进程被占满了，服务处于繁忙状态，Nginx的请求PHP未能及时回应，用了最简单粗暴的方式，重启php-fpm服务。

       重启服务后正常，并调整pm.max_children参数，过了一个星期后又出现，一样的现象。再次出现后，根据网上的资料，优化Nginx和php-fpm参数，详细如下：

php-fpm.conf

pm.max_children = 60 修改为pm.max_children = 70

;request_terminate_timeout = 0 修改为request_terminate_timeout = 300

nginx.conf

worker_processes  4;    修改为worker_processes  16;

增加：

worker_rlimit_nofile 200000;

use epoll;

        fastcgi_connect_timeout 300;

        fastcgi_read_timeout 300;

        fastcgi_send_timeout 300;

        fastcgi_buffer_size 128k;

      fastcgi_buffers   4 64k;

        fastcgi_busy_buffers_size 128k;

        fastcgi_temp_file_write_size 128k; 

      做了一次调优，相信应该有所改善。不出意外，第二天问题再次出现。

因出现问题的服务器，运行着多个业务项目，这给排查原因增加了很多难度。

首先，可以判断的是此服务器php服务在那个时间段已经满负载再跑。因无法断定是哪个项目出现问题，只能

一个一个项目排除。第一，查询Nginx日志，看到的情况是一秒内同个接口有多次调用，按我们的业务量，那个项目

不可能出现此情况，但这个并不是此次出现的原因。第二，查询php-fpm日志(/usr/local/php/var/log/php-fpm.log)，

终于在此日志中，找到蛛丝马迹：

[24-Sep-2017 10:05:24] WARNING: [pool www] child 23085, script '/usr/local/nginx/html/project/index.php' (request: "POST /index.php") execution timed out (372.841606 sec), terminating
[24-Sep-2017 10:05:24] WARNING: [pool www] child 23084, script '/usr/local/nginx/html/project/index.php' (request: "POST /index.php") execution timed out (348.815395 sec), terminating
[24-Sep-2017 10:05:24] WARNING: [pool www] child 23083, script '/usr/local/nginx/html/project/index.php' (request: "POST /index.php") execution timed out (372.849417 sec), terminating
[24-Sep-2017 10:05:24] WARNING: [pool www] child 23081, script '/usr/local/nginx/html/project/index.php' (request: "POST /index.php") execution timed out (336.801517 sec), terminating
[24-Sep-2017 10:05:24] WARNING: [pool www] child 23080, script '/usr/local/nginx/html/project/index.php' (request: "POST /index.php") execution timed out (390.862969 sec), terminating
[24-Sep-2017 10:05:24] WARNING: [pool www] child 23077, script '/usr/local/nginx/html/project/index.php' (request: "POST /index.php") execution timed out (390.859550 sec), terminating
[24-Sep-2017 10:05:24] WARNING: [pool www] child 23076, script '/usr/local/nginx/html/project/index.php' (request: "POST /index.php") execution timed out (384.855514 sec), terminating
[24-Sep-2017 10:05:24] WARNING: [pool www] child 23075, script '/usr/local/nginx/html/project/index.php' (request: "POST /index.php") execution timed out (360.829416 sec), terminating
[24-Sep-2017 10:05:24] WARNING: [pool www] child 23074, script '/usr/local/nginx/html/project/index.php' (request: "POST /index.php") execution timed out (372.788659 sec), terminating

……

……

      共一秒钟，这个项目同一秒钟69个子进程超时(此日志的打印得益于参数优化的调整)。查询此项目出现问题的时间点都有一个共同的操作：几十万的消息推送。初步可以断定，问题的原因是出现在这里。处理方案，暂时关闭此功能，增加对php-fpm的监控，来进一步确认(另外就是把此项目移到另外的服务器再继续观察)。

php-fpm的监控处理步骤如下：

1、查看php-fpm配置文件，开启。

cat /usr/local/php/etc/php-fpm.conf | grep status

pm.status_path = /php-fpm_status

2、Nginx配置文件增加

server {

  listen 80;

        server_name 127.0.0.1;

        location /php-fpm_status {

    fastcgi_pass 127.0.0.1:9000;

    include fastcgi_params;

    fastcgi_param SCRIPT_FILENAME $fastcgi_script_name;

  }

3、查看

curl 127.0.0.1/php-fpm_status

4、php-fpm status参数说明

pool:                 www    (池子名称)

process manager:      static (进程管理方式,值：static, dynamic)

start time:           26/Sep/2017:00:36:08 +0800 (启动日期,如果reload了php-fpm，时间会更新)

start since:          47933    (运行时长)

accepted conn:        120873    (当前池子接受的请求数)

listen queue:         0        (请求等待队列，如果这个值不为0，那么要增加FPM的进程数量)

max listen queue:     1        ( 请求等待队列最高的数量)

listen queue len:     128      (socket等待队列长度)

idle processes:       65        (空闲进程数量)

active processes:     5        (活跃进程数量)

total processes:      70        (总进程数量)

max active processes: 26        (最大的活跃进程数量（FPM启动开始算）)

max children reached: 0            (大道进程最大数量限制的次数，如果这个数量不为0，那说明你的最大进程数量太小了，请改大一点。)

slow requests:        0            ( 启用了php-fpm slow-log，缓慢请求的数量)

(大道进程，这个专业术语不是很明白，如果有知道，还请赐教)

      做一下总结:对于问题的排查， 一定要善用排除法。当然必要的参数优化，可能对我们排查问题有很大的帮助(像我此次，如果没有看到超时日志，可能还需要更长的时间查找问题)。

      仅以此文记录一下，每次在睡梦中被电话吵醒的历程。