JAVA知识体系之问题处理篇（一）——记一次神奇的mysql死锁排查过程

最新推荐文章于 2024-07-20 13:00:00 发布
最新推荐文章于 2024-07-20 13:00:00 发布
阅读量477 收藏 4
点赞数 5
分类专栏： 生产问题实战篇 文章标签： mysql java 数据库
版权声明：本文为博主原创文章，遵循 CC 4.0 BY-SA 版权协议，转载请附上原文出处链接和本声明。
本文链接：https://blog.csdn.net/qsmiley10/article/details/120418939
版权

1、问题

  由于公司业务和技术性需求，新上线一个独立支付系统，其中部分退款功能在进行并发测试时出现偶发性mysql死锁：

[2021-09-22 15:46:18,760][c.b.a.s.i.ReverseServiceImpl][thread0][ERROR][816fbe90-a4fa-4dea-b52c-719f1f2a8c37][]call [ReverseServiceImpl][refund] EXCEPTION:Cause[org.springframework.dao.DeadlockLoserDataAccessException: 
### Error updating database.  Cause: com.mysql.cj.jdbc.exceptions.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
### The error may exist in com/xxx/xxx/dal/mapper/OrderMapper.java (best guess)
### The error may involve com.xxx.xxx.dal.mapper.OrderMapper.updateRefundAmountByPayNo-Inline
### The error occurred while setting parameters
### SQL: UPDATE t_xxx_pay_order SET updated_by = ?, refund_amount = ?, cancel_flag = ?, updated_at = now(3) WHERE (pay_no = ? AND cancel_flag = ? AND refund_amount = ?)
### Cause: com.mysql.cj.jdbc.exceptions.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.cj.jdbc.exceptions.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
	at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:267)
	at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72)
	at org.mybatis.spring.MyBatisExceptionTranslator.translateExceptionIfPossible(MyBatisExceptionTranslator.java:88)
	at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:440)
	at com.sun.proxy.$Proxy123.update(Unknown Source)
	at org.mybatis.spring.SqlSessionTemplate.update(SqlSessionTemplate.java:287)
	at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:67)
	at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:93)
	at com.sun.proxy.$Proxy128.updateRefundAmountByPayNo(Unknown Source)

退款功能介绍：

  1. 用户在完成一笔订单后可以发起退款，并且只要退款总金额不大于原订单金额就允许多次退款，所以需要在原订单记录总退款金额。
  2. 支付时可能涉及用户+营销金额支付，退款时同样存在退回资金到营销的场景。例如一笔订单100，用户支付80，营销优惠20，退款时可以指定用户退5，营销退2。
  3. 在进行一笔交易（支付/退款）时会涉及3张主要的表操作，分别是order表（记录订单信息），fund表（记录用户支付信息），innermarket表（记录营销信息）。
  4. 所有更新原订单的操作以金额作乐观锁更新，sql语句伪代码如下：
update xxx set refund_amount = ? where pay_no = ? and refund_amount = ?(原退款金额)

退款处理流程：

  1. 执行退款前事务（事务X）：处理之前插入退款单到order表、innermarket表；更新原订单order表、fund表、innermarket表的退款金额。
  2. 执行退款。
  3. 执行退款后事务（事务Y）：更新退款单order表、fund表、innermarket表退款结果；如果退款执行失败，需要回退原订单order表、fund表、innermarket表中的退款金额。

2、初步解决

  • 出现问题时，刚好边上有一个大佬，推测是由于一个线程（线程A）在执行事务X更新原订单表的流程，另一个线程（线程B）在执行事务Y退款失败回退原订单表的流程，且更新顺序不一致导致。
  • 检查代码，发现事务X中更新原单的顺序是order表->fund表->innermarket表，事务Y中回退原订单退款金额的顺序是fund表->order表->innermarket表。由于原单是同一笔订单，A更新order表持有行锁尝试竞争fund表行锁，B更新fund表持有行锁尝试竞争order表行锁，会导致死锁。
  • 调试代码，问题复现。
  • 解决问题，修改回退原订单退款金额的操作，更新顺序改为order表->fund表->innermarket表。
  • 调试代码，问题消失。
  • 此时大家都以为问题解决，我脑海里闪现过一丝疑问：好像发生死锁的时候，并没有出现调用失败回滚的场景，事实上测试人员并发测试的结果是线程A执行成功，而线程B在进行执行事务X抛出死锁异常。但没有放在心上。

3、问题重现

  第二天，测试人员继续进行并发测试，问题重现。

