TransmittableThreadLocal和Hystrix共用引发的血案

前段时间为了解决feign超时重试太多次的问题（后续可以分享出来），一言不合就把feign.hystrix.enabled开关给打开了。一系列相关的问题便接踵而至，眼看就要失业了，整夜未眠，从现象出发，一个一个击破，最终算是解决了，工作保住了。

现象一： 用Feign调用的服务中获取不到在FeignInterceptor添加到Header中的值

之前已经配置好了FeignInterceptor，把该传递的头信息都放进了header，开关开启前还是好好的，一打开就出问题了。肯定是Hystrix出了问题，于是搜索了一下Hystrix Feign传值，结果一堆答案出现。

原来是因为我们使用的Hystrix策略是THREAD模式，每一个FeignClient都会对应一个线程池，核心线程数配置了20个，在HystrixCommand执行Feign接口访问时，会在新的线程（会复用线程池中的）执行，这时原来的FeignInterceptor里面是通过取RequestContextHolder的上下文获取的值放置到FeignClient的请求头里面，但是Hystrix的执行线程并不会把父线程的RequestContextHolder的信息同步进去，所以FeignInterceptor里的代码并不能按计划完成。

修改方案也很简单，就是利用Hystrix提供的并发策略配置接口HystrixConcurrencyStrategy来自定义自己的线程执行过程，在线程执行前读取RequestContextHolder的信息，然后在执行时将这个信息设置到线程的RequestContextHolder中。代码如下：

/**
 * Feign的Hystrix并发策略
 *
 * @author luodongseu
 */
@Component
@Slf4j
public class FeignHystrixConcurrencyStrategy extends HystrixConcurrencyStrategy {

  public FeignHystrixConcurrencyStrategy() {
    try {
      HystrixConcurrencyStrategy delegate = HystrixPlugins.getInstance().getConcurrencyStrategy();
      if (delegate instanceof FeignHystrixConcurrencyStrategy) {
        return;
      }

      HystrixCommandExecutionHook commandExecutionHook =
          HystrixPlugins.getInstance().getCommandExecutionHook();
      HystrixEventNotifier eventNotifier = HystrixPlugins.getInstance().getEventNotifier();
      HystrixMetricsPublisher metricsPublisher = HystrixPlugins.getInstance().getMetricsPublisher();
      HystrixPropertiesStrategy propertiesStrategy =
          HystrixPlugins.getInstance().getPropertiesStrategy();

      // 打印日志
      if (log.isDebugEnabled()) {
        log.debug(
            "Current Hystrix plugins configuration is [concurrencyStrategy [{}], eventNotifier [{}], metricPublisher [{}], propertiesStrategy [{}]]",
            delegate,
            eventNotifier,
            metricsPublisher,
            propertiesStrategy);
        log.debug("Registering FeignWithHystrix Concurrency Strategy.");
      }

      HystrixPlugins.reset();
      HystrixPlugins instance = HystrixPlugins.getInstance();
      instance.registerConcurrencyStrategy(this);
      instance.registerCommandExecutionHook(commandExecutionHook);
      instance.registerEventNotifier(eventNotifier);
      instance.registerMetricsPublisher(metricsPublisher);
      instance.registerPropertiesStrategy(propertiesStrategy);
    } catch (Exception e) {
      log.error("Failed to register FeignWithHystrix Concurrency Strategy", e);
    }
  }

  @Override
  public <T> Callable<T> wrapCallable(Callable<T> callable) {
    // 读取上下文信息
    RequestAttributes requestAttributes = RequestContextHolder.getRequestAttributes();
    String traceId = AppContext.getTraceId();
    return () -> {
      try {
        // 在子线程中添加request上下文信息 
        RequestContextHolder.setRequestAttributes(requestAttributes);
        return callable.call();
      } finally {
        RequestContextHolder.resetRequestAttributes();
      }
    };
  }
}

你以为这就完了？

问题二：致命的交易问题来自于线程复用和线程之间的信息传递

为了做日志的链路追踪，前段时间刚引入了TransmittableThreadLocal这个阿里开源的小工具包，确实挺好用，可以在多线程中传递父线程的信息。于是，链路追踪的ID以及访问用户的身份信息等就这样放在了TransmittableThreadLocal中。本以为可以开开心心的听着歌敲着代码，然而上线不到1天，客户A来投诉了对账对不上，一查日志发现客户A的¥打到了客户B的账上。呕呕。。。

顿时，感觉到了即将失业的恐惧😱。

饭也顾不上吃了，目不转睛的找代码的问题。在几十万行日志中寻找关键的几个日志。花了几个小时的对比查找，发现很有可能是Feign在查询客户信息的时候本来应该取A的信息，结果返回了B的信息。立即展开压力测试，现象很明显，前几次的数据正确，概率性的出现数据错乱，大多数都出现了取不到数据。一度怀疑是见了鬼，完全不知道错在哪儿。只好一步步来，把整个Feign调用链路上打满日志，终于发现在FeignInterceptor拷贝信息时从TransmittableThreadLocal读取的客户信息错了。于是翻遍了TransmittableThreadLocal的代码issues，然而一无所获。这时一个不起眼的直觉告诉我，是不是不能从TransmittableThreadLocal中取，直接从RequestContextHolder取试试。果然，RequestContextHolder中的值可以传递过去。于是乎，问题答案几乎快要水落石出。

猜测可能是因为Hystrix会线程复用，所以它是不是用了其他线程的数据。对应代码就是在HystrixConcurrencyStrategy中的wrapCallable实现时，没有更新TransmittableThreadLocal中的客户的信息。果然，简单修改了一下真的就不会再出现错误的了。代码如下：

@Override
  public <T> Callable<T> wrapCallable(Callable<T> callable) {
    // 读取上下文信息
    RequestAttributes requestAttributes = RequestContextHolder.getRequestAttributes();
    String traceId = AppContext.getTraceId();
    return () -> {
      try {
        // 在子线程中添加request上下文信息 
       TransmittableThreadLocalContext.set("userInfo", "B"); RequestContextHolder.setRequestAttributes(requestAttributes);
        return callable.call();
      } finally {
        RequestContextHolder.resetRequestAttributes();
      }
    };
  }

此时，已经得到答案。

通过仔细的思考和查看了Hystrix以及TransmittableThreadLocal的相关源码，得出结论，Hystrix的线程池由简单的封装了JDK的ThreadPoolExecutor，然而TransmittableThreadLocal需要用TtlRunnable才能保证信息安全同步。因此，在前几次调用Feign时，由于ThreadPoolExecutor中并未创建线程，所以会由请求线程RequestThread_1创建新的线程HystrixThread_1，此时RequestThread_1中的TransmittableThreadLocal内的值（"A"）会被HystrixThread_1同步且缓存起来供下次读取。新的请求线程RequestThread_X（TransmittableThreadLocal值为"B"）来了后如果Hystrix创建了新的线程HystrixThread_X,则不会出现数据错误或空值；但如果Hystrix复用了线程HystrixThread_1，那么HystrixThread_1中是不会读取到"B"的信息，此时如果RequestThread_1线程结束了，此时读取TransmittableThreadLocal的值就会不存在，但如果RequestThread_1线程还在运行，那么TransmittableThreadLocal的值就为"A"，就出现了数据错乱。

真的是血的教训，不说了，准备卖肾赔客户的💰。