Spring cloud Sleuth链路追踪对于异步线程池的支持

在spring中使用不同的创建线程池的方式调用对日志中traceId的生成逻辑的影响

• 使用问题:
  用sleuth做日志追踪时,在用到@Async注解做异步时,发现traceId重新生成了,导致 无法和main线程关联到一起。
  追踪源码后发现是因为sleuth对实现了AsyncConfigurer接口的线程池做包装时,由于加载顺序的问题导致未对线程池做代理,导致异步的线程重新生成了traceId。

场景描述:

一.不使用scheduling中的AsyncConfigurer创建线程池

1.使用JDK的ThreadPoolExecutor创建线程池（对应代理类LazyTraceExecutor）

ThreadPoolExecutor jdkExecutor = new ThreadPoolExecutor(5, 20, 60, TimeUnit.SECONDS, new ArrayBlockingQueue<Runnable>(60));
        jdkExecutor.setThreadFactory(new CustomizableThreadFactory("jdkCustomExecutor-"));
        jdkExecutor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());

• 其中JDK的executor 对应代理类LazyTraceExecutor,该类只实现了executor的execute方法(对应runnable的代理类SpanContinuingTraceRunnable),
  所以其它调用方式(如submit)都会重新生成traceId。
• 使用executor.execute()调用的话 main线程和异步线程使用同一个traceId,不同的spanId。其他调用方式都会重新生成traceId。
  因为sleuth-core源码中 org.springframework.cloud.sleuth.instrument.async.AsyncDefaultAutoConfiguration 中方法executorBeanPostProcessor
  会对线程池进行代理ExecutorBeanPostProcessor#postProcessAfterInitialization,以支持traceId在异步线程中的输出。
  
  图一

图二

2.使用spring的ThreadPoolTaskExecutor创建线程池（对应代理类LazyTraceThreadPoolTaskExecutor）

ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        executor.setCorePoolSize(5);
        executor.setMaxPoolSize(20);
        executor.setQueueCapacity(50);
        executor.setKeepAliveSeconds(60);
        executor.setThreadNamePrefix("CustomExecutor-");

        // rejection-policy：当pool已经达到max size的时候，如何处理新任务
        // CALLER_RUNS：不在新线程中执行任务，而是有调用者所在的线程来执行
        executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
        executor.initialize();

见[图二]中 79行,框架调用了createThreadPoolTaskExecutorProxy 方法创建ThreadPoolTaskExecutor的代理类LazyTraceThreadPoolTaskExecutor,
该类中实现了execute,submit等方法,且对线程runnable和callable进行了包装,如SpanContinuingTraceRunnable,SpanContinuingTraceCallable,实现了和main线程使用同一traceId的目的。

• 另:如果使用@async注解的话,在@async(“线程池名”)中指定线程池的名字,和使用线程池中execute/submit是同样的效果,同样共用同一个traceId。

二.实现scheduling中的AsyncConfigurer接口配置线程池

@Configuration
@EnableAsync
public class AsyncExecutorConfig implements AsyncConfigurer{
    @Override
    public Executor getAsyncExecutor() {
        if (logger.isInfoEnabled()) {
            logger.info("init asyncServiceExecutor");
        }
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        //配置核心线程数
        executor.setCorePoolSize(corePoolSize);
        //配置最大线程数
        executor.setMaxPoolSize(maxPoolSize);
        //配置队列大小
        executor.setQueueCapacity(queueSize);
        //配置线程池中的线程的名称前缀
        executor.setThreadNamePrefix(poolName);
        //配置保存时间
        executor.setKeepAliveSeconds(keepAliveSeconds);
        executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
        //执行初始化
        executor.initialize();
        return executor;
    }
 }   

• 首先该配置方式会导致main线程和异步线程不能共用同一traceId。

• 因为AsyncConfigurer的实例在AsyncCustomAutoConfiguration之前进行了初始化,日志中在对bean进行检查时同样会输出- [main] o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'testExecutorConfig2' of type [com.csii.gateway.controller.TestExecutorConfig2$$EnhancerBySpringCGLIB$$ebe6404] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 表示AsyncConfigurer的实例不会被所有的BeanPostProcessors所解析(原因猜测是注解@Async相关的配置导致的实例化)。
  所以如果使用了AsyncConfigurer进行配置异步线程池，且使用了注解@Async不管使用的jdk还是spring的线程池实现方式，异步线程都不会使用main线程的traceId。

• 解决办法：

1. 1.1 不通过实现接口的方式配置AsyncConfigurer，而是通过@Configuration 的方式注册一个sleuth中的LazyTraceAsyncCustomizer包装类型的AsyncConfigurer。
   1.2 需要配置application.yaml
spring: sleuth: async: configurer: enabled: false
   将sleuth中默认的org.springframework.cloud.sleuth.instrument.async.AsyncDefaultAutoConfiguration.DefaultAsyncConfigurerSupport 异步线程池的配置忽略掉。
2. 直接使用@Async("线程池")的方式进行指定线程池(不使用AsyncConfigurer)。

• 解决办法1 示例如下：

@Configuration
public class TestExecutorConfig {

    @Value("${online.threadPool.coreSize:20}")
    private int corePoolSize;
    @Value("${online.threadPool.maxSize:110}")
    private int maxPoolSize;
    @Value("${online.threadPool.queueSize:5}")
    private int queueSize;
    @Value("${online.threadPool.name:Online-Async-}")
    private String poolName;
    @Value("${online.threadPool.keepAliveTime:3000}")
    private int keepAliveSeconds;

    @Autowired
    private BeanFactory beanFactory;

    @Bean
    public AsyncConfigurer asyncConfigurer(){
    //  在这里返回一个 LazyTraceAsyncCustomizer 类型的AsyncConfigurer
        return new LazyTraceAsyncCustomizer(this.beanFactory, new AsyncConfigurer() {
            @Override
            public Executor getAsyncExecutor() {
                System.err.println("getAsyncExecutor-----");
                ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
                //配置核心线程数
                executor.setCorePoolSize(corePoolSize);
                //配置最大线程数
                executor.setMaxPoolSize(maxPoolSize);
                //配置队列大小
                executor.setQueueCapacity(queueSize);
                //配置线程池中的线程的名称前缀
                executor.setThreadNamePrefix(poolName);
                //配置保存时间
                executor.setKeepAliveSeconds(keepAliveSeconds);
                executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
                //执行初始化
                executor.initialize();
                return executor;
            }

            @Override
            public AsyncUncaughtExceptionHandler getAsyncUncaughtExceptionHandler() {
                return (throwable, method, obj) -> {
                    System.err.println("zidingyi "+throwable);
                };

            }
        });
    }
}

参考文档:

1. SpringCloud多线程链路追踪
2. 注意BeanPostProcessor启动时对依赖Bean的“误伤”陷阱（is not eligible for getting processed by all…）