[[356276]] 

圖片來自 Pexels

說實(shí)話，這是一次比較曲折的 Bug 跟蹤之旅。10 月 28 日，我們?cè)?GitHub 上提交 issue，中途因?yàn)楣俜介_發(fā)者的主觀臆斷被 Close 了兩次，直到 11 月 20 日才被認(rèn)定成 Bug 并發(fā)出修復(fù)版本，歷時(shí) 20 多天。

本文將還原該 Bug 的分析過程，將有價(jià)值的經(jīng)驗(yàn)和技術(shù)點(diǎn)進(jìn)行提煉。通過本文，你將收獲到：

• 疑難問題的排查思路
• 數(shù)據(jù)庫中間件 Sharding Proxy 的原理
• MySQL 預(yù)編譯的流程和交互協(xié)議
• Wireshark 抓包分析 MySQL 的奇淫技巧

問題描述

這個(gè) Bug 來源于我的讀者，他替公司預(yù)研 ShardingProxy(屬于 ShardingSphere 的子產(chǎn)品，可用作分庫分表，后文會(huì)詳細(xì)介紹)。

他按照官方文檔寫了一個(gè)很簡單的 demo，但是運(yùn)行后無法查詢出數(shù)據(jù)。

下面是他遇到問題后發(fā)給我的信息，希望我能幫忙一起定位下原因：

 

截圖中的 doc 詳細(xì)記錄了 ShardingProxy 的配置、調(diào)試分析日志、以及問題的具體現(xiàn)象。

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

Demo 的業(yè)務(wù)邏輯說明

這個(gè) Demo 很簡單，主要為了跑通 ShardingProxy 的分庫分表功能。程序用 SpringBoot+MyBatis 實(shí)現(xiàn)了一個(gè)單表的查詢邏輯，然后用這張表的一個(gè) long 類型字段作為分區(qū)鍵，并通過 ShardingProxy 進(jìn)行了分表。

下面是那張數(shù)據(jù)表的詳細(xì)定義，共 16 個(gè)字段，大家關(guān)注前兩個(gè)字段即可，其他字段和本文提到的 Bug 無關(guān)。

 

前兩個(gè)字段的作用如下：

• BIZ_DT：業(yè)務(wù)字段，date 類型，和 Bug 有關(guān)
• ECIF_CUST_NO：bigint 類型，用做分區(qū)鍵

代碼就是 Controller 調(diào)用 Service，Service 調(diào)用 Dao，Dao 通過 MyBatis 實(shí)現(xiàn)，這里就不粘貼了。

由于使用了 ShardingProxy 中間件，因此它跟直連數(shù)據(jù)庫的配置會(huì)有所不同，在定義 dataSource 時(shí)，url 需要配置成這樣：

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

可以看到，jdbc 連接的是 ShardingProxy 的邏輯數(shù)據(jù)源 sharding_db，端口使用的是 3307，并非真正的底層數(shù)據(jù)庫以及 MySQL Server 的真實(shí)端口 3306，具體原理下文會(huì)介紹到。

其中，標(biāo)藍(lán)色的 useServerPrepStmts 和 cachePrepStmts 這兩個(gè)參數(shù)，和本文說的 Bug 有關(guān)，這里先提一下，后面會(huì)具體分析。

另外，ShardingProxy 的分表策略是：用 long 類型的 ecif_cust_no 字段對(duì) 2 進(jìn)行取模，分成了兩張表。

具體配置如下：

shardingColumn: ecif_cust_noalgorithmExpression: pscst_prdt_cvr${ecif_cust_no % 2}

問題描述

再說下遇到的問題。首先，往數(shù)據(jù)表中預(yù)先插入一條 ECIF_CUST_NO 等于 10000 的數(shù)據(jù)：

然后啟動(dòng) demo 程序，使用 curl 發(fā)起 post 請(qǐng)求，查詢 ecifCustNo 等于 10000 的那條記錄，居然查詢不出數(shù)據(jù)：

 

至此，背景基本交代清楚了，為什么數(shù)據(jù)庫中明明有數(shù)據(jù)，但是程序卻查詢不出來呢?問題到底出現(xiàn)在 ShardingProxy，還是應(yīng)用程序本身?

ShardingProxy 原理簡介

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

開源的數(shù)據(jù)庫中間件大家一定接觸過，最流行的是 MyCat 和 ShardingSphere。

