背景
线上多套数据库集群遇到问题无法写入,具体表象如下:
1.错误日志出现如下类似信息:
page_cleaner: 1000ms intended loop took 8397ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)
2.业务sql执行超时失败
3.磁盘无写入但是io util为100%,如下图
基础知识
控制刷盘的线程
master_thread(5.6早期)---------->单个pager_leaner thread(5.7初期)------>多个pager_cleaner thread(后期)
控制刷盘相关参数:
1.innodb_buffer_pool_size=N
2.innodb_buffer_pool_instances=N #bufferpool instance
3.innodb_max_dirty_pages_pct_lwm=N #是否开启预刷5.7默认0,表示关闭
4.innodb_page_cleaners=N #page_cleaner的线程数量,如果该值大于innodb_buffer_pool_instances则自动调整为与innodb_buffer_pool_instances数量一致
5.innodb_max_dirty_pages_pct=N #
6.innodb_flush_neighbors=0|1|2 #0表示关闭,1表示刷新同一extent(64个页面)中连续的脏页面,2表示刷新同一个extent中所有的脏页
7.innodb_lru_scan_depth=N #控制扫描lru列表的深度
8.innodb_adaptive_flushing_lwm=N #
9.innodb_io_capacity=N
10.innodb_io_capacity_max=N
刷脏策略:
Adaptive Flushing
redo生成速度
redo切换
当前刷盘速率
问题
1.page_cleaner工作机制及mysql错误日志为什么会输出刷盘超时日志
2.为什么出现page_cleaner这段时间出现了数据库无法写入
3.为什么出现page_cleaner这段时间磁盘无写入但是io打满
问题1分析(page_cleaner工作机制及mysql错误日志为什么会打印超时日志)
#(page_cleaner工作机制及错误日志输出信息对应的源码如下(仅仅保留了关注代码)
page_cleaner工作时机:
1.启动mysqld时需要recover,此时要进行刷脏
buf_page_cleaner_is_active = true;
while (!srv_read_only_mode && srv_shutdown_state == SRV_SHUTDOWN_NONE && recv_sys->heap != NULL) { /*启动时recover innodb调用*/
/* treat flushing requests during recovery. */
ulint n_flushed_lru = 0;
ulint n_flushed_list = 0;
os_event_wait(recv_sys->flush_start);
if (srv_shutdown_state != SRV_SHUTDOWN_NONE || recv_sys->heap == NULL) {
break;
}
switch (recv_sys->flush_type) {
case BUF_FLUSH_LRU: /*刷lru列表*/
/* Flush pages from end of LRU if required */
pc_request(0, LSN_MAX);
while (pc_flush_slot() > 0) {}
pc_wait_finished(&n_flushed_lru, &n_flushed_list);
break;
case BUF_FLUSH_LIST: /*刷flush列表*/
/* Flush all pages */
do {
pc_request(ULINT_MAX, LSN_MAX);
while (pc_flush_slot() > 0) {}
} while (!pc_wait_finished(&n_flushed_lru,&n_flushed_list));
break;
default:
ut_ad(0);
}
os_event_reset(recv_sys->flush_start);
os_event_set(recv_sys->flush_end);
}
2.mysqld正常运转时按照以下3种场景进行刷脏:
while (srv_shutdown_state == SRV_SHUTDOWN_NONE){
if (ret_sleep == OS_SYNC_TIME_EXCEEDED) { /*如果此次刷脏页的当前时间 > next_loop_time+3000,则输出日志到错误日志,并重置下一次next_loop_time、n_flushed_last、n_evicted*/
ulint curr_time = ut_time_ms();
if (curr_time > next_loop_time + 3000) {
if (warn_count == 0) {
ib::info() << "page_cleaner: 1000ms intended loop took 1000 + curr_time - next_loop_time ms. The settings might not be optimal. (flushed=n_flushed_last and evicted=n_evicted, during the time.)";
if (warn_interval > 300) {
warn_interval = 600;
} else {
warn_interval *= 2;
}
warn_count = warn_interval;
} else {
--warn_count;
}
} else {
/* reset counter */
warn_interval = 1;
warn_count = 0;
}
next_loop_time = curr_time + 1000;
n_flushed_last = n_evicted = 0;
}
/*有活跃线程说明系统繁忙等等再刷,有阻塞的io说明io比较繁忙稍后再刷,上一次刷脏为0说明脏页已经被刷完了稍后再刷,原则就是不必要的刷脏不要影响业务*/
if (srv_check_activity(last_activity) || buf_get_n_pending_read_ios() || n_flushed == 0) {
ret_sleep = pc_sleep_if_needed(next_loop_time, sig_count); /*这个位置休眠1秒*/
if (srv_shutdown_state != SRV_SHUTDOWN_NONE) {
break;
}
} else if (ut_time_ms() > next_loop_time) {
ret_sleep = OS_SYNC_TIME_EXCEEDED;
} else {
ret_sleep = 0;
}
if (ret_sleep != OS_SYNC_TIME_EXCEEDED && srv_flush_sync && buf_flush_sync_lsn > 0) /*同步刷脏,srv_flush_sync位true表示剧烈刷脏跳过io_capacity限制*/
{
pc_request(ULINT_MAX, lsn_limit); /*ULINT_MAX为要刷的脏页数量,lsn_limit为要刷新到lsn的位置*/
while (pc_flush_slot() > 0) {} /*如果worker线程不够用了则协调线程也参与刷脏*/
pc_wait_finished(&n_flushed_lru, &n_flushed_list); /*等待所有线程完成刷脏*/
n_flushed = n_flushed_lru + n_flushed_list; /*统计此次共刷了多少脏页面*/
/*更新后台已完成刷脏相关变量*/
}
else if (srv_check_activity(last_activity)) /*当前有活跃线程,有ddl、dml刷脏*/
{
n_to_flush = page_cleaner_flush_pages_recommendation(&lsn_limit, last_pages); /*确定此次刷新脏页的数量*/
pc_request(n_to_flush, lsn_limit); /*唤醒工作线程刷脏,n_to_flush为要刷的脏页数量*/
while (pc_flush_slot() > 0) {} /*如果worker线程不够用了则协调线程也参与刷脏*/
pc_wait_finished(&n_flushed_lru, &n_flushed_list); /*等待所有线程完成刷脏*/
/*更新后台已完成刷脏相关变量*/
}
else if (ret_sleep == OS_SYNC_TIME_EXCEEDED) /*空闲刷脏*/
{
buf_flush_lists(PCT_IO(100), LSN_MAX, &n_flushed); /*按照innodb_io_capacity配置最大限度100%刷脏*/
/*更新后台已完成刷脏相关变量*//
}
else {
n_flushed = 0;
}
}
#从源码处可以了解到当mysql正常运行期间,如果上一次bufferpool页面刷盘时间大于1s+3s就会触发打印这条日志