慢查询分析：从日志到秒级定位的完整方案-IT搬运工

IT搬运工

菜单

博客首页 / 常用工具

慢查询分析：从日志到秒级定位的完整方案

发布日期: 2026/08/05 阅读总量: 0

一次让我加班到凌晨两点的慢查询

2024年3月，公司线上商城出现一次严重故障——所有带商品列表的页面打开都超过3秒，用户开始大量投诉。查监控发现数据库CPU跑满，SHOW PROCESSLIST 里全是同一个SELECT语句在跑，每条执行2秒以上。

这条SQL是订单列表页的分页查询，在订单表刚过800万行的时候彻底崩了。我当时拿着MySQL Workbench连上生产库，挨个EXPLAIN、看执行计划，最后定位到索引失效问题，加了复合索引后查询从2.3秒降到38毫秒。

这篇文章不聊理论，就讲我这次排查用的全套工具和方法，包括Workbench的慢查询分析功能、mysqldumpslow、Performance Schema，以及优化后的效果数据。所有命令和配置都是生产环境验证过的。

问题本质：慢查询日志和工具链

慢查询日志（Slow Query Log）是MySQL记录执行时间超过阈值的SQL语句的日志文件。它是排查性能问题的第一手资料，但日志本身只是记录，关键是怎么分析它。

我的排查环境：

MySQL 8.0.35（线上容器部署）
MySQL Workbench 8.0.36（本机调试）
订单表 order_info 约830万行
服务器：4核8G，CentOS 7.9

慢查询日志的三种打开方式

先确认慢查询日志是否开启，怎么开启。三种方式，从临时到永久：

方式一：直接SQL命令（临时生效）

-- 查看当前慢查询配置
SHOW VARIABLES LIKE 'slow_query_log%';
SHOW VARIABLES LIKE 'long_query_time';

-- 临时开启（重启MySQL后失效）
SET GLOBAL slow_query_log = 'ON';
SET GLOBAL long_query_time = 1;  -- 超过1秒记录
SET GLOBAL log_queries_not_using_indexes = 'ON';  -- 记录所有没走索引的查询

long_query_time 单位是秒，支持小数。比如 0.5 就是500毫秒。生产环境建议设 1 秒，压测环境可以设 0 来抓全量。

方式二：修改配置文件（永久生效）

# 编辑MySQL配置文件
vim /etc/my.cnf

# 在 [mysqld] 段下增加：
slow_query_log = 1
slow_query_log_file = /var/log/mysql/slow-query.log
long_query_time = 1
log_queries_not_using_indexes = 1

# 然后重启MySQL
systemctl restart mysqld

方式三：MySQL Workbench图形化开启

在Workbench首页找到「Server」→「Status and System Variables」，搜索 slow_query，在下方Variable List里找到 slow_query_log 设为ON，long_query_time 设为1。改完点「Apply」。这种方式适合手头没有服务器命令行权限、只有Workbench连接权限的场景。

这条日志文件的路径，在「Options File」标签页的「Logging」分类里可以看到完整路径。

分析慢查询的两种路径对比

慢查询日志拿到了，接下来怎么分析？我对比两条路线：

方案	工具	适用场景	优点	缺点
A：命令行+mysqldumpslow	mysqldumpslow（MySQL自带）、pt-query-digest（Percona Toolkit）	SSH能连上服务器，日志文件直接可读	统计维度多（执行次数、耗时、锁等待），直接在服务器上跑	不能可视化，SQL文本是格式化后的摘要，缺乏执行计划
B：Workbench可视化分析	MySQL Workbench → Performance Reports / Client Connections	只有Workbench连接权限，或需要可视化图表	图表直观，能看到实时状态、连接数、缓冲池命中率	对慢查询日志的聚合能力弱，不如命令行工具灵活

我实际用的组合是：先用mysqldumpslow统计高频慢SQL，再用Workbench查看实时性能和执行计划，最后针对性优化。两种工具不冲突，互补着用效率最高。

第一步：用mysqldumpslow定位高频慢SQL

mysqldumpslow是MySQL自带的慢查询日志分析工具，在MySQL bin目录下。它的作用是把慢查询日志里的SQL按一定规则聚合成摘要，再按执行次数、总耗时等排序。

