人人都会AI编程

11.3 SHOW PROFILE 分析 SQL 执行耗时

更新时间:2026-07-11

EXPLAIN 让你看到“优化器打算怎么做”,而 SHOW PROFILE 让你看到“引擎实际花了多少时间,时间都花在了哪个阶段”。它是一把微观层面的手术刀,用于解剖单条 SQL 语句在执行过程中的时间分布。

11.3.1 开启与使用

SHOW PROFILE 默认是关闭的,需要在会话级别手动开启:

SET profiling = 1;

然后正常执行你的 SQL 语句。之后,通过以下命令查看已记录的查询列表:

SHOW PROFILES;

你会看到类似输出:

+----------+------------+-----------------------------------------+
| Query_ID | Duration   | Query                                   |
+----------+------------+-----------------------------------------+
|        1 | 0.00081500 | SELECT * FROM users WHERE id = 1001     |
|        2 | 0.52314200 | SELECT COUNT(*) FROM orders WHERE ...   |
+----------+------------+-----------------------------------------+

选择你想要分析的 Query_ID,查看其详细耗时分布:

SHOW PROFILE FOR QUERY 2;

输出会列出执行过程中各个阶段的名称、耗时,以及该阶段在整个查询时间中的占比。

11.3.2 理解各阶段含义

一个典型的 SHOW PROFILE 输出如下(精简后):

+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000028 |
| checking permissions | 0.000005 |
| Opening tables       | 0.000014 |
| init                 | 0.000021 |
| System lock          | 0.000007 |
| optimizing           | 0.000026 |
| statistics           | 0.000092 |
| preparing            | 0.000017 |
| executing            | 0.000003 |
| Sending data         | 0.520016 |
| end                  | 0.000006 |
| query end            | 0.000004 |
| closing tables       | 0.000003 |
| freeing items        | 0.000010 |
| cleaning up          | 0.000007 |
+----------------------+----------+

不要被一长串名字吓到,作为开发者,你应该重点关注以下高耗时阶段:

  • Sending data:这是一个非常容易误导的名字。它并不只是“将结果返回给客户端”,而是涵盖了从引擎层读取数据、处理、过滤到发送的整个过程。如果你的查询需要扫描大量行,或者有复杂的 WHERE 条件在服务端进行过滤,时间基本都会消耗在这里。绝大多数慢查询的“病灶”就在这个阶段。看到它占比极高,优化的方向仍然是索引优化、减少扫描行数。
  • Creating tmp table:查询中需要用到临时表(比如 GROUP BY 的列没有索引、DISTINCTUNION、子查询等)来暂存中间结果。如果临时表数据量大,会进一步触发 converting HEAP to MyISAM,表示内存临时表放不下了,改用磁盘临时表。一旦出现这两个阶段,就要想办法通过索引改写 SQL 来消除临时表。
  • Sorting result:发生了排序操作,如果排序列没有索引,就会触发文件排序(filesort)。结合 Sending data 高耗时,基本可以断定排序是瓶颈。
  • Opening tables:打开表时会尝试获取元数据锁,如果这个阶段耗时异常,很可能是有长事务或 DDL 操作阻塞了。
  • statistics:优化器收集统计信息以生成执行计划。偶尔耗时略高是正常的,但如果持续异常,可能要检查统计信息是否过时,是否需要执行 ANALYZE TABLE

11.3.3 实战案例

一条业务反馈的“用户列表加载慢”的 SQL:

SELECT user_id, nickname, SUM(amount) AS total
FROM orders
WHERE create_time >= '2024-01-01' AND create_time < '2024-07-01'
GROUP BY user_id
ORDER BY total DESC
LIMIT 20;

SHOW PROFILE 结果:

+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| ...                  | ...      |
| Creating tmp table   | 0.451220 |
| Sorting result       | 0.782310 |
| Sending data         | 1.140050 |
+----------------------+----------+

时间基本消耗在创建临时表和排序上,且 Sending data 极高。这说明优化器先全表扫描下单数据,取出满足时间范围的记录,再用临时表进行 GROUP BY,最后对临时表文件排序。优化方向很明确:在 (create_time, user_id) 上建立联合索引,让 WHEREGROUP BY 都能利用索引,消除临时表和排序。优化后再次 SHOW PROFILE,这些高耗时阶段消失,查询降至 0.05 秒以内。

11.3.4 实用注意事项

  • 启用开销profiling 会记录每个查询的执行细节,对数据库性能有一定影响。绝对不要在持续的业务负载下全局开启,只在需要分析特定慢查询的调试会话中使用。
  • 查看 CPU 等细节:可以用 SHOW PROFILE CPU, BLOCK IO FOR QUERY N 查看 CPU 时间、I/O 等待等额外信息,进一步精确定位是计算瓶颈还是 I/O 瓶颈。
  • 弃用状态:从 MySQL 5.6.7 开始,SHOW PROFILE 已被标记为废弃功能;在 8.0 版本中虽仍可使用,但官方计划在未来版本中移除。它的替代品是 performance_schema 中的 events_statements_* 表,以及 sys 库中的 statement_analysisstatement_performance_analyzer 等工具。
  • 现实使用场景:大多数时候,你通过 EXPLAIN 已经能定位 80% 的性能问题,SHOW PROFILE 主要用在 EXPLAIN 看不出明显问题、但执行依然很慢时,用来验证具体耗时到底在哪个环节。它非常适合开发环境和预发分析,线上只在紧急诊断且可控时使用。

11.3.5 从 SHOW PROFILE 到 Performance Schema

既然 SHOW PROFILE 已走上退役之路,建议读者尽早熟悉其现代替代方案。比如用以下查询获取类似的效果(需开启 performance_schema):

SELECT 
    event_name, 
    timer_wait/1000000000000 AS time_ms,
    lock_time/1000000000000 AS lock_time_ms
FROM performance_schema.events_statements_history_long
WHERE sql_text LIKE '%SELECT ...%'
ORDER BY timer_wait DESC LIMIT 1;

sys 库也提供了更人性化的视图:

SELECT * FROM sys.statement_analysis WHERE query LIKE '%orders%'\G

这些工具能提供比 SHOW PROFILE 更丰富、更准确的信息,并且对系统的影响可控。

但即使如此,SHOW PROFILE 作为一个“轻量快速看一眼”的调试手段,在开发和测试库上仍然保留着不可替代的便捷性。掌握它,可以让你的 SQL 调优工作流更加立体。