PHP FPM慢请求日志与应用日志时间线对齐方法

PHP-FPM 的 slowlog 能在请求超过阈值时记录 PHP 调用栈，但它通常不是完整的请求追踪日志。要把这段调用栈和应用日志对上，关键是让请求从进入 Web 层开始就携带同一个 request_id，再用统一时区、微秒或毫秒精度，以及 FPM access log 的耗时字段做交叉确认。

官方地址：https://www.php.net/manual/en/install.fpm.configuration.php

先把同一个请求标识传到三类日志

最容易误判的场景是两个请求几乎同时结束：一个触发了 FPM slowlog，另一个在应用日志里留下了慢 SQL。只按秒级时间戳拼接，结果很可能错位。入口层应优先生成或透传 X-Request-ID，PHP 端只在缺失时补一个随机值，并在 JSON 日志中始终打印它。

 'request.end',
        'request_id' => $requestId,
        'elapsed_ms' => round((hrtime(true) - $startedAt) / 1e6, 2),
        'status' => 200,
    ], JSON_UNESCAPED_UNICODE | JSON_UNESCAPED_SLASHES));
} catch (Throwable $exception) {
    // 异常也记录耗时和 ID，便于与 FPM slowlog 对齐。
    error_log(json_encode([
        'event' => 'request.error',
        'request_id' => $requestId,
        'elapsed_ms' => round((hrtime(true) - $startedAt) / 1e6, 2),
        'error' => $exception->getMessage(),
    ], JSON_UNESCAPED_UNICODE | JSON_UNESCAPED_SLASHES));
    throw $exception;
}

如果前面的 Nginx 或网关已经生成 ID，就不要在 PHP 中覆盖它。应用日志建议同时写 request.start、下游调用名、结果和 request.end；这样 slowlog 只提供调用栈时，仍可把它放回业务事件之间。

在 FPM pool 保留慢栈与访问耗时

把下面配置放到实际生效的 pool 文件，而不是只改全局模板。request_slowlog_timeout 控制触发回溯的阈值，slowlog 指定文件；access.log 与 access.format 则提供请求结束时间和耗时，用来和应用日志做第二次校准。

; www.conf：只记录超过阈值的 PHP 调用栈，并保留访问耗时。
request_slowlog_timeout = 2s
slowlog = /var/log/php-fpm/www-slow.log
access.log = /var/log/php-fpm/www-access.log
access.format = "%R %t \"%m %r\" %s %{milliseconds}dms"

; 生产环境把普通 PHP 错误集中到独立文件，便于按 request_id 检索。
php_admin_flag[log_errors] = on
php_admin_value[error_log] = /var/log/php-fpm/www-error.log

阈值不要直接照搬成 0.1 秒。先看正常请求的尾延迟，再选择能抓住异常又不会让 slowlog 爆量的值；排查完成后也要检查日志轮转、目录权限和磁盘空间。FPM 官方手册说明，slowlog 会记录慢脚本的 PHP backtrace，而不是完整的访问链路。

用时间精度把 slowlog 放回请求时间线

排查时先拿 FPM access log 的时间和耗时确定窗口，再查同一窗口内的应用 request.start 与 request.end。如果应用日志有 request_id，就以 ID 为主、时间为辅；如果 slowlog 本身没有 ID，就用 URI、开始时间附近的访问记录、worker 进程信息和调用栈中的文件位置做组合确认。

统一使用 UTC 或明确的服务器时区，并让所有日志至少保留毫秒；跨主机采集时还要关注 NTP 偏差。一次慢请求的回放顺序可以是：access log 找到候选结束点 → 用耗时反推开始区间 → 在应用日志按 request_id 确认 → 用 slowlog 的函数栈解释卡在哪个调用附近。

常见问题

slowlog 里没有 request_id 还能对齐吗？

可以，但可信度会低一些。用 access log 的 URI、精确时间、耗时、worker 信息和 slowlog 中的文件位置交叉确认；下一轮排查应先补齐应用 request_id。

为什么应用日志显示 800 毫秒，FPM access log 却是 2 秒？

应用计时可能只包住业务函数，FPM 总耗时还包括排队、PHP 初始化、输出处理或未纳入计时的收尾逻辑。两者差值正是继续拆分边界的线索。

request_slowlog_timeout 设置后没有文件怎么办？

先确认修改的是正在使用的 pool，检查 slowlog 父目录权限和轮转配置，再确认请求确实超过阈值并重载了 FPM。不要只看 PHP 应用的 error_log。