摘要：對(duì)于該故障的分析，我們要從主從實(shí)例相同，但是事務(wù)不同的原因入手，該問題猜測(cè)與相關(guān)，我們針對(duì)同步事務(wù)的時(shí)序做如下分析。接受者被動(dòng)接收提議者的提議，并記錄和反饋，或?qū)W習(xí)達(dá)成共識(shí)的提議。節(jié)點(diǎn)將的提案信息發(fā)送至組內(nèi)，仍收到了大多數(shù)成員返回。

本文是由愛可生運(yùn)維團(tuán)隊(duì)出品的「MySQL專欄」系列文章，內(nèi)容來自于運(yùn)維團(tuán)隊(duì)一線實(shí)戰(zhàn)經(jīng)驗(yàn)，涵蓋MySQL各種特性的實(shí)踐，優(yōu)化案例，數(shù)據(jù)庫架構(gòu)，HA，監(jiān)控等，有掃雷功效。
愛可生開源社區(qū)持續(xù)運(yùn)營維護(hù)的小目標(biāo)：

每周至少推送一篇高質(zhì)量技術(shù)文章

每月研發(fā)團(tuán)隊(duì)發(fā)布開源組件新版

每年1024開源一款企業(yè)級(jí)組件
2019年至少25場社區(qū)活動(dòng)


歡迎大家持續(xù)關(guān)注～

MGR作為MySQL原生的高可用方案，它的基于共識(shí)協(xié)議的同步和決策機(jī)制，看起來也更為先進(jìn)。吸引了一票用戶積極嘗試，希望通過MGR架構(gòu)解決RPO=0的高可用切換。在實(shí)際使用中經(jīng)常會(huì)遇到因?yàn)榫W(wǎng)絡(luò)抖動(dòng)的問題造成集群故障，最近我們某客戶就遇到了這類問題，導(dǎo)致數(shù)據(jù)不一致。

問題現(xiàn)象

這是在生產(chǎn)環(huán)境中一組MGR集群，單主架構(gòu)，我們可以看到在相同的GTID86afb16f-1b8c-11e8-812f-0050568912a4:57305280下，本應(yīng)執(zhí)行相同的事務(wù)，但binlog日志顯示不同事務(wù)信息。

Primary節(jié)點(diǎn)binlog：

SET @@SESSION.GTID_NEXT= "86afb16f-1b8c-11e8-812f-0050568912a4:57305280"/*!*/;# at 637087357#190125 15:02:55 server id 3136842491 end_log_pos 637087441 Querythread_id=19132957 exec_time=0 error_code=0SET TIMESTAMP=1548399775/*!*/;BEGIN/*!*/;# at 637087441#190125 15:02:55 server id 3136842491 end_log_pos 637087514 Table_map:`world`.`IC_WB_RELEASE` mapped to number 398# at 637087514#190125 15:02:55 server id 3136842491 end_log_pos 637087597 Write_rows: table id 398flags: STMT_END_FBINLOG "n7RKXBP7avi6SQAAABov+SUAAI4BAAAAAAEAB2ljZW50ZXIAFUlDX1FVRVJZX1VTRVJDQVJEX0xP"/*!*/;### INSERT INTO `world`.`IC_WB_RELEASE`### SET

Secondary節(jié)點(diǎn)binlog：

SET @@SESSION.GTID_NEXT= "86afb16f-1b8c-11e8-812f-0050568912a4:57305280"/*!*/;# at 543772830#190125 15:02:52 server id 3136842491 end_log_pos 543772894 Querythread_id=19162514 exec_time=318 error_code=0SET TIMESTAMP=1548399772/*!*/;BEGIN/*!*/;# at 543772894#190125 15:02:52 server id 3136842491 end_log_pos 543772979 Table_map:`world`.`IC_QUERY_USERCARD_LOG` mapped to number 113# at 543772979#190125 15:02:52 server id 3136842491 end_log_pos 543773612 Delete_rows: table id113 flags: STMT_END_FBINLOG "nLRKXBP7avi6VQAAADNRaSAAAHEAAAAAAAEAB2ljZW50ZXIADUlDX1dCX1JFTEVBU0UACw8PEg8"/*!*/;### DELETE FROM `world`.`IC_QUERY_USERCARD_LOG`### WHERE

