最近遇到一个很诡异的bug,觉得很有趣也很值得分享,于是想写篇文章记录下来,希望有缘人看到以后少踩坑~
先简单说下场景:有个任务平台,功能很多但我们只关注 提交任务和取消任务 两个功能,并且取消任务后会有消息通知
业务代码不方便透露,写个简化的伪代码帮助理解吧
@Transactional(rollbackFor = Exception.class, propagation = Propagation.REQUIRED)public void cancel() {Job job = select();//查出job才进入ifif (job != null) {update();//这个方法跟bug无关,可以忽略delete(job);//删除成功后,下一次执行就不会进入ifsendMsg();//发送通知}}
业务流程:任务提交执行后,可以通过cancel方法取消执行,cancel方法内部逻辑很好理解,先查询一个job对象,如果对象不为null则进行下面的一系列操作,因为涉及到多个写操作,所以整个方法加了注解@Transactional用于事务控制
下面是我的排查过程,极其精彩,极其费头发!!
bug描述:提交任务后,有三种情况
- 👉提交任务后立马取消,此时不发送通知,正常
- 👉提交后在很短时间内取消(任务执行时间在六秒内),此时发送两条通知,异常
- 👉提交后正常取消(任务执行超过十秒),此时发送一条通知,正常
问题就在第二种情况
上面的规律看起来简单,其实是花了很长很长很长很长的时间才发现的,从发现这个规律开始才找到了稳定复现bug的方法
又花了很长很长很长很长时间,我确定cancel方法在上面第二种情况时会执行两次,并且两次执行间隔很短
两次间隔时间大概就这么点
所以,我很自信的判定这是由多线程导致的,对于一个多写的操作,不应该允许多个线程异步执行
具体执行情况:
T时刻,两个线程同时执行cancel方法
A线程和B线程读取到的job都不为null,于是都进入if语块
导致sendMsg()执行两次,所以发送两次消息通知
给大家看下消息通知长啥样,注意看时间,其实相差了几十纳秒,只是没显示出来
原来问题这么简单!
于是,我给整个方法加上 synchronized
@Transactional(rollbackFor = Exception.class, propagation = Propagation.REQUIRED)public synchronized void cancel() {//加上synchronized Job job = select();if (job != null) {update();//这个方法跟bug无关,可以忽略delete(job);//删除成功后,下一次执行就不会进入ifsendMsg();//发送通知}}
完事儿测试发现不行
我就知道你synchronized是渣锁不靠谱,我换lock
换lock测试也不行
加锁后虽然线程能顺序执行,但依然会发送两次通知
麻了
好好好,这么玩是吧
继续分析,方向肯定没错,两个线程select都不为null,所以继续往下执行导致bug
但是我已经加了锁了,从日志看线程也已经同步执行了为啥还是不行(加了日志后能看出来是一个线程执行完了才执行另一个)
此时,我把目光集中在了@Transactional注解
会不会是事务导致的??
为了验证猜想,我把事务直接注释掉,测试发现居然行了
这么神奇?尊嘟假嘟~
它虽然行了,但业务不行,谁家好人这种多写操作不加事务啊
虽然但是,到这里我几乎确定了bug跟事务有关
原来问题这么简单!+1
继续猜测,有没有可能是事务虽然提交了,但执行删除操作需要时间,还没来得及删除成功第二个线程就进来,此时查到的job是不为null的,所以才出现bug
为了验证这个猜想,我在方法结束前加了个sleep,既然你删除需要时间,我就给你时间
@Transactional(rollbackFor = Exception.class, propagation = Propagation.REQUIRED)public synchronized void cancel() {//加上synchronized Job job = select();if (job != null) {update();//这个方法跟bug无关,可以忽略delete(job);//删除成功后,下一次执行就不会进入ifsendMsg();//发送通知}Thread.sleep(100);//给删除操作预留时间}
测试发现又行了
它虽然行了,但业务还是不行,谁家好人用这么取巧的手段啊,万一网络波动或者数据库卡了导致删除操作延时,bug还是会复现
虽然但是,到这里我几乎确定了bug跟事务提交后的删除操作耗时有关
原来问题这么简单!+2
继续排查掉头发
很快想到了新疑点:声明式事务其实有个弊端,它提交事务的时机是在方法执行完成后的,记住这句话,后面要考
所以,有没有可能是因为锁的释放时机和事务提交时机导致的,锁是方法执行完释放,事务也是方法执行完才提交,那问题就出在锁刚刚释放,第二个线程立马拿到锁入栈搞偷袭
好好好,原来是你不讲武德搞偷袭
原来问题这么简单!+3
继续验证猜想
其实很好验证,将声明式事务改成手动提交事务即可
public synchronized void cancel() {//加上synchronized try {// 创建数据库连接connection = DriverManager.getConnection(url, username, password);// 开始事务connection.setAutoCommit(false);// 执行一些数据库操作Job job = select();if (job != null) {update();//这个方法跟bug无关,可以忽略delete(job);//删除成功后,下一次执行就不会进入ifsendMsg();//发送通知}//提交事务connection.commit();} catch (SQLException e) {e.printStackTrace();//回滚事务try {if (connection != null) {connection.rollback();}} catch (SQLException ex) {ex.printStackTrace();}} finally {// 关闭数据库连接try {if (connection != null) {connection.close();}} catch (SQLException e) {e.printStackTrace();}}}
测试发现确实可以,多次测试也未发现异常
ok破案
至此,bug就算是修复了
但是,第二天我又想起这个bug,忍不住多思考了一下
有没有可能通过修改事务隔离级别来实现??
其实通过加锁和手动提交事务达到的效果,理论上确实可以通过隔离级别来实现
原来问题这么简单!+4
继续验证猜想
当前的数据库隔离级别是READ_COMMITTED,先设置到REPEATABLE_READ试试
@Transactional(rollbackFor = Exception.class, propagation = Propagation.REQUIRED, isolation = Isolation.REPEATABLE_READ)//指定隔离级别public synchronized void cancel() {//加上synchronized Job job = select();if (job != null) {update();//这个方法跟bug无关,可以忽略delete(job);//删除成功后,下一次执行就不会进入ifsendMsg();//发送通知}}
测试发现8太行
估计还是事务注解提交事务的时机导致,READ_COMMITTED虽然能保证事务内多次读取同一条数据是一样的,但保证不了删除数据
直接设置成SERIALIZABLE试试
@Transactional(rollbackFor = Exception.class, propagation = Propagation.REQUIRED, isolation = Isolation.SERIALIZABLE)//指定隔离级别public synchronized void cancel() {//加上synchronizedJob job = select();if (job != null) {update();//这个方法跟bug无关,可以忽略delete(job);//删除成功后,下一次执行就不会进入ifsendMsg();//发送通知}}
欸嗨,可以了
多次测试也未发现问题
看来还是得让两个线程串行,SERIALIZABLE 和 手动提交事务并且加锁的原理和效果其实是一样的,都是从源头上保证一个事务内只有一个线程执行
原来问题这么简单!+10086
至此,bug正式修复
bug是修复了,头发没了