「这是我参与2022首次更文挑战的第 3 天,活动详情查看:2022首次更文挑战」
本文旨在学会看死锁日志。
现象
线上告警显示任务执行异常,该任务的主要功能逻辑为将上游系统下发的数据按规则进行匹配转换成我们系统的数据结构并进行存储。 异常堆栈详情:
org.springframework.dao.DeadlockLoserDataAccessException: ### Error updating database.
Cause: java.sql.SQLException: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException:
Deadlock found when trying to get lock; try restarting transaction
<!-- 发生死锁的具体mapper及sql语句 -->
### The error may involve XXXMapper.batchInsert-Inline
### The error occurred while setting parameters ### SQL: insert into xxx (xxx) values(xxx)
从异常堆栈中我们能看出,在写入数据时发生了死锁,导致任务执行异常。
怎么排查问题
关键点:学会分析查看死锁日志
定位异常堆栈
由堆栈信息我们能看到发生死锁的具体sql:
<!-- 发生死锁的具体mapper及sql语句 -->
### The error may involve XXXMapper.batchInsert-Inline
### The error occurred while setting parameters ### SQL: insert into xxx (xxx) values(xxx)
查看死锁日志
简单补充一点不同锁的日志知识:
锁类型 | 锁信息 | 日志 |
---|---|---|
Record Lock(记录锁) | 加在索引记录上的锁 | lock_mode X locks rec but not gap / lock_mode S locks rec but not gap |
Gap Lock(间隙锁) | 锁定一个范围的锁,不包括记录本身 | lock_mode X locks gap before rec |
Next-key Lock | 间隙锁和行锁的组合,在下一个索引记录本身和索引之前的间隙加上S锁或是X锁(如果是读就加上S锁,如果是写就加X锁) | lock_mode X |
插入意向锁 | 间隙锁的一种,插入前,该范围有间隙锁则会申请插入意向锁 | lock_mode X locks gap before rec insert intention |
LATEST DETECTED DEADLOCK ------------------------
时间:
2021-09-22 23:03:00 0x7f15a45bf700
事务1:
*** (1) TRANSACTION:
// 事务编号:38118847464,活跃时间:0s,当前状态:inserting
TRANSACTION 38118847464, ACTIVE 0 sec inserting
// 使用一个表,拥有一个表锁
mysql tables in use 1, locked 1
// 正在等待锁,锁的信息:锁链长度为3,事务分配锁堆内存大小为1136
LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
// 当前正在执行的sql
MySQL thread id 14416460, OS thread handle 139733411297024, query id 61272162890 xx.xx.xx.xx table_xxx update /*id:90d9868d*//*ip=xx.xx.xx.xx*/INSERT INTO table_xxx (id, uid, xxx) VALUES (null, xxx, xxx)
// 事务编号:38118847464正在等待的锁信息
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
// 等待记录锁,space id:149413,page:1370
RECORD LOCKS space id 149413 page no 1370 n bits 368
// 当前事务等待idx_uid索引的插入意向锁(lock_mode X locks gap before rec insert intention),所以当前事务被阻塞
**index idx_uid of table `xxx库`.`xxx表` trx id 38118847464 lock_mode X locks gap before rec insert intention waiting**
事务2:详情如下,与事务1的分析查看过程类似。
*** (2) TRANSACTION:
// 事务编号:38118847465,活跃时间:0s,当前状态:inserting
TRANSACTION 38118847465, ACTIVE 0 sec inserting
// 使用一个表,拥有一个表锁
mysql tables in use 1, locked 1
// 锁的信息:锁链长度为3,事务分配锁堆内存大小为1136
3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
// 正在执行的sql
MySQL thread id 14415908, OS thread handle 139730928531200, query id 61272162892 xx.xx.xxx.xxx table_xxx update /*id:90d9868d*//*ip=xx.xx.xxx.xxx*/INSERT INTO table_xxx (id, uid, xxx) VALUES (null, xxx, xxx)
持有锁:
***(2) HOLDS THE LOCK(S):
// 持有记录锁,space id:149413,page:1370
RECORD LOCKS space id 149413 page no 1370 n bits 368
// 当前事务持有索引idx_uid的间隙锁(lock_mode X locks gap before rec)
**index idx_uid of table table `xxx库`.`xxx表` trx id 38118847465 lock_mode X locks gap before rec**
等待锁:
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
// 事务2等待索引idx_uid的插入意向锁(lock_mode X locks gap before rec insert intention)
RECORD LOCKS space id 149413 page no 1370 n bits 368
**index idx_uid of table `xxx库`.`xxx表` trx id 38118847465 lock_mode X locks gap before rec insert intention waiting**
// 回滚事务2
*** WE ROLL BACK TRANSACTION (2)
由上述分析我们可得知死锁的原因为:事务1insert语句申请插入意向锁,但事务2持有间隙锁,同时也在等待插入意向锁,从而发生了死锁。
分析死锁原因
该业务场景为一个并发插入数据的场景,在并发插入时会产生死锁的可能。
解决办法
- 尽量避免大事务,减少每个事务占锁时间。
思考总结
首先要学会查看分析死锁日志,进而才能分析出产生死锁的原因并解决。
这个死锁问题,主要是insert语句产生的死锁问题,那么insert语句如何加锁的呢?下次再细说,还没搞透彻。。。