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(7);
threadPoolTaskExecutor.setMaxPoolSize(42);
threadPoolTaskExecutor.setQueueCapacity(11);
threadPoolTaskExecutor.setRejectedExecutionHandler(rejectedHandler);
threadPoolTaskExecutor.setThreadNamePrefix("Custom Executor-");
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 信息失落。
问题总算找着了,至于有什么代替的计划,下篇文章介绍。