1. 现象
某天服务器监控上发现大量接口报错,查看服务器日志,并且分析代码后,发现最直接的问题现象有:
- Controller 的主线程中,RequestContextHolder.getRequestAttributes() 返回的值,会突然在某个时刻返回的是 null,从而导致API的逻辑报错。
- elk日志中,spring cloud sleuth 框架里面的 traceId,会在接口处理链路的某个环节突然丢失了,只有新建的spanId。
- elk日志中,最大量的报错日志信息,都是在于异步请求一个第三方服务 timeout,但是请求这个第三方服务是通过线程池异步执行的。
前面1、2 两个问题暂时无思路,因为通过日志来看,问题出现的环节无规律,也摸不着头脑。但第3个问题则是很明确,那个第三方服务不可用了。但问题3毕竟是异步线程执行的,原则上来讲不应该影响主线程,虽说暂时看不到和第1、2问题的关联点,可经验上来看应该脱不了干系。
于是我们将对那个第三方服务的请求熔断了。结果是慢慢的,服务器错误逐渐减少,直到最终恢复正常。
现在基本可以肯定,问题1、2 是受问题3影响的。接下来就需要查清问题发生的原委。
2. 排查
进一步分析问题1、2,就能明显看出来,这和线程有关。无论 RequestContextHolder
还是 MDC
,都是基于 ThreadLocal 实现的,上述乱象表面,应该是本地线程 ThreadLocal 被动了。可到底是 ThreadLocal 的值被动了?还是当前线程被切换了呢?目前只能从问题3着手。
分析问题3的现象,当时第三方服务不可用,当调用服务不是直接被拒绝,而且在请求达到最大 timeout 限制后报错。虽说整个过程是基于线程池异步执行,可这类请求 timeout 的现象,对线程池带来的结果是灾难性的。
因为线程池中分配的线程在处理 timeout 请求时,也只能保持等待,等到超时时间后才回收线程。因为是异步执行的,tomcat 线程池的处理效率并不会受影响,不断的有API请求涌入尽量,并给业务线程池分配调用第三方服务的任务。而业务线程池下执行任务的每个线程因为 timeout 请求阻塞,会导致短时间内并发线程数量迅速飙升。
我们再着重搜一下出问题时,线程池的告警日志,果然,当时线程池已经打满,开始大量执行拒绝策略。
再看看我们业务线程池的配置。这个线程池的配置在我前面几篇文章中出现过,之前以为是比较标准的,但这次发现有很大的坑。
@Bean("customExecutor")
public Executor getAsyncExecutor() {
final RejectedExecutionHandler rejectedHandler = new ThreadPoolExecutor.CallerRunsPolicy() {
@Override
public void rejectedExecution(Runnable r, ThreadPoolExecutor e) {
log.warn("LOG:线程池容量不够,考虑增加线程数量,但更推荐将线程消耗数量大的程序使用单独的线程池");
super.rejectedExecution(r, e);
}
};
ThreadPoolTaskExecutor threadPoolTaskExecutor = new ThreadPoolTaskExecutor();
threadPoolTaskExecutor.setCorePoolSize(10);
threadPoolTaskExecutor.setMaxPoolSize(50);
threadPoolTaskExecutor.setQueueCapacity(2000);
threadPoolTaskExecutor.setRejectedExecutionHandler(rejectedHandler);
threadPoolTaskExecutor.setThreadNamePrefix("custom exec-");
threadPoolTaskExecutor.setTaskDecorator(runnable -> {
try {
Optional<RequestAttributes> requestAttributesOptional = ofNullable(RequestContextHolder.getRequestAttributes());
Optional<Map<String, String>> contextMapOptional = ofNullable(MDC.getCopyOfContextMap());
return () -> {
try {
requestAttributesOptional.ifPresent(RequestContextHolder::setRequestAttributes);
contextMapOptional.ifPresent(MDC::setContextMap);
runnable.run();
} finally {
MDC.clear();
RequestContextHolder.resetRequestAttributes();
}
};
} catch (Exception e) {
return runnable;
}
});
return threadPoolTaskExecutor;
}
3. 结论
我们着重关注线程池的两个参数配置:
- 线程池拒绝策略: 拒绝策略是
CallerRunsPolicy
,即:当线程池满了之后,再有线程进来,将由对应请求的主线程来执行。 - 任务装饰: 当线程池在分配子线程时,会先让当前主线程将自身ThreadLocal 值复制给子线程。并在子线程执行完任务后,子线程清除 ThreadLocal 的值。
这些参数各自的逻辑都没有问题,可结合到一起就出问题了。试想一下:
- API 主线程原本携带 ThreadLocal 信息。此时需要基于业务线程池异步执行任务。
- 但是由于业务线程池满了,根据CallerRunsPolicy拒绝策略,只能由主线程自己来充当执行任务的“子线程”。
- 再根据线程任务装饰的逻辑,在执行完业务线程池中的任务后,线程中的“子线程”(即:主线程)会被清空 ThreadLocal 信息。
- 主线程在执行完上述任务后,就丢弃了原本携带的 ThreadLocal 信息,从而出现之前的第1和第2个问题。
所以说这样的线程池配置就是个大坑,只要线程池满了,后续的线程执行了拒绝策略。就会导致主线程 ThreadLocal 信息丢失。
问题总算找着了。
4. 解决
4.1. TaskDecorator 逻辑优化
回顾前面,发生的问题在于当执行拒绝策略时,TaskDecorator 的处理逻辑中,将主线程当子线程处理,做了 ThreadLocal 值当清除操作,最终导致主线程的 ThreadLocal 值丢失。那么首先可以针对该现象解决的是,在 TaskDecorator 逻辑对当前线程做出区分,如果发现当前线程是主线程,则不进行 ThreadLocal 的赋值和清除。如下:
@Bean("customExecutor")
public Executor getCustomExecutor() {
final RejectedExecutionHandler rejectedHandler = new ThreadPoolExecutor.CallerRunsPolicy() {
@Override
public void rejectedExecution(Runnable r, ThreadPoolExecutor e) {
log.warn("LOG:线程池容量不够,考虑增加线程数量,但更推荐将线程消耗数量大的程序使用单独的线程池");
super.rejectedExecution(r, e);
}
};
ThreadPoolTaskExecutor threadPoolTaskExecutor = new ThreadPoolTaskExecutor();
threadPoolTaskExecutor.setCorePoolSize(2);
threadPoolTaskExecutor.setMaxPoolSize(2);
threadPoolTaskExecutor.setQueueCapacity(0);
threadPoolTaskExecutor.setRejectedExecutionHandler(rejectedHandler);
threadPoolTaskExecutor.setThreadNamePrefix("custom-exec-");
threadPoolTaskExecutor.setTaskDecorator(runnable -> {
try {
Thread mainThread = Thread.currentThread();
Optional<RequestAttributes> requestAttributesOptional = ofNullable(RequestContextHolder.getRequestAttributes());
Optional<Map<String, String>> contextMapOptional = ofNullable(MDC.getCopyOfContextMap());
return () -> {
Thread subThread = Thread.currentThread();
if (!subThread.equals(mainThread)) {
try {
requestAttributesOptional.ifPresent(RequestContextHolder::setRequestAttributes);
contextMapOptional.ifPresent(MDC::setContextMap);
runnable.run();
} finally {
MDC.clear();
RequestContextHolder.resetRequestAttributes();
}
} else {
runnable.run();
}
};
} catch (Exception e) {
return runnable;
}
});
return threadPoolTaskExecutor;
}
4.2. TransmittableThreadLocal
TransmittableThreadLocal (简称TTL)是阿里推出的工具库,专门解决线程复用情况下变量传递问题。
这个工具能解决上述问题的关键在于下面的比较:
- TaskDecorator:(1)父线程给子线程赋值;(2)子线程执行完成后清空 TreadLocal值。
- TTL:(1)先给子线程做备份backup;(2)父线程给子线程赋值;(3)子线程执行完成后清空 TreadLocal值;(4)利用之前的backup,给子线程restore还原回刚来的样子。
如果是 TTL 的设计,就算按照拒绝策略,由主线程来线程池中执行异步,也因为backup还原回原来的值,并不会有任何丢值的现象。
具体的使用方法和文档,请参考 TTL github,这里就不多介绍。
但是,TTL 这个工具的框架封装上,没 TaskDecorator 那么灵活,它纯粹为了业务使用的 TreadLocal 变量服务的。如果你希望和上面一样,针对 RequestContextHolder、MDC也能实现,就比较难了。但如果你只是自己定义 ThreadLocal 值,希望子线程依然能使用,不妨使用它,再专门定义一个 TtlExecutors 类方法封装后的线程池。
5. 其他知识点
5.1. 线程池拒绝策略
拒绝策略提供顶级接口 RejectedExecutionHandler ,其中方法 rejectedExecution 即定制具体的拒绝策略的执行逻辑。
jdk默认提供了四种拒绝策略:
- AbortPolicy:抛出异常,中止任务。抛出拒绝执行 RejectedExecutionException 异常信息。线程池默认的拒绝策略。必须处理好抛出的异常,否则会打断当前的执行流程,影响后续的任务执行
- CallerRunsPolicy:使用调用线程执行任务。当触发拒绝策略,只要线程池没有关闭的话,则使用调用线程直接运行任务。一般并发比较小,性能要求不高,不允许失败。但是,由于调用者自己运行任务,如果任务提交速度过快,可能导致程序阻塞,性能效率上必然的损失较大
- DiscardPolicy:直接丢弃,其他啥都没有
- DiscardOldestPolicy:丢弃队列最老任务,添加新任务。当触发拒绝策略,只要线程池没有关闭的话,丢弃阻塞队列 workQueue 中最老的一个任务,并将新任务加入
**粗体** _斜体_ [链接](http://example.com) `代码` - 列表 > 引用
。你还可以使用@
来通知其他用户。