线上BUG:MySQL死锁分析实战

数据库 MySQL
我们不需要关注截图中得其他信息,只要能看到打印得org.springframework.dao.DeadlockLoserDataAccessException就足够了,就是MySQL发生死锁导致服务抛异常。

 [[409159]]

本文转载自微信公众号「不送花的程序猿」,作者Howinfun 。转载本文请联系不送花的程序猿公众号。  

1 线上告警

我们不需要关注截图中得其他信息,只要能看到打印得org.springframework.dao.DeadlockLoserDataAccessException就足够了,就是MySQL发生死锁导致服务抛异常。

关于接口的逻辑,可以大概描述为:C端调用接口查询店铺的追踪事件列表,如果查询为空列表则顺便给初始化,这里的初始化是批量插入一批事件追踪列表,然后再返回,这里要给到一个关于表的信息点:这个表有主键索引和唯一索引。

1.1 云日志&死锁日志

不管是云日志还是死锁日志,都是显示着是并发重复插入导致的死锁,下面我就简单放一下云日志的截图,关于死锁的日志就不放了,因为下面将自己弄个demo来仿造并发重复请求导致批量插入发生死锁。

2 相关锁概念

2.1 INSERT语句如何加锁

首先我们得先知道在执行 INSERT 语句时,引擎(默认InnoDb)是如何加锁的。

默认情况下,执行 INSERT 语句是不用加锁的,

不过如果事务中执行一条 INSERT 语句,会先定位到该记录在 B+ 树的位置时,接着判断该位置的下一条记录被加了 grap 锁;如果是的话会在记录上加上一种类型为插入意向锁的锁,最后事务进入等待状态。

插入意向锁是行级别的,也是一种间隙锁。插入意向锁之间互相兼容,多个事务可以同时对同一区间加上插入意向锁;还有在事务中,如果成功插入记录并且还未提交事务,那么当前事务还会持有插入记录的行锁。

2.2 键发生重复冲突

如果当插入记录时遇到重复键,当前事务会在生成错误信息前,对记录加上S锁,如果是唯一索引发生的重复键,会加上S型的next-key锁。

3 实践出真知

下面我们开始上例子了。

3.1 表信息

使用现有的表:

  • 用户表
  • 字段有:id、name、gender、user_type
  • id为主键,name加了唯一索引;这里加唯一索引是要和上面的告警对齐。
  1. CREATE TABLE `user` ( 
  2.   `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT, 
  3.   `namevarchar(20) NOT NULL
  4.   `gender` char(1) NOT NULL
  5.   `user_type` varchar(2) NOT NULL
  6.   PRIMARY KEY (`id`), 
  7.   UNIQUE KEY `uk_name` (`name`) 
  8. ) ENGINE=InnoDB DEFAULT CHARSET=utf8; 

3.2 单元测试

接着是单元测试:

entity、mapper和service就直接省略过了。

单元测试主要是为了模拟线上的场景,前端并发发起请求,导致发生并发批量插入同一批数据。

3.2.1 代码如下

