那些遇到过的问题

Spring Data JPA - 数据库问题连接不可用，请求在 30000 毫秒后超时

Kel*_*lyM 4 java hibernate spring-data-jpa spring-boot

我有一个非常典型的基于 Spring Boot 的 Web 应用程序，Spring Boot 版本 2.2.4，具有以下“启动器”：data-jpa、mail、security、web、thymeleaf。我使用 PostgreSQL 作为我的数据源和 Spring Session JDBC。该应用程序将正常运行几个小时，但最终会抛出与数据库连接相关的错误：

2020-02-07 02:36:42.891  WARN 14412 --- [https-jsse-nio-8445-exec-9] o.h.engine.jdbc.spi.SqlExceptionHelper   : SQL Error: 0, SQLState: null
2020-02-07 02:36:42.891 ERROR 14412 --- [https-jsse-nio-8445-exec-9] o.h.engine.jdbc.spi.SqlExceptionHelper   : HikariPool-1 - Connection is not available, request timed out after 30001ms.
2020-02-07 02:36:42.891 ERROR 14412 --- [https-jsse-nio-8445-exec-9] o.a.c.c.C.[.[.[.[dispatcherServlet]      : Servlet.service() for servlet [dispatcherServlet] threw exception
Run Code Online (Sandbox Code Playgroud)

完整的堆栈跟踪：

    2020-02-07 02:36:42.891  WARN 14412 --- [https-jsse-nio-8445-exec-9] o.h.engine.jdbc.spi.SqlExceptionHelper   : SQL Error: 0, SQLState: null
2020-02-07 02:36:42.891 ERROR 14412 --- [https-jsse-nio-8445-exec-9] o.h.engine.jdbc.spi.SqlExceptionHelper   : HikariPool-1 - Connection is not available, request timed out after 30001ms.
2020-02-07 02:36:42.891 ERROR 14412 --- [https-jsse-nio-8445-exec-9] o.a.c.c.C.[.[.[.[dispatcherServlet]      : Servlet.service() for servlet [dispatcherServlet] threw exception

org.springframework.transaction.CannotCreateTransactionException: Could not open JPA EntityManager for transaction; nested exception is org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection
    at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:448) ~[spring-orm-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:376) ~[spring-tx-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
    at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:137) ~[spring-tx-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
    at org.springframework.session.jdbc.JdbcIndexedSessionRepository.findById(JdbcIndexedSessionRepository.java:414) ~[spring-session-jdbc-2.2.0.RELEASE.jar!/:2.2.0.RELEASE]
    at org.springframework.session.jdbc.JdbcIndexedSessionRepository.findById(JdbcIndexedSessionRepository.java:130) ~[spring-session-jdbc-2.2.0.RELEASE.jar!/:2.2.0.RELEASE]
    at org.springframework.session.web.http.SessionRepositoryFilter$SessionRepositoryRequestWrapper.getRequestedSession(SessionRepositoryFilter.java:351) ~[spring-session-core-2.2.0.RELEASE.jar!/:2.2.0.RELEASE]
    at org.springframework.session.web.http.SessionRepositoryFilter$SessionRepositoryRequestWrapper.getSession(SessionRepositoryFilter.java:289) ~[spring-session-core-2.2.0.RELEASE.jar!/:2.2.0.RELEASE]
    at org.springframework.session.web.http.SessionRepositoryFilter$SessionRepositoryRequestWrapper.getSession(SessionRepositoryFilter.java:192) ~[spring-session-core-2.2.0.RELEASE.jar!/:2.2.0.RELEASE]
    at javax.servlet.http.HttpServletRequestWrapper.getSession(HttpServletRequestWrapper.java:244) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.springframework.security.web.savedrequest.HttpSessionRequestCache.getRequest(HttpSessionRequestCache.java:71) ~[spring-security-web-5.2.1.RELEASE.jar!/:5.2.1.RELEASE]
    at org.springframework.security.web.savedrequest.HttpSessionRequestCache.getMatchingRequest(HttpSessionRequestCache.java:92) ~[spring-security-web-5.2.1.RELEASE.jar!/:5.2.1.RELEASE]
    at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:60) ~[spring-security-web-5.2.1.RELEASE.jar!/:5.2.1.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) ~[spring-security-web-5.2.1.RELEASE.jar!/:5.2.1.RELEASE]
    at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:200) ~[spring-security-web-5.2.1.RELEASE.jar!/:5.2.1.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) ~[spring-security-web-5.2.1.RELEASE.jar!/:5.2.1.RELEASE]
    at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:116) ~[spring-security-web-5.2.1.RELEASE.jar!/:5.2.1.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) ~[spring-security-web-5.2.1.RELEASE.jar!/:5.2.1.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:103) ~[spring-web-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) ~[spring-security-web-5.2.1.RELEASE.jar!/:5.2.1.RELEASE]
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:82) ~[spring-security-web-5.2.1.RELEASE.jar!/:5.2.1.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) ~[spring-security-web-5.2.1.RELEASE.jar!/:5.2.1.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:103) ~[spring-web-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) ~[spring-security-web-5.2.1.RELEASE.jar!/:5.2.1.RELEASE]
    at com.midamcorp.team.config.SimpleCORSFilter.doFilter(SimpleCORSFilter.java:43) ~[classes!/:na]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) ~[spring-security-web-5.2.1.RELEASE.jar!/:5.2.1.RELEASE]
    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:215) ~[spring-security-web-5.2.1.RELEASE.jar!/:5.2.1.RELEASE]
    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:178) ~[spring-security-web-5.2.1.RELEASE.jar!/:5.2.1.RELEASE]
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:358) ~[spring-web-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:271) ~[spring-web-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.springframework.session.web.http.SessionRepositoryFilter.doFilterInternal(SessionRepositoryFilter.java:141) ~[spring-session-core-2.2.0.RELEASE.jar!/:2.2.0.RELEASE]
    at org.springframework.session.web.http.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:82) ~[spring-session-core-2.2.0.RELEASE.jar!/:2.2.0.RELEASE]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:712) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:461) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:384) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:312) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.catalina.core.StandardHostValve.custom(StandardHostValve.java:394) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.catalina.core.StandardHostValve.status(StandardHostValve.java:253) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.catalina.core.StandardHostValve.throwable(StandardHostValve.java:348) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:173) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:367) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:860) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1598) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na]
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-9.0.30.jar!/:9.0.30]
    at java.base/java.lang.Thread.run(Thread.java:834) ~[na:na]
