[[197701]]

主從復(fù)制作為 MySQL 的精髓，有兩大困難：主從數(shù)據(jù)的延時(shí)與數(shù)據(jù)的不一致性。針對(duì)數(shù)據(jù)不一致的排查處理，相信各位大佬們都有豐富的處理經(jīng)驗(yàn)，我就不多說了。

本文主要是給大家分享一個(gè)工作中遇到的奇葩事例：由于一個(gè)極隱式的騷操作，導(dǎo)致從庫丟失數(shù)據(jù)(數(shù)據(jù)丟失量在每天將近萬條記錄)!

環(huán)境描述

業(yè)務(wù)環(huán)境：短時(shí)間內(nèi)(幾個(gè)月的時(shí)間)，業(yè)務(wù)蓬勃發(fā)展，客戶量從一兩萬一下增加到幾十萬用戶。

數(shù)據(jù)庫環(huán)境，如下圖：

問題描述

某天，主庫 10.0.0.1 的 CPU 使用率突然升高，均值達(dá)到 80%+，導(dǎo)致 Keepalived 的 VIP 漂移至從庫 10.0.0.2。

理論上丟失的是切換過程中的幾秒鐘數(shù)據(jù)，業(yè)務(wù)側(cè)對(duì)丟失的這幾秒數(shù)據(jù)表示沒關(guān)系，那么這個(gè)事件到此應(yīng)該就結(jié)束了。

然而當(dāng)天晚上，業(yè)務(wù)打電話過來說：丟失了部分用戶信息，導(dǎo)致用戶登入不了，要求幫忙恢復(fù)數(shù)據(jù)并查找數(shù)據(jù)丟失的原因。

本文對(duì)數(shù)據(jù)恢復(fù)這塊就不具體展開了，稍微提一下，這邊因?yàn)樾轮?10.0.0.2 已經(jīng)有數(shù)據(jù)寫入，只能對(duì)比用戶表數(shù)據(jù)把新主少的數(shù)據(jù)導(dǎo)入進(jìn)去。

初步排查

對(duì)于主從復(fù)制丟失數(shù)據(jù)，解決方法沒有捷徑，只能老老實(shí)實(shí)地跟蹤數(shù)據(jù)復(fù)制過程，查看是哪里出了問題。

選擇丟失數(shù)據(jù)中時(shí)間比較近的，時(shí)間為 2017-06-09 13:36:01，ID為 849791 這條數(shù)據(jù)，來跟蹤整個(gè)復(fù)制過程，因?yàn)槿罩局槐Ａ?14 天的。

分析主庫 binlog 日志，binlog 日志中是有這條記錄的。

分析從庫日志：因?yàn)閿?shù)據(jù)庫配置了 relay_log_purge 與 log-slave-updates，所以中繼日志已經(jīng)找不到這個(gè)時(shí)間點(diǎn)了，只能查看從庫 binlog 日志。

然而在從庫的 binlog 日志中并未找到這條記錄，說明這條數(shù)據(jù)是未執(zhí)行，排除后期人為刪除的，那么數(shù)據(jù)為何不被執(zhí)行呢?或者說數(shù)據(jù)是在執(zhí)行過程中丟失的?

數(shù)據(jù)分析

無可用的中繼日志怎么辦?難道沒辦法查了?于是我決定觀察和對(duì)比一下丟失的數(shù)據(jù)，看看其中是否含有什么規(guī)律，是不定時(shí)丟失數(shù)據(jù)，還是會(huì)在某些特定時(shí)刻丟失數(shù)據(jù)。

整理了一下某表丟失的數(shù)據(jù)，通過觀察、分析丟失數(shù)據(jù)的屬性(下圖是我截取的部分列，***一列的時(shí)間是創(chuàng)建時(shí)間，也就是寫表時(shí)間)：

從圖中可以看出，丟失的數(shù)據(jù)的插表時(shí)間都是在每分鐘的前 2 秒。這不由地讓人思考，為何丟失的數(shù)據(jù)是每分鐘前 2 秒的呢?

而且數(shù)據(jù)丟失的時(shí)間間隔也不是很長(zhǎng)，基本隔幾天就肯定有數(shù)據(jù)丟失。經(jīng)過這樣分析，事情似乎就變得簡(jiǎn)單了。

深入調(diào)查

首先，關(guān)閉 log-slave-updates、relay_log_purge 等一切影響判斷的額外參數(shù)設(shè)置，等待一段時(shí)間后，再來對(duì)比某表新數(shù)據(jù)丟失情況。

可以看到又有新數(shù)據(jù)丟失，根據(jù)這些丟失數(shù)據(jù)再來排查問題。

首先先查主庫，查看主庫的 binlog 日志狀體信息狀態(tài)。

就以 2017-6-17 15:17:02 ***丟失的這條數(shù)據(jù)來跟蹤，查看主庫 10.0.0.2 上的 binlog 日志中是否存在這條數(shù)據(jù)：

 結(jié)果顯示主庫是存在這條數(shù)據(jù)的

在登入從庫查看 relay-log 日志情況，發(fā)現(xiàn) relay-log 日志生成太頻繁，每分鐘生成 1 個(gè) relay-log 日志，而且有些文件大小又不一致。