4、问题无法复现

  本地调试，无法复现，并发执行时，由于乐观锁控制，仅线程A更新成功，线程B由于金额发生变动，没有更新到记录，同时也没有抛出死锁异常。
  为了保证同时执行，引入循环屏障CyclicBarrier，仍无法复现。

    CyclicBarrier cyclicBarrier = new CyclicBarrier(20);
    
    @Test
    public void test() {
        
        for (int i=0;i<20;i++) {
            new Thread(() -> {
                log.info("等待执行");
                try {
                    cyclicBarrier.await();
                } catch (Exception e) {
                    e.printStackTrace();
                }
                log.info("开始执行");
                refundTest();
            }, "thread" + i).start();
        }
    }

5、拉取mysql数据库日志

  找不到原因，拉取mysql报错日志：

2021-09-22T09:17:22.420170+08:00 338572 [Note] InnoDB: 
*** (1) TRANSACTION:

TRANSACTION 28286381, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 4 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 2
MySQL thread id 338566, OS thread handle 140158367102720, query id 1295050108 172.17.241.83 xxx updating
UPDATE t_xxx_order
SET updated_by = 'Hardy', refund_amount = 10, cancel_flag = 'FALSE', updated_at = now(3)
WHERE (pay_no = 'xxx' 'FALSE' AND refund_amount = 0)
2021-09-22T09:17:22.420317+08:00 338572 [Note] InnoDB: *** (1) WAITING FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 64 page no 5 n bits 288 index UIDX_PAY_NO of table `xxx`.`xxx_order` trx id 28286381 lock_mode X locks rec but not gap waiting
Record lock, heap no 213 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 30; hex 323032313039323232303030303031303030303130303030303030303033; asc 202109222000001000010000000003; (total 32 bytes);
 1: len 8; hex 00000000000000db; asc         ;;

2021-09-22T09:17:22.437466+08:00 338572 [Note] InnoDB: *** (2) TRANSACTION:

TRANSACTION 28286382, ACTIVE 0 sec fetching rows
mysql tables in use 1, locked 1
11 lock struct(s), heap size 1136, 117 row lock(s), undo log entries 5
MySQL thread id 338572, OS thread handle 140158405760768, query id 1295050112 172.17.241.83 xxx updating
UPDATE xxx_innermarket
SET updated_by = 'Hardy', refund_amt = 5, updated_at = now(3)
WHERE (account_no = 'xxx' AND pay_no = 'xxx')
2021-09-22T09:17:22.437566+08:00 338572 [Note] InnoDB: *** (2) HOLDS THE LOCK(S):

RECORD LOCKS space id 64 page no 5 n bits 288 index UIDX_PAY_NO of table `xxx`.`xxx_order` trx id 28286382 lock_mode X locks rec but not gap
Record lock, heap no 213 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 30; hex 323032313039323232303030303031303030303130303030303030303033; asc 202109222000001000010000000003; (total 32 bytes);
 1: len 8; hex 00000000000000db; asc         ;;

2021-09-22T09:17:22.438068+08:00 338572 [Note] InnoDB: *** (2) WAITING FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 33 page no 5 n bits 136 index PRIMARY of table `xxx`.`xxx_innermarket` trx id 28286382 lock_mode X waiting
Record lock, heap no 63 PHYSICAL RECORD: n_fields 17; compact format; info bits 0
 0: len 8; hex 0000000000000071; asc        q;;
 1: len 6; hex 000001af9dad; asc       ;;
 2: len 7; hex d2000001a40120; asc        ;;
 3: len 3; hex 8fcb36; asc   6;;
 4: len 7; hex 99aaac94560e24; asc     V $;;
 5: len 5; hex 4861726479; asc Hardy;;
 6: len 7; hex 99aaac94560e24; asc     V $;;
 7: len 5; hex 4861726479; asc Hardy;;
 8: len 30; hex 323032313039323232303030303031303030303130303030303030303033; asc 202109222000001000010000000003; (total 32 bytes);
 9: len 6; hex 524546554e44; asc REFUND;;
 10: len 18; hex 383831313336303530303030303339313536; asc xxx;;
 11: len 7; hex 42414c414e4345; asc BALANCE;;
 12: len 8; hex 8000000000000005; asc         ;;
 13: len 8; hex 8000000000000000; asc         ;;
 14: len 4; hex 494e5445; asc INTE;;
 15: len 0; hex ; asc ;;
 16: len 30; hex 323032313039323232303030303031303030303130303030303030303033; asc 202109222000001000010000000003; (total 32 bytes);