從以上信息可以推測(cè)，primary節(jié)點(diǎn)在這個(gè)GTID下對(duì)world.IC_WB_RELEASE表執(zhí)行了insert操作事件沒有同步到secondary節(jié)點(diǎn)，secondary節(jié)點(diǎn)收到主節(jié)點(diǎn)的其他事件，造成了數(shù)據(jù)是不一致的。當(dāng)在表IC_WB_RELEASE發(fā)生delete操作時(shí)，引發(fā)了下面的故障，導(dǎo)致從節(jié)點(diǎn)脫離集群。

2019-01-28T11:59:30.919880Z 6 [ERROR] Slave SQL for channel "group_replication_applier": Could not execute Delete_rows event on table `world`.`IC_WB_RELEASE`; Can"t find record in "IC_WB_RELEASE", Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND, Error_code: 10322019-01-28T11:59:30.919926Z 6 [Warning] Slave: Can"t find record in "IC_WB_RELEASE" Error_code: 10322019-01-28T11:59:30.920095Z 6 [ERROR] Plugin group_replication reported: "The applier thread execution was aborted. Unable to process more transactions, this member will now leave the group."2019-01-28T11:59:30.920165Z 6 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log "FIRST" position 271.2019-01-28T11:59:30.920220Z 3 [ERROR] Plugin group_replication reported: "Fatal error during execution on the Applier process of Group Replication. The server will now leave the group."2019-01-28T11:59:30.920298Z 3 [ERROR] Plugin group_replication reported: "The server was automatically set into read only mode after an error was detected."

問題分析

主節(jié)點(diǎn)在向從節(jié)點(diǎn)同步事務(wù)時(shí)，至少有一個(gè)GTID為86afb16f-1b8c-11e8-812f-0050568912a4:57305280（執(zhí)行的是insert操作）的事務(wù)沒有同步到從節(jié)點(diǎn)，此時(shí)從實(shí)例還不存在這個(gè)GTID；于是主實(shí)例GTID高于從實(shí)例。數(shù)據(jù)就已經(jīng)不一致了。

集群業(yè)務(wù)正常進(jìn)行，GTID持續(xù)上漲，新上漲的GTID同步到了從實(shí)例，占用了86afb16f-1b8c-11e8-812f-0050568912a4:57305280這個(gè)GTID，所以從實(shí)例沒有執(zhí)行insert操作，少了一部分?jǐn)?shù)據(jù)。

主節(jié)點(diǎn)對(duì)GTID為86afb16f-1b8c-11e8-812f-0050568912a4:57305280執(zhí)行的insert數(shù)據(jù)進(jìn)行delete，而從節(jié)點(diǎn)由于沒有同步到原本的insert操作；沒有這部分?jǐn)?shù)據(jù)就不能delete，于是脫離了集群。

對(duì)于該故障的分析，我們要從主從實(shí)例GTID相同，但是事務(wù)不同的原因入手，該問題猜測(cè)與bug（https://bugs.mysql.com/bug.ph...）相關(guān)，我們針對(duì)MGR同步事務(wù)的時(shí)序做如下分析。

相關(guān)知識(shí)背景

MGR全組同步數(shù)據(jù)的Xcom組件是基于paxos算法的實(shí)現(xiàn)；每當(dāng)提交新生事務(wù)時(shí)，主實(shí)例會(huì)將新生事務(wù)發(fā)送到從實(shí)例進(jìn)行協(xié)商，組內(nèi)協(xié)商通過后全組成員一起提交該事務(wù)；每一個(gè)節(jié)點(diǎn)都以同樣的順序，接收到了同樣的事務(wù)日志，所以每一個(gè)節(jié)點(diǎn)以同樣的順序回放了這些事務(wù)，最終組內(nèi)保持了一致的狀態(tài)。

paxos包括兩個(gè)角色：

