Go访问MySQL异常排查及浅析其超时机制
原创
一、问题现象：通过监控发现访问MySQL偶尔出现异常，查看日志错误为unexpected EOF。
由于是偶现，并且都是间隔一段时间才发生，猜测是由于mysql服务端超时主动断开连接，而go没有对这种情况进行重试导致。本着大胆猜想，小心求证的原则，利用自己搭建的mysql和测试程序验证。
二、求证过程：
A、设置本地mysql的wait_timeout为4秒：
B、再写个简单的测试程序，每5秒请求一次：
func main() {
db, err := sql.Open("mysql", "user:password@tcp(127.0.0.1:3306)/tpadmin")
if err != nil {
panic(err)
}
defer db.Close()
// test
for {
_, err = db.Query("select * from user where id = 1")
if err != nil {
panic(err)
}
fmt.Println("Query OK!")
time.Sleep(5 * time.Second)
}
}C、通过抓包分析：的确MySQL服务端先关闭了连接，然后客户端继续发送请求，并收到RST包：
D、对比问题发生的间隔时间和云MySQL的wait_timeout值，确定了问题的原因。
三、解决方法：找到原因后，该怎么解决呢？显然go对mysql服务端超时关闭的情况是无感知的，但我们可以主动设置超时时长，在发生错误之前，就弃用这条连接。通过SetConnMaxLifetime设置超时时长，并通过上面的测试程序进行验证，问题得到了解决。
但这样就结束了，我想是不够的。还需要分析下go访问mysql超时部分的源码，是不是存在其它的坑以及学习其中的一些思想和方法，才是我们接下去要走的路。
四、源码分析：
Go 在必要的时候会开启一个协程，用来处理超时连接，源码如下：
func (db *DB) connectionCleaner(d time.Duration) {
const minInterval = time.Second
if d < minInterval {
d = minInterval
}
t := time.NewTimer(d)
for {
select {
case <-t.C:
case <-db.cleanerCh: // maxLifetime was changed or db was closed.
}
db.mu.Lock()
d = db.maxLifetime
if db.closed || db.numOpen == 0 || d <= 0 {
db.cleanerCh = nil
db.mu.Unlock()
return
}
expiredSince := nowFunc().Add(-d)
var closing []*driverConn
for i := 0; i < len(db.freeConn); i++ {
c := db.freeConn[i]
if c.createdAt.Before(expiredSince) {
closing = append(closing, c)
last := len(db.freeConn) - 1
db.freeConn[i] = db.freeConn[last]
db.freeConn[last] = nil
db.freeConn = db.freeConn[:last]
i--
}
}
db.mu.Unlock()
for _, c := range closing {
c.Close()
}
if d < minInterval {
d = minInterval
}
t.Reset(d)
}
}通过上面代码可以发现，只有当定时器触发、超时时长改变、DB关闭时，才会清理一次超时连接。那这里会不会有坑：定时器每隔一段时间才触发，已超时的连接没有及时清理，从而导致错误再次发生？单单从这里超时处理的代码，确实会有这个坑存在。我们继续看下mysql获取连接时的源码：
func (db *DB) conn(ctx context.Context, strategy connReuseStrategy) (*driverConn, error) {
db.mu.Lock()
if db.closed {
db.mu.Unlock()
return nil, errDBClosed
}
// Check if the context is expired.
select {
default:
case <-ctx.Done():
db.mu.Unlock()
return nil, ctx.Err()
}
lifetime := db.maxLifetime
// Prefer a free connection, if possible.
numFree := len(db.freeConn)
if strategy == cachedOrNewConn && numFree > 0 {
conn := db.freeConn[0]
copy(db.freeConn, db.freeConn[1:])
db.freeConn = db.freeConn[:numFree-1]
conn.inUse = true
db.mu.Unlock()
if conn.expired(lifetime) {
conn.Close()
return nil, driver.ErrBadConn
}
......
}获取连接有两种策略，一种是alwaysNewConn，一种是cachedOrNewConn，在cachedOrNewConn策略下，从连接池中获取的连接都是先检查是否超时，超时就返回driver.ErrBadConn。这里虽然解决了超时连接没有及时清理的问题，但又看到了另外一个问题，这里只是返回失败，并没有返回有效的连接，是否最终导致这次mysql请求失败呢？继续查看conn被调处：
// QueryContext executes a query that returns rows, typically a SELECT.
// The args are for any placeholder parameters in the query.
func (db *DB) QueryContext(ctx context.Context, query string, args ...interface{}) (*Rows, error) {
var rows *Rows
var err error
for i := 0; i < maxBadConnRetries; i++ {
rows, err = db.query(ctx, query, args, cachedOrNewConn)
if err != driver.ErrBadConn {
break
}
}
if err == driver.ErrBadConn {
return db.query(ctx, query, args, alwaysNewConn)
}
return rows, err
}
func (db *DB) query(ctx context.Context, query string, args []interface{}, strategy connReuseStrategy) (*Rows, error) {
dc, err := db.conn(ctx, strategy)
if err != nil {
return nil, err
}
return db.queryDC(ctx, nil, dc, dc.releaseConn, query, args)
}从上可以发现，在cachedOrNewConn策略下会重试几次，如果依旧返回driver.ErrBadConn错误时会采用alwaysNewConn策略获取新连接。至此所有问题都得到解决，没有发现新的坑。另外我们也学到了Go访问mysql采用的超时机制是定时检查+复用前检查+重复尝试。
原创声明：本文系作者授权腾讯云开发者社区发表，未经许可，不得转载。
如有侵权，请联系 cloudcommunity@tencent.com 删除。
原创声明：本文系作者授权腾讯云开发者社区发表，未经许可，不得转载。
如有侵权，请联系 cloudcommunity@tencent.com 删除。
腾讯云开发者
