记一次SpringBoot应用性能调优过程_springboot3.x性能调优

背景

使用SpringBoot、MyBatis-Plus开发一个接口转发的能，将第三方接口注册到平台中，由平台对外提供统一的地址，平台转发时记录接口的转发日志信息。开发完成后使用Jmeter进行性能测试，使用100个线程、持续压测180秒，测试结果如下，每秒仅支持8个并发。

服务器参数

优化过程

XSS拦截器

首先通过 jstack 命令查看下进程堆栈信息，并在堆栈信息中查询项目的包名，很快找到了几个拦截器的信息，拦截器如下

public class XssEscapeFilter implements Filter {

 public ServletInputStream getInputStream() throws IOException {
        BufferedReader br = new BufferedReader(new InputStreamReader(orgRequest.getInputStream()));
        String line = br.readLine();
        String result = "";
        while (line != null) {
            result += clean(line);
            line = br.readLine();
        }
        return new WrappedServletInputStream(new ByteArrayInputStream(result.getBytes()));
    }
}
...
1
2
3
4
5
6
7
8
9
10
11
12
13
14

该拦截器用于对请求的内容先解析成字符串、并对内容进行标签替换，然后在重新放入到流中，先把这个过滤器去除了, 去除后性能测试结果如下，达到了每秒42并发

HTTP连接池

接口转发时需要用到apache httpclient工具，于是找到了http设置连接池的方法，代码如下：

