测试了一下滚动重启 tidb 导致事务失败的情况，发现基本当前在跑的事务基本全会失败，原因是当前 tidb 停止的时候对连接的处理还是比较粗暴。
如何测试
k apply -f tc.yaml 部署一个版本 v5.4.0-pre 的集群 (3 tidb, 1 tikv, 1 pd)，spec 如下：
apiVersion: pingcap.com/v1alpha1
kind: TidbCluster
metadata:
name: test
spec:
version: v5.4.0-pre
timezone: Asia/Kolkata
pvReclaimPolicy: Delete
enableDynamicConfiguration: true
configUpdateStrategy: RollingUpdate
discovery: {}
helper:
image: busybox:1.34.1
pd:
baseImage: pingcap/pd
maxFailoverCount: 0
enableDashboardInternalProxy: true
service:
type: ClusterIP
clusterIP: "None"
replicas: 1
# if storageClassName is not set, the default Storage Class of the Kubernetes cluster will be used
# storageClassName: local-storage
requests:
storage: "1Gi"
config: {}
tikv:
baseImage: pingcap/tikv
maxFailoverCount: 0
evictLeaderTimeout: 1m
replicas: 1
requests:
storage: "10Gi"
config:
storage:
reserve-space: "0MB"
tidb:
# just update it to trigger rolling update
annotations:
kk: v9
baseImage: pingcap/tidb
maxFailoverCount: 0
replicas: 3
service:
type: ClusterIP
storageVolumes:
- name: log
# storageClassName: ${storageClass}
storageSize: "10Gi"
mountPath: /var/tidb/log
config: |
graceful-wait-before-shutdown = 10
[log]
level = "debug"
[log.file]
filename = "/var/tidb/log/tidb.log"
写一个简单的测试程序，并发 n 个连接，不停跑事务, 每个事务简单跑两个 replace 语句。代码在这里。
k apply test.yaml 跑一个 pod 运行测试程序：
apiVersion: v1
kind: Pod
metadata:
name: test
spec:
containers:
- name: write
image: july2993/tk:latest
command:
- "/tk"
- "test"
- "--host"
- "test-tidb"
- "--max-connection"
- "1000"
随便修改 tidb spec 的 annotations 触发滚动重启 tidb
...
tidb:
# just update it to trigger rolling update
annotations:
kk: v99
...
重启完三个 tidb 后失败事务个数 1275
...
[mysql] 2022/02/05 07:00:13 packets.go:123: closing bad idle connection: EOF
[mysql] 2022/02/05 07:00:13 packets.go:37: read tcp 10.244.0.30:56934->10.96.1.38:4000: read: connection reset by peer
[mysql] 2022/02/05 07:00:13 packets.go:123: closing bad idle connection: EOF
...
[2022/02/05 07:00:13.425 +00:00] [ERROR] [test.go:81] ["failed to run txn"] [error="failed to begin txn: invalid connection"]
[mysql] 2022/02/05 07:00:13 packets.go:37: read tcp 10.244.0.30:57754->10.96.1.38:4000: read: connection reset by peer
...
[2022/02/05 07:02:37.508 +00:00] [ERROR] [test.go:81] ["failed to run txn"] [error="failed to exec statement: invalid connection"] [stack="github.com/july2993/tk/cmd.glob..func1.2\n\t/go/src/github.com/july2993/tk/cmd/test.go:81"]
...
totalCount: 1030993, failCount: 1275, totalCountDiff: 2576, failCountDiff: 0
注意下这里有的是在 begin 的时候报错，有的是 exec statement 的时候报错。
为什么失败
为了理解为什么会失败，我们需要了解下 tidb 是如何处理退出跟 go sql driver 。
tidb 如何处理退出
我们来看下处理 signal 退出的代码code：
func main() {
//... omit some code
exited := make(chan struct{})
signal.SetupSignalHandler(func(graceful bool) {
svr.Close()
cleanup(svr, storage, dom, graceful)
cpuprofile.StopCPUProfiler()
close(exited)
})
topsql.SetupTopSQL()
terror.MustNil(svr.Run())
<-exited
syncLog()
}
这里 graceful 只有 signal 是 QUIT 才会是 true(不明原因为什么这样), 我们可以先忽略只考虑 false 情况。因为我们都是发 SIGTERM 来停止 tidb, 一定时间后再直接 SIGKILL。
svr.Close() 主要做如下事情 (code)：
- 设置
inShutdownMode为 true, 并等待s.cfg.GracefulWaitBeforeShutdown，目的是为了先让 LB 发现并且摘掉这个 tidb 。 - Close 掉全部
Listener拒绝新连接。
cleanup() 主要看最后调用的 GracefulDwon()：
// TryGracefulDown TryGracefulDown will try to gracefully close all connection first with timeout. if timeout, will close all connection directly.
func (s *Server) TryGracefulDown() {
ctx, cancel := context.WithTimeout(context.Background(), gracefulCloseConnectionsTimeout)
defer cancel()
done := make(chan struct{})
go func() {
s.GracefulDown(ctx, done)
}()
select {
case <-ctx.Done():
s.KillAllConnections()
case <-done:
return
}
}
func (s *Server) GracefulDown(ctx context.Context, done chan struct{}) {
logutil.Logger(ctx).Info("[server] graceful shutdown.")
metrics.ServerEventCounter.WithLabelValues(metrics.EventGracefulDown).Inc()
count := s.ConnectionCount()
for i := 0; count > 0; i++ {
s.kickIdleConnection()
count = s.ConnectionCount()
if count == 0 {
break
}
// Print information for every 30s.
if i%30 == 0 {
logutil.Logger(ctx).Info("graceful shutdown...", zap.Int("conn count", count))
}
ticker := time.After(time.Second)
select {
case <-ctx.Done():
return
case <-ticker:
}
}
close(done)
}
GracefulDown() 里 s.kickIdleConnection() 主要是扫一遍 s.clients（维护的全部连接），如果当前这个连接不处在一个事务中它就会 close 掉这个连接。但是注意它是每一秒检查一遍，如果一个连接是不停的跑事务它很可能一直不会 close, 到最后超过 gracefulCloseConnectionsTimeout(15s) 后不管连接当前状态直接 close 掉连接。前文说的 exec statement 的时候报错的就都是等到这里直接 close 的。
go sql driver
这里我们使用 driver 是 https://github.com/go-sql-driver/mysql, driver 实现并不自己管理连接池而是 go 的database/sql package 来管理的，driver 实现 database/sql/driver 下的一些接口。实现通过返回 driver.ErrBadConn 来告诉 sql package 这个连接状态 invalid(比如 server 端 close 掉了连接)， 你需要使用新的连接重试。
go-sql-driver/mysql 对连接的检查逻辑主要在 conncheck.go, 参考 pr924。做的主要是当一个连接在连接池被拿来用的时候第一次执行语句的时候先非阻塞读下这个连接，如果读不到任何数据并且 err 是 syscall.EAGAIN 或者 syscall.EWOULDBLOCK 这个连接就是正常的，否则返回 ErrBadConn。我们重启的时候部分跑 begin 失败的事务就是因为 client 侧还没感知到我们 server 要 close 或者已经 close 掉了这个连接，然后拿着连接跑 "START TRANSACTION" 语句的时候失败了。
原因总结
可以看到 tidb 尝试在事务间 close 掉连接（或者说在连接空闲的时候 close 掉连接）。一类失败是 server 端 close 连接跟 client 检查 连接状态之间的 race 导致的。一类失败是 tidb 尝试 close 掉连接超时后直接 close 全部连接导致的（exec statement 失败的部分都是）。
优化
每个连接都会有个 gorouting 跑 func (cc *clientConn) Run(ctx context.Context)。 Run 函数做的注意是不停读一个 packet(这里指 mysql 协议的 packet)，然后处理这个 packet。这里我们可以改成让这个 clientConn 的 Run 自己发现当前要 shutdown 然后自己选择在合适的时候（就是跑完当前事务）close 掉连接，而不是靠外部定时检查。这样我们可以做到每个连接跑完当前事务后马上 close, 不会出现超时后强制 close 的情况。但是 begin 失败的情况，因为这里有 race，我们 close 连接的时候 client 甚至可能已经用了这个连接发送了开启事务的语句并且发成功了，这部分我们是没办法的。
修改后重新测试(代码在这里) failCount: 642，失败只有之前的不到一半。为了测试当不是很 active 的跑事务的时候错误情况，我们改下测试程序让每个 goroutin 在 DB 里拿连接跑完一个事务后 sleep 一秒，后重新测试：
| version | failCount |
|---|---|
| v5.4.0-pre | 57 |
| 优化后版本 | 0 |
可以看到优化后的版本没有任何失败（不保证一定不会有失败）。
一个进一步的可能优化是 server 端处理 commit 语句之前就先 close tcp read 侧(ref shutdown TCPConn.CloseREAD), 如果 driver 的 connCheck 实现再检查下这个连接是否 close read 了那么理论上对于我们的测试程序是可以做到在滚动重启 tidb 的时候不会有任何失败的。
总结
优化后的 tidb 可以减少重启 tidb 导致的 client 端失败，在事务间 close 掉连接，不会出现超过 gracefulCloseConnectionsTimeout 后直接 close 连接的情况（在事务本身跑的时间不超过 gracefulCloseConnectionsTimeout 的前提下)。
网友评论