问题

今天项目上频繁出现了大量的这样的报错

Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 6000ms.at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:695)at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:197)at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:162)at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128)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)... 75 more

百度了一下，很多都说需要把spring.datasource.hikari.connection-timeout的值调大就行。但是我们试了一下之后发现效果并不明显，然后我们调大了spring.datasource.hikari.maximum-pool-size的大小，这下有效果了。这是为什么呢?

排查

一直以来，我都以为这个报错是hikari连接数据库时，创建数据库连接超时抛出的异常，但是翻了一下抛出异常的源码之后发现并不是这样的，简单的贴一下代码：

public Connection getConnection(final long hardTimeout) throws SQLException{suspendResumeLock.acquire();final long startTime = currentTime();try {long timeout = hardTimeout;do {PoolEntry poolEntry = connectionBag.borrow(timeout, MILLISECONDS);if (poolEntry == null) {break; // We timed out... break and throw exception}final long now = currentTime();if (poolEntry.isMarkedEvicted() || (elapsedMillis(poolEntry.lastAccessed, now) > aliveBypassWindowMs && !isConnectionAlive(poolEntry.connection))) {closeConnection(poolEntry, poolEntry.isMarkedEvicted() ? EVICTED_CONNECTION_MESSAGE : DEAD_CONNECTION_MESSAGE);timeout = hardTimeout - elapsedMillis(startTime);}else {metricsTracker.recordBorrowStats(poolEntry, startTime);return poolEntry.createProxyConnection(leakTaskFactory.schedule(poolEntry), now);}} while (timeout > 0L);metricsTracker.recordBorrowTimeoutStats(startTime);throw createTimeoutException(startTime);}catch (InterruptedException e) {Thread.currentThread().interrupt();throw new SQLException(poolName + " - Interrupted during connection acquisition", e);}finally {suspendResumeLock.release();}}

里面的代码虽然没有细究，但是从意思上看，应该是如果在hardTimeout时间内没有从连接池中获取到有效的连接，那就抛出异常，而抛出的正是日志中大量打印的那个异常。

论证

从上面的源码中看，增加spring.datasource.hikari.connection-timeout的值应该确实是有效的，最起码可以降低异常率，但是总连接数依然不足，所以看起来的现象应该是日志中的报错少了，但是系统会卡的要命。增加spring.datasource.hikari.maximum-pool-size之后整个系统可用的最大连接数变多了，自然就不卡不报错了。

通过demo重现问题

为了验证我的想法，我写了一个demo
数据库相关配置文件：

#5个最小空闲连接，我把它理解为coreSize
spring.datasource.hikari.minimum-idle=5
#最大生命周期60s，测试用
spring.datasource.hikari.max-lifetime=60000
#一个连接空闲10s后，将会被回收
spring.datasource.hikari.idle-timeout=10
#连接池中的最大连接数
spring.datasource.hikari.maximum-pool-size=10
#获取连接的等待时长5s
spring.datasource.hikari.connection-timeout=5000
#判断连接是否有效
spring.datasource.hikari.connection-test-query=select 1

demo源码：

@SpringBootApplication(scanBasePackages = "com.example.juc.hikari")
public class Main {private static final Logger logger = LoggerFactory.getLogger(Main.class);public static void main(String[] args) {ConfigurableApplicationContext applicationContext = SpringApplication.run(Main.class, args);DataSource dataSource = applicationContext.getBean(DataSource.class);logger.info("{}", dataSource);//先获取10个连接，就获取，不释放int maxConnectionCount = 10;List<Connection> connections = new ArrayList<>();for (int i = 0; i < maxConnectionCount; i++) {try {Connection connection = dataSource.getConnection();connections.add(connection);} catch (SQLException e) {e.printStackTrace();}}//起一个新的Thread thread = new Thread(() -> {Connection connection = null;do {try {//开始尝试获取连接connection = dataSource.getConnection();} catch (SQLException e) {logger.error("连接获取失败:[{}]", e.getMessage());}//如果获取失败，就再来一次} while (connection == null);logger.info("获取到新的连接了！");try {connection.close();} catch (SQLException e) {e.printStackTrace();}logger.info("链接归还了！");}, "test");thread.start();try {logger.info("主线程休眠10s");TimeUnit.SECONDS.sleep(10);} catch (InterruptedException e) {e.printStackTrace();}//主线程休眠10秒之后，开始归还连接connections.forEach(connection -> {try {connection.close();logger.info("归还了");} catch (SQLException e) {e.printStackTrace();}});}
}

先看结论：

  .   ____          _            __ _ _/\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \\\/  ___)| |_)| | | | | || (_| |  ) ) ) )'  |____| .__|_| |_|_| |_\__, | / / / /=========|_|==============|___/=/_/_/_/:: Spring Boot ::                (v2.4.6)21:42:11.251 [main       ] INFO  c.e.j.h.Main - Starting Main using Java 1.8.0_261 on DESKTOP-5R7UHQH with PID 15948 (D:\code\myCode\out\production\classes started by w123x in D:\code\myCode)
