一次数据库查询超时优化问题的实战记录

问题发现

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

### 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 上网搜索了下 killquery 发生的场景,在一篇文章 深入分析jdbc超时机制 找到问题所在,sql 执行超时,jdbc 会向 mysql 服务发送一个kill 命令,从而让 mysql 停止 sql 执行。不过传给了 mycat 服务,mycat 没有处理该命令,而是直接报错返回

3 查看了下应用服务的配置,在 jdbc:url 统一配置的 mysql socket 执行超时时间是 15s。而在 mybatis 单独的 sql 执行语句配置的设置更长,是 20s(注意这里的配置是 xml 加 注解的方式)

3.1 mybatis xml里的 sql 语句我单独在客户端执行,测试的 sql 执行时间大概在 6,7 秒左右,是不会超过 15s 这个限制的,但是从定时任务调度日志看,每次任务总体上就执行了 8 秒左右,说明 mycat 确实是在15秒内收到超时 kill 命令,从而导致sql 执行失败

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

从mybatis 源码文档上看,单独设置的 mybatis @options timeout属性是会覆盖掉在 yml 配置的 default-statement-timeout属性的。难道是 @options 没生效 ?

5 因此决定本地调试一波。发现 @options 还真的没生效,jdbc的 querytimeout 取值的是 mybatis在yml的 全局配置

解决问题

上面提到, sql 的 statment 混合使用了 mybatis 的注解和xml混合使用。猜测应该是 mybatis 的 注解和xml 使用方式是不兼容的。因此试着在 xml 的 statment 修改了 timeout配置。设置 timeout = 60。发现 配置生效了,如下图

后面也试着将 sql 放置到 mybatis 的 @select 注解,去掉 xml 的 statement。@options 的配置也是可以生效的。mybatis 的@options 和 xml 是无法同时生效的,可能 mybatis 其他的注解一样和 xml 配置不能同时生效,希望读者以后能避开这个坑

额外话:transaction timeout、statement timeout、socket timeout 的区别

上面 mybatis 配置的 timeout 其实就是statement timeout。还有就是在jdbc:url 配置的sockettimeout;其实还有是spring定义的一个事务超时: transaction timeout

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

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就变得毫无意义

总结

到此这篇关于数据库查询超时优化问题的文章就介绍到这了,更多相关数据库查询超时优化内容请搜索www.887551.com以前的文章或继续浏览下面的相关文章希望大家以后多多支持www.887551.com!

参数文章

  • 深入分析jdbc超时机制
  • 如何配置mysql数据库超时设置
(0)
上一篇 2022年3月21日
下一篇 2022年3月21日

相关推荐