MySQL慢查询日志怎么看

文章导读
搜这个问题的人通常已经打开了慢查询日志,但打开后看到一屏 Query_time、Lock_time、Rows_examined,不清楚该从哪一条读起。正确的顺序是先确认四个参数:日志开没开、写到哪里、阈值多少、有没有开启“记录未走索引”;再按耗时排序看前几条;最后用 Lock_time 与 Query_time 的关系,以及 Rows_examined 与 Rows_sent 的比例,判断是等锁还
📋 目录
  1. 一 MySQL慢:先把能核对的事实摆清楚
  2. 二 MySQL慢最容易搞错的一点
  3. 三 MySQL慢:一个照着就能做完的做法
  4. 四 MySQL慢:怎么验证结果对不对
A A

搜这个问题的人通常已经打开了慢查询日志,但打开后看到一屏 Query_time、Lock_time、Rows_examined,不清楚该从哪一条读起。正确的顺序是先确认四个参数:日志开没开、写到哪里、阈值多少、有没有开启“记录未走索引”;再按耗时排序看前几条;最后用 Lock_time 与 Query_time 的关系,以及 Rows_examined 与 Rows_sent 的比例,判断是等锁还是扫描过多。

慢查询日志只记录超过 long_query_time 的语句,它本身不告诉你哪条 SQL 有问题。建议先执行 SHOW VARIABLES,确认 slow_query_log、log_output、slow_query_log_file、long_query_time 四项,再用 mysqldumpslow -s t 排序看前 20 条。如果日志里没有正在卡住的语句,原因大概率不在执行耗时,而应到 SHOW FULL PROCESSLIST 和锁等待里找。长期开启前先确认日志目录的磁盘余量。

MySQL慢:先把能核对的事实摆清楚

排查对象是某个 MySQL 实例上的慢查询日志。前提是你有读取 SHOW VARIABLES 的权限,并且能登录到数据库服务器读取日志文件;默认情况下,日志写在 datadir 下。先执行:

SHOW VARIABLES WHERE Variable_name IN (
  'slow_query_log',
  'log_output',
  'slow_query_log_file',
  'long_query_time',
  'log_queries_not_using_indexes',
  'min_examined_row_limit'
);

需要核对四件事。第一,slow_query_log 是 ON 还是 OFF。第二,log_output 是 FILE、TABLE 还是两者都有;值为 TABLE 时日志落在 mysql.slow_log 表里,按文件路径找不到。第三,slow_query_log_file 给出的路径,在部分版本里这个变量只有文件名,实际文件通常在 datadir 下,可用 SELECT @@datadir; 确认。第四,long_query_time 是多少秒,它支持小数,例如 0.5。另外,min_examined_row_limit 大于 0 时,扫描行数不够的语句根本不会被记录,这一点也要看清。

日志记录的字段可以直接读取:# Query_time、# Lock_time、# Rows_sent、# Rows_examined,后面跟着 SET timestamp、执行账户和原始 SQL。这几项就是判断的全部原料,不需要再凭印象猜。

MySQL慢最容易搞错的一点

最常见的误解是“慢查询日志里有这条 SQL,所以就是它写得慢”。Query_time 统计的是语句从开始执行到返回结果的总耗时,其中可能有很大一部分花在等锁、等 IO 或等元数据锁上,SQL 本身并不慢。反过来还有一种情况更常见:排查时发现日志里压根没有正在卡住的那条语句,因为慢查询日志一般在语句执行结束后才写入;一条跑了很久还没结束的语句不会出现在文件里。

区分这两种情况的动作是:在另一个会话执行 SHOW FULL PROCESSLIST;,看 State 列有没有 Waiting for ... lock、Waiting for table metadata lock 这类字样;同时查询 SELECT * FROM performance_schema.data_lock_waits;(MySQL 8.0;5.7 用 information_schema.innodb_lock_waits),看谁在阻塞谁。如果 PROCESSLIST 里有长时间运行的语句,而慢日志迟迟没有新记录,那属于“还没结束”,不是“没超过阈值”。如果日志里有记录,但 Lock_time 和 Query_time 接近,则先查持锁方。需要注意,不同版本对 Lock_time 的统计口径不完全一致,行锁等待不一定全部体现在这个字段里,建议和 performance_schema 的结果交叉确认。

