级联slave中延迟计算和query event exe time获取方法的示例分析

120次阅读

共计 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 行业资讯频道！

正文完