关于java:hikari连接池mysql连接空闲超8小时后自动断开问题

10次阅读

共计 12647 个字符，预计需要花费 32 分钟才能阅读完成。

MySQL 的默认设置下，当一个连贯的闲暇工夫超过 8 小时后，MySQL 就会断开该连贯，而 hikari 连接池则认为该被断开的连贯仍然无效。在这种状况下，如果客户端代码向 hikari 连接池申请连贯的话，连接池就会把曾经生效的连贯返回给客户端，客户端在应用该生效连贯的时候即抛出异样

The last packet successfully received from the server was 36,012 milliseconds ago. The last packet sent successfully to the server was 36,013 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.

-->>spring-boot-starter-batch-2.3.4
-->>spring-boot-starter-jdbc-2.3.4
--> 引入 hikari-3.4.5
<dependency>
  <groupId>com.zaxxer</groupId>
  <artifactId>HikariCP</artifactId>
  <version>3.4.5</version>
  <scope>compile</scope>
</dependency>

官网 https://github.com/brettwoold…

参数阐明：有参数 connectionTestQuery，没有 keepalivetime 工夫设置机制

connectionTestQuery
If your driver supports JDBC4 we strongly recommend not setting this property. This is for “legacy” drivers that do not support the JDBC4 Connection.isValid() API. This is the query that will be executed just before a connection is given to you from the pool to validate that the connection to the database is still alive. Again, try running the pool without this property, HikariCP will log an error if your driver is not JDBC4 compliant to let you know. Default: none

翻译大略就是。只有第一次获取连贯的时候才会有执行该 sql

解决方案 1: mysql 超时相干配置

show variables like "%time%"; 
-- 相干参数 (8 小时 60 *60*8) 单位秒 =28800
wait_timeout =35          (等待时间)
interactive_timeout  =35 (交互工夫)

解决办法 8 小时不够那就加长：(60 * 60 *24)
set interactive_timeout=86400;
set wait_timeout=86400;

解决方案 2：定期应用连接池内的连贯，使得它们不会因为闲置超时而被 MySQL 断开。应用中的连贯是不会被闲暇执行的。

也就是通过获取连贯之后 Thread.sleep 的形式是管不到的。验证 druid 的闲暇连贯办法也是同样的情理

# 一个连贯在池里闲置多久时会被摈弃
# 当 minimumIdle < maximumPoolSize 才失效
# 默认值 600000 ms，最小值为 10000 ms，0 示意禁用该性能。反对 JMX 动静批改
idleTimeout=600000

# 多久查看一次连贯的活性
# 查看时会先把连贯从池中拿进去（闲暇的话），而后调用 isValid() 或执行 connectionTestQuery 来校验活性，如果通过校验，则放回池里。# 默认 0（不启用），最小值为 30000 ms，必须小于 maxLifetime。反对 JMX 动静批改
keepaliveTime=0

# 当一个连贯存活了足够久，HikariCP 将会在它闲暇时把它摈弃
# 默认 1800000  ms，最小值为 30000 ms，0 示意禁用该性能。反对 JMX 动静批改
maxLifetime=1800000

# 用来查看连贯活性的 sql，要求是一个查问语句，罕用 select 'x'
# 如果驱动反对 JDBC4.0，倡议不设置，这时默认会调用  Connection.isValid() 来查看，该形式会更高效一些
# 默认为空
# connectionTestQuery=

# 池中至多要有多少闲暇连贯。# 当闲暇连贯 < minimumIdle，总连贯 < maximumPoolSize 时，将新增连贯
# 默认等于 maximumPoolSize。反对 JMX 动静批改
minimumIdle=5

外围代码逻辑：

# 初始化连接池
public HikariPool(final HikariConfig config)
   {super(config);

      this.connectionBag = new ConcurrentBag<>(this);
      this.suspendResumeLock = config.isAllowPoolSuspension() ? new SuspendResumeLock() : SuspendResumeLock.FAUX_LOCK;

      this.houseKeepingExecutorService = initializeHouseKeepingExecutorService();
      // 在外面创立连贯
      checkFailFast();
        /*** 省略其余逻辑 ***/
      this.houseKeeperTask = houseKeepingExecutorService.scheduleWithFixedDelay(new HouseKeeper(), 100L, housekeepingPeriodMs, MILLISECONDS);
        
   }
#
private void checkFailFast()
   {final long initializationTimeout = config.getInitializationFailTimeout();
      if (initializationTimeout < 0) {return;}

      final long startTime = currentTime();
      do {final PoolEntry poolEntry = createPoolEntry();
                     /*** 省略其余逻辑 ***/
          }
   }
