Files
2026-05-24 11:42:38 +08:00

23 KiB
Raw Permalink Blame History

tags, create time
tags create time
MySQL
慢查询日志
pt-query-digest
性能分析
EXPLAIN
2026-05-16 10:30

慢查询日志分析

概述

慢查询日志(Slow Query Log)是 MySQL 自带的性能诊断工具,记录超过指定时间的 SQL 语句。配合 pt-query-digest 等专业工具,可以系统地识别和优化慢查询,定位数据库性能瓶颈。

[!TIP] 核心思路 慢查询日志本身只是"记录仪"——真正的价值在于归因分析。将日志中的原始数据聚合、分类、排名,才能把噪音变成可行动的信号。

配置慢查询日志

# my.cnf
[mysqld]
slow_query_log            = 1                    # 开启
slow_query_log_file       = /var/log/mysql/slow.log
long_query_time           = 2                    # 阈值(秒)
min_examined_row_limit  = 100                  # 只记录扫描了至少 N 行的查询
log_queries_not_using_indexes = 1              # 记录未使用索引的查询

# 可选:实时捕获到表
log_output               = FILE,TABLE          # 同时写入文件和 mysql.slow_log 表
-- 运行时动态开启(无需重启)
SET GLOBAL slow_query_log = 'ON';
SET GLOBAL long_query_time = 1;
SET GLOBAL log_queries_not_using_indexes = 'ON';

-- 查看当前配置
SHOW VARIABLES LIKE 'slow_query%';
SHOW VARIABLES LIKE 'long_query_time';

[!WARNING] 生产环境注意事项

  • 不要盲目设置极低的 long_query_time(如 0.1s),否则会产生大量噪声。建议从 1~5 秒开始逐步下调。
  • 开启 log_queries_not_using_indexes 会让所有无索引查询都被记录,即使它们只需要 0.01s。谨慎启用,最好配合 min_examined_row_limit 过滤无害查询。
  • TABLE 模式会往 mysql.slow_log 写数据,需要评估写入开销。如果已有 FILE 模式,优先选 FILE。
  • DDL 语句(ALTER TABLE、CREATE INDEX)默认不记录到慢查询日志。如有需要可开启 log_slow_admin_statements = 1,排查大表 DDL 阻塞。

min_examined_row_limit

-- 设置 1000 意味着:只扫描了 < 1000 行的查询不会被记录
-- 过滤掉大量无害查询,让慢日志专注于真正有问题的 SQL
SET GLOBAL min_examined_row_limit = 1000;

[!NOTE] 为什么需要这个参数? 一个看似"快"的查询可能扫描了大量行才找到目标数据——比如一次全表扫描回查 50 万行最终返回 1 条结果。这样的查询单看执行时间并不长(缓存命中时不到 0.1s),但放在高并发下就是 CPU 杀手。min_examined_row_limit 就是从扫描行数维度额外加了一层拦截。

慢查询日志格式

每一条慢查询由元数据头 + 时间戳锚点 + SQL 体三部分组成:

# Time: 2026-05-16T10:30:45.123456Z         ← 执行时间(UTC)
# User@Host: app_user[app_user] @ app-server-01 [10.0.1.50]  Id:  12345  ← 哪个用户、哪台机器、连接 ID
# Query_time: 3.456789  Lock_time: 0.000123 Rows_sent: 1  Rows_examined: 985432  ← 核心指标
# Rows_affected: 0                             ← 影响的行数(DML)
# Bytes_received: 512  Bytes_sent: 65432     ← 网络传输量
# Thread_id: 12345  Schema: app_db           ← 线程 ID、所属数据库
SET timestamp=1715848245;                    ← 锚点:SQL 实际执行时的 Unix 时间戳
SELECT o.*, u.username FROM orders o          ← SQL 语句本体
JOIN users u ON o.user_id = u.id
WHERE o.status = 'pending' AND o.amount > 100
ORDER BY o.created_at DESC LIMIT 20;

