对并发请求进行长时间I/o操作后，HikariPool连接不可用

Question

我最近开始在我的项目上遇到错误，它调用第三方 api，通常需要 40 秒。看起来来自 hikaripool 的数据库连接被父线程劫持，不可用于其他并发请求

下面是实现的概述

1. DB插入（业务逻辑）
2. 恢复板调用（40秒）
3. DB更新（业务逻辑）

高并发的一些错误

java.sql.SQLTransient连接异常：HikariPool-1-连接不可用，请求在30005ms后超时。

我试图在本地模拟，发现这些错误与生产相同

光配置

hikari:
      maximumPoolSize: 2
      idleTimeout: 60000
      minimumIdle: 2
      maxLifetime: 120000
      leak-detection-threshold: 1000 

模拟生产逻辑的服务方法

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);
    }

编辑1:

现在向调用此服务方法的api（hikari cp 1中的2个连接）发出3个并发请求

堆栈跟踪-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)

如何处理这个问题？

编辑2：

找到这篇文章。设置此配置spring.jpa.open-in-view=false似乎可以解决问题。关于此配置的任何线索。它安全吗？

Answer 1

这是迟到的回复，但希望它能帮助其他人：

我的直觉是，如果您启用了OSIV过滤器(即，当< code > spring . JPA . open-in-view 为< code>true或未设置时),则会话对于整个流是打开的(持续40秒),并且仅在会话关闭后连接才返回到池。这样，如果有两个这样的流处于活动状态，那么在40秒内将没有其他逻辑可用的连接，这些连接将超时。

另一方面，如果您像以前一样禁用 OSIV，并且您没有跨越第一个和最后一个数据库操作之间的事务，则连接将在 40 秒Rest调用期间返回到池中。

请在此处查看Vlad对OSIV的精彩解释

Answer 2

您说过您已经:

高并发的一些错误

你会得到：

java.sql.SQLTransient连接异常：HikariPool-1-连接不可用，请求在30005ms后超时。

这意味着DB连接池（Hikari）无法在最多30秒内提供连接。
您将池的最大连接数配置为2：

  maximumPoolSize: 2

它很少，而且，如果您的查询处理时间很长，并且您的应用程序具有高并发性，则该参数看起来确实被低估了。< br >将它增加到更大的数字，如10或更大，并观察其行为。您也可以使用connectionTimeout参数，但结果是，如果客户端请求等待连接，它会降低您的应用程序的速度。

Hikari池大小文档可以为您提供有关调整配置方法的一些信息。

作为替代方案，您可以重新考虑数据源。例如，定义两个数据源：一个用于长连接（用于长查询），另一个用于排序连接（用于短查询），并根据情况使用更适合的数据源。

作为旁注，Spring Boot 提供了一个专注于数据源连接的执行器：DataSourceHealthIndicator，用于检查是否可以获得与数据源的连接。
加入监控系统工具（普罗米修斯或任何其他工具），这些可能有助于诊断此类问题。

Answer 3

您可以通过设置相应的属性来增加连接超时：

hikari:
  connectionTimeout: 60000        #30000 (or 30 sec) by default

但是，在这种情况下，最好不要在调用第三方API时保持连接，而是使用单独的连接进行DB调用。