21:42:11.253 [main       ] INFO  c.e.j.h.Main - No active profile set, falling back to default profiles: default
21:42:12.086 [main       ] INFO  o.s.b.w.e.t.TomcatWebServer - Tomcat initialized with port(s): 8080 (http)
21:42:12.092 [main       ] INFO  o.a.c.h.Http11NioProtocol - Initializing ProtocolHandler ["http-nio-8080"]
21:42:12.093 [main       ] INFO  o.a.c.c.StandardService - Starting service [Tomcat]
21:42:12.093 [main       ] INFO  o.a.c.c.StandardEngine - Starting Servlet engine: [Apache Tomcat/9.0.46]
21:42:12.164 [main       ] INFO  o.a.c.c.C.[.[.[/] - Initializing Spring embedded WebApplicationContext
21:42:12.165 [main       ] INFO  o.s.b.w.s.c.ServletWebServerApplicationContext - Root WebApplicationContext: initialization completed in 873 ms
21:42:12.453 [main       ] INFO  o.a.c.h.Http11NioProtocol - Starting ProtocolHandler ["http-nio-8080"]
21:42:12.467 [main       ] INFO  o.s.b.w.e.t.TomcatWebServer - Tomcat started on port(s): 8080 (http) with context path ''
21:42:12.474 [main       ] INFO  c.e.j.h.Main - Started Main in 1.581 seconds (JVM running for 2.601)
21:42:12.475 [main       ] INFO  c.e.j.h.Main - HikariDataSource (null)
21:42:12.476 [main       ] WARN  c.z.h.HikariConfig - HikariPool-1 - idleTimeout is less than 10000ms, setting to default 600000ms.
21:42:12.476 [main       ] INFO  c.z.h.HikariDataSource - HikariPool-1 - Starting...
21:42:12.595 [main       ] INFO  c.z.h.HikariDataSource - HikariPool-1 - Start completed.
21:42:12.636 [main       ] INFO  c.e.j.h.Main - 主线程休眠10s
21:42:17.640 [test       ] ERROR c.e.j.h.Main - 连接获取失败:[HikariPool-1 - Connection is not available, request timed out after 5003ms.]
21:42:22.647 [test       ] ERROR c.e.j.h.Main - 连接获取失败:[HikariPool-1 - Connection is not available, request timed out after 5006ms.]
21:42:22.650 [main       ] INFO  c.e.j.h.Main - 归还了
21:42:22.650 [main       ] INFO  c.e.j.h.Main - 归还了
21:42:22.650 [main       ] INFO  c.e.j.h.Main - 归还了
21:42:22.650 [main       ] INFO  c.e.j.h.Main - 归还了
21:42:22.650 [main       ] INFO  c.e.j.h.Main - 归还了
21:42:22.650 [main       ] INFO  c.e.j.h.Main - 归还了
21:42:22.650 [main       ] INFO  c.e.j.h.Main - 归还了
21:42:22.650 [main       ] INFO  c.e.j.h.Main - 归还了
21:42:22.650 [main       ] INFO  c.e.j.h.Main - 归还了
21:42:22.650 [main       ] INFO  c.e.j.h.Main - 归还了
21:42:22.650 [test       ] INFO  c.e.j.h.Main - 获取到新的连接了！
21:42:22.650 [test       ] INFO  c.e.j.h.Main - 链接归还了！

从日志看到test线程一开始确实没有获取到连接，每次获取连接的最大等待时长为spring.datasource.hikari.connection-timeout，也就是5秒，所以一共失败了2次。10秒之后，主线程开始归还连接，test线程就获取到连接了。

总结

这个报错跟spring.datasource.hikari.connection-timeout和spring.datasource.hikari.maximum-pool-size都有关系。
连接是一种非常宝贵的资源，获取到connection之后，马上就应该开始执行SQL，执行完SQL之后马上就应该close。一定要尽快归还connection，这样也不影响其他业务的操作。
同一个线程中多次getConnection，获取到的是不同的connection。
遇到问题不要紧张，不要乱猜，一定要看源码，看源码，硬着头皮看源码。

HikariPool-1 - Connection is not available, request timed out after 6000ms相关推荐

数据库连接异常: HikariPool-1 - Connection is not available, request timed out after 30000ms.
记一次生产环境数据库连接数导致的报错问题:Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConn ...
【解决】HikariPool-1 - Connection is not available, request timed out / Thread starvation or clock leap
问题描述:运行一个多线程程序,在一两小时不用的情况下,再执行mybatis的sql会报错.重启应用后正常,但也不是个事情. 错误日志如下: 2020-02-13 04:22:22.395 [Hikar ...
Pg报错: HikariPool-1 - Connection is not available, request timed out after 30040ms.问题处理
1. 问题背景数据批量入库时,报错:HikariPool-1 - Connection is not available, request timed out after 30040ms. 2. 问 ...
HikariPool-1 - Connection is not available, request timed out after 30000ms.
HikariPool是号称史上最快的数据库连接池,而且目前来看确实是这样的,SpringBoot2.0也已经采用HikariCP作为默认连接池配置. 近期项目也将druid切成了HikariPool, ...
Connection is not available, request timed out after xxxms. 超时异常 Hikari连接池配置说明
## 数据库配置 spring.datasource.type=com.zaxxer.hikari.HikariDataSource spring.datasource.driverClassName ...
Xcode的SVN提示The request timed out.的解决方案
问题描述在利用Xcode的SourceControl进行SVN代码检出时,确认输入地址.帐号密码都正确的情况下,总是提示"The request timed out.".该问题的 ...
Oracle 关于Pooled connection request timed out
发生场景: 系统异常卡死,报错: 通过查找日志和业务接口定位,是因为数据库连接池溢出导致链接不上,系统卡死异常测试代码如下格式: 测试了一个1000次的链接,每次连接都持续30秒,链接沾满了之后,后 ...
HikariPool 连接池问题
前言:今天在一个项目运行的时候发现一个很奇怪的问题,当我有一段时间无操作之后再进行插入操作的话,就会出现HikariPool相关的报错,在此记录一下问题 2022-02-20 13:14:04.17 ...
flowable exception during resetting expired jobs: Could not open JDBC Connection for transaction
项目中遇到的一个问题,记录一下:项目中引入flowable后,生产环境运行一段时间后,出现了奇怪的问题, [flowable-bpmn-reset-expired-jobs] org.flowable ...
ConnectionIsClosedException: No operations allowed after connection closed
最近生产上spring boot项目使用Hikari 数据源在一个用户信息查询操作数据库时总是报如题的错误.网上查看很多资料一直没有解决,但目前也没有什么好的办法,哪位大神给指导下. 报错信息如下: ...

HikariPool-1 - Connection is not available, request timed out after 6000ms

Connection is not available, request timed out after 6000ms

问题

排查

论证

通过demo重现问题

总结

HikariPool-1 - Connection is not available, request timed out after 6000ms相关推荐

最新文章

热门文章