作者简介:高鹏,笔名八怪。《深入理解MySQL主从原理》图书作者,同时运营个人公众号“MySQL学习”,持续分享遇到的有趣case以及代码解析!
源码版本5.7.29。主库端的回调函数比较多,比较复杂。
一、回调函数:repl_semi_binlog_dump_start
调用线程:dump线程
#0 repl_semi_binlog_dump_start (param=0x7fffe8150ba0, log_file=0x7fffe81520c0 "", log_pos=4) at /home/mysql/soft/percona-server-5.7.29-32/plugin/semisync/semisync_master_plugin.cc:127
#1 0x00000000013dca8e in Binlog_transmit_delegate::transmit_start (this=0x2d1c980 , thd=0x7ffdec000b90, flags=0, log_file=0x7fffe81520c0 "", log_pos=4,
observe_transmission=0x7fffe8151e24) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_handler.cc:726
#2 0x000000000182233e in Binlog_sender::init (this=0x7fffe8151490) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_binlog_sender.cc:119
#3 0x0000000001822611 in Binlog_sender::run (this=0x7fffe8151490) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_binlog_sender.cc:208
#4 0x000000000182040a in mysql_binlog_send (thd=0x7ffdec000b90, log_ident=0x7fffe81520c0 "", pos=4, slave_gtid_executed=0x7fffe8151e90, flags=0)
at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_master.cc:421
#5 0x00000000018202d6 in com_binlog_dump_gtid (thd=0x7ffdec000b90, packet=0x7ffdec00a8b1 "", packet_length=123) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_master.cc:405
#6 0x00000000014b76ef in dispatch_command (thd=0x7ffdec000b90, com_data=0x7fffe8152c90, command=COM_BINLOG_DUMP_GTID) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:1754
#7 0x00000000014b5a94 in do_command (thd=0x7ffdec000b90) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:1060
#8 0x00000000015e9d32 in handle_connection (arg=0x7019220) at /home/mysql/soft/percona-server-5.7.29-32/sql/conn_handler/connection_handler_per_thread.cc:325
#9 0x00000000018b97f2 in pfs_spawn_thread (arg=0x6f595f0) at /home/mysql/soft/percona-server-5.7.29-32/storage/perfschema/pfs.cc:2198
#10 0x00007ffff7bc6ea5 in start_thread () from /lib64/libpthread.so.0
#11 0x00007ffff5f2b8dd in clone () from /lib64/libc.so.6
dump线程可以参考 https://www.jianshu.com/p/de323358fd49
回调方式:
Binlog_sender::init
Binlog_sender::check_start_file之后调用插件函数
if (RUN_HOOK(binlog_transmit, transmit_start,
(thd, m_flag, m_start_file, m_start_pos,
&m_observe_transmission)))
调入
binlog_transmit_delegate->transmit_start
调入
repl_semi_binlog_dump_start(Binlog_transmit_param *param, //server id和flag
const char *log_file, //文件名
my_off_t log_pos)//位点
如果是GTID这里pos没有实际意义,因为这个时候刚刚读取了从库发送过来的binlog位点信息,但是gtid实际没有传输实际的位点信息。
函数过程:
repl_semi_binlog_dump_start
->get_user_var_int("rpl_semi_sync_slave", &semi_sync_slave, NULL); //获取线程rpl_semi_sync_slave参数,这是io线程会发起的设置参考从库repl_semi_slave_request_dump的回调函数
//本参数为dump线程设置,通过调用函数repl_semi_slave_request_dump进行,写入到semi_sync_slave变量中
->如果semi_sync_slave不为0,则说明是开启了半同步的从库
->Ack_receiver::add_slave 本函数主要讲dump线程纳入ack receiver线程管理
->slave.thread_id= thd->thread_id(); //将dump线程processlist id加入
->slave.server_id= thd->server_id; //server id为从库的server id
...其他属性
->mysql_mutex_lock(&m_mutex); //防止同时修改 ack_receiver 的属性 ,因为ack_receiver是全局唯一的内存结构,比如有多个dump线程同时启动
->m_slaves.push_back(slave); //将slave 信息写入到Ack_receiver的m_slaves数组中
->修改属性m_slaves_changed为true
->mysql_cond_broadcast(&m_cond);//做唤醒操作
->mysql_mutex_unlock(&m_mutex);//解锁
->my_set_thread_local(THR_RPL_SEMI_SYNC_DUMP, &SEMI_SYNC_DUMP); //设置函数共享数据THR_RPL_SEMI_SYNC_DUMP
->repl_semisync.add_slave()/增加变量Rpl_semi_sync_master_clients
->rpl_semi_sync_master_clients++;
->如果日志处于info级别输出日志
sql_print_information("Start %s binlog_dump to slave (server_id: %d), pos(%s, %lu)",
semi_sync_slave != 0 ? "semi-sync" : "asynchronous",
param->server_id, log_file, (unsigned long)log_pos);
也就是加入的半同步的从库的的server id,位点信息
总的说来这个钩子就是在启动的时候判断主从是否是半同步,如果是需要加入到ack receiver进行管理和更改统计值Rpl_semi_sync_master_clients,加入的是dump线程 processlist id如下证明
(gdb) p slave.thread_id
$2 = 85
(gdb) n
140 slave.net_compress= thd->get_protocol_classic()->get_compression();
(gdb) p thd->server_id
$3 = 631
mysql> show processlist;
+----+--------+--------------------+------+------------------+------+---------------------------------------------------------------+------------------+-----------+---------------+
| Id | User | Host | db | Command | Time | State | Info | Rows_sent | Rows_examined |
+----+--------+--------------------+------+------------------+------+---------------------------------------------------------------+------------------+-----------+---------------+
| 85 | repsem | 192.168.1.63:41434 | NULL | Binlog Dump GTID | 49 | Master has sent all binlog to slave; waiting for more updates | NULL | 0 | 0 |
| 86 | root | localhost | NULL | Query | 0 | starting | show processlist | 0 | 0 |
+----+--------+--------------------+------+------------------+------+---------------------------------------------------------------+------------------+-----------+---------------+
二、回调函数:repl_semi_binlog_dump_end
调用线程:dump线程
#0 ReplSemiSyncMaster::remove_slave (this=0x7ffdb3fff1c0 ) at /home/mysql/soft/percona-server-5.7.29-32/plugin/semisync/semisync_master.cc:586
#1 0x00007ffdb3df30e1 in repl_semi_binlog_dump_end (param=0x7fffe8192dc0) at /home/mysql/soft/percona-server-5.7.29-32/plugin/semisync/semisync_master_plugin.cc:180
#2 0x00000000013dccc8 in Binlog_transmit_delegate::transmit_stop (this=0x2d1c980 , thd=0x7ffde0000be0, flags=0)
at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_handler.cc:740
#3 0x00000000018224dd in Binlog_sender::cleanup (this=0x7fffe8193490) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_binlog_sender.cc:183
#4 0x0000000001822c2d in Binlog_sender::run (this=0x7fffe8193490) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_binlog_sender.cc:319
#5 0x000000000182040a in mysql_binlog_send (thd=0x7ffde0000be0, log_ident=0x7fffe81940c0 "", pos=4, slave_gtid_executed=0x7fffe8193e90, flags=0)
at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_master.cc:421
#6 0x00000000018202d6 in com_binlog_dump_gtid (thd=0x7ffde0000be0, packet=0x7ffde000a901 "", packet_length=83) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_master.cc:405
#7 0x00000000014b76ef in dispatch_command (thd=0x7ffde0000be0, com_data=0x7fffe8194c90, command=COM_BINLOG_DUMP_GTID) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:1754
#8 0x00000000014b5a94 in do_command (thd=0x7ffde0000be0) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:1060
#9 0x00000000015e9d32 in handle_connection (arg=0x36a8a20) at /home/mysql/soft/percona-server-5.7.29-32/sql/conn_handler/connection_handler_per_thread.cc:325
#10 0x00000000018b97f2 in pfs_spawn_thread (arg=0x36d4480) at /home/mysql/soft/percona-server-5.7.29-32/storage/perfschema/pfs.cc:2198
#11 0x00007ffff7bc6ea5 in start_thread () from /lib64/libpthread.so.0#12 0x00007ffff5f2b8dd in clone () from /lib64/libc.so.6
回调方式:
Binlog_sender::run
->THD_STAGE_INFO(m_thd, stage_waiting_to_finalize_termination);
进入状态waiting_to_finalize_termination
->是否是由于出现了重复的dump线程
->Binlog_sender::cleanup
->RUN_HOOK(binlog_transmit, transmit_stop, (thd, m_flag));
->Binlog_transmit_delegate::transmit_stop
函数过程:
Binlog_transmit_delegate::transmit_stop
->是否是半同步
如果是
->ack_receiver.remove_slave(current_thd);//ack_receiver去掉当前dump线程
-> mysql_mutex_lock(&m_mutex); //加锁准备修改Ack_receiver的全局结构信息
->for (it= m_slaves.begin(); it != m_slaves.end(); it++)
迭代m_slaves,在所有的dump线程中进行循环迭代
找到删除m_slaves.erase(it); //删除
->mysql_mutex_unlock(&m_mutex);//解锁
->repl_semisync.remove_slave();
->lock();//加锁
->rpl_semi_sync_master_clientst-- //统计值减去1
->如果半同步开启(getMasterEnabled() && is_on())
->如果rpl_semi_sync_master_clients小于了参数rpl_semi_sync_master_wait_for_slave_count设置
且(rpl_semi_sync_master_wait_no_slave设置false 或者 是 abort_loop关闭数据库)
->如果是 abort_loop关闭数据库
需要比较当前收到的ack的pos和最新提交的pos是否一致。不一致则输出警告
sql_print_warning("SEMISYNC: Forced shutdown. Some updates might " "not be replicated.");
->switch_off()//关闭半同步
总说的这里是在dump线程退出之前进行的操作,就是在ack_receiver中将本dump线程去掉,然后判断是否需要关闭半同步:
- 如果rpl_semi_sync_master_clients小于了参数rpl_semi_sync_master_wait_for_slave_count设置退化为异步复制
三、回调函数:repl_semi_report_binlog_update
调用线程:用户线程
(gdb) bt
#0 repl_semi_report_binlog_update (param=0x7ffdf416a1a0, log_file=0x2d66935 "binlog.000002", log_pos=322)
at /home/mysql/soft/percona-server-5.7.29-32/plugin/semisync/semisync_master_plugin.cc:59
#1 0x00000000013db911 in Binlog_storage_delegate::after_flush (this=0x2d1c800 , thd=0x7ffdc8000c20, log_file=0x2d66935 "binlog.000002",
log_pos=322) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_handler.cc:589
#2 0x0000000001803351 in MYSQL_BIN_LOG::ordered_commit (this=0x2d668a0 , thd=0x7ffdc8000c20) at /home/mysql/soft/percona-server-5.7.29-32/sql/binlog.cc:10282
#3 0x000000000180192a in MYSQL_BIN_LOG::commit (this=0x2d668a0 , thd=0x7ffdc8000c20, all=false) at /home/mysql/soft/percona-server-5.7.29-32/sql/binlog.cc:9494
#4 0x00000000015c686c in trans_commit_stmt (thd=0x7ffdc8000c20) at /home/mysql/soft/percona-server-5.7.29-32/sql/transaction.cc:470
#5 0x00000000014c090b in mysql_execute_command (thd=0x7ffdc8000c20, first_level=true) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:5330
#6 0x00000000014c2025 in mysql_parse (thd=0x7ffdc8000c20, parser_state=0x7ffdf416c4a0, update_userstat=false) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:5927
#7 0x00000000014b6c5f in dispatch_command (thd=0x7ffdc8000c20, com_data=0x7ffdf416cc90, command=COM_QUERY) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:1539
#8 0x00000000014b5a94 in do_command (thd=0x7ffdc8000c20) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:1060
#9 0x00000000015e9d32 in handle_connection (arg=0x3385e00) at /home/mysql/soft/percona-server-5.7.29-32/sql/conn_handler/connection_handler_per_thread.cc:325
#10 0x00000000018b97f2 in pfs_spawn_thread (arg=0x7005b10) at /home/mysql/soft/percona-server-5.7.29-32/storage/perfschema/pfs.cc:2198
#11 0x00007ffff7bc6ea5 in start_thread () from /lib64/libpthread.so.0#12 0x00007ffff5f2b8dd in clone () from /lib64/libc.so.6
回调方式:
MYSQL_BIN_LOG::ordered_commit
->flush阶段 flush之后
->if (RUN_HOOK(binlog_storage, after_flush,
(thd, file_name_ptr, flush_end_pos)))
->如果sync_binlog !=1 这里 通知dump线程发送binlog
调入binlog_storage_delegate->after_flush(THD *thd,const char *log_file,my_off_t log_pos)
Binlog_storage_param param;
param.server_id= thd->server_id; //拿到从库的server id
调入
repl_semi_report_binlog_update
函数过程:
repl_semi_report_binlog_update(Binlog_storage_param *param,const char *log_file,my_off_t log_pos)
传入参数为从库server_id,主库binlog filename,binlog最新刷新到的pos位点
->repl_semisync.getMasterEnabled()
是否开启了半同步,这里是在初始化的时候根据参数rpl_semi_sync_master_enabled判断的
及全局ReplSemiSyncMaster.master_enabled_的设置
->ReplSemiSyncMaster::writeTranxInBinlog(const char* log_file_name,my_off_t log_file_pos)
这里带入binlog filename和binlog最新刷新到的pos位置,对位点进行存储
->上锁准备修改 ReplSemiSyncMaster全局变量信息
lock();
->如果commit_file_name_inited_已经初始化,也就是已经接收过提交的位点信息
->调用ActiveTranx::compare进行简单比较,当前位点和commit file位点进行比较
->如果大于
复制当前位点信息到commit_file_name_和commit_file_pos_
->如果小于
不做操作
->如果没有初始化
复制当前位点信息到commit_file_name_和commit_file_pos_
同时commit_file_name_inited_设置为true代表已经初始化
->如果半同步状态处于正常状态
由参数rpl_semi_sync_master_wait_for_slave_count和rpl_semi_sync_master_wait_no_slave共同控制
->插入活跃事务链表
active_tranxs_->insert_tranx_node(log_file_name, log_file_pos)
如果插入失败调用ReplSemiSyncMaster::switch_off,并且打印出警告
sql_print_warning("Semi-sync failed to insert tranx_node for binlog file: %s, position: %lu",
log_file_name, (ulong)log_file_pos);
总的说来这个回调函数主要用在binlog flush阶段之后,发送之前,用于将活跃的事务的位点信息放入到活跃事务链表中。
四、回调函数:repl_semi_report_commit
用户线程,堵塞等待ack 当参数设置rpl_semi_sync_master_wait_point设置为after commit的时候调用,这里简单记录一下主要研究after sync,这个参数是修改立即生效。如下是函数内部的判断:
if (rpl_semi_sync_master_wait_point == WAIT_AFTER_COMMIT &&
is_real_trans && param->log_pos)
#0 ReplSemiSyncMaster::commitTrx (this=0x7ffdf438b1c0 , trx_wait_binlog_name=0x7ffddc006d90 "binlog.000005", trx_wait_binlog_pos=3560)
at /home/mysql/soft/percona-server-5.7.29-32/plugin/semisync/semisync_master.cc:715
#1 0x00007ffdf417ef33 in repl_semi_report_commit (param=0x7fffe81d3dd0) at /home/mysql/soft/percona-server-5.7.29-32/plugin/semisync/semisync_master_plugin.cc:113
#2 0x00000000013db38c in Trans_delegate::after_commit (this=0x2d1c740 , thd=0x7ffddc000c00, all=false)
at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_handler.cc:553
#3 0x0000000001802212 in MYSQL_BIN_LOG::process_after_commit_stage_queue (this=0x2d668a0 , thd=0x7ffddc000c00, first=0x7ffddc000c00)
at /home/mysql/soft/percona-server-5.7.29-32/sql/binlog.cc:9743
#4 0x00000000018038ac in MYSQL_BIN_LOG::ordered_commit (this=0x2d668a0 , thd=0x7ffddc000c00) at /home/mysql/soft/percona-server-5.7.29-32/sql/binlog.cc:10413
#5 0x000000000180192a in MYSQL_BIN_LOG::commit (this=0x2d668a0 , thd=0x7ffddc000c00, all=false) at /home/mysql/soft/percona-server-5.7.29-32/sql/binlog.cc:9494
#6 0x0000000000ea64b8 in ha_commit_trans (thd=0x7ffddc000c00, all=false, ignore_global_read_lock=false) at /home/mysql/soft/percona-server-5.7.29-32/sql/handler.cc:1839
#7 0x00000000015c680d in trans_commit_stmt (thd=0x7ffddc000c00) at /home/mysql/soft/percona-server-5.7.29-32/sql/transaction.cc:465
#8 0x00000000014c090b in mysql_execute_command (thd=0x7ffddc000c00, first_level=true) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:5330
#9 0x00000000014c2025 in mysql_parse (thd=0x7ffddc000c00, parser_state=0x7fffe81d64a0, update_userstat=false) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:5927
#10 0x00000000014b6c5f in dispatch_command (thd=0x7ffddc000c00, com_data=0x7fffe81d6c90, command=COM_QUERY) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:1539
#11 0x00000000014b5a94 in do_command (thd=0x7ffddc000c00) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:1060
#12 0x00000000015e9d32 in handle_connection (arg=0x6fe6df0) at /home/mysql/soft/percona-server-5.7.29-32/sql/conn_handler/connection_handler_per_thread.cc:325
回调方式:
commit队列处理之后
MYSQL_BIN_LOG::process_after_commit_stage_queue
(THD *head= first; head; head= head->next_to_commit)
此处为一个循环,和after sync的回调不一样,明显这里是循环队列中的每一个事务
->transaction_delegate->after_commit
thd->get_trans_fixed_pos(¶m.log_file, ¶m.log_pos);
这里寻找到到本事务的log file和pos带入
->repl_semi_report_commit
最重要的就是
return repl_semisync.commitTrx(binlog_name, param->log_pos);
具体这个函数做什么参考下面的after sync
五、回调函数:repl_semi_report_binlog_sync
用户线程,堵塞等待ack,可以说这事最重要的函数了 当参数设置rpl_semi_sync_master_wait_point设置为after sync的时候调用,这里主要研究本回调函数这个参数是修改立即生效
#0 ReplSemiSyncMaster::commitTrx (this=0x7ffdf438b1c0 , trx_wait_binlog_name=0x7ffddc006ea0 "binlog.000005", trx_wait_binlog_pos=3880)
at /home/mysql/soft/percona-server-5.7.29-32/plugin/semisync/semisync_master.cc:715
#1 0x00007ffdf417ee82 in repl_semi_report_binlog_sync (param=0x7fffe81d3ed0, log_file=0x7ffddc006ea0 "binlog.000005", log_pos=3880)
at /home/mysql/soft/percona-server-5.7.29-32/plugin/semisync/semisync_master_plugin.cc:80
#2 0x00000000013dc824 in Binlog_storage_delegate::after_sync (this=0x2d1c800 , thd=0x7ffddc000c00, log_file=0x7ffddc006ea0 "binlog.000005", log_pos=3880)
at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_handler.cc:709
#3 0x0000000001802bb6 in call_after_sync_hook (queue_head=0x7ffddc000c00) at /home/mysql/soft/percona-server-5.7.29-32/sql/binlog.cc:10036
#4 0x000000000180384e in MYSQL_BIN_LOG::ordered_commit (this=0x2d668a0 , thd=0x7ffddc000c00) at /home/mysql/soft/percona-server-5.7.29-32/sql/binlog.cc:10390
#5 0x000000000180192a in MYSQL_BIN_LOG::commit (this=0x2d668a0 , thd=0x7ffddc000c00, all=false) at /home/mysql/soft/percona-server-5.7.29-32/sql/binlog.cc:9494
#6 0x0000000000ea64b8 in ha_commit_trans (thd=0x7ffddc000c00, all=false, ignore_global_read_lock=false) at /home/mysql/soft/percona-server-5.7.29-32/sql/handler.cc:1839
#7 0x00000000015c680d in trans_commit_stmt (thd=0x7ffddc000c00) at /home/mysql/soft/percona-server-5.7.29-32/sql/transaction.cc:465
#8 0x00000000014c090b in mysql_execute_command (thd=0x7ffddc000c00, first_level=true) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:5330
#9 0x00000000014c2025 in mysql_parse (thd=0x7ffddc000c00, parser_state=0x7fffe81d64a0, update_userstat=false) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:5927
#10 0x00000000014b6c5f in dispatch_command (thd=0x7ffddc000c00, com_data=0x7fffe81d6c90, command=COM_QUERY) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:1539
#11 0x00000000014b5a94 in do_command (thd=0x7ffddc000c00) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:1060
#12 0x00000000015e9d32 in handle_connection (arg=0x6fe6df0) at /home/mysql/soft/percona-server-5.7.29-32/sql/conn_handler/connection_handler_per_thread.cc:325
#13 0x00000000018b97f2 in pfs_spawn_thread (arg=0x6f06c40) at /home/mysql/soft/percona-server-5.7.29-32/storage/perfschema/pfs.cc:2198
#14 0x00007ffff7bc6ea5 in start_thread () from /lib64/libpthread.so.0
回调方式:
MYSQL_BIN_LOG::ordered_commit
->binlog做sync
->commit队列形成
->call_after_sync_hook(commit_queue)进行回调,当然这里说的是binlog_order_commits 为ON
->处理commit队列,进行innodb层提交
call_after_sync_hook
->for (THD *thd= queue_head; thd != NULL; thd= thd->next_to_commit)//循环整个队列
//Used by MYSQL_BIN_LOG to maintain the commit queue for binary log group commit.
if (likely(thd->commit_error == THD::CE_NONE))
thd->get_trans_fixed_pos(&log_file, &pos); //拿commit队列,遍历,目的在于获取队尾最后一个提交事务的og file和pos
->RUN_HOOK(binlog_storage, after_sync, (queue_head, log_file, pos))
//显然这里实际上有用的参数是将commit队列的尾部事务最大的pos给传进去了,这里极为重要。
binlog_storage_delegate->after_sync(THD *thd,const char *log_file,my_off_t log_pos)
->param.server_id= thd->server_id;//从库server_id传入
最终调用函数,如果为after sync则输入就是本次group commit最大的pos/after commit为每个事务
函数过程:
repl_semi_report_binlog_sync(Binlog_storage_param *param,const char *log_file,my_off_t log_pos)
->if (rpl_semi_sync_master_wait_point == WAIT_AFTER_SYNC)
如果参数rpl_semi_sync_master_wait_point设置为after sync,则调用
->repl_semisync.commitTrx(log_file, log_pos);//如果为binlog_order_commits为ON则输入就是本次group commit最大的pos
->lock(); 首先上锁准备修改全局变量ReplSemiSyncMaster的信息
->如果存在活跃事务链表并且本次最大事务的file name存在
->entry=active_tranxs_->find_active_tranx_node(trx_wait_binlog_name,trx_wait_binlog_pos);
通过输入的本次group commit的最大log file和 pos事务进行查找
这里是调用的链表查找
->查找到后带入本活跃事务的条件变量
->进入 Waiting for semi-sync ACK from slave 状态,并且带入线程的 条件变量和mutex
->是否参数m_enable设置了,并且存在group commit最大pos
->set_timespec(&start_ts, 0); //设置时间 为当前开始等待时间
->trace_level_ & kTraceDetail 如果设置为16
"%s: wait pos (%s, %lu), repl(%d)\n", kWho,trx_wait_binlog_name, (unsigned long)trx_wait_binlog_pos,(int)is_on()
->abstime.tv.i64 = start_ts.tv.i64 + (__int64)wait_timeout_ * TIME_THOUSAND * 10;//超时时间
->abstime.max_timeout_msec= (long)wait_timeout_;//设置超时相对时间
->开启循环条件is_on(),如果条件半同步状态正常
->cmp = ActiveTranx::compare(reply_file_name_, reply_file_pos_,trx_wait_binlog_name, trx_wait_binlog_pos);
比较当前最新ack的位点和本次需要等待的事务(order commit为队列中末尾的binlog最大位点)
->if (cmp >= 0)
如果大于则说明本次需要的位点已经收到了,则不需要等待
如果trace级别为16则输出日志
sql_print_information("%s: Binlog reply is ahead (%s, %lu),",kWho, reply_file_name_, (unsigned long)reply_file_pos_);
-> if (!entry) //这里主要处理的是如果半同步是半途开启的情况,可能entry不存在
->wait_file_name_inited_如果已经初始化,显然大部分是这种情况
->cmp = ActiveTranx::compare(trx_wait_binlog_name, trx_wait_binlog_pos,wait_file_name_, wait_file_pos_);
//进行比较,是否本次需要等待的等待pos更小
->(cmp <= 0) 如果比较结果是小于,那么进行wait_file_name_和wait_file_pos_得到替换
strncpy(wait_file_name_, trx_wait_binlog_name, sizeof(wait_file_name_) - 1);
wait_file_name_[sizeof(wait_file_name_) - 1]= '\0';
wait_file_pos_ = trx_wait_binlog_pos;
rpl_semi_sync_master_wait_pos_backtraverse自加
如果trace_level_设置为16则进行输出
"%s: move back wait position (%s, %lu),"
->wait_file_name_inited_如果没有初始化
直接拷贝,如果trace_level_设置为16则进行输出
("%s: init wait position (%s, %lu),"
->(abort_loop && ...如果遇到终止判断流程(关闭从库?)再研究
->等待session+1(group commit为等待的group commit个数)
rpl_semi_sync_master_wait_sessions++;
->如果trace_level_设置为16则进行输出
sql_print_information("%s: wait %lu ms for binlog sent (%s, %lu)"kWho, wait_timeout_,wait_file_name_, (unsigned long)wait_file_pos_);
->本活跃事务对象等待+1,且进入等待状态等待ack_reciver线程唤醒
entry->n_waiters++;
wait_result= mysql_cond_timedwait(&entry->cond, &LOCK_binlog_, &abstime);
->entry->n_waiters--; 等待结束 -1
->rpl_semi_sync_master_wait_sessions--; 等待session减1(group commit为等待的group commit个数)
->如果等待的结果是超时,输出警告
sql_print_warning("Timeout waiting for reply of binlog (file: %s, pos: %lu), "
"semi-sync up to file %s, position %lu.",
trx_wait_binlog_name, (unsigned long)trx_wait_binlog_pos,
reply_file_name_, (unsigned long)reply_file_pos_);
rpl_semi_sync_master_wait_timeouts++; //超时次数加1
并且切换到异步同步状态,switch_off();
l_end:
->否则一般为正常,例外状态为rpl_semi_sync_master_timefunc_fails++
rpl_semi_sync_master_trx_wait_num++; //等待的事务加1(group commit为等待的group commit个数)
rpl_semi_sync_master_trx_wait_time += wait_time;//等待时间增加
->(is_on() && is_semi_sync_trans) 主要是根据is_on()进行判断,如果进行了switch_off()
则这里判定为没有经过半同步
rpl_semi_sync_master_yes_transactions++; //这是我们经常注意的状态值了
如果不是半同步状态
rpl_semi_sync_master_no_transactions++; //这是我们经常注意的状态值了
->最后,如果是最后一个等待活跃事务的用户线程,如果通过半同步等待则说明已经
达到了这个活跃事务的提交位点去掉。
if (trx_wait_binlog_name && active_tranxs_
&& entry && entry->n_waiters == 0)
active_tranxs_->clear_active_tranx_nodes(trx_wait_binlog_name,
trx_wait_binlog_pos);
->解锁unlock();
->THD_EXIT_COND(NULL, & old_stage);恢复老的状态
总的说来这是一个最重要的回调函数,用于堵塞等待事务且让会话状态进入Waiting for semi-sync ACK from slave状态,这个唤醒是通过Ack_receiver进行唤醒的。且参数rpl_semi_sync_master_timeout也在这个函数里面生效。而等待mutex和cond为mutex :ReplSemiSyncMaster.LOCK_binlog_ /cond:TranxNode.cond 。
六、回调函数:repl_semi_reserve_header
调用线程:dump线程,读取event之后,发送之前
#0 ReplSemiSyncMaster::reserveSyncHeader (this=0x7ffdb3fff1c0 , header=0x7fffe8150b30 "P\v\025\350\377\177", size=32)
at /home/mysql/soft/percona-server-5.7.29-32/plugin/semisync/semisync_master.cc:1038
#1 0x00007ffdb3df3138 in repl_semi_reserve_header (param=0x7fffe8150b70, header=0x7fffe8150b30 "P\v\025\350\377\177", size=32, len=0x7fffe8150b80)
at /home/mysql/soft/percona-server-5.7.29-32/plugin/semisync/semisync_master_plugin.cc:191
#2 0x00000000013dceca in Binlog_transmit_delegate::reserve_header (this=0x2d1c980 , thd=0x7ffdec000b90, flags=0, packet=0x7ffdec002a10)
at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_handler.cc:779
#3 0x000000000182592c in Binlog_sender::reset_transmit_packet (this=0x7fffe8151490, flags=0, event_len=65) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_binlog_sender.cc:956
#4 0x0000000001825ab7 in Binlog_sender::read_event (this=0x7fffe8151490, log_cache=0x7fffe8150ea0, checksum_alg=binary_log::BINLOG_CHECKSUM_ALG_CRC32, event_ptr=0x7fffe8150d68,
event_len=0x7fffe8150d64) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_binlog_sender.cc:1189
#5 0x0000000001822f87 in Binlog_sender::send_events (this=0x7fffe8151490, log_cache=0x7fffe8150ea0, end_pos=1154) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_binlog_sender.cc:430
#6 0x0000000001822d64 in Binlog_sender::send_binlog (this=0x7fffe8151490, log_cache=0x7fffe8150ea0, start_pos=123)
at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_binlog_sender.cc:356
#7 0x00000000018226f7 in Binlog_sender::run (this=0x7fffe8151490) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_binlog_sender.cc:233
#8 0x000000000182040a in mysql_binlog_send (thd=0x7ffdec000b90, log_ident=0x7fffe81520c0 "", pos=4, slave_gtid_executed=0x7fffe8151e90, flags=0)
at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_master.cc:421
#9 0x00000000018202d6 in com_binlog_dump_gtid (thd=0x7ffdec000b90, packet=0x7ffdec00a691 "", packet_length=83) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_master.cc:405
#10 0x00000000014b76ef in dispatch_command (thd=0x7ffdec000b90, com_data=0x7fffe8152c90, command=COM_BINLOG_DUMP_GTID) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:1754
#11 0x00000000014b5a94 in do_command (thd=0x7ffdec000b90) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:1060
#12 0x00000000015e9d32 in handle_connection (arg=0x36a8a20) at /home/mysql/soft/percona-server-5.7.29-32/sql/conn_handler/connection_handler_per_thread.cc:325
#13 0x00000000018b97f2 in pfs_spawn_thread (arg=0x36d4480) at /home/mysql/soft/percona-server-5.7.29-32/storage/perfschema/pfs.cc:2198
#14 0x00007ffff7bc6ea5 in start_thread () from /lib64/libpthread.so.0
#15 0x00007ffff5f2b8dd in clone () from /lib64/libc.so.6
回调方式:
Binlog_sender::send_events
->Binlog_sender::read_event
->Binlog_sender::reset_transmit_packet
->Binlog_transmit_delegate::reserve_header
->repl_semi_reserve_header
函数过程:
repl_semi_reserve_header
->(is_semi_sync_dump()) 如果是半同步
->*len += repl_semisync.reserveSyncHeader(header, size)
->memcpy(header, kSyncHeader, sizeof(kSyncHeader));
这里主要讲半同步需要的header写入到包头中(event)如下:
const unsigned char ReplSemiSyncBase::kSyncHeader[2] =
{ReplSemiSyncBase::kPacketMagicNum, 0};
这个回调函数比较简单,将半同步需要信息的信息写入,其中ReplSemiSyncBase::kPacketMagicNum用于识别是否是半同步信息,而ReplSemiSyncBase::kPacketFlagSync则用于判定是否是事务的最后一个event是否需要ack反馈,当然这里只是初始化,ReplSemiSyncBase::kPacketFlagSync的修改在后面会提到
七、回调函数:repl_semi_after_send_event
调用线程:dump线程,发送event之后回调
(gdb) bt
#0 ReplSemiSyncMaster::readSlaveReply (this=0x7ffdf438b1c0 , net=0x7ffde00027b8, server_id=631, event_buf=0x7ffde0012c40 "")
at /home/mysql/soft/percona-server-5.7.29-32/plugin/semisync/semisync_master.cc:1251
#1 0x00007ffdf417f23e in repl_semi_after_send_event (param=0x7fffe8192c60, event_buf=0x7ffde0012c40 "", len=54, skipped_log_file=0x7fffe81934d5 "binlog.000010", skipped_log_pos=0)
at /home/mysql/soft/percona-server-5.7.29-32/plugin/semisync/semisync_master_plugin.cc:228
#2 0x00000000013dd3af in Binlog_transmit_delegate::after_send_event (this=0x2d1c980 , thd=0x7ffde0000be0, flags=0, packet=0x7ffde0002a60,
skipped_log_file=0x7fffe81934c0 "/opt/mysql/mysql3306/binlog.000010", skipped_log_pos=0) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_handler.cc:829
#3 0x0000000001826109 in Binlog_sender::after_send_hook (this=0x7fffe8193490, log_file=0x7fffe81934c0 "/opt/mysql/mysql3306/binlog.000010", log_pos=0)
at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_binlog_sender.cc:1332
#4 0x000000000182350b in Binlog_sender::send_events (this=0x7fffe8193490, log_cache=0x7fffe8192ea0, end_pos=1127) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_binlog_sender.cc:525
#5 0x0000000001822d64 in Binlog_sender::send_binlog (this=0x7fffe8193490, log_cache=0x7fffe8192ea0, start_pos=123)
at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_binlog_sender.cc:356
#6 0x00000000018226f7 in Binlog_sender::run (this=0x7fffe8193490) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_binlog_sender.cc:233
#7 0x000000000182040a in mysql_binlog_send (thd=0x7ffde0000be0, log_ident=0x7fffe81940c0 "", pos=4, slave_gtid_executed=0x7fffe8193e90, flags=0)
at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_master.cc:421
#8 0x00000000018202d6 in com_binlog_dump_gtid (thd=0x7ffde0000be0, packet=0x7ffde000a901 "", packet_length=83) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_master.cc:405
#9 0x00000000014b76ef in dispatch_command (thd=0x7ffde0000be0, com_data=0x7fffe8194c90, command=COM_BINLOG_DUMP_GTID) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:1754
#10 0x00000000014b5a94 in do_command (thd=0x7ffde0000be0) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:1060
#11 0x00000000015e9d32 in handle_connection (arg=0x700eb10) at /home/mysql/soft/percona-server-5.7.29-32/sql/conn_handler/connection_handler_per_thread.cc:325
#12 0x00000000018b97f2 in pfs_spawn_thread (arg=0x6ff19e0) at /home/mysql/soft/percona-server-5.7.29-32/storage/perfschema/pfs.cc:2198
#13 0x00007ffff7bc6ea5 in start_thread () from /lib64/libpthread.so.0
#14 0x00007ffff5f2b8dd in clone () from /lib64/libc.so.6
回调方式:
回调:
com_binlog_dump_gtid
->Binlog_sender::send_binlog
->Binlog_sender::send_events
->读取read_event
->before_send_hook(log_file, log_pos)
->send_packet() 发送event
->after_send_hook(log_file, in_exclude_group ? log_pos : 0))
inline int Binlog_sender::after_send_hook(const char *log_file,my_off_t log_pos)
->RUN_HOOK(binlog_transmit, after_send_event,(m_thd, m_flag, &m_packet, log_file, log_pos))
binlog_transmit_delegate->after_send_event
->param.server_id= thd->server_id;//拿到从库的server id
函数过程
repl_semi_after_send_event(Binlog_transmit_param *param,const char *event_buf, unsigned long len,const char * skipped_log_file,my_off_t skipped_log_pos)
->(is_semi_sync_dump()) //是否是半同步 dump
->是否是需要跳过的event
如果是调入 repl_semisync.skipSlaveReply (这个分支没细看)
如果不是调入repl_semisync.readSlaveReply(thd->get_protocol_classic()->get_net(),param->server_id, event_buf);
repl_semisync.readSlaveReply
->(unsigned char)event_buf[2] != kPacketFlagSync
根据before end event中设置的kPacketFlagSync来判断是否是需要ack的event,也就是事务最后一个event
->如果不是,则不作处理
->如果net_flush(net) //刷新最后的net buffer,因为这个event是半同步ack需要的
并且rpl_semi_sync_master_net_wait_num++
总的说来,这个回调函数是用于,在发送完event后,根据是否是事务的最后一个event,是否需要刷net buffer。因为如果是事务的最后一个event这个event很可能是ack 需要的,因此需要及时刷net buffer。
八、回调函数:repl_semi_reset_master
用户线程执行reset master触发
(gdb) bt
#0 ReplSemiSyncMaster::resetMaster (this=0x7ffdb3fff1c0 ) at /home/mysql/soft/percona-server-5.7.29-32/plugin/semisync/semisync_master.cc:1286
#1 0x00007ffdb3df3271 in repl_semi_reset_master (param=0x7fffe81d5130) at /home/mysql/soft/percona-server-5.7.29-32/plugin/semisync/semisync_master_plugin.cc:237
#2 0x00000000013dd5af in Binlog_transmit_delegate::after_reset_master (this=0x2d1c980 , thd=0x7ffddc000c00, flags=0)
at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_handler.cc:844
#3 0x0000000001820871 in reset_master (thd=0x7ffddc000c00) at /home/mysql/soft/percona-server-5.7.29-32/sql/rpl_master.cc:619
#4 0x00000000014ff943 in reload_acl_and_cache (thd=0x7ffddc000c00, options=128, tables=0x0, write_to_binlog=0x7fffe81d5f4c)
at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_reload.cc:321
#5 0x00000000014be417 in mysql_execute_command (thd=0x7ffddc000c00, first_level=true) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:4469
#6 0x00000000014c2025 in mysql_parse (thd=0x7ffddc000c00, parser_state=0x7fffe81d64a0, update_userstat=false) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:5927
#7 0x00000000014b6c5f in dispatch_command (thd=0x7ffddc000c00, com_data=0x7fffe81d6c90, command=COM_QUERY) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:1539
#8 0x00000000014b5a94 in do_command (thd=0x7ffddc000c00) at /home/mysql/soft/percona-server-5.7.29-32/sql/sql_parse.cc:1060
#9 0x00000000015e9d32 in handle_connection (arg=0x36a8a20) at /home/mysql/soft/percona-server-5.7.29-32/sql/conn_handler/connection_handler_per_thread.cc:325
#10 0x00000000018b97f2 in pfs_spawn_thread (arg=0x36d4480) at /home/mysql/soft/percona-server-5.7.29-32/storage/perfschema/pfs.cc:2198
#11 0x00007ffff7bc6ea5 in start_thread () from /lib64/libpthread.so.0
#12 0x00007ffff5f2b8dd in clone () from /lib64/libc.so.6
这个函数比较简单如下:
lock();
ack_container_.clear(); //清空半同步从库容器
wait_file_name_inited_ = false; //全部初始化为false,需要重新获取
reply_file_name_inited_ = false;
commit_file_name_inited_ = false;
rpl_semi_sync_master_yes_transactions = 0; //统计值全部清理
rpl_semi_sync_master_no_transactions = 0;
rpl_semi_sync_master_off_times = 0;
rpl_semi_sync_master_timefunc_fails = 0;
rpl_semi_sync_master_wait_sessions = 0;
rpl_semi_sync_master_wait_pos_backtraverse = 0;
rpl_semi_sync_master_trx_wait_num = 0;
rpl_semi_sync_master_trx_wait_time = 0;
rpl_semi_sync_master_net_wait_num = 0;
rpl_semi_sync_master_net_wait_time = 0;
unlock();
不过多解释。
九、一个有趣的现象
首先我们先说明一下after commit和after sync的一个不同点:
- after sync是leader会话直接等待commit队列中最大的pos(循环整个commit队列获取),也就是commit队列尾部的事物的pos。因此只有leader会标记为Waiting for semi-sync ACK from slave
- after commit是leader会话循环commit队列队列中的每个事务,分别带入pos进行等待,因为commit队列是按照binlog顺序排列的,但是在每个事务的结尾会恢复以前的状态,因此每个commit队列中的事务可能会顺序的分别标记为Waiting for semi-sync ACK from slave
这里遇到的一个问题after commit如果堵塞可能出现多个Waiting for semi-sync ACK from slave。而after sync则不是,一个为query end一个为Waiting for semi-sync ACK from slave。测试方法就是设置time out参数很大,然后关闭从库的io线程,主库做两个事务即可,如下:
after commit:
mysql> show processlist;
+-----+------+-----------+------+---------+------+--------------------------------------+----------------------------------+-----------+---------------+
| Id | User | Host | db | Command | Time | State | Info | Rows_sent | Rows_examined |
+-----+------+-----------+------+---------+------+--------------------------------------+----------------------------------+-----------+---------------+
| 2 | root | localhost | test | Query | 18 | Waiting for semi-sync ACK from slave | insert into testsemi values(100) | 0 | 0 |
| 223 | root | localhost | test | Query | 12 | Waiting for semi-sync ACK from slave | insert into testsemi values(100) | 0 | 0 |
| 224 | root | localhost | NULL | Query | 0 | starting | show processlist | 0 | 0 |
+-----+------+-----------+------+---------+------+--------------------------------------+----------------------------------+-----------+---------------+
3 rows in set (0.00 sec)
after sync:
mysql> show processlist;
+-----+------+-----------+------+---------+------+--------------------------------------+----------------------------------+-----------+---------------+
| Id | User | Host | db | Command | Time | State | Info | Rows_sent | Rows_examined |
+-----+------+-----------+------+---------+------+--------------------------------------+----------------------------------+-----------+---------------+
| 2 | root | localhost | test | Query | 11 | Waiting for semi-sync ACK from slave | insert into testsemi values(100) | 0 | 0 |
| 223 | root | localhost | test | Query | 4 | query end | insert into testsemi values(100) | 0 | 0 |
| 224 | root | localhost | NULL | Query | 0 | starting | show processlist | 0 | 0 |
+-----+------+-----------+------+---------+------+--------------------------------------+----------------------------------+-----------+---------------+
这是因为after commit实际上是在commit队列处理之后,last commit已经修改,已经释放LOCK commit, 多个commit队列的leader线程都能达到这个点。而after sync则不是,它等待在commit队列处理之前,commit队列形成之后,虽然是两个commit队列,但是这个时候last commit还没有修改,因此他们的last commit是一致的,其次因为commit队列已经形成,后来的那个想要入commit队列的sync队列只有等待,言外之意就是在after sync中半同步如果遇到半同步等待的状态也会让从库的MTS并发加大。因此出现了这种状况,我们从last commit可以验证:
after commit
#210206 6:42:23 server id 623306 end_log_pos 259 CRC32 0xe1b25db3 GTID last_committed=0 sequence_number=1 rbr_only=yes
#210206 6:42:29 server id 623306 end_log_pos 574 CRC32 0x3f8a9cf2 GTID last_committed=1 sequence_number=2 rbr_only=yes
after sync
#210206 6:43:31 server id 623306 end_log_pos 889 CRC32 0xdf58d3de GTID last_committed=2 sequence_number=3 rbr_only=yes
#210206 6:43:38 server id 623306 end_log_pos 1204 CRC32 0xd8436e20 GTID last_committed=2 sequence_number=4 rbr_only=yes