2021-09-22T09:17:22.439896+08:00 338572 [Note] InnoDB: *** WE ROLL BACK TRANSACTION (1)

日志分析结论：

  • 死锁在两个线程都执行事务X时发生，与事务Y没有关系。
  • 其中一个锁与update order有关，另一个貌似与update innermarket有关。

6、问题复现与思考

  • 根据分析结论猜测，调试没有复现问题是由于发起的退款没有退innermarket（退款方式是自定义的，可以选择只退fund或者只退innermarket，也可以fund和innermarket一起退，原本以为只与update order有关，没有发起innermarket退款），发起退款时带上innermarket，问题复现。
  • 定位异常场景：线程A执行事务X的最后一步update innermarket时，同时线程B执行事务X的update order时，抛出死锁异常。
  • 仍然没有想明白的是：死锁只有在线程A获得锁M尝试获取锁N，线程B获得锁N尝试获取锁M时才会出现。而本场景中两个线程执行的是同一段代码，且同样保持先update order再update innermarket的更新顺序，二者不相符。
  • 天马行空的想法：JIT优化？延迟释放锁？表级锁？

7、得出结论

  • 了解到，mysql的锁针对的是索引而不是记录，当查询条件包含唯一索引的时候，只会锁当前记录的索引，当查询索引是一个范围的话会锁一个范围的索引，考虑是不是sql语句没有走索引的问题。
  • 检查代码中更新sql，写法没有问题：
update xxx set refund_amount = ? where pay_no = ? and refund_amount = ?(原退款金额)
  • 抱着试一试的心态查了innermarket表，发现innermarket表没有加索引，这张表是团队中一个小伙伴在开发过程中增加的，而我也没有再次进行检查。回想起来，事务X刚好在update order之前有insert innermarket的操作。

至此，问题水落石出

  • 线程A在执行事务X过程中，获取了update order行级锁M。
  • 线程B在执行事务X过程中，获取了insert innermarket（营销退款单插入操作）行级锁N，执行到update order，尝试获取锁M，进入锁等待。
  • 线程A执行到update innermarket的时候需要锁全表，但由于线程B持有了行级锁N，进入锁等待。
  • mysql检测到死锁，关闭并回滚线程B的事务，线程A执行成功，线程B执行失败。

8、问题解决

  innermarket表增加索引pay_no，问题解决。

9、问题反思

  • 蝴蝶效应在本次事例中体现得淋漓尽致。细节决定成败，代码不会骗人，设计开发过程中一定要对自己的代码负责，实际上做每一份工作都要对自己的工作负责，只是这个问题在IT行业很容易被放大。
  • 没有人能保证永远不出问题，那么解决问题的能力就很关键。同样一个问题有些人一瞬间就能猜到答案，有些人想破脑袋好几天都解决不了。这个能力需要技术和经验的结合，经验需要沉淀，那么技术就需要学习。团队成员普遍对mysql底层原理了解不够透彻，也是问题解决缓慢的重要因素。
