5.4 慢查询日志分析

5.4 慢查询日志分析

本节摘要：慢查询日志是性能治理的雷达：谁慢、慢在哪、多久犯一次，日志全记着。本节讲开启配置与参数取舍、日志字段的解读方法、聚合分析的思路，以及把个案沉淀成治理看板的做法。位置：第 5 章的收束——前几节的诊断技术，靠它才能持续命中目标。

从救火到防火

没有慢日志的团队，性能工作的形态是救火：用户投诉了、超时告警响了，才满头汗地找问题。有慢日志的团队，周一早上打开看板，上周 Top 10 慢查询已经排好队，带着执行次数、平均耗时、扫描行数。两者的差距不是技术，是基础设施。慢日志的开销极低（超阈值才写一行文本），却换来全库语句级的可观测性，是性价比最高的性能设施，没有之一。

开启与配置

SET GLOBAL slow_query_log = ON;
SET GLOBAL slow_query_log_file = 'mall-slow.log';
SET GLOBAL long_query_time = 0.5;        -- 超过 0.5 秒记入
SET GLOBAL log_queries_not_using_indexes = ON;
SET GLOBAL log_throttle_queries_not_using_indexes = 60;  -- 同类每分钟最多记 60 条
​

两个参数的取舍值得讨论。long_query_time 设 1 秒太宽松（线上 500ms 已是用户体验的痛感线），设 0.01 秒又会被海量微小查询淹没——我的习惯是生产 0.5 秒起步，优化达标后逐步收紧到 0.2。log_queries_not_using_indexes 能抓"有索引却没走"的暗坑，但会多记很多扫描小表的无害查询，用 log_throttle 限流防爆量。8.0 还支持 SET GLOBAL slow_query_log = OFF 动态开关，临时压测时灵活启停。

日志字段解读

一条慢日志长这样（有删节）：

# Time: 2026-08-28T14:22:31
# Query_time: 1.83  Lock_time: 0.00012  Rows_sent: 20  Rows_examined: 2100000
# Rows_read: 2100000
SET timestamp=1779999999;
SELECT order_id, amount FROM orders WHERE status = 2 ORDER BY created_at DESC LIMIT 20;
​

逐个看。Query_time 1.83 秒是总耗时；Lock_time 近乎为零，排除锁等待——耗时都花在执行上，去查索引；Rows_sent 20、Rows_examined 2100000，读了 210 万行只吐 20 行，效率比 0.001%，典型的排序吃不到索引（本例正是 5.3 的场景）。诊断口诀：先看 Rows_examined 与 Rows_sent 的比值，比值越大，索引欠账越多。若 Lock_time 很大而 Query_time 也大，方向则完全不同——那是锁与并发问题，转向第 6 章。

聚合分析与治理看板

单条日志好读，上万条要靠聚合。思路：按语句指纹（归一化参数后的 SQL 模板）分组，统计执行次数、总耗时、平均耗时、Rows_examined 中位数，排出治理优先级。官方与第三方都有现成工具（pt-query-digest 是社区标准），原理一致。输出通常是这样的排行：

Rank  Query ID          Calls  Sum(s)  Mean(ms)  Rows_examined
1     0x8F3A...         84213  15420   183       2100000
2     0xD02B...         1210   3400    2810      89000
3     0x77C1...         90000  2100    23        45
​

读法有讲究：别只看平均耗时。第 1 名单次 183ms 看着温和，但一天 8 万次，总耗时碾压全场，是真正的资源黑洞；第 2 名单次 2.8 秒，虽然次数少，但用户每次都撞上痛感强烈，是体验杀手。治理策略：总量黑洞先治（收益最大），体验长尾同步跟。

演练：搭一个最小治理闭环

背景：新接手一个系统，要一周内建立慢查询治理机制。操作分四步。第一步，开启慢日志（上文配置），先跑 72 小时采集基线。第二步，聚合排行，锁定 Top 5 指纹，逐条跑 EXPLAIN 归因（5.1 方法），标注病灶类型：缺索引、写法失效、排序失配、深分页。第三步，按优先级整改，每条整改前后各存一份 EXPLAIN，写进评审记录。第四步，建看板跟踪三条曲线：慢查询条数每天多少条、Top 10 指纹的总耗时、Rows_examined 中位数；并给单日慢查询数设告警阈值（比如环比上涨 50% 触发）。

