高并发下 MySQL Statement Cancellation Timer 的线程数暴涨

问题描述

线上业务高峰期 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

引用关系如下

image.png

什么时候启动 enableQueryTimeouts = true

image.png

默认值是 true

image.png

startQueryTime 的调用方 StatementImpl 的 executeQuery

image.png

可以发现 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 参数

image.png

如果这些都去掉可以通过 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/

参考资料

https://segmentfault.com/a/1190000020162800
https://dev.mysql.com/doc/refman/5.7/en/server-system-variables.html#sysvar_wait_timeout