[!NOTE] SET timestamp=1715848245; 是什么? 这行不是用户执行的 SQL,而是 MySQL 自动注入的时间锚点。它的作用是:当你用 mysql < slow.log 回放这条慢查询时,MySQL 会用这个 Unix 时间戳作为 NOW() 的基准,确保时间相关函数(NOW()、CURDATE() 等)在回放时的值与原始执行时一致。不影响执行计划,仅供回放使用。

关键字段含义

字段 含义 关注点
Query_time 从接收请求到返回结果的总耗时 > long_query_time 即触发记录
Lock_time 等待行锁/表锁的时间 占比过高 → 存在锁竞争
Rows_sent 返回给客户端的行数 应用层真正收到的结果
Rows_examined InnoDB 引擎扫描的索引+数据行数 与 Rows_sent 差距越大越危险
Rows_affected INSERT/UPDATE/DELETE 实际变更的行数 DML 操作的副作用评估

[!QUESTION] 如何判断查询效率是否健康?

Rows_examined / Rows_sent < 10    → ✅ 合理——每条扫描的行大部分都返回了
Rows_examined / Rows_sent > 100   → ⚠️ 可疑——可能是全索引扫描或回查过多
Rows_examined / Rows_sent > 1000  → 🔴 严重低效——典型的全表扫描或错误的 WHERE 条件

理想情况是比值接近 1。但需注意:对范围查询来说,这个比值高一些是正常的(因为 B+Tree 范围内每页都要读)。

Lock_time 专项解读

Lock_time 占 Query_time 的比例越大,说明查询在"等锁"而非"执行"上浪费了越多时间。下面的诊断路径帮你快速判断严重程度:

flowchart LR
    A["计算 Lock_time / Query_time"] --> B{"< 1% ?"}
    B -- "是" --> C["🟢 正常,无锁问题"]
    B -- "否" --> D{"< 10% ?"}
    D -- "是" --> E["🟡 轻度竞争,可接受"]
    D -- "否" --> F{"< 50% ?"}
    F -- "是" --> G["🟠 需排查:长事务 or 未命中索引"]
    F -- "否" --> H["🔴 紧急:大概率死锁或锁升级"]

mysqldumpslow 内置工具

MySQL 自带的轻量级日志分析工具,适合快速查看 Top N:

# 最常用的参数组合:按执行时间排序,取前 10 条
mysqldumpslow -s t -t 10 /var/log/mysql/slow.log
# -s t: 按 Query_time 排序;-t 10: 取前 10 条

# 按扫描行数排序(关注"杀 CPU"的查询)
mysqldumpslow -s r -t 10 /var/log/mysql/slow.log

# 按出现频率排序(关注高频小额查询累积成的大问题)
mysqldumpslow -s c -t 10 /var/log/mysql/slow.log

# 只看包含特定关键词的
mysqldumpslow -s t -t 20 -g "order" /var/log/mysql/slow.log

输出解读

Count: 150  Time=3.50s (525s)  Lock=0.00s (0s)  Rows=1.0 (150), app_user@app-server-01
  SELECT o.*, u.username FROM orders o JOIN users u ON o.user_id=u.id
  WHERE o.status='pending' AND o.amount>100 ORDER BY o.created_at DESC LIMIT N
字段 含义
Count: 150 该模式在日志中出现了 150 次
Time=3.50s 单次平均执行 3.5 秒
(525s) 150 次累计占用 525 秒——这才是对生产真正造成伤害的数字
Rows=1.0 (150) 每次返回约 1 行,累计 150 行

[!NOTE] Count × Average = Total 的意义 Time=3.50s (525s) 揭示了一个关键思路:优化一个频繁执行的中等耗时查询,往往比优化一个极端耗时的罕见查询收益更大。这就是为什么 -s c(按频率排序)有时能发现更隐蔽的性能问题。

使用限制

mysqldumpslow 的输出较为粗糙,它只能做聚合统计,无法提供:

  • SQL 指纹归因的详细分组(哪些参数值不同但 SQL 结构相同)
  • 趋势对比(和上次报告相比变化了多少)
  • HTML 可视化报告

对于系统性诊断,推荐使用 pt-query-digest。

pt-query-digest(专业分析工具)

Percona Toolkit 中最强大的 MySQL 分析工具,支持日志文件、Performance Schema、甚至直连生产库实时采样:

