我給 Apache 頂級項目提了個 Bug

• 2020 年 11 月 26 日
• 筆記

這篇文章記錄了給 Apache 頂級項目 – 分庫分表中間件 ShardingSphere 提交 Bug 的歷程。

說實話，這是一次比較曲折的 Bug 跟蹤之旅。10月28日，我們在 GitHub 上提交 issue，中途因為官方開發者的主觀臆斷被 Close 了兩次，直到 11 月 20 日才被認定成 Bug 並發出修復版本，歷時 20 多天。

本文將還原該 Bug 的分析過程，將有價值的經驗和技術點進行提煉。通過本文，你將收穫到：

1、疑難問題的排查思路

2、資料庫中間件 Sharding Proxy 的原理

3、MySQL 預編譯的流程和交互協議

4、Wireshark 抓包分析 MySQL 的奇淫技巧

01 問題描述

這個 Bug 來源於我的公號讀者，他替公司預研 ShardingProxy（屬於 ShardingSphere 的子產品，可用作分庫分表，後文會詳細介紹）。他按照官方文檔寫了一個很簡單的 demo，但是運行後無法查詢出數據。

下面是他遇到問題後發給我的資訊，希望我能幫忙一起定位下原因。

截圖中的 doc 詳細記錄了 ShardingProxy 的配置、調試分析日誌、以及問題的具體現象。

為了方便大家理解，我重新描述下這個 Demo 的業務邏輯以及問題表象。

1. Demo 的業務邏輯說明

這個 Demo 很簡單，主要為了跑通 ShardingProxy 的分庫分表功能。程式用 SpringBoot + MyBatis 實現了一個單表的查詢邏輯，然後用這張表的一個 long 類型欄位作為分區鍵，並通過 ShardingProxy 進行了分表。

下面是那張數據表的詳細定義，共 16 個欄位，大家關注前兩個欄位即可，其他欄位和本文提到的 Bug 無關。

前兩個欄位的作用如下：

• BIZ_DT：業務欄位，date類型，和Bug有關

• ECIF_CUST_NO：bigint 類型，用做分區鍵

程式碼就是 Controller 調用 Service，Service 調用 Dao，Dao 通過 MyBatis 實現，這裡就不粘貼了。

由於使用了 ShardingProxy 中間件，因此它跟直連資料庫的配置會有所不同，在定義 dataSource 時，url 需要配置成這樣：

jdbc:mysql://127.0.0.1:3307/sharding_db?useServerPrepStmts=true&cachePrepStmts=true&serverTimezone=UTC

可以看到，jdbc 連接的是 ShardingProxy 的邏輯數據源 sharding_db，埠使用的是 3307，並非真正的底層資料庫以及 MySQL Server 的真實埠 3306，具體原理下文會介紹到。其中，標藍色的 useServerPrepStmts 和 cachePrepStmts 這兩個參數，和本文說的 Bug 有關，這裡先提一下，後面會具體分析。

另外，ShardingProxy 的分表策略是：用 long 類型的 ecif_cust_no 欄位對 2 進行取模，分成了兩張表。具體配置如下：

shardingColumn: ecif_cust_no

algorithmExpression: pscst_prdt_cvr${ecif_cust_no % 2}

2. 問題描述

再說下遇到的問題。首先，往數據表中預先插入一條 ECIF_CUST_NO 等於 10000 的數據：

然後啟動 demo 程式，使用 curl 發起 post 請求，查詢 ecifCustNo 等於 10000 的那條記錄，居然查詢不出數據：

至此，背景基本交代清楚了，為什麼資料庫中明明有數據，但是程式卻查詢不出來呢？問題到底出現在 ShardingProxy，還是應用程式本身？

02 ShardingProxy 原理簡介

在開啟這個問題的分析過程之前，我先快速普及下 ShardingProxy 的基本原理，以便大家能更好的理解我的分析思路。

開源的資料庫中間件大家一定接觸過，最流行的是 MyCat 和 ShardingSphere。其中 MyCat 是阿里開源的；ShardingSphere 是由噹噹網開源，並在京東逐漸發展壯大，於 2020 年成為了 Apache 頂級項目。

ShardingSphere 的目標是一個生態圈，它由非常著名的 ShardingJDBC、ShardingProxy、ShardingSidecar 3 款獨立的產品組成。本文重點普及下 ShardingProxy，另外兩個就不展開了。

