前言

  最近碰到了一个Bug,折腾了我好几天。并且这个Bug不是必现的,呈现的概率比拟低。一开始我认为是旧数据的问题,就让测试从新生成了一下数据,从新测试。因为前面几轮测试均未呈现,我也就没太在意。

  惋惜好景不长,测试反馈上次的问题又呈现了。于是我立马着手排查,依据日志的体现,定位是三方服务出问题了。然而我不是十分确定,于是让测试持续察看。

  然而明天又呈现了,这次并不是第三方服务引起的。于是我开始逐行审查代码,进行排查。一开始认为缓存的保护策略不对,导致数据库和redis呈现数据不统一的状况。然而通过进一步剖析日志,发现问题并不是在Redis而是在Spring事务。

场景介绍

  业务场景如下:用户绑定了设施,须要显示在设施列表内,并且能够查看设施信息。

  当用户绑定了一个设施,我须要在数据库内新增一条绑定记录。而后批改用户的策略,在用户的策略外面加上以后的设施,这样就能够查看设施信息了。

  如果用户再次绑定同一个设施,会将原先的记录解绑,再生成一条新的绑定记录,因为是同一个设施笼罩绑定,则不会去批改用户策略。

  如果在设施端或者手机端,进行解绑操作。则服务端会将绑定记录的状态变为解绑,同时用户策略也会删除以后设施。这样就看不到设施信息了。

代码示例

代码构造