# 基本用法:输出完整分析报告
pt-query-digest /var/log/mysql/slow.log

# 按响应时间分组排名
pt-query-digest --group-by latency /var/log/mysql/slow.log

# 只分析报告 Top 5% 的查询(保留细节,去掉噪声)
pt-query-digest --limit 5% /var/log/mysql/slow.log

# 与历史基线对比(需提前用 --review/--history 采集数据)
pt-query-digest --review D=perflive,h=localhost \
                --history D=perflive,h=localhost \
                /var/log/mysql/slow.log

# 生成 HTML 可视化报告
pt-query-digest --output=slowreport.html /var/log/mysql/slow.log

# 分析最近 1 小时的慢查询
pt-query-digest --since 1h /var/log/mysql/slow.log

# 分析最近 30 分钟且执行时间 > 1s 的查询
pt-query-digest --since 30m --filter '$event->{qt} > 1000000' /var/log/mysql/slow.log

输出解读框架

pt-query-digest 的报告分为四个核心区域:

===== Profile (整体概况)
 Rank Query ID           Response time  Calls R/Call V/M   Item
 ==== ================= ============== ===== ====== ===== ===========
    1 0xA1B2C3D4       525.1234 50.0%   150 3.5008  0.00 SELECT orders
    2 0xE5F6A7B8       180.5678 17.2%    50 3.6114  0.00 SELECT users

===== Query 1: Hash = 0xA1B2C3D4
  # 该查询模式的详细统计(P95, Q3, Q1 等百分位)
  # Count: 150        → 出现次数
  # Exec time: 1~8s   → 单次执行时间范围
  # Lock time: ...    → 锁等待分布
  # Rows sent: 1 avg  → 返回行数(平均值/中位数/最大最小)
  
  # EXPLAIN output  → 执行计划(最关键部分!)
  # The query is above that you can use EXPLAIN to analyze
区域 作用
Profile 快速了解哪些查询占了大部分资源——通常是 Pareto 20/80 规律
Query N 单个查询模式的详细统计,包含执行计划
Flattened SQL 归一化后的指纹,展示参数替换前后的差异

[!TIP] 标准诊断流程 拿到 pt-query-digest 报告后:先看 Profile 找出 Top 3 耗时查询 → 再逐条看其 EXPLAIN 输出 → 最后决定优化方向。不要一开始就陷入某一条 SQL 的细节。

从实时 Performance Schema 分析

当慢查询日志未开启或已关闭时,可以直接从 MySQL 内部采集:

-- MySQL 5.7+ 启用 performance_schema
SET GLOBAL performance_schema = ON;

-- 清理已有数据(可选,重置统计基线)
TRUNCATE performance_schema.events_statements_summary_by_digest;

等业务跑一段时间后,用 pt-query-digest 直接从 Performance Schema 提取分析:

# 方式一:基于 processlist 实时采样
pt-query-digest --processlist D=localhost,U=root \
                --no-report /var/log/mysql/slow.log

# 方式二:直接从 digest 表提取
pt-query-digest --type processlist D=host:port,user,password

SHOW PROFILE(单条 SQL 微观分析)

pt-query-digest 和 mysqldumpslow 解决的是"哪些 SQL 慢"的宏观问题;而当你已经定位到一条具体的慢 SQL,想进一步搞清楚它的时间花在哪个阶段时,就需要 SHOW PROFILE。

[!TIP] EXPLAIN vs SHOW PROFILE

  • EXPLAIN:告诉你查询将会怎么执行(执行计划),是"预言家"
  • SHOW PROFILE:告诉你查询已经怎么执行(各阶段耗时),是"回放仪" 两者互补:先 EXPLAIN 看计划是否合理,再 PROFILE 看执行时到底慢在哪。
-- 开启当前会话的 profiling
SET profiling = 1;

-- 执行你的目标 SQL
SELECT o.id, o.status, o.amount
FROM orders o
WHERE o.user_id = 100 AND o.status = 'pending'
ORDER BY o.created_at DESC LIMIT 20;

-- 查看最近一次查询的各阶段耗时
SHOW PROFILE;

-- 更详细:查看 CPU 和 Block IO
SHOW PROFILE CPU, BLOCK IO FOR QUERY 1;