1. 什麼是 ShardingProxy ？

ShardingProxy 屬於和 MyCat 對標的產品，定位為透明化的資料庫代理端，可以理解成：一個實現了 MySQL 協議的 Server（獨立進程），可用於讀寫分離、分庫分表、柔性事務等場景。

對於應用程式或者 DBA 來說，可以把 ShardingProxy 當做資料庫代理，能用 MySQL 客戶端工具（Navicat）或者命令行和它直接交互，而 ShardingProxy 內部則通過 MySQL 原生協議與真實的 MySQL 伺服器通訊。

從架構圖來看，ShardingProxy 就相當於 MySQL，它本身不存儲數據，但是對外屏蔽了 Database 的存儲細節，你可以用連接 MySQL 的方式去連接 ShardingProxy（除了埠不同），用你熟悉的 ORMapping 框架使用它。

2. ShardingProxy 的內部架構

再來看下 ShardingProxy 的內部架構，後續源碼分析時會涉及到此部分。

整個架構分為前端、核心組件和後端：

前端（Frontend）負責與客戶端進行網路通訊，採用的是 NIO 框架，在通訊的過程中完成對MySQL協議的編解碼。

核心組件（Core-module）得到解碼的 MySQL 命令後，開始調用 Sharding-Core 對 SQL 進行解析、改寫、路由、歸併等核心功能。

後端（Backend）與真實資料庫交互，採用 Hikari 連接池，同樣涉及到 MySQL 協議的編解碼。

3. ShardingProxy 的預編譯 SQL 功能

本文的 Bug 跟 ShardingProxy 的預編譯 SQL 有關，這裡單獨介紹下此功能以及與之相關的 MySQL 協議，這個是本文的關鍵，請耐心看完。

熟悉資料庫開發的同學一定了解：預編譯 SQL（PreparedStatement），在資料庫收到一條 SQL 到執行完畢，一般分為以下 3 步：

1、詞法和語義解析

2、優化 SQL，制定執行計劃

3、執行並返回結果

但是很多情況下，一條 SQL 語句可能會反覆執行，只是執行時的參數值不同。而預編譯功能將這些值用佔位符代替，最終達到一次編譯、多次運行的效果，省去了解析優化等過程，能大大提高 SQL 的執行效率。

假設我們要執行下面這條 SQL 兩次：

SELECT * FROM t_user WHERE user_id = 10;

那 JDBC 和 MySQL 之間的協議消息如下：

通過上述流程可以看到：第 1 條消息是PreparedStatement，查詢語句中的參數值用問號代替了，它告訴 MySQL 對這個SQL 進行預編譯；第 2 條消息 MySQL 告訴 JDBC 準備成功了；第 3 條消息 JDBC 將參數設置為 1 ；第 4 條消息 MySQL 返回查詢結果；第 5 條和第 6 條消息表示第二次執行同樣的 SQL，已經無需再次預編譯了。

再回到 ShardingProxy，如果需要支援預編譯功能，交互流程肯定是需要變的，因為 Proxy 在收到 JDBC 的PreparedStatement 命令時，SQL 里的分片鍵是問號，它根本不知道該路由到哪個真實資料庫。

因此，流程變成了下面這樣：

可以看到，Proxy在收到 PreparedStatement 命令後，並不會把這條消息轉發給MySQL，只是快取了這個 SQL，在收到 ExecuteStatement 命令後，才根據分片鍵和傳過來的參數值確定真實的資料庫，並與 MySQL 交互。

03 問題分析

上一章節基本把這個 Bug 相關的原理知識介紹清楚了，下面正式進入問題的分析過程。

最開始拿到這個問題，我也是比較頭禿的，尤其看到讀者下面這段資訊。

當然，我的功力是達不到盲猜水平的，說下我的完整思路。

第 1 步 復現問題

我讓讀者給我打包發了 Demo 的源程式碼、資料庫腳本以及 ShardingProxy 配置，然後本地安裝了 ShardingProxy 4.1.1 版本，再通過 Navicat 連接到 ShardingProxy 執行資料庫腳本，環境基本就準備完畢了。

啟動 Demo 程式後，通過 Postman 發送請求，問題穩定復現了，確實查不出數據。

第 2 步 確認應用程式是否有BUG

