MySQL Malformed Packet

這是來自 go-sql-driver/mysqlissue757 的錯誤睛琳,因為該 issue 使我對 MySQL 的認知更深了华弓,于是請允許我使用第一人稱的視角解剖這個 issue 。

Intro

這是 MySQL 的一個內部錯誤挽霉,該錯誤很有可能來自 query_cache 写穴,但是 go-sql-driver/mysql 沒有針對該錯誤進行處理琼富,而是拋出了一個 panic

版本信息

  • Go : 1.9.3
  • MySQL : 5.7.21
  • go-sql-driver/mysql : 1.3

現(xiàn)象

當我使用 go-sql-driver/mysql 包在新建的 MySQL 數(shù)據(jù)庫進行查詢蜓萄,此時從 go-sql-driver/mysql 拋出了一個我 意料之外panic 信息隅茎,具體信息如下:

panic: runtime error: slice bounds out of range

goroutine 1 [running]:
github.com/go-sql-driver/mysql.(*mysqlConn).readColumns(0xc42008e000, 0x3, 0x0, 0x0, 0x0, 0x0, 0x0)
    /root/go/src/github.com/go-sql-driver/mysql/packets.go:693 +0xa33
github.com/go-sql-driver/mysql.(*mysqlConn).query(0xc42008e000, 0x60d623, 0x12, 0x729d08, 0x0, 0x0, 0x0, 0x0, 0x58b010)
    /root/go/src/github.com/go-sql-driver/mysql/connection.go:408 +0x3cb
github.com/go-sql-driver/mysql.(*mysqlConn).QueryContext(0xc42008e000, 0x6f1160, 0xc420018118, 0x60d623, 0x12, 0x729d08, 0x0, 0x0, 0x7fc20e05b058, 0x4530c0, ...)
    /root/go/src/github.com/go-sql-driver/mysql/connection_go18.go:72 +0x112
database/sql.ctxDriverQuery(0x6f1160, 0xc420018118, 0x7fc20e05b058, 0xc42008e000, 0x60d623, 0x12, 0x729d08, 0x0, 0x0, 0x429d89, ...)
    /opt/go/src/database/sql/ctxutil.go:48 +0x277
database/sql.(*DB).queryDC.func1()
    /opt/go/src/database/sql/sql.go:1320 +0x99
database/sql.withLock(0x6efda0, 0xc420092000, 0xc420051c50)
    /opt/go/src/database/sql/sql.go:2873 +0x65
database/sql.(*DB).queryDC(0xc42007c140, 0x6f1160, 0xc420018118, 0x0, 0x0, 0xc420092000, 0xc420010690, 0x60d623, 0x12, 0x0, ...)
    /opt/go/src/database/sql/sql.go:1319 +0x6ba
database/sql.(*DB).query(0xc42007c140, 0x6f1160, 0xc420018118, 0x60d623, 0x12, 0x0, 0x0, 0x0, 0x1, 0x6, ...)
    /opt/go/src/database/sql/sql.go:1304 +0x147
database/sql.(*DB).QueryContext(0xc42007c140, 0x6f1160, 0xc420018118, 0x60d623, 0x12, 0x0, 0x0, 0x0, 0xc420051e50, 0xc420051e58, ...)
    /opt/go/src/database/sql/sql.go:1281 +0xd2
database/sql.(*DB).Query(0xc42007c140, 0x60d623, 0x12, 0x0, 0x0, 0x0, 0x0, 0x58d40c, 0x60a70a)
    /opt/go/src/database/sql/sql.go:1295 +0x82
main.main()
    /data/src/gowork/test.go:57 +0x132
exit status 2

在一個穩(wěn)定了 快500天 的包居然出現(xiàn)了 slice bound of range 的異常,這是非常嚴重的錯誤嫉沽,好奇心驅使我開始研究該異常辟犀。

分析過程

先從源頭來分析,數(shù)據(jù)庫結構以及應用代碼如下所示绸硕。

schema

