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 readmysql tables in use 1, locked 1LOCK WAIT 42 lock struct(s), heap size 6544, 3 row lock(s), undo log entries 1MySQL thread id 79774, OS thread handle 0x7f3c93c5c700, query id 57613264 172.*.*.10 pop_mq Searching rows for updateupdate 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 waitingRecord 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 readmysql tables in use 1, locked 14 lock struct(s), heap size 1184, 2 row lock(s), undo log entries 1MySQL thread id 79171, OS thread handle 0x7f3c0eba1700, query id 57613277 172.*.*.10 pop_seller updatingupdate 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 gapRecord 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 waitingRecord 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异常的排查过程"的内容就介绍到这里了，感谢大家的阅读。如果想了解更多行业相关的知识可以关注网站，小编将为大家输出更多高质量的实用文章！