Pia! JDBC遇上MySQL的那些事儿~2

订正:

上文 中SockettimeoutException 我也没有成功复现(之前一定成功复现过,所以,问题依旧存在), 请期待后续!!!

要解决的问题:

上文取巧在net_write_timeout=1 设置值,过小,如果这个值设置成600 , 依旧会出现之前的问题么? 如果会要如何验证.

TL;DR:

• 是的, 在某些情况下,即使你调大net_write_timeout 的值, 依旧会出现. 本文构建的模拟的云服务器厂商自动kill到慢查询的行为导致发生此问题.

如何做到?

一个历时5年的问题分析 | plantegg JDBC 在 streaming 流模式下只要连接异常就会报如上错误，比如：

• 连接被 TCP reset
• RDS 前端自带的Proxy 主动断开连接
• 连接因为某种原因(比如 QueryTimeOut) 触发 kill Query导致连接中断
• RDS 端因为kill 主动断开连接 //比如用户监控RDS、DRDS脚本杀掉慢查询

可以做的事情:

• 手动kill 掉进程
• 慢查询监控 kill掉进程.

环境配置

MySQL

docker-compose.yaml

services:
  mysql:
    image: mysql:5.7
    container_name: test-mysql
    environment:
      MYSQL_ROOT_PASSWORD: 123
      MYSQL_DATABASE: fun-demo
      MYSQL_USER: test
      MYSQL_PASSWORD: test123
    ports:
      - "13306:3306"
    volumes:
      - ./data:/var/lib/mysql
      - ./conf/my.cnf:/etc/mysql/my.cnf
      - ./init/init.sql:/docker-entrypoint-initdb.d/init.sql
    command:
      --character-set-server=utf8mb4
      --collation-server=utf8mb4_unicode_ci
    restart: always

my.conf

• /root/servers/mysql/conf/my.conf 修改 net_write_timeout 到 600

• 以及配置 slow_query 检测

[mysqld]
character-set-server=utf8mb4
collation-server=utf8mb4_unicode_ci
max_connections=1000
net_write_timeout=600
net_read_timeout=600
wait_timeout=28800
interactive_timeout=28800

# slow_query
slow_query_log=1
slow_query_log_file=/var/log/mysql-slow.log
long_query_time=1 # 设置慢查询阈值（单位：秒）
log_queries_not_using_indexes=1 # 可选：记录未使用索引的查询


[client]
default-character-set=utf8mb4

[mysql]
default-character-set=utf8mb4

kill_slow_queries.sh

cd /root/servers/mysql/
vim kill_slow_queries.sh 

• 注意:需要更你的mysql 账号,以及密码

#!/bin/bash

# 获取 ens33 网卡的 IP 地址
MYSQL_HOST=$(ip addr show ens33 2>/dev/null | grep -w inet | awk '{print $2}' | cut -d/ -f1)

# 如果获取失败则退出
if [ -z "$MYSQL_HOST" ]; then
    echo "Error: Could not get IP address from ens33 interface"
    exit 1
fi

# MySQL 配置
MYSQL_USER="root"
MYSQL_PASSWORD="123"
MYSQL_PORT="13306"        # 映射到主机的端口
THRESHOLD=10              # 超时阈值（秒）

echo "Using MySQL host: $MYSQL_HOST"

# 测试 MySQL 连接
until mysql -u$MYSQL_USER -p$MYSQL_PASSWORD -h$MYSQL_HOST -P$MYSQL_PORT -e "SELECT 1" &> /dev/null
do
    echo "Waiting for MySQL connection..."
    sleep 3
done

echo "Connected to MySQL successfully!"

