问题描述临时解决办法根本原因
最近在压测springboot服务的是时候,遇到
HikariPool-1 - Interrupted during connection acquisition,先记录一下临时解决办法,后面有时间在review这个问题。
问题日志:
Caused by: org.apache.ibatis.exceptions.PersistenceException: ### Error querying database. Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLException: HikariPool-1 - Interrupted during connection acquisition ### The error may exist in URL [jar:file:/data/app.jar!/BOOT-INF/classes!/mapping/SessionDataMapper.xml] ### The error may involve com.geniuworks.bot.mapper.SessionDataMapper.selectById ### The error occurred while executing a query ### Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLException: HikariPool-1 - Interrupted during connection acquisition at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30) at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:149) at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:140) at org.apache.ibatis.session.defaults.DefaultSqlSession.selectOne(DefaultSqlSession.java:76) at jdk.internal.reflect.GeneratedMethodAccessor121.invoke(Unknown Source) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:567) at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:426) ... 125 more Caused by: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLException: HikariPool-1 - Interrupted during connection acquisition at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:82) at org.mybatis.spring.transaction.SpringManagedTransaction.openConnection(SpringManagedTransaction.java:80) at org.mybatis.spring.transaction.SpringManagedTransaction.getConnection(SpringManagedTransaction.java:67) at org.apache.ibatis.executor.baseExecutor.getConnection(baseExecutor.java:336) at com.baomidou.mybatisplus.core.executor.MybatisSimpleExecutor.prepareStatement(MybatisSimpleExecutor.java:93) at com.baomidou.mybatisplus.core.executor.MybatisSimpleExecutor.doQuery(MybatisSimpleExecutor.java:66) at org.apache.ibatis.executor.baseExecutor.queryFromDatabase(baseExecutor.java:324) at org.apache.ibatis.executor.baseExecutor.query(baseExecutor.java:156) at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:109) at com.github.pagehelper.PageInterceptor.intercept(PageInterceptor.java:143) at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:61) at jdk.proxy3/jdk.proxy3.$Proxy354.query(Unknown Source) at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:147) ... 131 more Caused by: java.sql.SQLException: HikariPool-1 - Interrupted during connection acquisition at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:201) at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:162) at com.zaxxer.hikari.HikariDataSource.getConnection$original$ll24d7XA(HikariDataSource.java:128) at com.zaxxer.hikari.HikariDataSource.getConnection$original$ll24d7XA$accessor$Ht7KSzci(HikariDataSource.java) at com.zaxxer.hikari.HikariDataSource$auxiliary$lqHwejmZ.call(Unknown Source) at org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.InstMethodsInter.intercept(InstMethodsInter.java:86) at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java) at org.springframework.jdbc.datasource.DataSourceUtils.fetchConnection(DataSourceUtils.java:158) at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:116) at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:79) ... 143 more Caused by: java.lang.InterruptedException at java.base/java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:940) at com.zaxxer.hikari.util.ConcurrentBag.borrow(ConcurrentBag.java:151) at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:180) ... 152 more
问题日志截图:
日志给出的原因:
HikariPool-1 - Interrupted during connection acquisition
jdbc的一个中间组件链接的时候被强制中断了。
导致压测百分之99.9的请求都失败了。
临时解决办法去掉了下面的线程池配置,配置如下:
@Configuration
@Slf4j
public class ThreadPoolConfig implements AsyncConfigurer {
private static final int cpuNum = Runtime.getRuntime().availableProcessors();
@Override
@Bean(name = "threadPoolTaskExecutor")
public Executor getAsyncExecutor() {
ThreadPoolTaskExecutor taskExecutor = new ThreadPoolTaskExecutor();
// 最小线程数(核心线程数)
taskExecutor.setCorePoolSize(cpuNum + 1);
// 最大线程数
taskExecutor.setMaxPoolSize(cpuNum * 2);
// 等待队列(队列最大长度)
taskExecutor.setQueueCapacity(1000);
// 等待时间
taskExecutor.setAwaitTerminationSeconds(300);
// 线程池维护线程所允许的空闲时间 ,单位s
taskExecutor.setKeepAliveSeconds(300);
// 线程池名称前缀
taskExecutor.setThreadNamePrefix("thread-pool-");
// 线程池对拒绝任务(无线程可用)的处理策略
taskExecutor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
taskExecutor.initialize();
log.info("线程池初始化完成...");
return taskExecutor;
}
@Override
public AsyncUncaughtExceptionHandler getAsyncUncaughtExceptionHandler() {
return new SpringAsyncExceptionHandler();
}
class SpringAsyncExceptionHandler implements AsyncUncaughtExceptionHandler {
@Override
public void handleUncaughtException(Throwable throwable, Method method, Object... obj) {
log.error("Exception occurs in async method", throwable.getMessage());
}
}
}
通过这个方法,可以使压测正常进行,且能预期的1000QPS。
根本原因目前只能大概推测,大量并发请求过来后,导致线程并发数量增加,但是因为cpu是一定的,会存在少数线程得不到响应。在超过一定时长后,被HikariPool组件认为是僵死线程,强制清理退出导致请求失败。
但具体为什么会产生这种原因,个人还是有点困惑,还需要进一步研究,最近手头工作比较忙,先记录一下,等闲的时候再review这个问题。



