The phenomenon of

Recently, my colleague found that the driver used by the new service is MySQL8.0, while the MySQL driver version of some old systems is relatively low and there are some dangerous vulnerabilities, so he took the initiative to upgrade the MySQL driver of some old applications to 8.0. However, the Druid connection pool takes more than 200ms to get a connection and execute SQL when you look at the monitoring points when the concurrency is high.

This paper analyzes the whole process of this “case solving” in detail.

A large number of threads are blocked when the system is pressed. Thread dump information is as follows:

`"http-nio-5366-exec-48" #210 daemon prio=5 os_prio=0 tid=0x00000000023d0800 nid=0x3be9 waiting for monitor entry [0x00007fa4c1400000]` `java.lang.Thread.State: BLOCKED (on object monitor)` `at org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader.loadClass(TomcatEmbeddedWebappClassLoader.j ava:66)` `- waiting to lock <0x0000000775af0960> (a java.lang.Object)` `at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1186)` `at com.alibaba.druid.util.Utils.loadClass(Utils.java:220)` `at com.alibaba.druid.util.MySqlUtils.getLastPacketReceivedTimeMs(MySqlUtils.java:372)`Copy the code

Through the above information, have the threads BLOCKED, the location of the BLOCKED in com. Alibaba. Druid. Util. Utils. LoadClass (Utils. Java: 220), and focus on the view of this piece of code, finally found out the problem.

Returning for analysis

`public class MySqlUtils {` `public static long getLastPacketReceivedTimeMs(Connection conn) throws SQLException {` `if (class_connectionImpl == null && ! class_connectionImpl_Error) {` `try {` `class_connectionImpl = Utils.loadClass("com.mysql.jdbc.MySQLConnection"); ` `} catch (Throwable error){` `class_connectionImpl_Error = true; ` `}` `}` `if (class_connectionImpl == null) {` `return -1; ` `}` `if (method_getIO == null && ! method_getIO_error) {` `try {` `method_getIO = class_connectionImpl.getMethod("getIO"); ` `} catch (Throwable error){` `method_getIO_error = true; ` `}` `}` `if (method_getIO == null) {` `return -1; ` `}` `if (class_MysqlIO == null && ! class_MysqlIO_Error) {` `try {` `class_MysqlIO = Utils.loadClass("com.mysql.jdbc.MysqlIO"); ` `} catch (Throwable error){` `class_MysqlIO_Error = true; ` `}` `}` `if (class_MysqlIO == null) {` `return -1; ` `}` `if (method_getLastPacketReceivedTimeMs == null && ! method_getLastPacketReceivedTimeMs_error) {` `try {` `Method method = class_MysqlIO.getDeclaredMethod("getLastPacketReceivedTimeMs"); ` `method.setAccessible(true); ` `method_getLastPacketReceivedTimeMs = method; ` `} catch (Throwable error){` `method_getLastPacketReceivedTimeMs_error = true; ` `}` `}` `if (method_getLastPacketReceivedTimeMs == null) {` `return -1; ` `}` `try {` `Object connImpl = conn.unwrap(class_connectionImpl); ` `if (connImpl == null) {` `return -1; ` `}` `Object mysqlio = method_getIO.invoke(connImpl); ` `Long ms = (Long) method_getLastPacketReceivedTimeMs.invoke(mysqlio); ` `return ms.longValue(); ` `} catch (IllegalArgumentException e) {` `throw new SQLException("getLastPacketReceivedTimeMs error", e); ` `} catch (IllegalAccessException e) {` `throw new SQLException("getLastPacketReceivedTimeMs error", e); ` `} catch (InvocationTargetException e) {` `throw new SQLException("getLastPacketReceivedTimeMs error", e); ` ` `} ` `}Copy the code

In MySqlUtils getLastPacketReceivedTimeMs () method loads com. Mysql. JDBC. MySQLConnection this class, But the name of the class in the MySQL driver 8.0 to com. MySQL. Cj. JDBC. ConnectionImpl, so can’t load in MySQL driver 8.0 com. MySQL. JDBC. MySQLConnection

GetLastPacketReceivedTimeMs () method implementation, if Utils loadClass (” com. Mysql. JDBC. MySQLConnection “) to load is less than class and throws an exception, The class_connectionImpl_Error variable is modified and will not be loaded in the next call

`public class Utils {` `public static Class<? > loadClass(String className) {` `Class<? > clazz = null; ` `if (className == null) {` `return null; ` `}` `try {` `return Class.forName(className); ` `} catch (ClassNotFoundException e) {` `// skip` `}` `ClassLoader ctxClassLoader = Thread.currentThread().getContextClassLoader(); ` `if (ctxClassLoader ! = null) {` `try {` `clazz = ctxClassLoader.loadClass(className); ` `} catch (ClassNotFoundException e) {` `// skip` `}` `}` `return clazz; ` ` `}Copy the code

However, the loadClass() method of Utils also catches ClassNotFoundException, which causes loadClass() not to throw an exception when the class cannot be loaded. Which would lead to every call getLastPacketReceivedTimeMs () method, which will load a MySQLConnection this class

Can see in the thread dump information is in the call of TomcatEmbeddedWebappClassLoader loadClass () method, causes the thread block.