Caused by: org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection
    at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:48) ~[hibernate-core-5.4.10.Final.jar!/:5.4.10.Final]
    at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42) ~[hibernate-core-5.4.10.Final.jar!/:5.4.10.Final]
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113) ~[hibernate-core-5.4.10.Final.jar!/:5.4.10.Final]
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99) ~[hibernate-core-5.4.10.Final.jar!/:5.4.10.Final]
    at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:107) ~[hibernate-core-5.4.10.Final.jar!/:5.4.10.Final]
    at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:134) ~[hibernate-core-5.4.10.Final.jar!/:5.4.10.Final]
    at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:250) ~[hibernate-core-5.4.10.Final.jar!/:5.4.10.Final]
    at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:258) ~[hibernate-core-5.4.10.Final.jar!/:5.4.10.Final]
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:246) ~[hibernate-core-5.4.10.Final.jar!/:5.4.10.Final]
    at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:83) ~[hibernate-core-5.4.10.Final.jar!/:5.4.10.Final]
    at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:184) ~[spring-orm-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
    at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:402) ~[spring-orm-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
    ... 54 common frames omitted
Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30001ms.
    at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:689) ~[HikariCP-3.4.2.jar!/:na]
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:196) ~[HikariCP-3.4.2.jar!/:na]
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:161) ~[HikariCP-3.4.2.jar!/:na]
    at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128) ~[HikariCP-3.4.2.jar!/:na]
    at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122) ~[hibernate-core-5.4.10.Final.jar!/:5.4.10.Final]
    at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:38) ~[hibernate-core-5.4.10.Final.jar!/:5.4.10.Final]
    at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:104) ~[hibernate-core-5.4.10.Final.jar!/:5.4.10.Final]
    ... 61 common frames omitted
Run Code Online (Sandbox Code Playgroud)

我的 application.properties 中的数据库相关属性：

primary.datasource.url=jdbc:postgresql://localhost:5432/main
primary.datasource.username=xxx
primary.datasource.password=xxx

spring.session.store-type=jdbc
session.datasource.url=jdbc:postgresql://localhost:5432/session
session.datasource.driverClassName=org.postgresql.Driver
session.datasource.username=xxx
session.datasource.password=xxx
Run Code Online (Sandbox Code Playgroud)

数据库配置：

@Configuration
@EnableTransactionManagement
public class DatabaseConfig {

    @Bean
    @Primary
    @ConfigurationProperties("primary.datasource")
    public DataSourceProperties primaryDataSourceProperties() {
        return new DataSourceProperties();
    }

    @Bean
    @Primary
    public DataSource primaryDataSource() {
        return primaryDataSourceProperties().initializeDataSourceBuilder().type(HikariDataSource.class).build();
    }

    @Bean
    @ConfigurationProperties("session.datasource")
    public DataSourceProperties sessionDataSourceProperties() {
        return new DataSourceProperties();
    }

    @Bean
    @SpringSessionDataSource
    public DataSource springSessionDataSource() {
        return sessionDataSourceProperties().initializeDataSourceBuilder().type(HikariDataSource.class).build();
    }
}
Run Code Online (Sandbox Code Playgroud)