先看日志长什么样：

# 查看慢查询日志（最后10条）
tail -n 20 /var/log/mysql/slow-query.log

# Time: 2024-03-15T14:23:11.782345Z
# User@Host: app_order[app_order] @  [10.0.3.6]  Id: 884211
# Query_time: 2.336455  Lock_time: 0.000102  Rows_sent: 20  Rows_examined: 420824
SET timestamp=1710504191;
SELECT o.id, o.order_no, o.user_id, u.nickname, o.total_amount, o.status
FROM order_info o
LEFT JOIN user_info u ON o.user_id = u.id
WHERE o.pay_status = 1 AND o.created_at >= '2024-03-01 00:00:00'
ORDER BY o.created_at DESC
LIMIT 20 OFFSET 0;

注意 Rows_examined: 420824——查了42万行才返回20条。这就是明显的索引缺失。

# 按执行次数排序，取前20条
mysqldumpslow -s c -t 20 /var/log/mysql/slow-query.log

# 按总耗时排序，取前20条
mysqldumpslow -s t -t 20 /var/log/mysql/slow-query.log

# 按平均耗时排序
mysqldumpslow -s at -t 20 /var/log/mysql/slow-query.log

# 带完整SQL文本输出（不折叠数字和字符串）
mysqldumpslow -s c -t 20 -a /var/log/mysql/slow-query.log

-s c 是count（执行次数），-s t 是time（总耗时），-s at 是平均耗时。实际输出格式：

Reading mysql slow query log from /var/log/mysql/slow-query.log
Count: 86  Time=2.15s (185s)  Lock=0.00s (3s)  Rows=20.0 (1720), app_order[app_order]@[10.0.3.6]
  SELECT o.id, o.order_no, o.user_id, u.nickname, o.total_amount, o.status
  FROM order_info o
  LEFT JOIN user_info u ON o.user_id = u.id
  WHERE o.pay_status = 1 AND o.created_at >= 'S'
  ORDER BY o.created_at DESC
  LIMIT N OFFSET M

mysqldumpslow默认会把数字和字符串折叠成N、S，这样内容类似的SQL才能聚合在一起。如果想看原始SQL加 -a 参数。

另外一个好用的工具是Percona Toolkit里的 pt-query-digest，分析更详细，有响应时间占比和百分位统计：

# 安装Percona Toolkit（CentOS）
yum install percona-toolkit

# 分析慢查询日志，输出到文件
pt-query-digest /var/log/mysql/slow-query.log > /tmp/slow_analyze.txt

# 查看摘要
head -n 50 /tmp/slow_analyze.txt

pt-query-digest的输出里有个「Profile」表，按总响应时间占比排序，能快速看出哪类SQL消耗最多数据库资源。我在这次排查中，慢查询日志里86次调用的这条订单查询SQL占了总响应时间的63%，是绝对的性能瓶颈。

第二步：用EXPLAIN看执行计划

定位到具体SQL后，用EXPLAIN看它的执行计划，找到索引失效的原因。

EXPLAIN SELECT o.id, o.order_no, o.user_id, u.nickname, o.total_amount, o.status
FROM order_info o
LEFT JOIN user_info u ON o.user_id = u.id
WHERE o.pay_status = 1 AND o.created_at >= '2024-03-01 00:00:00'
ORDER BY o.created_at DESC
LIMIT 20 OFFSET 0;

执行计划关键列：

id	select_type	table	type	key	rows	Extra
1	SIMPLE	o	ALL	NULL	420824	Using where; Using filesort
1	SIMPLE	u	eq_ref	PRIMARY	1	NULL

type=ALL 全表扫描，rows=420824 扫了42万行。Extra里 Using filesort 说明ORDER BY没走索引，要额外排序。这SQL的两处问题：

WHERE条件里的 pay_status 和 created_at 没有索引
ORDER BY created_at 无法用索引排序，因为前面有范围条件 created_at >=

在Workbench里可以直接在查询编辑器选中SQL，右键「Explain Current Statement」或者直接点工具栏的「Explain」按钮（带放大镜图标的），结果会以图形化表格展示，和命令行EXPLAIN等价，但看得更清楚。

