ANBOB™

最近一客户的应用日志随机会出现一些数据库源访问错误，中间件使用Caucho的连接池，数据库为MySQL 5.7主从，前端有HAproxy, 应用server多个，报错也不是持续性，再次重试可能会就正常，错误日志DataAccessException: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure，简单记录该问题。

应用日志

[2024/04/07 09:21:03] com.anbob.jdbc.DataAccessException: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet sent successfully to the server was 0 milliseconds ago. The driver has not received any packets from the server. <<<<<<<<< 0 milliseconds ago
 [2024/04/07 09:21:03] at com.anbob.jdbc.JdbcUtils.processException(JdbcUtils.java:187)
 [2024/04/07 09:21:03] at com.anbob.jdbc.JdbcTemplate.queryObject(JdbcTemplate.java:696)
 [2024/04/07 09:21:03] at com.anbob.jdbc.JdbcTemplate.queryInt(JdbcTemplate.java:618)
 [2024/04/07 09:21:03] at com.anbob.jdbc.JdbcTemplate.queryInt(JdbcTemplate.java:624)
 [2024/04/07 09:21:03] at com.anbob.tiger2017.service.portal.StatLoginDataService.saveStatLogin(StatLoginDataService.java:39)
 [2024/04/07 09:21:03] at com.anbob.tiger2017.service.admin.UserOnlineService$1.run(UserOnlineService.java:141)
 [2024/04/07 09:21:03] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
 [2024/04/07 09:21:03] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
 [2024/04/07 09:21:03] at java.lang.Thread.run(Thread.java:750)
 [2024/04/07 09:21:03] Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet sent successfully to the server was 0 milliseconds ago. The driver has not received any packets from the server.
 [2024/04/07 09:21:03] at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
 [2024/04/07 09:21:03] at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
 [2024/04/07 09:21:03] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
 [2024/04/07 09:21:03] at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
 [2024/04/07 09:21:03] at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
 [2024/04/07 09:21:03] at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:990)
 [2024/04/07 09:21:03] at com.mysql.jdbc.MysqlIO.readPacket(MysqlIO.java:632)
 [2024/04/07 09:21:03] at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:1016)
 [2024/04/07 09:21:03] at com.mysql.jdbc.ConnectionImpl.coreConnect(ConnectionImpl.java:2188)
 [2024/04/07 09:21:03] at com.mysql.jdbc.ConnectionImpl.connectOneTryOnly(ConnectionImpl.java:2219)
 [2024/04/07 09:21:03] at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2014)
 [2024/04/07 09:21:03] at com.mysql.jdbc.ConnectionImpl.(ConnectionImpl.java:776)
 [2024/04/07 09:21:03] at com.mysql.jdbc.JDBC4Connection.(JDBC4Connection.java:47)
 [2024/04/07 09:21:03] at sun.reflect.GeneratedConstructorAccessor91.newInstance(Unknown Source)
 [2024/04/07 09:21:03] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
 [2024/04/07 09:21:03] at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
 [2024/04/07 09:21:03] at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
 [2024/04/07 09:21:03] at com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:386)
 [2024/04/07 09:21:03] at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:330)
 [2024/04/07 09:21:03] at com.caucho.sql.DriverConfig.createDriverConnection(DriverConfig.java:709)
 [2024/04/07 09:21:03] at com.caucho.sql.ManagedConnectionImpl.initDriverConnection(ManagedConnectionImpl.java:280)
 [2024/04/07 09:21:03] at com.caucho.sql.ManagedConnectionImpl.(ManagedConnectionImpl.java:147)
 [2024/04/07 09:21:03] at com.caucho.sql.ManagedFactoryImpl.createManagedConnection(ManagedFactoryImpl.java:155)
 [2024/04/07 09:21:03] at com.caucho.env.dbpool.ConnectionPool.createConnection(ConnectionPool.java:1019)
 [2024/04/07 09:21:03] at com.caucho.env.dbpool.ConnectionPool.allocatePoolConnection(ConnectionPool.java:877)
 [2024/04/07 09:21:03] at com.caucho.env.dbpool.ConnectionPool.allocateConnection(ConnectionPool.java:741)
 [2024/04/07 09:21:03] at com.caucho.env.dbpool.ConnectionPool.allocateConnection(ConnectionPool.java:714)
 [2024/04/07 09:21:03] at com.caucho.sql.UserDataSource.getConnection(UserDataSource.java:75)
 [2024/04/07 09:21:03] at com.caucho.sql.DBPool.getConnection(DBPool.java:822)
 [2024/04/07 09:21:03] at com.anbob.jdbc.JdbcTemplate.queryObject(JdbcTemplate.java:687)
 [2024/04/07 09:21:03] ... 7 more
 [2024/04/07 09:21:03] Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
 [2024/04/07 09:21:03] at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3011)
 [2024/04/07 09:21:03] at com.mysql.jdbc.MysqlIO.readPacket(MysqlIO.java:567)
 [2024/04/07 09:21:03] ... 30 more
 [2024/04/07 09:21:31] java.sql.SQLException: No operations allowed after statement closed.

