数据库连接报错CommunicationsException和Communications link failure

背景

    在做项目数据库迁移过程中发现数据库迁移后，服务正常启动，但是日志中出现错误日志，大致意思就是数据连接失败，心跳检测没有收到回应；

2024-05-15 12:29:52.365 | ERROR | 7 | nio-9090-exec-8 | com.alibaba.druid.pool.DruidDataSource :1849 | | discard connection

com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure

The last packet successfully received from the server was 4,191,705 milliseconds ago. The last packet sent successfully to the server was 1 milliseconds ago.
at com.mysql.cj.jdbc.exceptions.SQLError.createCommunicationsException(SQLError.java:172) ~[mysql-connector-java-8.0.11.jar!/:8.0.11]
at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:64) ~[mysql-connector-java-8.0.11.jar!/:8.0.11]
at com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:960) ~[mysql-connector-java-8.0.11.jar!/:8.0.11]
at com.mysql.cj.jdbc.ClientPreparedStatement.execute(ClientPreparedStatement.java:388) ~[mysql-connector-java-8.0.11.jar!/:8.0.11]
at com.alibaba.druid.pool.DruidPooledPreparedStatement.execute(DruidPooledPreparedStatement.java:497) ~[druid-1.1.22.jar!/:1.1.22]
at com.atomikos.jdbc.AtomikosXAPooledConnection.testUnderlyingConnection(AtomikosXAPooledConnection.java:104) [transactions-jdbc-4.0.6.jar!/:na]
at com.atomikos.datasource.pool.AbstractXPooledConnection.createConnectionProxy(AbstractXPooledConnection.java:55) [transactions-jta-4.0.6.jar!/:na]
at com.atomikos.datasource.pool.ConnectionPoolWithConcurrentValidation.concurrentlyTryToUse(ConnectionPoolWithConcurrentValidation.java:59) [transactions-jta-4.0.6.jar!/:na]
at com.atomikos.datasource.pool.ConnectionPoolWithConcurrentValidation.retrieveFirstAvailableConnection(ConnectionPoolWithConcurrentValidation.java:41) [transactions-jta-4.0.6.jar!/:na]
at com.atomikos.datasource.pool.ConnectionPool.retrieveFirstAvailableConnectionAndGrowPoolIfNecessary(ConnectionPool.java:156) [transactions-jta-4.0.6.jar!/:na]
at com.atomikos.datasource.pool.ConnectionPool.findOrWaitForAnAvailableConnection(ConnectionPool.java:141) [transactions-jta-4.0.6.jar!/:na]
at com.atomikos.datasource.pool.ConnectionPool.borrowConnection(ConnectionPool.java:132) [transactions-jta-4.0.6.jar!/:na]```

排查过程

• 当时以为数据库连接有问题，但是排查下来发现是可以正常查询的；
• 抓包查看数据库的收发都是正常的（tcpdump -i any -s 0 host xx.xx.xx and port xxxx），然后查看网络连接状态(netstat -anp | grep 3306)时发现数据库连接有一部分是处于close_wait的；
  由于项目是刚启动不久，而且连接池的存活时间也不小，不太可能是应用主动断开连接的，那么就怀疑是mysql断开连接的；
• 查询资料发现，mysql的配置有个wait_timeout参数，这个参数的值表示服务器关闭非交互连接的等待时间（跟这个参数比较接近的还有个interactive_timeout，感兴趣的可以自己去了解一下）；
• 登录数据库查询wait_timeout的值（show global variables like ‘wait_timeout’;），发现该值为600，默认其实是28800秒也就是8小时；这里数据库连接池配置的最大存活时间是20000秒，因此确实会存在数据库关闭了连接，但是应用没有发现，然后后续使用了该连接来进行查询，最后发现该连接已失效；

解决方法

• 第一种方法很简单，将wait_timeout值调大，这样mysql服务端就不会主动断开链接了，但是这里就是需要考虑资源的问题了，建议是将该值略大于数据库连接的最大存活时间；
• 第二种方法是设置spring.datasource.druid.goodsdb.testOnBorrow=true(可以搭配testWhileIdle使用)，这个表示每次拿取数据库连接使用前都进行检测，这样能保证使用的连接是有效的；