数据库查询时间过长导致The last packet sent successfully to the server was 10,001 milliseconds ago深入分析及解决方案

前言

不想看原因的可直接前往点击解决方案查看解决办法(简单到不能再简单)
当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());我们可以看出是将mysqlConnectionSocketInputStream传入,具体看下方代码

  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
         
  • 5
    点赞
  • 6
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值