Linux下PHP-FPM慢日志如何分析

Linux下PHP-FPM慢日志分析实操指南

来，咱们直接进入正题。PHP-FPM慢日志这个东西，属于那种“平时想不起来，线上出问题才后悔没早点配置”的工具。很多人在排查性能问题时，第一反应是去看数据库慢查询，或者怀疑带宽，但往往问题就出在PHP进程本身——某个函数调用卡住了，或者某个外部请求迟迟没有响应。这时候，慢日志就能帮你精准定位到是哪一行代码出了问题。

先说几个关键点。要开启慢日志，核心配置在PHP-FPM的pool配置文件中，通常是www.conf。你需要设置两个参数：slowlog指定日志文件的存放路径，比如/var/log/php-fpm/www-slow.log；request_slowlog_timeout设置阈值，比如1s，当然你也可以用毫秒单位，写成1000ms。配置完成后，记得重启PHP-FPM使其生效，命令是systemctl restart php-fpm，或者根据你实际使用的PHP版本执行php7.4-fpm、php8.1-fpm之类的操作。

配置完之后，怎么确认它真的在工作呢？很简单，用tail -f /var/log/php-fpm/www-slow.log实时观察日志输出，然后在某个PHP脚本里手动加上一个sleep(2)，发起一次请求。如果日志里出现了包含script_filename和具体函数调用栈的条目，那就说明配置成功了。不过这里要提醒一下，PHP-FPM慢日志和MySQL的慢查询日志完全是两回事，后者需要在数据库层面配置slow_query_log和long_query_time，别搞混了。

一、看得懂日志，才能对症下药

当你在慢日志里看到类似这样的条目时，别慌，其实结构很清楚：

[26-Oct-2023 15:30:45][pool www] pid 12345
script_filename = /var/www/html/index.php
[0x00007f8b8c0c8000] curl_exec() /var/www/html/api.php:45
[0x00007f8b8c0c8100] api_call() /var/www/html/index.php:23

核心信息就三个：哪个脚本、哪个进程、堆栈长什么样。解读的时候，关键是要先揪出具体的文件和行号，看看那个函数到底是什么——是数据库查询、外部API调用、文件IO，还是锁竞争？比如上面这个例子，curl_exec出现在api.php:45，那就说明问题很可能是调用外部接口超时了。

二、几个实用的分析命令

搞清楚了日志结构，接下来就是怎么从海量日志里快速找到“元凶”。

实时观察新增的慢请求，tail -f是最直接的。如果你想看看哪些脚本是“常客”，可以把日志里的script_filename提取出来，按出现频率或者平均耗时排个序。当然，这需要一点脚本功夫去解析时间戳。

另一个常见的需求是统计热点函数。你可以用一行命令搞定：

grep -o '[0x[0-9a-f]*] [^(]*([^)]*)' /var/log/php-fpm/www-slow.log | sort | uniq -c | sort -nr | head

这个命令会把所有出现在堆栈中的函数名和文件路径提取出来，统计它们出现的次数，然后按降序排列。排在最前面的，就是你的性能瓶颈所在。

如果只想看某个特定脚本的慢记录，直接用grep过滤就行：

grep 'script_filename = /var/www/html/index.php' /var/log/php-fpm/www-slow.log

此外，如果你的access.log里记录了请求耗时，也可以用awk做统计。比如按脚本平均耗时排序，思路大致是这样的：先提取出每个请求的脚本名和耗时，然后累加并计算平均值，最后排序输出。这里就不展开细说了，但有心的话可以写个脚本固化下来。

当你怀疑问题可能出在数据库层面时，别客气，直接上pt-query-digest这个利器。它会自动分析MySQL的慢查询日志，把最耗时的SQL语句和模式聚合出来，信息量非常大。

三、当进程“假死”时，怎么办？

有时候，慢日志里记录的信息还不够，比如某个PHP进程直接卡住了，没有任何响应。这时候就需要上一些“硬核”工具了。

strace是排查系统调用阻塞的神器。运行strace -p -f -e trace=all，你会看到这个进程正在进行的每一个系统调用。如果它长时间卡在connect()、read()或poll()上，那问题就很明显了：要么是网络不通，要么是对方服务没响应。

另一个工具是gdb，更适合在测试环境调试。用gdb -p 附加到进程，然后执行bt查看调用栈，或者用info threads、thread apply all bt查看所有线程的堆栈。虽然有点重，但确实非常直接。

如果问题出在CPU高占用上，perf会是你的好帮手。运行perf record -p -g -- sleep 30，采样30秒，然后用perf report查看结果。它会把CPU时间花在哪些函数上清晰地展示出来，让你一目了然。

当然，不要只盯着PHP本身。配合free -h看内存，用iostat -x 1看磁盘IO，有时候你会发现，慢请求只是表象，真正的根源在于系统资源已经吃紧。

四、治本：优化与预防

分析慢日志的最终目的，是避免下次再出现同样的问题。这里有几个比较实用的建议。

第一，所有外部依赖必须设置超时。比如数据库连接，用PDO的时候设置ATTR_TIMEOUT，或者调整MySQL的wait_timeout参数。更推荐的做法是使用连接池，减少频繁创建和销毁连接带来的开销。对于HTTP调用，比如用cURL，一定记得设置CURLOPT_TIMEOUT和CURLOPT_CONNECTTIMEOUT，避免一个下游接口的故障拖死你所有的PHP进程。

第二，注意锁竞争。很多人用flock处理文件锁时没有考虑超时，结果一个进程卡住了，后面排队的进程全都在等待。这种情况其实完全可以用非阻塞模式或超时机制来避免。

最后，建立常态化的监控机制。不要只在出问题时才去看慢日志，而是应该定期分析，配合access.log做访问画像。每次优化后，保留基线数据，回归验证，这样才能持续提升系统的稳定性。