其中 MyCat 是阿里開源的;ShardingSphere 是由當(dāng)當(dāng)網(wǎng)開源，并在京東逐漸發(fā)展壯大，于 2020 年成為了 Apache 頂級(jí)項(xiàng)目。

ShardingSphere 的目標(biāo)是一個(gè)生態(tài)圈，它由非常著名的 ShardingJDBC、ShardingProxy、ShardingSidecar 3 款獨(dú)立的產(chǎn)品組成。本文重點(diǎn)普及下 ShardingProxy，另外兩個(gè)就不展開了。

什么是 ShardingProxy?

ShardingProxy 屬于和 MyCat 對(duì)標(biāo)的產(chǎn)品，定位為透明化的數(shù)據(jù)庫代理端，可以理解成：一個(gè)實(shí)現(xiàn)了 MySQL 協(xié)議的 Server(獨(dú)立進(jìn)程)，可用于讀寫分離、分庫分表、柔性事務(wù)等場景。

對(duì)于應(yīng)用程序或者 DBA 來說，可以把 ShardingProxy 當(dāng)做數(shù)據(jù)庫代理，能用 MySQL 客戶端工具(Navicat)或者命令行和它直接交互。

而 ShardingProxy 內(nèi)部則通過 MySQL 原生協(xié)議與真實(shí)的 MySQL 服務(wù)器通信。

 

圖 1：ShardingProxy 的應(yīng)用架構(gòu)圖

從架構(gòu)圖來看，ShardingProxy 就相當(dāng)于 MySQL，它本身不存儲(chǔ)數(shù)據(jù)，但是對(duì)外屏蔽了 Database 的存儲(chǔ)細(xì)節(jié)。

你可以用連接 MySQL 的方式去連接 ShardingProxy(除了端口不同)，用你熟悉的 ORMapping 框架使用它。

ShardingProxy 的內(nèi)部架構(gòu)

再來看下 ShardingProxy 的內(nèi)部架構(gòu)，后續(xù)源碼分析時(shí)會(huì)涉及到此部分。

 

圖 2：ShardingProxy 的內(nèi)部架構(gòu)圖

整個(gè)架構(gòu)分為前端、核心組件和后端：

• 前端(Frontend)：負(fù)責(zé)與客戶端進(jìn)行網(wǎng)絡(luò)通信，采用的是 NIO 框架，在通信的過程中完成對(duì)MySQL協(xié)議的編解碼。
• 核心組件(Core-module)：得到解碼的 MySQL 命令后，開始調(diào)用 Sharding-Core 對(duì) SQL 進(jìn)行解析、改寫、路由、歸并等核心功能。
• 后端(Backend)：與真實(shí)數(shù)據(jù)庫交互，采用 Hikari 連接池，同樣涉及到 MySQL 協(xié)議的編解碼。

ShardingProxy 的預(yù)編譯 SQL 功能

本文的 Bug 跟 ShardingProxy 的預(yù)編譯 SQL 有關(guān)，這里單獨(dú)介紹下此功能以及與之相關(guān)的 MySQL 協(xié)議，這個(gè)是本文的關(guān)鍵，請(qǐng)耐心看完。

熟悉數(shù)據(jù)庫開發(fā)的同學(xué)一定了解：預(yù)編譯 SQL(PreparedStatement)，在數(shù)據(jù)庫收到一條 SQL 到執(zhí)行完畢。

一般分為以下 3 步：

• 詞法和語義解析
• 優(yōu)化 SQL，制定執(zhí)行計(jì)劃
• 執(zhí)行并返回結(jié)果

但是很多情況下，一條 SQL 語句可能會(huì)反復(fù)執(zhí)行，只是執(zhí)行時(shí)的參數(shù)值不同。

而預(yù)編譯功能將這些值用占位符代替，最終達(dá)到一次編譯、多次運(yùn)行的效果，省去了解析優(yōu)化等過程，能大大提高 SQL 的執(zhí)行效率。

假設(shè)我們要執(zhí)行下面這條 SQL 兩次：

SELECT * FROM t_user WHERE user_id = 10;

那 JDBC 和 MySQL 之間的協(xié)議消息如下：

通過上述流程可以看到：

