ticdc 延迟非常高 后台一直刷 The resolvedTs is fallen back in kvclient

【概述】 场景 + 问题概述
tidb&pd 混部 3个节点 ,ticdc 2个节点,tikv 11个
下午tidb集群3个tidb节点 oom。导致ticdc 很多任务停滞。后台一直刷日志
The resolvedTs is fallen back in kvclient
image

【背景】 做过哪些操作
重启过整个集群
单独重启过tikv所有节点 ,
单独重启过cdc服务

【问题】 当前遇到的问题
ticdc还在一直刷日志。

【业务影响】
影响数据推送,业务数据延迟。影响用户。
【TiDB 版本】
V5.4.0

【附件】 相关日志及监控(https://metricstool.pingcap.com/)
image

你重启tikv 前ticdc 是什么状态?

cdc任务是normal状态

有什么办法可以解决么

环境

集群版本:v5.1.2

Tidb server:16c 32g 7 台

Ticdc 机器:16c 64g 2 台高可用

问题发生版本:v4.0.9 v4.0.13 v5.1.2

Tidb server 发生 oom 后,ticdc checkpointTs 不向前推进,尝试 pause changefeed 后未恢复,尝试使用 tiup 重启 cdc 组件后未恢复。

检查 ticdc 日志出现大量 warning 日志:

[2022/01/30 11:17:55.761 +08:00] [WARN] [region_worker.go:377] [“region not receiving resolved event from tikv or resolved ts is not pushing for too long time, try to resolve lock”] [regionID=40982339] [span=”[7480000000000016ffa05f72f000000019ff3a9b7b0000000000fa, 7480000000000016ffa05f72f000000019ff7319ad0000000000fa)“] [duration=17m21.65s] [lastEvent=93.273628ms] [resolvedTs=430836713476849684]

[2022/01/30 11:17:55.771 +08:00] [WARN] [region_worker.go:743] [“The resolvedTs is fallen back in kvclient”] [“Event Type”=RESOLVED] [resolvedTs=430836713699672811] [lastResolvedTs=430836984350245604] [regionID=31134532]

TiDB server oom 监控

Tidb cdc 监控

问题排查

TiDB server oom 原因排查

从相关慢查询中

初步排查结果是研发当时查询 dashboard 慢查询页面导致 tidb server 发生 oom

dashboard 的慢查询页面导致 oom,从 4.0 版本到 5.1.2 版本,曾经多次发生,目前版本还存在该问题,在未来的版本中会得到修复。

目前的缓解方案:

  • 尽可能减少 slow-log 文件的数量比如定期做 slow log 的归档删除或设置 log.file.max-days,调大 slow query 的阈值 log.slow-threshold。
  • 在查询时选择时间范围选小一点,比如一小时以内,并尽量避免多人并发查询 slow query 。
  • 查询时尽量不要使用 order by 排序功能。

目前 tidb 在分析 oom 问题上提供了一个 oom tracker 工具,能将当时的 top memory sql 以及 heap 统计到 tidb server 的 tmp 目录下以供分析,较以前版本来说,排查问题相对简单容易很多。

TiCDC 问题排查

从监控中可以看到,在 tidb server oom 后,部分 tikv 节点中 resolved-lag 增大

通过 cdc 研发人员确认,tidb 在事务中对相关表加乐观或悲观锁,当 tidb server oom 后,相关锁未正常释放,且 region merge 会阻塞 resolveLock 功能,导致 lock 无法释放

在最新的 5.1.4 版本中,已经修复了该问题

问题处理

5.1.4 版本及之后版本

tidb server oom 后 cdc 进程 checkpointTs 不向前推进问题可以得到解决,不需要特别进行处理。

5.1.4 之前的版本需要手动处理

Workaround:

上一次出现类似问题,使用 select count(*) from tb_name,通过对表做 count 操作来释放相关锁。

也有可能会遇到 count 表后没有恢复的情况。

如果是悲观锁的话,select count 无法解锁,也有可能锁存在于 index 上,select 需要使用 use index,即每一个 index 都 count 一次。

如何判断 count 后锁是否被释放

当 count(*) 后启动 changefeed 进程且 cdc log 中出现大量 ”The resolvedTs is fallen back in kvclient” 日志时,说明锁未被释放。释放锁之前建议暂停问题链路,问题链路会导致正常链路 checkpointTs 也不向前推进的情况。

问题修复:kv client 触发 resolved lock 的逻辑有问题,不能及时触发,详见:

https://github.com/pingcap/tiflow/issues/2867

相关信息

fallback resolvedTs event skips the lock resolving unexpectly · Issue #3061 · pingcap/tiflow · GitHub

https://github.com/tikv/tikv/pull/11991

目前我这个版本都V5.4.0了

重启tikv 前 ticdc 是运行的,ticdc实例没有停、或者同步任务没停?

目前解决了吗? 有遇到类似的问题,目前还没有解决

把你的场景尽量做到最小化配置,比如ticdc节点数量、同步表的数量、同步配置参数等,然后再看看情况

重启tikv前没有停cdc的 task

怀疑当时cdc 可能正在同步,tidb 突然断开了导致的

你还是检查下日志,把cdc 同步涉及的系统、节点日志都检查一下,看是否可以找到蛛丝马迹

哦, 源端也检查一下

目前已经解决了,但是因为集群版本是v5.4.0 这个bug再v5.4.1修复了,已经升级集群到v5.4.2。感谢