问题描述
线上业务高峰期 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();
}
发生过程分析
- 找到该线程的创建的地方 NativeSession
图片
- 引用关系如下
图片
- 什么时候启动 enableQueryTimeouts = true
图片
- 默认值是 true
图片
- startQueryTime 的调用方 StatementImpl 的 executeQuery
图片
- 可以发现 timeOutInMillis 不为 0 的情况下,并且 enableQueryTimeouts = true 就会创建 CanalQueryTask 然后如果超时就会自动调度
方法调用如下:com.mysql.cj.CancelQueryTaskImpl#run
图片
处理方案
- 项目使用的是使用 alibaba druid
图片
参考:https://github.com/alibaba/druid/wiki/DruidDataSource%E9%85%8D%E7%BD%AE%E5%B1%9E%E6%80%A7%E5%88%97%E8%A1%A8调用的是 setQueryTimeOut 方法,然后传给 timeOutInMills
图片
如果需要取消 CancelQueryTask 需要将 validationQueryTimeout 设置为 0
- 并且去掉 mybatis defalutStatemnetTimeOut 参数
图片
- 如果这些都去掉可以通过 mysql 服务端 collection timeout 配置处理
mysql 服务器会有一个参数 wait_timeout:mysql server 关闭连接之前,允许连接闲置多少秒。默认是 28800,单位秒,即 8 个小时。
# 分别查看全局、会话变量值
show global VARIABLES like '%timeout%';
show VARIABLES like '%timeout%';
图片
- druid 可以通过 testOnBorrow 和 testOnReturn、testWhileIdle分别在链接获取,链接归还的时候判断是否有效。
图片
复现和修复
测试代码
- PushCallbackService.java
- CallbackLog.java
- DBTimerController.java
- MccClient.java
修复效果
现象 MySQL Statement Cancellation Timer的线程不再产生
图片
thread dump 分析工具地址:https://fastthread.io/
参考资料
- https://segmentfault.com/a/1190000020162800
- https://dev.mysql.com/doc/refman/5.7/en/server-system-variables.html#sysvar_wait_timeout