• 第 1 條消息是PreparedStatement，查詢語句中的參數(shù)值用問號(hào)代替了，它告訴 MySQL 對(duì)這個(gè)SQL 進(jìn)行預(yù)編譯。
• 第 2 條消息 MySQL 告訴 JDBC 準(zhǔn)備成功了。
• 第 3 條消息 JDBC 將參數(shù)設(shè)置為 1。
• 第 4 條消息 MySQL 返回查詢結(jié)果。
• 第 5 條和第 6 條消息表示第二次執(zhí)行同樣的 SQL，已經(jīng)無需再次預(yù)編譯了。

再回到 ShardingProxy，如果需要支持預(yù)編譯功能，交互流程肯定是需要變的，因?yàn)?Proxy 在收到 JDBC 的PreparedStatement 命令時(shí)，SQL 里的分片鍵是問號(hào)，它根本不知道該路由到哪個(gè)真實(shí)數(shù)據(jù)庫。

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

 

可以看到，Proxy在收到 PreparedStatement 命令后，并不會(huì)把這條消息轉(zhuǎn)發(fā)給MySQL，只是緩存了這個(gè) SQL，在收到 ExecuteStatement 命令后，才根據(jù)分片鍵和傳過來的參數(shù)值確定真實(shí)的數(shù)據(jù)庫，并與 MySQL 交互。

問題分析

上一章節(jié)基本把這個(gè) Bug 相關(guān)的原理知識(shí)介紹清楚了，下面正式進(jìn)入問題的分析過程。

最開始拿到這個(gè)問題，我也是比較頭禿的，尤其看到讀者下面這段信息。

當(dāng)然，我的功力是達(dá)不到盲猜水平的，說下我的完整思路。

第 1 步：復(fù)現(xiàn)問題

我讓讀者給我打包發(fā)了 Demo 的源代碼、數(shù)據(jù)庫腳本以及 ShardingProxy 配置，然后本地安裝了 ShardingProxy 4.1.1 版本，再通過 Navicat 連接到 ShardingProxy 執(zhí)行數(shù)據(jù)庫腳本，環(huán)境基本就準(zhǔn)備完畢了。

啟動(dòng) Demo 程序后，通過 Postman 發(fā)送請(qǐng)求，問題穩(wěn)定復(fù)現(xiàn)了，確實(shí)查不出數(shù)據(jù)。

第 2 步：確認(rèn)應(yīng)用程序是否有 Bug

因?yàn)檎麄€(gè)代碼很簡單，代碼層面唯一有可能存在問題的是 Mybatis 這一層。

為了確認(rèn)這一點(diǎn)，我修改了 SpringBoot 的配置，將 MyBatis 的 debug 日志也打印了出來。

再次發(fā)起請(qǐng)求后，能從控制臺(tái)中看到以下詳細(xì)日志：

 

日志中沒發(fā)現(xiàn)異常，而且 PreparedStatement 以及 ExecuteStatement 的參數(shù)設(shè)置都是正確的，查詢結(jié)果確實(shí)是空。

為了縮小排查范圍，我把 dataSource 的 配置改回了直連真實(shí)數(shù)據(jù)庫，這樣能將 ShardingProxy 這個(gè)干擾因素排除在外。

改完后的 url 如下：

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

其中，db1 是真實(shí)數(shù)據(jù)庫，3306 也是MySQL 服務(wù)器的端口了。然后再次用 Postman 發(fā)送請(qǐng)求，可以看到：有正確數(shù)據(jù)返回了。

 

通過這一步，我將懷疑對(duì)象再次轉(zhuǎn)移到 ShardingProxy 上了，并將 dataSource 配置改回成原樣，繼續(xù)排查。

第 3 步：排查 ShardingProxy

首先，查看 ShardingProxy 的運(yùn)行日志，沒發(fā)現(xiàn)任何異常;其次，能看到日志中的 Actual SQL 是正確的，它已經(jīng)根據(jù)分區(qū)鍵正確路由到了 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 的分庫分表配置應(yīng)該是沒有問題的。

我開始懷疑：是否跟 ShardingProxy 所使用的數(shù)據(jù)庫驅(qū)動(dòng)有關(guān)?因?yàn)檫@個(gè) Jar 包是應(yīng)用方選擇版本，手動(dòng)放到 ShardingProxy 安裝目錄中的。

因此，我將驅(qū)動(dòng)版本從 5.1.47 版本改成了 8.0.13 (和 Demo 使用了相同的版本)，但是問題仍然存在。

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

