在最近的性能测试中,某一个查询接口指标不通过,开发做了N次优化,最终的优化方案如下:异步查询然后转同步,再加上redis缓存。此为背景。

在测试过程中发现一个BUG:同样的请求在第一次查询结果是OK的,但是第二次查询(理论上讲得到的缓存数据)缺失了某些字段。

后端服务的测试代码如下,代码内容作了简化,留下了关键的部分,​​doSomething(dataMap);​​​为简化方法,其中​​teacherPadAsyncService.doExcuteLikeSateAsync()​​​、​​teacherPadAsyncService.doExcuteAccuracyAsync()​​​、​​teacherPadAsyncService.doExcuteTeacherTagAsync​​这三个是异步方法:

@Override
public void doExecute(Map<String, Object> dataMap) {
String cache = defaultRedisUtil.getString(RedisKeyConfig.COURSE_PKG_DETAIL_KEY + id);
if (StringUtils.isNotBlank(cache)) {
dataMap = JSON.parseObject(cache, Map.class);
return;
}
doSomething(dataMap);
CountDownLatch countDownLatch = new CountDownLatch(3);
String traceKey = TraceKeyHolder.getTraceKey();
teacherPadAsyncService.doExcuteLikeSateAsync(dataMap, coursePackage.getId(),ResourceTypeEnum.COURSE_PACKAGE.value, currentUser.getSystemId(), countDownLatch, traceKey);
teacherPadAsyncService.doExcuteAccuracyAsync(dataMap, coursePackage.getId(), countDownLatch, traceKey);
teacherPadAsyncService.doExcuteTeacherTagAsync(dataMap, coursePackage, countDownLatch, traceKey);
doSomething(dataMap);
defaultRedisUtil.setString(RedisKeyConfig.COURSE_PKG_DETAIL_KEY + id, JSON.toJSONString(dataMap), RedisKeyConfig.COURSE_PKG_DETAIL_EXPIRE_TIME);
try {
countDownLatch.await();
} catch (InterruptedException e) {
logger.error("异步处理线程异常", e);
}
}复制代码

​teacherPadAsyncService.doExcuteLikeSateAsync()​​​这个方法是异步查询点赞状态,会在​​dataMap​​​里面添加一个字段​​state​​​,但是在第二次请求的时候有可能发现这个字段缺失,这只是其中一个BUG。原因在于往​​redis​​​里面放置信息的时机不对,大概是由于写代码太着急,正确的做法应该是在异步转同步以后再去操作​​redis​​。下面是改之后的代码:

@Override
public void doExecute(Map<String, Object> dataMap) {
String cache = defaultRedisUtil.getString(RedisKeyConfig.COURSE_PKG_DETAIL_KEY + id);
if (StringUtils.isNotBlank(cache)) {
dataMap = JSON.parseObject(cache, Map.class);
return;
}
doSomething(dataMap);
CountDownLatch countDownLatch = new CountDownLatch(3);
String traceKey = TraceKeyHolder.getTraceKey();
teacherPadAsyncService.doExcuteLikeSateAsync(dataMap, coursePackage.getId(),ResourceTypeEnum.COURSE_PACKAGE.value, currentUser.getSystemId(), countDownLatch, traceKey);
teacherPadAsyncService.doExcuteAccuracyAsync(dataMap, coursePackage.getId(), countDownLatch, traceKey);
teacherPadAsyncService.doExcuteTeacherTagAsync(dataMap, coursePackage, countDownLatch, traceKey);
doSomething(dataMap);
try {
countDownLatch.await();
defaultRedisUtil.setString(RedisKeyConfig.COURSE_PKG_DETAIL_KEY + id, JSON.toJSONString(dataMap), RedisKeyConfig.COURSE_PKG_DETAIL_EXPIRE_TIME);
} catch (InterruptedException e) {
logger.error("异步处理线程异常", e);
}
}复制代码

BUG的原因也比较简单,由于第一次查询的时候​​redis​​​里面内容时空的,所以走了数据库查询,查询到结果后,放到​​redis​​​里面,但是在存​​redis​​​时候,异步的查询任务并没有完成,导致第一次请求得多的响应是对的,但是​​redis​​里面存放的却是错误的。在缓存有效期内,查询的结果都将是错误的。

当然这个实现方法的BUG不止这一个,这里不列举了,有机会再分享。