最近系统间歇性很慢,比如登录,经常超时、无反应,查看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
异常情况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
怀疑数据库链接存在死链,后端是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'
查看源码得知,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);
}
}
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;
}
继续往下跟到了com.mysql.cj.protocol.a.NativeProtocol#sendCommand
public final NativePacketPayload sendCommand(Message queryPacket, boolean skipCheck, int timeoutMillis) {
//发送心跳包,debug得知发送的十六进制0x0e,也就是数字14
send(queryPacket, queryPacket.getPosition());
}
总结
至此真相大白,因为配置了connectionTestQuery,所以没有使用jdbc的校验机制,修改方法就是去掉connectionTestQuery,jdbc的校验机制是在获取连接时,校验合法性,比定时校验效率要高;
另外,jdbc的校验相比上层库校验效率更高,因为是tcp层的心跳包而不是mysql引擎解析的sql语句,所以druid、hikari层的校验可以去掉了。