做后端开发和数据库运维这些年我最怕听到的一句话就是“接口突然变慢了”。页面转圈、接口超时、数据库CPU飙高一顿排查下来往往无从下手。如果你也遇到过这种场景我建议你先把目光投向一个最基础也最实用的工具——MySql慢查询日志慢日志。它就像数据库的黑匣子会把每一条执行时间超过阈值的SQL原原本本记录下来告诉你是哪条语句拖慢了整体性能。这篇文章不聊空泛的理论直接从实际运维视角出发讲清楚慢查询日志的原理、开启方式、日志解读、分析工具和真实故障案例最后附上我踩坑多年的经验总结。无论你是刚接触MySQL的开发者还是已经在生产环境里摸爬滚打的DBA这篇文章都能帮你把慢查询日志真正用起来。1. 慢查询日志是什么数据库性能问题的第一现场1.1 工作原理日志是怎么把慢SQL“抓”出来的慢查询日志的机制并不复杂。MySQL在执行每一条SQL时都会记录真实的执行时间。当这条SQL的执行时间超过了我们设定的阈值默认是10秒MySQL就会把这条SQL连同执行时间、锁等待时间、扫描行数等信息原样写入到慢查询日志文件中。这个过程是MySQL Server层完成的不需要额外的插件也不会影响正常的业务逻辑。你可以把它理解成家里装了一个智能电表平时不会打扰你但一旦某个电器的功率异常超标它就会自动记录下来提醒你去检查到底是哪台设备出了问题。核心涉及三个变量slow_query_log慢查询日志的总开关值为ON或OFF。long_query_time执行时间阈值单位是秒支持小数比如0.5就代表500毫秒。slow_query_log_file日志文件的存放路径。在MySQL 5.7及以上版本中这三个参数都可以在线动态修改。这也是它比很多外部监控工具更灵活的地方——发现问题随时可以打开不需要重启数据库。1.2 为什么慢查询日志是性能优化的起点我见过不少开发同学上来就讨论索引怎么建、SQL怎么改写但问起“到底是哪条SQL慢”却一脸茫然。这就好比你去看病还没做检查就让医生开药完全是在碰运气。慢查询日志的价值就在于它提供了可量化的证据。它不只是告诉你“有一条SQL很慢”更关键的是告诉你三个信息这SQL在哪台客户端上执行的、执行了多久、扫描了多少行数据。有了这些原始线索后续的索引优化、SQL改写才能有的放矢。而且慢查询日志暴露的问题面非常广。它不仅能反映索引缺失这类常见问题还能暴露锁等待Lock_time很大、排序性能差Order by导致文件排序、深分页limit偏移量过大、隐式类型转换导致索引失效等一堆隐蔽问题。可以说慢查询日志是绝大多数MySQL性能调优的起点没有它后面所有的工作都像是盲人摸象。2. 开启慢查询日志参数配置与三种开启方式2.1 核心参数逐一说明先把涉及慢查询日志的关键参数完整过一遍。除了上面提到的三个基础参数还有几个辅助参数在实践中非常重要参数名默认值作用说明slow_query_logOFF总开关ON开启OFF关闭long_query_time10执行时间阈值单位秒超过才记录slow_query_log_file主机名-slow.log日志存储路径和文件名log_queries_not_using_indexesOFF记录所有没走索引的SQL哪怕执行时间没超阈值log_slow_admin_statementsOFF记录ALTER TABLE、ANALYZE TABLE等管理语句min_examined_row_limit0扫描行数小于该值的SQL不记录过滤小查询噪音这里重点说下log_queries_not_using_indexes。我建议在开发环境打开这个参数它可以帮你暴露出大量“跑得不算慢但根本没走索引”的SQL。这些SQL单次执行也许只花几十毫秒但在高并发场景下全表扫描带来的IO和CPU开销会被成倍放大最终拖垮整个数据库。需要特别提醒的是这个参数在生产环境要慎开。如果业务里确实存在无法避免的全表扫描SQL比如某些统计报表查询日志文件会涨得飞快。我的经验是先短期打开观测一天分析完再关掉。2.2 临时开启与永久开启两种方式各有利弊第一种临时开启在线生效重启失效-- 查看当前状态 SHOW VARIABLES LIKE slow_query_log; SHOW VARIABLES LIKE long_query_time; SHOW VARIABLES LIKE slow_query_log_file; -- 开启慢查询日志 SET GLOBAL slow_query_log ON; -- 设置阈值单位秒 SET GLOBAL long_query_time 1; -- 设置日志文件路径注意MySQL服务账号需要对目录有写权限 SET GLOBAL slow_query_log_file /data/mysql/logs/slow.log; -- 查看修改后是否生效 SHOW VARIABLES LIKE slow_query_log;注意SET GLOBAL方式修改的是全局变量对新的连接才生效已经存在的会话仍会沿用旧参数。这一点经常有人踩坑——改完参数后当前命令行窗口去查询还显示旧值让人误以为没改成功。解决办法是重新连接一次再执行SHOW VARIABLES确认。第二种永久开启写入配置文件临时开启这种方式数据库一重启就丢了。生产环境必须把配置写入配置文件让MySQL每次启动都自动加载。在Linux下编辑/etc/my.cnf在[mysqld]段落下添加[mysqld] slow_query_log ON slow_query_log_file /data/mysql/logs/slow.log long_query_time 1 log_queries_not_using_indexes ONWindows环境下配置文件通常位于MySQL安装目录下的my.ini配置方式完全一致。改完之后需要重启MySQL服务或者用SET GLOBAL动态加载一遍部分参数支持在线修改。我的习惯是先用SET GLOBAL在线打开确认不影响业务后再把配置写进my.cnf避免重启造成不必要的连接中断。2.3 阈值设置经验千万别傻等10秒long_query_time默认值是10秒但说实话10秒才抓一条慢SQL对绝大多数业务来说太迟钝了。一个接口如果有2秒的数据库查询用户体验已经很差了但这个查询根本不会被记录。这就导致很多人开了慢查询日志跑了一整天却什么都没抓到然后得出“数据库没问题”的错误结论。我个人的经验值OLTP在线事务处理业务阈值建议设置在1秒以内先从1秒起步观察几天如果日志量太大再逐步调到2到3秒如果日志量太小就下调到500毫秒。对于复杂的报表系统、BI查询可以放宽到5秒因为这类查询本身执行时间长、频率低没必要把阈值卡得太死。另外阈值修改后要注意已经开启的慢查询日志不会因为阈值调低而马上补记只有阈值调整之后新执行的SQL才会按新标准判断。这一点也容易产生误解。3. 日志内容逐步拆解看懂每一行都说了什么3.1 慢查询日志文件的实际格式日志打开后很多人面对一堆# Time开头的文本不知道从哪看起。我摘一段典型的日志片段逐行拆给你看# Time: 2025-06-21T10:24:36.872145Z # UserHost: root[root] localhost [127.0.0.1] Id: 8 # Query_time: 2.538375 Lock_time: 0.000174 Rows_sent: 1000 Rows_examined: 1250000 SET timestamp1750487076; SELECT * FROM orders WHERE status 1 ORDER BY create_time DESC LIMIT 1000;逐字段解读# TimeSQL执行的时间注意这里默认是UTC时区。如果你发现记录的时间跟本地时间对不上大概率是时区问题。可以检查time_zone参数或者直接用date命令做换算。# UserHost哪个账号、从哪个客户端IP发起的查询便于定位是哪个应用服务器产生的问题。# Query_time总执行时间这是判断是否慢查询的核心指标包含CPU执行时间和等待时间。# Lock_time锁等待时间包含行锁、表锁等待。如果这个值很大说明SQL不是在“执行”上慢而是在“等待别人释放锁”上慢要往锁竞争方向排查。# Rows_sent最终返回了多少行给客户端。# Rows_examined扫描了多少行数据这个值和Rows_sent的差距是判断索引效率的关键。SET timestamp...MySQL内部会在记录SQL前附带一条SET timestamp语句它表示下面这条SQL执行时的Unix时间戳。剩下的就是原始SQL语句。简单粗暴的判断标准如果Rows_examined几十万、几百万但Rows_sent只有几十、几百条那基本可以认定这条SQL做了大量无用功十有八九是索引缺失或者索引选择错误。3.2 日志切割与历史归档慢查询日志开启后文件会持续增长。不管理的后果就是磁盘被日志文件占满、数据库直接挂掉尤其是日志放在系统盘上的情况。我身边真实发生过数据库实例因为这个原因崩溃的案例代价非常惨痛。正确的处理方式是定期切割归档。MySQL本身没有自动切割慢日志的功能不像binlog有max_binlog_size需要我们手动操作。标准做法是利用mysqladmin flush-logs命令配合重命名# 先把当前日志改个名 mv /data/mysql/logs/slow.log /data/mysql/logs/slow_$(date %Y%m%d).log # 生成新的空文件重新打开日志句柄 mysqladmin -uroot -p flush-logs注意顺序不能反必须先mv改名再flush-logs。因为flush-logs会告诉MySQL“你现在写的是新文件”。如果你先flush再mv那么mv操作会把MySQL正在写入的文件移走导致一直在往旧文件里写新的日志内容就丢失了。把这个操作做成定时任务每天晚上凌晨执行一次日志保留30天这样既方便问题回溯又不会撑爆磁盘。脚本可以结合crontab来实现就不在这里展开写完整脚本了。4. 慢查询分析实战工具与三类典型故障定位4.1 内置工具 mysqldumpslow日志太多看不过来怎么办跑了一段时间后慢日志里积累了几百条记录人工逐条查看显然不现实。MySQL自带的mysqldumpslow工具能帮我们快速聚合日志内容它会把结构相似的SQL归为一类并统计出执行次数、总耗时、平均耗时等指标。基本用法# 按执行次数从高到低排序显示前20条 mysqldumpslow -s c -t 20 /data/mysql/logs/slow.log # 按总耗时排序显示前10条 mysqldumpslow -s t -t 10 /data/mysql/logs/slow.log # 按平均耗时排序显示前10条 mysqldumpslow -s at -t 10 /data/mysql/logs/slow.log # 输出原文不把数字抽象成N、字符串抽象成S mysqldumpslow -a -s c -t 20 /data/mysql/logs/slow.log # 只看包含指定关键词的慢SQL mysqldumpslow -g orders /data/mysql/logs/slow.log参数说明参数作用-s c按执行次数排序-s t按总执行时间排序-s at按平均执行时间排序默认是总时间看平均更有价值-s l按锁等待时间排序-t N只显示前N条结果-a不把数字和字符串抽象成N和S显示原始SQL-g pattern过滤包含指定字符串的SQL默认情况下mysqldumpslow会把SQL里的具体数字替换成N、字符串替换成S这是为了把只差参数不同的同类SQL聚合到一起。比如WHERE id 100和WHERE id 200会被视作同一条SQL统计在一起。如果只看原始SQL带-a参数就行了。这是官方自带工具的最大优势——零安装零依赖只要有MySQL客户端环境就能用。对于更高阶的需求可以考虑Percona Toolkit里的pt-query-digest它能输出更详细的统计数据甚至生成HTML报告但这个工具需要单独安装平时用mysqldumpslow其实已经能解决八成的问题了。4.2 实战案例一全表扫描导致的高Rows_examined有一次排查线上商品订单接口变慢的问题慢日志里频繁出现这样一条SQL# Query_time: 2.538375 Lock_time: 0.000174 Rows_sent: 1000 Rows_examined: 1250000 SELECT * FROM orders WHERE status 1 ORDER BY create_time DESC LIMIT 1000;扫描了125万行却只返回1000行典型的全表扫描临时文件排序。orders表当时只有id主键索引status字段是普通列没有任何索引。每次查询都要把整张表的记录全翻一遍再按create_time排序取前1000条。优化方案很简单建一个复合索引ALTER TABLE orders ADD INDEX idx_status_create_time (status, create_time);这里有个细节为什么建(status, create_time)而不是(status)或者(create_time)因为这条SQL的查询逻辑是“按status过滤再按create_time排序”复合索引(status, create_time)正好能同时覆盖过滤和排序两个需求。MySQL在扫描索引时定位到status1的记录后索引已经天然按create_time排好序了可以省掉ORDER BY带来的文件排序filesort开销。建完索引后同一个慢查询的Rows_examined从125万降到了1052Query_time从2.53秒降到了0.02秒效果立竿见影。4.3 实战案例二隐式类型转换导致索引失效接着上面订单表的问题优化完两天后慢日志里又出现了一批新SQL。这次的特点恰恰相反Query_time不算太长但频率极高。# Query_time: 0.356200 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 350000 SELECT * FROM users WHERE phone 13800138000;phone字段明明是varchar类型但SQL里直接传了一个整数。MySQL在执行比较时会把phone字段强制转换成数字类型再跟整数值比较。一旦对索引字段做了隐式转换索引就失效了MySQL只能放弃索引、走全表扫描。这种问题最难排查因为单条SQL执行只要300毫秒根本不会引起注意但QPS高的时候并发累积起来数据库的连接数和CPU都会被打满。解决办法有两个方向。第一个是把SQL改规范写成字符串形式SELECT * FROM users WHERE phone 13800138000;第二个是从代码层面根治在业务代码里就保证参数类型与字段类型一致。我更推荐后者因为只要应用层的传参逻辑不改慢日志里还会反复出现类似SQL。这类隐式转换问题在排查时有个特征EXPLAIN执行计划里possible_keys有索引但key一列为NULL或者干脆显示的rows扫描行数很大。记住这个规律下次遇到可以少走很多弯路。4.4 实战案例三深分页limit带来的排序灾难第三个案例很典型几乎每个做业务系统的都会遇到。后台管理系统的订单列表运维同事反馈翻到第5000页后接口响应时间越来越长。慢日志中捕获到的问题SQL长这样# Query_time: 5.132550 Lock_time: 0.000045 Rows_sent: 20 Rows_examined: 2280020 SELECT * FROM orders WHERE status IN (1,2) ORDER BY id DESC LIMIT 300000, 20;问题根源在于LIMIT 300000, 20。MySQL执行这条SQL时需要扫描前300020行然后把前300000行全部丢弃只留下最后20行返回。即使id主键索引存在也没用因为索引并不能直接定位到第300000行的位置。同时要注意这里用了IN (1,2)条件而解决方案里的索引idx_status_create_time在这种情况下也可能派不上用场。MySQL要先去status里面匹配两个值然后把结果合并再排序实际扫描行数依然非常惊人。这类深分页问题有几种优化方案方案一游标分页推荐改造成“记住上一页最大id”的方式-- 首页 SELECT * FROM orders WHERE status IN (1,2) ORDER BY id DESC LIMIT 20; -- 翻页传入上一页最后一条的id SELECT * FROM orders WHERE status IN (1,2) AND id 上一页最小id ORDER BY id DESC LIMIT 20;这种方式的逻辑跟微信朋友圈下拉加载类似往下翻页时只需要用id 上次看到的最后一条来过滤直接利用主键索引定位扫描行数恒定在20行左右。方案二延迟关联非连续翻页场景先利用覆盖索引查出目标id再回原表取完整数据SELECT o.* FROM orders o INNER JOIN ( SELECT id FROM orders WHERE status IN (1,2) ORDER BY id DESC LIMIT 300000, 20 ) t ON o.id t.id;子查询里id走主键索引不需要回表扫描性能比直接丢limit高几个数量级。方案三限制最大翻页深度如果是后台管理系统一个更务实的做法是限制翻页深度。用户不会真的去翻第10000页系统最多允许查看前100页超过就提示缩小查询范围。这个方案虽然“粗暴”但直接把问题根治了配合方案一使用效果最好。5. 慢查询优化里的常见坑与我的排查心得5.1 容易踩坑的几个点有了前面这些案例基础再来聊聊实践中最容易踩的坑。这些坑有些是经验问题有些是认知问题但都很容易被忽略。第一个坑是只开日志不分析。我见过很多团队慢查询日志开了好几个月日志文件积累了十几个GB却从来没人去翻过。开启慢查询日志只是工具分析并推动优化才是目的。建议每周固定花一小时用mysqldumpslow拉一份TOP10把最频繁的几条SQL逐个做EXPLAIN有条件的就优化没条件的至少心里有数。第二个坑是long_query_time没调过。很多人用默认的10秒导致日志里一年都抓不到一条记录。建议从1秒起步宁可记录多一点也不要错过问题SQL。记录多了顶多费点磁盘抓不到才是真的浪费这个功能。第三个坑是日志文件放在系统盘。这属于一个比较危险的操作慢日志增长过快时会把系统盘空间耗尽导致数据库服务异常。我个人习惯于将慢日志、binlog等都放在数据盘单独规划的目录下跟系统盘隔离。第四个坑是上线配置改了但没重启加载。永久配置写进了my.cnf但MySQL一直没重启在线又没执行SET GLOBAL导致实际上还是旧配置在运行。确认生效的方式是执行SHOW VARIABLES LIKE slow_query_log看到ON才是真的开了。第五个坑是生产环境错误地开启log_queries_not_using_indexes后全表扫描SQL刷屏。前面提到过这个参数对开发环境的索引质量审查很有帮助但在生产环境如果没有配套的告警和分析机制日志会在几个小时内暴涨到几十GB。建议先用min_examined_row_limit设置一个扫描行数下限比如10000低于这个数量的SQL就不记录这样能过滤掉大量无价值的记录。5.2 完整的排查流程清单根据我的实践一个完整的慢查询排查流程可以按下面这个步骤走开启慢查询日志阈值从1秒开始确认日志文件写入正常。运行一段时间至少覆盖一个业务高峰积累足够样本。用mysqldumpslow -s at -t 20拉取平均耗时前20的SQL。挑出频率最高的几条用EXPLAIN查看执行计划。依次检查索引是否可用、是否被隐式转换干扰、是否需要复合索引、是否触发了文件排序、是否锁等待严重。针对定位到的问题设计优化方案加索引、改SQL、改业务逻辑。优化后持续观察慢日志确认Rows_examined和Query_time是否下降。把成功案例沉淀下来纳入团队SQL开发规范。这个流程可以沉淀成团队的标准化动作。每一次优化都留下记录后续新人排查问题的时候可以直接照着走效率会高很多。我自己带的团队基本就是靠这套流程来保证线上数据库的健康度。5.3 个人经验与补充技巧最后说几个我的个人经验供你参考。第一慢日志只是起点EXPLAIN才是终点。慢日志告诉你是哪条SQL慢为什么慢要交给EXPLAIN去深挖。看执行计划的时候重点关注type列是否有ALL全表扫描、key列实际用了哪个索引、rows列预估扫描行数、Extra列是否出现Using filesort、Using temporary。这四个字段能回答95%的问题。第二留意“快但频繁”的SQL。慢查询日志默认抓的是执行时间超过阈值的但有很多SQL单次执行只有100毫秒却在每秒钟被调用几百次。这类SQL带来的总开销可能比一条慢SQL还大。分析慢日志时我会使用-s c按执行次数排序看一遍而不是只看耗时最长的。第三锁等待问题要关联监控去看。如果一条SQL的Lock_time占Query_time的比例很高说明问题不在SQL本身而在锁竞争。这时候要看information_schema.innodb_trx和performance_schema里的锁等待信息定位到阻塞源头是哪条事务没提交。单看慢日志容易把锅扣在SQL头上实际是别的事务在搞事情。第四慢查询日志用久了建议加一个“人工巡检告警”机制。纯粹靠人肉看日志总有疏忽的时候。现在很多数据库运维平台都支持对慢日志做监控告警比如每分钟慢查询数量超过阈值就报警。即使没有平台也可以写个简单的定时脚本统计日志文件大小和新增条数异常时发送通知。这样我们才能从被动救火变成主动防御。另外有一个小技巧如果遇到完全无法分析根源的“疑难杂症”先把慢日志里的时间戳和业务访问日志对齐看看那个时间点发生了什么大促活动、什么定时任务在跑往往能定位到问题全貌。数据库的性能问题从来都不只是数据库单方面的问题。
