【踩坑日記】Druid連接池在MySQL主備切換時引發高可用問題

背景

由於MySQL供應商內部升級，線上數據庫需要主動進行主備切換。切換基於SIP漂移，理論上是毫秒級閃斷。但在實際模擬演練的過程中，除了預期內切換瞬間產生的連接異常外，后續半個小時仍不斷地產生連接異常，導致問題不可控。

org.springframework.dao.RecoverableDataAccessException:
### Error querying database.  Cause: com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure
 
The last packet sent successfully to the server was 11,603,448 milliseconds ago.; nested exception is java.lang.Throwable
    at org.springframework.jdbc.support.SQLExceptionSubclassTranslator.doTranslate(SQLExceptionSubclassTranslator.java:100)
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72)
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:81)
    ······
    
Caused by: java.io.IOException: Socket is closed
    at com.mysql.cj.protocol.AbstractSocketConnection.getMysqlInput(AbstractSocketConnection.java:72)
    at com.mysql.cj.protocol.a.NativeProtocol.clearInputStream(NativeProtocol.java:803)
    ... 130 common frames omitted

主備切換后仍有一段時間的報錯

分析

排除服務端影響

首先進行一下分析：在報錯中顯示錯誤為CommunicationsException: Communications link failure，並且Caused by: java.io.IOException: Socket is closed，由此可知此時業務方取出的連接已經關閉了。而The last packet sent successfully to the server was 11,603,448 milliseconds ago指出上一次成功送出數據包到服務端的時間已經是很久之前了。

為了排除連接在取出后才關閉的可能性，我將連接池的TestOnBorrow開關打開。

testOnBorrow：每次獲取連接的時候都會執行validate操作，確保連接取出時有效，對性能有損耗。

在取出前校驗，就可以過濾所有取出前就已失效的連接，如果仍有錯誤，證明MySQL服務端持續有通信問題。

演練結果證明了服務端的清白，報錯不再持續出現。

雖然TestOnBorrow能解決無效連接，但作為代價，每一條SQL都會PING一次服務端進行校驗，這對性能的影響還是不容小覷的，可不能這樣簡單交差。

在排除服務端的問題后，我們將目光鎖定到應用使用的數據庫連接池——Druid。

讀源碼

既然是獲取連接時報錯，我們就分析一下獲取連接的源代碼。
以下為com.alibaba.druid.pool.DruidDataSource#getConnectionDirect的核心邏輯

       for (;;) {
           //省略從連接池中取出poolableConnection的邏輯
           
            if (testOnBorrow) {
                boolean validate = testConnectionInternal(poolableConnection.holder, poolableConnection.conn);
                if (!validate) {
                    if (LOG.isDebugEnabled()) {
                        LOG.debug("skip not validate connection.");
                    }

                    Connection realConnection = poolableConnection.conn;
                    discardConnection(realConnection);
                    continue;
                }
            } else {
                Connection realConnection = poolableConnection.conn;
                if (poolableConnection.conn.isClosed()) {
                    discardConnection(null); // 傳入null，避免重復關閉
                    continue;
                }

                if (testWhileIdle) {
                    final DruidConnectionHolder holder = poolableConnection.holder;
                    long currentTimeMillis             = System.currentTimeMillis();
                    long lastActiveTimeMillis          = holder.lastActiveTimeMillis;
                    long lastKeepTimeMillis            = holder.lastKeepTimeMillis;

                    if (lastKeepTimeMillis > lastActiveTimeMillis) {
                        lastActiveTimeMillis = lastKeepTimeMillis;
                    }

                    long idleMillis                    = currentTimeMillis - lastActiveTimeMillis;

                    long timeBetweenEvictionRunsMillis = this.timeBetweenEvictionRunsMillis;

                    if (timeBetweenEvictionRunsMillis <= 0) {
                        timeBetweenEvictionRunsMillis = DEFAULT_TIME_BETWEEN_EVICTION_RUNS_MILLIS;
                    }

                    if (idleMillis >= timeBetweenEvictionRunsMillis
                            || idleMillis < 0 // unexcepted branch
                            ) {
                        boolean validate = testConnectionInternal(poolableConnection.holder, poolableConnection.conn);
                        if (!validate) {
                            if (LOG.isDebugEnabled()) {
                                LOG.debug("skip not validate connection.");
                            }

                            discardConnection(realConnection);
                             continue;
                        }
                    }
                }
            }
        }

