TiDB SQL 自动重试调研

【是否原创】是
【首发渠道】微信公共号:晓磊聊DB
【首发渠道链接】https://mp.weixin.qq.com/s/5FP0ra5xwp1XGc6h_-Ax9Q
【正文】

TiDB SQL自动重试调研

本文将通过一个讲述小案例来展开不同事务模型下的SQL重试策略,且听我娓娓道来:

某日上班时间,研发同学跑过来对DBA吐槽:我看我们的日志,发现一条很简单的insert SQL在TiDB里面执行时间都10s+,慢的时候都1分钟,而且出现的频率比较高,帮我们查查什么问题?

OK,Let’s GO!

开始排查和分析:

通过查看grafana的Overview相关的相关的监控页面,比如SQL Duration监控,确实发现SQL执行的“毛刺”,并且通过System info看不是偶发的系统资源抖动导致写入慢,其实业务也反馈这种“写入慢”出现的频率较高,其实排查问题先看监控是为了避免“写热点”或者硬件故障导致写入抖动。

通过监控排除一些故障点后,接下来需要通过排查tidb server的log,以及tidb slow log看是否有有价值的发现了。通过查看日志有重大的发现:

(1)tidb server 日志里面有大量的retry报警日志,发现大量的retrying、Write confilct以及retrycnt较高的报警日志。

[WARN] [session.go:664] [retrying] [conn=1165700] [schemaVersion=13873] [retryCnt=10]
[WARN] [session.go:713] [sql] [conn=1165697] [label=general] [error="[kv:9007]Write conflict, txnStartTS=420135027926630456, conflictStartTS=420135027979059203, conflictCommitTS=420135027979059208, key={tableID=14342, handle=10895814047} primary={tableID=14342, handle=10895814047} [try again later]"] [txn="Txn{state=invalid}"]
[WARN] [session.go:658] [retrying] [conn=1165702] [schemaVersion=13873] [retryCnt=0] [queryNum=0] [sql="INSERT INTO xxx"]

(2)tidb slow日志里面也有涉及上面慢SQL的记录,通过日志中SQL耗时情况查看,其中,Commit_backoff_time:表示commit重试时间,Backoff_types: [txnLock txnLock]表示重试类型是:集群中存在写写冲突,这些时间都很快,大家需要关注一个retry次数Txn_retry: 15次。

Time: 2021-08-06T13:40:50.216614662+08:00
Txn_start_ts: 426830302171889757
User: ad_stat@10.203.164.206
Conn_ID: 363
Query_time: 33.671954617
Parse_time: 0.0011528
Compile_time: 0.000609021
Prewrite_time: 0.489890509 Commit_backoff_time: 0.483 Backoff_types: [txnLock txnLock] Resolve_lock_time: 0.000715966 Write_keys: 50 Write_size: 9980 Prewrite_region: 6 Txn_retry: 15
DB: DB_XXXX
Is_internal: false
Digest: 3234fe71e25b4f3643f7c0c0528cc5544a8133c7628c59dbecb04537223ece8a
Num_cop_tasks: 0
Mem_max: 286500
Prepared: false
Plan_from_cache: false
Has_more_results: false
Succ: true
"INSERT INTO xxxxxxx"

PS:不同版本的慢日志打印出来的字段可能不一样,主要看涉及慢日志中高跟retry和backoff相关的耗时,具体慢日志字段含义见下面链接:

https://docs.pingcap.com/zh/tidb/stable/identify-slow-queries#日志示例
https://docs.pingcap.com/zh/tidb/stable/identify-slow-queries

写入慢的原因

首先先说上面出现问题的这个重试的环境和产生写入慢的原因
我们的环境:乐观+autocommit。
原因:SQL有写冲突,再写冲突高的情况下导致了SQL的重试,从SQL的重试次数也会看出来,SQL重试导致的insert SQL执行时间过长。

写入重试场景分析

既然问题已经定位到是因为SQL重试导致的问题,那么TIDB什么场景下SQL会重试?以及SQL是如何重试的?重试次数有什么限制?
OK,其实这个跟:tidb 的悲观/乐观事务模型,以及业务链接的隐式/显示事务有关系了。
这里明确2个概念:
(1)我如何知道我的TiDB集群是悲观 or 乐观模式,只需执行下面的SQL即可:

show variables like 'tidb_txn_mode';

如果value=pessimistic那就是悲观模式, 如果value=‘’或者optimistic就是乐观模式。

(2)隐式 or 显示事务,取决于业务链接,隐式事务就是autocmmit事务。显示事务就是非autocommit事务或者通过begin/start translation;commit;命令显示开启的事务。

注意:这里强调一点要想实现跟MySQL一样的悲观事务模型需要tidb_txn_mode= pessimistic,并且所有新创建 session 开启显示事务,具体关于悲观/乐观模式的详情可以去我上一篇公众号文章了解。

我这里用一个表格来说明重试场景:

(1)乐观+4.0.6版本前的隐式:默认10次乐观事务的重试

注意:具体由变量 tidb_disable_txn_auto_retry(是否禁用自动重试,默认1,不重试) 和 tidb_retry_limit(控制重试次数,默认10。当前面参数启用时才会生效) 控制。另外这2个参数仅适用于乐观事务,不适用于悲观事务。

(2)乐观+4.0.6之后版本的隐式:默认10次乐观事务的重试

(3)乐观+显示:tidb_disable_txn_auto_retry 的默认值为 on ,即不会重试非自动提交的事务,也就说这种情况遇到写冲突直接报错给client。

(4)悲观+4.0.6版本前的隐式:正如我上文强调的,虽然tidb是悲观模式,但是由于没有开显示事务,所以SQL遇到写冲突还是默认256次的乐观模式重试。

注意:悲观事务的重试次数由 max_retry_count(悲观事务中单个语句最大重试次数,重试次数超过该限制,语句执行将会报错,默认256)

(5)悲观+4.0.6之后版本的隐式:这里需要特别注意,虽然tidb是悲观模式,但是由于没有开显示事务,第一次是乐观提交,如果遇到写冲突后续TiDB帮着采用悲观提交,避免大量的乐观提交带来的写冲突。

(6)悲观+显示:不重试,跟MySQL悲观事务模式的行为一致。

大家明白tidb的SQL重试了么?

欢迎大家关注我的微信公众号:
qrcode_for_gh_16d24fa5d992_258

5赞