原標題：MySQL 復制延遲 Seconds_Behind_Master 究竟是如何計算的

導讀：

作者：羅小波

參考鏈接

https://dev.mysql.com/doc/refman/5.7/en/show-slave-status.html

https://wemp.app/posts/33881a28-ba27-4908-994e-29440455d5be https://blog.csdn.net/innobase/article/details/51302138

歡迎轉載，轉載請注明出處！

目錄

"口口相傳" 的計算方法

探尋 "正確" 的計算方法

驗證 我們想確認什么 提前確認一些信息 執行驗證

總結

背景說明

在使用主從復制的拓撲中，監控復制延遲時間是必不可少的功課，如果應用場景對復制延遲并不敏感，那么，大多數時候通過采集 SHOW SLAVE STATUS 語句輸出信息中的 Seconds_Behind_Master 字段值來監控復制延遲就已經足夠了，相信有MySQL使用經驗的人對通過這種方法來查看復制延遲并不陌生，我們都知道 Seconds_Behind_Master 的值在某些場景下并不是那么可靠，也或多或少都知道一些 Seconds_Behind_Master 字段值計算方法。但這些計算方法真的正確么？

本著鉆研的精神，今天我就較真一回，搜羅一些關于計算方法的傳說，并進行一些簡單的驗證，整理出來，洋洋灑灑寫了一大篇，在這里分享給大家

一、"口口相傳" 的計算方法

?方法一：從庫 I/O 線程讀取的主庫 binlog event 時間戳與 SQL 線程正在執行的 binlog event 的時間戳之間的時間差，單位為秒

該方法其實就是在計算兩個線程處理日志的時間差，這也是目前最為 "流行" 的一種說法?；谶@個算法，如果主從之間的網絡存在很大延遲的時候，主庫中就可能存在著大量的binlog還沒來得及發送給從庫，那么這個時候其實使用該方法計算出來的延遲時間，跟主從之間數據真正的延遲就沒有太大關系了

?方法二：從庫的系統(主機)時間與 I/O 線程讀取的主庫 binlog event 的時間差之間的時間差，單位為秒

這種說法沒那么 "流行" ，基于這個算法，如果從庫的操作系統時間被更改了，或者主庫的操作系統時間被修改了，即主從庫的主機時間差本身就比較大的時候，那么計算出來的結果也毫無參考意義

? 結論，看起來這兩種算法都不太靠譜，正確的算法真的是這樣的嗎？為了一探究竟，我們需要找到可靠的信息源進行確認。

那么從哪里可以獲得可靠的信息源呢？

二、探尋 "正確" 的計算方法

?信息源一：MySQL 官方手冊

為了不占篇幅、也為了避免本人英文理解錯誤，下面直接貼出官方手冊中關于 Seconds_Behind_Master 字段值計算描述的原文

大概的含義：

* 當從庫正在不斷地處理更新時(持續不斷有event被SQL線程或者I/O線程處理時)，此字段顯示從庫主機當前時間戳和來自主庫(原始)的二進制日志中記錄的時間戳之間的差異

* 當從庫沒有任何需要處理的更新時，如果I/O和SQL線程狀態都為Yes，則此字段顯示為0，如果有任意一個線程狀態不為Yes，則此字段顯示為NULL

* 實際上，這個字段是度量從庫SQL線程和I/O線程之間的時間差，單位為秒，如果主備之間的網絡非?？?#xff0c;那么從庫的I/O線程讀取的主庫binlog會與主庫中最新的binlog非常接近，所以這樣計算得來得值就可以作為主備之間的數據延遲時間，但是如果主備之間的網絡非常慢，可能導致從庫SQL線程正在重放的主庫binlog 非常接近從庫I/O線程讀取的主庫binlog，而I/O線程因為網絡慢的原因可能讀取的主庫binlog遠遠落后于主庫最新的binlog，此時，這么計算得來的值是不可靠的，盡管這個時候有可能該字段顯示為0，但實際上可能從庫已經落后于主庫非常多了。所以，對于網絡比較慢的情況，該值并不可靠

* 如果主庫與從庫的server自身的時間不一致，那么，只要從庫復制線程啟動之后，沒有做過任何時間變更，那么這個字段的值也可以正常計算，但是如果修改了server的時間，則可能導致時鐘偏移，從而導致這個計算值不可靠