这个应用程序的结构与我之前构建的许多应用程序类似，但我从未遇到过这个问题。该应用程序已投入生产一段时间，并未遇到该问题。这种情况大约在一个月前开始，但变得越来越频繁。该应用程序定期更新，但很长一段时间没有对数据库逻辑进行更新。另一个应用程序联系同一个数据库，但没有遇到此问题。数据库中的日志没有显示任何错误。

任何指示将不胜感激。老实说，我有点不知所措。我设置了logging.level.com.zaxxer.hikari=DEBUGand logging.level.org.hibernate=INFO（调试产生了太多与问题无关的输出）希望它可以帮助我跟踪问题，但没有成功。具有这些级别的完整堆栈如上所示。

Chr*_*ory 8

发生的情况是您的应用程序试图从池中获取数据库连接，并且在 30 秒（默认值）后超时，因为没有更多连接可用（它们都在使用中）。

您是为 Hikari 设置这些值中的任何一个还是仅接受默认值？

datasource:
  hikari:
    connection-init-sql: SELECT 1
    connection-test-query: SELECT 1
    auto-commit: true
    connection-timeout: 3000
    idle-timeout: 600000
    leak-detection-threshold: 45000
    max-lifetime: 1800000
    maximum-pool-size: 10
    validation-timeout: 5000
Run Code Online (Sandbox Code Playgroud)

为了找到你的问题，我建议你做两件事：

  1. 打开 Leak Detection:leak-detection-threshold: 45000这将打印出这样的日志语句：
2020-02-07 18:16:26,100 WARN HikariPool-1 housekeeper ProxyLeakTask.? - Connection leak detection triggered for org.postgresql.jdbc.PgConnection@2dda7a8e on thread https-jsse-nio-8458-exec-11, stack trace follows
java.lang.Exception: Apparent connection leak detected
 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:38)
 at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:104)
 at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:134)
 at org.hibernate.internal.SessionImpl.connection(SessionImpl.java:462)
 at jdk.internal.reflect.GeneratedMethodAccessor206.invoke(Unknown Source)
 at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
 at java.base/java.lang.reflect.Method.invoke(Method.java:566)
 at org.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:282)
 at org.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:266)
 at org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle.doGetConnection(HibernateJpaDialect.java:430)
 at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:174)
 at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:402)
 at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:376)
 at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:572)
...
Run Code Online (Sandbox Code Playgroud)

这将告诉您在应用程序中的哪个位置保持连接超过 45 秒的进程。如果需要，您可以更改为 30。

  1. 在您的记录器中启用此调试：
    logging:
      level:
        com.zaxxer.hikari.pool.HikariPool: DEBUG
Run Code Online (Sandbox Code Playgroud)

它会经常记录这样的语句：

2020-02-07 04:17:38,798 DEBUG HikariPool-1 housekeeper HikariPool.logPoolState - HikariPool-1 - Pool stats (total=10, active=1, idle=9, waiting=0)
Run Code Online (Sandbox Code Playgroud)

当 active 等于总数时，您知道您的池已被充分使用，您将开始看到等待人数上升。基本上，此时您需要任何泄漏连接的进程来放弃连接或重新启动您的应用程序。否则，您将开始看到这些错误。

另外值得注意的是，等待连接超时的时间为 30 秒（默认值）。如果这是来自网页的请求，请记住有一个实际用户在等待 30 秒（大多数人太不耐烦而无法等待那么长时间）以等待某事发生。正如您在我们的应用程序中看到的，我们将其设置为 3000 毫秒（或 3 秒）。

归档时间：

查看次数：

6482 次

最近记录：

6 年，7 月 前
相关归档
如何使用JSP/Servlet将文件上传到服务器？ 671
我使用@SuppressWarnings来抑制"可以私有"警告的价值是多少？ 61
RestRepositoryResource的自动配置 10
将本地 React 前端连接到本地 Spring Boot 中间件应用程序时出现 CORS 错误 7
带有 swagger UI 的 Spring Boot 提供空页面 6
如何在.yml文件中使用Property占位符 6
通过 Java/Spring Boot 连接 Docker Elasticsearch 实例 6
Spring Data JPA 和 MyBatis 5
SpringBoot:无法使用2.0.0-M3创建完全可执行的jar 5
Spring Kafka 和 Spring Integration Kafka 的区别 5
难疑归档
event.preventDefault()与return false 2891
提高SQLite的每秒INSERT性能？ 2880
如何在Git中更改多个提交的作者和提交者名称以及电子邮件？ 2282
如何计算C#中某人的年龄？ 1754
在PostgreSQL中显示表格 1703
如何避免JSP文件中的Java代码？ 1649
你如何合并两个Git存储库？ 1517
使用jQuery作为JS对象向select中添加选项的最佳方法是什么？ 1340
如何将包含文件的文件夹复制到Unix/Linux中的另一个文件夹？ 1145
在HTML中嵌入PDF的推荐方法？ 1128