典型输出:

+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000089 |
| checking permissions | 0.000012 |
| Opening tables       | 0.000035 |
| init                 | 0.000025 |
| System lock          | 0.000015 |
| optimizing           | 0.000018 |
| statistics           | 0.000042 |
| preparing            | 0.000020 |
| executing            | 0.000008 |
| Sending data         | 0.452300 | ← ⚠️ 99% 的时间在这里
| end                  | 0.000012 |
| query end            | 0.000008 |
+----------------------+----------+

[!NOTE] 如何解读各阶段

阶段 含义 如果占比过高意味着什么
Sending data 扫描行、返回结果集 索引不佳或结果集过大
Sorting result 排序操作 缺少 ORDER BY 对应索引
Creating tmp table 创建临时表(内存/磁盘) GROUP BY / DISTINCT 无法走索引
System lock 等待表锁 存在锁竞争
statistics 优化器统计信息收集 统计信息过旧,需 ANALYZE TABLE

[!WARNING] 版本兼容性 SHOW PROFILE 在 MySQL 8.0 中已被标记为废弃(deprecated),官方推荐迁移到 performance_schema.events_statements_* 表。但在 MySQL 5.7 以及快速排查场景下,它依然是最轻便的选择。

常见慢查询反模式

即使有索引,SQL 写法不当也会导致索引失效。以下是生产中最常见的几种反模式:

反模式 示例 为什么慢 优化方向
前导通配符 WHERE name LIKE '%abc' 无法使用 B+Tree 前缀匹配,全表扫描 改用全文检索 (FULLTEXT)
隐式类型转换 WHERE phone = 13800138000 (phone 是 VARCHAR) 字符型字段与数字比较触发隐式转换,索引失效 传参类型与列类型一致
OR 条件未覆盖 WHERE idx_col = 1 OR other_col = 2 只有第一个字段有索引 拆分 UNION ALL 或用 BITMAP
函数包裹列名 WHERE YEAR(created_at) = 2025 对列计算函数导致索引失效 改为范围扫描:created_at >= '2025-01-01' AND created_at < '2026-01-01'
NOT IN / <> WHERE id NOT IN (SELECT id FROM ...) 子查询难以走索引 改写为 LEFT JOIN ... IS NULL
SELECT * SELECT * FROM orders WHERE ... 回表额外开销 + 网络传输浪费 只查需要的列

[!QUESTION] 为什么 SELECT * 会拖慢查询? 有两个原因:

  1. 回表:如果用的是二级索引(非聚簇),SELECT * 需要拿着二级索引的值去聚簇索引回表取出所有列数据;而如果只 SELECT 了索引中包含的列,则可以直接"覆盖索引"取数,无需回表。
  2. 带宽浪费:即使通过聚簇索引取数,多取的每列也会占用更多内存缓冲和网络传输时间。在高频查询场景下,每次省 2KB,一万次就是 20MB 的额外开销。

慢查询优化工作流

从发现慢查询到完成优化的完整闭环:

flowchart TD
    A["收集慢查询日志"] --> B["分类归因<br/>pt-query-digest / mysqldumpslow"]
    B --> C{"定位 Top 瓶颈 SQL"}
    
    C --> D["EXPLAIN 执行计划分析"]
    D --> E{问题类型?}
    
    E -- "type=ALL" --> F["缺索引 → ADD INDEX"]
    E -- "Extra: Using filesort" --> G["调整联合索引顺序 / 覆盖索引"]
    E -- "Extra: Using temporary" --> H["改写 SQL,避免 GROUP BY 临时表"]
    E -- "rows 过大但 sent 很小" --> I["检查 WHERE 条件是否命中索引"]
    E -- "无锁等待但耗时高" --> J["排查深层原因:深分页/大事务/函数包裹列"]
    E -- "Lock_time 占比高" --> K["排查死锁 / 长事务 / 行锁竞争"]
    
    F --> L["优化后验证"]
    G --> L
    H --> L
    I --> L
    J --> L
    K --> L
    
    L --> M{"效果达标?"}
    M -- "是" --> N["🎉 上线 + 接入监控告警"]
    M -- "否" --> D

