MySQL同步狀態雙Yes的假象及seconds_behind_master的含義

　　近期由於特殊原因有一台主庫宕機了一個小時沒有處理，說起來這是個挺不好啥意思的事情，但是由於這個事情反而發現個比較詭異的情況，那就是在主庫宕機一個小時候后，監控才發出從庫IO thread中斷的報警，也就是說在那一個小時內，從庫的同步狀態是雙Yes的。這是多么詭異的現象，那么這是因為什么原因呢？我們下來分析一下。

 

　　眾所周知，MySQL的同步是異步完成的，其中IO thread負責接收從主庫dump的binlog到從庫上生成relay log，然后SQL thead負責解析relay log后在從庫上進行重放來完成同步。這個2步是完全異步的，單獨停止其中一個，並不會影響另一個的正行工作。當這兩個thread都正常工作的時候，show slave status會顯示雙Yes狀態，表示同步正常。

　　提到這2個狀態就不得不提另外一個非常重要的狀態，那就是seconds_behind_master，一般意義上說代表着從庫和主庫的延遲時間，數值越高意味着延遲越大，但是當SBM為0的時候，並不真正意味着從庫已經追上主庫了。相信大家都遇到過，從監控圖上看，SBM一直都是0，在某一個時間點之后突然就變得非常高。這是由於在主庫上執行了一個非常大的event，在這個event在主庫上沒執行完畢的時候，從庫的SBM會顯示為0，而當主庫執行完畢傳到從庫上開始執行的時候，就會顯示SBM非常巨大了。官方的文檔解釋如下：

It is also possible that transient values for Seconds_Behind_Master may not reflect the situation accurately. When the slave SQL thread has caught up on I/O, Seconds_Behind_Master displays 0; but when the slave I/O thread is still queuing up a new event, Seconds_Behind_Master may show a large value until the SQL thread finishes executing the new event. This is especially likely when the events have old timestamps; in such cases, if you execute SHOW SLAVE STATUS several times in a relatively short period, you may see this value change back and forth repeatedly between 0 and a relatively large value.

 

 　　想要驗證的同學可以按照如下的方式進行測試，可以100%復現。

1、首先搭建一個主從關系的數據庫集群 2、在主庫上隨便建立一個表。 3、執行如下語句 insert into aaa select 1 from aaa where x = 1 or sleep(10); 以上語句會在主庫上執行一段時間 4、在執行時間內，在從庫上show slave status會看到SBM全部都是0。（但是這時候其實已經是不同步的了） 5、等待在主庫執行完畢之后，我們就會看到SBM變成一個較大的數字了。

 

 　　那么這個seconds_behind_master的值到底是怎么計算出來的呢？官方的解釋如下：

Seconds_Behind_Master: The number of seconds that the slave SQL thread is behind processing the master binary log

 

 　　也就是說，是SQL thread在執行IO thread dump下來的relay log的時間差。大家都知道relay log中event記錄的時間戳是主庫上的時間戳，而SQL thread的時間戳是從庫上的，也就是說，如果主庫和從庫的時間是一致的，那么這個SBM代表的確實是從庫延后主庫的一個時間差。但是如果主庫和從庫的時間不是一致的，那么這個SBM的意義就基本不存在了。我們可以做如下的測試。

1、還是上的測試環境 2、在從庫上修改時間設置 date -s“+1 hour” 3、執行上面帶有sleep的語句 4、等待主庫執行完畢之后在從庫執行 show slave status 5、可以看到，這時候的SBM的數值至少是一個大於3600的數值 這也就驗證了我們上面的觀點。

 

　　說完了seconds_behind_master，我們繼續來說IO thread和SQL thread的雙Yes假象的問題。

　　我們進行了如下實驗：

1、正常shutdown，結果狀態單no 2、kill mysqld，結果狀態單no 3、kill -9 mysqld，結果狀態雙Yes 4、reboot 服務器，結果狀態雙Yes

 

　　可以看出，只有在重啟服務器的時候（也就是我們今天越到的這個場景），從庫的狀態是雙Yes的。推測在服務器重啟的時候，作為從庫是不知道主庫是已經宕機還是並沒有寫入，所以一直保持雙Yes狀態，一直等待到一定時間點（預估一個小時）之后重試的時候才會真正發現主庫已經宕機了。

　　有如下3個重要參數控制着這個過程slave-net-timeout，master-connect-retry，master-retry-count。根據官方文檔解釋如下

slave-net-timeout意味着在沒有得到更多數據之后slave等待的時間，默認值3600s
master-connect-retry意味着每次和主庫建立鏈接重試的等待時間，默認值為60s master-retry-count意味着從庫同主庫建立鏈接的重試次數，默認86400次

 

　　而這個重試機制是按照如下方法運行的，當從庫發現從主庫上無法獲得更多的暑假了，就會等待slave-net-timeout時間，然后將IO thread置為no狀態，接着開始嘗試重建建立連接，每次建立失敗之后等待master-connect-retry時間，一直重試master-retry-count次。

 

　　所以，由於以上的原因，就造成了我們今天遇到的雙Yes狀態假象，其實當時主庫已經宕機了很久了。

　　解決的辦法其實很簡單，將slave-net-timeout降低即可，比如修改成5分鍾或者1分鍾，這樣可以縮短進入重試機制的等待時間，可以盡早發現問題。

 

　　另，感謝@zolker提醒， MySQL5.5之后增加了relication的heartbeat機制，可以在從庫上通過執行show global status like 'Slave_received_heartbeats'進行查看。

　　當主庫沒有寫入的時候會按照間隔時間跳動，可以依據此進行一定的health-check。

1 2 3 4 5

STOP SLAVE; CHANGE MASTER  TO  master_heartbeat_period= milliseconds; START SLAVE; SHOW STATUS  like  'slave_heartbeat period' SHOW STATUS  like  'slave_received_heartbeats'