升级springboot导致的业务异步回调积压问题定位
1. 起因
A与B云侧模块特性联调的过程中,端侧发现云侧返回有延迟的情况。
7月19日与A模块一起抓包初步判断,B业务有积压的情况。
7月18日已经转侧B业务现网版本,由于使用一套逻辑。故可能存在请求积压的问题。(严重)
2. 定位过程
2.1 复现问题
15路压测大屏发现请求有将近十多秒的时延,对于B业务实时性要求极高的业务,这无疑是灾难性的。
由于B业务最近针对业务并没有修改关键代码,只对springboot等相关第三方包做了升级。对比升级前后日志发现一个线程的名称发生了变化
升级前:
升级后:
因为B业务的上传接口采用的是异步回调机制。
升级之前,当springmvc内部有异步回调的时候,每次都会创建线程去处理回调逻辑,即没有线程池的概念,每次都是创建新的线程。线程命名规则是:MvcAsync[xx]
[xx]标示数值,比如MvcAsync1,MvcAsync9,MvcAsync10...
升级之后发现线程名字变成了task-[xx], xx标示数值,似乎只是名称改了,且在长期运行日志中发现task-[xx]也是大体递增趋势。
2.2 找异常点
后来为了复现问题,我们采用了15路压测,利用Java VisualVM观察CPU,内存,进程等。CPU和内存都ok,但是发现了很奇怪的现象:在压测的时候,为什么task-[xx]不递增,而且只维持8个线程,而我们15路并发,自然是处理不了。
难道task-[xx]是线程池里面的线程?且业务明显很“忙”,为什么不继续创建线程?难道内部真的改成线程池,并且对线程数量做了最多8个线程的限制?
后来我做了单次调用的测试,发现,task-[xx]同一时刻最多有8个线程同时运行,如果一直运行的话,就会复用线程,与之前的每次都创建新的线程完全不同,而且只运行一次的线程的存活时间是大约60秒,这不是keepalive的特性吗?
通过分析可以基本判断异步回调已经不是每次都创建新的线程,而是可能内部有线程池?
这些都是分析和猜测,并没有直接的证据说明,而且我们是需要最终去修改问题,如果只是大体猜出问题在哪?但是却不知道如何修改,也是没有办法的。
2.3 确认问题及解决方案
没办法,只能撸代码。
对于springboot我们基本都是当黑盒使用的,代码确实看了大概,但是要完全靠走读代码很难确定问题(面向接口编程一般很难确定具体运行类),所以我们采用了单步调试。撸代码基本可以确定问题对应的代码范围,方便我们调试代码。
为了方便调试,我写了一个简单的demo(个人觉得这个很重要,最好的方式肯定直接利用业务代码调试,但是有的时候我们的业务很庞大或者调试条件比较苛刻)
@RequestMapping("/webAsyncTask") public WebAsyncTask<String> webAsyncTask() { System.out.println("外部线程:" + Thread.currentThread().getName()); WebAsyncTask<String> result = new WebAsyncTask<>(6000000L, new Callable<String>() { @Override public String call() throws Exception { System.out.println("内部线程:" + Thread.currentThread().getName()); return "web async task"; } }); result.onTimeout(new Callable<String>() { @Override public String call() throws Exception { return "timeout"; } }); result.onCompletion(new Runnable() { @Override public void run() { System.out.println("finish"); } }); return result; }
通过走读代码,确定在spring-web-x.x.x.RELEASE.jar包里面的类
org.springframework.web.context.request.async.WebAsyncManager
其中的AsyncTaskExecutor taskExecutort保存异步调度线程的创建方式。
private AsyncTaskExecutor taskExecutor = new SimpleAsyncTaskExecutor(this.getClass().getSimpleName());
默认赋值SimpleAsyncTaskExecutor,这个对象就是每次都创建新的线程去执行异步回调。
我们分别使用springboot-1.5.14.RELEASE和springboot-2.1.3.RELEASE调试代码,对于调试的断点也很重要,到底把断点加在什么地方呢?针对我们的这个问题,加在业务代码里面肯定是看不出问题。有个方法可以大体判断地方,通过线程调用堆栈,如下图(可放大,下同):
断点基本可以确定在WebAsyncManager.startCallProcessing()方法里面
springboot-1.5.14.RELEASE调试截图:taskExecutor就是SimpleAsyncTaskExecutor实例
springboot- 2.1.3.RELEASE调试截图:taskExecutor就是org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor实例,并且是一个线程池corePoolSize=8,keepalive=60sec,maxPoolSize= 2147483647,queueCapacity=2147483647
这些默认值肯定是不合理的。
补充:
(1)corePoolSize: 线程池中的核心线程数,当提交一个任务时,线程池创建一个新线程执行任务,直到当前线程数等于corePoolSize;如果当前线程数为corePoolSize,继续提交的任务被保存到阻塞队列中,等待被执行;
(针对该问题由于队列很大,任务一直在排队,导致新的线程创建不了,而且一直是8个)
(2)maximumPoolSize: 线程池中允许的最大线程数。如果阻塞队列满了,且继续提交任务,则创建新的线程执行任务,前提是当前线程数小于maximumPoolSize
(3)keepAliveTime: 线程空闲的存活时间,即当线程没有任务执行时,继续存活的时间,默认情况下,该参数只在线程数大于corePoolSize时才有用。
(4)workQueue: 必须是BlockingQueue阻塞队列,当线程池中的线程数超过它的corePoolSize的时候,线程会进入阻塞队列进行阻塞等待。
至此才能确定问题是由于springboot升级底层改变了异步回调线程的管理方式。
解决方案,其实我在都读代码的时候已经发现了:即继承WebMvcConfigureationSupport重载方法configureAsyncSupport设置异步回调的线程池或还是采用SimpleAsyncTaskExecutor
@Override public void configureAsyncSupport(final AsyncSupportConfigurer configurer) { configurer.setTaskExecutor(threadPoolTaskExecutor()); }
3. 总结
线程池的设置一直都是很重要的问题,而且大多数框架提供的默认线程池针对具体业务基本都是不合理的,顺便吐槽一下,springboot对task-[xx]的命名,没有体现线程池,应该起一个更具功能和意义的名字,比如async-threadpool-2-thread-[xx]