出现负载低但是访问很慢排查思路

最近遇到一个很奇怪的问题,出现了几次论坛负载低但是访问很慢的问题,登录服务器查看服务器情况,top看不到任何php-cgi进程,正常情况下会看到很多php-cgi进程,重起php-cgi之后问题解决。原因有二,其一是php-cgi进程挂掉了,其二是nginx没有把php请求转发给php-cgi处理,我认为后者可能性大点。下次再出现是这样排查一下:

  1. 查看php-cgi进程是否还挂掉

    cpu大小排序进程

    top -b -n 1 |sort -nk 9 
    

    按mem大小排序进程

    top -b -n 1 |sort -nk 10 
    
  2. 查看nginx进程情况

    top -p `ps h -o pid -C nginx| sed -e ':a;N;$ s/\n/,/g;ba'`
    
  3. 查看连接数

    netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'
    
    
    TIME_WAIT 5013
    
    
    FIN_WAIT1 32
    
    
    FIN_WAIT2 104
    
    
    ESTABLISHED 1625
    
    
    SYN_RECV 28
    
    
    LAST_ACK 1
    
  4. 上传一个测试文件看看,访问是否慢(deven2012年3月31号测试,访问test.php很慢,但是访问test.html很快,证明是php-cgi有问题了。)

  5. 检查memcache是否正常,重起memcache试试(经测试memcache正常)。

  6. 搜索php.log日志查找“started”关键字 ,看php-cgi什么时候重起了。

经过一段时间的观察,最终找到问题:

mysql出现锁表,然后导致所有php请求都不能得到响应。

devne感觉我们的情况与以下情况有点不一样: 一台服务器上运行着nginx php(fpm) cache,访问量日均 300W pv左右

最近经常会出现这样的情况: php页面打开很慢,cpu使用率突然降至很低,系统负载突然升至很高,查看网卡的流量,也会发现突然降到了很低。这种情况只持续数秒钟就恢复了 检查php-fpm的日志文件发现了一些线索

Sep 30 08:32:23.289973 [NOTICE] fpm_unix_init_main(), line 271: 
getrlimit(nofile): max:51200, cur:51200
Sep 30 08:32:23.290212 [NOTICE] fpm_sockets_init_main(), line 371: 
using inherited socket fd=10, “127.0.0.1:9000″
Sep 30 08:32:23.290342 [NOTICE] fpm_event_init_main(), line 109: 
libevent: using epoll
Sep 30 08:32:23.296426 [NOTICE] fpm_init(), line 47: fpm is running, pid 30587

在这几句的前面,是1000多行的关闭children和开启children的日志 原来,php-fpm有一个参数 max_requests ,该参数指明了,每个children最多处理多少个请求后便会被关闭,默认的设置是500。因为php是把请求轮询给每个children,在大流量下,每个childre到达max_requests所用的时间都差不多,这样就造成所有的children基本上在同一时间被关闭。

在这期间,nginx无法将php文件转交给php-fpm处理,所以cpu会降至很低(不用处理php,更不用执行sql),而负载会升至很高(关闭和开启childrennginx等待php-fpm),网卡流量也降至很低(nginx无法生成数据传输给客户端)

解决问题很简单,增加children的数量,并且将 max_requests 设置未 0 或者一个比较大的值,重启php-fpm

2018