异常信息
测试工程师反馈数据不一致,查看日志发现如下异常信息。
### 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.hst.mds.alarmcenter.dao.IAlarmHistoryRecordDAO.insert-Inline
### The error occurred while setting parameters
### SQL: INSERT INTO 省略表结构 VALUES (?, ?, ?, ?)
### 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
意思就是说死锁了,好在MySQL有死锁检测机制,能检测出来并抛出异常。默默死锁是最恐怖的!
仔细看了下代码,数据不一致很有可能和上面的死锁异常有关。虽然加了事务,但是因为com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException不是RuntimeException及其子类,而我的@Transactional使用的都是默认参数(也就是rollbackFor=RuntimeException),所以根本就不会回滚事务。
初步排查
一开始以为是SELECT … FOR UPDATE
使用不当导致的,但看了代码发现问题没这么简单。异常信息提示的那个表我根本就没有显式的使用SELECT … LOCK IN SHARE MODE
或SELECT … FOR UPDATE
加锁。
这时,如果能查看死锁日志对定位问题肯定有很大帮助。于是登录mysql执行show engine innodb status\G
,提示ERROR 1227 (42000): Access denied; you need (at least one of) the PROCESS privilege(s) for this operation 。
随后,切换到mysql的root用户,再次执行show engine innodb status\G
,显示了一堆信息,但是却缺少了LATEST DETECTED DEADLOCK这部分信息,真是怕什么来什么。
我的应用程序是用a用户登录mysql的,由于不知道是否是权限问题,于是grant process on *.* to a
赋权限,flush privileges
刷新权限,切换到a用户登录,再次show engine innodb status\G
,依旧提示ERROR 1227 (42000): Access denied; you need (at least one of) the PROCESS privilege(s) for this operation。看来查看死锁日志这条路行不通,只能自己复现了。
一开始我在代码逻辑里只看到了表t_b的insert操作,多个insert总不可能死锁吧。正当我百思不得其解时,发现死锁的时间有玄机,是凌晨一点,我记得有个定时任务就是凌晨一点执行的,一看,定时任务果然有对这张表的delete操作。问题是,凌晨一点时,理论上我对表t_b只有一次delete(定时任务触发的),多次insert,这咋也会死锁呢?根本不存在互相等待释放锁的场景啊。
但当我的目光不再局限在t_b这一张表,而是结合表t_a的加锁操作来看,果然,发现了端倪。接下来,我将结合我的业务场景来着手复现该死锁异常。
问题复现
通过阅读代码发现,业务逻辑里会先使用SELECT … FOR UPDATE
对表t_a加锁,接下来有一个操作是向表t_b insert数据。好巧不巧的是,定时任务里是先删除表t_b表的数据,然后再删除表t_a的数据。这很可能会构成一个互相等待释放锁的死锁场景。
接下来,我们在不影响前后逻辑的情况下,对业务逻辑和表结构做一些屏蔽和精简。首先表t_a的结构如下:
表t_b的结构如下:
事先声明,以下演示基于REPEATABLE READ事务隔离级别。复现步骤:
按照时间先后顺序执行上述命令后,果然发生了死锁。
分析
这里涉及到的锁的相关知识可以参考我的另一篇博客彻底搞懂MySQL InnoDB存储引擎的锁和事务的并发问题
事务1:
SELECT * FROM t_a WHERE name = 'zhangsan' AND serviceId = 'ss' FOR UPDATE;
上面这一句加排他锁,由于查询条件不包含索引,所以会锁表。
事务2:
DELETE FROM t_b WHERE occurrenceTime < DATE_SUB(CURRENT_TIMESTAMP,INTERVAL 3 MONTH);
DELETE语句会加排他锁。DATE_SUB(CURRENT_TIMESTAMP,INTERVAL 3 MONTH)
这个函数的作用是取当前时间往前推三个月的时间戳。虽然我删除的是occurrenceTime 在三个月之前的数据,但是因为occurrenceTime 不是索引,所以这一句也会锁表。
事务2:
DELETE FROM t_a WHERE occurrenceTime < DATE_SUB(CURRENT_TIMESTAMP,INTERVAL 3 MONTH);
这一句会阻塞,因为事务2尝试对表t_a加排他锁,但是事务1已经对表t_a加了排他锁,所以事务2会等待事务1释放锁。
事务1:
INSERT INTO t_b(`occurrenceTime`) VALUES (now());
INSERT语句也会加排他锁(大家可以自行去搜索相关文章,不是本文重点,暂不讨论)。
此时会形成事务1持有表t_a的排他锁,并尝试获取表t_b的排他锁;以及事务2持有表t_b的排他锁,并尝试对表t_a加排他锁的死锁局面。
解决
最简单的解决方案就是调整加锁顺序。
如图,将3、4的顺序对调下。