* 如果從庫的SQL線程沒運行、SQL線程正在運行且已經消費完了所有的relay log且I/O線程沒有運行，則該字段顯示為NULL(如果I/O線程已經停止，但還存在著relay log未重放完成時，仍然會顯示出復制延遲時間，直到所有relay log被重放完成之后，顯示為NULL)，如果SQL線程和I/O線程都運行著，但是處于空閑狀態(SQL線程已經重放完了I/O線程產生的

relay log)，則該字段顯示為0

* 該字段的值是基于存儲在主庫binlog event中的時間戳，保留這個時間戳并通過復制架構同步到從庫進行計算得來，那就意味著正常的復制情況下(排除人為在從庫寫入數據的情況)主庫與從庫上的binlog event的時間戳都來自主庫，在目前的計算該字段值的算法中有一個問題，在單線程復制場景下，即如果從庫上通過客戶端連接進入并直接更新數據，這可能導致該字段的值隨機波動，因為有時候event來源于主庫，有時候來源于從庫直接更新產生的event，而這個字段的值會受到直接更新產生的event的影響。但如果是多線程復制，則此值是基于Exec_Master_Log_Pos點的event時間戳來計算的，因此可能不會反映從庫最近提交的事務的位置

?信息源二：源碼

以下是源碼中關于延遲時間計算方法的注釋說明

# 位于rpl_mi.h中定義clock_diff_with_master附近(翻閱了5.6.34和5.7.22 兩個版本，對于復制延遲的計算公式兩者一致)

# 從源碼注釋上來看，復制延遲的計算公式為 clock_of_slave - last_timestamp_executed_by_SQL_thread - clock_diff_with_master

# 該公式的含義為：從庫的當前系統(主機)時間 - 從庫 SQL 線程正在執行的event的時間戳 - 主從庫的系統(主機)之間的時間差

/*

The difference in seconds between the clock of the master and the clock of

the slave (second - first). It must be signed as it may be <0 or >0.

clock_diff_with_master is computed when the I/O thread starts; for this the

I/O thread does a SELECT UNIX_TIMESTAMP() on the master.

"how late the slave is compared to the master" is computed like this:

clock_of_slave - last_timestamp_executed_by_SQL_thread - clock_diff_with_master

*/

# clock_diff_with_master 值為主從服務器的主機時間差，該值只在I/O線程啟動時計算一次，后續每次計算Seconds_Behind_Master字段值時，是直接復用這個計算結果，每次重啟I/O線程時該值會重新計算

long clock_diff_with_master;

# master_row[0] 為從庫在主庫上執行SELECT UNIX_TIMESTAMP()的操作，clock_diff_with_master為主從庫主機的時間差計算結果

mi->clock_diff_with_master=

(long) (time((time_t*) 0) - strtoul(master_row[0], 0, 10));

# 從rpl_slave.cc 文件中啟動 I/O 線程時可以看出：

start_slave_thread-> # 啟動start slave

handle_slave_io-> # 啟動start io thread

get_master_version_and_clock # 獲取當前slave和主機之間的時間差(clock_diff_with_master)

以下是源碼中關于Seconds_Behind_Master 計算結果的一些判定值

/*

The pseudo code to compute Seconds_Behind_Master: # 闡明這是一段注釋關于如何計算Seconds_Behind_Master的偽代碼

if (SQL thread is running) # 如果SQL線程正在運行，則進入這個if判斷內，假設這里標記為if one

{

if (SQL thread processed all the available relay log) # 如果SQL線程應用完成了所有可用的relay log，則進入這個if判斷內，假設這里標記為if two

{

if (IO thread is running) # 如果I/O線程正在運行，則進入這個if判斷內，假設這里標記為if three

print 0; # 如果if one/two/three三個條件都為真，則延遲值判定為0

else

print NULL; # 如果if one/two為真，if three為假，則延遲值判定為NULL

}

else

compute Seconds_Behind_Master; # 如果if one為真，if two為假，則執行公式計算延遲值

}

else

print NULL; # 如果if one為假，則延遲值判定為NULL

*/

if (mi->rli->slave_running)

