本文主要討論的還是5.7，8.0沒有實際測試，這里簡單記錄。
一、問題說明
最近在處理一個主從問題的時候，發現一個比較奇怪的現象，這個主從是級聯的也就是A->B->C庫，B庫問題處理后先啟動了B庫追數據，然后修復C庫啟動追延遲，這個時候觀察到的B庫和C庫的延遲分別為20000多秒和900多秒，顯然這個差距是非常大的，而級聯又是平時用得很多的一種方式。 這里實際上C庫的延遲應該比B庫更大，那么級聯從庫中C庫的延遲計算到底是怎么樣的呢？
這里我們簡單探討一下，未考慮清楚的地方還請見諒，下面我們也用A B C來代表主庫、從庫1、從庫2。
二、延遲計算和級聯從庫C
一般來講我們在討論延遲的時候，延遲的計算公式大概如下，當然準確來說是單SQL線程（非MTS）下計算延遲的公式。
其中在主庫row格式的binlog其query event中exec time的時間基本為0，因此B庫在計算延遲的時候基本可以在公式中簡化掉。
而在級聯從庫C中，其binlog來自B庫，那么在B庫中的binlog如何記錄的就成了關鍵，那么其有2個關鍵就是：
(1) Event中header中timestamp的時間：這個時間實際上還是主庫的timestamp時間，并不會因為在B庫執行過就是B庫產生binlog的時間。如下：
thd->set_time(&(common_header->when));
thd->set_query(query_arg, q_len_arg);
thd->set_query_id(next_query_id());
thd->variables.pseudo_thread_id= thread_id; // for temp tables
這里在B庫應用event的時候，設置了線程的start_time,也就是來自event header，這個實際上就是主庫執行命令的時間，因此B庫中記錄的binlog的event header的timestamp 依舊來自主庫。
(2) query event中exec time的時間：這個時間雖然在主庫幾乎為0，但是B庫在記錄的時候為當前時間 - 線程的start_time，而線程的start_time來自主庫執行命令的時間，因此這個時間大概就是，B庫當前時間-主庫A執行命令的時間，基本就是B庫的在執行query event時刻的延遲時間，如下：
ulonglong micro_end_time= my_micro_time();//這里獲取當前服務器時間時間
my_micro_time_to_timeval(micro_end_time, &end_time);
exec_time= end_time.tv_sec - thd_arg->start_time.tv_sec; //計算exec time
那么級聯從庫C的延遲實際上就是：
從庫C當前時間-(主庫執行命令的時間+B庫的在執行query event時刻的延遲時間)- 主從服務器時間差
好了回到開頭的問題，總結為2點：
- 當B庫延遲很大的時候顯然根據這個公式可以計算出C庫的延遲是比較小的，因為B庫在執行query event時刻的延遲非常大，那么記錄的exec time就很大，到了C庫計算延遲的時候就直接扣除了這部分。
- 當B庫沒什么延遲的時候，C庫計算的延遲基本上就是相對于主庫的延遲，因為這個時候B庫在執行query event時刻的延遲非常小，不會產生太大的誤差。
當然整個邏輯還是說的是時鐘同步的情況下。
三、觀察B庫中的exec time
這里很容易觀察到這種現象，只需要稍微做一下延遲就可以了。 主庫A：
# at 1097
#230518 15:50:04 server id 333900 end_log_pos 1174 CRC32 0xab4d2adc Query thread_id=4 exec_time=0 error_code=0
SET TIMESTAMP=1684396204/*!*/;
從庫B：
# at 1069
#230518 15:50:04（timestampm是主庫的） server id 333900 end_log_pos 1132 CRC32 0x483e49b5 Query thread_id=4 exec_time=48（這里） error_code=0
SET TIMESTAMP=1684396204/*!*/;
在測試期間還發現B庫，可能 exec_time很大的情況這里簡單描述一下，如下，
#230517 15:33:05 server id 1623306 end_log_pos 1558 CRC32 0x2d7d12fc Query thread_id=17 exec_time=4283165634（這里） error_code=0
SET TIMESTAMP=1684308785/*!*/;
顯然這個是B庫服務器時間落后于A庫的時候，出現相減負數的情況，然后轉非負整數，得到了一個很大的值。這種情況下C的延遲計算也會受到影響。
