級聯slave中延遲計算和query event exe time獲取方法的示例分析

144次閱讀

共計 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 行業資訊頻道！

正文完