1. 程式人生 > >一個MySQL-JDBC驅動bug引起的血案……

一個MySQL-JDBC驅動bug引起的血案……

快速 調整 before nal pre create ext ado proc

問題背景
公司是做電商系統的,整個系統搭建在華為雲上。系統設計的時候,考慮到後續的用戶和訂單數量比較大,需要使用一些大數據庫的組件。關系型數據庫這塊,考慮到後續數據量的快速增長,不是直接寫入MySQL,而是使用了華為雲的分布式數據庫中間件DDM。使用了DDM之後,可以在業務不感知的情況下,直接增加MySQL讀實例的個數,線性提升讀性能。也支持中間件層面的分庫分表,提供海量關系型數據庫的操作。簡直是為電商系統貼身定制的。

DDM自身是以集群形式提供服務的,對業務開放的是多個連接IP地址。需要有一層負載均衡。如果使用傳統的加LB的形式做負載均衡,會多一層中轉,有性能損耗。所以,直接使用了MySQL-JDBC提供的客戶端負載均衡能力。

邏輯結構如下圖所示:
技術分享圖片
▲業務通過MySQL-JDBC的Loadbalance能提訪問多個DDM節點。MySQL-JDBC提供負載均衡能力。

問題說明
MySQL JDBC驅動的客戶端負載均衡能力,一直運行得好好,性能嗷嗷叫。可是前一陣子竟無故出現業務請求失敗。我是負責電商訂單模塊的,涉及到真實的Money,這個問題可嚇了寶寶一身冷汗……

於是趕緊查看了後臺日誌,發現是訪問DDM出現了異常,二話不說直接提了工單給華為雲DDM服務。
技術分享圖片

不得不說,華為雲的服務還是很好的,不到半個小時就有專門的工作人員聯系了我,還跟我一起排查問題。將我們業務的日誌取下來,和DDM的支撐人員一起分析,發現報錯如下:根本原因竟然是MySQL驅動的bug,導致StackOverflow本地棧溢出導致……原來是一個Bug引發的血案,誤會了DDM服務,真是抱歉了……

技術分享圖片
技術分享圖片

從堆棧可以看出來,某個異常,觸發了MySQL-JDBC的bug,導致循環調用,直至棧溢出。在華為DDM支撐人員的建議下,對驅動代碼進行了反編譯,從反編譯的情況下,可以看到的確是存在循環嵌套的可能。

Loadbalance輪詢連接 –>同步新老連接的狀態 ->發送sql給服務端 -> Loadbalance輪詢連接。

相關代碼如下:
com/mysql/jdbc/LoadBalancedConnectionProxy.java的pickNewConnection()函數
for (int hostsTried = 0, hostsToTry = this.hostList.size(); hostsTried < hostsToTry; hostsTried++) {

ConnectionImpl newConn = null;
try {
newConn = this.balancer.pickConnection(this, Collections.unmodifiableList(this.hostList), Collections.unmodifiableMap(this.liveConnections),
this.responseTimes.clone(), this.retriesAllDown);

    if (this.currentConnection != null) {
        if (pingBeforeReturn) {
            if (pingTimeout == 0) {
                newConn.ping();
            } else {
                newConn.pingInternal(true, pingTimeout);
            }
        }

        syncSessionState(this.currentConnection, newConn);
    }

    this.currentConnection = newConn;
    return;

} catch (SQLException e) {
    if (shouldExceptionTriggerConnectionSwitch(e) && newConn != null) {
        // connection error, close up shop on current connection
        invalidateConnection(newConn);
    }
}

}
syncSessionState()函數,在執行完SQL之後,又會調用postProcess()函數,如此嵌套循環就來了。
if (!this.conn.getAutoCommit()) {
this.matchingAfterStatementCount = 0;
// auto-commit is enabled:
} else {

if (this.proxy == null && this.conn.isProxySet()) {
    MySQLConnection lcl_proxy = this.conn.getMultiHostSafeProxy();
    while (lcl_proxy != null && !(lcl_proxy instanceof LoadBalancedMySQLConnection)) {
        lcl_proxy = lcl_proxy.getMultiHostSafeProxy();
    }
    if (lcl_proxy != null) {
        this.proxy = ((LoadBalancedMySQLConnection) lcl_proxy).getThisAsProxy();
    }

}

if (this.proxy != null) {
    // increment the match count if no regex specified, or if matches:
    if (this.matchingAfterStatementRegex == null || sql.matches(this.matchingAfterStatementRegex)) {
        this.matchingAfterStatementCount++;
    }
}
// trigger rebalance if count exceeds threshold:
if (this.matchingAfterStatementCount >= this.matchingAfterStatementThreshold) {
    this.matchingAfterStatementCount = 0;
    try {
        if (this.proxy != null) {
            this.proxy.pickNewConnection();
        }

    } catch (SQLException e) {
        // eat this exception, the auto-commit statement completed, but we could not rebalance for some reason.  User may get exception when using
        // connection next.
    }
}

}

這麽明顯的bug,不太相信MySQL會沒有發現。當前我們使用的是5.1.44版本的驅動,查看了下最新的5.1.66的代碼,發現的確是修復了這個問題的,代碼如下:

public ResultSetInternalMethods postProcess(String sql, Statement interceptedStatement, ResultSetInternalMethods originalResultSet, Connection connection,
int warningCount, boolean noIndexUsed, boolean noGoodIndexUsed, SQLException statementException) throws SQLException {

// Don‘t count SETs neither SHOWs. Those are mostly used internally and must not trigger a connection switch.
if (!this.countStatements || StringUtils.startsWithIgnoreCase(sql, "SET") || StringUtils.startsWithIgnoreCase(sql, "SHOW")) {
    return originalResultSet;
}

通過過濾掉SET和SHOW語句,避免了循環嵌套的發生。但是5.1.66又引入了新的bug,由於並不是每個調用postProcess的地方都有SQL,這裏的代碼會拋空指針異常。MySQL JDBC的開發者都不做測試的嗎……

沒辦法,分析了下5.1.44的代碼,發現通過適當的調整loadBalanceAutoCommitStatementThreshold這個參數的數值,也可以避免循環嵌套的發生。我們的環境改成了5,修改之後,平穩運行1周,沒再出現過問題。


修改方案
loadBalanceAutoCommitStatementThreshold修改成了5,但是引入的問題是,如果業務包含一些比較耗時的SQL,可能會導致DDM的負載不均衡。不過,就目前情況來看,DDM的性能還是比較強勁的~點擊這裏,免費體驗一番吧!

一個MySQL-JDBC驅動bug引起的血案……