網(wǎng)上有很多關(guān)于pos機(jī)自動(dòng)重啟,sync插件崩潰導(dǎo)致MySQL重啟的故障分析的知識(shí)，也有很多人為大家解答關(guān)于pos機(jī)自動(dòng)重啟的問題，今天pos機(jī)之家(www.shineka.com)為大家整理了關(guān)于這方面的知識(shí)，讓我們一起來看下吧!
本文目錄一覽：
pos機(jī)自動(dòng)重啟
起因：測(cè)試公司的保障MySQL高可用組件時(shí)發(fā)現(xiàn)一個(gè)異常。
停止從庫，高可用組件將從庫自動(dòng)啟動(dòng)后，主庫發(fā)生重啟。而正常情況下主庫不應(yīng)發(fā)生重啟。
環(huán)境：OS: CentOS release 6.7 (Final)MySQL：Ver 14.14 Distrib 5.7.13, for linux-glibc2.5 (x86_64) using EditLine wrapper主從實(shí)例開啟半同步 MySQL semi-sync配置文檔分析：首先，先分析log文件在主庫的mysql-error.log中我們可以發(fā)現(xiàn)如下幾點(diǎn)：1. 主庫的semi-sync在崩潰前做了啟停動(dòng)作。
2017-07-25T16:02:38.636061+08:00 40 [Note] Semi-sync replication switched OFF.2017-07-25T16:02:38.636105+08:00 40 [Note] Semi-sync replication disabled on the master.2017-07-25T16:02:38.636137+08:00 0 [Note] Stopping ack receiver thread2017-07-25T16:02:38.638008+08:00 40 [Note] Semi-sync replication enabled on the master.2017-07-25T16:02:38.638131+08:00 0 [Note] Starting ack receiver thread
2. 主庫的semi-sync啟動(dòng)后立即引發(fā)了semi-sync插件崩潰，并拋出Assert異常。
mysqld: /export/home/pb2/build/sb_0-19016729-1464157976.67/mysql-5.7.13/plugin/semisync/semisync_master.cc:844: int ReplSemiSyncMaster::commitTrx(const char*, my_off_t): Assertion `entry' failed.08:02:38 UTC - mysqld got signal 6 ;
3. 這里還有一個(gè)相當(dāng)重要的復(fù)現(xiàn)故障的線索。簡(jiǎn)單說明一下，這條SQL語句是為了檢測(cè)主從數(shù)據(jù)差，而由高可用中間件不斷的向數(shù)據(jù)庫更新時(shí)間戳。
Trying to get some variables.Some pointers may be invalid and cause the dump to abort.Query (7f408c0054c0): update universe.u_delay set real_timestamp=now(), logic_timestamp = logic_timestamp + 1 where source = 'ustats'Connection ID (thread ID): 61Status: NOT_KILLED
到這里初步判斷是這個(gè)故障應(yīng)與設(shè)置rpl_semi_sync_master_enabled開關(guān)相關(guān)，并且應(yīng)該當(dāng)時(shí)是有事務(wù)提交的。
進(jìn)一步驗(yàn)證，這里只部署一組開啟semi-sync的MySQL實(shí)例，而不安裝高可用組件。利用bash腳本向主庫不斷插入數(shù)據(jù)：
/opt/mysql/base/bin/mysql -uroot -p1 -S /opt/mysql/data/3306/mysqld.sock -e "create database if not exists test;use test;drop table if exists t1;create table t1(id int) "
i=0
while true
do
/opt/mysql/base/bin/mysql -uroot -p1 -S /opt/mysql/data/3306/mysqld.sock -e "insert into test.t1 values($i)"
i=$((i+1))
done
在主庫的機(jī)器上，反復(fù)運(yùn)行如下命令，啟停semi-sync master，不超過5次必能復(fù)現(xiàn)這個(gè)故障。
/opt/mysql/base/bin/mysql -uroot -p1 -S /opt/mysql/data/3306/mysqld.sock -e'SET GLOBAL rpl_semi_sync_master_enabled = OFF;SET GLOBAL rpl_semi_sync_master_enabled = ON'
所以這個(gè)故障復(fù)現(xiàn)有了兩個(gè)必要條件：
啟停semi-sync master數(shù)據(jù)庫當(dāng)時(shí)有事務(wù)提交其次，分析MySQL源碼至于為什么不能每次啟停semi-sync master都能觸發(fā)這個(gè)故障，那我們就要看看MySQL的源碼了
還好mysql-error.log明確的指出了拋出異常的位置：
mysqld: /export/home/pb2/build/sb_0-19016729-1464157976.67/mysql-5.7.13/plugin/semisync/semisync_master.cc:844: int ReplSemiSyncMaster::commitTrx(const char*, my_off_t): Assertion `entry' failed.08:02:38 UTC - mysqld got signal 6 ;This could be because you hit a bug. It is also possible that this binaryor one of the libraries it was linked against is corrupt, improperly built,or misconfigured. This error can also be caused by malfunctioning hardware.Attempting to collect some information that could help diagnose the problem.As this is a crash and something is definitely wrong, the informationcollection process might fail.
找到MySQL源碼，拋出異常的的位置 mysql-5.7.13 semisync_master.cc#L844
看來是這個(gè)‘entry’的值為NULL，才拋出的異常，但是這還沒有回答我的疑問。
再看MySQL的報(bào)錯(cuò)信息，MySQL自己也認(rèn)識(shí)到這應(yīng)該是個(gè)BUG，那它有沒有修復(fù)這個(gè)故障呢？
我找到MySQL最新5.7.19的版本，查看它的歷史記錄mysql-5.7.19 semisync_master.cc history
這正是我想要的修復(fù)和提交，打開看看有沒有對(duì)產(chǎn)生故障原因的分析。Bug#22202516: ENABLING SEMI-SYNC DURING COMMIT CAN CAUSE MASTER TO ASSERT.
為了方便解釋這個(gè)BUG, 這里先簡(jiǎn)單的介紹一下MySQL binlog提交過程：MySQL 在5.6版本引入了Binary Log Group Commit，二進(jìn)制日志的提交由此可以簡(jiǎn)化為三個(gè)階段：
Flush stage：將事務(wù)的日志寫入binlog文件的緩存中
Sync stage: 將binlog文件中的緩存數(shù)據(jù)寫入磁盤
Commit stage：根據(jù)順序調(diào)用存儲(chǔ)引擎提交事務(wù)。
MYSQL_BIN_LOG::ordered_commit，這個(gè)是事務(wù)在binlog階段提交的核心函數(shù)。通過該函數(shù)，實(shí)現(xiàn)了事務(wù)日志寫入binlog文件，以及觸發(fā)dump線程將binlog發(fā)送到從庫，在最后將事務(wù)設(shè)置為提交狀態(tài)。
事實(shí)上，有沒有semi-sync機(jī)制，上面介紹的MySQL的有關(guān)事務(wù)提交中關(guān)于binlog的流程都是一樣的。semi-sync的作用只是主從之間的一個(gè)確認(rèn)過程，主庫等待從庫返回相關(guān)位置的binlog已經(jīng)同步到從庫的確認(rèn)，沒有得到確認(rèn)之前，事務(wù)提交則在該函數(shù)（步驟）上等待直至獲得返回。
在半同步復(fù)制中，為了在主庫提交事務(wù)時(shí)等待從庫的確認(rèn)，才引出了由‘entry’組成的active transaction鏈表。
在BUG分析中提到：首先在flush stage，由semi-sync創(chuàng)建一個(gè)‘entry’，并關(guān)聯(lián)一個(gè)或一組處于flush stage的事務(wù)。這個(gè)‘entry’被插入一個(gè)active transaction鏈表。 參考: create entry搜圖
編輯
接下來是sync stage，在sync stage每個(gè)處于這個(gè)階段的線程將會(huì)設(shè)置trx_wait_binlog_name和trx_wait_binlog_pos為事務(wù)對(duì)應(yīng)binlog的相對(duì)位置最后再commit stage，semi-sync為了等從庫的確認(rèn)，會(huì)用trx_wait_binlog_name和trx_wait_binlog_pos獲取這個(gè)位置關(guān)聯(lián)的'entry', 參考: find entry這里有兩個(gè)場(chǎng)景會(huì)出現(xiàn)‘entry’找不到的狀況：
1. 從庫已經(jīng)確認(rèn)的事務(wù)在binlog位置比當(dāng)前等待從庫確認(rèn)的事務(wù)在binlog的位置要大
2. 當(dāng)事務(wù)進(jìn)入flush stage的時(shí)候semi-sync還沒有開啟，也就沒有‘entry’被創(chuàng)建，然后插入active transaction鏈表
這里情況1永遠(yuǎn)也不會(huì)進(jìn)入等待階段，因?yàn)樗呀?jīng)被從庫確認(rèn)過了。情況2則會(huì)導(dǎo)致上述的斷言異常，因?yàn)檫@里他無法在active transaction鏈表找到相應(yīng)的’entry‘
到這里我的疑問終于解開，原來開啟semi-sync master的時(shí)機(jī)很重要，要恰巧撞到事務(wù)提交過了flush stage但還沒有到commit stage這個(gè)縫隙。
結(jié)論：最終修復(fù)的結(jié)果也很明顯，就是遇到找不到‘entry’，并且從庫也沒有確認(rèn)的情況，這個(gè)事務(wù)提交就被認(rèn)為是一次異步提交。
再看一眼在哪些版本修復(fù)了這個(gè)BUG：
所以升級(jí)MySQL版本可以解決問題。
復(fù)盤：最后總結(jié)一下我的診斷路徑：
觀察故障出現(xiàn)的現(xiàn)象，分析MySQL的error log通過猜想和實(shí)驗(yàn)，構(gòu)成簡(jiǎn)單的復(fù)現(xiàn)場(chǎng)景通過日志和MySQL源碼的對(duì)應(yīng)關(guān)系, 搜索代碼歷史, 定位BUG號(hào)通過閱讀BUG的分析，了解異常發(fā)生的原理并知道了詳細(xì)的復(fù)現(xiàn)條件以上就是關(guān)于pos機(jī)自動(dòng)重啟,sync插件崩潰導(dǎo)致MySQL重啟的故障分析的知識(shí)，后面我們會(huì)繼續(xù)為大家整理關(guān)于pos機(jī)自動(dòng)重啟的知識(shí)，希望能夠幫助到大家！
