本文主要討論的還是5.7，8.0沒有實(shí)際測(cè)試，這里簡(jiǎn)單記錄。

一、問題說明

最近在處理一個(gè)主從問題的時(shí)候，發(fā)現(xiàn)一個(gè)比較奇怪的現(xiàn)象，這個(gè)主從是級(jí)聯(lián)的也就是A->B->C庫(kù)，B庫(kù)問題處理后先啟動(dòng)了B庫(kù)追數(shù)據(jù)，然后修復(fù)C庫(kù)啟動(dòng)追延遲，這個(gè)時(shí)候觀察到的B庫(kù)和C庫(kù)的延遲分別為20000多秒和900多秒，顯然這個(gè)差距是非常大的，而級(jí)聯(lián)又是平時(shí)用得很多的一種方式。 這里實(shí)際上C庫(kù)的延遲應(yīng)該比B庫(kù)更大，那么級(jí)聯(lián)從庫(kù)中C庫(kù)的延遲計(jì)算到底是怎么樣的呢？

這里我們簡(jiǎn)單探討一下，未考慮清楚的地方還請(qǐng)見諒，下面我們也用A B C來代表主庫(kù)、從庫(kù)1、從庫(kù)2。

二、延遲計(jì)算和級(jí)聯(lián)從庫(kù)C

一般來講我們?cè)谟懻撗舆t的時(shí)候，延遲的計(jì)算公式大概如下，當(dāng)然準(zhǔn)確來說是單SQL線程（非MTS）下計(jì)算延遲的公式。

其中在主庫(kù)row格式的binlog其query event中exec time的時(shí)間基本為0，因此B庫(kù)在計(jì)算延遲的時(shí)候基本可以在公式中簡(jiǎn)化掉。

而在級(jí)聯(lián)從庫(kù)C中，其binlog來自B庫(kù)，那么在B庫(kù)中的binlog如何記錄的就成了關(guān)鍵，那么其有2個(gè)關(guān)鍵就是：

(1) Event中header中timestamp的時(shí)間：這個(gè)時(shí)間實(shí)際上還是主庫(kù)的timestamp時(shí)間，并不會(huì)因?yàn)樵贐庫(kù)執(zhí)行過就是B庫(kù)產(chǎn)生binlog的時(shí)間。如下：

    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庫(kù)應(yīng)用event的時(shí)候，設(shè)置了線程的start_time,也就是來自event header，這個(gè)實(shí)際上就是主庫(kù)執(zhí)行命令的時(shí)間，因此B庫(kù)中記錄的binlog的event header的timestamp 依舊來自主庫(kù)。

(2) query event中exec time的時(shí)間：這個(gè)時(shí)間雖然在主庫(kù)幾乎為0，但是B庫(kù)在記錄的時(shí)候?yàn)楫?dāng)前時(shí)間 - 線程的start_time，而線程的start_time來自主庫(kù)執(zhí)行命令的時(shí)間，因此這個(gè)時(shí)間大概就是，B庫(kù)當(dāng)前時(shí)間-主庫(kù)A執(zhí)行命令的時(shí)間，基本就是B庫(kù)的在執(zhí)行query event時(shí)刻的延遲時(shí)間，如下：

  ulonglong micro_end_time= my_micro_time();//這里獲取當(dāng)前服務(wù)器時(shí)間時(shí)間
  my_micro_time_to_timeval(micro_end_time, &end_time);

  exec_time= end_time.tv_sec - thd_arg->start_time.tv_sec; //計(jì)算exec time

那么級(jí)聯(lián)從庫(kù)C的延遲實(shí)際上就是：

從庫(kù)C當(dāng)前時(shí)間-(主庫(kù)執(zhí)行命令的時(shí)間+B庫(kù)的在執(zhí)行query event時(shí)刻的延遲時(shí)間)- 主從服務(wù)器時(shí)間差

好了回到開頭的問題，總結(jié)為2點(diǎn)：

• 當(dāng)B庫(kù)延遲很大的時(shí)候顯然根據(jù)這個(gè)公式可以計(jì)算出C庫(kù)的延遲是比較小的，因?yàn)锽庫(kù)在執(zhí)行query event時(shí)刻的延遲非常大，那么記錄的exec time就很大，到了C庫(kù)計(jì)算延遲的時(shí)候就直接扣除了這部分。
• 當(dāng)B庫(kù)沒什么延遲的時(shí)候，C庫(kù)計(jì)算的延遲基本上就是相對(duì)于主庫(kù)的延遲，因?yàn)檫@個(gè)時(shí)候B庫(kù)在執(zhí)行query event時(shí)刻的延遲非常小，不會(huì)產(chǎn)生太大的誤差。

當(dāng)然整個(gè)邏輯還是說的是時(shí)鐘同步的情況下。

三、觀察B庫(kù)中的exec time

這里很容易觀察到這種現(xiàn)象，只需要稍微做一下延遲就可以了。 主庫(kù)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/*!*/;

從庫(kù)B：

# at 1069
#230518 15:50:04（timestampm是主庫(kù)的） server id 333900  end_log_pos 1132 CRC32 0x483e49b5    Query   thread_id=4     exec_time=48（這里）    error_code=0
SET TIMESTAMP=1684396204/*!*/;

在測(cè)試期間還發(fā)現(xiàn)B庫(kù)，可能 exec_time很大的情況這里簡(jiǎn)單描述一下，如下，

#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/*!*/;

顯然這個(gè)是B庫(kù)服務(wù)器時(shí)間落后于A庫(kù)的時(shí)候，出現(xiàn)相減負(fù)數(shù)的情況，然后轉(zhuǎn)非負(fù)整數(shù)，得到了一個(gè)很大的值。這種情況下C的延遲計(jì)算也會(huì)受到影響。