while true; do
    # 查询当前慢查询线程 ID
    THREAD_IDS=$(mysql -u$MYSQL_USER -p$MYSQL_PASSWORD -h$MYSQL_HOST -P$MYSQL_PORT -e \
        "SHOW FULL PROCESSLIST;" | awk '{if ($6 > '"$THRESHOLD"' && $5 == "Query") print $1}')

    # 如果有慢查询，则处理
    if [ ! -z "$THREAD_IDS" ]; then
        echo "$(date '+%Y-%m-%d %H:%M:%S') - Found slow queries"
        
        # 遍历并终止慢查询线程
        for THREAD_ID in $THREAD_IDS; do
            echo "$(date '+%Y-%m-%d %H:%M:%S') - Killing slow query with Thread ID: $THREAD_ID"
            mysql -u$MYSQL_USER -p$MYSQL_PASSWORD -h$MYSQL_HOST -P$MYSQL_PORT -e "KILL $THREAD_ID;"
        done
    fi

    # 等待 5 秒后再检查
    sleep 5
done

chmod +x ./kill_slow_queries.sh 
./kill_slowqueries.sh

测试代码:

package com.example.demo;  
  
import java.sql.*;  
import java.util.Properties;  
  
  
public class Test {  
    //    private static final String URL = "jdbc:mysql://win-vm:3306/fun_demo?serverTimezone=UTC";  
  
    private static final String IP = "win-vm";  
    private static final String PORT = "13306";  
    private static final String DBNAME = "testdb";  
    private static final String USERNAME = "root";  
    private static final String PASSWORD = "123";  
  
    private static String URL = "jdbc:mysql://" + IP + ":" + PORT + "/" + DBNAME + "?serverTimezone=UTC&useSSL=false";  
    //        private static final String sql = "SELECT timestamp, id, count, data FROM data_table ORDER BY timestamp, id";  
    private static final String sql = "SELECT * FROM data_table ORDER BY timestamp, id";
  
    private static void testNetWriteTimeoutWithSleep() throws ClassNotFoundException, InterruptedException {  
        //        Class.forName("com.mysql.cj.jdbc.Driver");  
        Class.forName("com.mysql.jdbc.Driver");  
        String user = USERNAME;  
        String pass = PASSWORD;  
        Properties props = new Properties();  
        props.setProperty("user", USERNAME);  
        props.setProperty("password", PASSWORD);  
  
        String slowSql = "select data  from data_table";  
  
        try (Connection conn = DriverManager.getConnection(URL, props)) {  
  
            while (true) {  
  
                conn.setAutoCommit(false);  
                Statement stmt = conn.createStatement();  
                stmt.setFetchSize(Integer.MIN_VALUE);  
  
                System.out.println("开始执行慢查询...");  
                long startTime = System.currentTimeMillis();  
  
                ResultSet rs = stmt.executeQuery(slowSql);  
                int count = 0;  
                while (rs.next()) {  
                    Thread.sleep(500);  
                    System.out.println("读取第 " + (++count) + " 行数据");  
                    if (count < 3) Thread.sleep(3000); 
                }  
                long endTime = System.currentTimeMillis();  
                System.out.println("查询执行时间：" + (endTime - startTime) + "ms");  
                rs.close();  
                stmt.close();  
                break;            }  
        } catch (Exception e) {  
            e.printStackTrace();  
        }  
    }
    public static void main(String args[]) throws NumberFormatException, InterruptedException, ClassNotFoundException {  

        // 测试 net_write_timeout 600s 的 net_write_timeout 问题  
        testNetWriteTimeoutWithSleep();  
    }
 }

测试结果:

读取第 587 行数据
读取第 588 行数据
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Application was streaming results when the connection failed. Consider raising value of 'net_write_timeout' on the server.
	at java.base/jdk.internal.reflect.DirectConstructorHandleAccessor.newInstance(DirectConstructorHandleAccessor.java:62)
	at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:502)
	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:486)
	at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
	at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:990)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3559)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3459)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3900)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:873)
	at com.mysql.jdbc.MysqlIO.nextRow(MysqlIO.java:1996)
	at com.mysql.jdbc.RowDataDynamic.nextRecord(RowDataDynamic.java:374)
	at com.mysql.jdbc.RowDataDynamic.next(RowDataDynamic.java:354)
	at com.mysql.jdbc.ResultSetImpl.next(ResultSetImpl.java:6312)
	at com.example.demo.Test.testNetWriteTimeoutWithSleep(Test.java:134)
	at com.example.demo.Test.main(Test.java:30)
	Suppressed: java.sql.SQLException: Streaming result set com.mysql.jdbc.RowDataDynamic@59ec2012 is still active. No statements may be issued when any streaming result sets are open and in use on a given connection. Ensure that you have called .close() on any active streaming result sets before attempting more queries.
		at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:869)
		at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:865)
		at com.mysql.jdbc.MysqlIO.checkForOutstandingStreamingData(MysqlIO.java:3214)
		at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2450)
		at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2680)
		at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2480)
		at com.mysql.jdbc.ConnectionImpl.rollbackNoChecks(ConnectionImpl.java:4672)
		at com.mysql.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:4564)
		at com.mysql.jdbc.ConnectionImpl.realClose(ConnectionImpl.java:4202)
		at com.mysql.jdbc.ConnectionImpl.close(ConnectionImpl.java:1462)
		at com.example.demo.Test.testNetWriteTimeoutWithSleep(Test.java:121)
		... 1 more
Caused by: java.io.EOFException: Can not read response from server. Expected to read 1,003 bytes, read 575 bytes before connection was unexpectedly lost.
	at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3011)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3519)
	... 9 more

流程图

sequenceDiagram
    participant RS as ResultSetImpl
    participant RDD as RowDataDynamic
    participant IO as MysqlIO
    participant Socket as MySQL Socket

    RS->>RDD: next()
    activate RS
    Note over RS: ResultSetImpl.java:6312
    activate RDD

    RDD->>RDD: nextRecord()
    Note over RDD: RowDataDynamic.java:374

    RDD->>IO: nextRow()
    activate IO
    Note over IO: MysqlIO.java:1996

    IO->>IO: checkErrorPacket()
    Note over IO: MysqlIO.java:873

    IO->>IO: checkErrorPacket(Buffer)
    Note over IO: MysqlIO.java:3900

    IO->>IO: reuseAndReadPacket(reusablePacket)
    Note over IO: MysqlIO.java:3459

    IO->>IO: reuseAndReadPacket(reusablePacket, -1)
    Note over IO: MysqlIO.java:3559

    IO->>Socket: readFully(mysqlInput, packetHeaderBuf, 0, 4)
    Socket-->>IO: return header bytes or timeout

    alt socket read timeout
        Socket-->>IO: throw IOException
        IO-->>RDD: throw CommunicationsException
        Note over IO: SQLError.createCommunicationsException()
        RDD-->>RS: propagate exception
    end

    deactivate IO
    deactivate RDD
    deactivate RS

• By the way , 我一共运行了两次,两次都是同样的异常,关于SockettimeoutException , 容我再学习一下!

番外:

为啥 mysql-connector-java8.x 不能重现 net_write_timeout 吗？

mysql-connector-java8.x 更换后,

java.sql.SQLException: Error retrieving record: Unexpected Exception: java.io.EOFException message given: Can not read response from server. Expected to read 1,003 bytes, read 991 bytes before connection was unexpectedly lost.

这是不是告诉我们, MySQL服务端自己断开连接了? 现在,你还想要用mysql-connector-java5.x 这个包么?🤔

执行结果

读取第 460 行数据
java.sql.SQLException: Error retrieving record: Unexpected Exception: java.io.EOFException message given: Can not read response from server. Expected to read 1,003 bytes, read 991 bytes before connection was unexpectedly lost.

Nested Stack Trace:


** BEGIN NESTED EXCEPTION ** 

java.io.EOFException
MESSAGE: Can not read response from server. Expected to read 1,003 bytes, read 991 bytes before connection was unexpectedly lost.

