MySQL错误日志分析

最近这段时间，线上的一个生产库，经常看到内存用的很满，而且磁盘IO出现告警，于是打开错误日志，分析了一下，其中一条note引起了注意，如下，

2019-05-04T00:58:57.708768+08:00 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4111ms. The settings might not

be optimal. (flushed=1164 and evicted=0, during the time.)

2019-05-04T00:59:43.866249+08:00 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4335ms. The settings might not

be optimal. (flushed=1041 and evicted=0, during the time.)

2019-05-04T01:05:19.581244+08:00 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 5172ms. The settings might not

be optimal. (flushed=731 and evicted=0, during the time.)

2019-05-04T02:29:15.037309+08:00 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4073ms. The settings might not

be optimal. (flushed=148 and evicted=0, during the time.)

我们从这个日志中可以了解到，我们刷脏页的page_cleaner一直在输出日志，想到翻看源码，从源码包storage的innobase目录下的buf中找到buf0flu.cc这个代码文件，经过网上查询以及分析，定位到了上面输出的源代码位置，如下：

通过这段源码，我们可以知道，触发它输出日志的条件主要是，curr_time > next_loop_time + 3000即当前实际刷脏页的时间比原定的时间超出很多，而next_loop_time的标准时间是1000毫秒，即1秒钟做一次刷新页的操作，这里就牵出了我们master thread主线程中loop主循环的每1秒的操作和每10秒的操作，如下

日志后面输出的(flushed=148 and evicted=0, during the time.)，对应n_flushed_last与n_evicted 变量，而这两个变量又由n_flushed_list与n_flushed_lru赋值。

而这两个变量的赋值函数为pc_wait_finished，我们再来看下对于这个函数的注释，

这里我只拉了一部分代码注释，其中主要是一些条件判断刷新页的操作。

n_flushed_lru 这个值表示从lru 列表尾部刷新的页数，也就是日志中如evicted=0 指标的所表示的值。

最后与开发人员沟通了一下，得知这套库平常以写入居多，刷新页的操作很频繁，导致IO吃紧，又

找了一些网上大神的博客总结，根据官方文档中针对page_cleaner线程的描述我们将innodb_lru_scan_depth参数做了调整，默认是1024，调整成了 innodb_io_capacity / innodb_buffer_pool_instances=300，后续需要继续跟踪观察错误日志。

https://blog.csdn.net/isoleo/article/details/54342180

https://yq.aliyun.com/articles/41005