郑昀 基于田志全和端木洪涛的分析报告 2015/6/30
关键词：Java，JDBC，升级，MySQL驱动，频繁数据查询，mysql-5.1.34，mysql-5.0.7
问题现象：
2015年4月22日（周日）晚间，线上 TaskMall 工程（一个 Java 工程）频繁报警。分析 jvm 情况，taskmall 在内存使用上确实存在问题，可能有大量对象不正常堆积：
图2 155 jmap
问题原因：
频繁的大数据查询场景下，mysql-5.1.34 驱动的性能远优于 mysql-5.0.7 驱动。一定要及时升级驱动啊。
RCA类型：
维护问题。
其实我们在RCA(Root Cause Analysis)第四季就曾经遇到此类问题：
|
第四季案例5 官方驱动也会设计不当，及时升级 ——实例： 2013年1月，由于 PHP 一直使用 MongoDB PHP Driver 1.2.x 驱动，导致 PHP-FPM 模式下，每一个 PHP Worker 进程都有自己独立的 mongodb 连接池，从而导致连接数极易超标，占用内存数也随之倍增，MongoDB 负载很重。 如当时编辑后台192 --> mongodb-165 之间的连接数基本维持在：750～751个左右。 升级到 mongodb-php driver 1.3.2 驱动之后，日常连接数大为下降。 ——教训： 引入了重要存储介质的驱动之后，如spymemcahced、mongodb php/java driver、jedis等，保持跟踪它们的动态，第一时间更新驱动。 |
问题分析：
志全分析堆栈信息发现，系统中有大量的 CancelTask 定时任务需要执行。
图3 大量的CancelTask
为什么会有这么多的任务呢？
这是 mysql 的一个定时任务，主要用于查询超时处理。即，系统在执行一个 sql 查询时，jdbc 会给你一个超时时间。为了保证超时时间后，能够关闭 statement，会打开一个保护关闭的定时任务。如果超时情况下，sql 还没响应执行，cancel task 就会执行关闭任务。注，ibatis 的默认超时时间为3秒（<setting name="defaultStatementTimeout" value="3000" />）。
图4 mysql源码
其实，cancel() 方法只是对状态做了一个标记而已：
图5 mysql源码
只有在调度任务时，发现状态为取消，才会真正移除该任务：
图6 mysql源码
于是，在某些情况下，CancelTask 会大量累积，从而严重影响 JVM 内存，最终引发 FullGC！
问题解决：
志全分析了 MySQL 最新的 jdbc 驱动，发现 CancelTask 在 mysql 驱动中，后续的版本已经不采用全局的 Timer 任务池了。
在 mysql-connector-java-5.0.7-bin.jar 中：
图7 mysql源码
而在 mysql-connector-java-5.1.34-bin.jar 中：
图8 mysql源码
端木洪涛经过针对性的压力测试，确实证实了这个现象可以重现。测试报告如下所示：
|
测试时间：2015年4月29日 使用taskmall联调环境做测试。 协调器：10.8.210.168 分发器：10.9.210.151、10.9.210.152 执行器：10.9.210.154 分发器配置如下： 151使用mysql-5.1.34驱动，152使用mysql-5.0.7驱动。其中分发器两机器为2核8G配置，统一resin4 JVM配置： <jvm-arg>-Xmx1024M</jvm-arg> 基础准备： 1、往数据库中压入5180条队列数据，（其中151机器分的2614条，152机器分得2566条）； 2、改造执行器，使其只接受数据不处理数据。则5180条数据对分发器来说一直都是有效数据； 3、改造分发器，设置ibatis参数：cacheModelsEnabled="true"、defaultStatementTimeout="3000"。每150ms加载一次数据； （分发器起16个线程对应16个cobar分库，每个线程分页加载分库中的有效数据，每页200条数据。） 4、jvisualvm远程监控151、152机器。 测试结果如下： 一、15分钟后监控结果如下 从图上看出152机器从cpu占用、堆大小在逐渐升高，查看gc日志发现152已经开始出现FullGC。
152机器已快挂：
151机器则一切正常：
二、32分钟后监控结果如下 此时除了cpu占用、堆飙高外，152的线程数也远远高于151。此时的152已经频繁FullGC了。 152机器：
151机器则：
统计堆内存中活着对象数据： 152机器出现大量的Byte数据以及PreparedStatement，以及CancelTask。 1）但是在151机器上前47位的占用排行上找不到CancelTask。 2）在byte数据量上，152机器达到了600M，而151机器只有几十M。 测试结论： 频繁的大数据查询场景下，mysql-5.1.34 驱动的性能处理远优于 mysql-5.0.7 驱动。 |
-EOF-