# 创立池对象
private PoolEntry createPoolEntry()
   {
      try {final PoolEntry poolEntry = newPoolEntry();
            /*** 省略其余逻辑 ***/
         final long keepaliveTime = config.getKeepaliveTime();
         if (keepaliveTime > 0) {
            // variance up to 10% of the heartbeat time
            final long variance = ThreadLocalRandom.current().nextLong(keepaliveTime / 10);
            final long heartbeatTime = keepaliveTime - variance;
            // 定时执行
            poolEntry.setKeepalive(houseKeepingExecutorService.scheduleWithFixedDelay(new KeepaliveTask(poolEntry), heartbeatTime, heartbeatTime, MILLISECONDS));
         }

         return poolEntry;
      }
      catch (ConnectionSetupException e) { }
      return null;
   }
   
## 执行工作线程
private final class KeepaliveTask implements Runnable
   {
      private final PoolEntry poolEntry;

      KeepaliveTask(final PoolEntry poolEntry)
      {this.poolEntry = poolEntry;}

      public void run()
      {    
        
          // 要害判断 只判断是连接池种闲暇的连贯，曾经被标记为应用的连贯 不做判断
          // return poolEntry.compareAndSet(STATE_NOT_IN_USE, STATE_RESERVED);
          // 总共四种状态 
          //int STATE_NOT_IN_USE = 0;
        //int STATE_IN_USE = 1;
        //int STATE_REMOVED = -1;
        //int STATE_RESERVED = -2;
         if (connectionBag.reserve(poolEntry)) {if (!isConnectionAlive(poolEntry.connection)) {softEvictConnection(poolEntry, DEAD_CONNECTION_MESSAGE, true);
               addBagItem(connectionBag.getWaitingThreadCount());
            }
            else {connectionBag.unreserve(poolEntry);
               logger.debug("{} - keepalive: connection {} is alive", poolName, poolEntry.connection);
            }
         }
      }
   }

# 连贯什么时候状态被置为 STATE_IN_USE
public Connection getConnection(final long hardTimeout) throws SQLException
   {suspendResumeLock.acquire();
      final long startTime = currentTime();

      try {
         long timeout = hardTimeout;
         do {PoolEntry poolEntry = connectionBag.borrow(timeout, MILLISECONDS);
}
# borrow 标记办法
public T borrow(long timeout, final TimeUnit timeUnit) throws InterruptedException
   {
      try {for (T bagEntry : sharedList) {
             // 获取连贯 将连贯标记为 STATE_IN_USE
            if (bagEntry.compareAndSet(STATE_NOT_IN_USE, STATE_IN_USE)) {
               // If we may have stolen another waiter's connection, request another bag add.
               if (waiting > 1) {listener.addBagItem(waiting - 1);
               }
               return bagEntry;
            }
         }
      }
   }

配置代码：数据库 mysql 35s 超时

spring.datasource.driver-class-name=com.mysql.cj.jdbc.Driver
spring.datasource.url = jdbc:mysql://127.0.0.1:3306/uuid_task?autoReconnect=true&useUnicode=true&characterEncoding=utf-8&serverTimezone=GMT
spring.datasource.username = root
spring.datasource.password = root1234
spring.datasource.hikari.minimum-idle = 1
spring.datasource.hikari.maximum-pool-size=1
spring.datasource.hikari.auto-commit=false
spring.datasource.hikari.connection-timeout=10000
spring.datasource.hikari.max-lifetime = 650000
spring.datasource.hikari.idle-timeout = 650000
spring.datasource.hikari.validation-timeout = 300000
spring.datasource.hikari.connectionTestQuery = select 99 from dual
spring.datasource.hikari.keepaliveTime = 40000

@Test
    void hikariDataSourceSingleTestOne() {
        try {System.out.println("===================sleep=60s::"+new Date());
            Thread.sleep(60000);
            Connection connection =dataSource.getConnection();
            System.out.println("======connection==="+connection);
        } catch (Exception throwables) {throwables.printStackTrace();
        }
    }

hikari-4.0.1 keepalivetime=40s

===================sleep=36s::Tue May 10 16:11:49 CST 2022
2022-05-10 16:12:17.729 DEBUG 27580 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Pool stats (total=1, active=0, idle=1, waiting=0)
2022-05-10 16:12:17.730 DEBUG 27580 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2022-05-10 16:12:25.942 DEBUG 27580 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - keepalive: connection com.mysql.cj.jdbc.ConnectionImpl@28e19366 is alive
2022-05-10 16:12:47.741 DEBUG 27580 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Pool stats (total=1, active=0, idle=1, waiting=0)
2022-05-10 16:12:47.742 DEBUG 27580 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Fill pool skipped, pool is at sufficient level.
======connection===HikariProxyConnection@2079332573 wrapping com.mysql.cj.jdbc.ConnectionImpl@28e19366

hikari-4.0.1 keepalivetime=65s

===================sleep=36s::Tue May 10 16:18:42 CST 2022
2022-05-10 16:19:09.819 DEBUG 25464 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Pool stats (total=1, active=0, idle=1, waiting=0)
2022-05-10 16:19:09.819 DEBUG 25464 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2022-05-10 16:19:39.820 DEBUG 25464 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Pool stats (total=1, active=0, idle=1, waiting=0)
2022-05-10 16:19:39.821 DEBUG 25464 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2022-05-10 16:19:42.560  WARN 25464 --- [main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@5cb042da (Communications link failure

The last packet successfully received from the server was 60,704 milliseconds ago. The last packet sent successfully to the server was 60,715 milliseconds ago.). Possibly consider using a shorter maxLifetime value.
2022-05-10 16:19:42.561 DEBUG 25464 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Closing connection com.mysql.cj.jdbc.ConnectionImpl@5cb042da: (connection is dead)
2022-05-10 16:19:42.588 DEBUG 25464 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Closing connection com.mysql.cj.jdbc.ConnectionImpl@5cb042da failed

java.sql.SQLNonTransientConnectionException: Communications link failure during rollback(). Transaction resolution unknown.
    at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:110) ~[mysql-connector-java-8.0.21.jar:8.0.21]
    at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97) ~[mysql-connector-java-8.0.21.jar:8.0.21]
    at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:89) ~[mysql-connector-java-8.0.21.jar:8.0.21]
    at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:63) ~[mysql-connector-java-8.0.21.jar:8.0.21]
    at com.mysql.cj.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:1848) ~[mysql-connector-java-8.0.21.jar:8.0.21]
    at com.mysql.cj.jdbc.ConnectionImpl.realClose(ConnectionImpl.java:1705) ~[mysql-connector-java-8.0.21.jar:8.0.21]
    at com.mysql.cj.jdbc.ConnectionImpl.close(ConnectionImpl.java:721) ~[mysql-connector-java-8.0.21.jar:8.0.21]
    at com.zaxxer.hikari.pool.PoolBase.quietlyCloseConnection(PoolBase.java:143) ~[HikariCP-4.0.1.jar:na]
    at com.zaxxer.hikari.pool.HikariPool.lambda$closeConnection$1(HikariPool.java:451) [HikariCP-4.0.1.jar:na]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[na:1.8.0_301]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[na:1.8.0_301]
    at java.lang.Thread.run(Thread.java:748) ~[na:1.8.0_301]

