做数据库排查这些年,我最大的感触是:慢查询SQL这事,几乎每个团队都在“等”。等线上告警响了,DBA才登服务器翻日志,再慌慌张张把SQL拎出来看一眼。其实MySQL从设计上就给了我们一整套发现慢查询SQL的机制,日志、实时会话、性能字典都有,真正常态用起来的人却不多。这篇文章不聊怎么优化执行计划那种大道理,就专心讲清楚一件事:怎么把慢查询SQL从MySQL里“揪”出来。包括慢日志怎么开才不坑、日志里的字段到底怎么读、线上正在跑的慢SQL用什么姿势抓、以及怎样用性能字典定位到具体瓶颈,最后给一套能长期稳定运行的监控思路。适合刚接手数据库维护的同学,也适合被慢SQL折磨过的后端和运维。
1. 慢查询日志:第一道闸门怎么才算开对了
1.1 慢查询日志到底记录了什么
慢查询日志是MySQL最朴素的“自白书”。只要一条SQL的执行时间超过了我们设定的阈值,MySQL就会把这条SQL的完整文本、执行时间、锁等待时间、扫描行数、发送行数等信息原样记下来。默认情况下这个功能是关闭的,因为日志本身有IO开销,很多生产库一上来就直接开,容易忽略阈值设置带来的磁盘压力,后面会讲到怎么平衡。
先看几个核心参数,直接用命令行查看:
SHOW VARIABLES LIKE 'slow_query_log%'; SHOW VARIABLES LIKE 'long_query_time'; SHOW VARIABLES LIKE 'log_queries_not_using_indexes'; SHOW VARIABLES LIKE 'min_examined_row_limit';默认值一般是:slow_query_log=OFF,long_query_time=10.000000,log_queries_not_using_indexes=OFF。也就是说默认超过10秒的SQL才记录,而且不记录没走索引的查询。对一个面向用户的OLTP系统来说,10秒这个阈值太宽松了,等日志里有内容的时候,前端页面早就超时报错无数轮了。
我的做法是:OLTP业务库设置long_query_time=1,也就是超过1秒的SQL就记。如果业务对延迟极敏感,比如秒杀、支付回调这类,可以压到0.5秒。不太建议直接设成0,因为那样等于把所有SQL都记录下来,日志量一天能涨好几GB,排查的时候反而被噪音淹没。
1.2 参数配置的常见坑:全局值与会话值
这里有一个特别容易踩的坑:long_query_time在MySQL里同时存在全局变量和会话变量,而且它们的修改方式不完全一样。用SET GLOBAL只影响新建立的连接,已经存在的连接仍然沿用旧值。很多同学改了global之后,发现当前命令行窗口里测一条慢SQL没被记录,就以为没生效,其实是被会话变量挡了一下。
正确操作是:
-- 全局开启 SET GLOBAL slow_query_log = 'ON'; SET GLOBAL long_query_time = 1; SET GLOBAL log_queries_not_using_indexes = 'ON'; -- 当前会话也要同步,否则当前连接里测不出来 SET SESSION long_query_time = 1;另外要注意,这些参数是内存级修改,实例重启后会丢。想永久生效,必须写入配置文件。各版本路径不太一样,一般是my.cnf或my.ini,在[mysqld]段下加:
slow_query_log = 1 slow_query_log_file = /var/log/mysql/mysql-slow.log long_query_time = 1 log_queries_not_using_indexes = 1加了log_queries_not_using_indexes之后,没走索引的查询也会被记录。这个选项是把双刃剑:它能帮你发现那些因为缺索引而全表扫描的“隐形炸弹”,但线上的低效查询往往不止一两条,一旦开启,日志量会迅速膨胀。我见过一个库开了之后,一天慢日志涨了20GB。建议先临时开一周,把收集到的“没走索引”清单整理完,再评估是否长期保留。
1.3 另一个隐藏参数:min_examined_row_limit
还有一个参数容易被人忽略:min_examined_row_limit。它的意思是只有当SQL扫描行数大于等于这个值时,才可能被记入慢日志。默认值是0,表示不限制。
问题来了:如果你同时开启了log_queries_not_using_indexes,又把min_examined_row_limit设成了很大的值,比如100000,那么一条扫描了50000行但确实没走索引的查询就不会被记录下来。反过来,如果你希望特别关注那些扫描行数巨大但执行时间没超过阈值的SQL,这个参数也能帮你过滤噪音。
实际调整时我的建议是:生产环境把这个值设成0,保持默认,不要额外加限制。让慢日志“忠实记录”,后续用工具去统计,别让它在源头就丢了信息。
1.4 日志文件还是日志表:两种落盘方式
慢查询日志可以输出到文件,也可以输出到mysql库下的slow_log表,由log_output参数控制。log_output可以取值FILE、TABLE或两者都写。
文件模式的优点是开销小、格式灵活,配合logrotate切割方便。表模式的好处是可以直接SQL查询,比如按执行时间排序、按SQL文本去重,但坏处是写表有额外锁竞争,高并发下反而拖慢性能。另外如果slow_log表损坏,事务可能会受影响。
我在生产环境只用FILE。表模式更多是实验室或短期排查时临时开启用用。日志文件的位置要注意权限,mysqld进程要有写权限,否则会一直报错但不影响业务,只是你什么都查不到。
1.5 慢日志不会自动轮转,必须自己切
MySQL的慢查询日志不会像业务日志那样自动按天滚动。它一直写同一个文件,时间长了能撑爆磁盘。我见过不止一次,公司的监控磁盘告警响了,排查半天发现是慢日志文件已经几十GB。
解决办法是用系统自带的logrotate或自己写crontab定时切割。简单方案是每天凌晨用mv把当前慢日志改名,然后执行FLUSH LOGS让MySQL重新创建一个空文件继续写。注意顺序不能反:一定先mv旧文件,再FLUSH LOGS。如果先FLUSH再mv,可能出现文件句柄还没释放,新日志继续写进已被mv的旧文件里,导致新文件始终是空的。
mv /var/log/mysql/mysql-slow.log /var/log/mysql/mysql-slow-$(date +%F).log mysql -e "FLUSH LOGS"2. mysqldumpslow与日志分析:从杂乱日志里快速锁定头号嫌疑犯
2.1 原始慢日志的可读性有多差
慢日志文件默认是一堆“# 开头注释 + SQL文本”的堆叠,比如:
# Time: 2025-01-10T10:23:45.123456Z # User@Host: bi_user[bi_user] @ [10.10.10.10] Id: 884217 # Query_time: 12.345678 Lock_time: 0.001234 Rows_sent: 10 Rows_examined: 3000000 SET timestamp=1736511825; SELECT * FROM user_order WHERE user_id = 10086 AND status = 1;这条记录本身不难懂,但一个生产库一天能产生几百条甚至上千条这样的记录。如果每条都肉眼看,等看完,业务早就被拖垮了。而且不同时间点的相同SQL,只是参数不同,会反复出现,却不方便直接看出哪类SQL累计耗时最高。这时候就需要一个“排行榜”工具,把相似的SQL聚合成一条,按总耗时或平均耗时排序。
2.2 mysqldumpslow的使用姿势与输出解读
mysqldumpslow是MySQL自带的小工具,不需要额外安装。几个关键参数:
- -s:排序方式。常用at表示按平均查询时间排序,c表示按出现次数排序,al表示按平均锁等待时间排序。
- -t:只显示前N条。
- -g:按正则表达式过滤SQL文本。
实际执行:
mysqldumpslow -s at -t 10 /var/log/mysql/mysql-slow.log典型输出长这样:
Count: 56 Time=3.86s (216s) Lock=0.00s (0s) Rows=283160.0 (15856960), user[user]@[10.10.10.0%] SELECT * FROM report_data WHERE biz_date BETWEEN 'N' AND 'N' ORDER BY id解释一下这行:Count=56表示这条SQL在日志里出现了56次(数字已经被抽象成N,所以内容相同的SQL才能聚合到一起);Time=3.86s是平均执行时间,(216s)是56次的总耗时;Lock=0.00s是平均锁等待;Rows=283160.0是平均扫描行数,(15856960)是总扫描行数。后面跟的是来源用户和IP段。
看到平均3.86秒、56次总共216秒,你就能判断出这是报表类的重量级查询,如果不优化,每天会有3分半钟的数据库时间耗在这上面。这就是mysqldumpslow的核心价值:把散落的日志变成一张可行动的TOP榜。
2.3 为什么输出里的数字都变成了N
mysqldumpslow默认会把SQL文本里的数字替换成N,目的是把同一类不同参数的SQL合并。比如WHERE id=10086和WHERE id=99都会被归一化成WHERE id=N,从而归为一条。
这个设计很聪明,但也带来一个问题:如果某个SQL的优化必须依赖具体参数值(比如数据倾斜,某些user_id的数据量特别大),只看聚合结果会觉得它一直很慢,实际上可能只是个别参数触发。遇到这种情况,建议用mysqldumpslow的-a参数保留原始数字,或者直接grep原始日志文件,单独看那一条SQL的多个执行记录。
2.4 进阶思路:把日志归档后再分析
慢日志切割之后,建议归档保留至少一个月,这样你能对比不同时间段的TOP SQL变化。比如上线新功能后,某条SQL从排行榜第20名冲到第1名,那就是新功能惹的祸,很好定位。
我自己的归档习惯是:慢日志按天切割后,再跑一次mysqldumpslow生成当天的TOP20,存成文本文件。这样即使原始文件因为空间清理被删了,历史趋势还在,写周报和做复盘都有依据。
3. 实时抓取:正在跑的慢SQL,看这两个最直接
日志适合事后分析,但线上突发故障时,你需要的是“此时此刻数据库里正在跑什么SQL,谁跑得最久”。这时候慢查询日志帮不上忙,因为它是事后写的,而且有延迟。两个直面现场的工具是SHOW PROCESSLIST和information_schema.processlist。
3.1 SHOW PROCESSLIST老命令,新用法
一个命令打天下:
SHOW FULL PROCESSLIST;输出结果里每一行代表一个连接会话,关键字段是Id、Command、Time、State、Info。其中Info就是正在执行的SQL文本,FULL关键字能保证SQL不被截断。
重点看两个字段:Time和State。Time表示这个连接当前操作已经执行了多久,如果Time持续增长且SQL文本不为NULL,说明确实在跑一条慢SQL。State则告诉我们它到底卡在哪个阶段。
我排障时经常看到的状态有这么几种:
- Sending data:正在读取数据并发送给客户端。如果大量线程停在这个状态,说明磁盘IO或内存排序压力很大。
- Waiting for table metadata lock:等元数据锁,多半是被DDL或长事务堵住了。
- Copying to tmp table:正在做临时表排序或去重,常见于GROUP BY、ORDER BY、DISTINCT操作。
- Waiting for handler commit:等存储引擎层提交,InnoDB刷盘或组提交瓶颈时常见。
先说清楚一点:State显示Sending data不代表SQL已经执行完了,只是它正在这个阶段消耗时间。想快速判断一条SQL是不是有问题,看它User是不是业务账号、Time是否远大于你设定的long_query_time、State是否长时间不变。
3.2 information_schema.processlist:可过滤的实时视图
SHOW PROCESSLIST的输出不能直接做复杂过滤,数据量大的时候刷屏刷到你眼花。换成information_schema.processlist就能SQL查询了:
SELECT id, user, host, db, command, time, state, LEFT(info, 200) AS query FROM information_schema.processlist WHERE command <> 'Sleep' AND time > 5 ORDER BY time DESC;这条SQL把正在执行且已经跑了超过5秒的会话全都捞出来,按耗时倒序排。有时候你会看到某个连接Time已经几百秒,Info却显示NULL,这种情况多半是它卡在事务里没释放锁,或者在等待客户端发送数据,要结合innodb_trx表进一步排查:
SELECT trx_id, trx_state, trx_started, trx_mysql_thread_id FROM information_schema.innodb_trx ORDER BY trx_started ASC LIMIT 10;如果发现一个事务存在很久,其mysql_thread_id对应的会话又没有实际SQL在跑,多半是业务代码里开启了事务没提交。别急着KILL,先和业务确认,否则容易误伤正在做报表的长事务。
3.3 怎么用MAX_EXECUTION_TIME兜底
排障时不少人会直接对慢SQL执行KILL,但KILL只能治标,下线后问题SQL照样能重新进来。一个更实用的兜底是给查询设超时上限。MySQL 5.7之后支持MAX_EXECUTION_TIME提示,比如:
SELECT /*+ MAX_EXECUTION_TIME(5000) */ * FROM big_table WHERE ...这个提示要求SELECT语句在5秒内返回,否则MySQL主动终止。但要注意,这个提示对UPDATE、DELETE不生效。如果你想全局兜底,可以在账号维度用max_execution_time这个资源组参数,不过要确认你的版本支持。
我的经验是:对于核心链路的读接口,代码层也要做超时控制;MAX_EXECUTION_TIME只是数据库侧的最后一道安全带,不能指望靠它来“优化慢SQL”,它的价值是防止一条慢SQL拖垮整个实例。
4. performance_schema:不依赖日志也能精确定位“为什么慢”
慢日志告诉你“哪条SQL慢”,processlist告诉你“现在正卡在哪儿”,但它们都没回答一个关键问题:SQL慢到底慢在哪个环节?是CPU计算、磁盘IO、锁等待,还是排序临时表?performance_schema就是回答这个问题的地方。
4.1 events_statements_summary_by_digest:按语句指纹统计
这张表是性能字典里的“明星表”。它会把结构相同的SQL归一化成一个DIGEST(语句指纹),然后累计执行次数、总耗时、平均耗时、最大耗时、扫描行数、锁等待时间等。查询方式:
SELECT SCHEMA_NAME, DIGEST_TEXT, COUNT_STAR, ROUND(SUM_TIMER_WAIT / 1e12, 2) AS total_sec, ROUND(AVG_TIMER_WAIT / 1e12, 2) AS avg_sec, ROUND(MAX_TIMER_WAIT / 1e12, 2) AS max_sec, ROUND(SUM_ROWS_EXAMINED / COUNT_STAR, 2) AS avg_rows_examined FROM performance_schema.events_statements_summary_by_digest WHERE DIGEST_TEXT IS NOT NULL ORDER BY total_sec DESC LIMIT 20;SUM_TIMER_WAIT的单位是皮秒(1e12皮秒=1秒),所以除1e12转成秒。这条SQL能让你一眼看出过去一段时间里,哪个库、哪类SQL累计消耗的数据库时间最多。
这张表和慢日志最大的不同是:它统计的是“所有SQL”,不只是超过阈值的慢SQL。很多SQL单次执行只有200毫秒,没进慢日志,但一天调几百万次,累计起来比个别慢SQL占用资源更多。从这张表里,你能发现那些“基数大、单次不慢”的隐形巨头。
4.2 从“看到慢”到“知道为什么慢”:等待事件怎么读
performance_schema更大的价值在等待事件。它记录了每个线程在每个环节等了多久,比如等待磁盘IO、等待锁、等待binlog写入。查询当前累计等待时间最长的等待事件:
SELECT EVENT_NAME, COUNT_STAR, ROUND(SUM_TIMER_WAIT / 1e12, 2) AS total_wait_sec, ROUND(AVG_TIMER_WAIT / 1e12, 2) AS avg_wait_sec FROM performance_schema.events_waits_summary_global_by_event_name WHERE SUM_TIMER_WAIT > 0 ORDER BY total_wait_sec DESC LIMIT 15;如果排在最前面的是wait/io/table/sql/handler,说明瓶颈在存储引擎读写;如果是wait/io/file/innodb/innodb_data_file,说明InnoDB数据文件IO吃紧;如果大量锁等待事件,比如lock/row_lock,那多半有锁竞争。
再配合语句阶段的统计,你可以知道SQL在“解析”、“优化”、“执行”三个阶段各自花了多少时间。查询语句执行各阶段的累计时间:
SELECT EVENT_NAME, COUNT_STAR, ROUND(SUM_TIMER_WAIT / 1e12, 2) AS total_sec FROM performance_schema.events_stages_summary_global_by_event_name WHERE SUM_TIMER_WAIT > 0 ORDER BY total_sec DESC LIMIT 10;正常情况下,解析和优化阶段占比很小,大头应该在执行阶段。如果sql_statement/optimizing阶段占了很高比例,说明SQL本身太复杂或者统计信息有问题,执行计划需要优化。这一层信息,慢日志和processlist都给不了你。
4.3 容易忽略的前提:开关和清空
performance_schema不是所有采集开关都默认打开。MySQL 5.7以后一般默认开启performance_schema,但部分等待事件、阶段事件的consumer可能需要手动开启。如果查询events_waits_summary_global_by_event_name发现很多EVENT_NAME的数据都是0,先检查setup_consumers:
SELECT * FROM performance_schema.setup_consumers; SELECT * FROM performance_schema.setup_instruments WHERE NAME LIKE 'wait/io/%';另外,events_statements_summary_by_digest这类汇总表是累积的,实例跑几个月不清,总量会被历史数据占满,新的统计不明显。建议定期重置。重置语句很简单:
TRUNCATE TABLE performance_schema.events_statements_summary_by_digest;注意不要随便TRUNCATE别的汇总表,有些和会话关联的数据被清空后会影响当前统计。
4.4 人性化的sys库视图
MySQL 5.7以上自带sys库,很多视图就是把performance_schema的数据做成了“开箱即用”的报表。最常用的几个:
- sys.statements_with_full_table_scans:正在/曾经进行全表扫描的语句排行。
- sys.statement_analysis:按总耗时排序的语句分析,包含平均耗时和扫描行数。
- sys.innodb_lock_waits:当前InnoDB锁等待的详细信息,能看到谁锁了谁。
以全表扫描为例,一条SQL就能列出最严重的几条:
SELECT * FROM sys.statements_with_full_table_scans ORDER BY exec_count DESC LIMIT 5;sys库在排障时非常实用,尤其是刚接触performance_schema,还没记熟表结构的阶段,先靠sys库视图形成直觉,再回到底层表加深理解。
5. 把“发现慢SQL”变成日常机制,而不是救火行动
前面讲的都是“怎么抓”,但真正有价值的工程实践,是把这件事从“救火”变成“例行巡检”。我后面管理的实例多了之后,就不再依赖登录服务器手动敲命令了,而是设置了一套定时任务和告警,让慢SQL自己浮上来。
5.1 定时统计脚本的思路
每天凌晨数据库负载最低的时候,对前一天的慢日志做切割和统计,输出当天TOP榜。脚本思路可以很简单:
#!/bin/bash BASE_DIR=/var/log/mysql YESTERDAY=$(date -d "yesterday" +%F) SLOG=$BASE_DIR/mysql-slow.log ARCHIVE=$BASE_DIR/mysql-slow-$YESTERDAY.log # 切割 mv $SLOG $ARCHIVE mysql -e "FLUSH LOGS" # 汇总TOP20 mysqldumpslow -s at -t 20 $ARCHIVE > $BASE_DIR/report/top20-$YESTERDAY.txt建议把汇总文件按周归档,这样既能看日趋势,也能看周趋势。报表里突然出现一条之前没见过的SQL,多半是最近上线的代码或业务改动引起的。
5.2 告警怎么设才不会被误报淹没
告警的原则是“宁可漏报不可误报”,因为告警太多会让人麻木。我的做法是分两级:
第一级:慢日志里出现执行时间超过30秒的SQL就告警。这个阈值已经很高了,出现基本板上钉钉有问题。
第二级:单条SQL在10分钟内累计执行超过N次,且平均耗时超过2秒,说明它已经不只是偶发慢,而是持续消耗资源。
告警动作最好只发到固定的运维群或邮箱,不要所有人群发。通知里附上SQL文本、来源IP、平均耗时、出现次数,这样收到的人不用再登录服务器查一遍,可以直接进入优化讨论。
5.3 四种手段的定位差异
我把前面几种工具按照用途做了一张对照表,方便你在不同场景下快速选择:
| 手段 | 回答的问题 | 适合场景 | 缺点 |
|---|---|---|---|
| 慢查询日志 | 哪些SQL超过了阈值 | 事后分析、趋势统计 | 有IO开销、需要人工配置 |
| mysqldumpslow | 日志里哪类SQL最耗时 | 定期TOP榜 | 只能基于日志,无法覆盖未超时SQL |
| SHOW PROCESSLIST | 现在正在跑什么SQL | 线上故障实时排障 | 只能看当时快照 |
| performance_schema与sys | SQL慢在哪个环节 | 深度定位根因 | 数据量大、学习成本高 |
这四种手段不是互斥的,实际排障中我会组合使用。比如线上报障,先用processlist抓现场;如果没有现场,翻慢日志找TOP;定位到具体SQL后,再用performance_schema看等待事件确认瓶颈点。平时巡检则以慢日志和mysqldumpslow为主,按周看趋势。
5.4 发现本身不是终点
技术上把慢SQL找到之后,真正的工作才刚开始。常见的后续动作包括:EXPLAIN看执行计划、检查索引是否合理、评估SQL改写方案、必要时调整业务逻辑或引入缓存。慢SQL往往是“业务痛点”在数据库层的投影,比如报表查询慢的背后可能是数据模型设计问题;接口偶发超时的背后可能是连接池配置偏小。
我现在每处理一个线上慢SQL问题,都会在归档目录建一个文档,记录当时的执行计划、优化措施和优化后的效果对比。下次遇到同类问题,直接翻历史文档,比重新分析快得多。这个习惯坚持下来后,团队的数据库故障处理时间在逐步缩短,很多SQL问题看一眼就能判断大概方向,再去验证即可。
最后说一句实际体会:慢查询SQL的发现机制,最好在业务量还小的时候就搭好。等真的遇到性能问题再回头补监控,你会发现自己丢掉了最关键的历史数据,不知道这个慢SQL是从什么时候开始的,也不知道它到底是常态还是个例。早一天把日志、进程查看和性能统计跑起来,后面就能早一天从“被动救火”转为“主动优化”。如果你现在还没有任何一套机制,最简单的入手点就是把慢查询日志打开,阈值设成1秒,然后每天睡前瞄一眼当天的TOP10——这不占用多少时间,但对库的感知会完全不一样。