作者:张新力
爱可生交付服务部南区团队 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 参数。还有下面这“四大护法”
该参数开启后,ALTER TABLE, ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE, and REPAIR TABLE 等操作也会被写入慢查询日志(前提条件是执行时间超过 long_query_time,并且 min_examined_row_limit=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 需要经如下流程,来判断是否写入慢日志
补充:经实际验证(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