那么這套主從集群，業(yè)務(wù)肯定部署過分割 relay-log 日志的腳本，而且應(yīng)該是 flush 來強(qiáng)制刷新的。如圖：

 我們先來看從庫 relay-log 日志中是否存在這條數(shù)據(jù)，查找17分生成的relay日志，提取前 2 秒能匹配的插入情況。

 發(fā)現(xiàn)并沒有這條 insert 操作，難道數(shù)據(jù)未寫入 relay 日志，刷新日志時(shí)導(dǎo)致事務(wù)丟失? 把查詢時(shí)間拉長(zhǎng)至 50 秒。

 發(fā)現(xiàn)也沒有這條數(shù)據(jù)，并且數(shù)據(jù)跟前面 2 秒的一致，那么其它數(shù)據(jù)呢?會(huì)不會(huì)在下一個(gè)日志中?

趕緊去 18 分生成的 relay 日志查看，發(fā)現(xiàn)這條數(shù)據(jù)在 15:18 分這個(gè) relay 日志中的***個(gè)事務(wù)的位置。

 那么是沒有執(zhí)行，還是執(zhí)行過程丟失?仔細(xì)觀察主庫 binlog 與從 relay-log 日志的記錄，也沒能看出什么名堂，從事務(wù)開始到 commit，都一樣。

問題定位

如果一條數(shù)據(jù)無法比較，那就再隨機(jī)拿出幾條丟失的數(shù)據(jù)來跟蹤。發(fā)現(xiàn)情況都一樣，數(shù)據(jù)都已經(jīng)復(fù)制到 relay 日志中，而且內(nèi)容根本看不出為何不能執(zhí)行。

唯一有疑點(diǎn)的是這些事務(wù)都在日志的***個(gè)事務(wù)中。頓時(shí)，我有種想法，會(huì)不會(huì)強(qiáng)制刷新 relay 日志，造成日志的***個(gè)事務(wù)有時(shí)不執(zhí)行，或執(zhí)行過程中丟失?

如果是腳本引起的，那么除去這些事務(wù)未執(zhí)行外，肯定還有其它事務(wù)也未執(zhí)行。那么，我就隨機(jī)選擇幾個(gè) relay-log 日志，找到***個(gè)事務(wù)。

具體分析如下：

 再登入從庫查詢結(jié)果：

 可以看出從庫數(shù)據(jù)并未更新。隨后，隨機(jī)分析了幾個(gè) relay 日志，發(fā)現(xiàn)***個(gè)事務(wù)都未被執(zhí)行。而且操作的表都是有不同的，操作也是有不同，有 insert、update 等等，頓時(shí)感覺事情大條了。

如果每個(gè)日志的***個(gè)事務(wù)都未執(zhí)行，那么從庫要缺少多少條數(shù)據(jù)?不敢想象，現(xiàn)在業(yè)務(wù)還在上升期，不久業(yè)務(wù)量會(huì)是現(xiàn)在的幾倍，甚至更多，到那時(shí)就不是用戶投訴那么簡(jiǎn)單了。

又抓取了部分 relay 日志情況，***個(gè)事務(wù)也都未被執(zhí)行。我可以肯定了，是所有 relay 日志的***個(gè)事務(wù)都未被執(zhí)行。

這個(gè)問題也可以是由于分割 relay 日志的腳本造成的。一般強(qiáng)制刷新日志是用 flush 命令來操作的，flush 命令一般不會(huì)造成數(shù)據(jù)丟失，當(dāng)然像他們這樣頻繁的操作，我是不知道會(huì)不會(huì)造成 Bug，導(dǎo)致丟數(shù)據(jù)。

還有在 flush relay logs 的時(shí)候有沒有用到其他的什么操作呢?我決定抓一把數(shù)據(jù)庫中操作過的命令。

抓取命令，問題解決

想到就做，登上從庫主機(jī)、登入數(shù)據(jù)庫，開啟 general_log 日志。坐等 5 分鐘，打開日志，尋找每分鐘前幾秒的記錄。

哇!哇!哇!

你們猜我看到了什么? 我從未見過如此騷的操作!上圖，以表我的震驚。

 為什么要跳過事務(wù)?你用 stop slave 與 Start slave 來刷新 relay 日志，已經(jīng)刷新了我的三觀，那，有必要跳過事務(wù)?這就解釋得通了，為何 relay 日志***個(gè)事務(wù)全都丟失。

至此!問題已經(jīng)清晰，是由于開發(fā)設(shè)置的分割 relay 日志的腳本，使用了非常規(guī)命令及 sql_slave_skip_counter 跳過事務(wù)命令來分隔 relay-log 日志，導(dǎo)致事務(wù)大量丟失。

所以，創(chuàng)新是好事，但要打好基本功，別搞些騷操作。

[[197703]]

 洪凌

新炬網(wǎng)絡(luò)資深 MySQL 工程師

超過 7 年 MySQL 數(shù)據(jù)庫運(yùn)維經(jīng)驗(yàn)，擅長(zhǎng)數(shù)據(jù)庫運(yùn)維體系、集群架構(gòu)建設(shè)，熟悉 MySQL 性能優(yōu)化，對(duì)數(shù)據(jù)庫監(jiān)控系統(tǒng)也有著獨(dú)特的理解。