{

/*

Check if SQL thread is at the end of relay log

Checking should be done using two conditions

condition1: compare the log positions and

condition2: compare the file names (to handle rotation case)

*/

if ((mi->get_master_log_pos() == mi->rli->get_group_master_log_pos()) &&

(!strcmp(mi->get_master_log_name(), mi->rli->get_group_master_log_name())))

{

if (mi->slave_running == MYSQL_SLAVE_RUN_CONNECT)

protocol->store(0LL);

else

protocol->store_null();

}

else

{

long time_diff= ((long)(time(0) - mi->rli->last_master_timestamp)

- mi->clock_diff_with_master);

/*

Apparently on some systems time_diff can be <0. Here are possible

reasons related to MySQL:

- the master is itself a slave of another master whose time is ahead.

- somebody used an explicit SET TIMESTAMP on the master.

Possible reason related to granularity-to-second of time functions

(nothing to do with MySQL), which can explain a value of -1:

assume the master's and slave's time are perfectly synchronized, and

that at slave's connection time, when the master's timestamp is read,

it is at the very end of second 1, and (a very short time later) when

the slave's timestamp is read it is at the very beginning of second

2. Then the recorded value for master is 1 and the recorded value for

slave is 2. At SHOW SLAVE STATUS time, assume that the difference

between timestamp of slave and rli->last_master_timestamp is 0

(i.e. they are in the same second), then we get 0-(2-1)=-1 as a result.

This confuses users, so we don't go below 0: hence the max().

last_master_timestamp == 0 (an "impossible" timestamp 1970) is a

special marker to say "consider we have caught up".

*/

protocol->store((longlong)(mi->rli->last_master_timestamp ?

max(0L, time_diff) : 0)); # time_diff這里其實就是最終計算的Seconds_Behind_Master 值，如果為負數，則直接歸零

}

}

三、驗證

1、我們想確認什么

正所謂 "盡信書不如無書" ，我們不能 "它說是這樣我們就信了" ，所以，我們這里簡單對官方手冊和源碼中提及的計算公式、場景進行簡單的驗證，看看實際的表現如何

根據上文源碼中的注釋，我們找到了計算復制延遲的 "正確" 方法(公式)為： * clock_of_slave - last_timestamp_executed_by_SQL_thread - clock_diff_with_master，該公式含義為 "從庫的當前系統(主機)時間 - 從庫 SQL 線程正在執行的event的時間戳 - 主從庫的系統(主機)之間的時間差" * 計算公式中的clock_diff_with_master值，也就是主從庫的主機時差只在I/O線程啟動的時候計算一次(后續會復用該計算結果來計算復制延遲，直到下次重啟I/O線程時才會重新計算)

根據上文官方手冊中的描述，主從庫系統時間不一致也支持正確計算復制延遲： * 如果主從庫的系統時間不一致，那么如果在復制線程(I/O線程)啟動之后，沒有對主庫或者從庫的系統時間再次進行修改，那么根據公式是可以正確計算復制延遲時間的，除非在復制啟動之后再次修改了主從庫的系統時間，就會導致復制延遲時間不可靠(因為計算公式中的clock_diff_with_master 只在I/O線程啟動時才會進行計算，后續計算復制延遲時會復用該計算結果)

根據上文源碼中的描述，當Seconds_Behind_Master計算結果為負數的時候，直接歸零

2、提前確認一些信息

首先：我們需要確認當I/O線程啟動之后，會在主庫上執行一些什么動作？

然后：我們需要確認直接修改主機時間之后，在數據庫中執行一些時間函數是返回的時間信息是否會跟著改變，寫入到二進制日志中的時間信息是否會跟著改變？

我們先來看第一個問題，當I/O線程啟動之后，會在主庫上執行一些什么動作？

先在主庫打開general_log

root@localhost : (none) 10:09:47> set globalgeneral_log=1;

Query OK, 0 rows affected (0.01 sec)

從庫啟動 I/O 線程

root@localhost : (none) 10:16:33> start slave io_thread;

Query OK, 0 rows affected (0.00 sec)

查看主庫general_log中記錄的內容

2019-04-18T10:16:36.414222+08:00 8 Connect qbench@10.10.30.162 on using TCP/IP

2019-04-18T10:16:36.414632+08:00 8 Query SELECT UNIX_TIMESTAMP() # 在主庫查詢系統時間語句，這里可以證實I/O線程啟動的時候會獲取主庫的系統時間，當從庫拿到主庫的系統時間之后，就可以計算主從庫的系統時間之差

