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异常的排查过程”的内容就介绍到这里了,感谢大家的阅读。如果想了解更多行业相关的知识可以关注创新互联网站,小编将为大家输出更多高质量的实用文章!


网页题目:Mysql事务死锁触发Rollback异常的排查过程
网页地址:http://pwwzsj.com/article/jijoed.html