升级springboot导致的业务异步回调积压问题定位

最新推荐文章于 2023-06-21 08:36:23 发布

weixin_30553065

最新推荐文章于 2023-06-21 08:36:23 发布

阅读量179

点赞数

文章标签： java

原文链接：http://www.cnblogs.com/lujiango/p/11435171.html

版权

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());
    }