慢查询日志开了却没抓到东西，问题往往在 long_query_time

MySQL 的慢查询日志是排查数据库性能问题最直接的工具，但很多站长开了之后发现日志文件一直是空的，于是得出「我的数据库没问题」的结论。真实情况通常是：long_query_time 默认是 10 秒，而绝大多数拖垮网站的查询慢在 0.5–3 秒之间——它们不会进慢日志，但累积起来足以让页面 TTFB 从 200ms 涨到 2 秒。本文讲清慢查询日志的正确开启方式、怎么读出真正有价值的信息，以及怎么在日常运维里持续用起来而不是查完就关。

第一步：确认现在到底有没有在记

先看当前状态，不要凭印象：

SHOW VARIABLES LIKE 'slow_query_log%';
SHOW VARIABLES LIKE 'long_query_time';
SHOW VARIABLES LIKE 'log_queries_not_using_indexes';
SHOW VARIABLES LIKE 'slow_query_log_file';

典型输出里 slow_query_log 是 OFF、long_query_time 是 10.000000。注意 MySQL 5.7 和 8.0 的默认行为不一样，8.0 默认仍然是关闭慢日志。开启可以在线做，不需要重启：

SET GLOBAL slow_query_log = ON;
SET GLOBAL long_query_time = 1;
SET GLOBAL log_queries_not_using_indexes = OFF;

这里的 long_query_time = 1 是个人站比较合适的起点。设成 0.5 在低配 VPS 上会刷出大量噪音，设成 5 又会漏掉真正的问题。等你看过一轮日志、知道基线在哪之后，再决定要不要收紧。log_queries_not_using_indexes 建议先关掉——它对每一张没用到索引的查询都记一条，包括那些跑得飞快的小表全扫，日志会被瞬间撑爆，反而淹没了真正慢的语句。等你有明确目标时再单独开。

但要注意：上面这些 SET GLOBAL 都是临时的，MySQL 重启就丢。要持久化必须写进配置文件：

[mysqld]
slow_query_log = 1
slow_query_log_file = /var/log/mysql/slow.log
long_query_time = 1
log_queries_not_using_indexes = 0
min_examined_row_limit = 100

min_examined_row_limit = 100 是个很实用的过滤条件：只有扫描行数超过 100 的查询才会被记录。它和 log_queries_not_using_indexes 是互补的——前者过滤「扫得多」，后者过滤「没索引」。加上它之后，日志里剩下的基本都是值得看的。

第二步：把日志读成「按代价排序的清单」，而不是逐行翻

慢日志原文很难读，因为它按时间顺序记录，而你要的是「哪些查询最该优化」。用 mysqldumpslow 可以先做个粗略聚类：

# 按总耗时排序取前 20
mysqldumpslow -s at -t 20 /var/log/mysql/slow.log

# 按平均耗时排序，只看出现 5 次以上的
mysqldumpslow -s at -t 20 -g 'SELECT' -a /var/log/mysql/slow.log

# 按出现次数排序
mysqldumpslow -s c -t 20 /var/log/mysql/slow.log

参数含义：-s at 是 sort by average time（也可用 t 总时间、c 次数、l 锁定时间、r 返回行数），-t 限制输出条数，-a 是不把数字替换成 N（默认会把常量抽象化以便聚类，但对定位具体问题不利），-g 是正则过滤。

这里有个判断优先级的原则：优先看「单次很慢」还是「次数很多」？取决于你的场景。对个人博客，一篇热门文章被反复打开，一条 0.8 秒的查询每天跑 5 万次，它比一条偶尔出现的 8 秒管理后台查询更值得优化。所以先按 -s c 看次数榜，再按 -s at 看平均耗时榜，两份清单的交叉部分就是最高优先级。

mysqldumpslow 的局限是它不展示执行计划。如果要看 Rows_examined 和执行计划，建议装 pt-query-digest（Percona Toolkit 的一部分），它的输出是真正的可操作报告：

pt-query-digest /var/log/mysql/slow.log > /tmp/slow_report.txt