2019-04-18T10:16:36.415401+08:00 8 Query SELECT @@GLOBAL.SERVER_ID # 查詢主庫的SERVER_ID

2019-04-18T10:16:36.415638+08:00 8 Query SET @master_heartbeat_period= 5000000000 # 對dump線程在會話級別設置心跳間隔時間

2019-04-18T10:16:36.415814+08:00 8 Query SET @master_binlog_checksum= @@global.binlog_checksum

2019-04-18T10:16:36.416129+08:00 8 Query SELECT @master_binlog_checksum

2019-04-18T10:16:36.416335+08:00 8 Query SELECT @@GLOBAL.GTID_MODE # 查詢主庫的GTID模式值

2019-04-18T10:16:36.416527+08:00 8 Query SELECT @@GLOBAL.SERVER_UUID # 查詢主庫的UUID

2019-04-18T10:16:36.416693+08:00 8 Query SET @slave_uuid= '2d623f55-2111-11e8-9cc3-0025905b06da' # 會話級別設置從庫自己的UUID

2019-04-18T10:16:36.417224+08:00 8 Binlog Dump GTID Log: '' Pos: 4 GTIDs: '06188301-b333-11e8-bdfe-0025905b06da:1-270852,

2d623f55-2111-11e8-9cc3-0025905b06da:1,

f3372787-0719-11e8-af1f-0025905b06da:1-21'

現在，我們來看第二個問題。修改主機時間之后(數據庫進程不重啟)，在數據庫中執行一些時間函數時返回的時間信息是否會跟著改變，寫入到二進制日志中的時間信息是否會跟著改變

在主庫的主機中修改時間

# 修改之前先查詢一下主機和數據庫中的時間，都為2019-04-19 16:14附近

[root@localhost ~]# date

2019年 04月 19日 星期五 16:14:19 CST

# 修改之前先查看數據庫中的時間

mysql > select now(),unix_timestamp(),from_unixtime(unix_timestamp());

+---------------------+------------------+---------------------------------+

| now() | unix_timestamp() | from_unixtime(unix_timestamp()) |

+---------------------+------------------+---------------------------------+

| 2019-04-19 16:14:20 | 1555661660 | 2019-04-19 16:14:20 |

+---------------------+------------------+---------------------------------+

# 修改主機時間為2020-04-19 17:15:00

[root@localhost ~]# date -s '2020-04-19 17:15:00'

2020年 04月 19日 星期日 17:15:00 CST

# 發現在數據庫中使用unix_timestamp()函數查詢到的時間跟隨著主機時間變化了，也變為了2020-04-19

mysql > select now(),unix_timestamp(),from_unixtime(unix_timestamp());

+---------------------+------------------+---------------------------------+

| now() | unix_timestamp() | from_unixtime(unix_timestamp()) |

+---------------------+------------------+---------------------------------+

| 2020-04-19 17:15:03 | 1587287703 | 2020-04-19 17:15:03 |

+---------------------+------------------+---------------------------------+

# 插入一點測試數據，解析binlog，發現binlog中的時間戳也跟著發生了變化，也變為了2020-04-19 ，這里就可以證實主機時間的修改將直接影響數據庫中時間函數獲取的時間以及binlog的時間戳

......

# at 468

#190419 16:14:29 server id 3306154 end_log_pos 499 CRC32 0x80c44c50 Xid = 74

COMMIT/*!*/;

# at 499

#200419 17:15:08 server id 3306154 end_log_pos 564 CRC32 0xc2794ccb GTID last_committed=1 sequence_number=2 rbr_only=yes

/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;

SET @@SESSION.GTID_NEXT= 'c413c893-56b0-11e9-a705-000c29c10fa5:35'/*!*/;

......

3、執行驗證

驗證場景

1、在主庫持續每秒有數據寫入的情況下(腳本持續的每隔一秒插入10行數據)驗證主庫和從庫各自向前和向后修改主機時間、主從庫同時向前和向后修改主機時間時，從庫的復制延遲時間如何變化(腳本持續每秒鐘獲取一次Seconds_Behind_Master字段值)

