609 lines
23 KiB
Markdown
609 lines
23 KiB
Markdown
---
|
||
tags: [MySQL, 慢查询日志, pt-query-digest, 性能分析, EXPLAIN]
|
||
create time: 2026-05-16 10:30
|
||
---
|
||
|
||
# 慢查询日志分析
|
||
|
||
## 概述
|
||
|
||
慢查询日志（Slow Query Log）是 MySQL 自带的性能诊断工具，记录超过指定时间的 SQL 语句。配合 `pt-query-digest` 等专业工具，可以系统地识别和优化慢查询，定位数据库性能瓶颈。
|
||
|
||
> [!TIP] 核心思路
|
||
> 慢查询日志本身只是"记录仪"——真正的价值在于**归因分析**。将日志中的原始数据聚合、分类、排名，才能把噪音变成可行动的信号。
|
||
|
||
## 配置慢查询日志
|
||
|
||
```ini
|
||
# 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 表
|
||
```
|
||
|
||
```sql
|
||
-- 运行时动态开启（无需重启）
|
||
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
|
||
|
||
```sql
|
||
-- 设置 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` 的比例越大，说明查询在"等锁"而非"执行"上浪费了越多时间。下面的诊断路径帮你快速判断严重程度：
|
||
|
||
```mermaid
|
||
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：
|
||
|
||
```bash
|
||
# 最常用的参数组合：按执行时间排序，取前 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、甚至直连生产库实时采样：
|
||
|
||
```bash
|
||
# 基本用法：输出完整分析报告
|
||
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 内部采集：
|
||
|
||
```sql
|
||
-- MySQL 5.7+ 启用 performance_schema
|
||
SET GLOBAL performance_schema = ON;
|
||
|
||
-- 清理已有数据（可选，重置统计基线）
|
||
TRUNCATE performance_schema.events_statements_summary_by_digest;
|
||
```
|
||
|
||
等业务跑一段时间后，用 `pt-query-digest` 直接从 Performance Schema 提取分析：
|
||
|
||
```bash
|
||
# 方式一：基于 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 看执行时到底慢在哪。
|
||
|
||
```sql
|
||
-- 开启当前会话的 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 的额外开销。
|
||
|
||
## 慢查询优化工作流
|
||
|
||
从发现慢查询到完成优化的完整闭环：
|
||
|
||
```mermaid
|
||
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 ...` 获取结构化执行计划：
|
||
|
||
```sql
|
||
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: 针对性优化
|
||
|
||
根据诊断结果选择优化策略：
|
||
|
||
```mermaid
|
||
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
|
||
```
|
||
|
||
详见：
|
||
- [[hhs/MySQL/03-索引与查询优化/17-查询改写技巧]] — 常见 SQL 改写方案
|
||
- [[hhs/MySQL/03-索引与查询优化/18-深分页优化]] — OFFSET 深分页的替代方案
|
||
- [[hhs/MySQL/03-索引与查询优化/14-联合索引与最左前缀]] — 索引设计原则
|
||
|
||
#### Step 5: 回归验证 & 监控接入
|
||
|
||
优化不是一次性动作，需要建立持续监控机制：
|
||
|
||
> [!TIP] 最小可落地的监控方案
|
||
> ```sql
|
||
> -- 定期从 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 原生轮转
|
||
|
||
```bash
|
||
# 手动轮转（适合简单场景）
|
||
mv /var/log/mysql/slow.log /var/log/mysql/slow.log.$(date +%Y%m%d)
|
||
mysql -e "FLUSH SLOW LOGS;" # 让 MySQL 重新打开新的 slow.log
|
||
```
|
||
|
||
### 方案二：logrotate（推荐）
|
||
|
||
```bash
|
||
# /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 做"先分析、再清理"
|
||
> ```bash
|
||
> # 在 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 — 采集慢日志
|
||
|
||
```bash
|
||
# 确认慢日志已开启
|
||
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 指纹：
|
||
|
||
```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 诊断
|
||
|
||
```sql
|
||
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;
|
||
```
|
||
|
||
关键输出（简化）：
|
||
|
||
```json
|
||
{
|
||
"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：缺少索引** — 添加联合索引：
|
||
|
||
```sql
|
||
-- 覆盖 WHERE + ORDER BY + SELECT 列（覆盖索引）
|
||
ALTER TABLE orders ADD INDEX idx_user_status_created
|
||
(user_id, status, created_at, amount);
|
||
```
|
||
|
||
**问题 B：深分页** — 改用"延迟关联"：
|
||
|
||
```sql
|
||
-- 改写前：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 |
|
||
|
||
```bash
|
||
# 重新采集慢日志确认
|
||
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 触发告警）
|
||
|
||
## 关联笔记
|
||
|
||
- [[hhs/MySQL/03-索引与查询优化/15-EXPLAIN 完全指南]] — EXPLAIN 各字段的详细解读与执行计划分析
|
||
- [[hhs/MySQL/03-索引与查询优化/17-查询改写技巧]] — SQL 反模式改写方案
|
||
- [[hhs/MySQL/03-索引与查询优化/18-深分页优化]] — OFFSET 深分页的替代方案
|
||
- [[hhs/MySQL/03-索引与查询优化/12-B+Tree 索引原理]] — 索引底层结构，理解为何某些写法会让索引失效
|
||
- [[hhs/MySQL/06-事务与并发控制/26-锁机制总览]] — 行锁/表锁/间隙锁，排查 Lock_time 偏高问题
|
||
- [[hhs/MySQL/08-工程实践/40-常见踩坑]] — MySQL 日常使用中的典型陷阱
|