背景

在司機數(shù)據(jù)庫中，有一張用于存儲司機車型的表，暫且稱之為表t。該表結(jié)構(gòu)如下所示：

MySQL?

[comp_epower]> show create table t \G; *************************** 1. row *************************** Table:?

Create Table:?

CREATE TABLE `t` ( ?

`id` bigint(20) unsigned NOT NULL AUTO_INCREMENT COMMENT '主鍵', ?

`full_station_id` varchar(64) COLLATE utf8_bin NOT NULL DEFAULT '' COMMENT '司機唯一Id', ?

`platform` int(4) NOT NULL DEFAULT '-1' COMMENT '車型id', ?

`create_time` datetime NOT NULL DEFAULT '1970-01-01 00:00:00' COMMENT '創(chuàng)建時間', `update_time` datetime NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP COMMENT '時間', ?

PRIMARY KEY (`id`) USING BTREE, ?

KEY `idx_full_station_id` (`full_station_id`)?USING BTREE )?

ENGINE=InnoDB AUTO_INCREMENT=145612 DEFAULT CHARSET=utf8 COLLATE=utf8_bin COMMENT='樁站上線渠道'

這張表的業(yè)務(wù)場景：以full_station_id為'test'來舉例(full_station_id為的唯一Id)，如果在平板(車型號1)、小面(2)、金杯(3)，則在該表中會有如下三條記錄：

MySQL [comp_epower]> select * from t where full_station_id = 'test';?

發(fā)現(xiàn)問題

由于司機車型C端列表頁的檢索需求，DB中車型相關(guān)的信息需要同步到ES中，這其中就包括車型信息。由于歷史原因，“同步”這個動作發(fā)生在業(yè)務(wù)流程中，即在B端管理平臺上編輯司機車型信息時，后端服務(wù)器更新完DB需要檢索出車型完整信息發(fā)送到MQ，再清洗數(shù)據(jù)到ES。數(shù)據(jù)同步到ES中后，每條車型信息中都存在一個platform的List，存儲所有的渠道號用于C端檢索。

以上述full_station_id為'test'的車型為例，ES中就可能有如下的一條數(shù)據(jù)：

