胖虎的工具箱-编程导航 胖虎的工具箱-编程导航

HikariPool 连接池问题

2年前 (2022) 程序员胖胖胖虎阿
321 0 0

前言：今天在一个项目运行的时候发现一个很奇怪的问题，当我有一段时间无操作之后再进行插入操作的话，就会出现HikariPool相关的报错，在此记录一下

问题

2022-02-20 13:14:04.178  WARN 4012 --- [nio-8888-exec-6] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@4d500615 (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value.
2022-02-20 13:14:09.192  WARN 4012 --- [nio-8888-exec-6] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@3cf85fe2 (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value.
2022-02-20 13:14:14.202  WARN 4012 --- [nio-8888-exec-6] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@b4f2dcd (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value.
2022-02-20 13:14:19.220  WARN 4012 --- [nio-8888-exec-6] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@35b6e8f2 (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value.
2022-02-20 13:14:24.231  WARN 4012 --- [nio-8888-exec-6] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@1adb52ad (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value.
2022-02-20 13:14:29.237  WARN 4012 --- [nio-8888-exec-6] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@2e9842de (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value.
2022-02-20 13:14:29.243 ERROR 4012 --- [nio-8888-exec-6] c.g.d.h.ControllerExceptionHandler       : Request URL : /admin/blogs/10/input,Exception : {}

org.mybatis.spring.MyBatisSystemException: nested exception is org.apache.ibatis.exceptions.PersistenceException: 
### Error querying database.  Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30087ms.
### The error may exist in file [F:\Code\GithubRepository\MyBlog-MyBatis\demo1\target\classes\mapping\TypeDao.xml]
### The error may involve com.gcl.demo1.dao.TypeDao.findAllType
### The error occurred while executing a query
### Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30087ms.
	at org.mybatis.spring.MyBatisExceptionTranslator.translateExceptionIfPossible(MyBatisExceptionTranslator.java:96)
	at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:441)
	at com.sun.proxy.$Proxy80.selectList(Unknown Source)
	at org.mybatis.spring.SqlSessionTemplate.selectList(SqlSessionTemplate.java:224)
	at org.apache.ibatis.binding.MapperMethod.executeForMany(MapperMethod.java:147)
	at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:80)
	at org.apache.ibatis.binding.MapperProxy$PlainMethodInvoker.invoke(MapperProxy.java:145)
	at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:86)
	at com.sun.proxy.$Proxy86.findAllType(Unknown Source)
	at com.gcl.demo1.service.impl.TypeServiceImpl.listType(TypeServiceImpl.java:46)
	at com.gcl.demo1.service.impl.TypeServiceImpl$$FastClassBySpringCGLIB$$17f81c71.invoke(<generated>)
	at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
	at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:687)
	at com.gcl.demo1.service.impl.TypeServiceImpl$$EnhancerBySpringCGLIB$$ce851177.listType(<generated>)
	at com.gcl.demo1.controller.admin.BlogController.setTypeAndTag(BlogController.java:67)
	at com.gcl.demo1.controller.admin.BlogController.editInput(BlogController.java:73)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:197)
	at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:141)
	at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106)
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:893)
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:807)
	at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1061)
	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:961)
	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:626)
	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:733)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:374)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1590)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:748)
Caused by: org.apache.ibatis.exceptions.PersistenceException: 
### Error querying database.  Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30087ms.
### The error may exist in file [F:\Code\GithubRepository\MyBlog-MyBatis\demo1\target\classes\mapping\TypeDao.xml]
### The error may involve com.gcl.demo1.dao.TypeDao.findAllType
### The error occurred while executing a query
### Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30087ms.
	at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30)
	at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:153)
	at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:145)
	at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:140)
	at sun.reflect.GeneratedMethodAccessor101.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:427)
	... 64 common frames omitted
Caused by: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30087ms.
	at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:82)
	at org.mybatis.spring.transaction.SpringManagedTransaction.openConnection(SpringManagedTransaction.java:80)
	at org.mybatis.spring.transaction.SpringManagedTransaction.getConnection(SpringManagedTransaction.java:67)
	at org.apache.ibatis.executor.BaseExecutor.getConnection(BaseExecutor.java:337)
	at org.apache.ibatis.executor.SimpleExecutor.prepareStatement(SimpleExecutor.java:86)
	at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:62)
	at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:325)
	at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156)
	at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:109)
	at com.github.pagehelper.PageInterceptor.intercept(PageInterceptor.java:143)
	at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:62)
	at com.sun.proxy.$Proxy115.query(Unknown Source)
	at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:151)
	... 70 common frames omitted
Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30087ms.
	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)
	... 82 common frames omitted
