慢日志配置避坑指南：为什么你设置的long_query_time=1却记录了0.1秒的查询？

MySQL慢日志配置深度解析：为什么0.1秒的查询会被记录？

当你在MySQL中设置了long_query_time=1，却发现大量执行时间仅0.1秒的查询被记录到慢日志中时，这绝非偶然。本文将深入剖析MySQL慢日志记录机制中的隐藏规则，揭示那些鲜为人知的参数配置陷阱，并提供精准控制日志记录范围的实战方案。

1. 慢日志基础配置与常见误解

MySQL的慢查询日志是数据库性能优化的利器，但多数开发者对其工作原理存在根本性误解。让我们先澄清几个关键概念：

• long_query_time：这个参数确实定义了慢查询的时间阈值，单位为秒，支持微秒级精度（如设置为1.5表示1秒500毫秒）
• 慢查询判定标准：实际上，MySQL判断是否为慢查询的条件远比想象中复杂，执行时间只是其中一个因素

常见配置方法如下：

-- 开启慢查询日志
SET GLOBAL slow_query_log = 'ON';

-- 设置慢查询阈值为1秒
SET GLOBAL long_query_time = 1;

-- 查看当前设置
SHOW VARIABLES LIKE 'long_query_time';

但问题在于，仅配置这些参数并不能完全控制哪些查询会被记录。以下是一个典型的配置检查清单：

参数名	默认值	说明
slow_query_log	OFF	是否开启慢查询日志
long_query_time	10.000000	慢查询时间阈值(秒)
log_queries_not_using_indexes	OFF	是否记录未使用索引的查询
min_examined_row_limit	0	查询检查的最小行数阈值
log_slow_admin_statements	OFF	是否记录管理语句(如ALTER TABLE)
log_throttle_queries_not_using_indexes	0	限制每分钟记录未使用索引的查询数量

2. 隐藏参数对慢日志的影响

2.1 log_queries_not_using_indexes的陷阱

这个参数是导致"短时查询"被记录的常见元凶：

-- 查看是否开启未使用索引查询记录
SHOW VARIABLES LIKE 'log_queries_not_using_indexes';

-- 意外开启的案例
SET GLOBAL log_queries_not_using_indexes = 'ON';

当该参数启用时，任何未使用索引的查询都会被记录，无论其执行时间多短。这解释了为什么0.1秒的查询会出现在日志中。

真实案例：某电商平台发现慢日志暴增，检查发现是开启了此参数，而系统中存在大量小型查询虽然执行快但未走索引。

2.2 min_examined_row_limit的隐蔽作用

这个鲜为人知的参数同样会影响记录行为：

-- 设置查询检查行数下限为1000
SET GLOBAL min_examined_row_limit = 1000;

复合判定条件：当同时满足以下两个条件时，查询才会被记录：

1. 执行时间 ≥ long_query_time
2. 检查行数 ≥ min_examined_row_limit

这意味着即使查询执行很慢，但如果检查行数不足，也不会被记录。

2.3 时间精度问题的真相

MySQL在判断查询是否超时时存在一些特殊情况：

• 锁等待时间：默认不计入查询时间
• 网络延迟：客户端测量的时间可能比服务端长
• 精度问题：某些版本存在毫秒级四舍五入问题

使用Wireshark抓包分析可以发现，客户端与服务端的时间测量存在微妙差异：

# Wireshark过滤条件
mysql.query contains "SELECT"

3. 精准控制日志记录的配置方案

3.1 推荐的安全配置组合

-- 完整的安全配置示例
SET GLOBAL slow_query_log = 'ON';
SET GLOBAL long_query_time = 1;
SET GLOBAL log_queries_not_using_indexes = 'OFF';
SET GLOBAL min_examined_row_limit = 100;
SET GLOBAL log_throttle_queries_not_using_indexes = 10;

对应的my.cnf配置：

[mysqld]
slow_query_log = 1
long_query_time = 1
log_queries_not_using_indexes = 0
min_examined_row_limit = 100
log_slow_admin_statements = 0
log_throttle_queries_not_using_indexes = 10
slow_query_log_file = /var/log/mysql/mysql-slow.log
log_output = FILE

3.2 不同场景下的配置策略

根据业务特点选择合适的配置：

场景类型	推荐配置	理由
线上生产环境	严格模式：只记录>1s且检查行数>1000的查询	避免日志过大，聚焦真正性能问题
开发测试环境	宽松模式：记录所有>0.1s查询和未使用索引查询	全面捕获潜在问题
性能调优期间	精确模式：记录>0.5s查询，开启未使用索引记录但限制频率	平衡信息量和日志大小

3.3 使用Performance Schema作为替代方案

对于MySQL 5.6+版本，可考虑使用Performance Schema来监控慢查询：

-- 启用相关consumer
UPDATE performance_schema.setup_consumers 
SET ENABLED = 'YES' 
WHERE NAME LIKE 'events_statements%';

-- 查询长时运行语句
SELECT * FROM performance_schema.events_statements_history_long 
WHERE ELAPSED_TIME > 1000000;  -- 1秒=1000000微秒

这种方法相比慢查询日志有以下优势：

• 更细粒度的时间测量
• 不依赖文件I/O
• 可定制化的监控维度

4. 慢日志分析与优化实践

4.1 使用pt-query-digest分析日志