步骤详解

Step 1: 收集与分组

通过 pt-query-digest 将原始日志中的千条记录压缩为几十条"SQL 指纹"。每一条指纹代表一个查询模式,忽略参数差异(如 '123' vs '456'),聚焦结构。

Step 2: 定位 TOP N

按以下优先级排序关注对象:

场景 排序方式 适用情况
总耗时最大 -s t(总时间) 找最拖后腿的 SQL
最常见 -s c(频率) 高频小额查询累积成痛
扫描行数最多 -s r(Rows_examined) CPU 杀手型查询

Step 3: EXPLAIN 诊断

对 Top 3 的查询逐条执行 EXPLAIN FORMAT=JSON ... 获取结构化执行计划:

EXPLAIN FORMAT=JSON SELECT * FROM orders
WHERE user_id = 100 AND status = 'pending'
ORDER BY created_at DESC LIMIT 10;

重点关注 JSON 输出中的:

  • table->access_type(扫描方式:ALL / range / ref / index)
  • table->key(实际使用的索引)
  • table->rows(预估扫描行数)
  • query_block->filesort / temporary_table 是否存在

更详细的 EXPLAIN 解读见 hhs/MySQL/03-索引与查询优化/15-EXPLAIN 完全指南。

Step 4: 针对性优化

根据诊断结果选择优化策略:

flowchart LR
    subgraph "索引类优化"
        A1["补充缺失索引"] --> A3["验证:type 从 ALL→ref/range"]
        A2["调整联合索引顺序"] --> A3
        A4["创建覆盖索引"] --> A5["Extra 去掉 Using filesort/index"]
    end
    
    subgraph "SQL 改写"
        B1["LIKE '%xxx' → FULLTEXT"]
        B2["YEAR(col) → range 扫描"]
        B3["NOT IN → LEFT JOIN IS NULL"]
        B4["验证:rows↓, time↓"]
        B1 --> B4
        B2 --> B4
        B3 --> B4
    end
    
    subgraph "架构类优化"
        C1["深分页 OFFSET → 延迟关联"]
        C2["大事务拆小"]
        C3["读写分离 / 缓存"]
        C4["验证:P95 latency ↓"]
        C1 --> C4
        C2 --> C4
        C3 --> C4
    end

详见:

Step 5: 回归验证 & 监控接入

优化不是一次性动作,需要建立持续监控机制:

[!TIP] 最小可落地的监控方案

-- 定期从 Performance Schema 拉取 Top SQL
SELECT DIGEST_TEXT,
       ROUND(SUM_TIMER_WAIT/1e12, 2) AS total_ms,
       COUNT_STAR AS calls,
       ROUND(AVG_TIMER_WAIT/1e12, 2) AS avg_ms
FROM performance_schema.events_statements_summary_by_digest
ORDER BY total_ms DESC
LIMIT 20;

将此查询放入定时任务(如每 5 分钟),用 Grafana 或 Prometheus 做可视化告警。

日志轮转与清理策略

慢查询日志是持续增长的——高流量系统一天可以产生数 GB 的慢日志。没有轮转策略,磁盘会被撑满,甚至影响 MySQL 正常写入。

[!WARNING] 真实案例 曾有团队开启了慢查询日志但忘了清理,3 个月后磁盘 100%,MySQL 被迫停止服务。日志文件本身变成了"生产事故"。

方案一:MySQL 原生轮转

# 手动轮转(适合简单场景)
mv /var/log/mysql/slow.log /var/log/mysql/slow.log.$(date +%Y%m%d)
mysql -e "FLUSH SLOW LOGS;"   # 让 MySQL 重新打开新的 slow.log

方案二:logrotate(推荐)

# /etc/logrotate.d/mysql-slow
/var/log/mysql/slow.log {
    daily               # 每天轮转
    rotate 7            # 保留最近 7 份
    compress            # gzip 压缩旧日志
    missingok           # 文件不存在时不报错
    notifempty          # 空文件不轮转
    create 640 mysql mysql
    postrotate
        mysql -e "FLUSH SLOW LOGS;"
    endscript
}

