mysqlnote级别_Mysql5.7的错误⽇志中最常见的note级别⽇志
解释
在使⽤mysql5.7的时候，发现了不少在mysql5.6上不曾见过的⽇志，级别为note, 最常见的note⽇志以下三种，下⾯我们来逐个解释。
第⼀种，Aborted connection. 如上图，信息如下：
2016-03-17T14:44:24.102542Z 59 [Note] Aborted connection 59 to db: ‘unconnected’ ur: ‘mha’ host:
‘’ (Got an error reading communication packets)
2016-03-17T14:44:31.273897Z 61 [Note] Aborted connection 61 to db: ‘unconnected’ ur: ‘mha’ host:
‘(Got an error reading communication packets)
2016-03-17T14:44:31.273897Z 61 [Note] Aborted connection 61 to db: ‘unconnected’ ur: ‘mha’ host:
‘(Got an error reading communication packets)
2016-03-17T14:44:31.273897Z 61 [Note] Aborted connection 61 to db: ‘unconnected’ ur: ‘mha’ host:
‘(Got timeout reading communication packets)
上⾯两个是连接中断的错误信息，原因不⼀样，Got an error reading communication packets 的原因是因为⽹络等原因导致。 Got timeout reading communication packets 这个错误的原因是会话的idle时间达到了数据库指定的timeout时间。
第⼆种：SLAVE多线程同步的信息
信息如下：
2016-03-14T15:48:26.432150Z 73 [Note]Multi-threaded slave statistics for channel ”: conds elapd = 121; eventsassigned = 100374529; worker queues filled over
overrun level = 0; waited due aWorker queue full = 0; waited due the total size = 0; waited at clock conflicts= 1451875661700 waited (count) when Workers occupied = 3211993 waited whenWorkers occupied = 445032386000
2016-03-14T15:50:28.398745Z 73 [Note]Multi-threaded slave statistics for channel ”: conds elapd = 122; eventsassigned = 100500481; worker queues filled over
overrun level = 0; waited due aWorker queue full = 0; waited due the total size = 0; waited at clock conflicts= 1452001865500 waited (count) when Workers occupied = 3211993 waited whenWorkers occupied = 445032386000
我们通过源代码，找到下⾯⼀段，该段实现了上述⽇志的输出。
if ((my_now
– rli->mts_last_online_stat)>=
mts_online_stat_period)
{
sql_print_information(“Multi-threadedslave涨价 英文
英语学习方法总结statistics%s: “
“conds
elapd = %lu; “
“events
assigned = %llu; “
“worker
queues filled over overrun level = %lu;”
“waited
due a Worker queue full = %lu; “
中英翻译“waited
due the total size = %lu; “
“waited
at clock conflicts = %llu “
easterisland
“waited(count)
when Workers occupied = %lu “
“waited
when Workers occupied = %llu”,
rli->get_for_channel_str(),
static_cast
(my_now – rli->mts_last_online_stat),
rli->mts_events_assigned,
rli->mts_wq_overrun_cnt,
rli->mts_wq_overfill_cnt,
rli->wq_size_waits_cnt,英语学校
rli->mts_total_wait_overlap,
rli->mts_wq_no_underrun_cnt,
rli->mts_total_wait_worker_avail);
rli->mts_last_online_stat=my_now;
通过这⼀句(my_now
– rli->mts_last_online_stat), 以及最后⼀句rli->mts_last_online_stat=my_now; 可以得知，
conds elapd 就是上⼀次统计跟这⼀次统计的时间间隔。
⽽mts_online_stat_period =120秒，硬代码，因此就是⼏乎每隔120秒，就有上述⽇志的输出。
通过进⼀步查看原代码，初步了解上述⽇志信息的含义，如下：
events assigned：总共有多少个event被分配执⾏，计的是总数。
worker queues filled over overrun level：多线程同步中，worker 的私有队列长度超长的次数，计的是总数。waited due a Worker queue full ：因为worker的队列超长⽽产⽣等待的次数，计的是总数。
waited due the total size ：超过最⼤size的次数，这个由参数slave_pending_jobs_size_max 指定。
waited at clock conflicts ：因为逻辑时间产⽣冲突的等待时间，单位是纳秒。
waited (count) when Workers occupied ：因为workder被占⽤⽽出现等待的次数。(总计值)。
waited when Workersoccupied ：因为workder被占⽤⽽出现等待的总时间，总计值，单位是纳秒。
第三种：page_cleaner线程的输出⽇志
如图，信息如下：
2016-03-24T17:45:28.005117Z 0 [Note] InnoDB:page_cleaner: 1000ms intended loop took 4750ms.The ttings might not be optimal. (flushed=1519 and evicted=0, during the time.)
查找源代码，发现是上⾯的⽇志由下⾯⼀段代码输出：
the strokes
if (ret_sleep
== OS_SYNC_TIME_EXCEEDED) {
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
<省会英语
ttings might not”
” be optimal.
(flushed=”
pboc<
<
<
<
the time.)”;
if (warn_interval
>300) {
六级成绩查询2020年9月warn_interval= 600;
}el {
warn_interval*= 2;
}
warn_count= warn_interval;
} el {
–warn_count;
}
} el {
/* ret counter */
warn_interval= 1;
warn_count= 0;
}
next_loop_time= curr_time + 1000;
n_flushed_last= n_evicted = 0;
}
通过分析源代码， 输出上述⽇志的条件是curr_time> next_loop_time + 3000 ，即⽐原定的循环时间next_loop_time多3000毫秒，⽽next_loop_time的标准时间是1000毫秒，即1秒钟做⼀次刷新页的操作。
loop took 4750ms ，即是这次刷新循环的实际经历时间。
后⾯还有⼀个(flushed=1519 and evicted=0,during the time.)这样的⽇志，即对应n_flushed_last与n_evicted 变量，⽽这两个变量⼜由n_flushed_list与n_flushed_lru赋值。
./storage/innoba/:3322: n_flushed_last +=n_flushed_list;
./storage/innoba/:3321: n_evicted += n_flushed_lru;
⽽n_flushed_list与n_flushed_lru赋值函数为pc_wait_finished，如下，我们来看看该函数的注释。
pc_wait_finished(&n_flushed_lru,&n_flushed_list);
/**
Wait until all flush requests are finished.
@param n_flushed_lru numberof pages flushed from the end of the LRU list.
@param n_flushed_list numberof pages flushed from the end of the
flush_list.
@return trueif all flush_list flushing batch were success. */
static
bool
pc_wait_finished(
ulint* n_flushed_lru,
ulint* n_flushed_list)
{
。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。。
}
通过源代码的注释，我们获知如下信息：
n_flushed_lru number of pages flushed from the end of the LRU list.
8点20分发n_flushed_lru 这个值表⽰从lru 列表尾部刷新的页数，也就是⽇志中如evicted=0 指标的所表⽰的值，如果该值不为零，则存在innodbbuffer不够的嫌疑。
n_flushed_list 这个是从刷新列表中刷新的页数，也就是脏页数，也就是⽇志中flushed=1519 的值。
