上图是对save和saveScore两个接口的流程抽象,save是上传答题数据,saveScore则是上传答题分数,为保证幂等和防止并发调用,这两个接口都加了分布式锁(还是两层哦)。第一层使用的是不同的锁,因为处理的是不同的表,第二层处理的是相同的表,为了保证数据在某个维度上的唯一,所以使用了相同的锁。本篇文章则主要记录下表C中的逻辑唯一键出现重复数据的问题排查过程,该问题包含了对锁、事务及Mybatis框架的综合运用和理解。
最开始只看到了第二层锁的逻辑,始终无法想通,两个接口获取的同一把锁,且加锁后都做了幂等判断,查询缓存和数据库,没有再插入,有则更新,C表的重复数据是怎么来的呢?从链路上分析,save先获取到第二层锁,插入了数据;释放锁后,saveScore开始执行,这时候查询数据库返回的结果居然是null!
这时候首先想到的是save的事务没有提交,但查看代码,事务是在获取锁3后才开启的,因此save释放锁3前,事务必定也是提交了的,而saveScore也是在获取锁3后才开启的事务。
我想大部分同学到这里会定义为玄学问题,但作为一个资深码农,要相信一切问题必有根因(除非真的是玄学)。最终,终于在saveScore的入口找到了罪魁祸首。
问题很简单,在锁3的调用入口处已经开启了事务,当save执行第二层逻辑提交事务之前,saveScore已经开启了事务,由于事务的隔离性(可重复读),在获取到锁3时,查询的是事务开始时的快照,即使save的事务已经提交,对于saveScore来说也是不可见的。
这里修改方法目前想到以下几种:
综合考虑,设置传播级别是影响最小的(有其它想法的欢迎补充),如果业务方能接受saveScore异步处理,那么这种方法则是最优的。
问题分析到这就结束了?当然没有。
从流程图上可以看到,表C、D、E是在一个事务里的,那为什么只有表C有重复,表D、E数据却是正常的呢?
先说表E,这个比较简单,首先该表有唯一索引,不像前两个表只有普通索引,其次,业务上该表存放的数据粒度更粗,也就是前面两个表多次插入,这个表只会插入一次,其余都是更新,所以就算没有唯一索引,出现重复记录的概率也远比前两个表小很多。
再看表D,这个表可真的是让我一度以为是自己对事务理解没到位,经过反复验证,证明自己理解是没有问题的。那真的是玄学?于是请教了大佬。
经过大佬分析,事实证明我想的太简单了,最后得到一个推翻上面所有分析的结论。首先我们数据库事务隔离级别设置的read committed,不是repeatable read(是我太想当然,先入为主了)。那么表D、E没有重复数据就能解释了(事实上表D还是有重复数据存在,只是不是当前分析的链路,不过那又是另外一个问题,稍后分析);但是为啥表C的幂等判断失效了呢?
对表C采用的是双重校验,从链路上看两次查询C都是没有查到数据的,所以才会新增一条,但能获取到锁3说明另一个事务已经提交,当前事务由于是read committed一定也能查询到数据才对,那说明只有一种可能,锁内的查询C是从缓存查的,不是从数据库查的l。
从阿里云的sql洞察上也能验证这个猜想,按照代码逻辑,saveScore应该有两次查询才对,但实际上只有一条,说明有一次查询(结合skywalking分析得到是第二次没有查数据库)没有到达数据库。我们这个链路上的表都是做了redis缓存的,但是如果是第一次查询是null值,根本不会缓存到redis,那还有什么缓存会拦截到查询SQL呢?还有一个我们平时可能都忽略了的,那就是Mybatis的一二级缓存,一级缓存是默认开启的。先来复习一下Mybatis的一级缓存:
我们这里的两次查询是完全一样的,且是在同一个sqlSesson极短时间内重复查询,中间没有更新,完全符合一级缓存的使用条件,就是这玩意儿搞得鬼,我以前也没遇到过这个问题,所以也忽略了Mybatis的这个机制,还一直认为这玩意儿就是个摆设,这次算是给我上了一课。
最后再回头来看看为啥D表也有重复的数据,下图是统计的部分重复数据:
这个其实很简单,上文细心的朋友可以发现我的分析都是按照save先执行,saveScore后执行的逻辑来分析的,但这两个接口执行时序其实不是固定的,当saveScore先执行,再获取到锁二时就已经开启了事务,即使锁3释放了,内层事务2也不会提交,因为和外层事务是同一个事务,那么save获取到锁3开始执行时也查不到数据,就会重复插入了。这里要解决的话也可以把内层事务传播级别声明为REQUIRED_NEW即可,对业务也没有影响。
这次的问题好在对业务没有什么影响,但代码确实写的有问题,考验了对锁、事务以及框架的总和运用和理解。另外在分析问题时不要想当然,先入为主,一定要大胆猜想、亲手验证,只要有发现一点疑点就不应该发放过,因为很有可能就这一个疑点就推翻之前所有的分析。
最后附上链路:F947DF6DC8C94E339ED1BAC5AF5E9812(edu-study、edu-study-async),感兴趣的看官可自行分析验证,有问题欢迎指出。