先把当时的情况摆出来。Ubuntu 22.04 上跑 PHP 8.2 FPM,php-fpm.conf 里写了 request_slowlog_timeout = 3s 和 slowlog = /var/log/php-fpm/slow.log,接口明显有卡顿,那个文件一直不存在,目录里只有 fpm.log。
把日志和配置对完,能解释这个现象的基本就这几处。request_slowlog_timeout 没小于 request_terminate_timeout,请求先被杀,慢日志来不及写。也可能是slowlog 配在 global 段,真正生效的是 pool 段里的同名指令。
还有一种情况,php-fpm 的运行用户对日志目录没有写权限,打开失败只记在 fpm.log。另外,改完只 reload 了 nginx,php-fpm 进程压根没重新加载配置。
先确认运行中的配置值
php-fpm8.2 -tt 2>&1 | grep -E 'slowlog|slowlog_timeout'
接着看 pool 段有没有覆盖全局值
grep -rn -E 'slowlog|request_slowlog_timeout' /etc/php/8.2/fpm/
补齐目录权限并重新加载
install -d -o www-data -g www-data /var/log/php-fpm && systemctl reload php8.2-fpm
制造一次慢请求验证
curl -s -o /dev/null -w '%{time_total}
' 'http://127.0.0.1/slow.php?sleep=5'
排查用的命令都是临时敲的,没有写成脚本,事后才整理。
手上没有现成的复现脚本,就照着线上请求手工拼了一个。
恢复的判定其实很直接。slow.log 里出现带完整 PHP 调用栈的记录,fpm.log 中不再有打开文件失败的 warning。
slowlog 时间要略小于 terminate_timeout,不然抓到的是被杀现场而不是慢点;日志目录别放 /tmp,tmpfs 重启就没了。监控比日志更早给出信号,事后回看经常能提前半小时发现异常。
