1. 首页
  2. IT资讯

级联slave的延迟计算和query event exe time获取方法

源码5.7.22

一、级联时间计算方式

比如A->B->C那么C的延迟是计算B还是A的。因为Event的中timestamp没变,但是C计算时间差值却是以B为准。如果时钟同步的情况下,其实基本可以考虑为A的。计算方法可以参考我的《深入理解MySQL主从原理》专栏

欢迎关注我的《深入理解MySQL主从原理 32讲 》,如下:

如果图片不能显示可查看下面链接:
https://www.jianshu.com/p/d636215d767f

逻辑如下:

  级联中的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;//这里计算时间  

来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/7728585/viewspace-2651150/,如需转载,请注明出处,否则将追究法律责任。

主题测试文章,只做测试使用。发布者:深沉的少年,转转请注明出处:http://www.cxybcw.com/183980.html

联系我们

13687733322

在线咨询:点击这里给我发消息

邮件:1877088071@qq.com

工作时间:周一至周五,9:30-18:30,节假日休息

QR code