問題描述

線上業務高峰期 CPU 飆升，抓取 thread dump 發現 MySQL Statement Cancellation Timer 的線程數比較多，接收到線上預警，分析一下原因。業務高峰：

圖片

下面是一些可能相關的信息（ mysql 驅動，db 連接池，orm 框架）

依賴信息：

1. mysql-jdbc 8.0.24
2. druid 1.2.8
3. mybatis 3.4.6

環境配置信息

1. druid 配置，全部都是默認值
2. 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. 引用關系如下

圖片

3. 什么時候啟動 enableQueryTimeouts = true

圖片

4. 默認值是 true

圖片

5. startQueryTime 的調用方 StatementImpl 的 executeQuery

圖片

6. 可以發現 timeOutInMillis 不為 0 的情況下，并且 enableQueryTimeouts = true 就會創建 CanalQueryTask 然后如果超時就會自動調度

方法調用如下：com.mysql.cj.CancelQueryTaskImpl#run

圖片

處理方案

1. 項目使用的是使用 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

2. 并且去掉 mybatis defalutStatemnetTimeOut 參數

圖片

3. 如果這些都去掉可以通過 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