MySQL慢:一个照着就能做完的做法

第一步,如果日志没开,先临时开启用于本次定位(重启后失效):

MySQL慢查询日志怎么看
SET GLOBAL slow_query_log = ON;
SET GLOBAL long_query_time = 1;
SET GLOBAL log_queries_not_using_indexes = OFF;
SET GLOBAL log_output = 'FILE';

long_query_time 是会话级变量,改完之后已有连接仍然按旧值判断,需要重新连接才生效。这一步应该看到的结果是:重新执行前面的 SHOW VARIABLES,slow_query_log 为 ON,long_query_time 为 1。

要长期保留,写进配置文件后重启,或者确认参数支持动态修改后再通过 SET GLOBAL 设置:

[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 = 0

第二步,等几分钟、有业务流量之后,用聚合工具按总耗时排序取前 20 条,不要直接 cat 整个文件:

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

需要更细的分组统计时用 pt-query-digest:

pt-query-digest /var/log/mysql/slow.log | head -120

这一步应该看到按 Query time 从大到小排列的语句摘要,每条带出现次数、平均耗时、平均扫描行数。优先处理排在前面的语句。

MySQL慢查询日志怎么看

第三步,按下面的顺序判断,尽量不跳步:

  1. 日志里有没有目标 SQL:如果没有,就去 PROCESSLIST 和锁等待里找,这多半不属于慢查询日志能覆盖的问题。
  2. Query_time 明显大于 Lock_time:说明耗时主要在执行本身,进入第 3 步;两者接近,先查锁。
  3. Rows_examined 远大于 Rows_sent:索引没走好或过滤条件没生效,跑 EXPLAIN。
  4. 同一条 SQL 只是偶发慢:对比两次的 EXPLAIN,看是不是参数不同、数据量增长或统计信息过期。
  5. Rows_sent 本身就很大:问题在返回结果集太大,属于取数方式问题,不是索引问题。

容易踩的坑是把 log_queries_not_using_indexes 打开当作“加强监控”。这个开关会记录所有不走索引的语句,包括小表全表扫描和只有几行的语句,日志文件会在短时间内明显变大,真正慢的语句反而被淹没。排查时可以临时打开,确认问题后关掉,同时留意日志目录的磁盘余量。

MySQL慢:怎么验证结果对不对

验证分两层。第一层确认判断没跑偏:对目标 SQL 在业务库上执行 EXPLAIN(MySQL 8.0.18 之后可以用 EXPLAIN ANALYZE 看实际执行情况),正常的结果是 type 不是 ALL、key 有实际使用的索引、rows 的量级和预期的过滤结果接近。Extra 里出现 Using filesort 或 Using temporary 不一定就错,要结合数据量看。

第二层确认调整之后确实不再慢。用 performance_schema 看同类语句的聚合数据,比逐条读日志更直接:

SELECT DIGEST_TEXT,
       COUNT_STAR,
       ROUND(AVG_TIMER_WAIT/1000000000000, 3) AS avg_sec,
       SUM_ROWS_EXAMINED,
       SUM_ROWS_SENT
FROM performance_schema.events_statements_summary_by_digest
ORDER BY AVG_TIMER_WAIT DESC
LIMIT 20;

AVG_TIMER_WAIT 的单位是皮秒,除以 1e12 得到秒。正常结果应该表现为:目标语句的 avg_sec 落到 long_query_time 以下,SUM_ROWS_EXAMINED 与 SUM_ROWS_SENT 的比值收窄。如果 avg_sec 没降但 SUM_ROWS_EXAMINED 降了,说明瓶颈已经不在扫描行数上,需要回头再看锁等待和 IO。

另外观察 SHOW GLOBAL STATUS LIKE 'Slow_queries'; 的计数增长速度,以及慢日志文件在相同时长内新增的条目数,这两个数字在业务量稳定的前提下应该下降。如果日志条目数没变但业务侧感觉变快了,先确认是不是 long_query_time 被改过,或者 log_output 被设成 TABLE 导致文件不再增长。