MySQL:关于参数innodb_log_spin_cpu_abs_lwm和innodb_log_spin_cpu_pct_hwm


这两个参数总体说来控制了如果用户线程(session)正在等待redo write/flush,控制进行多少次spin操作,还是直接放弃CPU进入mutex wait。下面我们简单看看实现过程,经过下面的分析来看innodb_log_spin_cpu_pct_hwm的作用更大,特别是在高负载下面,低负载一般问题不大。


一、前言

关于MySQL 8中我们新增了几个redo相关的线程,主要为:

  • log_writer线程:将redo写到redo文件
  • log_write_notifier线程:通知用户会话写入redo文件结束
  • log_flusher线程:将redo fsync到redo文件
  • log_flush_notifier线程:通知用户会话fsync结束
  • log_checkpointer线程:定期检查脏数据写盘的redo 位置

具体实现很多文章已经分析过了,而这两个参数和writer和flusher均有关系。主要是通过计算当前CPU的负载来判定如果遇到redo刷盘等待后是否耗用CPU去做spin。
下面引用的文章(https://zhuanlan.zhihu.com/p/88427657)说明好处如下:

  • Spinlock优点:没有昂贵的系统调用,一直处于用户态,执行速度快

  • Spinlock缺点:一直占用cpu,而且在执行过程中还会锁bus总线,锁总线时其他处理器不能使用总线

  • Mutex优点:不会忙等,得不到锁会sleep

  • Mutex缺点:sleep时会陷入到内核态,需要昂贵的系统调用

而我们Innodb中大量使用的是先进行spin,如果spin一定次数不能获得,则转入mutex等待(或者sleep),放弃CPU,本处也是如此。

二、关于CPU时间的统计

稍微看了一下如下:

double cpu_utime = cpu_utime_diff * 100.0 / time_diff; 
//CPU 占用时间和自然时间的比率,这个比率应该是整体CPU负载,
//可能达到100%以上,单核为100%,2核200%(不包含SY%时间仅仅为mysql代码占用CPU时间) 
srv_cpu_usage.utime_abs = cpu_utime; 
//上面的计算比率
cpu_utime /= n_cpu;
srv_cpu_usage.utime_pct = cpu_utime; 
//上面的计算比率/CPU,为单核的时间
  • srv_cpu_usage.utime_abs主要用于和参数innodb_log_spin_cpu_abs_lwm比较,这是一个百分比。
  • srv_cpu_usage.utime_pct主要用于和参数innodb_log_spin_cpu_pct_hwm比较。

当然这里到底如何计算的CPU时间,没有去看代码。后面看看。

三、关于计算方式

算法(log_wait_for_write->log_max_spins_when_waiting_in_user_thread):

如果 整体占用CPU比率小于innodb_log_spin_cpu_abs_lwm(默认80%)或者单核占用比例大于innodb_log_spin_cpu_pct_hwm(默认50%)
     则说明负载很高或者 it's almost idle so no reason to bother.
     则 max_spins = 0 标记spins次数为0,
如果 单核占用比例大于等于(innodb_log_spin_cpu_pct_hwm(默认50%)/2)
     则 max_spins = 25000 spins次数为25000
否则 服务器压力不大,可以进行自旋
     则 max_spins = 25000 + 
     ((innodb_log_spin_cpu_pct_hwm(默认50%) / 2 - 当前单核占用CPU比率 ) 
     / (innodb_log_spin_cpu_pct_hwm(默认50%) / 2)) * 25000 * 9

本函数得出是每轮spin次数,本处条件整体占用CPU比率小于innodb_log_spin_cpu_abs_lwm(默认80%)比较费解,注释说( it's almost idle so no reason to bother.),对于我们线上一般是32或者64 或者更多的core,80%确实是一个比较空闲的比率,可能过于空闲说明压力太小,没必要做spin去及时判断条件。
注意这里的整体占用CPU比率来自srv_cpu_usage.utime_abs,而单核占用比例来自srv_cpu_usage.utime_pct。

四、本处spin使用方式

通过上面的计算方式就得到了每轮spin的次数,这里我们以log writer线程为例(flusher也是一样的),log_wait_for_write调入os_event_wait_for实现,并且带入本函数lambda函数,大概逻辑如下:

我们也可以看层两层循环,实际为一层:
第一层(每轮spin):
   第二层(每轮中每次spin):
     spin一次,判断条件
     log.write_lsn.load() >= lsn(本次session需要写入的lsn)
     是否满足,如果满足退出等待。
     否则继续,直到每轮spin次数耗尽。
   增加waits次数
   进入os pthread_cond_timedwait等待,等待时间为1秒(1000毫秒),醒来后继续循环,轮数+1 ,进入mutex等待就放弃了cpu

这个条件会一致等待,知道条件满足返回值为waits次数。

我们可以看到spin的条件就是log.write_lsn.load() >= lsn,也就是本session 本事务的redo 已经完全write到了redo,当然后续的flush也是一样。

证明如下:

这里只要稍微修改上层的函数的end_lsn 到一个当前redo 没有达到的位置就会反复的出现等待便于调试

os_event::wait_time_low (this=0x7fffe1cc49e0, time_in_usec=100000, reset_sig_count=1) at /newdata/mysql-8.0.23/storage/innobase/os/os0event.cc:456
456       bool timed_out = false;
(gdb) n
469       if (time_in_usec != OS_SYNC_INFINITE_TIME) {
(gdb) n
470         abstime = os_event::get_wait_timelimit(time_in_usec);
(gdb) n
476       ut_a(abstime.tv_nsec <= 999999999);
(gdb) n
480       mutex.enter();
(gdb) S
OSMutex::enter (this=0x7fffe1cc49f0) at /newdata/mysql-8.0.23/storage/innobase/include/sync0types.h:537
537         ut_ad(innodb_calling_exit || !m_freed);
(gdb) n
541         int ret = pthread_mutex_lock(&m_mutex); //加锁
(gdb) n
542         ut_a(ret == 0);
(gdb) n
544       }
(gdb) bt
#0  OSMutex::enter (this=0x7fffe1cc49f0) at /newdata/mysql-8.0.23/storage/innobase/include/sync0types.h:544
#1  0x00000000050b7dc6 in os_event::wait_time_low (this=0x7fffe1cc49e0, time_in_usec=100000, reset_sig_count=1) at /newdata/mysql-8.0.23/storage/innobase/os/os0event.cc:480
#2  0x00000000050b802e in os_event_wait_time_low (event=0x7fffe1cc49e0, time_in_usec=100000, reset_sig_count=1) at /newdata/mysql-8.0.23/storage/innobase/os/os0event.cc:588
#3  0x00000000050920b1 in os_event_wait_for<log_wait_for_flush(const log_t&, lsn_t, bool*)::<lambda(bool)> >(os_event_t &, uint64_t, uint64_t, <lambda(bool)>) (
   event=@0x7fffe1c8d520: 0x7fffe1cc49e0, spins_limit=0, timeout=100000, condition=...) at /newdata/mysql-8.0.23/storage/innobase/include/os0event.ic:135
#4  0x000000000508929c in log_wait_for_flush (log=..., lsn=38456686, interrupted=0x7fffe47cad37) at /newdata/mysql-8.0.23/storage/innobase/log/log0write.cc:891
#5  0x000000000508a56b in log_write_up_to (log=..., end_lsn=38456686, flush_to_disk=true) at /newdata/mysql-8.0.23/storage/innobase/log/log0write.cc:1119
#6  0x0000000005258a2d in trx_flush_log_if_needed_low (lsn=18456686) at /newdata/mysql-8.0.23/storage/innobase/trx/trx0trx.cc:1639
#7  0x0000000005258b06 in trx_flush_log_if_needed (lsn=18456686, trx=0x7fffe5be9078) at /newdata/mysql-8.0.23/storage/innobase/trx/trx0trx.cc:1663
#8  0x000000000525a7f2 in trx_commit_complete_for_mysql (trx=0x7fffe5be9078) at /newdata/mysql-8.0.23/storage/innobase/trx/trx0trx.cc:2332
#9  0x0000000004f1aa05 in innobase_commit (hton=0xaa39bf0, thd=0xad3d040, commit_trx=false) at /newdata/mysql-8.0.23/storage/innobase/handler/ha_innodb.cc:5439
#10 0x0000000003b6e61a in ha_commit_low (thd=0xad3d040, all=false, run_after_commit=true) at /newdata/mysql-8.0.23/sql/handler.cc:1937
#11 0x00000000049aa16e in MYSQL_BIN_LOG::commit (this=0x84b9140 <mysql_bin_log>, thd=0xad3d040, all=false) at /newdata/mysql-8.0.23/sql/binlog.cc:7962
#12 0x0000000003b6e01c in ha_commit_trans (thd=0xad3d040, all=false, ignore_global_read_lock=false) at /newdata/mysql-8.0.23/sql/handler.cc:1757
#13 0x000000000398255e in trans_commit_stmt (thd=0xad3d040, ignore_global_read_lock=false) at /newdata/mysql-8.0.23/sql/transaction.cc:532
#14 0x00000000037fab08 in mysql_execute_command (thd=0xad3d040, first_level=true) at /newdata/mysql-8.0.23/sql/sql_parse.cc:4573
#15 0x00000000037fbf41 in dispatch_sql_command (thd=0xad3d040, parser_state=0x7fffe47cda50) at /newdata/mysql-8.0.23/sql/sql_parse.cc:4988
#16 0x00000000037f2543 in dispatch_command (thd=0xad3d040, com_data=0x7fffe47ceb00, command=COM_QUERY) at /newdata/mysql-8.0.23/sql/sql_parse.cc:1836
#17 0x00000000037f095e in do_command (thd=0xad3d040) at /newdata/mysql-8.0.23/sql/sql_parse.cc:1320
#18 0x00000000039c5c91 in handle_connection (arg=0xab180d0) at /newdata/mysql-8.0.23/sql/conn_handler/connection_handler_per_thread.cc:301
#19 0x000000000562cd84 in pfs_spawn_thread (arg=0xaa3a100) at /newdata/mysql-8.0.23/storage/perfschema/pfs.cc:2900
#20 0x00007ffff7bc6ea5 in start_thread () from /lib64/libpthread.so.0
#21 0x00007ffff5e388dd in clone () from /lib64/libc.so.6

(gdb) n
os_event::wait_time_low (this=0x7fffe1cc49e0, time_in_usec=100000, reset_sig_count=1) at /newdata/mysql-8.0.23/storage/innobase/os/os0event.cc:482
482       if (!reset_sig_count) {
(gdb) n
487         if (m_set || signal_count != reset_sig_count) {
(gdb) n
492         timed_out = timed_wait(&abstime); 
(gdb) n
497       } while (!timed_out);//等待超时
(gdb) n
499       mutex.exit();
(gdb) S
OSMutex::exit (this=0x7fffe1cc49f0) at /newdata/mysql-8.0.23/storage/innobase/include/sync0types.h:526
526         ut_ad(innodb_calling_exit || !m_freed);
(gdb) n
530         int ret = pthread_mutex_unlock(&m_mutex);//解锁
(gdb) n
531         ut_a(ret == 0);
(gdb) n
533       }
(gdb) 

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 157,298评论 4 360
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 66,701评论 1 290
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 107,078评论 0 237
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 43,687评论 0 202
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 52,018评论 3 286
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 40,410评论 1 211
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 31,729评论 2 310
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 30,412评论 0 194
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 34,124评论 1 239
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 30,379评论 2 242
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 31,903评论 1 257
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 28,268评论 2 251
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 32,894评论 3 233
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 26,014评论 0 8
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 26,770评论 0 192
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 35,435评论 2 269
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 35,312评论 2 260

推荐阅读更多精彩内容