級聯slave的延遲計算和query event exe time獲取方法
原始碼5.7.22
一、級聯時間計算方式
比如A->B->C那麼C的延遲是計算B還是A的。因為Event的中timestamp沒變,但是C計算時間差值卻是以B為準。如果時鐘同步的情況下,其實基本可以考慮為A的。計算方法可以參考我的《深入理解MySQL主從原理》專欄
具體可以點選:ttps://j.youzan.com/yEY_Xi
邏輯如下:
級聯中的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/,如需轉載,請註明出處,否則將追究法律責任。
相關文章
- 【MySQL】六、常見slave 延遲原因以及解決方法MySql
- mysql同步問題之Slave延遲很大最佳化方法MySql
- MySQL中slave監控的延遲情況分析MySql
- 從Mysql slave system lock延遲說開去MySql
- mybatis延遲載入和快取MyBatis快取
- mybatis基礎系列(四)——關聯查詢、延遲載入、一級快取與二級快取MyBatis快取
- Mysql 建立心跳錶來監控Replication的Slave是否延遲MySql
- MySQL:slave 延遲一列 外來鍵檢查和自增加鎖MySql
- Mybatis延遲載入、快取MyBatis快取
- Python獲取當前日期和日期差計算Python
- Revit獲取元素Solid和計算包圍盒Solid
- 實現簡單延遲佇列和分散式延遲佇列佇列分散式
- RabbitMQ延遲訊息的延遲極限是多少?MQ
- Hawkeye:TopN慢query的獲取與優化優化
- Win10系統中下級選單顯示延遲的解決方法Win10
- 前向渲染和延遲渲染
- js獲取iframe和父級之間元素,方法、屬,獲取iframe的高度自適應iframe高度JS
- 簡單獲取電腦ip和計算機名計算機
- 使用延遲關聯實現高效分頁
- 快速獲取昨天的日期(time模組使用)
- Vivado使用技巧(32):IO延遲的約束方法
- 動態生成DOM元素的高度及行數獲取與計算方法
- function ALV 獲取OO ALV event IDFunction
- ntpdate會導致mysql slow query log出現很大的query timeMySql
- 使用JPA和Hibernate延遲載入實體屬性的最佳方法 - Vlad Mihalcea
- docker安裝rabbitmq和延遲外掛DockerMQ
- 延遲繫結
- 直播短影片原始碼,延遲任務的解決方法原始碼
- 使用Chronicle Queue建立低延遲的TB級別的佇列 - DZone佇列
- 獲取方法
- SAP Spartacus 的延遲載入 Lazy load 設計原理
- MySQL [ERROR] Slave I/O: Found a Gtid_log_event or Previous_gtids_log_eventMySqlError
- 整理獲取 viewport 和 element 尺寸和位置方法View
- 爬取LeetCode題目——如何傳送GraphQL Query獲取資料LeetCode
- PostgreSQL中的複製延遲SQL
- redis 延遲佇列Redis佇列
- Mybatis延遲查詢MyBatis
- WebGL之延遲著色Web