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

Posted 2021-03-17 路漫漫其修远兮

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

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

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

 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() 。

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

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