作者:张新力
爱可生交付服务部南区团队 DBA,主要负责公司自动化运维平台 DMP 维护和数据库日常问题处理。
本文来源:原创投稿
* 爱可生开源社区出品,原创内容未经授权不得随意使用,转载请联系小编并注明来源。

从事数据库运维工作的你,是否有遇到过慢日志大小飙升的经历?是否有见过 Slow_queries 变量数值布灵布灵跳动的场景?是什么原因导致的这个现象,是数据库出了 bug?还是深夜被告警惊醒后,睡眼朦胧时的错觉?下面让我们一起学习探究,愈发膨胀的慢日志是怎么“吃胖的”。

一般开启慢日志,我们只需要设置 slow_query_log=ON,slow_query_log_file= 存放路径,long_query_time= 慢查询的阈值即可,正常情况下慢日志大小不会有大的起伏。

但是,之前遇到过一次慢日志增长很快的情况,当查看慢日志具体内容时,并没有发现有耗时很高的 sql,只看到大量执行时间小于 1 秒的 sql 被记录进来。

再次确认慢查询参数设置正常后,异常 sql 还是不断的写进来,slow_queries 的数值也在不断地增大,这是为什么?难道是数据库出 bug 了?

在查询官方文档后发现,决定一条 sql 是否写入慢查询日志的因素,不仅仅是 long_query_time 参数。还有下面这“四大护法”

1. log_slow_admin_statements

该参数开启后,ALTER TABLE, ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE, and REPAIR TABLE 等操作也会被写入慢查询日志(前提条件是执行时间超过 long_query_time,并且 min_examined_row_limit=0 即不做限制)

2. log_queries_not_using_indexes 在启用慢查询日志的情况下启用此变量,会记录预期将检索所有行的查询,此选项不一定意味着不使用索引,参数默认是关闭状态。

3. min_examined_row_limit 查询操作扫描的行数小于该参数,则不会记录到慢查询日志中,默认值是 0 即不做限制。

4. log_throttle_queries_not_using_indexes 如果开启 log_queries_not_using_indexes 参数,log_throttle_queries_not_using_indexes 参数将会限制,此类查询每分钟写入慢日志中的数量,默认值是 0 表示无限制。

知道了这四个参数后,检查实例发现,log_queries_not_using_indexes 参数状态是开启的,记录的 sql 也是全表扫的操作。

随后便关闭了 log_queries_not_using_indexes 参数,再次观察慢日志不再急速增长了。

并且,慢日志中也没有继续写入该 sql 的记录了。导致慢日志”膨胀”的元凶找到了,那么 long_query_time,log_queries_not_using_indexes,min_examined_row_limit ,log_slow_admin_statements,log_throttle_queries_not_using_indexes 这几个参数之间有什么关联,他们又是如何手把手将“无辜的” sql 送入慢日志中的呢?

查询官方文档后,可以得知一条 sql 需要经如下流程,来判断是否写入慢日志

  1. 首先需开启慢日志记录 slow_query_log=ON

  2. sql 必须不是管理语句,或者 log_slow_admin_statements=ON

  3. sql 查询耗时超过 long_query_time 值,或者启用 log_queries_not_using_indexes,并且该查询不使用任何索引进行行查找。

  4. 该查询必须至少检查了 min_examined_row_limit 行。

  5. 根据 log_throttle_queries_not_using_indexes 设置,不得超过禁止的大小。

补充:经实际验证(mysql5.7.25)当 log_slow_admin_statements 开启后,若需要 ALTER TABLE, ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE, and REPAIR TABLE 等也会被记录的话,则不能设置 min_examined_row_limit 参数有限制。

验证:

设置

slow_query_log=ON

long_query_time=1

log_queries_not_using_indexes=ON

min_examined_row_limit=6

log_throttle_queries_not_using_indexes=3

情景 1:不使用索引,扫描行小于 6

慢查询日志不记录

情景 2:不使用索引,扫描行大于 6,查询数量大于 3

执行 3 次

执行 2 次

查看慢查询日志发现,仅仅记录了前三条查询

情景 3:开启 log_slow_admin_statements,并开启 min_examined_row_limit 参数,实际是不会记录的

慢日志中无记录

情景 4:开启 log_slow_admin_statements,关闭限制 min_examined_row_limit,会记录超时的操作

慢日志中有记录:通过慢日志记录可知,alter table 操作 Rows_examined 为 0,所以如果 min_examined_row_limit 参数大于 0 的话,该 sql 就不会被记录到慢日志中,不涉及到索引所以 alter table 操作也不受 log_throttle_queries_not_using_indexes 参数限制。

写入次数也不受限:

以上内容便是对影响慢日志写入原因的分析,若有不足之处请多多指教!

参考文章:

https://dev.mysql.com/doc/refman/5.7/en/slow-query-log.html