记一次数据库查询超时优化问题

问题发现

• 期初在七月份时，经常发现有几个定时任务报错，查看了下异常原因，大概定位是数据库执行异常

### Error querying database.  Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Unsupported command
### The error may exist in class path resource [mapper/XXXXXXXXX-Mapper.xml]
### The error may involve defaultParameterMap
### The error occurred while setting parameters
### SQL: select t3.cino, t2.sn as orderSn,             t2.provider_id as providerId,             t4.logistics_no as logisticsSn,             t2.`name`,      
### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Unsupported command
; Unsupported command; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Unsupported command
org.springframework.dao.DataAccessResourceFailureException: 
### Error querying database.  Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Unsupported command
### The error may exist in class path resource [mapper/XXXXXXXXXOMapper.xml]
### The error may involve defaultParameterMap
### The error occurred while setting parameters
### SQL: select t3.cino, t2.sn as orderSn,             t2.provider_id as providerId,             t4.logistics_no as logisticsSn,         
### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Unsupported command

查找原因

• 1 和 DBA 排查 mycat（公司使用 mycat ） 和 mysql 的错误日志。发现是应用服务这边会给 MyCat 发送一个 KILL QUERY 命令，而 myCat 不支持该 KILL QUERY 命令。才给应用服务返回了 Unsupported command 异常错误

2021-07-02 10:46:33.567  WARN [$_NIOREACTOR-37-RW] (io.mycat.server.ServerQueryHandler.query(ServerQueryHandler.java:96)) - Unsupported command:KILL QUERY 2956587

• 2 上网搜索了下 KILL QUERY 发生的场景，在一边文章里 深入分析JDBC超时机制 找到问题所在，sql执行超时，jdbc 会向 mysql 服务发送一个kill 命令，从而停止 sql 执行，不过公司的 mycat 服务没有处理改命令，而是直接报错

• 3 查看了下，服务的配置 这里统一配置的 mysql socket 执行超时时间是 15。而在单独的 sql 执行语句配置的设置更长是 20s（注意这里是 xml 加 注解的方式）
  

• 3.1 xml里的 sql 语句我单独在客户端执行，测试的 sql 执行时间在 6，7 秒左右，是不会超过 15 这个限制的，但是从定时任务来，任务总体上就执行了 8 秒左右。说明 sql 确实是在 15内秒被超时 KILL 掉的
  

• 4 想着是不是在其他配置超时。细看了下 mybatis的配置，还真有有个一个统一 sql 超时配置，default-statement-timeout = 5 的设置
  -

• 从文档上看，单独设置的 mybatis @Options 属性是会覆盖掉在 yml 配置的 default-statement-timeout属性的。难道是 @Options 没生效 ？
  

• 5 因此决定调试一波。发现 @Options 还真的没生效，jdbc的 queryTimeout 视同 mybatis在yml的 全局配置
  

解决问题

• 上面提到服务中用到 mybatis 的注解和xml混合使用。猜测应该是 mybatis 的 注解和xml 使用方式是相斥的，不兼容的，因此在 xml 的sql修改 timeout配置 timeout = 60。发现 timeout = 60 配置生效了
  
  
• 后面将 sql 放置到 mybatis 的 @Select 注解,去掉 xml 的声明。@Options 的配置也是生效的。真的坑， mybatis 的@Options 和 xml 是无法同时生效的，可能其他的注解是一样，希望读者以后能避开这个坑

额外话：Transaction Timeout、Statement Timeout、Socket timeout 的区别

• 上面 mybatis 配置的 timeout 其实就是Statement Timeout。还有就是在jdbc:url 配置的socketTimeout；其实还有一个事务超时 Transaction Timeout,是spring定义
  

它们三者的关系是在怎样的呢

Statement Timeout

• statement timeout 是用来限制statement 的执行时长，可通过调用JDBC的java.sql.Statement.setQueryTimeout(int timeout) 进行设置，不过一般是通过ORM框架来进行设置
• 在 myBatis中，statement timeout 的默认值是通过 defaultStatementTimeout 属性进行设置。同时还可以在 xml 中 select，insert，update标签设置timeout属性，从而对不同 sql 语句配置超时时间

Transaction Timeout

• Spring 提供的 transaction timeout 配置非常简单，它会记录每个事务的开始时间和消耗时间，当超出timeout值时将抛出异常。
• 假设某个事务中包含 3 个statement，每个statement的执行时间是 100ms，其他业务逻辑的执行时间是 50ms，那么transaction timeout至少应该设置为350ms(100 * 3 + 50)

Socket timeout

• JDBC的 socket timeout 在数据库被突然停掉或是发生网络错误时十分重要。由于TCP/IP的结构原因，socket没有办法探测到网络错误，因此应用也无法主动发现数据库连接断开。如果没有设置 socket timeout 的话，应用在数据库返回结果前会无期限地等下去，这种连接被称为 dead connection

生效顺序

• Socket timeout 包含 Transaction Timeout，Transaction Timeout 包含 Statement Timeout。也就是说如果 Statement Timeout 大于 Transaction Timeout 或者 Socket timeout，则无法生效
• 不推荐使用socket timeout来限制statement的执行时长，因此socket timeout的值必须要高于statement timeout，否则，socket timeout将会先生效，这样statement timeout就变得毫无意义

参数文章

• 深入分析JDBC超时机制
• 如何配置MySQL数据库超时设置