springboot hikari数据库连接池死链 出现异常_hikari the last packet successfully received from

最近系统间歇性很慢，比如登录，经常超时、无反应，查看log出现下述两种异常，
异常情况1

The last packet successfully received from the server was 995,202 milliseconds ago. The last packet sent successfully to the server was 995,202 milliseconds ago.
    at com.mysql.cj.jdbc.exceptions.SQLError.createCommunicationsException(SQLError.java:174)
    at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:64)
    at com.mysql.cj.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:2056)
    at com.zaxxer.hikari.pool.ProxyConnection.setAutoCommit(ProxyConnection.java:388)
    at com.zaxxer.hikari.pool.HikariProxyConnection.setAutoCommit(HikariProxyConnection.java)
    at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:284)
    ... 44 common frames omitted
1
2
3
4
5
6
7
8

异常情况2

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:2490)
    at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:550)
    at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:165)
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:179)
    ... 30 common frames omitted
1
2
3
4
5
6
7
8
9
10
11
12

异常情况3

2022-10-02 09:55:42.739  WARN 8280 --- [nio-8071-exec-4] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection com.mysql.cj.jdbc.ConnectionImpl@1a572671 (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value.
1

怀疑数据库链接存在死链，后端是springboot使用的默认数据库连接池hikari，配置如下

spring:
  datasource:
    driver: com.mysql.cj.jdbc.Driver
    url: jdbc:mysql://x.x.x.x:3306/dbname?useUnicode=true&characterEncoding=utf-8
    username: xx
    password: xxxx
    hikari:
      maximumPoolSize: 20
      maxLifetime: 60000
      minimumIdle: 10
      connectionTestQuery: SELECT 'x'
1
2
3
4
5
6
7
8
9
10
11

查看源码得知，com.zaxxer.hikari.pool.HikariPool#getConnection(long)获取连接时，判断连接是否存活，

com.zaxxer.hikari.pool.PoolBase#isConnectionAlive
boolean isConnectionAlive(final Connection connection)
 
     try {
        setNetworkTimeout(connection, validationTimeout);

        final int validationSeconds = (int) Math.max(1000L, validationTimeout) / 1000;
        //如果不配置connectionTestQuery，才会使用jdbc校验机制
        if (isUseJdbc4Validation) {
           return connection.isValid(validationSeconds);
        }
        //使用配置的ConnectionTestQuery来测试是否存活
        try (Statement statement = connection.createStatement()) {
               if (isNetworkTimeoutSupported != TRUE) {
                  setQueryTimeout(statement, validationSeconds);
               }

               statement.execute(config.getConnectionTestQuery());
            }
    }
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20

 com.zaxxer.hikari.pool.PoolBase#PoolBase
    PoolBase(final HikariConfig config)
   {
      this.config = config;
      this.isUseJdbc4Validation = config.getConnectionTestQuery() == null;
     
   }
   com.mysql.cj.jdbc.ConnectionImpl#isValid
   public boolean isValid(int timeout) throws SQLException {
        //发送心跳包
        pingInternal(false, timeout * 1000);
        return true;
        
    }
1
2
3
4
5
6
7
8
9
10
11
12
13
14

继续往下跟到了com.mysql.cj.protocol.a.NativeProtocol#sendCommand

public final NativePacketPayload sendCommand(Message queryPacket, boolean skipCheck, int timeoutMillis) {
    //发送心跳包，debug得知发送的十六进制0x0e,也就是数字14
    send(queryPacket, queryPacket.getPosition());

}
1
2
3
4
5

总结

至此真相大白，因为配置了connectionTestQuery，所以没有使用jdbc的校验机制，修改方法就是去掉connectionTestQuery，jdbc的校验机制是在获取连接时，校验合法性，比定时校验效率要高；
另外，jdbc的校验相比上层库校验效率更高，因为是tcp层的心跳包而不是mysql引擎解析的sql语句，所以druid、hikari层的校验可以去掉了。

• 因为防火墙等网络中间设备的存在，无论设置多大的存活时间，实际还会存在connection断掉的情况；
• 为了保证connection的有效性，通常会有两个措施，
  • 第一，使用链接前，check有效性，有两种实现方式
    • 使用jdbc的心跳机制，tcp层次的心跳包，不需要sql解析；即使connection不可用，没有输出异常信息，所以控制台或日志中看不到异常信息；使用这种方式日志上能干净些，校验的效率也能更高些；
    • 使用connection-test-query执行sql，比如select 1来保活；如果connection不可用会抛出异常，打印出异常，控制台或者日志中会看到；
  • 第二，定时check有效性Hikari的定时任务com.zaxxer.hikari.pool.HikariPool.KeepaliveTask，遍历所有connection来判断是否存活
• maxLifeTime，单位秒，通常要小于数据库的wait_timeout，我的情况是Mysql，如下show variables like '%wait_timeout%';
  

综上所述，可使用的配置

spring:
  datasource:
    driverClassName: com.mysql.cj.jdbc.Driver
    url: jdbc:mysql://xxxx:3306/databaseName?useUnicode=true&characterEncoding=utf-8
    username: xxx
    password: xxxx
    hikari:
      maximumPoolSize: 20
      # connection的最大存活时间,可以设置的时间长一些，这里设置的事30分钟
      maxLifeTime: 1800000
      # 获取connection时的超时时间，建议设置的时间短一些，最小1秒
      validation-timeout: 1000
      # 定时任务check链接存活性的间隔时间，这里设置的1分钟
      keepalive-time: 60000
1
2
3
4
5
6
7
8
9
10
11
12
13
14

参考

• what should be the Hikari maxLifetime for mysql wait_time out value 28800
• HikariCP - MYSQL No operations allowed after connection closed. Possibly consider using a shorter maxLifetime value
• Possibly consider using a shorter maxLifetime value - hikari connection pool spring boot