{ ? ?// ... 省略其他字段 ? ?"full_station_id": "test", ? ?

? "platform": [1, 2, 3] ? ?// ... 省略其他字段 }

近期偶然發(fā)現(xiàn)，ES中platform列表中存在重復(fù)的渠道號。即DB中的數(shù)據(jù)是[1, 2, 3]三條記錄，在es中變成了[1, 2, 3, 1, 2, 3]

定位問題

雖然初看起來好像并不影響檢索，但是作為一個具有技術(shù)潔癖的程序猿來講，錯誤一旦發(fā)現(xiàn)就必須解決。隨后在日志檢索平臺上搜索該站最近一次的變更記錄，成功定位到在16日該充車型在B端有編輯記錄，而且是連續(xù)兩次提交。查看源碼后發(fā)現(xiàn)，這個B端的更新流程被包裹在一個長事務(wù)中，在此次事務(wù)中有多次RPC請求。這里簡單介紹下編輯車型的流程：

開啟事務(wù)

• 做一些車型相關(guān)的其他DB操作

• 刪除該車型的全部已上線渠道記錄，再將B端上傳的渠道列表保存到庫中

• 一堆RPC操作

• 從DB檢索車型的已上線渠道記錄，再結(jié)合其他一些車型的信息組成寬表發(fā)送給ES

• 提交事務(wù)

前面提到這次異常更新有兩次連續(xù)的長事務(wù)，因此在機器上通過trace檢索到全部日志，根據(jù)不同事件發(fā)生的時間點，還原兩次編輯發(fā)生的完整歷程。因為問題主要是渠道重復(fù)，因此主要將目光集中在渠道相關(guān)的幾次操作，時間線如下：

通過日志還看出，在這兩次事務(wù)開始之前，庫中full_station_id為'test'的車型已經(jīng)有[1, 2, 3]三條渠道記錄。

那么開始在本地的mysql服務(wù)器上還原兩次事務(wù)流程(本地mysql版本5.7.31-log，隔離級別可重復(fù)讀)：

(1)建表、初始化數(shù)據(jù)

(2)開始按照上述兩個事務(wù)的執(zhí)行過程，還原現(xiàn)場

如上圖所示。但是奇怪，上圖中第9步按照當(dāng)時事發(fā)現(xiàn)場日志來看應(yīng)該是查詢出來6條記錄才對！

看到這里的小伙伴可以停下來想想上面的還原步驟哪里出了差錯(在編輯車型流程里有線索)

回過頭來仔細看了下編輯車型的流程以及日志的輸出時間線，發(fā)現(xiàn)在對渠道進行DB操作之前，還進行了其他一些DB操作，而且在事務(wù)一提交之前，事務(wù)二已經(jīng)完成了部分DB操作?；叵氲絠nnodb事務(wù)開啟的時機，我在本地還原的時候，右邊事務(wù)二其實是在7這個位置才開啟的(innodb事務(wù)不是在begin處開啟，而是在第一次真正的db操作時開啟)，也就是左邊事務(wù)一在時刻6提交之后開啟的。而實際上因為該長事務(wù)在渠道相關(guān)DB操作之前，已經(jīng)做了其他的DB操作，所以這里梳理的流程圖缺少了及其重要的一步：在事務(wù)一commit之前，將事務(wù)二開啟起來。

重新梳理流程圖

流程圖V2中，事務(wù)二在t2時刻使用begin語句聲明事務(wù)的開始，并在t3時刻事務(wù)一提交之前，完成了一次查詢(隨便什么)，開啟了事務(wù)。那么此時事務(wù)二就是在事務(wù)一未提交之前開啟的。

再次在本地mysql上按照時間線還原現(xiàn)場

可以看到第9步檢索出了6條數(shù)據(jù)，成功還原！

真相只有一個

簡單介紹下MVCC的原理

每個事務(wù)開啟時，都會被分配到一個全局唯一且遞增的事務(wù)id，即trx_id，當(dāng)每次事務(wù)對某些數(shù)據(jù)行進行修改時，都會將事務(wù)自身的trx_id記錄在數(shù)據(jù)行的隱藏列上。在事務(wù)開啟的那一刻，MVCC機制會為事務(wù)生成一個當(dāng)前mysql服務(wù)器上所有事務(wù)的快照。這個快照是按照如下方式實現(xiàn)的：

• 將當(dāng)前服務(wù)端活躍的全部事務(wù)id記錄在set中

• 當(dāng)前活躍的事務(wù)最小id記為min_trx_id

• 當(dāng)前活躍的事務(wù)最大id記為max_trx_id

• 當(dāng)進行一次普通查詢的時候，根據(jù)數(shù)據(jù)行上的trx_id進行判斷。

  trx_id < min_trx_id，該行是在當(dāng)前事務(wù)開啟前就提交的，對當(dāng)前事務(wù)可見。

  trx_id > max_trx_id，該行是在當(dāng)前事務(wù)開啟后開啟的，對當(dāng)前事務(wù)不可以。

  (但是trx_id > max_trx_id，并且max_trx_id比trx_id先提交，也是對當(dāng)前事務(wù)可見的。事務(wù)對數(shù)據(jù)做修改時會發(fā)起一致性讀，即強制讀取最新的記錄)

• min_trx_id <= trx_id <= max_trx_id，該行處在最大最小事務(wù)id中間，則判斷是否為set中的活躍事務(wù)的修改。若是，則不可見；若不是，則說明當(dāng)前事務(wù)開啟時已經(jīng)提交，則可見。

如何理解？

那既然 trx_id 這行數(shù)據(jù)，在快照最大最小事物中間了。那就肯定是最大最小中間的事物去修改的吧。會存在【若不是】的情況嗎

就是在最大最小中間的某個事物，可能在拍照的時候，就已經(jīng)提交了。這種就可以理解為在最小之前開啟的，所以可見。

換個角度看，其實就是看這行數(shù)據(jù)是在拍照之前提交的，就可見。拍照之后(還未提交、就還在set中)就不可見(對前兩條的補充)

對于隔離級別為可重復(fù)讀而言，這個快照是在事務(wù)開啟時生成的；對于讀已提交，是在每次進行快照讀的時刻生成的。

為行文方便，再次將上述流程梳理如下：

• 【1】[事務(wù)一]：begin;

• 【2】[事務(wù)一]：delete from t where full_station_id = 'test';

• 【3】[事務(wù)一]：insert into t(full_station_id, platform) values('test', 1), ('test', 2), ('test', 3);

• 【4】[事務(wù)一]：select * from t where full_station_id = 'test'

• 【5】[事務(wù)二]：begin;

• 【6】[事務(wù)二]：select * from t where full_station_id = 'test'

• 【7】[事務(wù)一]：commit;

• 【8】[事務(wù)二]：delete from t where full_station_id = 'test';

• 【9】[事務(wù)二]：insert into t(full_station_id, platform) values('test', 1), ('test', 2), ('test', 3);

• 【10】[事務(wù)二]：select * from t where full_station_id = 'test'

• 【11】[事務(wù)二]：commit

【1】首先，在兩次事務(wù)開始之前，表里fullStationId為'test'的渠道記錄有三條，如下所示：(這里的trx_id用來記錄最后一次更新該列的事務(wù)Id，delete_mask用作刪除標(biāo)記，這兩列都是innodb數(shù)據(jù)行上的隱藏列)

【2】事務(wù)一開啟，此時事務(wù)一的活躍事務(wù)集合為【2】，即只有自身。進行刪除操作，此時針對【1】中的三條數(shù)據(jù)會做如下幾條操作：(省略無關(guān)操作)

• 將delete_mask設(shè)置為1(標(biāo)記刪除)

• 將trx_id設(shè)置為2

• 生成undo log，內(nèi)容為將delete_mask改回0，trx_id改回1

此時這三條記錄狀態(tài)如下圖所示：

這里的示意圖可能與實際情況有所偏差，具體實現(xiàn)情況查看mysql相關(guān)文檔。

【3】事務(wù)一插入三條記錄。(注意后續(xù)示意圖中沒有畫insert相關(guān)的undolog，只要清楚新insert數(shù)據(jù)的undo就是該行數(shù)據(jù)不存在即可)

【4】事務(wù)一查詢fullStationId為'test'的記錄，將六條數(shù)據(jù)分為上下兩組，流程如下：

• 上面三條數(shù)據(jù)trx_id為2，為自身刪除，因此不可見。

• 下面三條數(shù)據(jù)trx_id為2，為自身插入，可見。放入結(jié)果集中返回。

因此本次查詢看到的是下面三條記錄。

【5】事務(wù)二聲明begin;

【6】事務(wù)二做了一次select操作，此時事務(wù)二真正開啟，MVCC機制開始工作，因為事務(wù)一此刻還沒提交，所以事務(wù)一的修改對事務(wù)二是不可見的。

假設(shè)事務(wù)二的trx_id為3，則在事務(wù)二開啟一刻生成的活躍事務(wù)集合為【2,3】

那么事務(wù)二在進行普通的select查詢時，實際上是做了一次快照讀。將表里當(dāng)前存在的數(shù)據(jù)分為兩組，上面三條和下面三條。

• 上面三條的trx_id為2，在活躍事務(wù)集合里，不可見。沿著undo鏈表往前回溯到上一個trx_id為1的版本。trx_id=1

• 下面三條的trx_id為2，在活躍事務(wù)集合里，不可見。回溯undolog，發(fā)現(xiàn)是insert類型undolog，停止回溯，結(jié)束查詢。

所以此時事務(wù)二進行快照讀，只讀到了上面三條記錄。

【7】事務(wù)一提交

【8】事務(wù)二執(zhí)行delete操作。此時刪除的是上面三條，還是下面三條？

答案是下面三條，原因是一致性讀。對于delete而言，首先肯定要在表里檢索到符合條件的記錄，那么在可重復(fù)讀級別下，事務(wù)對數(shù)據(jù)做修改時會發(fā)起一致性讀，即強制讀取最新的記錄，不管MVCC。所以該次操作實際上刪除的是事務(wù)一插入的三條記錄，流程與步驟【2】相仿，之后數(shù)據(jù)表狀態(tài)如下圖所示：(一致性讀時對于上面三條記錄而言，已經(jīng)是被已提交事務(wù)刪除了，因此事務(wù)二本次delete操作不對它們做操作)

【9】事務(wù)二插入三條記錄，之后數(shù)據(jù)表狀態(tài)如下：

【10】事務(wù)二進行一次快照讀，此時MVCC機制產(chǎn)生作用。將九條數(shù)據(jù)分為上中下三組，則流程如下：

• 上面三組trx_id為2，在活躍事務(wù)集合中，因此不可見。沿著undo鏈表回溯到trx_id為1的記錄，可見，放入結(jié)果集。

問：trx_id為2，在活躍事務(wù)集合中？如何判斷是否在活躍事物中？

答：事物二開啟的時候，快照了set

• 中間三組trx_id為3，是當(dāng)前事務(wù)的trx_id。因為delete_mask為1，表明當(dāng)前事務(wù)做了刪除，不可見。

• 下面三組trx_id為3，是當(dāng)前事務(wù)的trx_id，因此可見，放入結(jié)果集。

所以本次快照讀結(jié)果為6條，分別為事務(wù)一和二開啟前的三條數(shù)據(jù)，加上事務(wù)二插入的三條數(shù)據(jù)。

【11】事務(wù)二提交。

后記

分析流程到這里就結(jié)束了，感謝在排查問題過程中跟我一起討論問題的同學(xué)們，能遇到這種mysql實踐的場景也不多，所以也感謝寫出這個長事務(wù)的朋友:)。其實對于這個case每步操作的加鎖情況也值得深入分析，包括實際上undolog是使用數(shù)據(jù)行上的roll_pointer指針來引用的等等這些原理，礙于篇幅都沒有過多提及。

最終我也是在代碼中將最后一個對于渠道的select查詢加上了for update語句，強制進行一致性讀，暫時可以解決這個問題(對于去除長事務(wù)是一個稍微大點的改造，暫時沒有做)。不知道各位小伙伴有沒有更好的辦法，歡迎在評論區(qū)留言，文章中的錯誤提前感謝各位指正。

其他：長事物拆分、異步

總結(jié)

以上是生活随笔為你收集整理的mysql id还原_一次线上DB问题排查(MySQL、事务、MVCC)的全部內(nèi)容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網(wǎng)站內(nèi)容還不錯，歡迎將生活随笔推薦給好友。