[!TIP] 搭配 pt-query-digest 做"先分析、再清理"

# 在 logrotate 的 prerotate 中先分析,再轮转
prerotate
    pt-query-digest /var/log/mysql/slow.log > /var/log/mysql/slow_report_$(date +%Y%m%d).txt
endscript

这样每天轮转前自动保存一份分析报告,既不丢数据,又控制了磁盘占用。

实战 Walkthrough:从慢日志到上线优化

[!NOTE] 场景设定 电商系统,用户反馈"订单列表页加载慢"。DBA 介入排查。

Step 1 — 采集慢日志

# 确认慢日志已开启
mysql -e "SHOW VARIABLES LIKE 'slow_query_log%';"

# 用 pt-query-digest 分析最近 1 小时
pt-query-digest --since 1h /var/log/mysql/slow.log > /tmp/slow_report.txt

Step 2 — 定位 Top 1 瓶颈

报告 Profile 区域显示:

Rank  Query ID        Response time   Calls  R/Call  Item
====  ==============  ==============  =====  ======  ===================
   1  0xABCD1234      1850.5s  62.3%   3200   0.58s  SELECT orders JOIN users

[!TIP] 关键数字解读 3200 次调用 × 0.58s = 1850s 总耗时——高频 + 中等单次耗时,累积起来就是最大的性能杀手。

对应的 SQL 指纹:

SELECT o.id, o.status, o.amount, o.created_at, u.username
FROM orders o
JOIN users u ON o.user_id = u.id
WHERE o.user_id = ? AND o.status = ?
ORDER BY o.created_at DESC
LIMIT 20 OFFSET ?;

Step 3 — EXPLAIN 诊断

EXPLAIN FORMAT=JSON
SELECT o.id, o.status, o.amount, o.created_at, u.username
FROM orders o
JOIN users u ON o.user_id = u.id
WHERE o.user_id = 100 AND o.status = 'pending'
ORDER BY o.created_at DESC
LIMIT 20 OFFSET 5000;

关键输出(简化):

{
  "table": "o",
  "access_type": "ALL",
  "key": null,
  "rows": 520000,
  "filtered": 10.0,
  "Extra": "Using where; Using filesort"
}

[!QUESTION] 诊断结论是什么? 三个致命信号:

  1. type=ALL — 全表扫描,52 万行逐行检查
  2. key=null — 没有任何索引被使用
  3. OFFSET 5000 — 深分页,即使有索引也会丢弃前 5000 行

Step 4 — 优化方案

问题 A:缺少索引 — 添加联合索引:

-- 覆盖 WHERE + ORDER BY + SELECT 列(覆盖索引)
ALTER TABLE orders ADD INDEX idx_user_status_created
    (user_id, status, created_at, amount);

问题 B:深分页 — 改用"延迟关联":

-- 改写前:OFFSET 5000 需要扫描并丢弃 5000 行
SELECT ... FROM orders WHERE user_id = ? AND status = ?
ORDER BY created_at DESC LIMIT 20 OFFSET 5000;

-- 改写后:先用覆盖索引定位主键,再回表取数据
SELECT o.id, o.status, o.amount, o.created_at, u.username
FROM orders o
JOIN users u ON o.user_id = u.id
WHERE o.id IN (
    SELECT id FROM orders
    WHERE user_id = 100 AND status = 'pending'
    ORDER BY created_at DESC
    LIMIT 20 OFFSET 5000
)
ORDER BY o.created_at DESC;

Step 5 — 验证效果

优化前后的 EXPLAIN 对比:

指标 优化前 优化后
access_type ALL range
key null idx_user_status_created
rows 520,000 20
Extra Using filesort Using index condition
# 重新采集慢日志确认
pt-query-digest --since 1h /var/log/mysql/slow.log
# → 该 SQL 指纹已不在 Top 10 中 ✅

[!TIP] 上线 Checklist

  • 在测试环境验证 EXPLAIN 输出符合预期
  • 确认新索引不会影响写入性能(ALTER TABLE 可用 pt-online-schema-change 避免锁表)
  • 接入 Performance Schema 定时采集,设置告警阈值(如 Top SQL 单次 P95 > 2s 触发告警)

关联笔记