--- 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。 ### 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; ``` ### 关键字段含义 | 字段 | 含义 | 关注点 | |------|------|--------| | **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 的比例 诊断方向 ────────────────────────────────────────── < 1% 正常,无锁问题 1% ~ 10% 轻度竞争,可接受 > 10% 需要排查:是否有长事务或未命中索引 > 50% 紧急:大概率死锁或锁升级 ``` ## 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 直接分析 pt-query-digest --processlist D=localhost,U=root \ --no-report /var/log/mysql/slow.log -- 或者直接用下面的方式从 Performance Schema 提取 pt-query-digest --type processlist D=host:port,user,password ``` ## 常见慢查询反模式 即使有索引,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["分类归因
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/19-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"] --> B3["验证:rows↓, time↓"] B2["YEAR(col) → range 扫描"] --> B3 B3["NOT IN → LEFT JOIN IS NULL"] --> B3 end subgraph "架构类优化" C1["深分页 OFFSET → 延迟关联"] --> C3["验证:P95 latency ↓"] C2["大事务拆小"] --> C3 C3["读写分离 / 缓存"] --> C3 end ``` 详见: - [[hhs/MySQL/21-查询改写技巧]] — 常见 SQL 改写方案 - [[hhs/MySQL/22-深分页优化]] — OFFSET 深分页的替代方案 - [[hhs/MySQL/18-联合索引与最左前缀]] — 索引设计原则 #### 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 做可视化告警。 ## 关联笔记 - [[hhs/MySQL/19-EXPLAIN 完全指南]] — EXPLAIN 各字段的详细解读与执行计划分析 - [[hhs/MySQL/21-查询改写技巧]] — SQL 反模式改写方案 - [[hhs/MySQL/22-深分页优化]] — OFFSET 深分页的替代方案 - [[hhs/MySQL/16-B+Tree 索引原理]] — 索引底层结构,理解为何某些写法会让索引失效 - [[hhs/MySQL/26-锁机制总览]] — 行锁/表锁/间隙锁,排查 Lock_time 偏高问题 - [[hhs/MySQL/40-常见踩坑]] — MySQL 日常使用中的典型陷阱