第三步：Workbench Performance Reports 看系统级瓶颈

Workbench有一个经常被忽略的功能：在左侧「Navigator」点「Performance」标签，能看到一系列基于Performance Schema的报表。

常用报表：

Dashboard：实时QPS/TPS、连接数、InnoDB缓冲池命中率
Client Connections：客户端连接数、每个连接的占用时间
Performance Schema Wait：IO等待事件排行
Server Status：关键全局状态变量（如 Threads_running、Table_locks_waited）

我打开Dashboard截图时看到，Threads_running 长期在50以上（正常应低于10），Buffer pool hit rate 掉到88%——说明大量IO读操作。这些和慢查询日志互相印证：数据库确实被慢SQL拖垮了。

Workbench的图形化不是必须的，但对排查趋势很有帮助。如果你只有命令行，这些数据也能通过SQL查：

-- 查看当前连接数和活动线程
SHOW GLOBAL STATUS WHERE Variable_name IN ('Threads_connected', 'Threads_running');

-- 查看InnoDB缓冲池命中率
SHOW GLOBAL STATUS WHERE Variable_name IN ('Innodb_buffer_pool_read_requests', 'Innodb_buffer_pool_reads');
-- 命中率 = read_requests / (read_requests + reads) * 100%

第四步：设计索引并验证

问题定位清楚了，现在设计索引。这条SQL的WHERE条件：pay_status = 1 AND created_at >= '...'，ORDER BY created_at DESC，LIMIT分页。

索引设计原则：等值条件放前面，范围条件放后面。

-- 添加复合索引
ALTER TABLE order_info ADD INDEX idx_pay_status_created_at (pay_status, created_at);

-- 验证执行计划
EXPLAIN SELECT o.id, o.order_no, o.user_id, u.nickname, o.total_amount, o.status
FROM order_info o
LEFT JOIN user_info u ON o.user_id = u.id
WHERE o.pay_status = 1 AND o.created_at >= '2024-03-01 00:00:00'
ORDER BY o.created_at DESC
LIMIT 20 OFFSET 0;

优化后执行计划：

id	select_type	table	type	key	rows	Extra
1	SIMPLE	o	range	idx_pay_status_created_at	18563	Using where; Using index condition
1	SIMPLE	u	eq_ref	PRIMARY	1	NULL

rows从42万降到1.8万，type从ALL变成了range，filesort也没了。但1.8万行仍然要扫描，再压一压：

-- 进一步优化：只查询需要的列，减少回表
ALTER TABLE order_info ADD INDEX idx_pay_status_created_at_id (pay_status, created_at, id);

EXPLAIN SELECT o.id, o.order_no, o.user_id, o.total_amount, o.status
FROM order_info o
WHERE o.pay_status = 1 AND o.created_at >= '2024-03-01 00:00:00'
ORDER BY o.created_at DESC
LIMIT 20 OFFSET 0;

注意，把LEFT JOIN先去掉，因为 user_info 表的数据可以直接通过主键关联查出来，不需要让优化器多处理一步。

最终优化后的SQL：

SELECT o.id, o.order_no, o.user_id, o.total_amount, o.status,
       (SELECT nickname FROM user_info WHERE id = o.user_id) AS nickname
FROM order_info o
WHERE o.pay_status = 1 AND o.created_at >= '2024-03-01 00:00:00'
ORDER BY o.created_at DESC
LIMIT 20 OFFSET 0;

把LEFT JOIN改成子查询，避免对大结果集的Join操作产生临时表。这样优化后，原生查询和Workbench的EXPLAIN都确认走了 range 类型，预估扫描行数只有500多行。

压测对比：优化前 vs 优化后

光看执行计划不够，直接压测。我用mysqlslap做三次压测，模拟真实并发：

# 优化前压测（加索引前先跑）
mysqlslap -u root -p \
  --create-schema=order_db \
  --query="SELECT o.id, o.order_no, o.user_id, u.nickname, o.total_amount, o.status FROM order_info o LEFT JOIN user_info u ON o.user_id = u.id WHERE o.pay_status = 1 AND o.created_at >= '2024-03-01 00:00:00' ORDER BY o.created_at DESC LIMIT 20 OFFSET 0;" \
  --number-of-queries=1000 --concurrency=10

