RCA:JDBC drives the FULLGC of its own problems

Zheng Analysis report based on Tian Zhikuan and end-Mu Hongtao 2015/6/30

Keywords:java,jdbc, upgrade, MySQL driver, frequent data query, mysql-5.1.34,mysql-5.0.7

Symptom: April 22, 2015 (Sunday) evening, the online Taskmall project (a Java project) frequently alarms. Analyzing the JVM situation, there is a real problem with the memory usage, there may be a large number of objects Taskmall: Figure 2 155 jmap problem Reason: In the frequent Big data query scenario, the mysql-5.1.34 drive performance is much better than the mysql-5.0.7 driver. Must be in time to upgrade the driver AH.  RCA Type: Maintenance issues. In fact, we encountered this problem in the fourth quarter of the RCA (Root cause analysis):

fourth quarter Case 5 official driver will also be improperly designed to upgrade in time -- instance : January 2013, because PHP has been using the MongoDB PHP Driver 1.2.x driver, resulting in php-fpm mode, each PHP Worker process has its own separate MongoDB connection pool, resulting in the number of connections is extremely easy to exceed the number of memory, The MongoDB load is heavy. After upgrading to mongodb-php driver 1.3.2 Drive, the number of daily connections dropped significantly. --lesson: After the introduction of important storage media drivers, such as spymemcahced, MongoDB Php/java driver, Jedis, etc., keep track of their dynamics, the first time to update the driver.

Problem Analysis: The log analysis stack information found that the system has a large number of Canceltask scheduled tasks need to be executed.  Figure 3 Why does a lot of canceltask have so many tasks? This is a timed task for MySQL and is primarily used for query timeout processing. That is, when the system executes a SQL query, JDBC gives you a time-out. In order to be able to close statement after the timeout period, a timed task that protects the shutdown is turned on. If the SQL has not responded to execution in the time-out, the cancel task executes the shutdown. Note that the default time-out for Ibatis is 3 seconds (<setting name= "defaultstatementtimeout" value= "/>"). Figure 4 MySQL source code in fact, the Cancel () method just makes a mark on the state: Figure 5 MySQL source code only in the scheduling task, the discovery state is canceled, will really remove the task: Figure 6 MySQL Source Thus, in some cases, the canceltask accumulates heavily, which seriously affects the JVM's memory and eventually causes fullgc! Problem Solving: Log full analysis of MySQL latest JDBC driver, found that canceltask in the MySQL driver, the subsequent version has not adopted the global Timer task pool. In Mysql-connector-java-5.0.7-bin.jar: Figure 7 MySQL source code and in Mysql-connector-java-5.1.34-bin.jar: Figure 8 MySQL source end Mu Hongtao after the targeted stress test, It does confirm that the phenomenon can be reproduced. The test report looks like this:

Test Date: April 29, 2015 Use taskmall to test the environment. Coordinator:10.8.210.168 Dispenser:10.9.210.151,10.9.210.152 Actuator:10.9.210.154 The dispatcher is configured as follows: 151 using the mysql-5.1.34 drive, the152 uses the mysql-5.0.7 drive . where the two machines for the dispenser are 2-core 8G configuration, unified resin4 JVM configuration:                <jvm-arg> -xmx1024m</jvm-arg>                 <jvm-arg>-xms1024m</jvm-arg>                 <jvm-arg>-xmn512m</jvm-arg>                 <jvm-arg>-XX:SurvivorRatio=6</jvm-arg>                <jvm-arg>- Xss1024k</jvm-arg>                 <jvm-arg>-xx:permsize=256m</jvm-arg>                 <jvm-arg>-xx:maxpermsize=256m</jvm-arg> Basic Preparation: 1, into the database into 5,180 queue data, (of which 151 machine points 2,614,152 machines divided by 2,566 ); 2, the transformation actuator, so that it only accepts data not processing data. The 5,180 data is always valid data for the dispatcher; 3, transform the dispatcher, set the ibatis parameter:cachemodelsenabled= "true",defaultstatementtimeout= "3000". load data once per 150ms; (The dispatcher has 16 threads corresponding to 16 Cobar, each of which loads the valid data in the library, each page has 200 data.) ) 4,JVISUALVM remote monitoring 151,152 machines. The test results are as follows: One,15 minutes after the monitoring results are as follows As seen from the figure 152 machine from the CPU occupied, the heap size is gradually rising, viewing the GC Log Discovery 152 has begun to appear FULLGC. 152 The machine is fast hanging: 151 the machine is all normal: Two,32 minutes after the monitoring results are as follows At this point, in addition to CPU consumption, heap high,152 of the number of threads is much higher than 151. At this time the 152 has been FULLGC frequently. 152 machine: 151 The machine: Statistics Live Object Data in heap memory: 152 machines appear with a large number of byte data as well as PreparedStatement, as well as Canceltask. 1) but no canceltask was found on the top 47-bit occupancy of the 151 machine . 2) on the Byte data volume,152 machines reach 600M, and 151 machines are only dozens of M. Test conclusion: With the frequent big data query scenario, theperformance processing of the mysql-5.1.34 drive is far superior to the mysql-5.0.7 driver.

-eof-

RCA:JDBC drives the FULLGC of its own problems