1.异常描述
- Exception:
- com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure
- The last packet successfully received from the server was 7 milliseconds ago. The last packet sent successfully to the server was 1,023,250 milliseconds ago.
- at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
- at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
- at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
- at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
- at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
- at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1116)
- at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3589)
- at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3478)
- at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4019)
- at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:951)
- at com.mysql.jdbc.MysqlIO.nextRow(MysqlIO.java:1929)
- at com.mysql.jdbc.RowDataDynamic.nextRecord(RowDataDynamic.java:414)
- at com.mysql.jdbc.RowDataDynamic.next(RowDataDynamic.java:393)
- at com.mysql.jdbc.ResultSetImpl.next(ResultSetImpl.java:6883)
- at com.seven.migrate.MySQLJdbcTest.main(MySQLJdbcTest.java:58)
- Caused by: java.io.EOFException: Can not read response from server. Expected to read 18 bytes, read 14 bytes before connection was unexpectedly lost.
- at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3039)
- at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3545)
- ... 8 more
2. 问题分析:
从网上分析得知,此问题一般是MySQL端数据发送timeout所致。MySQL中可以设置net_write_timeout这个变量,来调整IO写的时候的超时时间。
connect_timeout
The number of seconds that the mysqld server waits for a connect packet before responding with Bad handshake.
interactive_timeout
The number of seconds the server waits for activity on an interactive connection before closing it.
wait_timeout
The number of seconds the server waits for activity on a noninteractive connection before closing it.
net_read_timeout
The number of seconds to wait for more data from a connection before aborting the read.
net_write_timeout
The number of seconds to wait for a block to be written to a connection before aborting the write.
由此可知,当客户端长时间不接收数据的时候,就会断开连接。接下来我们尝试在MySQL这边设置net_write_timeout,但发现还是无效,百思不得其解。
查看jdbc驱动发现,当调用PreparedStatement的executeQuery()方法的时候,如果我们是去获取流式resultset的话,就会默认执行SET net_write_timeout= ? 这个命令去重新设置timeout时间。源代码如下:
- if (doStreaming && this.connection.getNetTimeoutForStreamingResults() > 0) {
- java.sql.Statement stmt = null;
- try {
- stmt = this.connection.createStatement();
- ((com.mysql.jdbc.StatementImpl)stmt).executeSimpleNonQuery(this.connection, "SET net_write_timeout="
- + this.connection.getNetTimeoutForStreamingResults());
- } finally {
- if (stmt != null) {
- stmt.close();
- }
- }
- }
因此我们需要为MySQL驱动的connection这个类设置NetTimeoutForStreamingResults。当不设置NetTimeoutForStreamingResults这个变量的时候,默认是600秒。
接下来查看MySQL的源代码,发现最后影响的是sockopt的SO_SNDTIMEO。
- void vio_timeout(Vio *vio, uint which, uint timeout)
- {
- r= setsockopt(vio->sd, SOL_SOCKET, which ? SO_SNDTIMEO : SO_RCVTIMEO,
- IF_WIN(const char*, const void*)&wait_timeout,
- sizeof(wait_timeout));
- }
在msdn上有如下解释
setsockopt(SO_RCVTIMEO) "If a send or receive operation times out on a
socket, the socket state is indeterminate, and should not be used; TCP
sockets in this state have a potential for data loss, since the
operation could be canceled at the same moment the operation was to be
completed."
3.问题重现
在类ReadAheadInputStream中的fill方法中的this.underlyingStream.read处设置一个断点。停留长于NetTimeoutForStreamingResults的时间,这个问题就会重现了。MySQL驱动最终用来读取网络数据的对象是underlyingStream。
- private void fill(int readAtLeastTheseManyBytes) throws IOException {
- checkClosed();
- this.currentPosition = 0; /* no mark: throw away the buffer */
- this.endOfCurrentData = currentPosition;
- // Read at least as many bytes as the caller wants, but don't
- // block to fill the whole buffer (like java.io.BufferdInputStream
- // does)
- int bytesToRead = Math.min(this.buf.length - currentPosition,
- readAtLeastTheseManyBytes);
- int bytesAvailable = this.underlyingStream.available();
- if (bytesAvailable > bytesToRead) {
- // Great, there's more available, let's grab those
- // bytes too! (read-ahead)
- bytesToRead = Math.min(this.buf.length - currentPosition,
- bytesAvailable);
- }
- if (this.doDebug) {
- StringBuffer debugBuf = new StringBuffer();
- debugBuf.append(" ReadAheadInputStream.fill(");
- debugBuf.append(readAtLeastTheseManyBytes);
- debugBuf.append("), buffer_size=");
- debugBuf.append(this.buf.length);
- debugBuf.append(", current_position=");
- debugBuf.append(currentPosition);
- debugBuf.append(", need to read ");
- debugBuf.append(Math.min(this.buf.length - currentPosition,
- readAtLeastTheseManyBytes));
- debugBuf.append(" bytes to fill request,");
- if (bytesAvailable > 0) {
- debugBuf.append(" underlying InputStream reports ");
- debugBuf.append(bytesAvailable);
- debugBuf.append(" total bytes available,");
- }
- debugBuf.append(" attempting to read ");
- debugBuf.append(bytesToRead);
- debugBuf.append(" bytes.");
- if (this.log != null) {
- this.log.logTrace(debugBuf.toString());
- } else {
- System.err.println(debugBuf.toString());
- }
- }
- int n = this.underlyingStream.read(this.buf, currentPosition,
- bytesToRead);
- if (n > 0) {
- endOfCurrentData = n + currentPosition;
- }
- }
http://frankfan915.iteye.com/blog/1672465