一次诡异的数据库死锁问题排查过程
GitHub 1.8k Star 的Java工程師成神之路 ,不來了解一下嗎?
GitHub 1.8k Star 的Java工程師成神之路 ,真的不來了解一下嗎?
GitHub 1.8k Star 的Java工程師成神之路 ,真的確定不來了解一下嗎?
現象
某天晚上,同事正在發布,突然線上大量報警,很多是關于數據庫死鎖的,報警提示信息如下:
{"errorCode":"SYSTEM_ERROR","errorMsg":"nested exception is org.apache.ibatis.exceptions.PersistenceException: Error updating database. Cause: ERR-CODE: [TDDL-4614][ERR_EXECUTE_ON_MYSQL] Deadlock found when trying to get lock; The error occurred while setting parameters\n### SQL: update fund_transfer_stream set gmt_modified=now(),state = ? where fund_transfer_order_no = ? and seller_id = ? and state = 'NEW'通過報警,我們基本可以定位到發生死鎖的數據庫以及數據庫表。先來介紹下本文案例中涉及到的數據庫相關信息。
背景情況
我們使用的數據庫是Mysql 5.7,引擎是InnoDB,事務隔離級別是READ-COMMITED。
數據庫版本查詢方法:
SELECT version();引擎查詢方法:
show create table fund_transfer_stream;建表語句中會顯示存儲引擎信息,形如:ENGINE=InnoDB
事務隔離級別查詢方法:
select @@tx_isolation;事務隔離級別設置方法(只對當前Session生效):
set session transaction isolation level read committed;PS:注意,如果數據庫是分庫的,以上幾條SQL語句需要在單庫上執行,不要在邏輯庫執行。
發生死鎖的表結構及索引情況(隱去了部分無關字段和索引):
CREATE TABLE `fund_transfer_stream` ( `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT COMMENT '主鍵',`gmt_create` datetime NOT NULL COMMENT '創建時間',`gmt_modified` datetime NOT NULL COMMENT '修改時間', `pay_scene_name` varchar(256) NOT NULL COMMENT '支付場景名稱', `pay_scene_version` varchar(256) DEFAULT NULL COMMENT '支付場景版本',`identifier` varchar(256) NOT NULL COMMENT '唯一性標識',`seller_id` varchar(64) NOT NULL COMMENT '賣家Id',`state` varchar(64) DEFAULT NULL COMMENT '狀態', `fund_transfer_order_no` varchar(256) DEFAULT NULL COMMENT '資金平臺返回的狀態', PRIMARY KEY (`id`),UNIQUE KEY `uk_scene_identifier` (KEY `idx_seller` (`seller_id`),KEY `idx_seller_transNo` (`seller_id`,`fund_transfer_order_no`(20))) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COMMENT='資金流水';該數據庫共有三個索引,1個聚簇索引(主鍵索引),2個非聚簇索(非主鍵索引)引。
聚簇索引:
PRIMARY KEY (`id`)非聚簇索引:
KEY `idx_seller` (`seller_id`),KEY `idx_seller_transNo` (`seller_id`,`fund_transfer_order_no`(20))以上兩個索引,其實idx_seller_transNo已經覆蓋到了idx_seller,由于歷史原因,因為該表以seller_id分表,所以是先有的idx_seller,后有的idx_seller_transNo
死鎖日志
當數據庫發生死鎖時,可以通過以下命令獲取死鎖日志:
show engine innodb status發生死鎖,第一時間查看死鎖日志,得到死鎖日志內容如下:
Transactions deadlock detected, dumping detailed information. 2019-03-19T21:44:23.516263+08:00 5877341 [Note] InnoDB: *** (1) TRANSACTION: TRANSACTION 173268495, ACTIVE 0 sec fetching rows mysql tables in use 1, locked 1 LOCK WAIT 304 lock struct(s), heap size 41168, 6 row lock(s), undo log entries 1 MySQL thread id 5877358, OS thread handle 47356539049728, query id 557970181 11.183.244.150 fin_instant_app updatingupdate `fund_transfer_stream` set `gmt_modified` = NOW(), `state` = 'PROCESSING' where ((`state` = 'NEW') AND (`seller_id` = '38921111') AND (`fund_transfer_order_no` = '99010015000805619031958363857')) 2019-03-19T21:44:23.516321+08:00 5877341 [Note] InnoDB: *** (1) HOLDS THE LOCK(S): RECORD LOCKS space id 173 page no 13726 n bits 248 index idx_seller_transNo of table `xxx`.`fund_transfer_stream` trx id 173268495 lock_mode X locks rec but not gap Record lock, heap no 168 PHYSICAL RECORD: n_fields 3; compact format; info bits 02019-03-19T21:44:23.516565+08:00 5877341 [Note] InnoDB: *** (1) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 173 page no 12416 n bits 128 index PRIMARY of table `xxx`.`fund_transfer_stream` trx id 173268495 lock_mode X locks rec but not gap waiting Record lock, heap no 56 PHYSICAL RECORD: n_fields 17; compact format; info bits 0 2019-03-19T21:44:23.517793+08:00 5877341 [Note] InnoDB: *** (2) TRANSACTION: TRANSACTION 173268500, ACTIVE 0 sec fetching rows, thread declared inside InnoDB 81 mysql tables in use 1, locked 1 302 lock struct(s), heap size 41168, 2 row lock(s), undo log entries 1 MySQL thread id 5877341, OS thread handle 47362313119488, query id 557970189 11.131.81.107 fin_instant_app updatingupdate `fund_transfer_stream_0056` set `gmt_modified` = NOW(), `state` = 'PROCESSING' where ((`state` = 'NEW') AND (`seller_id` = '38921111') AND (`fund_transfer_order_no` = '99010015000805619031957477256')) 2019-03-19T21:44:23.517855+08:00 5877341 [Note] InnoDB: *** (2) HOLDS THE LOCK(S): RECORD LOCKS space id 173 page no 12416 n bits 128 index PRIMARY of table `fin_instant_0003`.`fund_transfer_stream_0056` trx id 173268500 lock_mode X locks rec but not gap Record lock, heap no 56 PHYSICAL RECORD: n_fields 17; compact format; info bits 02019-03-19T21:44:23.519053+08:00 5877341 [Note] InnoDB: *** (2) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 173 page no 13726 n bits 248 index idx_seller_transNo of table `fin_instant_0003`.`fund_transfer_stream_0056` trx id 173268500 lock_mode X locks rec but not gap waiting Record lock, heap no 168 PHYSICAL RECORD: n_fields 3; compact format; info bits 02019-03-19T21:44:23.519297+08:00 5877341 [Note] InnoDB: *** WE ROLL BACK TRANSACTION (2)簡單解讀一下死鎖日志,可以得到以下信息:
1、導致死鎖的兩條SQL語句分別是:
update `fund_transfer_stream_0056` set `gmt_modified` = NOW(), `state` = 'PROCESSING' where ((`state` = 'NEW') AND (`seller_id` = '38921111') AND (`fund_transfer_order_no` = '99010015000805619031957477256'))和
update `fund_transfer_stream_0056` set `gmt_modified` = NOW(), `state` = 'PROCESSING' where ((`state` = 'NEW') AND (`seller_id` = '38921111') AND (`fund_transfer_order_no` = '99010015000805619031958363857'))2、事務1,持有索引idx_seller_transNo的鎖,在等待獲取PRIMARY的鎖。
3、事務2,持有PRIMARY的鎖,在等待獲取idx_seller_transNo的鎖。
4、因事務1和事務2之間發生循環等待,故發生死鎖。
5、事務1和事務2當前持有的鎖均為:lock_mode X locks rec but not gap
兩個事務對記錄加的都是X 鎖,No Gap鎖,即對當行記錄加鎖,并為加間隙鎖。
X鎖:排他鎖、又稱寫鎖。若事務T對數據對象A加上X鎖,事務T可以讀A也可以修改A,其他事務不能再對A加任何鎖,直到T釋放A上的鎖。這保證了其他事務在T釋放A上的鎖之前不能再讀取和修改A。
與之對應的是S鎖:共享鎖,又稱讀鎖,若事務T對數據對象A加上S鎖,則事務T可以讀A但不能修改A,其他事務只能再對A加S鎖,而不能加X鎖,直到T釋放A上的S鎖。這保證了其他事務可以讀A,但在T釋放A上的S鎖之前不能對A做任何修改。
Gap Lock:間隙鎖,鎖定一個范圍,但不包括記錄本身。GAP鎖的目的,是為了防止同一事務的兩次當前讀,出現幻讀的情況。
Next-Key Lock:1+2,鎖定一個范圍,并且鎖定記錄本身。對于行的查詢,都是采用該方法,主要目的是解決幻讀的問題。
詳見:https://www.cnblogs.com/zhoujinyi/p/3435982.html 、 https://dev.mysql.com/doc/refman/5.7/en/innodb-transaction-isolation-levels.html
問題排查
根據我們目前已知的數據庫相關信息,以及死鎖的日志,我們基本可以做一些簡單的判定。
首先,此次死鎖一定是和Gap鎖以及Next-Key Lock沒有關系的。因為我們的數據庫隔離級別是RC(READ-COMMITED)的,這種隔離級別是不會添加Gap鎖的。前面的死鎖日志也提到這一點。
然后,就要翻代碼了,看看我們的代碼中事務到底是怎么做的。核心代碼及SQL如下:
@Transactional(rollbackFor = Exception.class) public int doProcessing(String sellerId, Long id, String fundTransferOrderNo) {fundTreansferStreamDAO.updateFundStreamId(sellerId, id, fundTransferOrderNo);return fundTreansferStreamDAO.updateStatus(sellerId, fundTransferOrderNo, FundTransferStreamState.PROCESSING.name()); }該代碼的目的是先后修改同一條記錄的兩個不同字段,updateFundStreamId SQL:
update fund_transfer_streamset gmt_modified=now(),fund_transfer_order_no = #{fundTransferOrderNo}where id = #{id} and seller_id = #{sellerId}updateStatus SQL:
update fund_transfer_streamset gmt_modified=now(),state = #{state}where fund_transfer_order_no = #{fundTransferOrderNo} and seller_id = #{sellerId}and state = 'NEW'可以看到,我們的同一個事務中執行了兩條Update語句,這里分別查看下兩條SQL的執行計劃:

updateFundStreamId執行的時候使用到的是PRIMARY索引。

updateStatus執行的時候使用到的是idx_seller_transNo索引。
通過執行計劃,我們發現updateStatus其實是有兩個索引可以用的,執行的時候真正使用的是idx_seller_transNo索引。這是因為MySQL查詢優化器是基于代價(cost-based)的查詢方式。因此,在查詢過程中,最重要的一部分是根據查詢的SQL語句,依據多種索引,計算查詢需要的代價,從而選擇最優的索引方式生成查詢計劃。
我們查詢執行計劃是在死鎖發生之后做的,事后查詢的執行計劃和發繩死鎖那一刻的索引使用情況并不一定相同的。但是,我們結合死鎖日志,也可以定位到以上兩條SQL語句執行的時候使用到的索引。即updateFundStreamId執行的時候使用到的是PRIMARY索引,updateStatus執行的時候使用到的是idx_seller_transNo索引。
有了以上這些已知信息,我們就可以開始排查死鎖原因及其背后的原理了。通過分析死鎖日志,再結合我們的代碼以及數據庫建表語句,我們發現主要問題出在我們的idx_seller_transNo索引上面:
KEY `idx_seller_transNo` (`seller_id`,`fund_transfer_order_no`(20))索引創建語句中,我們使用了前綴索引,為了節約索引空間,提高索引效率,我們只選擇了fund_transfer_order_no字段的前20位作為索引值。
因為fund_transfer_order_no只是普通索引,而非唯一性索引。又因為在一種特殊情況下,會有同一個用戶的兩個fund_transfer_order_no的前20位相同,這就導致兩條不同的記錄的索引值一樣(因為seller_id 和fund_transfer_order_no(20)都相同 )。
就如本文中的例子,發生死鎖的兩條記錄的fund_transfer_order_no字段的值:99010015000805619031958363857和99010015000805619031957477256這兩個就是前20位相同的。

那么為什么fund_transfer_order_no的前20位相同會導致死鎖呢?
加鎖原理
我們就拿本次的案例來看一下MySql數據庫加鎖的原理是怎樣的,本文的死鎖背后又發生了什么。
我們在數據庫上模擬死鎖場景,執行順序如下:
| begin | ||
| update fund_transfer_stream set gmt_modified=now(),fund_transfer_order_no = '99010015000805619031958363857' where id = 1 and seller_id = 3111095611; | 執行成功 | |
| begin | ||
| update fund_transfer_stream set gmt_modified=now(),fund_transfer_order_no = '99010015000805619031957477256' where id = 2 and seller_id = 3111095611; | 執行成功 | |
| update fund_transfer_stream set gmt_modified = NOW(), state = 'PROCESSING' where ((state = 'NEW') AND (seller_id = '3111095611') AND (fund_transfer_order_no = '99010015000805619031958363857')); | 阻塞 | |
| update fund_transfer_stream set gmt_modified = NOW(), state = 'PROCESSING' where ((state = 'NEW') AND (seller_id = '3111095611') AND (fund_transfer_order_no = '99010015000805619031958363857')); | 死鎖 |
我們知道,在MySQL中,行級鎖并不是直接鎖記錄,而是鎖索引。索引分為主鍵索引和非主鍵索引兩種,如果一條sql語句操作了主鍵索引,MySQL就會鎖定這條主鍵索引;如果一條語句操作了非主鍵索引,MySQL會先鎖定該非主鍵索引,再鎖定相關的主鍵索引。
主鍵索引的葉子節點存的是整行數據。在InnoDB中,主鍵索引也被稱為聚簇索引(clustered index)
非主鍵索引的葉子節點的內容是主鍵的值,在InnoDB中,非主鍵索引也被稱為非聚簇索引(secondary index)
所以,本文的示例中涉及到的索引結構(索引是B+樹,簡化成表格了)如圖:

死鎖的發生與否,并不在于事務中有多少條SQL語句,死鎖的關鍵在于:兩個(或以上)的Session加鎖的順序不一致。那么接下來就看下上面的例子中兩個事務的加鎖順序是怎樣的:

下圖是分解圖,每一條SQL執行的時候加鎖情況:

結合以上兩張圖,我們發現了導致死鎖的原因: 事務1執行update1占用PRIMARY = 1的鎖 ——> 事務2執行update1 占有PRIMARY = 2的鎖; 事務1執行update2占有idx_seller_transNo = (3111095611,99010015000805619031)的鎖,嘗試占有PRIMARY = 2鎖失敗(阻塞); 事務2執行update2嘗試占有idx_seller_transNo = (3111095611,99010015000805619031)的鎖失敗(死鎖);
事務在以非主鍵索引為where條件進行Update的時候,會先對該非主鍵索引加鎖,然后再查詢該非主鍵索引對應的主鍵索引都有哪些,再對這些主鍵索引進行加鎖。)
解決方法
至此,我們分析清楚了導致死鎖的根本原理以及其背后的原理。那么這個問題解決起來就不難了。
可以從兩方面入手,分別是修改索引和修改代碼(包含SQL語句)。
修改索引:只要我們把前綴索引 idx_seller_transNo中fund_transfer_order_no的前綴長度修改下就可以了。比如改成50。即可避免死鎖。
但是,改了idx_seller_transNo的前綴長度后,可以解決死鎖的前提條件是update語句真正執行的時候,會用到fund_transfer_order_no索引。如果MySQL查詢優化器在代價分析之后,決定使用索引 KEY idx_seller(seller_id),那么還是會存在死鎖問題。原理和本文類似。
所以,根本解決辦法就是改代碼:
* 所有update都通過主鍵ID進行。 * 在同一個事務中,避免出現多條update語句修改同一條記錄。總結與思考
在死鎖發生之后的一周內,我幾乎每天都會抽空研究一會,問題早早的就定位到了,修改方案也有了,但是其中原理一直沒搞清楚。
前前后后做過很多中種推斷及假設,又都被自己一次次推翻。最終還是要靠實踐來驗證自己的想法。于是我自己在本地安裝了數據庫,實戰的做了些測試,并實時查看數據庫鎖情況。show engine innodb status ;可以查看鎖情況。最終才搞清楚原理。
簡單說幾點思考:
1、遇到問題,不要猜!!!親手復現下問題,然后再來分析。
2、不要忽略上下文!!!我剛開始就是只關注死鎖日志,一直忽略了代碼中的事務其實還執行了另外一條SQL語句(updateFundStreamId)。
3、理論知識再充足,關鍵時刻不一定想的起來!!!
4、坑都是自己埋的!!!
參考資料: MySQL 加鎖處理分析
innodb 事務隔離級別
《MySql實戰45講》
MySQL中的行級鎖,表級鎖,頁級鎖
總結
以上是生活随笔為你收集整理的一次诡异的数据库死锁问题排查过程的全部內容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: 在不知道根节点的情况下生成树形结构 (采
- 下一篇: 给Ubuntu添加清华的软件源