HikariPool-1 - Interrupted during connection acquisition
- 问题描述
- 临时解决办法
- 根本原因
最近在压测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的请求都失败了。
临时解决办法
去掉了下面的线程池配置,配置如下:
/**
* @Author dingws
* @PackageName geniubot_developer_service
* @Package com.geniuworks.bot.config
* @Date 2022/3/16 4:35 下午
* @Version 1.0
*/
@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;
}
/**
* 异步异常处理
*
* @return
*/
@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这个问题。