這個(gè)時(shí)候，真感覺沒有其他可疑點(diǎn)了，所有能想到的點(diǎn)都排查了一遍。我再次回到了 Demo 程序本身，它和 ShardingProxy 唯一的結(jié)合點(diǎn)就在 DataSource 的 url 上。

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

庫名和端口號(hào)配置無誤，唯一可疑的是另外三個(gè)參數(shù):

• useServerPrepStmts
• cachePrepStmts
• serverTimezone

其中，前兩個(gè)參數(shù)和預(yù)編譯 SQL 有關(guān)，是一個(gè)組合。因此，我將這兩個(gè)參數(shù)從 url 中去掉，測試了一下。

這個(gè)時(shí)候奇跡出現(xiàn)了，居然返回了正確數(shù)據(jù)。至此，基本定位到了問題，但根本原因是什么呢?究竟是不是 ShardingProxy 的 Bug ?

第 4 步：Wireshark 抓包分析 MySQL 協(xié)議

找到這個(gè)問題的解決方案后，我同步給了讀者。與此同時(shí)，他也在 ShardingProxy 的 GitHub 上提交了 issue，反饋了這個(gè)最新進(jìn)展。

由于工作原因，這個(gè)問題我就暫時(shí)放一邊了，準(zhǔn)備抽空再接著排查。

大概過了一周我想起了這個(gè)問題，然后打開 issue 想了解下調(diào)查進(jìn)度，讓我非常驚訝的是：官方開發(fā)者居然在復(fù)現(xiàn)此問題后，主觀臆斷地認(rèn)為是應(yīng)用程序的問題，然后莫名奇妙的把這個(gè) issue 關(guān)閉了。

他們的答復(fù)是這樣的：

 

意思就是：我們針對(duì)預(yù)編譯 SQL 功能做了大量的測試，這個(gè)是不可能存在問題的，建議你們更換下應(yīng)用程序的數(shù)據(jù)庫連接池，抓包繼續(xù)分析下。(這個(gè)說法真讓人非常無語，完全不是程序員嚴(yán)謹(jǐn)?shù)乃季S!)

第二天，我開始用 Wireshark 抓包分析 MySQL 的協(xié)議，想弄清楚根本原因到底是什么?同時(shí)聯(lián)系上了官方，讓他們 reopen 了這個(gè)問題。

Wireshark 如何抓取 MySQL 協(xié)議的數(shù)據(jù)包，這里就不展開了，大家可以網(wǎng)上查下資料。

注意將 Wireshark 的過濾條件設(shè)置成：

mysql || tcp.port==3307 

其中：mysql 表示 ShardingProxy 和 MySQL Server 之間的數(shù)據(jù)包，tcp.port==3307 表示 Demo 程序和 ShardingProxy 之間的數(shù)據(jù)包。

啟動(dòng) Wireshark 抓包后，再次用 Postman 發(fā)起請(qǐng)求，觸發(fā)整個(gè)過程，然后就能順利抓到下面截圖的數(shù)據(jù)包了。

 

大家關(guān)注底色為 深藍(lán)色 的 8 個(gè)數(shù)據(jù)包即可。在本文第 2 章節(jié)的原理部分，我已經(jīng)詳細(xì)介紹過 ShardingProxy 的預(yù)編譯功能以及該流程的 MySQL 協(xié)議消息，這里的 8 個(gè)數(shù)據(jù)包和原理介紹是完成吻合的。

那接下來如何進(jìn)一步分析呢?結(jié)合 ShardingProxy 的架構(gòu)圖來思考下：Proxy 僅僅作為一個(gè)中間代理，介于應(yīng)用程序和 MySQL Server 之間。

它完全實(shí)現(xiàn)了 MySQL 協(xié)議，以便對(duì) MySQL 命令進(jìn)行解碼和編碼，然后加上自己的分庫分表邏輯。

如果 ShardingProxy 內(nèi)部存在 Bug，那一定是某個(gè)數(shù)據(jù)包出現(xiàn)了問題。

順著這個(gè)思路，很快就能發(fā)現(xiàn)：執(zhí)行完 ExecuteStatement 后，MySQL Server 返回正確數(shù)據(jù)包給 Proxy 了，但是 Proxy 沒有返回正確的數(shù)據(jù)包給應(yīng)用程序。

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

