线上BUG：MySQL死锁分析实战

旧城等待， 2022-10-12 12:17 199阅读 0赞

# 1 线上告警 #

我们不需要关注截图中得其他信息，只要能看到打印得`org.springframework.dao.DeadlockLoserDataAccessException`就足够了，就是MySQL发生死锁导致服务抛异常。  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L0hvd2luZnVu_size_16_color_FFFFFF_t_70]  
关于接口得逻辑，可以大概描述为：C端调用接口查询店铺得追踪事件列表，如果查询为空列表则顺便给初始化，这里的初始化是**批量插入一批事件追踪列表**，然后再返回，这里要给到一个关于表的信息点：这个表有主键索引和唯一索引。

## 1.1 云日志&死锁日志 ##

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

# 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加了唯一索引；这里加唯一索引是要和上面的告警对齐。

CREATE TABLE `user` (
      `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
      `name` varchar(20) NOT NULL,
      `gender` char(1) NOT NULL,
      `user_type` varchar(2) NOT NULL,
      PRIMARY KEY (`id`),
      UNIQUE KEY `uk_name` (`name`)
    ) ENGINE=InnoDB DEFAULT CHARSET=utf8;

## 3.2 单元测试 ##

接着是单元测试：  
entity、mapper和service就直接省略过了。

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

### 3.2.1 代码如下 ###

模拟并发数3：

@SpringBootTest(classes = MysqlInActionApplication.class)
    @RunWith(SpringRunner.class)
    public class MysqlInActionApplicationTests { 
    
    	@Autowired
    	private UserService userService;
    	
    	/** * 线程数 */
    	private static final int threadNum = 3;
    	/** * 控制同时请求 */
    	private static final CountDownLatch countDownLatch = new CountDownLatch(threadNum);
    
    	/** * 用户请求 */
    	class UserRequest implements Runnable{ 
    
    		@Override
    		public void run() { 
    			try { 
    				// 等待
    				countDownLatch.await();
    			} catch (InterruptedException e) { 
    				e.printStackTrace();
    			}
    			// 批量插入用户，插入数据不变
    			saveUserList();
    		}
    	}
    
    	@Test
    	public void contextLoads() { 
    		for (int i = 0; i < threadNum; i++) { 
    			new Thread(new UserRequest()).start();
    			// 计数减一
    			countDownLatch.countDown();
    		}
    		try { 
    			Thread.currentThread().join();
    		} catch (InterruptedException e) { 
    			e.printStackTrace();
    		}
    	}
    
    	/** * 批量插入用户 */
    	public void saveUserList(){ 
    		List<User> userList = new ArrayList<>();
    		userList.add(new User().setName("winfun").setGender("m").setUserType("1"));
    		userList.add(new User().setName("fenghao").setGender("w").setUserType("2"));
    		userList.add(new User().setName("luff").setGender("m").setUserType("1"));
    		this.userService.saveBatch(userList);
    	}
    }

### 3.2.2 运行结果 ###

我们可以看到，基本和上面的告警信息是保持一致的了，直接抛出死锁的异常。![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L0hvd2luZnVu_size_16_color_FFFFFF_t_70 2]

## 3.3 MySQL 日志 ##

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

show engine innodb status;

------------------------
    LATEST DETECTED DEADLOCK
    ------------------------
    2021-07-03 12:36:02 0x7000082df000
    *** (1) TRANSACTION:
    TRANSACTION 25374, ACTIVE 0 sec inserting
    mysql tables in use 1, locked 1
    LOCK WAIT 2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
    MySQL thread id 17, OS thread handle 123145438982144, query id 356 localhost 127.0.0.1 root update
    INSERT INTO user  ( gender,
    name,
    user_type )  VALUES  ( 'm',
    'winfun',
    '1' )
    *** (1) WAITING FOR THIS LOCK TO BE GRANTED:
    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
    Record lock, heap no 2 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
     0: len 6; hex 77696e66756e; asc winfun;;
     1: len 8; hex 0000000000000001; asc         ;;
    
    *** (2) TRANSACTION:
    TRANSACTION 25373, ACTIVE 0 sec inserting
    mysql tables in use 1, locked 1
    3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 2
    MySQL thread id 19, OS thread handle 123145439539200, query id 369 localhost 127.0.0.1 root update
    INSERT INTO user  ( gender,
    name,
    user_type )  VALUES  ( 'w',
    'fenghao',
    '2' )
    *** (2) HOLDS THE LOCK(S):
    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
    Record lock, heap no 2 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
     0: len 6; hex 77696e66756e; asc winfun;;
     1: len 8; hex 0000000000000001; asc         ;;
    
    *** (2) WAITING FOR THIS LOCK TO BE GRANTED:
    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
    Record lock, heap no 2 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
     0: len 6; hex 77696e66756e; asc winfun;;
     1: len 8; hex 0000000000000001; asc         ;;
    
    *** WE ROLL BACK TRANSACTION (1)

### 3.3.1 事务一信息 ###

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

事务一的trascationId为25374，存活0秒  
事务一执行的SQL为：`INSERT INTO user ( gender,name,user_type ) VALUES ( 'm','winfun','1' )`语句

### 3.3.2 事务一正在等待的锁 ###

*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
    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
    Record lock, heap no 2 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
     0: len 6; hex 77696e66756e; asc winfun;;
     1: len 8; hex 0000000000000001; asc         ;;

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

### 3.3.3 事务二的信息 ###

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

事务二的事务ID为25373，存活0秒  
事务一执行的SQL为：`INSERT INTO user ( gender,name,user_type ) VALUES ( 'w','fenghao','2' )`语句

### 3.3.4 事务二持有锁信息 ###

*** (2) HOLDS THE LOCK(S):
    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
    Record lock, heap no 2 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
     0: len 6; hex 77696e66756e; asc winfun;;
     1: len 8; hex 0000000000000001; asc         ;;

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

### 3.3.5 事务二等待的锁 ###

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
    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
    Record lock, heap no 2 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
     0: len 6; hex 77696e66756e; asc winfun;;
     1: len 8; hex 0000000000000001; asc         ;;

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

### 3.3.6 最后的解决 ###

*** WE ROLL BACK TRANSACTION (1)

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

## 3.4 分析总结： ##

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

# 4 最后 #

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

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

[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L0hvd2luZnVu_size_16_color_FFFFFF_t_70]: /images/20221005/2c834e9b7057472294940929304582d5.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L0hvd2luZnVu_size_16_color_FFFFFF_t_70 1]: /images/20221005/a5bb3f0dfb4b4c3f956fd1537100074a.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L0hvd2luZnVu_size_16_color_FFFFFF_t_70 2]: /images/20221005/95a20f4c759647b68a8d923928f04eca.png