由于数据库实例中可能有较多不走索引的 SQL 语句,若开启 log_queries_not_using_indexes,则存在日志文件或表容量增长过快的风险,此时可通过设置 log_throttle_queries_not_using_indexes 来限制每分钟写入慢日志中的不走索引的 SQL 语句个数,该参数默认为 0,表示不开启,也就是说不对写入 SQL 语句条数进行控制。启用后,系统会在第一条不走索引的查询执行后开启一个 60s 的窗口,在该窗口内,仅记录最多 log_throttle_queries_not_using_indexes 条 SQL 语句。超出部分将被抑制,在时间窗结束时,会打印该窗口内被抑制的慢查询条数以及这些慢查询一共花费的时间。下一个统计时间窗并不是马上创建,而是在下一条不走索引的查询执行后开启。对应到该线上问题,log_throttle_queries_not_using_indexes 被设置为 10,在日志文件中看到周期性打印了如下内容:
确实符合上面描述的现象,用户的慢日志应该是被抑制了,汇总到了 359 里面去。我们尝试将 log_throttle_queries_not_using_indexes 设置为 0,再执行对应的 SQL 语句,果然在日志文件中记录了相应的 SQL 语句。这个线上问题似乎已经定位到了,就是系统产生的不走索引的慢日志太多,而设置的 log_throttle_queries_not_using_indexes 太小,导致无法正常记录用户未走索引的慢日志。但还有一个疑惑点没有解决,那就是 log_throttle_queries_not_using_indexes 为 0 时,每分钟并没有打印超过 10 条慢日志,更没有 throttle 提示的 359 条这么多,那么设置为 10 的时候用户提供的那条 SQL 语句应该被记录到慢日志中才对啊,为何没有记录,原因何在?其实,仔细看下 MySQL 记录不走索引的日志的代码逻辑可以找到答案:
上图是记录慢日志的主逻辑,是否记录日志由函数 log_slow_applicable 控制,该函数先前已分析了一部分,我们进一步看该函数的其他相关内容,见下图红框:
Suppress_logging 是个决定性的变量,只有它为 false,该 SQL 语句才可能被记录。其结果就跟 log_throttle_queries_not_using_indexes 相关,我们进一步看下 log_throttle_qni.log 相关实现,如下图:
Eligible 即为 warn_no_index,inc_log_count() 函数在 1 分钟内不走索引的语句总数超过 log_throttle_queries_not_using_indexes 时返回值为 true,只有 warn_no_index 和 inc_log_count() 返回值都为 true,suppress_current 才为 true,而 suppress_current 即为 suppress_logging。通过对上述 2 个截图内容进行分析,可以解答之前的疑惑点:log_throttle_queries_not_using_indexes 统计的是所有不走索引的语句,其中有些语句因为不满足扫描记录数的约束而不会记录到慢日志中,这就是为什么该值为 10 的时候,慢日志文件中并没有 10 条记录。因为这 10 条中有 8 条 SQL 语句由于扫描记录数太少并没有被记录。
这也解惑了上图中 359 这个数字,它是这个时间窗内不走索引的 SQL 语句总数。所以,log_throttle_queries_not_using_indexes 是个很关键的参数,设置不当会无法正常记录不走索引的慢查询,导致慢日志功能部分失效。所以,用户首先需尽可能避免出现大量不走索引的 SQL 语句,可以通过 RDS 健康检查功能进行优化,再次,若出现慢日志中存在上述提示,应该调大 log_throttle_queries_not_using_indexes 的值,以便以进一步分析问题。
来源: http://www.roncoo.com/article/detail/131610