Caused by: java.sql.SQLNonTransientConnectionException: No operations allowed after connection closed.
	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:110)
	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97)
	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:89)
	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:63)
	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:73)
	at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:73)
	at com.mysql.cj.jdbc.ConnectionImpl.setNetworkTimeout(ConnectionImpl.java:2498)
	at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:560)
	at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:173)
	at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:186)
	... 87 common frames omitted
Caused by: com.mysql.cj.exceptions.ConnectionIsClosedException: No operations allowed after connection closed.
	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
	at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:61)
	at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:105)
	at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:151)
	at com.mysql.cj.NativeSession.checkClosed(NativeSession.java:1171)
	at com.mysql.cj.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:576)
	at com.mysql.cj.jdbc.ConnectionImpl.setNetworkTimeout(ConnectionImpl.java:2494)
	... 90 common frames omitted

2022-02-20 13:14:29.244  WARN 4012 --- [nio-8888-exec-6] .m.m.a.ExceptionHandlerExceptionResolver : Resolved [org.mybatis.spring.MyBatisSystemException: nested exception is org.apache.ibatis.exceptions.PersistenceException: 
### Error querying database.  Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30087ms.
### The error may exist in file [F:\Code\GithubRepository\MyBlog-MyBatis\demo1\target\classes\mapping\TypeDao.xml]
### The error may involve com.gcl.demo1.dao.TypeDao.findAllType
### The error occurred while executing a query
### Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30087ms.]

问题描述：
腾讯云上 centos7 安装的 mysql 5.7.27，SpringBoot 使用 Hikaricp 连接池连接 MySQL。

项目启动，第一次连接成功初始化连接池，连接无问题，无任何操作大概10几分钟的样子，连接池的连接全部失效。

分析

在报错前出现过几个这样的警告：
HikariPool-1 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@73888329 (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value
验证连接 ConnectionImpl@73888329 失败(连接关闭后不允许操作)。 可能考虑使用更短的maxLifetime值。

然后报错原因是连接超时，Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30061ms.，也就是连接池里面的连接全都连接不上，最后导致连接超时。

我们先捋一捋连接池的原理
当我们使用连接池中的连接连接数据库的时候，连接池会建立一条新的连接，如下图：
HikariPool 连接池问题
这条新的连接原来就与数据库产生了连接，只是一直存放在连接池里面没有使用（因为频繁地创建和销毁连接是一个占用资源的活动）。

程序与连接池的连接有存活时长，连接池中的连接和数据库的连接当然也有存活时长，MySQL 闲置连接的超时时间由 wait_timeout 控制，默认是8小时，如下图：
HikariPool 连接池问题

这里我猜想是不是我们获取到的这条连接在数据库那里超时了，但是很快我就发现不是这样的。
HikariPool 连接池问题

我查询了一下数据库中的所有连接信息，发现连接时间最长的都远远没有8个小时（PS：这是我后面复现了一遍这个错误前查出来的数据）…

这里先说一下，SpringBoot 使用的默认连接池为 Hikari ，它也被称为速度最快的连接池，它的连接最大存活时间（max-lifetime）的默认值是30分钟。

HikariPool 连接池问题

问题出来了，上面提到过MySQL的连接超时时间是8个小时，怎么看30分钟都不可能大于8个小时啊！！！

网上也有人遇到相同的问题，但是他们只给出了解决方法——就是减少max-lifetime的时间，并没有给出问题发生的原因。

其中值得参考的有这个大佬的观点，maxLifeTime不仅要像HikariCP官方说的那样小于数据库的 wait_timeout，还要小于包括代理在内的所有介于数据库和业务应用之间其他代理的超时时间。（出处：HikariCP不断打印WARN日志Failed to validate connection com.mysql.jdbc.JDBC4Connection@xxxxx (…) Possibly consider using a shorter maxLifetime value.）

可是人家是因为有类似 Nginx 的网站代理，所以那个时间才出现了差错，而我是直接在 IDEA 连接远程数据库，按理说没啥问题才对。

然后我想了想，既然不是 MySQL 这里断开连接的，那会不会是网络传输过程中哪里的连接中断了，比如网络问题导致的连接中断，于是我顺着这个思路上网搜了搜，发现了这么一篇文章：阿里云安全组之静默丢包。

我看了后犹如醍醐灌顶，原因知道了，可能是云服务器那里的一些连接策略导致连接断开，所以才会导致虽然程序和数据库那里的连接都没有过期，但是程序就是连接不上这些连接（因为他们已经在网络传输的过程中被中断了）。

解决方法

解决方法很简单，设置更短的 maxLifeTime，如下：

spring:
  datasource:
    driver-class-name: com.mysql.cj.jdbc.Driver
    url: jdbc:mysql://xxx.xxx.xx.xxx:3306/myblog?useUnicode=true&characterEncoding=utf-8&allowMultiQueries=true
    username: xxxx
    password: xxxx
    hikari:
      connection-timeout: 60000   # 数据库连接超时时间,默认30秒,即30000
      validation-timeout: 3000    # 指定验证连接有效性的超时时间(默认是5秒,最小不能小于250毫秒)
      idle-timeout: 60000         # 空闲连接超时时间,一个连接idle状态的最大时长（毫秒）,超时则被释放（retired）,默认是10分钟,只有空闲连接数大于最大连接数且空闲时间超过该值,才会被释放
      login-timeout: 5            # 指定连接数据库的超时时间,单位:秒
      max-lifetime: 70000         # 指定连接池中连接的最大生存时间,单位:毫秒.默认是1800000,即30分钟
      maximum-pool-size: 30       # 指定连接池最大的连接数,包括使用中的和空闲的连接,默认值10
      minimum-idle: 10            # 指定连接维护的最小空闲连接数,当使用HikariCP时指定
      read-only: false            # 当使用Hikari connection pool时,是否标记数据源只读
  redis:
    database: 0
    host: xxx.xxx.xx.xxx
    port: 6379
    password: xxxxxxxx
    jedis:
      pool:
        max-idle: 8
        min-idle: 0
    timeout: 300

mybatis:
  mapper-locations: classpath:mapping/*Dao.xml
  type-aliases-package: com.gcl.demo1.entity

logging:
  level:
    root: info
    com.gcl: debug
  file:
    name: log/blog-dev.log

server:
  port: 8888
  servlet:
    session:
      timeout: 864000

后续

其实如果在服务器部署项目的话是不会遇到这个问题的，恰好我是在自己电脑远程连接服务器的数据库才遇到，也算一种缘分吧。

借鉴文章：

HikariCP不断打印WARN日志Failed to validate connection com.mysql.jdbc.JDBC4Connection@xxxxx (…) Possibly consider using a shorter maxLifetime value.

阿里云安全组之静默丢包

PS：也可以到我的个人博客查看更多内容
个人博客地址：小关同学的博客

版权声明：程序员胖胖胖虎阿 发表于 2022年9月14日 上午12:16。
转载请注明：HikariPool 连接池问题 | 胖虎的工具箱-编程导航

相关文章

面试题总结 —— JAVA高级工程师
程序员胖胖胖虎阿
299
windows/mac idea安装及 激活码(IDEA最新免费激活码,永久激活IDEA)
程序员胖胖胖虎阿
472
Intellij IDEA2022.2破解版(IDEA全新激活工具最新有效IDEA激活码)
程序员胖胖胖虎阿
345
IntelliJ IDEA2022.1破解教程(Intellij IDEA2022.2破解版激活至2099年)
程序员胖胖胖虎阿
303
IDEA2022破解插件(windows/mac idea最新破解方法绝对有效)
程序员胖胖胖虎阿
122
Intellij IDEA2022破解方法(IDEA最新版激活工具每日更新)
程序员胖胖胖虎阿
152

暂无评论

暂无评论...
致力于称为最好的程序员导航网站

友链申请 免责声明 关于我们

Copyright © 2022  胖虎的工具箱-编程导航   陇ICP备2022001249号