2022-05-10 16:19:42.656 DEBUG 25464 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Added connection com.mysql.cj.jdbc.ConnectionImpl@175fb217
Tue May 10 16:19:42 CST 2022======connection===HikariProxyConnection@718781734 wrapping com.mysql.cj.jdbc.ConnectionImpl@175fb217

hikari-3.4.5

===================sleep=36s::Tue May 10 16:08:02 CST 2022
2022-05-10 16:08:30.769 DEBUG 4024 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Pool stats (total=1, active=0, idle=1, waiting=0)
2022-05-10 16:08:30.769 DEBUG 4024 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2022-05-10 16:09:00.776 DEBUG 4024 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Pool stats (total=1, active=0, idle=1, waiting=0)
2022-05-10 16:09:00.776 DEBUG 4024 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2022-05-10 16:09:02.662  WARN 4024 --- [main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@4726927c (Communications link failure

The last packet successfully received from the server was 60,303 milliseconds ago. The last packet sent successfully to the server was 60,305 milliseconds ago.). Possibly consider using a shorter maxLifetime value.
2022-05-10 16:09:02.664 DEBUG 4024 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Closing connection com.mysql.cj.jdbc.ConnectionImpl@4726927c: (connection is dead)
2022-05-10 16:09:02.674 DEBUG 4024 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Closing connection com.mysql.cj.jdbc.ConnectionImpl@4726927c failed

java.sql.SQLNonTransientConnectionException: Communications link failure during rollback(). Transaction resolution unknown.
    at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:110) ~[mysql-connector-java-8.0.21.jar:8.0.21]
    at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97) ~[mysql-connector-java-8.0.21.jar:8.0.21]
    at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:89) ~[mysql-connector-java-8.0.21.jar:8.0.21]
    at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:63) ~[mysql-connector-java-8.0.21.jar:8.0.21]
    at com.mysql.cj.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:1848) ~[mysql-connector-java-8.0.21.jar:8.0.21]
    at com.mysql.cj.jdbc.ConnectionImpl.realClose(ConnectionImpl.java:1705) ~[mysql-connector-java-8.0.21.jar:8.0.21]
    at com.mysql.cj.jdbc.ConnectionImpl.close(ConnectionImpl.java:721) ~[mysql-connector-java-8.0.21.jar:8.0.21]
    at com.zaxxer.hikari.pool.PoolBase.quietlyCloseConnection(PoolBase.java:143) ~[HikariCP-3.4.5.jar:na]
    at com.zaxxer.hikari.pool.HikariPool.lambda$closeConnection$1(HikariPool.java:451) [HikariCP-3.4.5.jar:na]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[na:1.8.0_301]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[na:1.8.0_301]
    at java.lang.Thread.run(Thread.java:748) ~[na:1.8.0_301]

======connection===HikariProxyConnection@2079332573 wrapping com.mysql.cj.jdbc.ConnectionImpl@77812b64
2022-05-10 16:09:02.717 DEBUG 4024 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Added connection com.mysql.cj.jdbc.ConnectionImpl@77812b64