问题描述
线上业务高峰期 CPU 飙升，抓取 thread dump 发现 MySQL Statement Cancellation Timer 的线程数比较多，接收到线上预警，分析一下原因。
业务高峰：
下面是一些可能相关的信息（ mysql 驱动，db 连接池，orm 框架）
依赖信息：
- mysql-jdbc 8.0.24
- druid 1.2.8
- mybatis 3.4.6
环境配置信息
- druid 配置，全部都是默认值
- mybatis 配置：
@Bean public SqlSessionFactory sqlSessionFactory(DataSource dataSource) throws Exception { SqlSessionFactoryBean factory = new SqlSessionFactoryBean(); factory.setVfs(SpringBootVFS.class); factory.setDataSource(dataSource); //todo 省略其他配置 Configuration c = new Configuration(); c.setLogImpl(StdOutImpl.class); c.setDefaultStatementTimeout(25000); factory.setConfiguration(c); return factory.getObject(); }
发生过程分析
- 1.找到该线程的创建的地方 NativeSession
- 2.引用关系如下
image.png
- 3.什么时候启动 enableQueryTimeouts = true
image.png
- 4.默认值是 true
image.png
- 5.startQueryTime 的调用方 StatementImpl 的 executeQuery
image.png
- 6.可以发现 timeOutInMillis 不为 0 的情况下，并且 enableQueryTimeouts = true 就会创建 CanalQueryTask 然后如果超时就会自动调度
方法调用如下：com.mysql.cj.CancelQueryTaskImpl#run
处理方案
- 1.项目使用的是使用 alibaba druid
调用的是 setQueryTimeOut 方法，然后传给 timeOutInMills
如果需要取消 CancelQueryTask 需要将 validationQueryTimeout 设置为 0
- 2.并且去掉 mybatis defalutStatemnetTimeOut 参数
image.png
- 3.如果这些都去掉可以通过 mysql 服务端 collection timeout 配置处理
- mysql 服务器会有一个参数 wait_timeout：mysql server 关闭连接之前，允许连接闲置多少秒。默认是 28800，单位秒，即 8 个小时。
# 分别查看全局、会话变量值 show global VARIABLES like '%timeout%'; show VARIABLES like '%timeout%';
image.png
- druid 可以通过 testOnBorrow 和 testOnReturn、testWhileIdle分别在链接获取，链接归还的时候判断是否有效。
image.png
复现和修复
测试代码
- PushCallbackService.java
- CallbackLog.java
- DBTimerController.java
- MccClient.java
修复效果
现象 MySQL Statement Cancellation Timer的线程不再产生
thread dump 分析工具地址：https://fastthread.io/
