这是来自 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
现象
当我使用 go-sql-driver/mysql
包在新建的 MySQL
数据库进行查询,此时从 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
在一个稳定了 快500天 的包居然出现了 slice bound of range
的异常,这是非常严重的错误,好奇心驱使我开始研究该异常。
分析过程
先从源头来分析,数据库结构以及应用代码如下所示。
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
返回的数据从 fields name
处出现了异常。
原因
既然是 MySQL
出现了异常,我们就能通过 TCP抓包 观察返回的数据,从而判断其是否符合协议。
最终,我们将问题定位在 https://bugs.mysql.com/bug.php?id=86318 中。
原来, MySQL
启动了 query cache
导致出现了 畸形包 ,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.
根据这句话,我们可以了解到, query cache
就是为了提高查询效率而发明的一种 简单 、 粗暴 的缓存策略,但是如果 SQL字符串 不能完全匹配上(包括大小写、空格、TAB等),都会导致缓存失效!!!
当缓存失效时,内部实现通过 single mutex
控制竞态,导致了严重的 锁竞争 。
解决方案
最好的解决方案就是关闭 query cache
,方法是在启动 MySQL
前必须添加 query_cache_type=0
参数,如:
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()
网友评论