问题背景 #

我在RHEL 8系统上部署了Apache 2.4 + PHP-FPM 7.4.30的环境，最近遇到了PHP慢日志无法正常工作的问题——它根本没法准确记录真正的长运行脚本信息。

具体来说，当我启用慢日志后，哪怕把request_slowlog_timeout设置成10秒甚至更久，日志里还是会冒出大量条目，其中不乏我明确知道运行速度很快的脚本。这些条目看起来毫无规律，各种脚本的函数回溯都有，完全不符合实际情况：这些脚本从接收请求到给Apache返回结果，根本花不了那么长时间。

预期行为 #

按照PHP官方文档的描述：

慢日志应该只标记那些从服务器接收到请求到脚本运行完成，耗时超过设定阈值的脚本。换句话说，它统计的应该是单个请求从开始到结束的完整运行时长。

但实际启用慢日志后，完全不是这个效果。

我的推测 #

我目前的猜想是：慢日志并没有统计Apache发来的单个请求的运行时间，而是在统计PHP-FPM子进程的整体运行时长。因为子进程本身可能会持续运行很长时间，当子进程的运行时长超过request_slowlog_timeout时，慢日志就会输出该进程当前正在运行的脚本的回溯信息——而这个脚本可能只是刚好在那个时间点被执行，本身并不属于长运行脚本。

我的疑问 #

• 为什么PHP-FPM会在慢日志中生成这类无效条目？它是不是无法正确识别单个请求的起始时间？
• 该如何配置慢日志，才能让它只记录原本应该记录的内容：单个请求的实际运行时长？

我在生产服务器和仅单用户的测试服务器上都能稳定复现这个问题，但目前还没找到其他用户报告过类似情况。非常感谢各位能提供任何见解或帮助！

备注：内容来源于stack exchange，提问作者potc