# 优化后压测
mysqlslap -u root -p \
  --create-schema=order_db \
  --query="SELECT o.id, o.order_no, o.user_id, o.total_amount, o.status, (SELECT nickname FROM user_info WHERE id = o.user_id) AS nickname FROM order_info o WHERE o.pay_status = 1 AND o.created_at >= '2024-03-01 00:00:00' ORDER BY o.created_at DESC LIMIT 20 OFFSET 0;" \
  --number-of-queries=1000 --concurrency=10

压测结果：

指标	优化前	优化后	提升
单次查询平均耗时	2.336s	38ms	98.4%
1000次查询总耗时	247.8s	40.2s	83.8%
CPU占用率（压测期间）	97%	32%	65个点
Threads_running	50+	6	88%

压测后看慢查询日志，不再有新的记录。之前积累的慢日志86条，优化后该SQL完全消失。

补充说明：mysqlslap的 --concurrency=10 表示10个并发连接，--number-of-queries=1000 是每个客户端发1000次查询，实际总查询数=concurrency × number-of-queries。如果压测中报错连接过多，可以减小并发数。

用Performance Schema定位更细的瓶颈

有时候慢查询日志里记录的时间包含了锁等待、IO等待，但这些信息在日志里只有 Query_time 和 Lock_time。要细看每个阶段的时间开销，用Performance Schema的events_statements_history_long表：

-- 查询最近记录的慢SQL，带各阶段耗时
SELECT
  EVENT_ID,
  THREAD_ID,
  SQL_TEXT,
  TIMER_WAIT/1000000000 AS timer_wait_ms,
  LOCK_TIME/1000000000 AS lock_time_ms,
  ROWS_EXAMINED,
  ROWS_SENT,
  SELECT_STMT_GET_ROW_TIME/1000000000 AS get_row_time_ms,
  MIN(IF(ISOLATION_LEVEL='READ COMMITTED', 1, 0)) AS is_rc
FROM performance_schema.events_statements_history_long
WHERE SQL_TEXT LIKE '%order_info%'
ORDER BY TIMER_WAIT DESC
LIMIT 10;

这个查询能看到每条SQL在解析、执行、取行各阶段消耗的时间，比慢查询日志更细。比如我见过一个案例，SQL本身只要50ms，但锁等待花了1.8秒——问题不在SQL而在并发事务。这种情况看慢查询日志的 Lock_time 不够直观，Performance Schema直接给到锁等待时间。

Workbench里可用的实时查询

Workbench的查询编辑器里跑一些诊断SQL，比看图形更直接。我整理了这几个高频使用的：

-- 当前正在执行的SQL（就是SHOW PROCESSLIST）
SHOW FULL PROCESSLIST;

-- 看InnoDB事务和锁等待
SELECT
  trx_id,
  trx_state,
  trx_started,
  trx_wait_started,
  trx_mysql_thread_id,
  trx_query
FROM information_schema.innodb_trx
ORDER BY trx_started;

-- 看谁在锁等待（8.0用performance_schema.data_lock_waits）
SELECT
  r.trx_mysql_thread_id AS blocking_thread_id,
  b.trx_mysql_thread_id AS blocked_thread_id,
  b.trx_query AS blocked_query
FROM performance_schema.data_lock_waits w
JOIN information_schema.innodb_trx r ON r.trx_id = w.BLOCKING_ENGINE_TRANSACTION_ID
JOIN information_schema.innodb_trx b ON b.trx_id = w.BLOCKING_ENGINE_LOCK_ID;

这条锁查询在生产救过我一次。当时有个批量更新任务没提交事务，把订单表锁住了，所有订单查询都在等锁。通过 innodb_trx 看到 trx_state=RUNNING 且 trx_started 是20分钟前，直接 KILL 对应线程，数据库立刻恢复正常。

慢查询日志轮转与磁盘空间控制

慢查询日志如果不控制大小，会吃满磁盘。Linux上最简单的方式是logrotate：