Percona Toolkit中的pt-query-digest是分析慢查询日志的利器：

# 基本用法
pt-query-digest /var/log/mysql/mysql-slow.log

# 高级分析示例
pt-query-digest \
  --filter '$event->{fingerprint} =~ m/^SELECT/' \
  --limit=10 \
  --order-by Query_time:sum \
  /var/log/mysql/mysql-slow.log

分析报告中的关键指标解读：

1. Query_time分布：查看95分位、99分位响应时间
2. Rows_examined：检查行数过多的查询
3. Lock_time：锁定时间过长的查询
4. 执行次数：高频查询即使不慢也可能需要优化

4.2 常见慢查询模式及优化方案

模式一：全表扫描

特征：Rows_examined远大于Rows_sent 优化：添加适当索引

-- 优化前
SELECT * FROM orders WHERE status = 'pending';

-- 优化后
ALTER TABLE orders ADD INDEX idx_status (status);
SELECT * FROM orders WHERE status = 'pending' LIMIT 1000;

模式二：低效JOIN

特征：多表JOIN导致执行计划复杂 优化：重写查询或添加联合索引

-- 优化前
SELECT * FROM users u 
JOIN orders o ON u.id = o.user_id 
WHERE u.register_time > '2023-01-01';

-- 优化后
ALTER TABLE orders ADD INDEX idx_user_id (user_id);
SELECT * FROM users u FORCE INDEX(PRIMARY)
JOIN orders o FORCE INDEX(idx_user_id) ON u.id = o.user_id 
WHERE u.register_time > '2023-01-01';

模式三：不合理排序

特征：出现filesort且Sort_merge_passes>0 优化：添加排序字段索引

-- 优化前
SELECT * FROM products ORDER BY price DESC LIMIT 100;

-- 优化后
ALTER TABLE products ADD INDEX idx_price (price);
SELECT * FROM products ORDER BY price DESC LIMIT 100;

5. 慢日志维护与管理策略

5.1 安全的日志轮换方案

不建议直接删除慢查询日志文件，推荐以下方法：

# 方法1：使用mysqladmin刷新日志
mysqladmin -uroot -p flush-logs

# 方法2：重命名后刷新
mv /var/log/mysql/mysql-slow.log /var/log/mysql/mysql-slow.log.old
mysql -e "FLUSH SLOW LOGS;"

# 方法3：使用logrotate配置

示例logrotate配置(/etc/logrotate.d/mysql-slow):

/var/log/mysql/mysql-slow.log {
    daily
    rotate 30
    missingok
    compress
    delaycompress
    notifempty
    create 640 mysql mysql
    sharedscripts
    postrotate
        /usr/bin/mysql -e "FLUSH SLOW LOGS;"
    endscript
}

5.2 监控慢日志增长

建议对慢日志大小进行监控，可使用以下命令：

# 检查当前慢日志大小
ls -lh /var/log/mysql/mysql-slow.log

# 监控慢日志增长情况
watch -n 60 "du -sh /var/log/mysql/mysql-slow.log"

# 统计慢查询数量
mysql -e "SHOW GLOBAL STATUS LIKE 'Slow_queries';"

当发现慢日志异常增长时，应检查：

1. 是否有新的代码部署
2. 是否数据量突然增大
3. 是否有锁竞争加剧
4. 是否配置被意外修改

6. 高级技巧与疑难问题排查

6.1 临时捕获特定查询

有时需要临时捕获某个特定模式的查询：

-- 临时调整设置
SET @old_long_query_time = @@global.long_query_time;
SET @old_log_queries_not_using_indexes = @@global.log_queries_not_using_indexes;

SET GLOBAL long_query_time = 0;
SET GLOBAL log_queries_not_using_indexes = 1;

-- 执行需要监控的操作...

-- 恢复原设置
SET GLOBAL long_query_time = @old_long_query_time;
SET GLOBAL log_queries_not_using_indexes = @old_log_queries_not_using_indexes;

6.2 解决时间精度不一致问题

当客户端和服务端时间测量不一致时：

1. 使用微秒级精度测量：

   SET GLOBAL long_query_time = 0.5;
   

2. 在查询中嵌入时间测量：

   SELECT /*+ MAX_EXECUTION_TIME(1000) */ * FROM large_table;
   

3. 使用Performance Schema获取精确时间：

   SELECT * FROM performance_schema.events_statements_history_long 
   WHERE SQL_TEXT LIKE '%your_query%';
   

6.3 处理特殊语句的记录

某些管理语句可能被意外记录：

-- 禁用管理语句记录
SET GLOBAL log_slow_admin_statements = 'OFF';

-- 忽略特定模式的查询
SET GLOBAL log_slow_filter = 'mariadb_slow_filter';

7. 真实案例分析

某金融系统遇到慢日志异常记录问题，配置为long_query_time=1但记录了大量0.1-0.5秒的查询。经排查发现：

1. log_queries_not_using_indexes=ON导致所有未使用索引的查询被记录
2. 部分查询虽然执行快但检查行数多，触发了min_examined_row_limit
3. 网络延迟导致客户端测量时间比服务端长

解决方案：

1. 调整min_examined_row_limit=1000过滤小型查询
2. 为高频查询添加合适索引
3. 使用log_throttle_queries_not_using_indexes限制未使用索引查询的记录频率

调整后，慢日志体积减少80%，真正聚焦于性能瓶颈查询。