一、背景

测试对http接口进行压测，压测请求并发数为300，每隔1秒进行持续加压直至1200。压测端发现，有20%~30%的请求被超时丢弃，大多数的接口耗时也都远大于3秒，换句话说，服务端的这个接口只有80左右。

服务端有两个节点，内存3.8g，cpu核数为2。接口的QPS和响应时间见下：

image.png

二、接口耗时分析

在压测时间段，接口的耗时最大有3.9秒之多，借助apm工具，进一步分析慢在哪里。

image.png image.png

和接口紧密相关的业务处理耗时只有388毫秒，但是三个异步任务原本应该是并行的，这里都变成了串行执行。

• 源码分析：

  
  image.png
  

  在接口上增加注解@Async，然后定义线程池"async-event-executor"

    @Bean("async-event-executor")
    public AsyncTaskExecutor eventExecutor() {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        executor.setCorePoolSize(4);
        executor.setMaxPoolSize(8);
        executor.setQueueCapacity(2000);
        executor.setKeepAliveSeconds(60);
        executor.setThreadNamePrefix("async-event-executor-");
        executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
        executor.initialize();
        return executor;
    }

串行执行的原因总结

• 当线程池的拒绝策略是CallerRunsPolicy() ，线程池的队列和最大线程数已满后,谁把任务给线程池的,就谁去执行。 也即undertow工作线程扔给线程池，因此不会交由线程池的线程去执行，不抛异常，而是调用者自己的线程串行执行。

三、线程池监控

image.png image.png

可以看到，线程的耗时非常大，线程池的压力非常大。

• 这里还可以接入Metrics，由Prometheus拉取线程池的指标，让grafana展示。

四、JVM监控

这里看到的是gc，包括young gc和full gc的次数剧增，申请的堆内存过大。

堆内存.png gc次数.png gc耗时.png

总结：这里能够解释，为什么redis和Mongodb都没有慢查询，而apm接口中的慢接口分析中，和它们的交互却很慢。

五、改进意见

• 1、线程池隔离，把不同的业务适用到多个线程池。

• 2、流量消峰，使用mq替代java线程池。

• 3、监控手段，实时分析线程池的队列积压。除了文中说的prometheus+grafana外， 还可以使用dynamic-tp等开源组件。