`public class TomcatEmbeddedWebappClassLoader extends ParallelWebappClassLoader {` `public Class<? > loadClass(String name, boolean resolve) throws ClassNotFoundException {` `synchronized (JreCompat.isGraalAvailable() ? this : getClassLoadingLock(name)) {` `Class<? > result = findExistingLoadedClass(name); ` `result = (result ! = null) ? result : doLoadClass(name); ` `if (result == null) {` `throw new ClassNotFoundException(name); ` `}` `return resolveIfNecessary(result, resolve); ` ` `} ` `}Copy the code

This is because the TomcatEmbeddedWebappClassLoader when loading a class, will add synchronized lock, this leads to every call getLastPacketReceivedTimeMs () method, Will load a com. Mysql. JDBC. MySQLConnection, and can’t load all the time, at the time of loading class will add synchronized lock, so there will be threads blocked, the phenomenon of performance degradation.

getLastPacketReceivedTimeMs()Method call timing

`public abstract class DruidAbstractDataSource extends WrapperAdapter implements DruidAbstractDataSourceMBean, DataSource, DataSourceProxy, Serializable {` `protected boolean testConnectionInternal(DruidConnectionHolder holder, Connection conn) {` `String sqlFile = JdbcSqlStat.getContextSqlFile(); ` `String sqlName = JdbcSqlStat.getContextSqlName(); ` `if (sqlFile ! = null) {` `JdbcSqlStat.setContextSqlFile(null); ` `}` `if (sqlName ! = null) {` `JdbcSqlStat.setContextSqlName(null); ` `}` `try {` `if (validConnectionChecker ! = null) {` `boolean valid = validConnectionChecker.isValidConnection(conn, validationQuery, validationQueryTimeout); ` `long currentTimeMillis = System.currentTimeMillis(); ` `if (holder ! = null) {` `holder.lastValidTimeMillis = currentTimeMillis; ` `holder.lastExecTimeMillis = currentTimeMillis; ` `}` `if (valid && isMySql) { // unexcepted branch` `long lastPacketReceivedTimeMs = MySqlUtils.getLastPacketReceivedTimeMs(conn); ` `if (lastPacketReceivedTimeMs > 0) {` `long mysqlIdleMillis = currentTimeMillis - lastPacketReceivedTimeMs; ` `if (lastPacketReceivedTimeMs > 0 //` `&& mysqlIdleMillis >= timeBetweenEvictionRunsMillis) {` `discardConnection(holder); ` `String errorMsg = "discard long time none received connection. "` `+ ", jdbcUrl : " + jdbcUrl` `+ ", jdbcUrl : " + jdbcUrl` `+ ", lastPacketReceivedIdleMillis : " + mysqlIdleMillis; ` `LOG.error(errorMsg); ` `return false; ` `}` `}` `}` `if (valid && onFatalError) {` `lock.lock(); ` `try {` `if (onFatalError) {` `onFatalError = false; ` `}` `} finally {` `lock.unlock(); ` `}` `}` `return valid; ` `}` `if (conn.isClosed()) {` `return false; ` `}` `if (null == validationQuery) {` `return true; ` `}` `Statement stmt = null; ` `ResultSet rset = null; ` `try {` `stmt = conn.createStatement(); ` `if (getValidationQueryTimeout() > 0) {` `stmt.setQueryTimeout(validationQueryTimeout); ` `}` `rset = stmt.executeQuery(validationQuery); ` `if (! rset.next()) {` `return false; ` `}` `} finally {` `JdbcUtils.close(rset); ` `JdbcUtils.close(stmt); ` `}` `if (onFatalError) {` `lock.lock(); ` `try {` `if (onFatalError) {` `onFatalError = false; ` `}` `} finally {` `lock.unlock(); ` `}` `}` `return true; ` `} catch (Throwable ex) {` `// skip` `return false; ` `} finally {` `if (sqlFile ! = null) {` `JdbcSqlStat.setContextSqlFile(sqlFile); ` `}` `if (sqlName ! = null) {` `JdbcSqlStat.setContextSqlName(sqlName); ` `} ` `} ` ` `}Copy the code

Only DruidAbstractDataSource testConnectionInternal () method will be called getLastPacketReceivedTimeMs () method

TestConnectionInternal () is used to check whether a connection is valid. This method may be called either when a connection is acquired or when a connection is returned, depending on the parameters Druid uses to check whether the connection is valid

Druid specifies whether a connection is valid.

  • TestOnBorrow: validationQuery is executed each time a connection is fetched to check whether the connection is valid (affecting performance)

  • TestOnReturn: validationQuery is executed each time a connection is returned to check whether the connection is valid (affecting performance)

  • TestWhileIdle: application connection testing, if free time is more than timeBetweenEvictionRunsMillis, performing validationQuery test connection is valid

TestOnBorrow =true is set in the application, and each time a connection is acquired, the synchronized lock will be preempt, so the performance degradation is obvious

The solution

X <=1.1.22. The solution is to upgrade to Druid 1.x >=1.1.23 or Druid 1.2.x

Making issue:github.com/alibaba/dru…

Send you the following learning materials, pay attention to the public number: IT elder brother, reply to the interview and actual combat project to receive