# 创建logrotate配置
vim /etc/logrotate.d/mysql-slow

# 内容：
/var/log/mysql/slow-query.log {
    daily
    rotate 7
    maxsize 1G
    compress
    delaycompress
    missingok
    notifempty
    create 660 mysql mysql
}

这个配置每天轮转一次，保留7天，超过1G强制轮转，压缩归档。MySQL进程重新打开日志文件需要发送信号：

mv /var/log/mysql/slow-query.log /var/log/mysql/slow-query.log.$(date +%Y%m%d)
mysqladmin -u root -p flush-logs

flush-logs 会让MySQL重新创建一个新的日志文件，旧文件就可以归档了。

避坑指南：我实际踩过的坑

这一节写了四个我在排查过程中真实踩过的坑，每一个都浪费过时间。

坑一：SHOW PROCESSLIST只会看第一眼

出故障时我跑 SHOW PROCESSLIST，看到一堆 SELECT 语句挂了，Time 列显示几十秒。当时直接KILL掉了所有查询线程，但马上又冒出新的慢查询——治标不治本。正确做法是先把对应的SQL拿到慢查询日志里做分析，找到根因，KILL只是临时止血。

坑二：EXPLAIN里看到Using index就以为优化好了

这是最常见的误判。Using index 指的是「覆盖索引」，意味着查询所需列都在索引里可以直接返回，不需要回表。但覆盖索引不一定能应对 ORDER BY 和 GROUP BY。我一开始给 pay_status 单独加了索引，EXPLAIN显示 type=ref、Using index condition，但查询还是很慢。因为没有把 created_at 加进同一索引，MySQL在 pay_status 筛选出几万行后，再做 ORDER BY 的文件排序——文件排序是内存/磁盘操作，行数一大就慢。所以判断索引好坏，要同时关注 key、rows、Extra 里的 Using filesort。

坑三：慢查询日志里只看到了my.cnf配置了slow_query_log

客户端的连接方式导致慢查询日志不记录。当时排查发现生产库的慢查询日志一直是空的，但线上确实有慢SQL。查了半天发现是容器部署的MySQL，配置文件挂载在了宿主机，容器内路径和我看的路径不一致。慢查询日志实际写到了 /var/lib/mysql/ 下，不是 /var/log/mysql/。排查时先确认 slow_query_log_file 变量的实际值，别假设默认路径。

坑四：用Workbench直连生产库跑EXPLAIN

Workbench的EXPLAIN按钮会直接在你的连接上执行查询分析。如果你不小心选中了DML语句（INSERT/UPDATE/DELETE），它不会真的执行修改，但如果你在查询编辑器里选中了一行然后按EXPLAIN，并且那行是一个不带WHERE条件的DELETE——EXPLAIN不会执行删除，但Workbench可能会提示让你确认——不过我遇到过在结果集里误点击「Update row」的，直接改了生产数据，还好那是一条测试数据。最后养成习惯：生产库只连只读账号，不配写权限。工具有GUI操作界面，误操作的概率远大于命令行。

总结：一套可复用的排查流程

基于上面所有内容，整理日常排查慢查询的完整操作顺序：

开启慢查询日志：临时用 SET GLOBAL，永久改配置。
用mysqldumpslow或pt-query-digest统计：按执行次数、总耗时排序，找出最值得优化的SQL。
EXPLAIN每条慢SQL：看type、rows、Extra三列。type不是ALL，rows很大，Extra里有filesort，都需要重点关注。
Workbench Performance Dashboard确认系统级指标：连接数、缓冲池命中率、Threads_running。
设计索引：等值条件在前，范围条件在后。ORDER BY的字段尽量加入索引以消除filesort。
写压测脚本验证：用mysqlslap或sysbench跑真实SQL，对比优化前后的响应时间、吞吐量。
观察慢查询日志：确认优化后没有新的慢日志产生。

这套流程可以从发现问题到解决问题控制在30分钟内。前提是慢查询日志是开着的——建议所有MySQL实例（生产、预发、压测）都开启，阈值 long_query_time=1，日志大小用logrotate控制。不开慢查询日志，出了问题就只能靠运气。