检查数据源配置
 -app xmlns="http://caucho.com/ns/resin">
<database>
 <jndi-name>idbc/DefaultDataSource</indi-name>
 <driver type"com.mysql.jdbc.Driver">
 <url>jdbc: mysql://188.*.37.*:3306/tiger2017_heb?characterEncoding=UTF -8&amp;useunicode=true&amp;useSSL=false</url>
 <user>root</user>
 <password>**************</password>
 </driver>
 <max-connections>60</max-connections>
</database>

这个错误通常意味着你的应用程序无法与MySQL服务器建立连接。

Diagnostic Steps

The following should be verified:
    1, the IP address or hostname in JDBC URL is correct
    2, the port number in the JDBC URL is correct
    3, the hostname in the JDBC URL is recognized by the local DNS server
    4, network connectivity is possible is possible between the host where JBoss is running and the host of the database server (e.g. test with ping)
    5, nothing is blocking connections (e.g. a firewall or proxy) between the host where JBoss is running and the database server host
    6, the database server is running
    7, the database server is accepting TCP/IP connections
    8, the database server is able to create new connections (e.g. use the mysql client to connect to the database server from the host where JBoss EAP is running)
         Confirm that applications are properly closing connections after use
         Confirm that the number of open connections reported by the database server is less than any configured limit for the database

客户开始怀疑是数据库参数配置timeout不合理，网上也有些介绍调整wait_timeout， 但是注意The last packet sent successfully to the server was 0 milliseconds ago判断这个connect一拿到就是无法连接的，而不是持续了多久以后timout超时，那种常见错误如Cause: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was 353,479,051 milliseconds ago.  可能是MySQL服务器默认的“wait_timeout”是28800秒即8小时，意味着如果一个连接的空闲时间超过8个小时，MySQL将自动断开该连接，而连接池却认为该连接还是有效的(因为并未校验连接的有效性)，当应用申请使用该连接时，就会导致上面的报错，这种情况是调整 wait_timeout和interactive_timeout。 一般连接池有探活机制，从池子中去connection会校验是否可用，我们检查一下Caucho连接池选项:

ping : If true, Resin will ping the database before returning a connection from the pool (if ping-interval is exceeded). default false.
ping-interval:   How often an idle connection should ping the database to ensure it is still valid.
ping-query:  A custom query used to ping the database connection.
ping-table:   A table used to ping the database connection.

注意，选项PING用于探测连接是否正常，但默认是false， 所以如果connection pool中如果没有探测有可能会因DB wait_timeout或网络层面等其它原因存在异常connect, 那就应用取connect就有可能选择了异常的而报上面的错误。

Solution:
Caucho增加ping.

打赏

微信扫一扫，打赏作者吧～