MySQL主從同步延遲的幾個場景
之所以進行這塊內容的研究，主要針對之前遇到的兩個未解的疑惑：
a． 線上有個系統，半同步狀態經常從半同步變成非同步，然後又馬上恢復為半同步，具體原因未明，雖然之前也猜得八九不離十，但還是未完全確定。
b． 前段時間因為有業務場景需求，做了跨機房非同步複製測試。當mysql寫qps非常高的時候，發現很多日誌還沒有來得及傳送到從庫，也就是binlog日誌在主庫的產生速度大於傳送到從庫的速度，這個速度差一直存在，因此當主庫在持續高壓力地產生binlog的時候，越來越多的binlog沒有傳送到從庫，但當時的網路流量也才18M/S左右（一主一從），從常規的知識認為，千兆的網路傳送的速度可以達到100M，而當前的主從之間的binlog傳送速度只達到了18M左右，原因是什麼？ 是網路問題？ 還是其他原因。
1、主從複製原理
Dump執行緒與io執行緒
當主從複製關係建立之後，主庫上有個dump執行緒，用來傳送在主庫產生的binlog日誌的，而從庫上的io執行緒，則用來接收由dump執行緒通過網路傳送到從庫的binlog日誌，並負責將其寫入relay log 中去。 這就是主從複製的機制， 同時，由於是非同步複製，傳送過程不需要ack的確認。
疑問也正在此處——因為是非同步傳輸，如果單純地理解為binlog檔案直接網路傳送，這個速度應該很快才是，但實際情況:在我們的測試環境中，binlog日誌的傳送速度才18M/s ，小於日誌產生的22M/s左右的速度。為什麼只有這個速度，而沒有把網路頻寬用滿？原因是什麼？
日誌傳送細節
主從複製的結構中，主庫上的dump執行緒跟從庫上的io執行緒各自有一個，所以不存在多執行緒地併發傳送跟接收的情況，只需要瞭解binlog dump執行緒的工作機制，就能瞭解所有的細節。
通過解析binlog檔案，我們可以知道，一個事務可以包含多個event, 下面是一個最簡單的事物的在binlog中所記錄的資訊：
# at 33580
#170531 17:22:53 server id 153443358 end_log_pos 33645 CRC32 0x4ea17869 GTID last_committed=125 sequence_number=126
SET @@SESSION.GTID_NEXT= ‘e1028e43-4123-11e7-a3c2-005056aa17e6:198’/*!*/;
# at 33645
#170531 17:22:53 server id 153443358 end_log_pos 33717 CRC32 0x66820e00 Query thread_id=4 exec_time=0 error_code=0
SET TIMESTAMP=1496222573/*!*/;
BEGIN
/*!*/;
# at 33717
#170531 17:22:53 server id 153443358 end_log_pos 33770 CRC32 0x22ddf25e Table_map: `test`.`xcytest` mapped to number 222
# at 33770
#170531 17:22:53 server id 153443358 end_log_pos 33817 CRC32 0x61051ea0 Write_rows: table id 222 flags: STMT_END_F
BINLOG ‘
bYsuWRMeXCUJNQAAAOqDAAAAAN4AAAAAAAEABHRlc3QAB3hjeXRlc3QAAgMPAlgCAl7y3SI=
bYsuWR4eXCUJLwAAABmEAAAAAN4AAAAAAAEAAgAC//x9AAAABQBzZGZhc6AeBWE=
‘/*!*/;
### INSERT INTO `test`.`xcytest`
### SET
### @1=125 /* INT meta=0 nullable=0 is_null=0 */
### @2=’sdfas’ /* VARSTRING(600) meta=600 nullable=1 is_null=0 */
# at 33817
#170531 17:22:53 server id 153443358 end_log_pos 33848 CRC32 0x630805b4 Xid = 303
COMMIT/*!*/;
每一個at xxxxx段，是一個event .
函式Binlog_sender::send_events 就是傳送binlog中的event事件的函式:
我們來解析一下這個函式：
函式入參：end_pos，當前讀到的binlog檔案的最末尾位置。
log_cache，記錄是當前傳送的日誌的資訊，包含已經傳送的binlog日誌的位置，以及binlog日誌檔案。
函式邏輯分析：
如果當前已傳送的位置log_pos小於已獲取到的檔案的末尾位置end_pos.則表明還有binlog日誌未傳送，進入迴圈。
迴圈體內：
a. 首先呼叫函式read_event,獲取一個事件event.
b. Log_event_type event_type= (Log_event_type)event_ptr[EVENT_TYPE_OFFSET];
該語句用來獲取事件event的型別，然後進行型別檢查
check_event_type(event_type, log_file, log_pos)，如果沒有通過檢查，直接返回1給上層函式。
c. log_pos= my_b_tell(log_cache); 更新log_pos位置，也就是將讀binlog位置的遊標前移到當前位置。
d. 然後呼叫send_packet() 函式進行binlog的傳送。
原來， 不管當前還有多少binlog沒有同步到從庫，主庫傳送binlog的粒度依然是一個一個event的傳送，傳送之前，還需要檢查event的型別。因為是小包傳送，所以網路的流量並不大。
但需要說明一下出現這個現象的前提條件：我們測試環境中，當時資料庫的寫qps達到了50000以上，所以需要傳送的event特別多，即使是非同步，也導致單執行緒的dump執行緒來不及傳送當前產生的日誌。
當寫的qps巨大的時候，確實存在來不及傳送日誌的情景。
2、總結
現在，再來回頭看線上遇到的問題，“同步狀態經常從半同步狀態變成非同步狀態，然後又被及時復原到半同步狀態”，原因是該資料庫是一個分析系統，有時候會做批量的更新，以及批量的匯入。同時，資料庫設定的binlog格式為row模式，對於一個更新多行的事務，裡面包含很多的event(一行是一個event), 所以傳送這個事務的binlog耗時會比較長，無法在1秒鐘內傳送完成（半同步的timeout時間設定為1），所以半同步狀態變成了非同步。
文章來自微信公眾號：資料庫隨筆