當testOnBorrow開啟時，會直接調用testConnectionInternal進行連接檢查，連接失效則直接踢出，進入下一次循環。這是我們剛才驗證過的可行路徑，而關閉testOnBorrow時失效連接暴露出來了，意味着沒有調用testConnectionInternal。帶着這樣的假設，我們再看else塊。

在else中，首先判斷testWhileIdle是否開啟，應用配置是開啟的（默認也是開啟），是則同時取出連接的lastActiveTimeMillis和lastKeepTimeMillis，取較大者，與當前時間取差值，如果大於等於timeBetweenEvictionRunsMillis，則進行testConnectionInternal校驗，同樣的，校驗不通過則拋棄。

簡單講，在else塊中就是durid實現的testWhileIdle機制：在連接取出時，判斷如果連接空閑超過指定時間（默認為1分鍾），則進行校驗，否則直接借出。

在前文中的報錯信息里，連接最后一次傳輸數據是在3個小時前，如此長時間的空閑理應進行校驗（校驗的正確性我們已在testOnBorrow中驗證），然而從現象來看卻是沒有的，說明計算出的空閑時間沒有滿足檢測門檻。

通過代碼分析，lastActiveTimeMillis就是連接使用時間 ，所以應在3個小時前，至此我們的分析剩下了最后一個可變量：lastKeepTimeMillis，這個字段從何而來？

連接保活機制

druid中設計了一種連接保活機制，開啟后將定時校驗連接的有效性。這個任務由DruidDataSource.DestroyTask承擔，在線程池初始化后通過調度線程池以timeBetweenEvictionRunsMillis為周期定時執行（當前為1分鍾）。

以下是連接保活中的校驗部分

                try {
                    this.validateConnection(connection);
                    validate = true;
                } catch (Throwable error) {
                    if (LOG.isDebugEnabled()) {
                        LOG.debug("keepAliveErr", error);
                    }
                    // skip
                }

                boolean discard = !validate;
                if (validate) {
                    holer.lastKeepTimeMillis = System.currentTimeMillis();
                    boolean putOk = put(holer);
                    if (!putOk) {
                        discard = true;
                    }
                }

當validate為真（即檢查通過）時，前文提到的lastKeepTimeMillis被刷新為當前時間。

所以保活機制對testWhileIdle形成了一種補充，當連接已在保活任務中被校驗過了，即使很久沒有被借給業務方，也不會進行冗余的testWhileIdle檢查，這也是一種性能優化。

然而問題就出在了validateConnection這個校驗方法中...（ps：為何不直接復用前文中的testConnectionInternal呢？）

以下是這個校驗方法的核心邏輯，錯誤就在其中，試着發現一下：

            boolean result = true;
            Exception error = null;
            try {
                result = validConnectionChecker.isValidConnection(conn, validationQuery, validationQueryTimeout);
            } catch (SQLException ex) {
                throw ex;
            } catch (Exception ex) {
                error = ex;
            }
            
            if (!result) {
                SQLException sqlError = error != null ? //
                    new SQLException("validateConnection false", error) //
                    : new SQLException("validateConnection false");
                throw sqlError;
            }
            return;

問題就在catch (Exception ex) 的處理塊中：result沒有置為false。
導致非SQLException的錯誤（例如服務端主動斷開導致的IO類異常）沒有拋出，從而“躲過”了保活篩查，同時又刷新了lastKeepTimeMillis，再次“躲過”testWhileIdle檢查，最終成功來到了業務方的世界，開始大搞破壞～

結論

解決方案：在catch塊內補上result = false即可，如果你不想自己動手，可以使用最近更新的1.2.6版本，已修復這個issue。

升級版本后，不再持續出現連接錯誤。