因為整個程式碼很簡單，程式碼層面唯一有可能存在問題的是 Mybatis 這一層。為了確認這一點，我修改了 SpringBoot 的配置，將 MyBatis 的 debug 日誌也列印了出來。再次發起請求後，能從控制台中看到以下詳細日誌：

日誌中沒發現異常，而且 PreparedStatement 以及 ExecuteStatement 的參數設置都是正確的，查詢結果確實是空。

為了縮小排查範圍，我把 dataSource 的 配置改回了直連真實資料庫，這樣能將 ShardingProxy 這個干擾因素排除在外。改完後的 url 如下：

jdbc:mysql://127.0.0.1:3306/db1?useServerPrepStmts=true&cachePrepStmts=true&serverTimezone=UTC

其中，db1 是真實資料庫，3306 也是MySQL 伺服器的埠了。然後再次用 Postman 發送請求，可以看到：有正確數據返回了。

通過這一步，我將懷疑對象再次轉移到 ShardingProxy 上了，並將 dataSource 配置改回成原樣，繼續排查。

第 3 步 排查 ShardingProxy

首先，查看 ShardingProxy 的運行日誌，沒發現任何異常；其次，能看到日誌中的 Actual SQL 是正確的，它已經根據分區鍵正確路由到了 pcsct_prdt_cvr0 這張表：

[INFO ] 17:25:48.804 [ShardingSphere-Command-15] 
ShardingSphere-SQL - Actual SQL: ds_0 ::: SELECT
BIZ_DT,ECIF_CUST_NO,DEP_FLG ...
FROM pscst_prdt_cvr0
WHERE ECIF_CUST_NO = ? ::: [10000]

因此可以推斷：ShardingProxy 的分庫分表配置應該是沒有問題的。

我開始懷疑：是否跟 ShardingProxy 所使用的資料庫驅動有關？因為這個 Jar 包是應用方選擇版本，手動放到 ShardingProxy 安裝目錄中的。因此，我將驅動版本從 5.1.47 版本改成了 8.0.13 （和 Demo 使用了相同的版本），但是問題仍然存在。

另外，還能想到的是：是否是 ShardingProxy 的這個最新版本引入了 Bug？然後，我又另外安裝了它的上一個版本 4.1.0，重新測試了一遍，還是有問題。

這個時候，真感覺沒有其他可疑點了，所有能想到的點都排查了一遍。我再次回到了 Demo 程式本身，它和 ShardingProxy 唯一的結合點就在 DataSource 的 url 上。

jdbc:mysql://127.0.0.1:3307/sharding_db?useServerPrepStmts=true&cachePrepStmts=true&serverTimezone=UTC

庫名和埠號配置無誤，唯一可疑的是另外三個參數: useServerPrepStmts、cachePrepStmts 、serverTimezone。其中，前兩個參數和預編譯 SQL 有關，是一個組合。

因此，我將這兩個參數從 url 中去掉，測試了一下。這個時候奇蹟出現了，居然返回了正確數據。至此，基本定位到了問題，但根本原因是什麼呢？究竟是不是 ShardingProxy 的 Bug ？

第 4 步 Wireshark 抓包分析 MySQL 協議

找到這個問題的解決方案後，我同步給了讀者。與此同時，他也在 ShardingProxy 的 GitHub 上提交了 issue，回饋了這個最新進展。

由於工作原因，這個問題我就暫時放一邊了，準備抽空再接著排查。

大概過了一周我想起了這個問題，然後打開 issue 想了解下調查進度，讓我非常驚訝的是：官方開發者居然在復現此問題後，主觀臆斷地認為是應用程式的問題，然後莫名奇妙的把這個 issue 關閉了，他們的答覆是這樣的：

意思就是：我們針對預編譯 SQL 功能做了大量的測試，這個是不可能存在問題的，建議你們更換下應用程式的資料庫連接池，抓包繼續分析下。

第二天，我開始用 Wireshark 抓包分析 MySQL 的協議，想弄清楚根本原因到底是什麼？同時聯繫上了官方，讓他們 reopen 了這個問題。

Wireshark 如何抓取 MySQL 協議的數據包，這裡就不展開了，大家可以網上查下資料。注意將 Wireshark 的過濾條件設置成：

mysql || tcp.port==3307

