前言
不想看原因的可直接前往点击解决方案查看解决办法(简单到不能再简单)
当sql执行时间超过10秒后会出现The last packet successfully received from the server was 10,018 milliseconds ago
项目技术栈是:springboot项目使用druid数据库连接池,同时又使用了动态数据源(不使用也可使用此方法解决)
错误信息
The last packet successfully received from the server was 10,018 milliseconds ago. The last packet sent successfully to the server was 10,001 milliseconds ago.
at sun.reflect.GeneratedConstructorAccessor521.newInstance(Unknown Source) ~[na:na]
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source) ~[na:1.8.0_40]
at java.lang.reflect.Constructor.newInstance(Unknown Source) ~[na:1.8.0_40]
at com.mysql.jdbc.Util.handleNewInstance(Util.java:403) ~[mysql-connector-java-5.1.49.jar!/:5.1.49]
at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:990) ~[mysql-connector-java-5.1.49.jar!/:5.1.49]
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3517) ~[mysql-connector-java-5.1.49.jar!/:5.1.49]
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3417) ~[mysql-connector-java-5.1.49.jar!/:5.1.49]
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3860) ~[mysql-connector-java-5.1.49.jar!/:5.1.49]
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2524) ~[mysql-connector-java-5.1.49.jar!/:5.1.49]
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2675) ~[mysql-connector-java-5.1.49.jar!/:5.1.49]
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2465) ~[mysql-connector-java-5.1.49.jar!/:5.1.49]
at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1915) ~[mysql-connector-java-5.1.49.jar!/:5.1.49]
at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:1254) ~[mysql-connector-java-5.1.49.jar!/:5.1.49]
at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_execute(FilterChainImpl.java:3446) ~[druid-1.2.15.jar!/:na]
at com.alibaba.druid.filter.FilterEventAdapter.preparedStatement_execute(FilterEventAdapter.java:434) ~[druid-1.2.15.jar!/:na]
at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_execute(FilterChainImpl.java:3444) ~[druid-1.2.15.jar!/:na]
at com.alibaba.druid.proxy.jdbc.PreparedStatementProxyImpl.execute(PreparedStatementProxyImpl.java:152) ~[druid-1.2.15.jar!/:na]
at com.alibaba.druid.pool.DruidPooledPreparedStatement.execute(DruidPooledPreparedStatement.java:483) ~[druid-1.2.15.jar!/:na]
at sun.reflect.GeneratedMethodAccessor306.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:1.8.0_40]
at java.lang.reflect.Method.invoke(Unknown Source) ~[na:1.8.0_40]
at org.apache.ibatis.logging.jdbc.PreparedStatementLogger.invoke(PreparedStatementLogger.java:59) [mybatis-3.5.5.jar!/:3.5.5]
at com.sun.proxy.$Proxy497.execute(Unknown Source) [na:na]
at org.apache.ibatis.executor.statement.PreparedStatementHandler.query(PreparedStatementHandler.java:64) [mybatis-3.5.5.jar!/:3.5.5]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [tomcat-embed-core-9.0.41.jar!/:9.0.41]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) [tomcat-embed-core-9.0.41.jar!/:9.0.41]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) [tomcat-embed-core-9.0.41.jar!/:9.0.41]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542) [tomcat-embed-core-9.0.41.jar!/:9.0.41]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143) [tomcat-embed-core-9.0.41.jar!/:9.0.41]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) [tomcat-embed-core-9.0.41.jar!/:9.0.41]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) [tomcat-embed-core-9.0.41.jar!/:9.0.41]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) [tomcat-embed-core-9.0.41.jar!/:9.0.41]
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:374) [tomcat-embed-core-9.0.41.jar!/:9.0.41]
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) [tomcat-embed-core-9.0.41.jar!/:9.0.41]
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:888) [tomcat-embed-core-9.0.41.jar!/:9.0.41]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1597) [tomcat-embed-core-9.0.41.jar!/:9.0.41]
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-embed-core-9.0.41.jar!/:9.0.41]
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [na:1.8.0_40]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [na:1.8.0_40]
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-9.0.41.jar!/:9.0.41]
at java.lang.Thread.run(Unknown Source) [na:1.8.0_40]
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method) ~[na:1.8.0_40]
at java.net.SocketInputStream.socketRead(Unknown Source) ~[na:1.8.0_40]
at java.net.SocketInputStream.read(Unknown Source) ~[na:1.8.0_40]
at java.net.SocketInputStream.read(Unknown Source) ~[na:1.8.0_40]
at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:101) ~[mysql-connector-java-5.1.49.jar!/:5.1.49]
at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:144) ~[mysql-connector-java-5.1.49.jar!/:5.1.49]
at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:174) ~[mysql-connector-java-5.1.49.jar!/:5.1.49]
at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2966) ~[mysql-connector-java-5.1.49.jar!/:5.1.49]
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3427) ~[mysql-connector-java-5.1.49.jar!/:5.1.49]
... 219 common frames omitted
分析
通过报错信息我们可以明显的看到,错误信息Caused by: java.net.SocketTimeoutException: Read timed out
直接进入到最后一句报错信息所在的类MysqlIo
这里我贴出主要的几个方法,方法中直接去主要部分,想看源码的可去自己项目里查看
private final Buffer reuseAndReadPacket(Buffer reuse, int existingPacketLength) throws SQLException {
try {
//.......
reuse.setBufLength(packetLength);
//注意这里使用了一个this.mysqlInput,然后我们进入下方构造方法看是什么---------------------------
int numBytesRead = this.readFully(this.mysqlInput, reuse.getByteBuffer(), 0, packetLength);
//---------------------------------------------------------------------------
if (numBytesRead != packetLength) {
throw new IOException("Short read, expected " + packetLength + " bytes, only read " + numBytesRead);
} else {
//...
}
} catch (IOException var9) {
//这里就是咱们报错抛出的地方
throw SQLError.createCommunicationsException(this.connection, this.lastPacketSentTimeMs, this.lastPacketReceivedTimeMs, var9, this.getExceptionInterceptor());
} catch (OutOfMemoryError var10) {
//.....
}
}
private final int readFully(InputStream in, byte[] b, int off, int len) throws IOException {
if (len < 0) {
throw new IndexOutOfBoundsException();
} else {
int n;
int count;
for(n = 0; n < len; n += count) {
//--------------此处调用SocketInputStream的read方法
count = in.read(b, off + n, len - n);
if (count < 0) {
throw new EOFException(Messages.getString("MysqlIO.EOF", new Object[]{len, n}));
}
}
return n;
}
}
//构造方法
public MysqlIO(String host, int port, Properties props, String socketFactoryClassName, MySQLConnection conn, int socketTimeout, int useBufferRowSizeThreshold) throws IOException, SQLException {
this.connection = conn;
//.......
this.reusablePacket = new Buffer(1024);
this.sendPacket = new Buffer(1024);
this.port = port;
this.host = host;
this.socketFactoryClassName = socketFactoryClassName;
this.socketFactory = this.createSocketFactory();
this.exceptionInterceptor = this.connection.getExceptionInterceptor();
try {
//从此处可以看出JDBC与数据库通信是采用Socket方式处理的
this.mysqlConnection = this.socketFactory.connect(this.host, this.port, props);
if (socketTimeout != 0) {
try {
this.mysqlConnection.setSoTimeout(socketTimeout);
} catch (Exception var9) {
}
}
this.mysqlConnection = this.socketFactory.beforeHandshake();
//根据报错信息我们可以知道,读取缓冲区数据,具体可查看[ReadAheadInputStream](https://spark.apache.org/docs/3.1.1/api/java/org/apache/spark/io/ReadAheadInputStream.html)
if (this.connection.getUseReadAheadInput()) {
this.mysqlInput = new ReadAheadInputStream(this.mysqlConnection.getInputStream(), 16384, this.connection.getTraceProtocol(), this.connection.getLog());
}else if (this.connection.useUnbufferedInput()) {
this.mysqlInput = this.mysqlConnection.getInputStream();
} else {
this.mysqlInput = new BufferedInputStream(this.mysqlConnection.getInputStream(), 16384);
}
//.......
} catch (IOException var10) {
throw SQLError.createCommunicationsException(this.connection, 0L, 0L, var10, this.getExceptionInterceptor());
}
}
通过 this.mysqlInput = new ReadAheadInputStream(this.mysqlConnection.getInputStream(), 16384, this.connection.getTraceProtocol(), this.connection.getLog());
我们可以看出是将mysqlConnection
的SocketInputStream
传入,具体看下方代码
public InputStream getInputStream() throws IOException {
//....
InputStream is = null;
try {
is = AccessController.doPrivileged(
new PrivilegedExceptionAction<InputStream>() {
public InputStream run() throws IOException {
//使用SocketInputStream,具体查看看下方-----------------------
return impl.getInputStream();
}
});
} catch (java.security.PrivilegedActionException e) {
throw (IOException) e.getException();
}
return is;
}
//impl.getInputStream方法
protected synchronized InputStream getInputStream() throws IOException {
synchronized (fdLock) {
if (isClosedOrPending())
throw new IOException("Socket Closed");
if (shut_rd)
throw new IOException("Socket input is shutdown");
if (socketInputStream == null)
//使用SocketInputStream-----------------------
socketInputStream = new SocketInputStream(this);
}
return socketInputStream;
}
我们进入到 java.net.SocketInputStream
类查看
class SocketInputStream extends FileInputStream
{
//此处就是MysqlIO中readFully调用的read方法
public int read(byte b[], int off, int length) throws IOException {
return read(b, off, length, impl.getTimeout());
}
//上方方法又调用此方法,在调用时增加了参数timeout,下方代码中当出现连接重置时会执行
int read(byte b[], int off, int length, int timeout) throws IOException {
//.....省略代码....
boolean gotReset = false;
// acquire file descriptor and do the read
FileDescriptor fd = impl.acquireFD();
try {
//此处调用socketRead方法--------在下方-------
n = socketRead(fd, b, off, length, timeout);
if (n > 0) {
return n;
}
} catch (ConnectionResetException rstExc) {
gotReset = true;
} finally {
impl.releaseFD();
}
/*
* We receive a "connection reset" but there may be bytes still
* buffered on the socket
*/
if (gotReset) {
impl.setConnectionResetPending();
impl.acquireFD();
try {
n = socketRead(fd, b, off, length, timeout);
if (n > 0) {
return n;
}
} catch (ConnectionResetException rstExc) {
} finally {
impl.releaseFD();
}
}
/*
* If we get here we are at EOF, the socket has been closed,
* or the connection has been reset.
*/
if (impl.isClosedOrPending()) {
throw new SocketException("Socket closed");
}
if (impl.isConnectionResetPending()) {
impl.setConnectionReset();
}
if (impl.isConnectionReset()) {
throw new SocketException("Connection reset");
}
eof = true;
return -1;
}
}
private int socketRead(FileDescriptor fd,
byte b[], int off, int len,
int timeout)
throws IOException {
//调用下方方法
return socketRead0(fd, b, off, len, timeout);
}
//调用JNI的socketRead0方法
private native int socketRead0(FileDescriptor fd,
byte b[], int off, int len,
int timeout)
throws IOException;
下面是JNI的socketRead0方法
/*
* Class: java_net_SocketInputStream
* Method: socketRead
* Signature: (Ljava/io/FileDescriptor;[BIII)I
*/
JNIEXPORT jint JNICALL
Java_java_net_SocketInputStream_socketRead0(JNIEnv *env, jobject this,
jobject fdObj, jbyteArray data,
jint off, jint len, jint timeout)
{
char *bufP;
char BUF[MAX_BUFFER_LEN];
jint fd, newfd;
jint nread;
if (IS_NULL(fdObj)) {
JNU_ThrowByName(env, JNU_JAVANETPKG "SocketException", "socket closed");
return -1;
}
fd = (*env)->GetIntField(env, fdObj, IO_fd_fdID);
if (fd == -1) {
NET_ThrowSocketException(env, "Socket closed");
return -1;
}
/*
* If the caller buffer is large than our stack buffer then we allocate
* from the heap (up to a limit). If memory is exhausted we always use
* the stack buffer.
*/
if (len <= MAX_BUFFER_LEN) {
bufP = BUF;
} else {
if (len > MAX_HEAP_BUFFER_LEN) {
len = MAX_HEAP_BUFFER_LEN;
}
bufP = (char *)malloc((size_t)len);
if (bufP == NULL) {
/* allocation failed so use stack buffer */
bufP = BUF;
len = MAX_BUFFER_LEN;
}
}
//druid当timeout参数为空时会将timeout设置为10000,具体看下方DruidDataSource类初始化方法init
if (timeout) {
if (timeout <= 5000 || !isRcvTimeoutSupported) {
int ret = NET_Timeout (fd, timeout);
if (ret <= 0) {
if (ret == 0) {
JNU_ThrowByName(env, JNU_JAVANETPKG "SocketTimeoutException",
"Read timed out");
} else if (ret == JVM_IO_ERR) {
JNU_ThrowByName(env, JNU_JAVANETPKG "SocketException", "socket closed");
} else if (ret == JVM_IO_INTR) {
JNU_ThrowByName(env, JNU_JAVAIOPKG "InterruptedIOException",
"Operation interrupted");
}
if (bufP != BUF) {
free(bufP);
}
return -1;
}
/*check if the socket has been closed while we were in timeout*/
newfd = (*env)->GetIntField(env, fdObj, IO_fd_fdID);
if (newfd == -1) {
NET_ThrowSocketException(env, "Socket Closed");
if (bufP != BUF) {
free(bufP);
}
return -1;
}
}
}
nread = recv(fd, bufP, len, 0);
if (nread > 0) {
(*env)->SetByteArrayRegion(env, data, off, nread, (jbyte *)bufP);
} else {
if (nread < 0) {
// Check if the socket has been closed since we last checked.
// This could be a reason for recv failing.
if ((*env)->GetIntField(env, fdObj, IO_fd_fdID) == -1) {
NET_ThrowSocketException(env, "Socket closed");
} else {
//WSAGetLastError()是指该函数返回上次发生的网络错误
switch (WSAGetLastError()) {
case WSAEINTR: //函数调用中断。该错误表明由于对WSACancelBlockingCall的调用,造成了一次调用被强行中断。
JNU_ThrowByName(env, JNU_JAVANETPKG "SocketException",
"socket closed");
break;
case WSAECONNRESET: //连接被对方重设
case WSAESHUTDOWN: //套接字关闭后不能发送
/*
* Connection has been reset - Windows sometimes reports
* the reset as a shutdown error.
*/
JNU_ThrowByName(env, "sun/net/ConnectionResetException",
"");
break;
case WSAETIMEDOUT : //连接超时。若发出了一个连接请求,但经过规定的时间,远程计算机仍未作出正确的响应(或根本没有任何响应),便会发生这样的错误。要想收到这样的错误,通常需要先在套接字上设置好SO_SNDTIMEO和SO_RCVTIMEO选项,然后调用connect及WSAConnect函数。
JNU_ThrowByName(env, JNU_JAVANETPKG "SocketTimeoutException",
"Read timed out");
break;
default:
NET_ThrowCurrent(env, "recv failed");
}
}
}
}
if (bufP != BUF) {
free(bufP);
}
return nread;
}
NET_Timeout(int fd, long timeout) {
int ret;
fd_set tbl;
struct timeval t;
t.tv_sec = timeout / 1000;
t.tv_usec = (timeout % 1000) * 1000;
FD_ZERO(&tbl);
FD_SET(fd, &tbl);
ret = select (fd + 1, &tbl, 0, 0, &t);
return ret;
}
从JNI代码代码可以看出,当查询数据时数据库超过指定时间就会执行JNU_ThrowByName(env, JNU_JAVANETPKG "SocketTimeoutException", "Read timed out");
,到SocketInputStream类的socketRead0时就会抛出IOException,存在异常就会触发gotReset=true
,然后进入impl.setConnectionResetPending()
之后会进入 impl.setConnectionReset();
然后抛出异常 throw new SocketException("Connection reset");
看下DruidDataSource.class
源码
通过查看Druid源码可以看到,当connectTimeout与socketTimeout未设置时,会默认设置成10000ms,即10s
public void init() throws SQLException {
if (!this.inited) {
DruidDriver.getInstance();
//....省略代码...
if (this.jdbcUrl != null) {
this.jdbcUrl = this.jdbcUrl.trim();
this.initFromWrapDriverUrl();
this.initFromUrlOrProperties();
}
当未设置connectTimeout 与socketTimeout 时默认设置为10000ms 即10s
if (this.connectTimeout == 0) {
this.socketTimeout = 10000;
}
if (this.socketTimeout == 0) {
this.socketTimeout = 10000;
}
//....省略代码...
}
}
解决办法
在DruidDataSource.class
中存在方法
private void initFromUrlOrProperties() {
if (this.jdbcUrl.startsWith("jdbc:mysql://")) {
if (this.jdbcUrl.indexOf("connectTimeout=") != -1 || this.jdbcUrl.indexOf("socketTimeout=") != -1) {
String[] items = this.jdbcUrl.split("(\\?|&)");
for(int i = 0; i < items.length; ++i) {
String item = items[i];
String strVal;
if (item.startsWith("connectTimeout=")) {
strVal = item.substring("connectTimeout=".length());
this.setConnectTimeout(strVal);
} else if (item.startsWith("socketTimeout=")) {
strVal = item.substring("socketTimeout=".length());
this.setSocketTimeout(strVal);
}
}
}
Object propertyConnectTimeout = this.connectProperties.get("connectTimeout");
if (propertyConnectTimeout instanceof String) {
this.setConnectTimeout((String)propertyConnectTimeout);
} else if (propertyConnectTimeout instanceof Number) {
this.setConnectTimeout(((Number)propertyConnectTimeout).intValue());
}
Object propertySocketTimeout = this.connectProperties.get("socketTimeout");
if (propertySocketTimeout instanceof String) {
this.setSocketTimeout((String)propertySocketTimeout);
} else if (propertySocketTimeout instanceof Number) {
this.setSocketTimeout(((Number)propertySocketTimeout).intValue());
}
}
}
也就是说通过在配置文件中配置connectTimeout与socketTimeout即可解决此问题.找到application.yml
找到数据源配置文件,在url后加上&connectTimeout=300000&socketTimeout=300000
更改前
url: jdbc:mysql://127.0.0.1:3306/sql?useUnicode=true&characterEncoding=utf-8&useSSL=false&serverTimezone=GMT%2B8&zeroDateTimeBehavior=convertToNull&allowPublicKeyRetrieval=true&useSSL=false
更改后
url: jdbc:mysql://127.0.0.1:3306/sql?useUnicode=true&characterEncoding=utf-8&useSSL=false&serverTimezone=GMT%2B8&zeroDateTimeBehavior=convertToNull&allowPublicKeyRetrieval=true&useSSL=false&connectTimeout=300000&socketTimeout=300000