Mysql事務死鎖觸發Rollback異常的排查過程

本篇內容介紹了“Mysql事務死鎖觸發Rollback異常的排查過程”的有關知識，在實際案例的操作過程中，不少人都會遇到這樣的困境，接下來就讓小編帶領大家學習一下如何處理這些情況吧！希望大家仔細閱讀，能夠學有所成！

整個事件起源于一個Error，日志如下：

2019-10-31 12:55:53,953 ERROR [http-apr-8080-exec-5] com.jollycorp.pop.web.PopExceptionResolver.doResolveException(PopExceptionResolver.java:73) unresolved exception!
### Error updating database.  Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
### The error may involve com.jollycorp.pop.entity.pop.goods.PopGoodsMapper.updateByPrimaryKeySelective-Inline
### The error occurred while setting parameters
### SQL: update pop_goods SET ... where goods_id = ?
...
### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
; Deadlock found when trying to get lock; try restarting transaction; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
...

日志說的很明白，更新某行數據時發現死鎖，并拋了個MySQLTransactionRollbackException異常。

那么問題來了，為什么死鎖了？

Mysql InnoDB 提供了死鎖檢測機制，通過Wait-For-Graph算法實現。簡單講就是將事務及它等待的鎖維護成一個有向圖，然后進行環檢測，如果發現有環則表示發生了死鎖，InnoDB需要回滾掉一個事務以打破環，因此拋出了上面的異常。

所以，對于日志上的update，肯定有另一個事務和這個update所在的事務有相互的鎖等待。為了找到另外一個事務，可以在數據庫執行show engine innodb status查詢最近的一次死鎖情況，日志如下：

LATEST DETECTED DEADLOCK
------------------------
2019-10-29 16:15:09 7f3c0eba1700
*** (1) TRANSACTION:
TRANSACTION 872050326, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 42 lock struct(s), heap size 6544, 3 row lock(s), undo log entries 1
MySQL thread id 79774, OS thread handle 0x7f3c93c5c700, query id 57613264 172.*.*.10 pop_mq Searching rows for update
update pop_sku_relation set status = 0 where goods_rec_id ...
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 5155 page no 23 n bits 144 index `PRIMARY` of table `jolly_pop_center`.`pop_sku_relation` trx id 872050326 lock_mode X locks rec but not gap waiting
Record lock, heap no 38 PHYSICAL RECORD: n_fields 41; compact format; info bits 0
 0: len 4; hex 0000070d; asc     ;;
 ...
 40: len 1; hex 81; asc  ;;

*** (2) TRANSACTION:
TRANSACTION 872050288, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1184, 2 row lock(s), undo log entries 1
MySQL thread id 79171, OS thread handle 0x7f3c0eba1700, query id 57613277 172.*.*.10 pop_seller updating
update pop_goods ... where goods_id = 1253
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 5155 page no 23 n bits 144 index `PRIMARY` of table `jolly_pop_center`.`pop_sku_relation` trx id 872050288 lock_mode X locks rec but not gap
Record lock, heap no 38 PHYSICAL RECORD: n_fields 41; compact format; info bits 0
 0: len 4; hex 0000070d; asc     ;;
 ...
 40: len 1; hex 81; asc  ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 11311 page no 66 n bits 96 index `PRIMARY` of table `jolly_pop_center`.`pop_goods` trx id 872050288 lock_mode X locks rec but not gap waiting
Record lock, heap no 23 PHYSICAL RECORD: n_fields 92; compact format; info bits 0
 0: len 3; hex 0004e5; asc    ;;
 ...
 91: len 1; hex 80; asc  ;;

*** WE ROLL BACK TRANSACTION (2)

可以看到，事務1(xid 872050326)等待pop_sku_relation的一個X鎖:

RECORD LOCKS space id 5155 page no 23 n bits 144 index PRIMARY of table jolly_pop_center.pop_sku_relation trx id 872050326 lock_mode X locks rec but not gap waiting Record lock

事務2(xid 872050288)持有pop_sku_relation的一個X鎖（注意是一行記錄）:

RECORD LOCKS space id 5155 page no 23 n bits 144 index PRIMARY of table jolly_pop_center.pop_sku_relation trx id 872050288 lock_mode X locks rec but not gap Record lock

然后事務2(xid 872050288)還等待pop_goods的一個X鎖：

RECORD LOCKS space id 11311 page no 66 n bits 96 index PRIMARY of table jolly_pop_center.pop_goods trx id 872050288 lock_mode X locks rec but not gap waiting Record lock

然后事務2(xid 872050288)被回滾了：

*** WE ROLL BACK TRANSACTION (2)

這里可以讓DBA幫忙撈事務1(xid 872050326)的binlog， 因為事務2回滾后，死鎖解除，事務1執行成功則會記錄binlog日志。應該能發現事務1也對pop_goods的同一行進行了操作。

最后跟蹤代碼，果然發現有一個事務首先更新了pop_goods，然后再更新pop_sku_relation。另一個事務中先更新了pop_sku_relation,然后更新pop_goods。在并發的情況下就會發生上面日志的情況：

1. 事務1對pop_goods中id=1253的記錄上X鎖

2. 事務2對pop_sku_relation中id=14616485的記錄上X鎖

3. 事務1申請pop_sku_realtion中id=14616485的記錄的X鎖，因為事務2已經鎖了所以等待

4. 事務2申請pop_goods中id=1253的記錄的X鎖，因為事務1已經鎖了所以等待

5. 發現事務1和事務2相互等待，回滾事務2

最后修改代碼，使update順序保持一致。 本例中是對不同表的修改不一致，其實對同一張表不同記錄如果兩個事務亂序，也會產生死鎖現象。因此如果有多記錄更新的時候，不同表需要固定一個更新順序，同一張表的不同記錄需要進行排序再更新，從而避免死鎖的發生。

“Mysql事務死鎖觸發Rollback異常的排查過程”的內容就介紹到這里了，感謝大家的閱讀。如果想了解更多行業相關的知識可以關注億速云網站，小編將為大家輸出更多高質量的實用文章！