STACKTRACE:

java.io.EOFException: Can not read response from server. Expected to read 1,003 bytes, read 991 bytes before connection was unexpectedly lost.
	at com.mysql.cj.protocol.FullReadInputStream.readFully(FullReadInputStream.java:67)
	at com.mysql.cj.protocol.a.SimplePacketReader.readMessageLocal(SimplePacketReader.java:137)
	at com.mysql.cj.protocol.a.SimplePacketReader.readMessage(SimplePacketReader.java:102)
	at com.mysql.cj.protocol.a.SimplePacketReader.readMessage(SimplePacketReader.java:45)
	at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readMessage(TimeTrackingPacketReader.java:62)
	at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readMessage(TimeTrackingPacketReader.java:41)
	at com.mysql.cj.protocol.a.MultiPacketReader.readMessage(MultiPacketReader.java:66)
	at com.mysql.cj.protocol.a.MultiPacketReader.readMessage(MultiPacketReader.java:44)
	at com.mysql.cj.protocol.a.ResultsetRowReader.read(ResultsetRowReader.java:75)
	at com.mysql.cj.protocol.a.ResultsetRowReader.read(ResultsetRowReader.java:42)
	at com.mysql.cj.protocol.a.NativeProtocol.read(NativeProtocol.java:1587)
	at com.mysql.cj.protocol.a.result.ResultsetRowsStreaming.next(ResultsetRowsStreaming.java:194)
	at com.mysql.cj.protocol.a.result.ResultsetRowsStreaming.next(ResultsetRowsStreaming.java:62)
	at com.mysql.cj.jdbc.result.ResultSetImpl.next(ResultSetImpl.java:1813)
	at com.example.demo.Test.testNetWriteTimeoutWithSleep(Test.java:134)
	at com.example.demo.Test.main(Test.java:30)


** END NESTED EXCEPTION **


	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:129)
	at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122)
	at com.mysql.cj.jdbc.result.ResultSetImpl.next(ResultSetImpl.java:1828)
	at com.example.demo.Test.testNetWriteTimeoutWithSleep(Test.java:134)
	at com.example.demo.Test.main(Test.java:30)
	Suppressed: java.sql.SQLException: Streaming result set com.mysql.cj.protocol.a.result.ResultsetRowsStreaming@f0f2775 is still active. No statements may be issued when any streaming result sets are open and in use on a given connection. Ensure that you have called .close() on any active streaming result sets before attempting more queries.
		at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:129)
		at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122)
		at com.mysql.cj.jdbc.ConnectionImpl.rollbackNoChecks(ConnectionImpl.java:1933)
		at com.mysql.cj.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:1827)
		at com.mysql.cj.jdbc.ConnectionImpl.realClose(ConnectionImpl.java:1695)
		at com.mysql.cj.jdbc.ConnectionImpl.close(ConnectionImpl.java:714)
		at com.example.demo.Test.testNetWriteTimeoutWithSleep(Test.java:121)
		... 1 more
Caused by: java.io.EOFException: Can not read response from server. Expected to read 1,003 bytes, read 991 bytes before connection was unexpectedly lost.
	at com.mysql.cj.protocol.FullReadInputStream.readFully(FullReadInputStream.java:67)
	at com.mysql.cj.protocol.a.SimplePacketReader.readMessageLocal(SimplePacketReader.java:137)
	at com.mysql.cj.protocol.a.SimplePacketReader.readMessage(SimplePacketReader.java:102)
	at com.mysql.cj.protocol.a.SimplePacketReader.readMessage(SimplePacketReader.java:45)
	at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readMessage(TimeTrackingPacketReader.java:62)
	at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readMessage(TimeTrackingPacketReader.java:41)
	at com.mysql.cj.protocol.a.MultiPacketReader.readMessage(MultiPacketReader.java:66)
	at com.mysql.cj.protocol.a.MultiPacketReader.readMessage(MultiPacketReader.java:44)
	at com.mysql.cj.protocol.a.ResultsetRowReader.read(ResultsetRowReader.java:75)
	at com.mysql.cj.protocol.a.ResultsetRowReader.read(ResultsetRowReader.java:42)
	at com.mysql.cj.protocol.a.NativeProtocol.read(NativeProtocol.java:1587)
	at com.mysql.cj.protocol.a.result.ResultsetRowsStreaming.next(ResultsetRowsStreaming.java:194)
	at com.mysql.cj.protocol.a.result.ResultsetRowsStreaming.next(ResultsetRowsStreaming.java:62)
	at com.mysql.cj.jdbc.result.ResultSetImpl.next(ResultSetImpl.java:1813)
	... 2 more