提議者（Proposer）：主動(dòng)發(fā)起投票選主，允許發(fā)起提議。
接受者（Acceptor）：被動(dòng)接收提議者（Proposer）的提議，并記錄和反饋，或?qū)W習(xí)達(dá)成共識(shí)的提議。

paxos達(dá)成共識(shí)的過程包括兩個(gè)階段：

第一階段（prepare）

a：提議者（Proposer）發(fā)送prepare請(qǐng)求，附帶自己的提案標(biāo)識(shí)（ballot，由數(shù)值編號(hào)加節(jié)點(diǎn)編號(hào)組成）以及value值。組成員接收prepare請(qǐng)求；b：如果自身已經(jīng)有了確認(rèn)的值，則將該值以ack_prepare形式反饋；在這個(gè)階段中，Proposer收到ack回復(fù)后會(huì)對(duì)比ballot值，數(shù)值大的ballot會(huì)取代數(shù)值小的ballot。如果收到大多數(shù)應(yīng)答之后進(jìn)入下一個(gè)階段。

第二階段（accept）

a：提議者（Proposer）發(fā)送accept請(qǐng)求
b：接收者（Acceptor）收到請(qǐng)求后對(duì)比自身之前的bollat是否相同以及是否接收過value值。如果未接受過value值 以及ballot相同，則返回ack_accept，如果接收過value值，則選取最大的ballot返回ack_accept。c：之后接受相同value值的Proposer節(jié)點(diǎn)發(fā)送learn_op，收到learn_op節(jié)點(diǎn)的實(shí)例表示確認(rèn)了數(shù)據(jù)修改，傳遞給上層應(yīng)用。

針對(duì)本文案例我們需要強(qiáng)調(diào)幾個(gè)關(guān)鍵點(diǎn)：

1.該案例最根本的異常對(duì)比發(fā)生在第二次提案的prepare階段。

2.prepare階段的提案標(biāo)識(shí)由數(shù)值編號(hào)和節(jié)點(diǎn)編號(hào)兩部分組成；其中數(shù)值編號(hào)類似自增長數(shù)值，而節(jié)點(diǎn)編號(hào)不變。

分析過程

結(jié)合paxos時(shí)序，我們對(duì)案例過程進(jìn)行推測(cè)：

Tips：以下分析過程請(qǐng)結(jié)合時(shí)序圖操作步驟觀看

建議點(diǎn)開放大，效果更清晰 ^ ^

【step1】primary節(jié)點(diǎn)要執(zhí)行對(duì)表world.IC_WB_RELEASE的insert操作，向組內(nèi)發(fā)送假設(shè)將ballot設(shè)置為（0.0）以及將value值world.IC_WB_RELEASE的prepare請(qǐng)求，并收到大多數(shù)成員的ack_prepare返回，于是開始發(fā)送accept請(qǐng)求。primary節(jié)點(diǎn)將ballot（0.0）的提案信息發(fā)送至組內(nèi)，仍收到了大多數(shù)成員ack_accept（ballot=0.0value=world.IC_WB_RELEASE）返回。然后發(fā)送learn_op信息【step3】。

同時(shí)其他從節(jié)點(diǎn)由于網(wǎng)絡(luò)原因沒有收到主實(shí)例的的learn_op信息【step3】，而其中一臺(tái)從實(shí)例開始新的prepare請(qǐng)求【step2】，請(qǐng)求value值為no_op（空操作）ballot=1.1（此編號(hào)中節(jié)點(diǎn)編號(hào)是關(guān)鍵，該secondary節(jié)點(diǎn)編號(hào)大于primary節(jié)點(diǎn)編號(hào)，導(dǎo)致了后續(xù)的問題，數(shù)值編號(hào)無論誰大誰小都要被初始化）。

其他的從實(shí)例由于收到過主節(jié)點(diǎn)的value值；所以將主節(jié)點(diǎn)的（ballot=0.0，value=world.IC_WB_RELEASE）返回；而收到的ack_prepare的ballot值的數(shù)值符號(hào)全組內(nèi)被初始化為0，整個(gè)ballot的大小完全由節(jié)點(diǎn)編號(hào)決定，于是從節(jié)點(diǎn)選取了ballot較大的該實(shí)例value值作為新的提案，覆蓋了主實(shí)例的value值并收到大多數(shù)成員的ack_accept【step2】。并在組成員之間發(fā)送了learn_op信息【step3】，跳過了主實(shí)例提議的事務(wù)。