模拟并发数3:

  1. @SpringBootTest(classes = MysqlInActionApplication.class) 
  2. @RunWith(SpringRunner.class) 
  3. public class MysqlInActionApplicationTests { 
  4.  
  5.   @Autowired 
  6.   private UserService userService; 
  7.    
  8.   /** 
  9.    * 线程数 
  10.    */ 
  11.   private static final int threadNum = 3; 
  12.   /** 
  13.    * 控制同时请求 
  14.    */ 
  15.   private static final CountDownLatch countDownLatch = new CountDownLatch(threadNum); 
  16.  
  17.   /** 
  18.    * 用户请求 
  19.    */ 
  20.   class UserRequest implements Runnable{ 
  21.  
  22.     @Override 
  23.     public void run() { 
  24.       try { 
  25.         // 等待 
  26.         countDownLatch.await(); 
  27.       } catch (InterruptedException e) { 
  28.         e.printStackTrace(); 
  29.       } 
  30.       // 批量插入用户,插入数据不变 
  31.       saveUserList(); 
  32.     } 
  33.   } 
  34.  
  35.   @Test 
  36.   public void contextLoads() { 
  37.     for (int i = 0; i < threadNum; i++) { 
  38.       new Thread(new UserRequest()).start(); 
  39.       // 计数减一 
  40.       countDownLatch.countDown(); 
  41.     } 
  42.     try { 
  43.       Thread.currentThread().join(); 
  44.     } catch (InterruptedException e) { 
  45.       e.printStackTrace(); 
  46.     } 
  47.   } 
  48.  
  49.   /** 
  50.    * 批量插入用户 
  51.    */ 
  52.   public void saveUserList(){ 
  53.     List<User> userList = new ArrayList<>(); 
  54.     userList.add(new User().setName("winfun").setGender("m").setUserType("1")); 
  55.     userList.add(new User().setName("fenghao").setGender("w").setUserType("2")); 
  56.     userList.add(new User().setName("luff").setGender("m").setUserType("1")); 
  57.     this.userService.saveBatch(userList); 
  58.   } 

3.2.2 运行结果

我们可以看到,基本和上面的告警信息是保持一致的了,直接抛出死锁的异常。

3.3 MySQL 日志

我们再看看mysql的死锁日志:

  1. show engine innodb status; 
  1. ------------------------ 
  2. LATEST DETECTED DEADLOCK 
  3. ------------------------ 
  4. 2021-07-03 12:36:02 0x7000082df000 
  5. *** (1) TRANSACTION
  6. TRANSACTION 25374, ACTIVE 0 sec inserting 
  7. mysql tables in use 1, locked 1 
  8. LOCK WAIT 2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1 
  9. MySQL thread id 17, OS thread handle 123145438982144, query id 356 localhost 127.0.0.1 root update 
  10. INSERT INTO user  ( gender, 
  11. name
  12. user_type )  VALUES  ( 'm'
  13. 'winfun'
  14. '1' ) 
  15. *** (1) WAITING FOR THIS LOCK TO BE GRANTED: 
  16. RECORD LOCKS space id 62 page no 4 n bits 72 index uk_name of table `test`.`user` trx id 25374 lock mode S waiting 
  17. Record lock, heap no 2 PHYSICAL RECORD: n_fields 2; compact format; info bits 0 
  18.  0: len 6; hex 77696e66756e; asc winfun;; 
  19.  1: len 8; hex 0000000000000001; asc         ;; 
  20.  
  21. *** (2) TRANSACTION
  22. TRANSACTION 25373, ACTIVE 0 sec inserting 
  23. mysql tables in use 1, locked 1 
  24. 3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 2 
  25. MySQL thread id 19, OS thread handle 123145439539200, query id 369 localhost 127.0.0.1 root update 
  26. INSERT INTO user  ( gender, 
  27. name
  28. user_type )  VALUES  ( 'w'
  29. 'fenghao'
  30. '2' ) 
  31. *** (2) HOLDS THE LOCK(S): 
  32. RECORD LOCKS space id 62 page no 4 n bits 72 index uk_name of table `test`.`user` trx id 25373 lock_mode X locks rec but not gap 
  33. Record lock, heap no 2 PHYSICAL RECORD: n_fields 2; compact format; info bits 0 
  34.  0: len 6; hex 77696e66756e; asc winfun;; 
  35.  1: len 8; hex 0000000000000001; asc         ;; 
  36.  
  37. *** (2) WAITING FOR THIS LOCK TO BE GRANTED: 
  38. RECORD LOCKS space id 62 page no 4 n bits 72 index uk_name of table `test`.`user` trx id 25373 lock_mode X locks gap before rec insert intention waiting 
  39. Record lock, heap no 2 PHYSICAL RECORD: n_fields 2; compact format; info bits 0 
  40.  0: len 6; hex 77696e66756e; asc winfun;; 
  41.  1: len 8; hex 0000000000000001; asc         ;; 
  42.  
  43. *** WE ROLL BACK TRANSACTION (1) 

3.3.1 事务一信息

  1. *** (1) TRANSACTION
  2. TRANSACTION 25374, ACTIVE 0 sec inserting 
  3. mysql tables in use 1, locked 1 
  4. LOCK WAIT 2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1 
  5. MySQL thread id 17, OS thread handle 123145438982144, query id 356 localhost 127.0.0.1 root update 
  6. INSERT INTO user  ( gender, 
  7. name
  8. user_type )  VALUES  ( 'm'
  9. 'winfun'
  10. '1' ) 

事务一的trascationId为25374,存活0秒

事务一执行的SQL为:INSERT INTO user ( gender,name,user_type ) VALUES ( 'm','winfun','1' )语句

  1. INSERT INTO user ( gender,name,user_type ) VALUES ( 'm','winfun','1' ) 

3.3.2 事务一正在等待的锁

  1. *** (1) WAITING FOR THIS LOCK TO BE GRANTED: 
  2. RECORD LOCKS space id 62 page no 4 n bits 72 index uk_name of table `test`.`user` trx id 25374 lock mode S waiting 
  3. Record lock, heap no 2 PHYSICAL RECORD: n_fields 2; compact format; info bits 0 
  4.  0: len 6; hex 77696e66756e; asc winfun;; 
  5.  1: len 8; hex 0000000000000001; asc         ;; 

事务一正在等待插入记录的S型的next-key锁。

3.3.3 事务二的信息

  1. *** (2) TRANSACTION
  2. TRANSACTION 25373, ACTIVE 0 sec inserting 
  3. mysql tables in use 1, locked 1 
  4. 3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 2 
  5. MySQL thread id 19, OS thread handle 123145439539200, query id 369 localhost 127.0.0.1 root update 
  6. INSERT INTO user  ( gender, 
  7. name
  8. user_type )  VALUES  ( 'w'
  9. 'fenghao'

事务二的事务ID为25373,存活0秒

事务一执行的SQL为:INSERT INTO user ( gender,name,user_type ) VALUES ( 'w','fenghao','2' )语句

  1. INSERT INTO user ( gender,name,user_type ) VALUES ( 'w','fenghao','2' ) 

3.3.4 事务二持有锁信息

  1. *** (2) HOLDS THE LOCK(S): 
  2. RECORD LOCKS space id 62 page no 4 n bits 72 index uk_name of table `test`.`user` trx id 25373 lock_mode X locks rec but not gap 
  3. Record lock, heap no 2 PHYSICAL RECORD: n_fields 2; compact format; info bits 0 
  4.  0: len 6; hex 77696e66756e; asc winfun;; 
  5.  1: len 8; hex 0000000000000001; asc         ;; 

事务二持有 name 为 winfun 这一行唯一二级索引的X锁,但不是gap锁。

3.3.5 事务二等待的锁

  1. *** (2) WAITING FOR THIS LOCK TO BE GRANTED: 
  2. RECORD LOCKS space id 62 page no 4 n bits 72 index uk_name of table `test`.`user` trx id 25373 lock_mode X locks gap before rec insert intention waiting 
  3. Record lock, heap no 2 PHYSICAL RECORD: n_fields 2; compact format; info bits 0 
  4.  0: len 6; hex 77696e66756e; asc winfun;; 
  5.  1: len 8; hex 0000000000000001; asc         ;; 

事务二在添加插入意向锁时发现记录已经被加上X型的间隙锁,所以无法添加,只能等待锁释放。

3.3.6 最后的解决

  1. *** WE ROLL BACK TRANSACTION (1) 

InnoDb 回滚了事务一,从而让事务一接触

3.4 分析总结:

  • 事务一和事务二是并发批量插入同一批数据
  • 事务二先执行,成功插入 winfun这条记录,然后对这条记录加上了行锁
  • 接着事务一进来了,发现winfun这个key是重复冲突了,接着在返回报错信息前,对winfun这条记录加上S型的next-key锁,但是发现winfun这条记录上已经有一个行锁,所以只能等待
  • 接着事务二进行第二条记录的插入,即插入fenghao;此时发现它的下一条记录,即winfun记录处已经有事务一要加入next-key锁,导致产生冲突,所以事务二也进入等待
  • 最后,只能回滚事务一,从而让事务二完整执行下去。

4 最后

最后如何解决线上这个问题呢?

其实很简单,可以上分布式锁,但是我们这场景没有必要,反而会一定程度上增加接口的耗时;并且我们这个是C端接口,完全没有必要拥有初始化店铺数据的能力,把这能力保留在Admin端的接口即可;所以最后将初始化,即批量插入初始化数据的逻辑干掉即可~

 

责任编辑:武晓燕 来源: 不送花的程序猿
相关推荐

2017-06-07 16:10:24

Mysql死锁死锁日志

2011-09-27 10:18:55

死锁

2021-03-26 10:40:16

MySQL锁等待死锁

2020-07-16 21:20:08

数据库MySQL死锁

2021-09-27 10:15:10

故障业务方电脑

2020-04-14 10:20:12

MySQL数据库死锁

2014-03-17 10:34:48

SQL Server

2011-08-24 17:41:16

MySQL死锁

2019-05-13 08:24:58

数据库MySQLInnoDB

2017-08-18 22:40:33

线上线程备份

2017-06-14 22:11:57

数据库MySQL死锁

2020-09-29 12:15:13

生死锁MySQL

2018-03-26 11:14:13

程序猿bug代码

2023-12-11 06:27:39

MySQL线上业务优化后台上传文件

2023-11-15 17:23:30

测试软件开发

2011-05-20 15:41:30

2023-07-18 09:24:04

MySQL线程

2023-11-09 11:56:28

MySQL死锁

2018-01-04 10:08:08

2019-07-11 05:53:48

MySQL死锁数据
点赞
收藏

51CTO技术栈公众号