这两个参数总体说来控制了如果用户线程(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)