利用php-fpm的慢日志定位故障

wer2122121

今天上午，开发小哥向我反映一台开发机访问时速度非常慢，让我帮他找一下原因，然后我就开始了一个排错的过程，当时我的思路是这样的：判断网络是否有问题，判断开发机资源是否耗尽，判断各服务是否正常运行，判断代码问题。
    网络问题较为简单了，ping一下，traceroute一下，发现没有问题，网络很正常。排除了网络问题以后就要判断是否是服务器资源耗尽了，然后我ssh登陆到开发机上，使用top命令，看到的结果如下：

从这个结果来看，服务器资源还是很富裕的，问题不在这里。那接下来就要查找是不是各服务的问题了。

    访问速度慢，最大的可能是缓存的问题，memcached是否挂了，memcached的内存是否够用，于是，我先查看了一下memcached的运行状态，发现其运行十分正常，然后又重新启动并增加了memcached的内存，但是访问速度依然很慢，看来故障并不是在这里，接着排错。
    既然不是缓存的问题，那我又在想，会不会是php进程开启的少了呢？然后我查了一下php的进程池：
从结果我们也可以看出来，php的进程是很多的，基本排除了php进程问题，那现在我的排错就进入了一个瓶颈，这时就感到自己知识的馈乏性了，最后还是在大牛的提醒下，让我查一下php的慢日志。由于本屌是一个新手，经验与技术都有所欠缺，所以对慢日志并没有多大的映像，毕竟在自己学习的过程中是很少用到这个日志的。
    既然查找慢日志，那么我做的第一步是开启php-fpm的慢日志功能，在php-fpm.conf配置文件中找到如下两条配置：

1 2 3 4 5 6 7 8 9

; The timeout for serving a single request after which a PHP backtrace will be ; dumped to the 'slowlog' file. A value of '0s' means 'off'. ; Available units: s(econds)(default), m(inutes), h(ours), or d(ays) ; Default Value: 0 request_slowlog_timeout = 5 ; The log file for slow requests ; Default Value: not set ; Note: slowlog is mandatory if request_slowlog_timeout is set slowlog = /var/log/php-fpm/www-slow.log

其中，request_slowlog_timeout = 5 这条配置表示，将执行时间超过5秒的php进程记录进入慢日志，为什么要设置为5秒呢？这是因为我查看了我网页的请求时间，响应时间大概在13秒左右；

slowlog = /var/log/php-fpm/www-slow.log 这条配置指定慢日志的位置。

    开启慢日志后，使用命令tail -F /var/log/php-fpm/www-slow.log来实时动态的查看日志内容，同时再继续访问该服务器，然后发现，在慢日志的输出中，有多个函数的执行时间超过了5秒，看来问题就出在这里了。然后我找了开发人员，反映了这个执行较慢的脚本和函数，经过他们的查找，发现是代码中有一个配置没有更新导致的，修改代码后问题解决。

    从这个运维事件中，我又积累到了一些实际生产环境中的运维经验，这一点是我值得记录的地方，可能这篇文章在许多大牛的眼里就是渣渣，但解决这个问题的过程与经验对于我来说是真正的宝贵财富，我也相信，只要我一点一滴的记录、积累，我也会变成一只大牛的。