3、慢查询分析工具:mysqldumpslow与pt-query-digest的使用与输出解读

在Go项目数据库性能调优中,慢查询日志是定位SQL瓶颈的第一手资料。MySQL自带的mysqldumpslow与Percona Toolkit中的pt-query-digest是两款最常用的慢查询分析工具。前者轻量快速,适合日常快速排查;后者功能强大,适合深度分析与报表生成。本节将详细讲解两者的使用场景、核心参数及输出解读方法。

3.1 慢查询日志基础配置

在使用分析工具前,必须确保MySQL已开启慢查询日志。以下为推荐配置参数:

参数名 推荐值 说明
slow_query_log ON 开启慢查询日志
slow_query_log_file /var/log/mysql/slow.log 日志文件路径
long_query_time 1 (秒) 超过此阈值的SQL被记录;Go项目建议设为1秒
log_queries_not_using_indexes ON 记录未使用索引的查询,便于发现索引缺失
min_examined_row_limit 100 仅记录扫描行数超过此值的查询,过滤小查询噪音
实践建议:在Go项目预发环境开启慢查询日志时,建议将 long_query_time 临时设为0.5秒,捕获更多潜在慢查询;上线稳定后再调回1秒。

3.2 mysqldumpslow:轻量级快速分析

mysqldumpslow 是MySQL官方提供的Perl脚本,无需额外安装,适合在服务器上快速查看慢查询摘要。

3.2.1 常用参数

参数 作用 示例
-s c 按查询次数排序 mysqldumpslow -s c slow.log
-s t 按查询总耗时排序 mysqldumpslow -s t slow.log
-s l 按锁定时间排序 mysqldumpslow -s l slow.log
-t N 只显示前N条 mysqldumpslow -s t -t 10 slow.log
-g pattern 按正则过滤SQL mysqldumpslow -g "SELECT.*user" slow.log
--verbose 显示详细信息 mysqldumpslow --verbose slow.log

3.2.2 输出解读

执行以下命令:

mysqldumpslow -s t -t 5 /var/log/mysql/slow.log

典型输出示例:

Reading mysql slow query log from /var/log/mysql/slow.log
Count: 123  Time=2.34s (288s)  Lock=0.01s (1s)  Rows=1500.0 (184500), root[root]@localhost
  SELECT * FROM orders WHERE status = 'N' AND created_at < 'N' ORDER BY id LIMIT N;

Count: 89   Time=1.87s (166s)  Lock=0.02s (2s)  Rows=800.0 (71200), app[app]@[10.0.0.1]
  UPDATE inventory SET stock = stock - N WHERE product_id = N AND stock >= N;

Count: 45   Time=3.12s (140s)  Lock=0.05s (2s)  Rows=3200.0 (144000), app[app]@[10.0.0.2]
  SELECT u.id, u.name, o.total FROM users u JOIN orders o ON u.id = o.user_id WHERE o.status = 'N';

输出字段解读:

  • Count:该模式SQL出现的总次数。
  • Time:平均耗时(秒),括号内为总耗时。
  • Lock:平均锁定时间,括号内为总锁定时间。
  • Rows:平均返回/影响行数,括号内为总行数。
  • SQL语句:经过归一化(参数替换为N)后的模板。
注意:mysqldumpslow 会将SQL中的具体数值替换为 N,字符串替换为 'N'。这有助于聚合同类查询,但也会丢失具体参数信息。如需查看原始SQL,需配合 --verbose 或直接查看日志文件。

3.3 pt-query-digest:深度分析与报表

pt-query-digest 是Percona Toolkit的核心工具,支持从慢查询日志、通用日志、tcpdump等多种来源分析查询性能,输出结构化的HTML或文本报表。

3.3.1 安装与基本用法

# 安装Percona Toolkit(以Ubuntu为例)
sudo apt-get install percona-toolkit

# 分析慢查询日志,输出文本报表
pt-query-digest /var/log/mysql/slow.log

# 输出HTML报表,便于可视化查看
pt-query-digest --output html /var/log/mysql/slow.log > slow_report.html

# 分析最近1小时的慢查询(配合时间过滤)
pt-query-digest --since "2025-01-15 10:00:00" --until "2025-01-15 11:00:00" slow.log

3.3.2 核心参数详解

参数 作用 典型场景
--output 输出格式:text/html/json 生成HTML报表分享给团队
--since / --until 按时间范围过滤 分析发版后1小时的慢查询
--limit 限制输出排名数量 --limit 10% 只显示前10%的查询
--filter 自定义过滤条件 --filter '$rows_examined > 10000'
--no-report 不输出报表,仅做数据收集 配合 --review 存入数据库
--review 将分析结果存入数据库表 长期跟踪慢查询趋势

3.3.3 输出解读

pt-query-digest 的输出分为三个主要部分:

第一部分:总体概览

# 200ms user time, 30ms system time, 24.97M rss, 92.32M vsz
# Current date: Wed Jan 15 10:30:00 2025
# Hostname: db-server-01
# Files: /var/log/mysql/slow.log
# Overall: 1.2k total, 6 unique, 0.01 QPS, 0.5x concurrency ________
# Time range: 2025-01-15 09:00:00 to 10:30:00
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time          1234s      1s     12s      1s      3s      2s      1s
# Lock time             5s       0       1s      0       0       0       0
# Rows sent          892k       0    120k     743    3200    5.2k      10
# Rows examine       5.6M       0    1.2M    4.7k     12k     28k     500
# Query size         1.2M      32     2k     987    1.5k     345     890

第二部分:查询排名(按总耗时降序)