下面截圖的是最后 1 個(gè) Response 數(shù)據(jù)包，由 Proxy 返回給應(yīng)用程序的，Payload 中只能看到表字段的定義，那條記錄已經(jīng)不翼而飛了。

 

通過這一步分析，就已經(jīng)坐實(shí)了：ShardingProxy 是有 Bug 的。然后，我將這些依據(jù)發(fā)給了官方開發(fā)者，對(duì)方開始重視，并正式進(jìn)入源碼分析階段。

根本原因定位

當(dāng)天晚上，官方開發(fā)者就定位到了根本原因，發(fā)出了 Pull Request。我看了下代碼改動(dòng)，僅僅修改了一行代碼。

 

改動(dòng)的這行代碼，就是在 ShardingProxy 再次組裝數(shù)據(jù)包返回給應(yīng)用程序時(shí)拋出來的。

由于我們的數(shù)據(jù)表中存在一個(gè) date 類型的字段，改動(dòng)的這行代碼卻強(qiáng)制將 date 類型轉(zhuǎn)換成了 Timestamp 類型，因此拋出了異常。還有幾個(gè)疑點(diǎn)，我結(jié)合對(duì)源代碼的理解逐一解答下。

①為什么代碼拋異常了，但是 ShardingProxy 的控制臺(tái)沒打印呢?

 

上面截圖的是：拋出 ClassCastException 那個(gè)方法的整個(gè)調(diào)用鏈。由于 ShardingProxy 并沒有捕獲這個(gè) RuntimeException 以及打印日志，最終這個(gè)異常被 netty 吞掉了。

②為什么 ShardingProxy 需要做 date 到 Timestamp 的類型轉(zhuǎn)換呢?

可以從 ShardingProxy 的架構(gòu)來理解，因?yàn)?Proxy 只有對(duì) MySQL 協(xié)議進(jìn)行編解碼后，才能在中間插入它的分庫分表邏輯。

針對(duì) date 類型的字段，ShardingProxy 通過 JDBC 的 API 從查詢結(jié)果中拿到的仍然是 Date 類型，之所以要轉(zhuǎn)換成 Timestamp，這個(gè)又跟 MySQL 的協(xié)議有關(guān)了，下面是 MySQL 官方文檔的說明：

 

簡單理解就是：ShardingProxy 在代碼實(shí)現(xiàn)時(shí)，用了一個(gè)范圍最大的 timestamp 存了三種可能的值 date，datetime 和 timestamp，然后再按照上面這個(gè)協(xié)議規(guī)范進(jìn)行二進(jìn)制的寫入。

③這個(gè) Bug 是只有在使用 SQL 預(yù)編譯功能時(shí)才會(huì)被觸發(fā)嗎?

是的，只有在處理 ExecuteStatement 命令時(shí)，這個(gè)方法才會(huì)被調(diào)用到。那普通的 SQL 查詢場景為什么用不到呢?

這個(gè)又跟 MySQL 協(xié)議有關(guān)了，普通的 SQL 查詢場景，payload 不是二進(jìn)制協(xié)議的，而是普通的文本協(xié)議。這種情況下，無需調(diào)用這個(gè)類進(jìn)行轉(zhuǎn)換。

至此，整個(gè)分析過程就結(jié)束了。

寫在最后

本文詳細(xì)復(fù)盤了這個(gè) Bug 的分析過程，并對(duì)其中的原理知識(shí)和排查經(jīng)驗(yàn)進(jìn)行了總結(jié)。

對(duì)于 ShardingSphere 這種頂級(jí)開源項(xiàng)目來說，我個(gè)人覺得同樣值得做一次深度復(fù)盤。

我不認(rèn)同他們對(duì)于 issue 的處理方式，另外在核心功能的自動(dòng)化測試上，也一定是存在 case 不完善的，不然不可能連續(xù)多個(gè)版本都沒發(fā)現(xiàn)這個(gè)嚴(yán)重 Bug。

作者：駱俊武

簡介：前亞馬遜工程師，現(xiàn) 58 轉(zhuǎn)轉(zhuǎn)技術(shù)總監(jiān)，持續(xù)分享個(gè)人的成長經(jīng)歷，希望為你的職場發(fā)展帶來些新思路。

編輯：陶家龍

出處：轉(zhuǎn)載自公眾號(hào)IT人的職場進(jìn)階(ID：BestITer)