报告里最该看的三列是：Response time（这条查询占总慢查询时间的比例）、Rows examine 与 Rows sent 的比值、以及 Query_time 的分布。如果 Rows examine 是 20 万而 Rows sent 只有 10，说明索引几乎没起作用，这是最典型的「加个索引就能救」的信号。

第三步：看懂日志条目里的每一行

一条典型的慢日志记录长这样：

# Time: 2026-09-25T08:12:33.123456Z
# User@Host: bloguser[bloguser] @ localhost []  Id: 8841
# Query_time: 3.421887  Lock_time: 0.000142 Rows_sent: 12  Rows_examined: 184322
SET timestamp=1758787953;
SELECT * FROM typecho_contents WHERE type='post' AND status='publish' ORDER BY created DESC LIMIT 10;

逐项解读：

Query_time 是执行总耗时。Lock_time 如果是 0 说明不是锁等待问题；如果 Lock_time 接近 Query_time，那才是并发写冲突，需要看事务和索引，而不是查询本身。Rows_examined 是诊断的核心——184322 行扫描只返回 12 行，比例是 1.5 万比 1，说明这条查询在做全表扫描加排序。

上面这条语句的问题在 ORDER BY created DESC LIMIT 10：如果没有 (type, status, created) 这样的复合索引，MySQL 必须把符合 type 和 status 的全部行取出来、在内存里或磁盘上排序、再取前 10 条。行数一多，排序就可能落到 Using filesort 甚至写临时文件。EXPLAIN 一确认就知道：

EXPLAIN SELECT * FROM typecho_contents WHERE type='post' AND status='publish' ORDER BY created DESC LIMIT 10;

如果 Extra 列出现 Using filesort，就说明排序没走索引。理想情况是 Using where; Using index 或者至少排序字段在索引的最右侧，让 MySQL 能顺着索引直接取到有序结果，一旦凑够 10 行就停止扫描，Rows_examined 会从 18 万直接降到 10 几行。这就是慢日志能带来的最典型收益。

第四步：把慢查询排查变成常态化动作，而不是救火

日志会一直增长，不加管理的话几个月就能吃掉几个 G 的磁盘。推荐做法是用 logrotate 做轮转，同时保留一段时间的可追溯性：

/var/log/mysql/slow.log {
    daily
    rotate 14
    missingok
    notifempty
    compress
    delaycompress
    create 640 mysql adm
    sharedscripts
    postrotate
        test -x /usr/bin/mysqladmin || exit 0
        if [ -f /var/run/mysqld/mysqld.pid ]; then
            /usr/bin/mysqladmin --defaults-file=/etc/mysql/debian.cnf flush-logs
        fi
    postrotate
}

关键在于 postrotate 里的 mysqladmin flush-logs。如果只是把文件改名，MySQL 仍然往原来打开的文件描述符里写，日志会「消失」在新文件名里，新的 slow.log 则一直是空的——这是轮转慢日志最经典的坑。用 flush-logs 通知 MySQL 重新打开文件句柄，才能真正实现日志切换。

再进一步，可以把「每日慢查询摘要」加进你的运维巡检里。不需要复杂的监控系统，一个 cron 加一条命令就够：

# 每天早上 7 点把昨天的慢查询摘要发到管理员邮箱
0 7 * * * mysqldumpslow -s at -t 10 /var/log/mysql/slow.log | mail -s "MySQL slow report $(date +\%F)" you@example.com

这里有个持续性收益：当你知道每天都会收到摘要时，就更容易判断「今天变慢了」到底是发布引起的、流量涨了、还是有异常访问。把慢查询日志和 SHOW GLOBAL STATUS 里的 Queries、Threads_connected 结合看，能快速区分「单条查询变慢」和「整体负载上升」——前者优化 SQL 和索引，后者要加缓存或升配置，处理方向完全不同。

第五步：从慢查询反推索引该怎么加

找到慢查询之后，最常见的动作是「加个索引」，但加错索引比不加更糟——它会占用磁盘、拖慢写入，还可能在优化器看来「有用」从而被选中，结果查询更慢。正确的顺序是先搞清楚查询的访问路径，再决定索引的列顺序。