2、sysbench 加壓到從庫存在復制延遲的情況下，突然停止主庫壓力或突然停止從庫 I/O線程時，從庫復制延遲時間如何變化

驗證結果

4、總結

根據以上可靠的信息來源以及測試驗證過程可以簡單得出如下一些結論

對于主從庫主機時間不一致的情況，在I/O線程第一次啟動時，會計算主從之間的主機時間差，在后續計算復制延遲時，會把這個時間差減掉，這樣就可以保證正確獲取到復制延遲時間，但是該時間差只在I/O線程啟動時才會進行計算，所以，當I/O線程啟動之后修改了主從庫的主機時間，則根據計算公式，會導致復制延遲時間不可靠，但是當I/O線程重啟之后就可以恢復(因為I/O線程重啟時，主從之間的時間差重新計算了)

在計算復制延遲時(執行 SHOW SLAVE STATUS語句時會進行計算)，對Seconds_Behind_Master計算結果做一些判定(上文源碼介紹部分的偽代碼注釋里有講解過，這里再啰嗦一下)： * 如果 I/O 和 SQL線程同時為 Yes，且SQL線程沒有做任何事情(沒有需要被執行的event)，此時直接判定復制延遲結果為0，不會走公式計算延遲時間，否則會走公式計算延遲時間(所以，在該前置條件下不會出現當主庫沒有寫任何binlog event時，從庫延遲不斷加大的情況) * 如果 SQL線程為Yes，且還存在著 I/O 線程已經讀取的relay log未應用完成的，則會走公式計算延遲時間，而不管 I/O線程是否正在運行，但當SQL線程重放完成了所有relay log時，如果 I/O線程不為Yes，直接判定復制延遲結果為NULL * 任何時候，如果SQL線程不為Yes，直接判定復制延遲結果為NULL。當計算出的復制延遲為負數時，直接歸零

補充說明：

1、當SQL線程重放大事務時，SQL線程的時間戳更新相當于被暫停了(因為一個大事務的event在重放時需要很長時間才能完成，雖然這個大事務也可能會有很多event，但是這些event的時間戳可能全都相同)，此時，根據計算公式可以得出，無論主庫是否有新的數據寫入，從庫復制延遲仍然會持續增大(也就是說此時的復制延遲值是不可靠的)。所以就會出現主庫停止寫入之后，從庫復制延遲逐漸增大到某個最高值之后突然變為0的情況

2、官方手冊中對主從拓撲處在一個慢速網絡中表現行為描述不太準確(個人推理觀點)：

* 根據公式計算，如果主庫持續不斷產生二進制日志(持續不斷有數據變更)，則復制延遲的計算結果不會出現誤差(或者說誤差可以忽略不計，因為從庫的系統時鐘是正常向后推進的，除非主從庫的系統時間被改動了)，如果在慢速網絡中主庫斷斷續續寫入數據，甚至主庫突然停止任何數據寫入，之后實際上主庫并沒有新的數據寫入(也就不會有新的binlog event時間戳產生)，但是由于計算公式中并不感知這個變化，所以隨著從庫的系統時鐘繼續向前推進，就會導致在追趕上主庫的數據之前，計算出的延遲時間值越來越大(也就是說此時的復制延遲值是不可靠的)

作者寄語：最后，感謝沃趣科技的同事 @劉云 幫忙做場景驗證，感謝 @沈剛 幫忙查看源碼

加入知數堂

挑戰40萬+年薪！

知數堂

葉金榮與吳炳錫聯合打造

領跑IT精英培訓

行業資深專家強強聯合，傾心定制

MySQL的實戰/ MySQL的優化/ MongoDB的/

Python / SQL優化/ Hadoop + ELK

數門精品課程

“閱讀原文”可獲更多正課試聽視頻

密碼：hg3h

緊隨技術發展趨勢，定期優化培訓教案

融入大量生產案例，貼合企業一線需求

社群陪伴學習，一次報名，可學1年

DBA，開發工程師必修課

上千位學員已華麗轉身，薪資翻番，職位提升

改變已悄然發生，你還在等什么？

MySQL的入門到精通-ZST返回搜狐，查看更多

責任編輯：

總結

以上是生活随笔為你收集整理的mysql seconds_behind_master_MySQL 复制延迟 Seconds_Behind_Master 究竟是如何计算的的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。