背景

在司機數據庫中，有一張用于存儲司機車型的表，暫且稱之為表t。該表結構如下所示：

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 '創建時間', `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='樁站上線渠道'

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

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

發現問題

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

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

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

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

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

定位問題

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

開啟事務

• 做一些車型相關的其他DB操作

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

• 一堆RPC操作

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

• 提交事務

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

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

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

(1)建表、初始化數據

(2)開始按照上述兩個事務的執行過程，還原現場

如上圖所示。但是奇怪，上圖中第9步按照當時事發現場日志來看應該是查詢出來6條記錄才對！

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

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

重新梳理流程圖

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

再次在本地mysql上按照時間線還原現場

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

真相只有一個

簡單介紹下MVCC的原理

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

• 將當前服務端活躍的全部事務id記錄在set中

• 當前活躍的事務最小id記為min_trx_id

• 當前活躍的事務最大id記為max_trx_id

• 當進行一次普通查詢的時候，根據數據行上的trx_id進行判斷。

  trx_id < min_trx_id，該行是在當前事務開啟前就提交的，對當前事務可見。

  trx_id > max_trx_id，該行是在當前事務開啟后開啟的，對當前事務不可以。

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

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

如何理解？

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

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

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

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

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

• 【1】[事務一]：begin;

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

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

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

• 【5】[事務二]：begin;

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

• 【7】[事務一]：commit;

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

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

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

• 【11】[事務二]：commit

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

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

• 將delete_mask設置為1(標記刪除)

• 將trx_id設置為2

• 生成undo log，內容為將delete_mask改回0，trx_id改回1

此時這三條記錄狀態如下圖所示：

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

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

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

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

• 下面三條數據trx_id為2，為自身插入，可見。放入結果集中返回。

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

【5】事務二聲明begin;

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

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

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

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

• 下面三條的trx_id為2，在活躍事務集合里，不可見?；厮輚ndolog，發現是insert類型undolog，停止回溯，結束查詢。

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

【7】事務一提交

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

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

【9】事務二插入三條記錄，之后數據表狀態如下：

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

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

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

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

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

• 下面三組trx_id為3，是當前事務的trx_id，因此可見，放入結果集。

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

【11】事務二提交。

后記

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

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

其他：長事物拆分、異步

總結

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

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。