這是來自 go-sql-driver/mysql
的 issue757 的錯誤睛琳,因為該 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()