@Slf4j@Servicepublic class DeviceUserServiceImpl {    @Resource    private DeviceUserServiceImpl self;        /**     * 绑定操作     */    @Transactional(rollbackFor = Exception.class)    public DeviceBindVo doBind(DeviceBindBo bo, DevicePo device) {      //  绑定逻辑    }            /**     * 设施解绑     */    @Override    @Transactional(rollbackFor = Exception.class)    public void unbind(DeviceUnbindBo bo) {        DeviceUserPo deviceUser = self.getBindInfo(bo.getDeviceId(), bo.getUserId());        self.unbind(deviceUser, true);    }    /**     * 设施解绑,公共逻辑     */    public void unbind(DeviceUserPo deviceUser, boolean modifyPolicy) {        // 解绑逻辑    }        /**     * 获取绑定记录     */    @Override    @Cacheable(value = RedisPrefixConst.DEVICE_USER, key = "#deviceId")    public DeviceUserPo get(Long deviceId) {        // 获取绑定记录    }}    

绑定逻辑

@Transactional(rollbackFor = Exception.class)public DeviceBindVo doBind(DeviceBindBo bo, DevicePo device) {    // 获取设施绑定信息,判断设施是否被绑定    DeviceUserPo oldDeviceUser = self.get(bo.getDeviceId());    boolean modifyPolicy = true;    if (oldDeviceUser != null) {        self.unbind(oldDeviceUser);        modifyPolicy = false;        log.info("设施绑定->已完笼罩绑定的解绑流程");    }    // 新增绑定记录    DeviceUserPo newDeviceUser = new DeviceUserPo();    log.info("设施绑定->已生成新的deviceUser数据: deviceUserId={}", newDeviceUser.getDeviceUserId());    // 删除缓存    self.deleteCache(bo.getUserId(), bo.getDeviceId());    // 依据需要,更新策略    if (modifyPolicy) {        certService.modifyUserPolicy(bo.getUserId());        log.info("设施绑定->已更新用户证书策略.");    }    // 返回绑定信息    return new DeviceBindVo();}

解绑逻辑

/** * 设施解绑 * * @param bo 参数 */@Override@Transactional(rollbackFor = Exception.class)public void unbind(DeviceUnbindBo bo) {    DeviceUserPo deviceUser = self.getBindInfo(bo.getDeviceId(), bo.getUserId());    self.unbind(deviceUser, true);}public void unbind(DeviceUserPo deviceUser, boolean modifyPolicy) {    // 解绑    Assert.isTrue(            // 执行解绑SQL,            () -> new BizException(DeviceCodeEnum.DEVICE_NOT_BOUND)    );    log.info("设施解绑->已更新数据库deviceUser的状态为unbind: deviceUserId={}", deviceUser.getDeviceUserId());    // 删除缓存    self.deleteCache(deviceUser.getUserId(), deviceUser.getDeviceId());    // 更改策略    if (modifyPolicy) {        certService.modifyUserPolicy(deviceUser.getUserId());        log.info("设施解绑->已更新用户证书策略实现: userId={}", deviceUser.getUserId());    }}

获取绑定信息

@Override@Cacheable(value = RedisPrefixConst.DEVICE_USER, key = "#deviceId")public DeviceUserPo get(Long deviceId) {    // 查问SQL}

问题排查过程

  首先咱们的业务场景是:用户绑定了设施,须要显示在设施列表内,并且能够点击查看设施信息。
Bug场景是:设施曾经绑定胜利了,并且显示在设施列表内,然而无奈查看设施信息。

谬误论断:第三方服务问题

  为什么会这样认为呢?首先无奈查看设施信息,肯定是策略有问题导致的。然而我查看了这个用户的策略,是有该设施的拜访权限。而后我又查看了第三方服务的文档,说批改用户策略,失效工夫可能会有几分钟的提早。

   我问他们有没有试过等几分钟,再查看设施信息。他们说没有,从新绑定了一下就失常了。所以我就回复他们可能是三方服务策略失效时间延迟导致的。

  其实过后,如果他们过几分钟,再测试查看设施信息,如果能失常查看,那就阐明是第三方服务策略失效提早导致的。然而他们并不知道,策略批改当前,可能会提早失效,就没有做这个场景的测试。

  因为呈现Bug了,他们就尝试复现,从新绑定了设施。然而这个Bug不是必现的,接连好几次都胜利了,并没有复现进去。所以他们将呈现的异常情况告知了我。于是我就开始排查了,然而在排查过程中我疏忽了一个关键点,就是他们为了复现Bug,从新测试绑定流程,并且都胜利了。这也为我前面得出这个谬误论断埋下了一个伏笔。

  因为我疏忽了那个关键点,在排查过程中发现用户是有该设施的策略的。当初回过头来看,发现过后大脑预计是短路。因为他们在复现的过程中并没有呈现失败,都是胜利的,所以策略外面必定是该设施的。因为策略外面有该设施,并且第三方服务的文档有提到策略可能会提早失效,所以就得出了第三方服务有问题的论断。

  然而我对这个论断不是十分确定,所以让他们持续察看。并且跟他们说,如果再次出现不要做任何操作。告诉我进行排查。然而明天又呈现了通过排查发现是策略缺失。所以就排除是第三方服务出问题引起的了。

实在的起因

  既然排除了是策略未失效的问题,发现是策略缺失了。失常状况下,绑定胜利了会批改用户的策略,那么为啥没批改呢?

  通过观察绑定代码发现,不批改用户策略只有一种状况下会产生,就是发现设施曾经被绑定了,在进行笼罩绑定就不会批改策略。然而理论状况,设施曾经解绑了,再进行绑定。按理来说是获取不到曾经绑定的信息的。

@Transactional(rollbackFor = Exception.class)public DeviceBindVo doBind(DeviceBindBo bo, DevicePo device) {    // 获取设施绑定信息,判断设施是否被绑定  --> 问题点    DeviceUserPo oldDeviceUser = self.get(bo.getDeviceId());    boolean modifyPolicy = true;    if (oldDeviceUser != null) {        self.unbind(oldDeviceUser);        modifyPolicy = false;        log.info("设施绑定->已完笼罩绑定的解绑流程");    }    // 新增绑定记录    DeviceUserPo newDeviceUser = new DeviceUserPo();    log.info("设施绑定->已生成新的deviceUser数据: deviceUserId={}", newDeviceUser.getDeviceUserId());    // 删除缓存    self.deleteCache(bo.getUserId(), bo.getDeviceId());    // 依据需要,更新策略    if (modifyPolicy) {        certService.modifyUserPolicy(bo.getUserId());        log.info("设施绑定->已更新用户证书策略.");    }    // 返回绑定信息    return new DeviceBindVo();}

  那么为什么还能获取到,曾经绑定的信息呢?因为get办法是加了缓存的,如果还能获取,也就阐明在解绑的时候没有革除缓存。导致在绑定的时候,误以是笼罩绑定,才没有去批改策略,导致问题的呈现。

@Override@Cacheable(value = RedisPrefixConst.DEVICE_USER, key = "#deviceId")public DeviceUserPo get(Long deviceId) {    // 查问SQL}

  通过观察解绑逻辑,发现是先更新数据库,再进行删除缓存。尽管在高并发下,可能在极短时间数据库曾经解绑了,然而缓存还没来得及革除,获取到的还是已绑定的状态。

  然而对于我这个场景来说是不可能的呈现的。因为从解绑设施,到操作设施进入绑定模式,再进行绑定。整个操作的耗时,缓存早就被清理了。并且通过查看接口日志,也发现缓存缺失是被删除了。那么为什么缓存外面还存有绑定信息呢?

  起初发现是其余线程的会获取调用get()办法,获取绑定信息做逻辑解决。因为解绑时删除了缓存,所以这个时候会从数据库外面查问最新的绑定信息并加载进缓存。按理来说这个时候,查问到的应该是解绑的状态,而不是绑定状态。

  在进行代码审查的,我看到unbind(DeviceUnbindBo bo)上有事务,unbind(DeviceUserPo deviceUser, boolean modifyPolicy)没有事务。并且是由本身的代理对象self调用的。依据Spring的事务流传性来讲,最外层开启了事务,并且通过代理对象调用外部办法,该外部办法也是具备事务的。所以说当unbind办法内的所有逻辑执行完后事务才会提交。

/** * 设施解绑 * * @param bo 参数 */@Override@Transactional(rollbackFor = Exception.class)public void unbind(DeviceUnbindBo bo) {    DeviceUserPo deviceUser = self.getBindInfo(bo.getDeviceId(), bo.getUserId());    self.unbind(deviceUser, true);}public void unbind(DeviceUserPo deviceUser, boolean modifyPolicy) {    // 解绑    Assert.isTrue(            // 执行解绑SQL,            () -> new BizException(DeviceCodeEnum.DEVICE_NOT_BOUND)    );    log.info("设施解绑->已更新数据库deviceUser的状态为unbind: deviceUserId={}", deviceUser.getDeviceUserId());    // 删除缓存    self.deleteCache(deviceUser.getUserId(), deviceUser.getDeviceId());    // 更改策略    if (modifyPolicy) {        certService.modifyUserPolicy(deviceUser.getUserId());        log.info("设施解绑->已更新用户证书策略实现: userId={}", deviceUser.getUserId());    }}   

  到这里根本破案了,bug产生的过程如下:当服务端收到解绑申请时,先更改数据库的绑定状态,而后再删除缓存。在执行批改用户策略的时候,其余的线程来查问绑定信息,因为缓存曾经被删除了,所以这个时候须要去数据库内查问最新的绑定信息。然而因为unbind办法具备事务,并且批改用户策略还未执行完,所事务并没有提交。导致查问到的还是旧的绑定信息,并将其写入缓存。

  这也就导致了,在从新绑定的时候,明明曾经解绑了,获取到的还是绑定的状态。导致进行笼罩绑定,从而没有批改用户策略,设施绑定胜利了,但无奈查看设施详情。

解决办法

  解决办法非常简单,把@Transactional去掉即可。因为没有事务只有执行完更新SQL就提交了。所以防止在耗时的操作里加上事物,也就防止了上述问题的产生。

总结

  在理论开发中,咱们可能一不小心就掉进了Spring事务的坑里了,所以对于事务咱们须要特地小心。对于事务,并不是简略的加个@Transactional注解就行了。而是每加一个@Transactional都要认真思考,否则它可能会给你来点意外的惊喜。

结尾

  如果感觉对你有帮忙,能够多多评论,多多点赞哦,也能够到我的主页看看,说不定有你喜爱的文章,也能够顺手点个关注哦,谢谢。

  我是不一样的科技宅,每天提高一点点,体验不一样的生存。咱们下期见!