從源碼中可以看到關(guān)于handle_ack_prepare的邏輯。

handle_ack_prepare has the following code:    if (gt_ballot(m->proposal,p->proposer.msg->proposal))        {            replace_pax_msg(&p->proposer.msg, m);            ...            }

此時(shí)，主節(jié)點(diǎn)在accept階段收到了組內(nèi)大多數(shù)成員的ack_accept并收到了 自己所發(fā)送的learn_op信息，于是把自己的提案（也就是binlog中對(duì)表的insert操作）提交【step3】，該事務(wù)GTID為86afb16f-1b8c-11e8-812f-0050568912a4:57305280。而其他節(jié)點(diǎn)的提案為no_op【step3】，所以不會(huì)提交任何事務(wù)。此時(shí)主實(shí)例GTID大于其他從實(shí)例的。

主節(jié)點(diǎn)新生GTID繼續(xù)上漲；同步到從實(shí)例，占用了從實(shí)例的86afb16f-1b8c-11e8-812f-0050568912a4:57305280這個(gè)GTID，于是產(chǎn)生了主節(jié)點(diǎn)與從節(jié)點(diǎn)binlog中GTID相同但是事務(wù)不同的現(xiàn)象。

當(dāng)業(yè)務(wù)執(zhí)行到對(duì)表world.IC_WB_RELEASE的delete操作時(shí)，主實(shí)例能進(jìn)行操作，而其他實(shí)例由于沒有insert過數(shù)據(jù)，不能操作，就脫離了集群。

▽過程總結(jié)：

舊主發(fā)送prepare請(qǐng)求，收到大多數(shù)ack，進(jìn)入accept階段，收到大多數(shù)ack。

從實(shí)例由于網(wǎng)絡(luò)原因沒有收到learn_op信息。

其中一臺(tái)從實(shí)例發(fā)送新的prepare請(qǐng)求，value為no_op。

新一輪的prepare請(qǐng)求中，提案標(biāo)識(shí)的數(shù)值編號(hào)被初始化，新的提案者大于主實(shí)例，從實(shí)例選取新提案，執(zhí)行空操作，不寫入relay-log。代替了主實(shí)例的事務(wù)，使主實(shí)例GTID大于從實(shí)例。

集群網(wǎng)絡(luò)狀態(tài)恢復(fù)，新生事物正常同步到從實(shí)例，占用了本該正常同步的GTID，使集群中主節(jié)點(diǎn)與從節(jié)點(diǎn)相同GTID對(duì)應(yīng)的事務(wù)時(shí)不同的。

結(jié)論

針對(duì)此問題我們也向官方提交SR，官方已經(jīng)反饋社區(qū)版MySQL 5.7.26和MySQL 8.0.16 中會(huì)修復(fù)，如果是企業(yè)版客戶可以申請(qǐng)最新的hotfix版本。

在未升級(jí) MySQL 版本前，若再發(fā)生此類故障，在修復(fù)時(shí)需要人工檢查，檢查切換時(shí)binlog中 GTID 信息與新主節(jié)點(diǎn)對(duì)應(yīng) GTID 的信息是否一致。如果不一致需要人工修復(fù)至一致狀態(tài)，如果一致才可以將被踢出的原主節(jié)點(diǎn)加回集群。

所以正在使用了MGR 5.7.26之前社區(qū)版的DBA同學(xué)請(qǐng)注意避坑。

開源分布式中間件DBLE
社區(qū)官網(wǎng)：https://opensource.actionsky....
GitHub主頁：https://github.com/actiontech...
技術(shù)交流群：669663113

開源數(shù)據(jù)傳輸中間件DTLE
社區(qū)官網(wǎng)：https://opensource.actionsky....
GitHub主頁：https://github.com/actiontech...
技術(shù)交流群：852990221