资讯动态

MySQL慢查询日志实战:从定位到优化,彻底解决接口超时

发布时间:2026/10/9 6:24:11 来源:尧图企业网站定制
周五晚上九点多我正在家收拾东西手机报警群连续弹了几条消息线上订单列表接口 P99 飙到 4.2 秒错误率虽然不高但超时已经开始拖垮依赖它的下游服务。我打开监控面板应用 CPU 只有 20%Redis 命中率正常GC 停顿也没异常。数据层连接池的活跃连接却一直满着很明显瓶颈在 MySQL 这边。这种时候我第一个要翻的东西就是 MySQL 的慢查询日志。做 Java 后端这些年我越来越觉得慢查询日志是排查数据库问题的第一入口它不是万能的但能帮你在最短时间内把问题从接口慢缩小到某条 SQL 慢再配合执行计划定位到具体原因。这篇文章就围绕慢查询日志展开从参数配置、日志解读、执行计划分析到生产环境的运维边界和 Java 侧的配合把我实际用过的路子完整梳理一遍。无论是刚接触 MySQL 的 Java 开发还是在准备面试时被问到调优思路的候选人都能从中拿到一套可以直接落地的排查方法。1. 为什么要盯慢查询日志一次线上接口超时的定位过程1.1 排查思路的优先级排序那晚的接口超时如果按错误方向排查可能折腾一小时都找不到根因。我的习惯是从最可能的原因开始排除先看应用进程有没有假死再确认外部依赖有没有抖动接着查 Redis、MQ 这类中间件最后落到数据库层。数据库层也分几步先看连接数是否被打满再确认是不是有锁等待然后才轮到慢查询。这里有个经验之谈连接数打满往往不是原因而是结果。大量请求拥堵在数据库连接池上排队表象是获取连接超时本质可能是某几条 SQL 执行太慢导致连接被长期占用。这个时候如果不去看慢查询日志而是盲目调大连接池只会让数据库更累情况更糟。MySQL 的日志体系里跟排查相关的主要有四类错误日志记录启动、运行、停止过程中的异常binlog 用于主从复制和数据恢复general log 会记录所有 SQL生产环境几乎没人敢开刷盘压力太大慢查询日志则只记录执行时间超过阈值的 SQL。最后这个就是我定位问题最常用的工具——它精准、可控、成本相对低。1.2 慢查询日志在整个排查链路里的位置慢查询日志的价值在于它把问题直接暴露在 SQL 粒度。你不需要依赖链路追踪不需要在代码里埋点只需要确认数据库开启了慢查询记录然后在日志文件里搜索对应时间段的记录往往一眼就能看到嫌疑对象。那晚的情况就是这样。我登录服务器打开 MySQL 慢查询日志grep 出 21:00 到 21:05 之间的记录发现同一条 SQL 出现了几十次SELECT * FROM order_info WHERE user_id ? ORDER BY create_time DESC LIMIT 20平均执行时间 1.8 秒。看到这个结果问题范围一下就收窄了要么是索引没建对要么是这条 SQL 本身走了全表扫描。后续的排查全部围绕这条 SQL 展开不再瞎猜。所以说慢查询日志更像一个缩小包围圈的侦察兵。它不负责告诉你为什么慢但它能告诉你是哪条 SQL 慢、慢到什么程度、执行时扫描了多少行这些信息足以把问题定位到索引设计、SQL 写法或表结构这三类原因中去。2. 慢查询日志的开关与阈值参数细节和 5.7/8.0 的差异2.1 三个核心参数慢查询日志涉及的参数不多最核心的是下面这三个先用 SQL 看一下当前实例的状态SHOW VARIABLES LIKE slow_query_log; SHOW VARIABLES LIKE long_query_time; SHOW VARIABLES LIKE slow_query_log_file;slow_query_log慢查询日志的总开关ON 是打开OFF 是关闭。MySQL 5.7 默认是 OFF8.0 默认是 ON。long_query_time慢查询阈值单位秒默认值是 10。也就是说一条 SQL 如果执行时间超过 10 秒才会被记录。这个默认值在生产环境几乎没什么用等真有 SQL 慢到 10 秒业务早就超时到用户投诉了。我通常一上来就把它改成 1也就是 1 秒。slow_query_log_file日志文件路径。5.7 默认是主机名-slow.log8.0 默认写到数据目录下的主机名-slow.log。生产环境建议显式指定一个独立路径方便统一采集。这里插一句题外话之前有人问我 MySQL 5.7 的版本号为什么从 5.7.43 跳到 5.7.44其实版本号就是按补丁顺序递增的5.7.44 在 5.7.43 之后发布只不过 5.7 系列已经进入维护期两个版本间隔的时间会比较短。跟慢查询日志本身没什么关系只是聊到版本时顺带说一句。2.2 临时开启与会话级调试修改参数有两种方式一种是运行时动态修改用SET GLOBAL或SET SESSION另一种是改配置文件重启后永久生效。动态修改的命令是这样的SET GLOBAL slow_query_log ON; SET GLOBAL long_query_time 1;注意SET GLOBAL long_query_time只对之后新建的连接生效不会影响已经存在的连接。所以你在命令行改了之后最好重新开一个会话再查或者等应用连接池建立新连接后才生效。这一点经常有人踩坑——改了参数发现日志还在记录旧阈值的行为就怀疑是不是没生效。调试单条 SQL 时我更喜欢用会话级参数。比如有一条 SQL 执行了 800 毫秒还没到 1 秒的阈值我想确认它到底有没有被记录可以在当前会话里把阈值临时降为 0SET SESSION long_query_time 0;这样当前会话里执行的所有 SQL 都会被记入慢查询日志非常适合验证自己写的 SQL 是不是真的走了索引、执行计划有没有变化。用完记得会话结束就自动还原了不影响其他连接。2.3 永久配置与版本差异如果希望数据库重启后依然保持配置就得改配置文件。Linux 下是/etc/my.cnfWindows 下是安装目录的my.ini在[mysqld]段落里加[mysqld] slow_query_log ON slow_query_log_file /var/log/mysql/slow.log long_query_time 1 log_queries_not_using_indexes OFF关于 5.7 和 8.0 的差异我实际用下来的感受是5.7 默认关闭需要手动开启8.0 默认开启但阈值还是 10 秒实际意义有限。另外 8.0 默认把时间戳的时区记录为 UTC查日志时容易对不上时间建议在配置文件里加一行log_timestamps SYSTEM让日志时间跟服务器本地时间保持一致排查问题时能少绕一个弯。3. 一行慢查询日志怎么读字段含义与真实样本拆解3.1 一条典型慢日志的逐段解析开启慢查询日志之后文件里每一条记录长这样这是我在测试环境实际跑出来的一条数据# Time: 2025-11-15T21:03:22.18847208:00 # UserHost: app_user[app_user] [10.0.0.12] Id: 123456 # Query_time: 1.824631 Lock_time: 0.000148 Rows_sent: 20 Rows_examined: 186432 use ecommerce; SET timestamp1700053402; SELECT * FROM order_info WHERE user_id 1234567 ORDER BY create_time DESC LIMIT 20;很多人拿到日志只盯 Query_time这没错但信息量太少了。我把每一行拆开说TimeSQL 执行的时刻精确到微秒。结合log_timestamps SYSTEM之后这块跟应用日志的时间就能对齐了。UserHost执行这条 SQL 的数据库账号和来源 IP。这一行很有用如果多个应用共用一个 MySQL 实例你可以通过它快速区分是哪个应用产生的慢 SQL。后面那个 Id 是线程 ID可以跟SHOW PROCESSLIST对应。Query_timeMySQL 服务器端执行这条 SQL 的总耗时包含解析、优化、执行等阶段。注意它不包含应用服务器到数据库之间的网络传输时间所以经常出现数据库日志显示 0.5 秒应用侧却感觉 1.5 秒的情况剩下的时间可能花在应用拿结果、序列化、等待连接上了。Lock_time锁等待时间。如果这个值明显偏大说明 SQL 不是在算而是在等。常见于高并发下对同一行记录的更新或者SELECT ... FOR UPDATE与普通查询之间的阻塞。Rows_sent最终返回给客户端的行数。结果集只有 20 行说明业务上要的数据量不大问题不在这里。Rows_examined执行过程中实际扫描的行数。18 万多行这就是问题本尊——为了返回 20 条数据扫描了 18 万行典型的索引缺失或索引失效。3.2 Query_time 和 Rows_examined 的关系是判断重点我判断一条慢 SQL 属于什么类型问题主要看 Query_time 和 Rows_examined 的组合。如果是扫描行数大、返回行数少几乎可以断定是查询路径设计问题要么没走索引要么索引没覆盖到查询条件。这种情况在订单表、用户表、日志表这类数据量大的表上尤其常见。还有一种情况是 Rows_examined 不算大比如就扫了几千行但 Query_time 依然很高。这时候要关注的就不单纯是索引了可能是 MySQL 在排序、临时表、或者大字段传输上吃了亏。比如ORDER BY走了文件排序filesort或者查询中间产生了临时表带的字段里有 TEXT、BLOB 类型导致排序成本飙升。这些在 EXPLAIN 的 Extra 列里能看到端倪。另外日志里的 SQL 文本是完整语句带参数值。有人觉得写日志文件很占空间其实它帮了大忙——你把参数值直接拿去 EXPLAIN 分析或者复现问题非常方便。但要注意慢查询日志里的 SQL 文本是原样记录的如果应用里用了 MyBatisSQL 可能是这样式儿的占位符版本参数值单独记录在SET timestamp附近的注释里别搞混。3.3 用 mysqldumpslow 快速聚合日志文件积攒一段时间后逐条看是不现实的。MySQL 自带了一个聚合工具叫mysqldumpslow用法不难# 按平均执行时间排序取前 10 条 mysqldumpslow -s t -t 10 /var/log/mysql/slow.log # 按出现次数排序取前 10 条 mysqldumpslow -s c -t 10 /var/log/mysql/slow.log # 只看包含 order 的 SQL按时间排序 mysqldumpslow -s t -g order /var/log/mysql/slow.log这个工具会做变量值的归一化把数字替换成 N把字符串替换成 S所以同样一条 SQL 只有参数不同的多次执行会被聚合成同一条记录。比如SELECT * FROM order_info WHERE user_id 1234567和WHERE user_id 7654321会合并成WHERE user_id N统计。实际用的过程中-s t按平均耗时排序更适合找单次最慢-s c按次数排序更适合找高频慢查询。比如那晚的订单列表接口按次数排完SELECT * FROM order_info WHERE user_id N ORDER BY create_time DESC LIMIT N排第一出现 87 次平均耗时 1.7 秒这就是要优先处理的 SQL。4. 顺着慢 SQL 挖根因EXPLAIN 执行计划的关键列4.1 type 与 key先看这两列拿到一条慢 SQL我的惯例是立刻跑一次 EXPLAIN看它到底怎么执行的。还是用那晚的 SQL 做例子EXPLAIN SELECT * FROM order_info WHERE user_id 1234567 ORDER BY create_time DESC LIMIT 20;执行计划里最需要注意的是type和key两列。key显示这条 SQL 实际用到的索引如果结果是 NULL说明一张 18 万行的表在裸扫。type表示访问类型从好到差大致是type 值含义我的直观理解system/const主键或唯一索引等值查询最多返回一行直接命中目标效率最高eq_ref被驱动表通过主键或唯一索引关联多表 JOIN 时的理想情况ref通过普通索引等值匹配返回多行常用且健康的状态range索引范围扫描比如 BETWEEN、IN、 还能接受但要注意范围大小index扫描整棵索引树索引全扫有时候比 ALL 好点但也是问题ALL全表扫描慢 SQL 的重灾区那晚的 EXPLAIN 结果我记得很清楚type 是 ALLkey 是 NULLrows 显示 186432。这三项一连起来结论就摆在眼前——user_id上没有可用的索引MySQL 只能把整张表翻一遍。4.2 我遇到过的三类索引失效全表扫描是最好认的但实际生产里还有三类更隐蔽的索引失效问题慢查询日志里同样会暴露出来我一个个说。第一类是函数包裹索引列。比如WHERE DATE(create_time) 2025-11-15日子一长表数据量一大这个查询就会在慢查询日志里频繁出现。原因是 MySQL 对索引列做完函数计算之后原来的索引顺序就失效了只能全扫。优化办法是改成范围查询WHERE create_time 2025-11-15 00:00:00 AND create_time 2025-11-16 00:00:00。第二类是隐式类型转换。有个索引列是 VARCHAR 类型比如手机号字段mobile写条件时图省事传了个数字WHERE mobile 13800138000。MySQL 会把列值转成数字跟常量比较索引就废了。改成一个字符串WHERE mobile 13800138000执行计划立刻就不一样了。这类问题很容易被忽略因为小数据量时看不出来数据量一大就上慢查询日志。第三类是 OR 条件导致索引失效。比如WHERE user_id 123 OR status 1只要其中一个条件没有索引整个查询就可能退化成全表扫描。建议拆成两个查询用 UNION 合并或者给status也建上合适的索引。4.3 优化后的验证方法找到根因之后不能改完就完事。我会重新执行 EXPLAIN 确认执行计划变了再实际跑一遍 SQL 看耗时降了多少。这不是形式主义——有时候你以为加了索引结果因为前缀长度、排序方向或者字符集不一致索引压根没生效。那晚我给order_info表加了联合索引(user_id, create_time)原因很简单查询条件是等值的user_id排序是create_time这个联合索引既能精确定位用户的数据又能让排序直接利用索引顺序省掉 filesort。之后重新 EXPLAINtype 从 ALL 变成了 refkey 显示新索引名rows 只剩 20 左右。再跑一次 SQL执行时间从 1.8 秒降到 20 毫秒接口 P99 也跟着掉下来了。如果加了索引还是不理想我会顺手看一眼 Extra 列有没有Using filesort或Using temporary。这两个词出现时MySQL 在额外干活排序如果没走索引会把数据先放进内存或磁盘排序Using temporary更是直接说明它建了临时表。这类 SQL 即使没到慢查询阈值也是潜在的性能隐患值得提前优化。5. 慢查询日志的运维边界别开着开关就撒手5.1 日志写入的代价慢查询日志既然这么好用是不是干脆一直开着不关我的答案是开可以但别开得太放任。日志写入是有 IO 代价的。尤其是把long_query_time设得很低比如 0.1 秒再加上log_queries_not_using_indexes ON慢查询日志可能每分钟写几万行磁盘 IO 被日志刷盘占掉不少反而影响正常业务。我见过一个案例某团队把阈值设成 0日志文件一天涨了 20G最后把数据盘写满了数据库直接只读事故比原来的慢查询还严重。这里要区分一个概念log_queries_not_using_indexes记录的是没走索引的 SQL不是慢的 SQL。有些小表只有几百行全表扫描也就一两毫秒本来不是问题但开着这个参数就会把它们全记进日志制造大量噪音把真正需要关注的慢 SQL 淹没掉。5.2 文件轮转和空间控制日志文件无限增长是另一个必须提前处理的问题。MySQL 不会自动切割慢查询日志文件需要外部工具或者手动轮转。我常用的手动方式是这样的# 1. 重命名当前日志文件 mv /var/log/mysql/slow.log /var/log/mysql/slow.log.20251115 # 2. 让 MySQL 重新生成新的 slow.log mysql -e FLUSH SLOW LOGS;FLUSH SLOW LOGS会让 MySQL 关闭当前日志文件重新按slow_query_log_file指定的路径创建新文件这样旧文件就可以归档或删除了。如果你的服务器装了 logrotate也可以直接配一条规则按天或按大小轮转原理是一样的。实际操作中我还会配一个脚本每天检查日志文件大小超过 500M 就轮转一次保留最近 7 天的归档。这个数字不是绝对的主要看你实例的慢查询数量但原则是明确的日志文件不能无限膨胀归档要有保留策略。5.3 参数组合的建议经过多次线上折腾我目前比较推荐的组合是这样的参数测试环境生产环境slow_query_logONONlong_query_time0.21log_queries_not_using_indexesONOFFmin_examined_row_limit01000log_slow_admin_statementsOFFOFFlog_slow_admin_statements默认是不记录 ALTER TABLE 这类管理语句的我建议保持关闭。DDL 本来就慢如果也被记进慢查询日志会干扰对业务 SQL 的分析。min_examined_row_limit是另一个有用的过滤条件表示扫描行数少于多少的不记录。生产环境我常设成 1000这样即使某些 SQL 没走索引只要扫描行数极少也不会产生日志噪音。它比单纯依赖执行时间更能过滤掉无意义记录因为扫描行数少的时候即使因为某种原因耗时略高影响面也有限。生产环境还有一个不太起眼的注意点查询慢查询日志内容时建议用tail或less别直接cat。日志文件大起来之后cat会把整个文件读进内存本身就是一个不小的 IO 操作。我吃过多线程grep大日志拖慢数据库的亏从那之后凡是看日志先ls -lh看大小再决定怎么读。6. 慢查询治理不是数据库单方面的事Java 侧怎么配合6.1 连接池与 ORM 层面的辅助慢查询日志是数据库视角的工具但治理慢查询不能只盯着数据库看。我在 Java 项目的日常维护里还会从应用侧做几件事来配合。第一是连接池的慢 SQL 统计。我们项目用的是 Druid它自带 SQL 监控。在连接池配置里开启StatFilter之后控制台上能看到每个 SQL 的执行次数、总耗时、最大耗时还能设置慢 SQL 阈值做标记。这相当于在应用侧又多了一层慢查询感知比起翻数据库日志更实时。如果你的项目用 HikariCP它没有内置慢 SQL 统计那就需要自己在 MyBatis 拦截器或者 Spring AOP 里做一层耗时统计。拦截的方法也很简单记录Around切面里 DAO 方法的耗时超过 500 毫秒就打印告警日志带上参数和 SQL。第二是 ORM 框架的 SQL 输出。MyBatis 的mybatis.configuration.log-impl设为标准日志输出可以打印出真实执行的 SQL 和参数。结合慢查询日志里那条 SQL 的文本能在应用代码里快速定位到对应的 Mapper 方法。这里有个小经验生产环境不要一直开着 SQL 全量打印IO 和日志量都受不了可以用一个开关控制排查时开半小时查完关掉。6.2 索引设计与 SQL 写法上的三个高频坑慢查询日志看得多了你会发现出问题的 SQL 翻来覆去就是那几类。Java 后端写 SQL 时有三个高频坑值得提前规避。第一个是SELECT *。Java 代码里图省事写了select *返回到应用层却发现只需要其中两三个字段。不仅网络传输多还断了覆盖索引的可能性。覆盖索引是优化查询的利器——如果索引本身包含了查询需要的所有列MySQL 就不用回表直接扫描索引就返回结果。一旦select *回表几乎不可避免。第二个是深分页。LIMIT 100000, 20这类写法看着是只要 20 条MySQL 实际要把前 10 万行全扫出来再丢掉。慢查询日志里这类 SQL 特别多。我的优化办法是延迟关联先通过覆盖索引查出主键再用主键关联回原表取完整行。或者改造成基于游标的分页用WHERE id last_max_id ORDER BY id LIMIT 20前提是业务允许这种分页方式。第三个是联合索引的字段顺序。建索引时把等值条件字段放前面排序字段放后面才可能同时服务过滤和排序。字段顺序反了order_info表那个例子就是现成反面教材——只给user_id建了单列索引排序还是要额外 filesort。索引不是越多越好但每个常用查询路径至少该有一个能接住它的联合索引。6.3 把慢查询分析变成日常巡检最后聊一个方法论层面的经验慢查询日志不应该是出了事故才去翻的东西。我现在的习惯是每周固定一次从慢查询日志里导出数据按出现次数和平均耗时排序看看有没有新冒出来的慢 SQL。很多问题在变成严重事故之前早就在日志里露出了苗头——某个接口的 SQL 执行时间从 50 毫秒慢慢涨到 800 毫秒期间可能持续了两周如果没人看日志就会一直被忽视直到触发告警。配合这个习惯我还会把 mysqldumpslow 的结果跟应用发布记录做对比。很多慢查询是发版后引入的某个同事改了一条 SQL 的写法或者一个上线的新功能带了低效的查询。如果巡检日志的时机刚好卡在发版之后很容易就能定位到是哪次变更引入了性能退化。MySQL 的慢查询日志并不复杂核心就是开关、阈值、文件位置三个参数加一个 mysqldumpslow 聚合工具。但它串联起来的排查链路是完整的从日志发现慢 SQL到 EXPLAIN 分析执行计划再到索引设计和 SQL 改写最后验证效果并沉淀为巡检项。这套流程我用了很多年每次遇到性能问题都靠它快速收窄范围。如果你现在连慢查询日志都还没打开我建议今天就先按文章里的参数组合配起来等哪天线上真出问题的时候你会发现这个开关救了大忙。

读完文章,也想定制专属网站?

尧图设计师 24 小时内与您沟通定制方案

免费获取报价 →
↑