核心规则是最左前缀原则：复合索引 (a, b, c) 能被用在 WHERE a=?、WHERE a=? AND b=?、WHERE a=? AND b=? AND c=? 上，但没法直接服务 WHERE b=?。所以列的顺序应该按「等值条件在前、范围条件在后」来排。上面那条 WHERE type='post' AND status='publish' ORDER BY created DESC，正确索引是 (type, status, created)：前两列等值匹配，第三列直接提供有序性，MySQL 顺着索引走就能拿到排好序的结果，LIMIT 10 一到就停。

如果写成 (created, type, status) 就完全跑偏了——它会走 created 索引扫出所有行再逐行过滤 type 和 status，扫描行数可能比全表扫还多。还有一种更隐蔽的错误：把 created 放在 (type, status, created) 里但类型不一致。比如表里 created 是 int 存时间戳，而查询条件里写成 ORDER BY created DESC 没问题，但如果 WHERE 里出现 WHERE DATE(created)='2026-09-25'，函数包在列上，索引直接失效。慢日志里这种语句看起来「条件很简单」，但 Rows_examined 会暴露它在全表扫。

加完索引必须验证三件事：EXPLAIN 里 key 是否真的用了新索引、rows 估算是否显著下降、以及写入性能有没有被拖累（索引越多，INSERT/UPDATE 越慢）。对读多写少的博客站，多几个索引不是问题；但对有频繁写入的场景，每加一个索引都要掂量一下。

第六步：慢查询与页面 TTFB 的对照定位

慢查询日志告诉你「数据库慢」，但它没法直接告诉你「用户感知变慢了」。把两者对上，才能确认优化有没有真正产生效果。做法是在排查页面上记下 TTFB 和慢日志里的时间窗口，看它们是否重合：

# 记录当前 TTFB
curl -o /dev/null -s -w 'ttfb:%{time_starttransfer} total:%{time_total}\n' https://你的域名/测试文章.html

# 同时段看慢日志有没有条目（按时间倒序取最后几条）
tail -n 40 /var/log/mysql/slow.log | grep -A2 'Query_time'

如果 TTFB 超过 1 秒，而慢日志同一分钟内有 Query_time > 0.5 的条目，那基本可以判定数据库就是瓶颈。反过来，TTFB 高但慢日志干净，就要往别处找：PHP-FPM 进程池打满、上游连接超时、或者 Nginx 到后端的网络抖动——这些都不会出现在慢查询日志里。

还有一个容易被忽略的混淆因素：慢日志里的查询未必都来自正常访问。搜索引擎爬虫批量抓取、有人在跑采集、甚至是扫描器在试探，都可能触发大量慢查询。所以在优化前先看 User@Host，确认这些慢查询来自你的应用还是外部。如果是爬虫引起的，正确做法是调抓取频率或限流（limit_req），而不是去改 SQL 和索引——方向错了，折腾再久也不会有改善。

几个容易踩的坑

坑一：开了慢日志却忘了它也会拖慢写入。在机械盘或高并发小机器上，慢日志的写盘本身有开销。如果 long_query_time 设得太低导致每秒记几十条，反而会加重 IO 压力。一个稳的做法是把日志目录放到独立分区或 tmpfs 之外的高速盘上，并定期确认日志增速正常。

坑二：以为「没慢查询」就是数据库没问题。慢日志只覆盖超过阈值的单条查询，覆盖不了「大量并发的中等查询」。如果每秒有 500 条 0.3 秒的查询，慢日志一条都不会记，但数据库已经饱和了。这种情况要看 SHOW ENGINE INNODB STATUS 里的信号量等待、Threads_running 指标，以及应用层的连接池等待时间。

坑三：优化完不验证。加了索引之后应该重新跑一次同样的 EXPLAIN，确认 Rows_examined 真的降下来了，并把优化前后的数据记下来。否则很容易出现「索引加了但没被用上」（比如字段类型不匹配、用了函数导致索引失效）的情况，白做一场。

把这些检查项做完，慢查询日志就不再是一个「开了不知道干嘛用」的开关，而是你日常判断数据库健康度的第一手资料。