结果：一周后慢查询日均值从 2 万条降到 800 条，Top 1 黑洞指纹（无索引的按客户聚合）整改后总耗时下降 97%。解读：治理闭环的关键是指纹化与复测留痕——指纹让同类问题合并治理，留痕让性能口径可追溯。变式：微服务架构下日志分散在各实例，需集中采集到日志平台再聚合；云数据库通常自带慢 SQL 分析面板，原理相通，直接用。

易错点与评审清单

• 只开日志没人看：日志落盘三个月无人翻阅等于没开，治理看板和例会审查是必要配套；
• 拿慢日志当唯一信号：它抓不到"频繁执行的快查询"累积的资源税（单次 20ms 一天百万次的指纹），需要定期按总耗时排行复查；
• 阈值一刀切：报表查询 2 秒可能正常，交易接口 300ms 已超标，按接口类型分层设阈值更科学；
• 整改无回归验证：改索引可能让另一条查询变慢（优化器成本重算），上线前对相关高频语句跑一轮 EXPLAIN 巡检。

要点回顾：慢日志是性价比最高的性能设施；long_query_time 从 0.5 起步逐步收紧；诊断口诀先看 Rows_examined 与 Rows_sent 比值；聚合排行要看总耗时不是单次均值；治理闭环四步——基线、归因、整改、看板。单机的查询优化到顶了，下一章视野上移到架构层。

慢日志到工单：一条完整处置链

慢日志的处理不该停在"看到一条慢 SQL"，而要形成从发现到验证的闭环。下面是一条真实处置链。

第一步，采集与聚合。 单条慢 SQL 没有意义，聚合后的"总耗时贡献"才有。用 pt-query-digest 对慢日志做聚合，输出按总耗时排序的指纹列表，每个指纹包含执行次数、平均耗时、扫描行数与返回行数的比值。

# 按总耗时聚合最近一天慢日志，取前 10 个指纹
pt-query-digest --limit 10 --order-by '2 DESC' slow-2026-09-01.log > digest.txt
​

第二步，判断优先级。 排序依据是总耗时而非单次耗时：一条每天跑两百万次、单次 20 毫秒的语句，比一条每天跑三次、单次 8 秒的语句更值得先动。看的是"次数乘以单次耗时"，同时参考 rows_examined / rows_sent 比值——这个比值越大，说明扫描浪费越严重，优化的想象空间也越大。

第三步，复现与定性。 把指纹还原成带真实参数的语句，在从库上跑执行计划，归到具体类别：索引缺失、索引失效、深翻页、大事务、锁等待（注意区分——锁等待表现为慢，但根因在并发，不在 SQL 本身）。这一步的交付物是一句定性结论，例如"orders 表按 merchant_id 统计的语句缺少联合索引，每次全表扫 420 万行"。

第四步，出方案并评估副作用。 加索引要考虑写入放大与磁盘占用；改 SQL 要考虑返回集合是否等价；引入缓存要考虑一致性窗口。方案里必须写明回滚方式——索引可删、SQL 可回滚、缓存可穿透，任何一条做不到就要重新设计。

第五步，灰度与验证。 先在从库验证执行计划变化，再在应用侧小流量观察，最后对比同一时间窗口的慢日志指纹：目标指纹消失或耗时下降一个量级，且没有新指纹冒头。验证通过后把结论写回工单，附上优化前后的执行计划截图。

处置链之外还有一件更重要的事：把阈值和留痕制度化。long_query_time 设成 1 秒还是 500 毫秒，取决于业务对延迟的敏感程度；慢日志保留多久，决定了一个月后还能不能追溯。评审会通常要求核心库保留不少于 30 天，并设置慢日志按天切割，避免单文件过大导致分析工具卡死。