业务背景
笔者参与维护的一个商城项目，其中一些表依赖于一个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能力还有待提高，共勉。