原由
最近一段时间,生产系统持续碰到一些数据库异常,致使 sql 执行失败。html
应用环境
Java 1.7 + Mysql 5.6 + spring + ibatisjava
问题排查
将各类失败的异常记录了一下,碰到最多下面几种异常。mysql
- java.net.SocketTimeoutException: Read timed out
- java.sql.BatchUpdateException: No operations allowed after statement closed。
- com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure
- java.io.EOFException: Can not read response from server. Expected to read 8 bytes, read 7 bytes before connection was unexpectedly lost.
- java.net.SocketException: Software caused connection abort: recv failed
SocketTimeoutException
针对上面第一种状况,很容易从字面意义就得出是读取超时。然而查询资料 JDBC 存在多种 timeout,仔细研究了一下,梳理一下。spring
JBDC 能够设置超时时间分别是 Transaction Timeout,Statement Timeout,Socket TimeOut,ConnectionTimeout。上述超时时间层次从上至下。sql
如下咱们从上之下分别了解这几种种超时时间。数据库
Transaction Timeout :事务超时时间,由多个 Statement 组成。事务的超时时间=N*Statement.timeout+其余代码执行时间。因此咱们不该该在一个事务中执行一些 RPC 或 HTTP 等这些长耗时的调用。若是时间卡在这些调用上,会致使事务超时发生回滚。segmentfault
Statement Timeout:一次语句的执行的时间,能够用来限制一个查询语句的执行时间。可是若是出现网络故障,这个超时间将不起做用。最终须要 Socket TimeOut 解决。网络
Socket TimeOut :目前 JDBC 类型存在四种,而咱们一般使用的是数据库协议驱动(Database-Protocol driver (Pure Java driver) or thin driver)。这种驱动采用 Socket 用来与数据库通讯。若没有设置,一但发生网络故障,SCOKET 读取就会直接阻塞。而设置之后,时间超时后将会抛出 java.net.SocketTimeoutException: Read timed out,防止长时间阻塞,系统不可用。session
ConnectionTimeout :这个超时参数也是与 Socket 创建链接有关。若没有设置,一旦若是数据库相关地址参数错误错误,将会长时间阻塞在创建数据库链接上。app
使用网上一张图能够清晰的解析前三者关系。
实际上还存在操做系统层面上 Socket 超时。各个操做系统能够设置相应 Socket 超时时间,而后若 JDBC 没有设置,到了操做系统的超时时间也将会断开。可是咱们不能依赖该超时间,由于该时间彻底不可控,咱们应该显式设置。
综上,针对相关 JDBC 参数咱们至少须要设置 ConnectionTimeout 以及 Socket TimeOut.针对 sql 语句,能够设置 Statement Timeout。若存在事务,还能够设置相应 Transaction Timeout。
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException
这个 CommunicationsException 异常会由于其余底层异常致使如如下这两种异常。
- java.io.EOFException: Can not read response from server. Expected to read 8 bytes, read 7 bytes before connection was unexpectedly lost.
- java.net.SocketException: Software caused connection abort: recv failed
刚开始碰到该异常,根据 CommunicationsException 查询一下了,大体都是说 Mysql server 端会检测空闲链接,超时后主动断开链接,致使客户端的链接失效。
那么什么是 mysql 的空闲链接那?简单来讲,mysql 链接进程 Command 为 sleep 状态。咱们可使用 show processlist ;
查看正在运行的进程。空闲的进程示例如图:
jdbc 链接会根据 mysql wait_timeout 检测空闲链接。若在 wait_timeout 时间内,链接仍是空闲状态,mysql server 将会断开这个连接。针对这种状况,采用编码模拟。 采用以下代码:
try { Connection connection = dataSource.getConnection(); TimeUnit.SECONDS.sleep(11L); run.query(connection,"select 'X'", h); //Thread.sleep(60000); } catch (Exception e) { log.error("查询异常", e); }
而后设置 mysql wait_timeout=10 。 如下模拟代码获取链接后,休眠11s,这个过程当中,mysql 主动断开链接,等真正执行时,程序抛出异常。
如下为报错的状况:
可是底层异常却为 java.net.SocketException: Software caused connection abort: recv failed,而不是 java.io.EOFException。
这个报错倒是很疑惑。而后仔细查看 EOFException 后面描述 Expected to read 8 bytes, read 7 bytes before connection was unexpectedly lost,能够看出这个链接其实有一段时间其实仍是可用,有读取数据,可是在读取数据过程当中,未读到符合数量的相应数据,致使报错。而上面代码模拟的倒是链接使用时链接已生效的状况。
执行 show variables like '%timeout%';
查看 mysql 其余超时时间,
从上图能够注意到 net_read_timeout 与 net_write_timeout 这两个参数。
net_read_timeout 默认30s The number of seconds to wait for more data from a connection before aborting the read. When the server is reading from the client, net_read_timeout is the timeout value controlling when to abort. When the server is writing to the client, net_write_timeout 默认60s The number of seconds to wait for a block to be written to a connection before aborting the write
net_write_timeout 控制 mysql 服务端向客户端写数据超时时间。针对这种状况,在 MysqlIO read 处打上短点,
程序启动时,先放开断点,查看 mysql processlist,看到 mysql 进程 state send to client 时,这个时候使断点生效。这个时候,等待60s 之后,成功复现出以下错误。
net_read_timeout 该超时不知道如何模拟:(。
综上,若发生 com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure 异常,为数据库链接失效,可是失效的缘由可能会有多种,大体都与 mysql 各类 timeout 参数相关。
BatchUpdateException
这个错误是发生在数据批量导入时。当时数据量大概 20 多W条,而后在批量插入时抛出该异常。如下为批量插入代码。
getSqlMapClientTemplate().execute(new SqlMapClientCallback<Object>() { @Override public Object doInSqlMapClient(SqlMapExecutor executor) throws SQLException { executor.startBatch(); for (int i = 0; i < 200000; i++) { Demo demo = new Demo(); demo.setName("asd"); demo.setAge(String.valueOf(i)); demo.setSubject("adassad"); // 原项目 这里会发生一次 RPC调用 现用 Sleep 代替 try { TimeUnit.MILLISECONDS.sleep(10L); } catch (InterruptedException e) { e.printStackTrace(); } executor.insert("insertDemo", demo); } executor.executeBatch(); return null; } });
这段代码就是使用 ibatis batch 功能,批量插入数据。
其实看到这个异常信息,java.sql.BatchUpdateException: No operations allowed after statement closed 能够明确看出是由于 statement 关闭致使,那么为何 statement 会提早关闭。下面咱们跟踪源码。
如今咱们先看 SqlMapClientCallback doInSqlMapClient 方法。debug executor.startBatch() 方法最后其调用的是 SqlMapExecutorDelegate.startBatch 方法
查看代码注释可知,其目的就是为了设置一个状态值,这个状态值下面将用到。
此时咱们查看 executor.insert ,正常来讲该方法应该会执行sql 语句,而后插入数据库。可是查看源码你会发现,他最后调用的是 MappedStatement.sqlExecuteUpdate,进入方法刚开始就判断上文设置的 session batch 属性。固然这个属性,咱们刚开始已经设置成 true , 因此此时并无执行 sql 插入动做,而是将此次 sql 以及相关参数存储到内存。
protected int sqlExecuteUpdate(StatementScope statementScope, Connection conn, String sqlString, Object[] parameters) throws SQLException { if (statementScope.getSession().isInBatch()) { getSqlExecutor().addBatch(statementScope, conn, sqlString, parameters); return 0; } else { return getSqlExecutor().executeUpdate(statementScope, conn, sqlString, parameters); } }
最后咱们查看 executor.executeBatch,该方法最后调用了 Statement.executeBatch,真正开始执行批量插入。
看完 SqlMapClientCallback 里面的逻辑,如今咱们来查看 SqlMapClientTemplate.execute 代码逻辑。
查看时序图可知,在真正执行 SqlMapClientCallback 回调方法逻辑时,这个时候会首先从 DataSource 获取 Connection, 而后后面开始执行 SqlMapClientCallback 回调逻辑,最后释放 Connection。这个过程当中若 SqlMapClientCallback 方法执行时间太久,如咱们的方法中调用 for 循环中每次都会发生一次 Dubbo 调用,而后因为这个循环须要遍历 20 多 W 数据,这就致使该循环结束就须要半个多小时(假设一次 dubbo 调用耗时 10 ms),而咱们 mysql server wait_timeout 为 300s,因此 mysql server 提早主动释放空闲链接,而后等到真正执行批量插入时,就会致使上面的异常。
题外话:mysql jdbc 使用 Batch 插入时,须要设置 rewriteBatchedStatements=true 参数。若没有设置,其最后等效使用一次 for 循环插入数据,并不能提高插入的效率。
参考
- JDBC 驱动程序类型
- Understanding JDBC Internals & Timeout Configuration
- 深刻理解 JDBC 的超时
- 深刻分析JDBC超时机制
- mysql: show processlist 详解
- 聊聊jdbc socketTimeout的设置
若是以为好的话,请帮做者点个赞呗~ 谢谢
喜欢本文的读者们,欢迎长按关注订阅号程序通事~让我与你分享程序那些事。