慢查询日志的Query_time字段最准确反映SQL全程真实耗时,包含解析、优化、执行、锁等待及结果发送等全部环节,单位为微秒;SHOW PROFILE的Duration仅估算引擎内部阶段,不包含网络、客户端及锁等待延迟。

直接看慢查询日志,别信 SHOW PROFILE 的 Duration
MySQL 5.7 中唯一能反映「从发起到返回结果」全程真实耗时的,是慢查询日志里的 Query_time 字段。它包含解析、优化、执行、锁等待、发送结果等全部环节,单位为微秒(小数点后六位),不是毫秒。而 SHOW PROFILE FOR QUERY N 输出的 Duration 只是引擎内部各阶段的粗略估算,不包含网络传输、客户端接收、锁等待时间——常见现象是客户端测出 300ms,SHOW PROFILE 加起来才 40ms,差的就是这些外部延迟。
关键操作:
- 必须把 long_query_time 设低(比如 0.2),否则 200ms 的语句根本进不了日志
- 确认 slow_query_log = ON,且 MySQL 进程对 slow_query_log_file 路径有写权限(ls -l 看权限,静默失败很常见)
- 日志中若 Lock_time 接近 Query_time,说明瓶颈在锁,不是 SQL 本身
用 performance_schema.events_statements_current 查实时皮秒级耗时
想抓正在跑的 SQL 各阶段耗时,events_statements_current 比 SHOW PROCESSLIST 准得多。SHOW PROCESSLIST 的 Time 字段只表示状态持续秒数,卡在 “Sending data” 时你不知道是计算慢还是网卡慢;而 events_statements_current 的 TIMER_WAIT 是皮秒单位(需除以 1000000000000 得秒),且可关联到 events_stages_history_long 查阶段明细。
前提条件:
- 执行 UPDATE performance_schema.setup_instruments SET ENABLED = 'YES' WHERE NAME LIKE 'stage/%';
- 确保 performance_schema.setup_consumers 中 events_stages_history_long 为 ENABLED
- 注意:该表只存当前线程最新一条语句,查刚跑完的得切到 events_statements_history_long
EXPLAIN ANALYZE 不是万能解,5.7 根本不支持
别在 MySQL 5.7 里折腾 EXPLAIN ANALYZE——它最早出现在 8.0.12,且会真实执行语句(有副作用)。5.7 的普通 EXPLAIN(包括 FORMAT=JSON)**完全不提供任何耗时字段**,cost_info 是优化器估算成本,不能换算成毫秒。看到 Extra: Using filesort 或 Using temporary 只能说明“可能慢”,但无法知道它到底花了多少毫秒,更没法拆解是排序慢还是磁盘 IO 慢。
替代思路:
- 先靠慢日志确认真实耗时和 Rows_examined
- 再用 EXPLAIN 验证是否走了预期索引、是否触发临时表
- 若怀疑排序/分组开销大,结合 performance_schema.events_stages_history_long 查 stage/sql/filesort 或 stage/sql/creating sort index 阶段的 TIMER_WAIT
别漏掉锁等待和元数据锁这类“隐形耗时”
很多 SQL 在慢日志里 Query_time 高,但 EXPLAIN 看不出问题,performance_schema 里也找不到高耗时阶段——这时大概率卡在锁上。比如 Waiting for table metadata lock 或 Waiting for global read lock,这些等待时间会计入 Query_time,但不会出现在 SHOW PROFILE 或 events_stages_history_long 里。
排查手段:
- 查 information_schema.INNODB_TRX 看长事务阻塞链
- 查 performance_schema.data_locks 和 data_lock_waits(5.7.15+)定位行锁冲突
- 检查是否有 DDL 操作(如 ALTER TABLE)长期持有 MDL 锁
- Lock_time 在慢日志里接近 Query_time 是最直接信号


















