业务中使用ThreadLocal中途居然还能变?

业务背景

笔者参与维护的一个商城项目,其中一些表依赖于一个gameCode字段进行分表处理,例如 a_sell_bill、b_sell_bill,a、b为不同的gameCode。在需要用的gameCode的接口处,前端会在header中传入gameCode,后端有统一的过滤器会将gameCode设置进一个ThreadLocal变量中,如:

...
HttpServletRequest httpServletRequest = (HttpServletRequest)request;
String gameCode = httpServletRequest.getHeader("gameCode");
gameContext.setGameCode(gameCode);
...
@Component
public class GameContext {

    static final ThreadLocal<String> ctx = new ThreadLocal<>();

    public void setGameCode(String gameCode){
        ctx.set(gameCode);
    }

    public String currentGameCode(){
        return ctx.get();
    }

}

后续很多业务场景都依赖于gameContext中的gameCode值进行分表处理。

问题描述

在某次开发一个订单需求时,开发环境能够正常下单,但是测试环境订单会下单不成功,正式环境也是正常的(不然早就有人反馈问题了)。通过添加日志发现订单Controller中还能从数据库中查到这笔卖单,结果到了订单Service就查不到这笔卖单了,比对查询参数发现并没有问题,直接查测试环境数据库也能查到相应数据。

初步怀疑可能是因为gameCode出现问题,导致没有走到对应的表上,继续增加日志,打印当前的gameCode值,发现订单Controller中从gameContext中获取到的gameCode还是正确的,结果到了调用的订单Service,从gameContext中获取到的gameCode就有问题了,是另一个值。

怎么回事?ThreadLocal值中途还会变的吗?仔细查看代码,在过滤器设置完gameCode之后,整个方法调用并没有去设置gameCode值呀,虽然考虑了tomcat是会存在线程复用的情况,但是一次请求还没完成的话,tomcat并不会把线程放回线程池呀。

继续排查,在所有设置gameContext值的地方打印日志,并且打印方法栈,看是否有其它方法会调用:

public void setGameCode(String gameCode){
    logger.error("gameCode setGameCode={}", gameCode);
    printCallStack();
    ctx.set(gameCode);
}

private static void printCallStack() {
    Throwable exception = new Throwable();
    StackTraceElement[] stackTraceElements = exception.getStackTrace();
    StringBuilder sb = new StringBuilder("gameCode ");
    if (stackTraceElements != null) {
        for (StackTraceElement element : stackTraceElements) {
            sb.append(element.getClassName()).append("\t")
                .append(element.getFileName()).append("\t")
                .append(element.getLineNumber()).append("\t")
                .append(element.getMethodName()).append("\n");
        }
        logger.error(sb.toString());
    }
}

果不其然,发现了在进入订单Service之前,会调用另一个检查用户金额Service的方法,该方法会从数据库中取出用户余额变动记录进行遍历,并且当类型为购买商品时,并将订单中的gameCode重新设置到gameContext变量中,用于查找对应的订单(因为订单依赖于gameContext中的gameCode值进行分表),导致检查完用户余额之后,再次查询由于gameCode值变了就找不到这笔订单了。该方法是通过注解进行调用的,所以先前并没有排查到该方法。

解决办法

在中途需要设置gameCode值的地方之前先保存原先的值,待方法结束之前再恢复到原来的gameCode值,如:

@UserMoneyType(Constants.MONEY_LOG_TYPE_BUY)
private UserMoney modifyUserMoneyBuy(UserMoneyLog userMoneyLog, BigDecimal change) {
    // 1. 设置gameCode之前一定要先保存到前的值
    String restoreGameCode = gameContext.currentGameCode();
    gameContext.setGameCode(userMoneyLog.getGameCode());
    // ...
    // 这里需要使用userMoneyLog.getGameCode()中的gameCode值去对应的表查询订单数据
    // ...
    // 2. 用完恢复
    gameContext.setGameCode(restoreGameCode);
    return new UserMoney(userMoneyLog.getUserid(), amount, trade, recharge, freeze);
}

感悟

由于笔者参与这个项目时,项目代码已基本成型,后续只是增加新的功能,故有一些代码笔者并不了解其实现逻辑,导致解决这个bug花了整整2天,期间还问了一些前辈同事。由于不能在测试环境debug,只能依赖于代码中打印的日志来排查问题,期间也走了很多弯路,其中在日志中打印执行的方法栈也是前辈提醒的,自己的debug能力还有待提高,共勉。

posted @ 2022-01-14 21:59  爱Code的王饱饱  阅读(105)  评论(0编辑  收藏  举报