mysql5.7,啟用基于logical_clock的多線程復制,發現error日志增長很快，查看日志發現大量關于多線程復制的Note級別日志。1

2

3

4

5

6

7

8

9

10

11

12

13

14

152018-07-03T03:22:01.638371+08:00 8941 [Note] Multi-threaded slave statistics for channel '': seconds elapsed = 298; events assigned = 3043329; worker queues filled over ove

rrun level = 0; waited due a Worker queue full = 0; waited due the total size = 0; waited at clock conflicts = 725810947700 waited (count) when Workers occupied = 5346 wait

ed when Workers occupied = 0

2018-07-03T03:24:22.589147+08:00 8941 [Note] Multi-threaded slave statistics for channel '': seconds elapsed = 141; events assigned = 3044353; worker queues filled over ove

rrun level = 0; waited due a Worker queue full = 0; waited due the total size = 0; waited at clock conflicts = 725810947700 waited (count) when Workers occupied = 5346 wait

ed when Workers occupied = 0

2018-07-03T03:27:00.554437+08:00 8941 [Note] Multi-threaded slave statistics for channel '': seconds elapsed = 158; events assigned = 3045377; worker queues filled over ove

rrun level = 0; waited due a Worker queue full = 0; waited due the total size = 0; waited at clock conflicts = 725818557700 waited (count) when Workers occupied = 5346 wait

ed when Workers occupied = 0

2018-07-03T03:32:00.079699+08:00 8941 [Note] Multi-threaded slave statistics for channel '': seconds elapsed = 300; events assigned = 3047425; worker queues filled over ove

rrun level = 0; waited due a Worker queue full = 0; waited due the total size = 0; waited at clock conflicts = 725846344900 waited (count) when Workers occupied = 5346 wait

ed when Workers occupied = 0

2018-07-03T03:34:04.567887+08:00 8941 [Note] Multi-threaded slave statistics for channel '': seconds elapsed = 124; events assigned = 3048449; worker queues filled over ove

rrun level = 0; waited due a Worker queue full = 0; waited due the total size = 0; waited at clock conflicts = 725852036800 waited (count) when Workers occupied = 5346 wait

ed when Workers occupied = 0

通過日期可以看到，日志的打印頻率大概在3分鐘左右。error log是mysql 出現問題時的重要分析日志，大量的note日志可能很快就把重要日志信息埋沒,給分析日志信息帶來了不便。而且日志量隨時間遞增，還必須有rotate機制，不然占用大量磁盤空間。那么這個日志的打印頻率能不能調低一些呢？

我看了下源碼這塊的實現(rpl_slave.cc 4800)1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

20

21

22

23

24

25

26

27

28

29*ptr_ev= NULL; // announcing the event is passed to w-worker

if (rli->is_parallel_exec() && rli->mts_events_assigned % 1024 == 1)

{

time_t my_now= my_time(0);

if ((my_now - rli->mts_last_online_stat) >=

mts_online_stat_period)

{

sql_print_information("Multi-threaded slave statistics%s: "

"seconds elapsed = %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 "

"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;

我們從兩個if語句可以看到，這個信息的打印受三個條件的控制：rli->is_parallel_exec() 這是個inline函數，它判斷是否在使用多線程復制

rli->mts_events_assigned % 1024 == 1 多線程執行的event個數剛剛超過1024個。也就是說按evnet個數來算，每隔1024個event打印一次。

最后還有個時間限制：(my_now - rli->mts_last_online_stat) >= mts_online_stat_period，距離上一次統計超過既定的間隔mts_online_stat_period。這個變量是60*2 ,代碼里寫死了。1

2

3

4/*

Statistics go to the error log every # of seconds when --log-warnings > 1

*/

const long mts_online_stat_period= 60 * 2;

由此可以判斷，這個日志打印頻率最少為2分鐘，沒法改了。但上面的代碼注釋中給了提示，當–log-warnings > 1時，這個統計間隔才生效，意味著可以通過修改日志打印級別來控制。

自mysql5.7.2，log-warnings被廢棄，引用了新的變量log_error_verbosity。這個變量有三個值：1、2、3，默認是3. 他們的意義是：

1 – Errors Only

2 – Errors and warnings

3 – Errors, warnings, and notes

我們可以修改這個變量為2 ，不再打印Note信息。1set global log_error_verbosity=2;

總結

以上是生活随笔為你收集整理的mysql 5.7 mts_mysql5.7 中启用MTS后error log中大量Note日志分析的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。