如何排查MySQL中慢日志记录的SQL真实耗时究竟卡在哪个阶段-mysql教程-PHP中文网

show profile仅适用于mysql 5.7及更早版本，8.0+已移除；需先执行select @@profiling确认状态，为0则set profiling = 1开启，再执行sql后立即用show profile for query n分析各阶段耗时，瓶颈常在creating tmp table、sorting result等阶段；8.0+应改用performance schema。

如何排查mysql中慢日志记录的sql真实耗时究竟卡在哪个阶段

直接看 `SHOW PROFILE`，但得先确认它没被禁用

MySQL 的 SHOW PROFILE 是唯一能告诉你某条 SQL 在「解析→优化→执行→发送结果」各阶段真实耗时的原生手段。但它默认是关闭的，而且只对当前会话生效，不是全局开关。很多排查者查了半天慢日志，却忘了这一步，直接跳去 EXPLAIN，结果把 IO 问题当成索引问题优化，白忙活。

操作前先确认是否可用：

SELECT @@profiling; 返回 0 就得先开：SET profiling = 1;
注意：MySQL 8.0.22+ 已废弃该功能，如果返回 Unknown system variable 'profiling'，说明你用的是新版，得换方案（见下一条）
执行完目标 SQL 后，立刻运行 SHOW PROFILES; 查到它的 Query_ID，再用 SHOW PROFILE FOR QUERY N; 看明细

重点关注这几列：Sending data（数据读取和传输）、Creating sort index（排序建临时索引）、Copying to tmp table（写磁盘临时表）、Locked（锁等待）。如果 Locked 耗时高，说明不是 SQL 本身慢，而是被别的事务堵住了。

MySQL 8.0.22+ 必须用 Performance Schema 替代 `SHOW PROFILE`

新版 MySQL 彻底移除了 profiling，但没删能力，只是换了个更严谨的路径：Performance Schema。它默认开启，但关键的语句阶段事件可能被关着，不手动打开就看不到细节。

执行前务必检查并启用：

SELECT * FROM performance_schema.setup_consumers WHERE NAME LIKE 'events%stage%'; —— 确保 events_stages_current 和 events_stages_history_long 是 ENABLED
SELECT * FROM performance_schema.setup_instruments WHERE NAME LIKE 'statement/%' AND NAME NOT LIKE '%abstract%'; —— 找到 statement/sql/select 等对应项，确保 ENABLED = YES，否则连语句都捕获不到
执行完慢 SQL 后，查：SELECT EVENT_NAME, TIMER_WAIT/1000000000 AS time_s FROM performance_schema.events_stages_history_long WHERE NESTING_EVENT_ID IN (SELECT EVENT_ID FROM performance_schema.events_statements_history_long WHERE SQL_TEXT LIKE '%your_slow_sql%') ORDER BY TIMER_WAIT DESC LIMIT 10;

这里 TIMER_WAIT 单位是皮秒，除以 1e9 得秒级耗时。你会发现 stage/sql/Sorting result 或 stage/innodb/row_lock_wait 占比异常高——这就定位到瓶颈了，不是“SQL 写得差”，而是“数据量大导致排序溢出内存”或“行锁冲突严重”。

别只信 `Query_time`，重点对比 `Lock_time` 和 `Rows_examined`

慢查询日志里的 Query_time 是总耗时，但它是“从执行器开始到结束”的黑盒时间，不拆解。真正暴露问题的其实是另外两个字段：Lock_time 和 Rows_examined。

MySQL

编写正确的MySQL查询，避免字符集、索引和锁方面的常见陷阱。

下载

如果 Query_time 是 2.5s，Lock_time 是 2.48s，那基本可以确定：不是 SQL 慢，是锁等得久。此时该查 INFORMATION_SCHEMA.INNODB_TRX 和 INNODB_LOCK_WAITS，而不是改索引
如果 Rows_examined 是 50 万，Rows_sent 是 20，比例超过 10000:1，说明过滤条件没走索引，或者索引区分度极低（比如对 is_deleted=0 建单列索引），扫描成本压倒一切优化
Lock_time 为 0 但 Query_time 高？大概率是磁盘 IO 或 CPU 密集型操作，比如大字段 GROUP BY、无缓冲的 ORDER BY、JSON 字段全文解析

这些字段在日志里都明文写着，但很多人只扫一眼 Query_time 就去改 SQL，反而错过最直接的线索。

用 `EXPLAIN FORMAT=TREE` 看执行流程树，比老式 `EXPLAIN` 更准

MySQL 8.0+ 的 EXPLAIN FORMAT=TREE 会输出带层级结构的执行计划，能清晰看出“哪个 JOIN 先做”“哪个子查询被物化”“排序是否用了文件”——这些正是 SHOW PROFILE 里 Creating sort index 或 Using temporary 的源头。

例如执行：EXPLAIN FORMAT=TREE SELECT u.name, o.total FROM users u JOIN orders o ON u.id = o.user_id WHERE o.status = 'paid' ORDER BY o.created_at DESC LIMIT 20;

输出中若看到 -> Sort row IDs + -> Read sorted row IDs，说明排序在内存完成；若出现 -> Materialize 或 -> Filesort，就是性能雷区。这时再结合 SHOW PROFILE 或 Performance Schema 的阶段耗时，就能交叉验证：到底是排序逻辑重，还是磁盘读取慢。

注意：FORMAT=TREE 不支持所有语句（比如含 UNION 的复杂查询会退化），遇到报错就切回 FORMAT=TRADITIONAL，但优先用 TREE。

真实耗时卡在哪，从来不是靠猜。关键在于别把慢日志当终点，它只是起点；Query_time 是总分，而 SHOW PROFILE、Performance Schema、EXPLAIN FORMAT=TREE 和日志里的 Lock_time/Rows_examined 才是得分明细。漏掉任意一项，都可能把锁等待当成 SQL 低效，把磁盘 IO 当成索引缺失。