经过长时间的I/O操作并发请求后，HikariPool连接不可用 [英] HikariPool connection not available after long I/o operation for concurrent request
问题描述
我最近开始在我的项目中出错，该项目调用第三方api，通常需要40秒.看起来来自hikaripool的数据库连接已被父线程劫持，无法用于其他并发请求
I recently started getting error on my project which calls a third party api which usually takes 40sec. Looks like db connection from hikaripool is hijacked by the parent thread and is not available for other concurrent requests
这是实施的概述
- 数据库插入(业务逻辑)
- 重新拨打电话(40秒)
- 数据库更新(业务逻辑)
一些高并发错误
java.sql.SQLTransientConnectionException:HikariPool-1-连接不可用，请求在30005ms后超时.
我试图在本地模仿，发现这些错误与生产相同
I tried to mimic this locally and found theses error same as production
Hikari配置
hikari:
maximumPoolSize: 2
idleTimeout: 60000
minimumIdle: 2
maxLifetime: 120000
leak-detection-threshold: 1000
模仿生产逻辑的服务方法
Service method to mimic the production logic
public void insertComment() throws InterruptedException {
Load load = new Load();
load.setComment("new comment "+System.currentTimeMillis());
repo.save(load);
Thread.sleep(60000); // mocking restemplate long i/o
load = new Load();
load.setComment("new comment "+System.currentTimeMillis());
repo.save(load);
}
现在向api发出3个并发请求(在hikari-cp + 1中为 2个连接)，调用此服务方法
Now firing 3 concurrent requests to api (2 connection in hikari-cp + 1) invoking this service method
堆栈跟踪-1
2021-01-01 22:50:01.309 WARN 6599 --- [l-1 housekeeper] com.zaxxer.hikari.pool.ProxyLeakTask : Connection leak detection triggered for com.mysql.jdbc.JDBC4Connection@462abec3 on thread http-nio-8080-exec-1, stack trace follows
java.lang.Exception: Apparent connection leak detected
at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128) ~[HikariCP-3.4.5.jar:na]
at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122) ~[hibernate-core-5.4.25.Final.jar:5.4.25.Final]
at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:38) ~[hibernate-core-5.4.25.Final.jar:5.4.25.Final]
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:108) ~[hibernate-core-5.4.25.Final.jar:5.4.25.Final]
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:138) ~[hibernate-core-5.4.25.Final.jar:5.4.25.Final]
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:273) ~[hibernate-core-5.4.25.Final.jar:5.4.25.Final]
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:281) ~[hibernate-core-5.4.25.Final.jar:5.4.25.Final]
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:246) ~[hibernate-core-5.4.25.Final.jar:5.4.25.Final]
at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:83) ~[hibernate-core-5.4.25.Final.jar:5.4.25.Final]
at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:164) ~[spring-orm-5.3.2.jar:5.3.2]
at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:421) ~[spring-orm-5.3.2.jar:5.3.2]
at org.springframework.transaction.support.AbstractPlatformTransactionManager.startTransaction(AbstractPlatformTransactionManager.java:400) ~[spring-tx-5.3.2.jar:5.3.2]
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373) ~[spring-tx-5.3.2.jar:5.3.2]
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:595) ~[spring-tx-5.3.2.jar:5.3.2]
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:382) ~[spring-tx-5.3.2.jar:5.3.2]
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119) ~[spring-tx-5.3.2.jar:5.3.2]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.2.jar:5.3.2]
at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:137) ~[spring-tx-5.3.2.jar:5.3.2]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.2.jar:5.3.2]
at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:174) ~[spring-data-jpa-2.4.2.jar:2.4.2]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.2.jar:5.3.2]
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97) ~[spring-aop-5.3.2.jar:5.3.2]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.2.jar:5.3.2]
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215) ~[spring-aop-5.3.2.jar:5.3.2]
at com.sun.proxy.$Proxy77.save(Unknown Source) ~[na:na]
at com.example.demo.Service.insertComment(Service.java:89) ~[classes/:na]
堆栈跟踪-2
java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30002ms.
at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:695) ~[HikariCP-3.4.5.jar:na]
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:197) ~[HikariCP-3.4.5.jar:na]
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:162) ~[HikariCP-3.4.5.jar:na]
at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128) ~[HikariCP-3.4.5.jar:na]
at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122) ~[hibernate-core-5.4.25.Final.jar:5.4.25.Final]
at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:38) ~[hibernate-core-5.4.25.Final.jar:5.4.25.Final]
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:108) ~[hibernate-core-5.4.25.Final.jar:5.4.25.Final]
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:138) ~[hibernate-core-5.4.25.Final.jar:5.4.25.Final]
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:273) ~[hibernate-core-5.4.25.Final.jar:5.4.25.Final]
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:281) ~[hibernate-core-5.4.25.Final.jar:5.4.25.Final]
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:246) ~[hibernate-core-5.4.25.Final.jar:5.4.25.Final]
at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:83) ~[hibernate-core-5.4.25.Final.jar:5.4.25.Final]
at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:164) ~[spring-orm-5.3.2.jar:5.3.2]
at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:421) ~[spring-orm-5.3.2.jar:5.3.2]
at org.springframework.transaction.support.AbstractPlatformTransactionManager.startTransaction(AbstractPlatformTransactionManager.java:400) ~[spring-tx-5.3.2.jar:5.3.2]
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373) ~[spring-tx-5.3.2.jar:5.3.2]
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:595) ~[spring-tx-5.3.2.jar:5.3.2]
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:382) ~[spring-tx-5.3.2.jar:5.3.2]
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119) ~[spring-tx-5.3.2.jar:5.3.2]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.2.jar:5.3.2]
at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:137) ~[spring-tx-5.3.2.jar:5.3.2]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.2.jar:5.3.2]
at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:174) ~[spring-data-jpa-2.4.2.jar:2.4.2]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.2.jar:5.3.2]
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97) ~[spring-aop-5.3.2.jar:5.3.2]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.2.jar:5.3.2]
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215) ~[spring-aop-5.3.2.jar:5.3.2]
at com.sun.proxy.$Proxy77.save(Unknown Source) ~[na:na]
at com.example.demo.Service.insertComment(Service.java:89) ~[classes/:na]
堆栈跟踪-3
2021-01-01 22:50:51.411 INFO 6599 --- [nio-8080-exec-1] com.zaxxer.hikari.pool.ProxyLeakTask : Previously reported leaked connection com.mysql.jdbc.JDBC4Connection@462abec3 on thread http-nio-8080-exec-1 was returned to the pool (unleaked)
如何处理这个问题?
找到了此帖.设置此配置 spring.jpa.open-in-view = false 似乎可以解决此问题.任何潜在客户对此配置所做的工作.安全吗?
Found this post. Setting this config spring.jpa.open-in-view=false seems to solve the issue. Any leads on what this config does. Is it safe?
推荐答案
您告诉过您:
一些高并发错误
您会得到:
java.sql.SQLTransientConnectionException:HikariPool-1-连接为不可用，请求在30005毫秒后超时.
java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30005ms.
这意味着数据库连接池(Hikari)未能在30秒内提供连接.
您将池的最大连接数配置为2:
That means that the DB connection pool (Hikari) didn't manage to provide a connection in 30 secs max.
You configured the max number of connection of the pool to 2 :
maximumPoolSize: 2
而且，如果查询的处理时间很长并且应用程序具有很高的并发性，那么该参数看起来确实被低估了.
将其增加到更大的数字，例如10或更多，然后观察行为.您也可以使用connectionTimeout参数，但是如果客户端请求等待连接，结果将减慢您的应用程序的运行速度.
It is few and moreover, if your queries are quite long processing and that your application has high concurrency, that parameter looks really under-estimate.
Increase it to a higher number such as 10 or more and watch the behavior.
You can also play with the connectionTimeout parameter but as a result, it will slow down your app if client requests wait for connection.
Hikari池大小文档可以为您提供一些有关调整配置的方式.
The Hikari pool size documentation could give you some information about the way to tweak the configuration.
作为替代方案，您可以重新考虑您的数据源.例如，定义两个数据源:一个用于长连接(用于长查询)，另一个用于排序连接(用于短查询)，并根据情况使用更合适的数据源.
As alternative, you could rethink your datasource. For example define two datasources : one for long connections (for long queries) and another one for sort connections (for short queries) and use the datasources that fits better according to the case.
作为旁注，Spring Boot提供了一个专注于数据源连接的执行器: DataSourceHealthIndicator ，用于检查是否可以获取与DataSource的连接.
结合使用监视系统工具(Prometheus或任何其他工具)，这些工具可能有助于诊断此类问题.
As a side note Spring Boot provides an actuator focused on datasource connections :
DataSourceHealthIndicator that checks that a connection to DataSource can be obtained.
Joined to a monitoring system tool (Prometheus or any other), these may be helpful to diagnostic that kind of issues.
这篇关于经过长时间的I/O操作并发请求后，HikariPool连接不可用的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！
