php-fpm的一次慢执行日志slow log

测试环境、预发布环境经过QA多番测试没有遇到问题,但在一次上线过程中,在线上环境出现20秒的响应超时,这个毫无疑问,环境问题。

尽管线上数据量大,可Mysql以不至于慢到20秒,而且发现每次技术都是20.01~20.04秒之间,相差不到一秒钟,mysql也不至于这么均匀,在好奇心下,运维大神配合查了一下Mysql慢查询日志,发现没有超时的sql日志,那这有可能就是php这边出现的问题,可一想,逻辑执行也总不能这么慢。想打日志一步步跟踪,这种方式有点慢。mysql 有慢查询,同样咱php也有慢日志。

使用php slow方式确实找到了问题所在,截图如下:

php-fpm的一次慢执行日志slow log

 pconnect()原因导致,这个我当然清楚,是因为连接redis失败导致。 因为是在新的服务器,所以连接不上核心项目的redis服务器,最终还是运维大神安装的证书解决。

解决了问题后,大概了解如下:

一、开启slow log方法:
如果你使用php-fpm来管理php的话,你可以通过如下方法开启:

首先打开 php-fpm.conf 配置文件。

vim /usr/local/php/etc/php-fpm.conf

PHP 5.3.3 之前设置如下:

<value name="request_slowlog_timeout">5s</value>
< value name="slowlog">logs/php-fpm-slowlog.log</value>

PHP 5.3.3 之后设置以下如下:

request_slowlog_timeout = 5s
slowlog = /usr/local/php/var/log/php-fpm-slowlog.log
request_terminate_timeout = 10s

说明:
request_slowlog_timeout 是脚本超过多长时间,就可以记录到日志文件;
slowlog 是日志文件的存储路径;
request_terminate_timeout 将执行时间太长的进程直接终止;

二、slow log如何使用?
开启后,如果有脚本执行超过指定的时间,就会在指定的日志文件中写入类似如上图所示,执行格式:pid  进程号

日志说明:

script_filename 是入口文件
curl_exec() : 说明是执行这个方法的时候超过执行时间的。
exfilter_curl_get() :说明调用curl_exec()的方法是exfilter_curl_get() 。

每行冒号后面的数字是行号。

开启后,在错误日志文件中也有相关记录...去日志查看就可以了

相关推荐