共计 6874 个字符，预计需要花费 18 分钟才能阅读完成。
这篇文章主要为大家展示了“级联 slave 中延迟计算和 query event exe time 获取方法的示例分析”，内容简而易懂，条理清晰，希望能够帮助大家解决疑惑，下面让丸趣 TV 小编带领大家一起研究并学习一下“级联 slave 中延迟计算和 query event exe time 获取方法的示例分析”这篇文章吧。
一、级联时间计算方式
逻辑如下：
级联中的 Event 依然是主库的时间，因此其延迟还是相对主库而言。虽然 apply_event_and_update_pos 函数中由设置为当前时间 thd- set_time()
但是最终设置还是在 Query_log_event::do_apply_event 和 Query_log_event::do_apply_event 中的
THD::set_time (this=0x7ffe74007da0, t=0x7ffe74007828)
因为只有做了数据库修改才会触发记录 Event 的工作
设个设置就是设置为 event header 的 timestamp，因此还是级联中记录的 Event 的时间还是
主库的时间，计算延迟就是相对主库的时间。#0 THD::set_time (this=0x7ffe74007da0, t=0x7ffe7493c4d0) at /root/mysqlall/percona-server-locks-detail-5.7.22/sql/sql_class.h:3526
#1 0x00000000018459ab in Query_log_event::do_apply_event (this=0x7ffe7493c3b0, rli=0x676be60, query_arg=0x7ffe740061dc BEGIN , q_len_arg=5)
at /root/mysqlall/percona-server-locks-detail-5.7.22/sql/log_event.cc:4714
#2 0x0000000001845287 in Query_log_event::do_apply_event (this=0x7ffe7493c3b0, rli=0x676be60)
at /root/mysqlall/percona-server-locks-detail-5.7.22/sql/log_event.cc:4567
#3 0x00000000018420d4 in Log_event::apply_event (this=0x7ffe7493c3b0, rli=0x676be60) at /root/mysqlall/percona-server-locks-detail-5.7.22/sql/log_event.cc:3570
#4 0x00000000018bc078 in apply_event_and_update_pos (ptr_ev=0x7fffec094830, thd=0x7ffe74007da0, rli=0x676be60)
at /root/mysqlall/percona-server-locks-detail-5.7.22/sql/rpl_slave.cc:4766
#5 0x00000000018bd773 in exec_relay_log_event (thd=0x7ffe74007da0, rli=0x676be60) at /root/mysqlall/percona-server-locks-detail-5.7.22/sql/rpl_slave.cc:5300
#6 0x00000000018c46e4 in handle_slave_sql (arg=0x6675d30) at /root/mysqlall/percona-server-locks-detail-5.7.22/sql/rpl_slave.cc:7543
#7 0x0000000001945620 in pfs_spawn_thread (arg=0x7ffe7c02c6c0) at /root/mysqlall/percona-server-locks-detail-5.7.22/storage/perfschema/pfs.cc:2190
#8 0x00007ffff7bc6aa1 in start_thread () from /lib64/libpthread.so.0
#9 0x00007ffff6719bcd in clone () from /lib64/libc.so.6
#0 THD::set_time (this=0x7ffe74007da0, t=0x7ffe7493c4d0) at /root/mysqlall/percona-server-locks-detail-5.7.22/sql/sql_class.h:3526
#1 0x00000000018459ab in Query_log_event::do_apply_event (this=0x7ffe7493c3b0, rli=0x676be60, query_arg=0x7ffe740061dc BEGIN , q_len_arg=5)
at /root/mysqlall/percona-server-locks-detail-5.7.22/sql/log_event.cc:4714
#2 0x0000000001845287 in Query_log_event::do_apply_event (this=0x7ffe7493c3b0, rli=0x676be60)
at /root/mysqlall/percona-server-locks-detail-5.7.22/sql/log_event.cc:4567
#3 0x00000000018420d4 in Log_event::apply_event (this=0x7ffe7493c3b0, rli=0x676be60) at /root/mysqlall/percona-server-locks-detail-5.7.22/sql/log_event.cc:3570
#4 0x00000000018bc078 in apply_event_and_update_pos (ptr_ev=0x7fffec094830, thd=0x7ffe74007da0, rli=0x676be60)
at /root/mysqlall/percona-server-locks-detail-5.7.22/sql/rpl_slave.cc:4766
#5 0x00000000018bd773 in exec_relay_log_event (thd=0x7ffe74007da0, rli=0x676be60) at /root/mysqlall/percona-server-locks-detail-5.7.22/sql/rpl_slave.cc:5300
#6 0x00000000018c46e4 in handle_slave_sql (arg=0x6675d30) at /root/mysqlall/percona-server-locks-detail-5.7.22/sql/rpl_slave.cc:7543
#7 0x0000000001945620 in pfs_spawn_thread (arg=0x7ffe7c02c6c0) at /root/mysqlall/percona-server-locks-detail-5.7.22/storage/perfschema/pfs.cc:2190
#8 0x00007ffff7bc6aa1 in start_thread () from /lib64/libpthread.so.0
#9 0x00007ffff6719bcd in clone () from /lib64/libc.so.6
query map event 在修改的第一条数据 记录时间 这个时间肯定是 Log_event::apply_event 的时间，GTID 自然是在最后 commit 的时候 ,XID EVENT 也是正确的主库时间。实际上第一个 THD::set_time(header- timestamp) 后 user_time 就正确，下面的逻辑不会设置为当前时间。inline void set_time()
{ start_utime= utime_after_lock= my_micro_time();
if (user_time.tv_sec || user_time.tv_usec)
{
start_time= user_time;
}
else
my_micro_time_to_timeval(start_utime, start_time);
#ifdef HAVE_PSI_THREAD_INTERFACE
PSI_THREAD_CALL(set_thread_start_time)(start_time.tv_sec);
#endif
}
但是主库 dispatch_command 的时候不会设置 user_time user_time 为 0，因此设置为当前时间。#0 THD::set_time (this=0x7ffedc0009c0) at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_class.h:3514
#1 0x00000000015c5fe8 in dispatch_command (thd=0x7ffedc0009c0, com_data=0x7fffec5bdd70, command=COM_QUERY)
at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_parse.cc:1247
#2 0x00000000015c58ff in do_command (thd=0x7ffedc0009c0) at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_parse.cc:1021
#3 0x000000000170e578 in handle_connection (arg=0x67d01a0) at /mysqldata/percona-server-locks-detail-5.7.22/sql/conn_handler/connection_handler_per_thread.cc:312
#4 0x0000000001945538 in pfs_spawn_thread (arg=0x67c9dc0) at /mysqldata/percona-server-locks-detail-5.7.22/storage/perfschema/pfs.cc:2190
#5 0x00007ffff7bcfaa1 in start_thread () from /lib64/libpthread.so.0
#6 0x00007ffff6b37c4d in clone () from /lib64/libc.so.6二、header 中的 timestamp 和 query_event 的 exe time 计算方式
common_header：中的时间来自 命令发起的时间。下面是其初始化
Log_event::Log_event(THD* thd_arg, uint16 flags_arg,
enum_event_cache_type cache_type_arg,
enum_event_logging_type logging_type_arg,
Log_event_header *header, Log_event_footer *footer)
: is_valid_param(false), temp_buf(0), exec_time(0),
event_cache_type(cache_type_arg), event_logging_type(logging_type_arg),
crc(0), common_header(header), common_footer(footer), thd(thd_arg)
server_id= thd- server_id;
common_header- unmasked_server_id= server_id;
common_header- when= thd- start_time;
common_header- log_pos= 0;
common_header- flags= flags_arg;
dispatch_command 调用时间
Query_log_event::Query_log_event(THD* thd_arg, const char* query_arg,
size_t query_length, bool using_trans,
bool immediate, bool suppress_use,
int errcode, bool ignore_cmd_internals)
: binary_log::Query_event(query_arg,
thd_arg- catalog().str,
thd_arg- db().str,
query_length,
thd_arg- thread_id(),
thd_arg- variables.sql_mode,
thd_arg- variables.auto_increment_increment,
thd_arg- variables.auto_increment_offset,
thd_arg- variables.lc_time_names- number,
(ulonglong)thd_arg- table_map_for_update,
errcode,
thd_arg- db().str ? strlen(thd_arg- db().str) : 0,
thd_arg- catalog().str ? strlen(thd_arg- catalog().str) : 0),
Log_event(thd_arg,
(thd_arg- thread_specific_used ? LOG_EVENT_THREAD_SPECIFIC_F :
0) |
(suppress_use ? LOG_EVENT_SUPPRESS_USE_F : 0),
using_trans ? Log_event::EVENT_TRANSACTIONAL_CACHE :
Log_event::EVENT_STMT_CACHE,
Log_event::EVENT_NORMAL_LOGGING,
header(), footer()),
data_buf(0)
DBUG_EXECUTE_IF( debug_lock_before_query_log_event ,
DBUG_SYNC_POINT(debug_lock.before_query_log_event , 10););
/* save the original thread id; we already know the server id */
slave_proxy_id= thd_arg- variables.pseudo_thread_id;
if (query != 0)
is_valid_param= true;
/*
exec_time calculation has changed to use the same method that is used
to fill out thd_arg- start_time
*/
struct timeval end_time;
ulonglong micro_end_time= my_micro_time();// 这里获取时间 query event
my_micro_time_to_timeval(micro_end_time, end_time);
exec_time= end_time.tv_sec - thd_arg- start_time.tv_sec;// 这里计算时间 以上是“级联 slave 中延迟计算和 query event exe time 获取方法的示例分析”这篇文章的所有内容，感谢各位的阅读！相信大家都有了一定的了解，希望分享的内容对大家有所帮助，如果还想学习更多知识，欢迎关注丸趣 TV 行业资讯频道！
正文完