CREATE TABLE `user` (
    `id` BIGINT NOT NULL AUTO_INCREMENT,
    `name` VARCHAR(20) NOT NULL DEFAULT '',
    `age` INT(11) NOT NULL DEFAULT 0,
    PRIMARY KEY (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4

Go

db, err := sql.Open("mysql", "root:123456@tcp(127.0.0.1:3306)/test")
if err != nil {
    log.Fatal("failed to open mysql: ", err)
}
defer db.Close()

rows, err := db.Query("SELECT * FROM `user`")
if err != nil {
    log.Fatal("failed to query users: ", err)
}
defer rows.Close()

// ...

一切看起來都是如此的正常堂竟,于是我想查看源碼到底是哪里拋出的異常,跟隨棧異常信息如果到 go-sql-drive/mysql 中:

// package.go

func (mc *mysqlConn) readColumns(count int) ([]mysqlField, error) {
    // ...
    name, _, n, err := readLengthEncodedString(data[pos:]) // Line 693
    if err != nil {
        return nil, err   
    }
    // ...
}

既然是 slice bounds out of range 異常玻佩,那么問題肯定出在 data[pos:] 了出嘹,再來看下 pos 的意義分明就是 游標 ,當它在解析前面的 database / table 的時候沒有問題咬崔,就能分析出是 MySQL 返回的數(shù)據(jù)從 fields name 處出現(xiàn)了異常税稼。

原因

既然是 MySQL 出現(xiàn)了異常,我們就能通過 TCP抓包 觀察返回的數(shù)據(jù)垮斯,從而判斷其是否符合協(xié)議郎仆。

最終,我們將問題定位在 https://bugs.mysql.com/bug.php?id=86318 中兜蠕。

原來扰肌, MySQL 啟動了 query cache 導致出現(xiàn)了 畸形包go-sql-drive/mysql 無法正確解析該包牺氨,直接拋出異常狡耻!

query cache 是什么?

The query cache stores the text of a SELECT statement together with the corresponding result that was sent to the client. If an identical statement is received later, the server retrieves the results from the query cache rather than parsing and executing the statement again. The query cache is shared among sessions, so a result set generated by one client can be sent in response to the same query issued by another client.

根據(jù)這句話猴凹,我們可以了解到夷狰, query cache 就是為了提高查詢效率而發(fā)明的一種 簡單粗暴 的緩存策略郊霎,但是如果 SQL字符串 不能完全匹配上(包括大小寫沼头、空格、TAB等),都會導致緩存失效=丁M林痢!

當緩存失效時猾昆,內部實現(xiàn)通過 single mutex 控制競態(tài)陶因,導致了嚴重的 鎖競爭

解決方案

最好的解決方案就是關閉 query cache 垂蜗,方法是在啟動 MySQL 前必須添加 query_cache_type=0 參數(shù)楷扬,如:

db, err := sql.Open("mysql", "root:123456@tcp(127.0.0.1:3306)/test?query_cache_type=0")
if err != nil {
    log.Fatal("failed to open mysql: ", err)
}
defer db.Close()

參考文檔

最后編輯于
?著作權歸作者所有,轉載或內容合作請聯(lián)系作者
  • 序言:七十年代末,一起剝皮案震驚了整個濱河市贴见,隨后出現(xiàn)的幾起案子烘苹,更是在濱河造成了極大的恐慌,老刑警劉巖片部,帶你破解...
    沈念sama閱讀 219,188評論 6 508
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件镣衡,死亡現(xiàn)場離奇詭異,居然都是意外死亡档悠,警方通過查閱死者的電腦和手機廊鸥,發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 93,464評論 3 395
  • 文/潘曉璐 我一進店門,熙熙樓的掌柜王于貴愁眉苦臉地迎上來辖所,“玉大人黍图,你說我怎么就攤上這事∨樱” “怎么了助被?”我有些...
    開封第一講書人閱讀 165,562評論 0 356
  • 文/不壞的土叔 我叫張陵,是天一觀的道長切诀。 經(jīng)常有香客問我揩环,道長,這世上最難降的妖魔是什么幅虑? 我笑而不...
    開封第一講書人閱讀 58,893評論 1 295
  • 正文 為了忘掉前任丰滑,我火速辦了婚禮,結果婚禮上倒庵,老公的妹妹穿的比我還像新娘褒墨。我一直安慰自己,他們只是感情好擎宝,可當我...
    茶點故事閱讀 67,917評論 6 392
  • 文/花漫 我一把揭開白布郁妈。 她就那樣靜靜地躺著,像睡著了一般绍申。 火紅的嫁衣襯著肌膚如雪噩咪。 梳的紋絲不亂的頭發(fā)上顾彰,一...
    開封第一講書人閱讀 51,708評論 1 305
  • 那天,我揣著相機與錄音胃碾,去河邊找鬼涨享。 笑死,一個胖子當著我的面吹牛仆百,可吹牛的內容都是我干的厕隧。 我是一名探鬼主播,決...
    沈念sama閱讀 40,430評論 3 420
  • 文/蒼蘭香墨 我猛地睜開眼俄周,長吁一口氣:“原來是場噩夢啊……” “哼栏账!你這毒婦竟也來了?” 一聲冷哼從身側響起栈源,我...
    開封第一講書人閱讀 39,342評論 0 276
  • 序言:老撾萬榮一對情侶失蹤,失蹤者是張志新(化名)和其女友劉穎竖般,沒想到半個月后甚垦,有當?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體,經(jīng)...
    沈念sama閱讀 45,801評論 1 317
  • 正文 獨居荒郊野嶺守林人離奇死亡涣雕,尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內容為張勛視角 年9月15日...
    茶點故事閱讀 37,976評論 3 337
  • 正文 我和宋清朗相戀三年艰亮,在試婚紗的時候發(fā)現(xiàn)自己被綠了。 大學時的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片挣郭。...
    茶點故事閱讀 40,115評論 1 351
  • 序言:一個原本活蹦亂跳的男人離奇死亡迄埃,死狀恐怖,靈堂內的尸體忽然破棺而出兑障,到底是詐尸還是另有隱情侄非,我是刑警寧澤,帶...
    沈念sama閱讀 35,804評論 5 346
  • 正文 年R本政府宣布流译,位于F島的核電站逞怨,受9級特大地震影響,放射性物質發(fā)生泄漏福澡。R本人自食惡果不足惜叠赦,卻給世界環(huán)境...
    茶點故事閱讀 41,458評論 3 331
  • 文/蒙蒙 一、第九天 我趴在偏房一處隱蔽的房頂上張望革砸。 院中可真熱鬧除秀,春花似錦、人聲如沸算利。這莊子的主人今日做“春日...
    開封第一講書人閱讀 32,008評論 0 22
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽效拭。三九已至棍好,卻和暖如春仗岸,著一層夾襖步出監(jiān)牢的瞬間,已是汗流浹背借笙。 一陣腳步聲響...
    開封第一講書人閱讀 33,135評論 1 272
  • 我被黑心中介騙來泰國打工扒怖, 沒想到剛下飛機就差點兒被人妖公主榨干…… 1. 我叫王不留,地道東北人业稼。 一個月前我還...
    沈念sama閱讀 48,365評論 3 373
  • 正文 我出身青樓盗痒,卻偏偏與公主長得像,于是被迫代替她去往敵國和親低散。 傳聞我的和親對象是個殘疾皇子俯邓,可洞房花燭夜當晚...
    茶點故事閱讀 45,055評論 2 355