# Profile
# Rank Query ID                      Response time   Calls  R/Call  V/M   Item
# ==== ============================= =============== ====== ======= ===== =====
#    1 0xABCD1234567890EF            456.2342 37.0%    123   3.7092  0.25 SELECT orders
#    2 0x1234567890ABCDEF            234.5678 19.0%     89   2.6356  0.18 UPDATE inventory
#    3 0xFEDCBA0987654321            123.4567 10.0%     45   2.7435  0.32 SELECT users JOIN orders
#    4 0x1111222233334444             89.0123  7.2%     67   1.3285  0.09 INSERT audit_log
#    5 0x5555666677778888             67.8901  5.5%     34   1.9968  0.15 SELECT products

第三部分:每个查询的详细分析

# Query 1: 0.01 QPS, 0.04x concurrency, ID 0xABCD1234567890EF at byte 123456
# This item is included in the report because it matches --limit
# Scores: V/M = 0.25
# Time range: 2025-01-15 09:00:00 to 10:30:00
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         10     123
# Exec time     37    456s      1s     12s      4s      8s      3s      3s
# Lock time     10      1s       0       0       0       0       0       0
# Rows sent     21    184k       0     10k    1.5k    5.0k    2.1k     200
# Rows examine  32    1.8M       0     80k     15k     40k     18k     5k
# Query size    10    121k     987    1024     987     987       0     987
# String:
# Hosts         localhost (50%), 10.0.0.1 (30%), 10.0.0.2 (20%)
# Users         root (50%), app (50%)
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+  ####
# Tables
#   SHOW TABLE STATUS LIKE 'orders'\G
#   SHOW CREATE TABLE `orders`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM orders WHERE status = 'N' AND created_at < 'N' ORDER BY id LIMIT N\G

关键指标解读:

  • Response time / Calls / R/Call:总响应时间、调用次数、每次平均耗时。优先优化总耗时最高的查询。
  • V/M (Variance-to-Mean ratio):方差均值比,值越大说明执行时间波动越大,可能存在偶发性能问题。
  • Rows examine / Rows sent:扫描行数与发送行数。差距过大说明索引效率低或查询逻辑需优化。
  • Query_time distribution:时间分布直方图,直观展示大多数查询落在哪个耗时区间。
  • Tables / EXPLAIN:自动输出表结构和执行计划,便于直接定位索引问题。

3.4 工具对比与选型建议

对比维度 mysqldumpslow pt-query-digest
安装依赖 MySQL自带,无需安装 需安装Percona Toolkit
分析深度 基础聚合,无执行计划 深度分析,含EXPLAIN、表结构、时间分布
输出格式 纯文本 文本/HTML/JSON
过滤能力 简单正则 时间范围、自定义表达式、数据库存储
适用场景 SSH登录服务器快速查看 深度分析、报表生成、长期趋势跟踪
性能开销 极低 中等,大日志文件建议分片处理
Go项目最佳实践:日常快速排查使用 mysqldumpslow -s t -t 10;每周或发版后使用 pt-query-digest --output html 生成报表,纳入CI/CD流水线,与上一周期对比,及时发现新增慢查询。

3.5 慢查询分析流程SVG

下图展示了从慢查询日志采集到最终优化的完整分析流程:

慢查询分析优化流程图 1. 开启慢查询日志 2. 采集慢查询日志 3. 工具分析 4. 输出解读 5. 定位问题SQL 6. 优化执行 验证效果,循环迭代 mysqldumpslow 适用场景 • SSH登录服务器,快速查看Top N慢查询 • 按次数、总耗时、锁定时间排序 • 轻量级,无需额外安装 • 输出简洁,适合日常巡检 • 缺点:无执行计划、无时间分布 • 缺点:无法按时间范围过滤 pt-query-digest 适用场景 • 深度分析,含EXPLAIN和表结构 • 输出HTML报表,便于团队分享 • 支持时间范围、自定义过滤 • 可存入数据库,长期趋势跟踪 • 缺点:需安装Percona Toolkit • 缺点:大日志文件分析较慢

3.6 实战案例:Go项目慢查询定位

某Go电商项目在高峰期出现接口响应变慢,通过以下步骤快速定位问题:

  1. 开启慢查询日志:设置 long_query_time=1,并开启 log_queries_not_using_indexes。
  2. 采集日志:运行15分钟后,日志文件约50MB。
  3. 使用mysqldumpslow快速查看:mysqldumpslow -s t -t 5 slow.log,发现排名第一的查询是 SELECT * FROM orders WHERE status = 'N',平均耗时4秒。
  4. 使用pt-query-digest深度分析:pt-query-digest --output html slow.log,查看该查询的EXPLAIN,发现 status 列没有索引,全表扫描120万行。
  5. 优化:添加索引 ALTER TABLE orders ADD INDEX idx_status (status);,查询耗时降至0.02秒。
  6. 验证:再次分析日志,该查询不再出现在Top N中。
效率提示:在Go项目中使用 pt-query-digest 的 --review 参数将分析结果存入MySQL表,配合Grafana展示慢查询趋势,可以做到“慢查询可观测”。

3.7 常见问题与避坑

问题 原因 解决方案
mysqldumpslow输出为空 日志文件权限不足或路径错误 检查 slow_query_log_file 路径和MySQL用户权限
pt-query-digest分析大日志卡死 日志文件过大(超过1GB) 使用 --since 按时间分片,或先 gzip 压缩后分析
慢查询日志磁盘爆满 未设置日志轮转 配置 logrotate 或MySQL的 expire_logs_days
pt-query-digest输出中V/M值过高 查询执行时间波动大,可能存在锁等待或数据倾斜 检查锁竞争、索引碎片或数据分布不均
mysqldumpslow无法识别自定义SQL注释 工具只解析标准慢查询格式 使用 pt-query-digest 的 --filter 自定义解析