问题现象

日志出现如下关键信息:

Caused by: org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection
at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:48)
at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:109)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:136)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:254)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:262)
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:236)
at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:86)
at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:184)
at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:402)
… 38 common frames omitted
Caused by: java.sql.SQLTransientConnectionException: Hikari - Connection is not available, request timed out after 30000ms.
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.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122)
at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:35)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:106)
… 45 common frames omitted

如果配置了相关监控,
很有可能会发现激活连接数(Hikari.pool.ActiveConnections)等于或者接近于最大连接数(Hikari.pool.MaxConnections)

在这里插入图片描述

问题分析

根据以上信息,基本可以确定是由于数据库连接池中活跃连接太多,无法获取新的连接,超过了了指定的超时时间后报错。

如果你的系统访问并发并不大,使用jstack命令打印线程信息发现也没有线程处于数据库操作的状态,则很有可能是某一处代码获取连接后没有及时释放导致。

那么如何定位是哪里的代码导致的呢?

可以使用hikari提供的泄漏检测功能,配置如下参数:

spring.datasource.hikari.leak-detection-threshold=10000

添加该参数后,如果某个线程没有释放连接,在获取连接 10000 毫秒后,系统会以WARN级别打印线程堆栈,而且不影响主程序运行。可以准确判断是哪一处代码引起,如下所示:

在这里插入图片描述

该配置会有一定的性能损耗,问题排查解决后建议关闭配置

参考

聊聊hikari连接池的leakDetectionThreshold

What constitutes an “Active” connnection? #862

Logo

腾讯云面向开发者汇聚海量精品云计算使用和开发经验,营造开放的云计算技术生态圈。

更多推荐