其中：mysql 表示 ShardingProxy 和 MySQL Server 之間的數據包，tcp.port==3307 表示 Demo 程式和 ShardingProxy 之間的數據包。

啟動 Wireshark 抓包後，再次用 Postman 發起請求，觸發整個過程，然後就能順利抓到下面截圖的數據包了。

大家關注底色為 深藍色 的 8 個數據包即可。在本文第 2 章節的原理部分，我已經詳細介紹過 ShardingProxy 的預編譯功能以及該流程的 MySQL 協議消息，這裡的 8 個數據包和原理介紹是完成吻合的。

那接下來如何進一步分析呢？結合 ShardingProxy 的架構圖來思考下：Proxy 僅僅作為一個中間代理，介於應用程式和 MySQL Server 之間，它完全實現了 MySQL 協議，以便對 MySQL 命令進行解碼和編碼，然後加上自己的分庫分表邏輯。

如果 ShardingProxy 內部存在 Bug，那一定是某個數據包出現了問題。順著這個思路，很快就能發現：執行完 ExecuteStatement 後，MySQL Server 返回正確數據包給 Proxy 了，但是 Proxy 沒有返回正確的數據包給應用程式。

下面截圖的是倒數第 2 個 Response 數據包，由 MySQL Server 返回給 Proxy 的，Payload 中能看到那條記錄的數據：

下面截圖的是最後 1 個 Response 數據包，由 Proxy 返回給應用程式的，Payload 中只能看到表欄位的定義，那條記錄已經不翼而飛了。

通過這一步分析，就已經坐實了：ShardingProxy 是有 Bug 的。然後，我將這些依據發給了官方開發者，對方開始重視，並正式進入源碼分析階段。

04 根本原因定位

當天晚上，官方開發者就定位到了根本原因，發出了 Pull Request。我看了下程式碼改動，僅僅修改了一行程式碼。

改動的這行程式碼，就是在 ShardingProxy 再次組裝數據包返回給應用程式時拋出來的。

由於我們的數據表中存在一個 date 類型的欄位，改動的這行程式碼卻強制將 date 類型轉換成了 Timestamp 類型，因此拋出了異常。還有幾個疑點，我結合對源程式碼的理解逐一解答下。

1、為什麼程式碼拋異常了，但是 ShardingProxy 的控制台沒列印呢？

上面截圖的是：拋出 ClassCastException 那個方法的整個調用鏈。由於 ShardingProxy 並沒有捕獲這個 RuntimeException 以及列印日誌，最終這個異常被 netty 吞掉了。

2、為什麼 ShardingProxy 需要做 date 到 Timestamp 的類型轉換呢？

可以從 ShardingProxy 的架構來理解，因為 Proxy 只有對 MySQL 協議進行編解碼後，才能在中間插入它的分庫分表邏輯。

針對 date 類型的欄位，ShardingProxy 通過 JDBC 的 API 從查詢結果中拿到的仍然是 Date 類型，之所以要轉換成 Timestamp，這個又跟 MySQL 的協議有關了，下面是 MySQL 官方文檔的說明：

簡單理解就是：ShardingProxy 在程式碼實現時，用了一個範圍最大的 timestamp 存了三種可能的值 date, datetime 和 timestamp，然後再按照上面這個協議規範進行二進位的寫入。

3、這個 Bug 是只有在使用 SQL 預編譯功能時才會被觸發嗎？

是的，只有在處理 ExecuteStatement 命令時，這個方法才會被調用到。那普通的 SQL 查詢場景為什麼用不到呢？

這個又跟 MySQL 協議有關了，普通的 SQL 查詢場景，payload 不是二進位協議的，而是普通的文本協議。這種情況下，無需調用這個類進行轉換。

至此，整個分析過程就結束了。

05 寫在最後

本文詳細復盤了這個 Bug 的分析過程，並對其中的原理知識和排查經驗進行了總結。

對於 ShardingSphere 這種頂級開源項目來說，我個人覺得同樣值得做一次深度復盤。我不認同他們對於 issue 的處理方式，另外在核心功能的自動化測試上，也一定是存在 case 不完善的，不然不可能連續多個版本都沒發現這個嚴重 Bug。

如果你有任何疑問，歡迎評論區留言討論。

作者簡介：985碩士，前亞馬遜工程師，現58轉轉技術總監

歡迎掃描下方的二維碼，關注我的個人公眾號：IT人的職場進階