快去检查下你Go服务连接MySQL的代码吧!!
一、现象
1、go版本信息:
go 1.15
go-mysql-driver/mysql v1.5
2、现象:
在服务全量拉取一张表的时候,返回了部分数据。但是我们自己的业务代码层面没有报错,只看到go-mysql-driver那里打印了部分错误日志:read: connection reset by peer
3、触发条件:
数据连接采用vip的方式对外提供服务,有多个后端。在某个后端停止宣告vip下线的时刻触发了拉取数据少了bug。
二、排查
1、复现过程
由于是vip停止宣告,也就是bgp抖动造成,查看日志发现mysql driver那一层打印了read: connection reset by peer也就是我们当时client和mysql server端的tcp连接被断开了,然后造成的现象。后面我就开始模拟tcp断开的场景来复现。使用下面的命令强制断开和数据库的tcp连接:
tcpkill -i any -9 host 192.168.100.1(db_ip)
强制断开和数据库的tcp连接后发现我们的数据确实拉取少了,bingo!复现了我们的问题。
2、替换driver
一开始我们怀疑driver那一层有bug,所以先换了一个driver进行替换将
"github.com/go-sql-driver/mysql"
换成了
"github.com/ziutek/mymysql/godrv"
但是发现现象依然存在。driver 往上一层就是go源码 database/sql ,这一层出错误的概率比较小了,要是有问题其他人也应该很大率碰到了,bgp抖动或者下线数据库后端是一个比较频繁的场景。后面就在driver那一层和我们自己连接数据库封装那一块代码增加debug日志调试。
3、debug
- driver 层面debug
//github.com/go-sql-driver/mysql/packet.go 54-65行 v1.5版本
// packets with length 0 terminate a previous packet which is a
// multiple of (2^24)-1 bytes long
if pktLen == 0 {
// there was no previous packet
if prevData == nil {
errLog.Print(ErrMalformPkt)
mc.Close()
return nil, ErrInvalidConn
}
return prevData, nil
}
一开始怀疑这个地方返回了数据,但是没有返回错误。然后就在packet.go里面加了不少调试日志。
- 业务层面debug
// 查询
func (c *MysqlConn) Select(sql string, args ...interface{}) (results []map[string]string, err error) {
rows, err := c.Db.Query(sql, args...)
if err != nil {
return
}
// 关闭数据集
defer rows.Close()
// 列信息
columns, _ := rows.Columns()
// 列值
values := make([][]byte, len(columns))
// 扫描器
scans := make([]interface{}, len(columns))
for i := range values {
scans[i] = &values[i]
}
results = make([]map[string]string, 0)
for rows.Next() {
if err = rows.Scan(scans...); err != nil {
return
}
row := make(map[string]string)
for k, v := range values {
key := columns[k]
row[key] = string(v)
}
results = append(results, row)
}
return
}
在这个业务代码层面也加了不少debug信息。后续定位到我们上面这个函数的问题,在rows.Next() 这个函数处理的方式有问题。
三、问题根因
请先看下面一段代码
//go/src/database/sql/sql.go go源码
// Next prepares the next result row for reading with the Scan method. It
// returns true on success, or false if there is no next result row or an error
// happened while preparing it. Err should be consulted to distinguish between
// the two cases.
//
// Every call to Scan, even the first one, must be preceded by a call to Next.
func (rs *Rows) Next() bool {
var doClose, ok bool
withLock(rs.closemu.RLocker(), func() {
doClose, ok = rs.nextLocked()
})
if doClose {
rs.Close()
}
return ok
}
上面注释当中写到了在false的情况下需要区分:
-
1、后面真的没有数据了
-
2、读取后面的数据报错了
回头看我们自己的封装的select的代码可以发现我们明显没有区分两种情况,导致了我们在tcp连接被断开的时候,读取Next()返回了false,但是错误没有向上层抛出。这个地方一个是我们自己业务代码层面写的不好,另外一个就是go源码这个地方没有显示返回错误,导致没有捕获这个错误。知道问题根因之后修改就比较简单了,判断下读取数据有没有错误就可以了。
在排查到这个根因之后再去看看人家的开源的连接数据库的框架发现别人就处理了这个错误的。比如sqlx:
// Scan is a fixed implementation of sql.Row.Scan, which does not discard the
// underlying error from the internal rows object if it exists.
func (r *Row) Scan(dest ...interface{}) error {
if r.err != nil {
return r.err
}
// TODO(bradfitz): for now we need to defensively clone all
// []byte that the driver returned (not permitting
// *RawBytes in Rows.Scan), since we're about to close
// the Rows in our defer, when we return from this function.
// the contract with the driver.Next(...) interface is that it
// can return slices into read-only temporary memory that's
// only valid until the next Scan/Close. But the TODO is that
// for a lot of drivers, this copy will be unnecessary. We
// should provide an optional interface for drivers to
// implement to say, "don't worry, the []bytes that I return
// from Next will not be modified again." (for instance, if
// they were obtained from the network anyway) But for now we
// don't care.
defer r.rows.Close()
for _, dp := range dest {
if _, ok := dp.(*sql.RawBytes); ok {
return errors.New("sql: RawBytes isn't allowed on Row.Scan")
}
}
if !r.rows.Next() {
if err := r.rows.Err(); err != nil {
return err
}
return sql.ErrNoRows
}
err := r.rows.Scan(dest...)
if err != nil {
return err
}
// Make sure the query can be processed to completion with no errors.
if err := r.rows.Close(); err != nil {
return err
}
return nil
}
四、总结
这个连接数据的代码作为公共的库已经多年了,也广泛用于公司的代码当中,这次被我们的服务踩到了。也算是给公司解决了一个大隐患,虽然因为我们的服务给客户造成3分钟的断网case。