@Bean("closeableHttpClient")
public CloseableHttpClient closeableHttpClient() throws NoSuchAlgorithmException, KeyStoreException, KeyManagementException {
    try {
        //https 配置
        TrustStrategy acceptingTrustStrategy = (X509Certificate[] chain, String authType) -> true;
        SSLContext sslContext = org.apache.http.ssl.SSLContexts.custom()
                .loadTrustMaterial(null, acceptingTrustStrategy)
                .build();

        SSLConnectionSocketFactory csf = new SSLConnectionSocketFactory(sslContext
                , null, null, NoopHostnameVerifier.INSTANCE);

        Registry<ConnectionSocketFactory> registry = RegistryBuilder.<ConnectionSocketFactory>create()
                .register("http", PlainConnectionSocketFactory.getSocketFactory())
                .register("https", csf)
                .build();
        
        PoolingHttpClientConnectionManager connectionManager = new PoolingHttpClientConnectionManager(registry);
        // 最大连接数
        connectionManager.setMaxTotal(1000);
        // 路由链接数
        connectionManager.setDefaultMaxPerRoute(100);
        RequestConfig requestConfig = RequestConfig.custom()
                .setSocketTimeout(60000)
                .setConnectTimeout(60000)
                .setConnectionRequestTimeout(10000)
                .build();

        CloseableHttpClient httpClient = HttpClients.custom().setDefaultRequestConfig(requestConfig)
                .setConnectionManager(connectionManager)
                .evictExpiredConnections()
                .evictIdleConnections(300, TimeUnit.SECONDS)
                .build();
        log.info("初始化HttpClient成功,连接池配置:{}", httpConfig);

        Thread httpMonitorThread = new Thread(() -> {
            while (true) {
                final PoolStats poolStats = connectionManager.getTotalStats();
                log.info("等待个数: {} , 执行中个数: {} , 空闲个数: {} , 使用个数: {}/{}", poolStats.getPending(), poolStats.getLeased(), poolStats.getAvailable(), poolStats.getLeased() + poolStats.getAvailable(), poolStats.getMax());
                try {
                    TimeUnit.SECONDS.sleep(1);
                } catch (InterruptedException e) {
                    log.error(ExceptionUtils.getStackTrace(e));
                }
            }
        });
        httpMonitorThread.setName("httpMonitor");
        httpMonitorThread.start();
        return httpClient;
    } catch (Exception e) {
        log.error("初始化HttpClient失败", e);
        throw e;
    }
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54

通过监控发现HTTP没有出现等待连接情况

数据库连接池

平台使用的是Druid连接池，配置如下：

spring:
  datasource:
    druid:
      # 初始化时建立物理连接的个数，初始化发生在显示调用init方法，或者第一次getConnection时
      initial-size: 100
      # 最大连接池数量
      max-active: 1000
      # 最小连接池数量
      min-idle: 100
      # 获取连接时最大等待时间，单位毫秒；配置了maxWait之后，缺省启用公平锁，并发效率会有所下降，如果需要可以通过配置useUnfairLock属性为true来使用非公平锁。
      max-wait: 60000
      # 是否缓存preparedStatement，也就是PSCache。PSCache对支持游标的数据库性能提升巨大，比如说oracle。在mysql下建议关闭
      pool-prepared-statements: true
      # 要启用PSCache，必须配置大于0，当大于0时，poolPreparedStatements自动触发修改为true。在Druid中，不会存在Oracle下PSCache占用内存过多的问题，可以把这个数值配置大一些，比如说100
      max-pool-prepared-statement-per-connection-size: 20
      # 单位毫秒。有两个含义：一个是Destroy线程会检测连接的间隔时间，如果连接空闲时间大于等于minEvictableIdleTimeMillis则关闭物理连接；另一个是testWhileIdle的判断依据
      time-between-eviction-runs-millis: 60000
      min-evictable-idle-time-millis: 300000
      # 用来检测连接是否有效的sql
      validation-query: SELECT 1
      # 建议配置为true，不影响性能，并且保证安全性。申请连接的时候检测，如果空闲时间大于timeBetweenEvictionRunsMillis，执行validationQuery检测连接是否有效
      test-while-idle: true
      # 申请连接时执行validationQuery检测连接是否有效，做了这个配置会降低性能
      test-on-borrow: false
      # 归还连接时执行validationQuery检测连接是否有效，做了这个配置会降低性能。
      test-on-return: false
      filter:
        stat:
          log-slow-sql: false
          slow-sql-millis: 1000
          merge-sql: false
          enabled: true
        wall:
          config:
            multi-statement-allow: true
      stat-view-servlet:
        enabled: true
        url-pattern: /druid/*
        # 访问SQL监控页面时的登录用户名
        login-username: admin
        # 访问SQL监控页面时的登录密码
        login-password: admin
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42

这里的max-active 不要超过数据库的最大连接个数，通过show variables like '%max_connections%'; 命令可以查询数据库设置的最大连接个数

SQL查询改成缓存查询

每次转发前都需要到数据库进行信息查询，这里把数据库查询改为从JVM缓存查询，去除后性能测试结果如下，达到了每秒 315并发

Logback日志修改为异步打印

使用的logback日志框架，在进行接口转发时会进行日志的打印，在调整日志级别为ERROR时，发现TPS会增加很多，所以猜测和日志打印也有关系，经过查找资料发现，默认日志打印是同步的，可以使用异步打印来提升性能，修改如下

    <!-- 异步日志输出 -->
    <appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
        <appender-ref ref="FILE" />
        <!--    解决异步行号不输出问题    -->
        <includeCallerData>true</includeCallerData>
        <!--    日志队列大小，默认 256    -->
        <queueSize>1000</queueSize>
    </appender>
1
2
3
4
5
6
7
8

还有一个参数比上面的效果更好，就是在 Appender标签中添加 <immediateFlush>false</immediateFlush> ,当日志的大小达到8k后就会自动写入到日志文件中，带来的问题是没有办法实时查看打印的日志且默认8k的缓冲没有找到修改的办法。

日志异步存储数据库

接口转发时会记录日志方便后续进行问题查找，这里是在响应给客户端前会进行日志存储，是同步存储的，当把这个日志存储代码注释时发现TPS很快就达到了2000，所以猜测是由于存储缓慢导致了系统的TPS上不去，然后就利用SpringBoot的@Aync注解并结合线程池ThreadPoolTaskExecutor进行异步处理，线程池代码如下：

@Slf4j
@Configuration
public class LogSyncThreadPoolConfiguration {

    /**
     * 把springboot中的默认的异步线程线程池给覆盖掉。用ThreadPoolTaskExecutor来进行处理
     **/
    @Bean(name = "logThreadPoolTaskExecutor")
    public ThreadPoolTaskExecutor getThreadPoolTaskExecutor(ApiPlatFormConfig apiPlatFormConfig) {
        ThreadPoolConfig threadPool = apiPlatFormConfig.getThreadPool();
        ThreadPoolTaskExecutor threadPoolTaskExecutor = new ThreadPoolTaskExecutor();
        threadPoolTaskExecutor.setCorePoolSize(threadPool.getCorePoolSize());
        threadPoolTaskExecutor.setMaxPoolSize(threadPool.getMaxPoolSize());
        threadPoolTaskExecutor.setQueueCapacity(threadPool.getQueueCapacity());
        threadPoolTaskExecutor.setKeepAliveSeconds(threadPool.getKeepAliveSeconds());
        threadPoolTaskExecutor.setThreadNamePrefix(threadPool.getThreadNamePrefix());
        threadPoolTaskExecutor.setRejectedExecutionHandler(new ThreadPoolExecutor.AbortPolicy());
        threadPoolTaskExecutor.initialize();
        threadPoolTaskExecutor.setAllowCoreThreadTimeOut(true);
        if (threadPool.getMonitor()) {
            log.info("开启线程池监控");
            Thread threadPoolMonitor = new Thread(() -> {
                while (true) {
                    int poolSize = threadPoolTaskExecutor.getPoolSize();
                    int activeCount = threadPoolTaskExecutor.getActiveCount();
                    int queueSize = threadPoolTaskExecutor.getThreadPoolExecutor().getQueue().size();
                    long completedTaskCount = threadPoolTaskExecutor.getThreadPoolExecutor().getCompletedTaskCount();
                    log.info("【{}】线程池信息, 最大线程数: {}, 核心线程数: {}, 当前线程池大小: {}, 当前活动线程数: {}, 当前队列长度: {}/{}, 已完成任务个数: {}", threadPool.getThreadNamePrefix(), threadPool.getMaxPoolSize(), threadPool.getCorePoolSize(), poolSize, activeCount, queueSize, threadPool.getQueueCapacity(), completedTaskCount);
                    try {
                        TimeUnit.SECONDS.sleep(threadPool.getMonitorIntervalSeconds());
                    } catch (InterruptedException e) {
                        throw new RuntimeException(e);
                    }
                }
            });
            threadPoolMonitor.setName("监控线程");
            threadPoolMonitor.start();
        }
        return threadPoolTaskExecutor;
    }
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41

无论上述的线程池大小怎么调整，发现TPS的变化幅度不大，于是怀疑是不是数据库的性能不行，并对数据库进行了性能测试

数据库性能测试

将日志的插入语句拿出来当做测试案例，同样的使用 100个线程压测180秒，数据库插入性能如下，数据库支持每秒1300并发，所以程序还是有优化空间的

使用队列+批量提交

使用线程池虽然是异步了，但是始终是一条一条的往数据库中插入的，如果改为批量插入的话，应该会提高性能，所以将日志存储的地方修改为存储到队列中，这里使用LinkedBlockingQueue队列，并启动一个线程一直消费该队列，当消费的数量达到批量提交的个数时进行数据库插入，启动一个线程监控队列的消费情况，代码案例如下：

Thread logQueueMonitorThread = new Thread(() -> {
            long lastCount = 0;
            while (true) {
                long nowCount = count.get();
                log.info("队列当前积压数量:{} , 新增处理数: {} , SQL批量插入大小: {} ,  总处理数: {} , 总异常数: {}", QUEUE.size(), nowCount - lastCount, logQueueConfig.getSqlBatchSize(), nowCount, errorCounter.get());
                lastCount = nowCount;
                try {
                    TimeUnit.SECONDS.sleep(1);
                } catch (InterruptedException e) {
                    log.error(ExceptionUtils.getStackTrace(e));
                }
            }
        });
        logQueueMonitorThread.setName("logQueueMonitor");
        logQueueMonitorThread.start();
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15

经过测试发现TPS可以达到了1300左右，而且队列的积压个数没有明显的增长，一直小于批量提交的个数。

其他说明

在上面的机器中测试发现一个简单的SpringBoot应用，里面写一个测试接口直接返回固定字符串，性能接近20000TPS每秒，而平台也按照上述操作测试接口发现性能在3000TPS左右，性能损耗非常大，不知道是不是因为用了Shiro导致，后面会再进行单独的测试验证。