這篇文章記錄了給 Apache 頂級項目 - 分庫分表中間件 ShardingSphere 提交 Bug 的歷程。前端
說實話,這是一次比較曲折的 Bug 跟蹤之旅。10月28日,咱們在 GitHub 上提交 issue,中途由於官方開發者的主觀臆斷被 Close 了兩次,直到 11 月 20 日才被認定成 Bug 併發出修復版本,歷時 20 多天。mysql
本文將還原該 Bug 的分析過程,將有價值的經驗和技術點進行提煉。經過本文,你將收穫到:sql
一、疑難問題的排查思路數據庫
二、數據庫中間件 Sharding Proxy 的原理後端
三、MySQL 預編譯的流程和交互協議緩存
四、Wireshark 抓包分析 MySQL 的奇淫技巧服務器
這個 Bug 來源於個人公號讀者,他替公司預研 ShardingProxy(屬於 ShardingSphere 的子產品,可用做分庫分表,後文會詳細介紹)。他按照官方文檔寫了一個很簡單的 demo,可是運行後沒法查詢出數據。網絡
下面是他遇到問題後發給個人信息,但願我能幫忙一塊兒定位下緣由。
架構
截圖中的 doc 詳細記錄了 ShardingProxy 的配置、調試分析日誌、以及問題的具體現象。併發
爲了方便你們理解,我從新描述下這個 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}
再說下遇到的問題。首先,往數據表中預先插入一條 ECIF_CUST_NO 等於 10000 的數據:
而後啓動 demo 程序,使用 curl 發起 post 請求,查詢 ecifCustNo 等於 10000 的那條記錄,竟然查詢不出數據:
至此,背景基本交代清楚了,爲何數據庫中明明有數據,可是程序卻查詢不出來呢?問題到底出如今 ShardingProxy,仍是應用程序自己?
在開啓這個問題的分析過程以前,我先快速普及下 ShardingProxy 的基本原理,以便你們能更好的理解個人分析思路。
開源的數據庫中間件你們必定接觸過,最流行的是 MyCat 和 ShardingSphere。其中 MyCat 是阿里開源的;ShardingSphere 是由噹噹網開源,並在京東逐漸發展壯大,於 2020 年成爲了 Apache 頂級項目。
ShardingSphere 的目標是一個生態圈,它由很是著名的 ShardingJDBC、ShardingProxy、ShardingSidecar 3 款獨立的產品組成。本文重點普及下 ShardingProxy,另外兩個就不展開了。
ShardingProxy 屬於和 MyCat 對標的產品,定位爲透明化的數據庫代理端,能夠理解成:一個實現了 MySQL 協議的 Server(獨立進程),可用於讀寫分離、分庫分表、柔性事務等場景。
對於應用程序或者 DBA 來講,能夠把 ShardingProxy 當作數據庫代理,能用 MySQL 客戶端工具(Navicat)或者命令行和它直接交互,而 ShardingProxy 內部則經過 MySQL 原生協議與真實的 MySQL 服務器通訊。
從架構圖來看,ShardingProxy 就至關於 MySQL,它自己不存儲數據,可是對外屏蔽了 Database 的存儲細節,你能夠用鏈接 MySQL 的方式去鏈接 ShardingProxy(除了端口不一樣),用你熟悉的 ORMapping 框架使用它。
再來看下 ShardingProxy 的內部架構,後續源碼分析時會涉及到此部分。
整個架構分爲前端、核心組件和後端:
前端(Frontend)負責與客戶端進行網絡通訊,採用的是 NIO 框架,在通訊的過程當中完成對MySQL協議的編解碼。
核心組件(Core-module)獲得解碼的 MySQL 命令後,開始調用 Sharding-Core 對 SQL 進行解析、改寫、路由、歸併等核心功能。
後端(Backend)與真實數據庫交互,採用 Hikari 鏈接池,一樣涉及到 MySQL 協議的編解碼。
本文的 Bug 跟 ShardingProxy 的預編譯 SQL 有關,這裏單獨介紹下此功能以及與之相關的 MySQL 協議,這個是本文的關鍵,請耐心看完。
熟悉數據庫開發的同窗必定了解:預編譯 SQL(PreparedStatement),在數據庫收到一條 SQL 到執行完畢,通常分爲如下 3 步:
一、詞法和語義解析
二、優化 SQL,制定執行計劃
三、執行並返回結果
可是不少狀況下,一條 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 交互。
上一章節基本把這個 Bug 相關的原理知識介紹清楚了,下面正式進入問題的分析過程。
最開始拿到這個問題,我也是比較頭禿的,尤爲看到讀者下面這段信息。
固然,個人功力是達不到盲猜水平的,說下個人完整思路。
我讓讀者給我打包發了 Demo 的源代碼、數據庫腳本以及 ShardingProxy 配置,而後本地安裝了 ShardingProxy 4.1.1 版本,再經過 Navicat 鏈接到 ShardingProxy 執行數據庫腳本,環境基本就準備完畢了。
啓動 Demo 程序後,經過 Postman 發送請求,問題穩定復現了,確實查不出數據。
由於整個代碼很簡單,代碼層面惟一有可能存在問題的是 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 配置改回成原樣,繼續排查。
首先,查看 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 ?
找到這個問題的解決方案後,我同步給了讀者。與此同時,他也在 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 的。而後,我將這些依據發給了官方開發者,對方開始重視,並正式進入源碼分析階段。
當天晚上,官方開發者就定位到了根本緣由,發出了 Pull Request。我看了下代碼改動,僅僅修改了一行代碼。
改動的這行代碼,就是在 ShardingProxy 再次組裝數據包返回給應用程序時拋出來的。
因爲咱們的數據表中存在一個 date 類型的字段,改動的這行代碼卻強制將 date 類型轉換成了 Timestamp 類型,所以拋出了異常。還有幾個疑點,我結合對源代碼的理解逐一解答下。
一、爲何代碼拋異常了,可是 ShardingProxy 的控制檯沒打印呢?
上面截圖的是:拋出 ClassCastException 那個方法的整個調用鏈。因爲 ShardingProxy 並無捕獲這個 RuntimeException 以及打印日誌,最終這個異常被 netty 吞掉了。
二、爲何 ShardingProxy 須要作 date 到 Timestamp 的類型轉換呢?
能夠從 ShardingProxy 的架構來理解,由於 Proxy 只有對 MySQL 協議進行編解碼後,才能在中間插入它的分庫分表邏輯。
針對 date 類型的字段,ShardingProxy 經過 JDBC 的 API 從查詢結果中拿到的仍然是 Date 類型,之因此要轉換成 Timestamp,這個又跟 MySQL 的協議有關了,下面是 MySQL 官方文檔的說明:
簡單理解就是:ShardingProxy 在代碼實現時,用了一個範圍最大的 timestamp 存了三種可能的值 date, datetime 和 timestamp,而後再按照上面這個協議規範進行二進制的寫入。
三、這個 Bug 是隻有在使用 SQL 預編譯功能時纔會被觸發嗎?
是的,只有在處理 ExecuteStatement 命令時,這個方法纔會被調用到。那普通的 SQL 查詢場景爲何用不到呢?
這個又跟 MySQL 協議有關了,普通的 SQL 查詢場景,payload 不是二進制協議的,而是普通的文本協議。這種狀況下,無需調用這個類進行轉換。
至此,整個分析過程就結束了。
本文詳細覆盤了這個 Bug 的分析過程,並對其中的原理知識和排查經驗進行了總結。
對於 ShardingSphere 這種頂級開源項目來講,我我的以爲一樣值得作一次深度覆盤。我不認同他們對於 issue 的處理方式,另外在覈心功能的自動化測試上,也必定是存在 case 不完善的,否則不可能連續多個版本都沒發現這個嚴重 Bug。
若是你有任何疑問,歡迎評論區留言討論。
做者簡介:985碩士,前亞馬遜工程師,現58轉轉技術總監
歡迎掃描下方的二維碼,關注個人我的公衆號:IT人的職場進階