东湖樵夫
关注
专栏目录
mysql锁问题排查_记一次 MySql 数据库死锁问题排查过程
weixin_33846982的博客
01-01 454
作者 | 小牛Java 工程师，关注服务端技术通过观察生产环境日志发现了一个数据库死锁问题。下面是问题排查过程的记录。项目使用的是 MySql 数据库，版本为 5.7.24-log，使用默认存储引擎 InnoDB，默认事务隔离级别：Repeatable Read(可重复读)，相关数据表如下：CREATE TABLE `bookingproperty` ( `id` int(11) N...
JVM问题排查——死锁
m0_46311226的博客
03-19 2022
文章目录环境准备工作排查姿势一：使用JVisualVM排查姿势二：使用Jps+Jstack 环境 JDK8   准备工作 先准备好一个死锁程序：（程序是网上随便找的） public class DeadLock { public static String obj1 = "obj1"; public static String obj2 = "obj2"; pu...
记录一次Mysql死锁排查过程
weixin_33894640的博客
02-20 210
背景以前接触到的数据库死锁，都是批量更新时加锁顺序不一致而导致的死锁，但是上周却遇到了一个很难理解的死锁。借着这个机会又重新学习了一下mysql的死锁知识以及常见的死锁场景。在多方调研以及和同事们的讨论下终于发现了这个死锁问题的成因，收获颇多。虽然是后端程序员，我们不需要像DBA一样深入地去分析与锁相关的源码，但是如果我们能够掌握基本的死锁排查方法，对我们的日常开发还是大有裨益的。PS：本文不会介...
记录一次 Mysql 死锁排查过程
weixin_34218890的博客
02-19 160
背景 以前接触到的数据库死锁，都是批量更新时加锁顺序不一致而导致的死锁，但是上周却遇到了一个很难理解的死锁。借着这个机会又重新学习了一下mysql的死锁知识以及常见的死锁场景。在多方调研以及和同事们的讨论下终于发现了这个死锁问题的成因，收获颇多。虽然是后端程序员，我们不需要像DBA一样深入地去分析与锁相关的源码，但是如果我们能够掌握基本的死锁排查方法，对我们的日常开发还是大有裨益的。 PS：本文不...
记一次MySQL死锁排查
Ikaros的博客
06-22 314
关于死锁排查
记MYSQL一次死锁排查
u010887012的博客
05-13 408
在2022.05.09 晚上的放款日报中发现，有2笔报 Deadlock 的异常，这种异常不属于业务异常，故需要人为介入排查。 Error 1213: Deadlock found when trying to get lock; try restarting transaction 根据日志排查怀疑是同一个表不同的索引之间产生了死锁 所以模拟线上环境复现死锁场景 线下模拟复现 线下模拟Live环境复现死锁场景 创建一个测试表: CREATE TABLE `user_infos` ( `i.
一次诡异的线上数据库的死锁问题排查过程
weixin_44174165的博客
04-15 1271
前几天，线上发生了一次数据库死锁问题，这一问题前前后后排查了比较久的时间，这个过程中自己也对数据库的锁机制有了更深的理解。本文总结了这次死锁排查的全过程，并分析了导致死锁的原因及解决方案。希望给大家提供一个死锁的排查及解决思路。 本文涉及到MySql执行引擎、数据库隔离级别、Innodb锁机制、索引、数据库事务等多领域知识。前车之鉴，后事之师，希望读者们都可以有所收获。 1 现象 某...
Java——死锁
Yawn
05-18 1860
1. 产生条件 一般来说，要出现死锁问题需要满足以下条件： 互斥条件：一个资源每次只能被一个线程使用。 请求与保持条件：一个线程因请求资源而阻塞时，对已获得的资源保持不放。 不剥夺条件：线程已获得的资源，在未使用完之前，不能强行剥夺。 循环等待条件：若干线程之间形成一种头尾相接的循环等待资源关系。 在JAVA编程中，有3种典型的死锁类型： 静态的锁顺序死锁 动态的锁顺序死锁 协作对象之间发生的死锁。 下面来一一介绍这三种死锁： 2. 静态的锁顺序死锁 a和b两个方法都需要获得A锁和B锁。一个线程执
一次线上JVM问题的排查——一把无人持有的锁
闲鱼技术的博客
06-02 3685
背景近期，闲鱼核心应用出现了一个比较难解决的问题。在该应用集群中，会随机偶现一两个实例，其JVM运行在一个挂起的状态，深入分析stack文件发现，此时jvm中有大量的线程在等待一把没有任...
java并发编程(三十八)——“死锁“的发生及修复策略
程序员资料站
01-12 291
前言 锁是我们之前常使用的并发工具，但有时候也会有一些问题，比如死锁。本文我们来了解下死锁相关的知识。 简介 死锁一定发生在并发场景中。我们为了保证线程安全，有时会给程序使用各种能保证并发安全的工具，尤其是锁，但是如果在使用过程中处理不得当，就有可能会导致发生死锁的情况。 死锁是一种状态，当两个（或多个）线程（或进程）相互持有对方所需要的资源，却又都不主动释放自己手中所持有的资源，导致大家都获取不到自己想要的资源，所有相关的线程（或进程）都无法继续往下执行，在未改变这种状态之前都不能向前推进，我们就把这种状
rowlock mysql_记一次神奇的MySQL死锁排查
weixin_39574943的博客
01-30 134
背景说起Mysql死锁，之前写过一次有关Mysql加锁的基本介绍，对于一些基本的Mysql锁或者死锁都有一个简单的认识，可以看下这篇文章为什么开发人员需要了解数据库锁。有了上面的经验之后，本以为对于死锁都能手到擒来，没想到再一个阳光明媚的下午报出了一个死锁，但是这一次却没想象的那么简单。问题初现在某天下午，突然系统报警，抛出个异常：仔细一看好像是事务回滚异常，写着的是因为死锁回滚，原来是个死锁问题...
mysql锁问题排查_Java分布式锁的一次神奇的Mysql死锁排查
weixin_34060849的博客
12-26 87
问题初现在某天下午，突然系统报警，抛出个异常:仔细一看好像是事务回滚异常，写着的是因为死锁回滚，原来是个死锁问题，由于我对Mysql锁还是有一定 了解的，于是开始主动排查这个问题。首先在数据库中查找Innodb Status，在Innodb Status中会记录上一次死锁的信息,输入下面命令:SHOW ENGINE INNODB STATUS死锁信息如下,sql信息进行了简单处理:--------...
记一次排查线上MySQL死锁过程，不能只会curd，还要知道加锁原理
一灯架构的专栏
06-23 483
昨晚我正在床上睡得着着的，突然来了一条短信。啥，线上MySQL死锁了，我赶紧登录线上系统，查看业务日志。能清楚看到是这条insert语句发生了死锁。MySQL如果检测到两个事务发生了死锁，会回滚其中一个事务，让另一个事务执行成功。很明显，我们这条insert语句被回滚了。 但是我们怎么排查这个问题呢？到底跟哪条SQL产生了死锁？好在MySQL记录了最近一次的死锁日志，可以用命令行工具查看： 在死锁日志中，可以清楚地看到这两条insert语句产生了死锁，最终事务2被会回滚，事务1执行成功。 这两条insert
记录一次Mysql死锁事件（由Insert与uniqueKey导致）
Diligence is the mother of success.
06-04 769
| 导语记录一次于2023年01月23日遇到的死锁问题。1、基础1.1 数据库隔离级别1.1.1RCREAD COMMITTED：只能读取已经提交的数据；此时：允许幻读和不可重复读，但不允许脏读，所以RC隔离级别要求解决脏读；1.1.2RRREPEATABLE READ：同一个事务中多次执行同一个select,读取到的数据没有发生改变；此时：允许幻读，但不允许不可重复读和脏读，所以RR隔离级别要求...
记一次mysql死锁问题
qq_19439605的博客
08-30 265
这是我第一次遇到mysql死锁问题，通过这次死锁问题的分析，我对数据库的锁和有了更详细的认识。漫漫长路，一点点走。 这是我的demo复现，出现的原因是在事务里面循环更新数据，注意，此时我的mysql默认事务隔离级别是提交读，且name和sex添加了组合索引。 public void test() { User user = new User("a", "a", "aa"); ...
记一个引起MYSQL死锁Deadlock found when trying to get lock； try restarting transaction的例子 及 Share Locks和排它锁
最新发布
本博客记录了从2014年以来在工作学习中遇到的技术问题、解决方法以及部分个人人生经历、经验等内容。
07-20 965
执行命令A之后（因为sleep(3)的作用，会用一些时间），在此期间执行B。验证事务的SERIALIZABLE级别时的顺序执行。测试时也能看到事务是顺序执行的，即B事务必须等到A事务执行完毕才执行结束。两个命令分别执行(非同时)是没有问题的，但是先执行A，再执行B。B等待A执行完成后再执行，最后会报错：Deadlock found when trying to get lock;但不清楚这样为什么会报这个错误，试了一下也不是autocommit的值的问题。目前也没时间去排查吧。先留在这里做个记录。
一次mysql死锁的发现
how_interesting的博客
01-24 540
一次mysql死锁的发现 这篇文章主要介绍了笔者在业务扩展的时候，设计欠妥，导致的死锁，以及解决方案 本题难点在于下面这几部分： INSERT并发执行：在DDB的RC事务下面的并发插入 INSERT、DELETE并发执行： INTENTION LOCK产生的原因与前提： INSERT并发执行 对于INSERT操作来说，若发生唯一约束冲突，则需要对冲突的唯一索引加上S Next-key L...
Java死锁的排查
silyvin
05-05 363
https://blog.csdn.net/sidihuo/article/details/52474227 先弄个死锁的代码例子： [java] view plain copy public class DeadLock implements Runnable {          private int flag
MySQL死锁排查与解决策略
MySQL死锁是一种常见的数据库并发控制问题，它发生在两个或多个事务在执行过程中互相等待对方释放锁的情况下。当一个事务持有某个表的一部分锁，并请求锁定其他表的剩余部分，而另一个事务持有该表的剩余部分并尝试...
评论 1
添加红包

请填写红包祝福语或标题

个

红包个数最小为10个

元

红包金额最低5元

当前余额3.43元 前往充值 >
需支付：10.00元
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付元
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明：

1.余额是钱包充值的虚拟货币，按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载，可以购买VIP、付费专栏及课程。

余额充值