同事升級了MySQL驅動8.0，致使應用大量超時

送你們如下學習資料

現象

最近同事發現新服務用的驅動都是 MySQL8.0，而一些老系統 MySQL 驅動版本較低，存在一些危險漏洞，因而主動的把一些老應用的 MySQL 驅動程序升級到了 8.0。然而升級後，在併發量較高時，查看監控打點，Druid 鏈接池拿到鏈接並執行 SQL 的時間大部分都超過 200ms。

本文詳細的分析了此次「破案」的全過程。

對系統進行壓測，發現出現大量線程阻塞的狀況，線程 dump 信息以下：

`"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.java: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)`

經過上面的信息得知，有線程 BLOCKED 了，BLOCKED 的位置在 com.alibaba.druid.util.Utils.loadClass(Utils.java:220)，因而重點的查看這一塊的代碼，最終發現了問題。

根因分析

`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);`
 `}`
 `}`

MySqlUtils 中的getLastPacketReceivedTimeMs()方法會加載com.mysql.jdbc.MySQLConnection這個類，但在 MySQL 驅動 8.0 中類名改成com.mysql.cj.jdbc.ConnectionImpl，因此 MySQL 驅動8.0 中加載不到com.mysql.jdbc.MySQLConnection

getLastPacketReceivedTimeMs()方法實現中，若是Utils.loadClass("com.mysql.jdbc.MySQLConnection")加載不到類並拋出異常，會修改變量 class\_connectionImpl\_Error，下次調用不會再進行加載

`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;`
 `}`

可是，在 Utils 的loadClass()方法中一樣 catch了ClassNotFoundException，這就致使loadClass()在加載不到類的時候，並不會拋出異常，從而會致使每調用一次getLastPacketReceivedTimeMs()方法，就會加載一次 MySQLConnection 這個類

線程 dump 信息中能夠看到是在調用 TomcatEmbeddedWebappClassLoader 的loadClass()方法時，致使線程阻塞的。

`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);`
 `}`
 `}`

這是由於 TomcatEmbeddedWebappClassLoader 在加載類的時候，會加synchronized鎖，這就致使每調用一次getLastPacketReceivedTimeMs()方法，就會加載一次com.mysql.jdbc.MySQLConnection，而又始終加載不到，在加載類的時候會加 synchronized 鎖，因此會出現線程阻塞，性能降低的現象。

getLastPacketReceivedTimeMs()方法調用時機

`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);`
 `}`
 `}`
 `}`

只有DruidAbstractDataSource的testConnectionInternal()方法中會調用getLastPacketReceivedTimeMs()方法

testConnectionInternal()是用來檢測鏈接是否有效的，在獲取鏈接和歸還鏈接時都有可能會調用該方法，這取決於Druid檢測鏈接是否有效的參數

「Druid檢測鏈接是否有效的參數」：

• testOnBorrow：每次獲取鏈接時執行validationQuery檢測鏈接是否有效（會影響性能）
• testOnReturn：每次歸還鏈接時執行validationQuery檢測鏈接是否有效（會影響性能）
• testWhileIdle：申請鏈接的時候檢測，若是空閒時間大於timeBetweenEvictionRunsMillis，執行validationQuery檢測鏈接是否有效

應用中設置了testOnBorrow=true，每次獲取鏈接時，都會去搶佔synchronized鎖，因此性能降低的很明顯

解決方案

經驗證，使用Druid 1.x版本<=1.1.22會出現該bug，解決方案就是升級至Druid 1.x版本>=1.1.23或者Druid 1.2.x版本

GitHub issue：https://github.com/alibaba/dr...