php-fpm slowlog仅记录请求总耗时及阻塞函数,无法区分数据库内部耗时;需结合mysql慢日志(通过trace_id关联)和php层microtime打点,才能精准定位真实瓶颈。

PHP-FPM slowlog 本身不区分数据库耗时
PHP-FPM 的 slowlog 只记录整个请求生命周期(从接收到响应)的总耗时,以及最终卡在哪个 PHP 函数调用上(如 sleep()、mysqli_query()、PDOStatement::execute())。它**无法自动拆解**出其中多少是网络延迟、多少是 MySQL 执行、多少是 PHP 自身逻辑。所以你在 slow.log 里看到 mysqli_query() 占了 4.2 秒,这 4.2 秒是「PHP 等待该函数返回」的全部时间 —— 包含连接建立、SQL 发送、MySQL 解析/执行/返回结果的全过程。
用唯一 trace_id 联动 MySQL 慢日志比对
这是最直接、生产环境验证有效的排除法:让 PHP 请求和 MySQL 查询通过同一个标识关联起来。
- 在 PHP 入口处生成并注入 trace_id,例如:
$trace_id = 'REQ-' . bin2hex(random_bytes(6)); - 将该
$trace_id作为注释插入所有 SQL(PDO/MySQLi 均支持),例如:/* {$trace_id} */ SELECT * FROM users WHERE id = ? - 确保 MySQL 已开启慢查询日志:
slow_query_log=1、long_query_time=0.5(建议设低些便于捕获) - 当 slowlog 报告某请求超时,去查
slow-query.log,用grep "REQ-"找对应 trace_id 的 SQL 行,看其实际执行时间(日志里明确标有# Query_time: 3.821s) - 若 MySQL 日志中该 SQL 执行仅 0.3 秒,但 PHP slowlog 显示卡在
mysqli_query()4.2 秒 → 剩余近 4 秒大概率是连接池空闲、DNS 解析、SSL 握手或结果集过大导致的阻塞读取
在 PHP 层加 SQL 执行前后的 microtime 计时
不依赖外部日志,直接在关键数据库操作前后打点,能快速定位是否真由 SQL 引起。
- 不要只测
query(),要覆盖完整链路:connect()、prepare()、execute()、fetch() - 示例片段(PDO):
$start = microtime(true); $pdo->query('/* REQ-abc123 */ SELECT COUNT(*) FROM huge_table'); $duration = microtime(true) - $start; error_log("SQL time: {$duration:.3f}s (trace: REQ-abc123)"); - 注意:如果使用了连接池或长连接(
pconnect),connect()时间通常可忽略;但首次连接、连接断开重连、或连接被服务端 kill 后重建,耗时会突增 - 这类计时必须写进业务关键路径,且仅在 debug 模式或采样开启(避免性能损耗)
为什么不能只看 slowlog 里的函数名就下结论
常见误判场景:
-
mysqli_query()卡住 ≠ SQL 慢:可能是 MySQL 连接数满(max_connections),PHP 在排队等可用连接 -
PDOStatement::execute()耗时高 ≠ 数据库瓶颈:可能因结果集太大(如未加LIMIT的全表 SELECT),PHP 在fetch()阶段把几 MB 数据一次性读进内存,触发 GC 或 OOM Killer -
curl_exec()出现在 slowlog → 和数据库完全无关,但常被当成“DB 慢”误判 - 使用了 ORM(如 Laravel Eloquent)时,slowlog 显示的是
__call()或get(),实际耗时分散在查询构建、绑定、执行、映射多个阶段,需结合 DB 查询日志 + 应用层 debug 日志交叉验证
真正排除数据库耗时,靠的不是看 slowlog 里哪行函数名,而是拿到两个时间戳:一个是 PHP 开始等数据库响应的时刻,一个是 MySQL 实际执行完的时刻。缺一不可。
php免费学习视频:立即使用
踏上前端学习之旅,开启通往精通之路!从前端基础到项目实战,循序渐进,一步一个脚印,迈向巅峰!











