本文講的是<b>semi-sync插件崩潰導緻MySQL重新開機故障詳析</b>
導讀
semi-sync插件崩潰導緻MySQL重新開機的故障分析全過程~
作者：劉安
現為愛可生進階測試工程師，擁有豐富的自動測試開發經驗；曾先後在文思海輝、Splunk擔任測試工程師。
一、起因：
在公司測試MySQL高可用元件時發現一個異常。如下：
停止從庫，高可用元件将從庫自動啟動後，主庫發生了重新開機。然而，正常情況下，主庫不應發生重新開機。
二、環境：
1、OS： CentOS release 6.7 (Final)；
2、MySQL：Ver 14.14 Distrib 5.7.13, for linux-glibc2.5 (x86_64) using EditLine wrapper；
3、主從執行個體開啟半同步 MySQL semi-sync配置文檔。
三、分析：
(一）首先，分析log檔案：
在主庫的mysql-error.log中，我們可以發現如下幾點：
1、主庫的semi-sync在崩潰前做了啟停動作：
2、主庫的semi-sync啟動後，立即引發了semi-sync插件崩潰并抛出Assert異常。
3、這裡還有一個相當重要的複現故障的線索。簡單說明一下，這條SQL語句是為了檢測主從資料差，而由高可用中間件不斷地向資料庫更新時間戳。
到這裡初步判斷是這個故障應與設定rpl_semi_sync_master_enabled開關相關，并且應該當時是有事務送出的。
（二）其次，進一步驗證：
這裡隻部署一組開啟semi-sync的MySQL執行個體，而不安裝高可用元件，利用bash腳本向主庫不斷插入資料：
在主庫的機器上，反複運作如下指令，啟停semi-sync master，不超過5次必能複現這個故障。
是以這個故障複現有了兩個必要條件：
啟停semi-sync master；
資料庫當時有事務送出。
（三）最後分析MySQL源碼：
至于為什麼不能每次啟停semi-sync master都能觸發這個故障，那我們就要看看MySQL的源碼了。還好mysql-error.log明确地指出了抛出異常的位置：
找到MySQL源碼，抛出異常的的位置 mysql-5.7.13 semisync_master.cc。
看來是這個‘entry’的值為NULL，才抛出的異常，但是這還沒有回答我的疑問；再看MySQL的報錯資訊，MySQL自己也認識到這應該是個BUG，那它有沒有修複這個故障呢？
我找到MySQL最新5.7.19的版本，檢視它的曆史記錄mysql-5.7.19 semisync_master.cc history 。
這正是我想要的修複和送出，打開看看有沒有對産生故障原因的分析，Bug#22202516: ENABLING SEMI-SYNC DURING COMMIT CAN CAUSE MASTER TO ASSERT。
為了友善解釋這個BUG, 這裡先簡單的介紹一下MySQL binlog送出過程：MySQL 在5.6版本引入了Binary Log Group Commit，二進制日志的送出由此可以簡化為三個階段：
Flush stage：将事務的日志寫入binlog檔案的緩存中
Sync stage: 将binlog檔案中的緩存資料寫入磁盤
Commit stage：根據順序調用存儲引擎送出事務
MYSQL_BIN_LOG::ordered_commit這是事務在binlog階段送出的核心函數。通過該函數，實作了事務日志寫入binlog檔案，以及觸發dump線程将binlog發送到從庫，在最後将事務設定為送出狀态；
事實上有沒有semi-sync機制，上面介紹的MySQL的有關事務送出中關于binlog的流程都是一樣的。semi-sync的作用隻是主從之間的一個确認過程，主庫等待從庫傳回相關位置的binlog已經同步到從庫的确認，沒有得到确認之前，事務送出則在該函數（步驟）上等待直至獲得傳回。
在半同步複制中，為了在主庫送出事務時等待從庫的确認，才引出了由‘entry’組成的active transaction連結清單。
在BUG分析中提到：
首先在flush stage，由semi-sync建立一個‘entry’，并關聯一個或一組處于flush stage的事務。這個‘entry’被插入一個active transaction連結清單。
接下來是sync stage，在sync stage每個處于這個階段的線程将會設定trx_wait_binlog_name和trx_wait_binlog_pos為事務對應binlog的相對位置；
最後再commit stage，semi-sync為了等從庫的确認，會用trx_wait_binlog_name和trx_wait_binlog_pos擷取這個位置關聯的'entry',
這裡有兩個場景會出現‘entry’找不到的情況：
1、從庫已經确認的事務在binlog位置比目前等待從庫确認的事務在binlog的位置要大；
2、當事務進入flush stage的時候semi-sync還沒有開啟，也就沒有‘entry’被建立，然後插入active transaction連結清單。
情況1永遠也不會進入等待階段，因為它已經被從庫确認過了；
情況2則會導緻上述的斷言異常，因為這裡它無法在active transaction連結清單找到相應的’entry‘。
到這裡我的疑問終于解開，原來開啟semi-sync master的時機很重要，要恰巧撞到事務送出過了flush stage但還沒有到commit stage這個縫隙。
四、結論：
最終修複的結果也很明顯，就是遇到找不到‘entry’并且從庫也沒有确認的情況，這個事務送出就被認為是一次異步送出。
再看一眼在哪些版本修複了這個BUG：
是以更新MySQL版本可以解決問題。
五、複盤：
最後總結一下我的診斷路徑：
觀察故障出現的現象，分析MySQL的error log；
通過猜想和實驗，構成簡單的複現場景；
通過日志和MySQL源碼的對應關系, 搜尋代碼曆史, 定位BUG号；
通過閱讀BUG的分析，了解異常發生的原理并知道了詳細的複現條件。
原文釋出時間為：2017-09-04
本文作者：劉安
本文來自雲栖社群合作夥伴“老葉茶館”，了解相關資訊可以關注“老葉茶館”微信公衆号