流程图

flowchart TD
    A[ResultSetImpl.next] --> B[ResultsetRowsStreaming.next]
    B --> C[NativeProtocol.read]
    C --> D[ResultsetRowReader.read]
    D --> E[MultiPacketReader.readMessage]
    E --> F[TimeTrackingPacketReader.readMessage]
    F --> G[SimplePacketReader.readMessage]
    G --> H[SimplePacketReader.readMessageLocal]
    H --> I[FullReadInputStream.readFully]
    I --> J{是否读取完预期字节?}
    J -->|是| K[返回读取数据]
    J -->|否| L[抛出EOFException]
    
    style L fill:#ff0000

时序图

sequenceDiagram
    participant App as Application
    participant RS as ResultSetImpl
    participant RR as ResultsetRowsStreaming
    participant NP as NativeProtocol
    participant RRD as ResultsetRowReader
    participant MPR as MultiPacketReader
    participant TPR as TimeTrackingPacketReader
    participant SPR as SimplePacketReader
    participant FRI as FullReadInputStream

    App->>RS: next()
    RS->>RR: next()
    RR->>NP: read()
    NP->>RRD: read()
    RRD->>MPR: readMessage()
    MPR->>TPR: readMessage()
    TPR->>SPR: readMessage()
    SPR->>SPR: readMessageLocal()
    SPR->>FRI: readFully(byte[], offset, length)
    Note right of FRI: Expected: 1,003 bytes<br/>Actually read: 991 bytes
    FRI-->>SPR: EOFException
    SPR-->>TPR: EOFException
    TPR-->>MPR: EOFException
    MPR-->>RRD: EOFException
    RRD-->>NP: EOFException
    NP-->>RR: EOFException
    RR-->>RS: EOFException
    RS-->>App: SQLException

• 对比mysql-connector-java5.x 发现, 8 相较于5 多了一层网络协议层,用于处理网络IO, 而mysql-connector-java5.x 只是用 MysqlIO 这个类充当网络协议层, 异常处理也是再次发生.

总结

• 慢查询被Kill导致的连接异常

  • 原因：云服务商/DBA配置的慢查询监控脚本自动kill慢查询, 即使设置较大的net_write_timeout(如600s)，仍会出现连接中断
  • 解决方案：
    • 优化SQL查询性能，避免产生慢查询
    • 合理设置慢查询监控阈值(或关闭慢查询)
    • 尽量使用新版本MySQL connector（8.x版本异常处理更完善）, 避免扯皮😮

• MySQL Connector版本差异

  • 5.x版本：
    • 使用简单的MysqlIO处理网络通信
  • 8.x版本：
    • 增加了完整的网络协议层
    • 异常信息更准确地反映出连接被中断的本质
    • 提供更好的异常处理机制

• 最佳实践建议：

  • 使用MySQL Connector 8.x版本
  • 做好慢查询优化
  • 合理配置监控阈值，避免过度激进的kill策略
  • 在应用层增加重试机制处理异常情况

Reference:

• 一个历时5年的问题分析 | plantegg

---

• Co-worker: cursor

Do you like it? Hope you enjoy it!

Have fun, Bye!