一场由 TiCDC 异常引发的 GC 不干活导致的 Tikv 硬盘使用问题
当大家看到这个标题时,就已经知道了下面几点:
(1)出了撒子问题?ok,集群所有 KV 节点存储硬盘使用 80%以上,凌晨触发频繁报警,搞 DB 的兄弟们还能不能愉快的睡觉?
(2)谁搞的?ok,GC 不干活。
(3)真正导致问题的原因是啥?OK,TiCDC 背锅。
完了,看到这里本篇文章就基本介绍完了,会不会被劝退?但是老铁千万别走,且听我将细节娓娓道来,后面有“干货”,我会说明我到底做了啥子操作降低硬盘使用;GC 为啥不干活?GC 的原理是啥?还有为啥是 TiCDC 背锅。
凌晨的报警和处理
晚上 11 点收到多条 tikv 集群硬盘空间报警,爬起来打开电脑看看到底出了啥问题,一般 TiKV 使用磁盘空间一般都有下面几个原因:
本来硬盘空间就比较紧张,是不是有哪个业务又晚上“偷偷”灌数据了?这种情况一般看下 grafana 的 overview 监控就能定位。
tikv 日志暴涨,之前遇到过集群升级后 tikv 日志由于静默 reigon 开启导致的日志量过大。这个看下 tikv 日志产生情况,如果是日志过量,直接 rm 日志即可,另外 tikv 支持配置日志保留策略来自动删除日志。
其他情况
本次就是“其他情况”的类型,这个集群本来使用方就多,写入也没有突增啥的,tikv 日志也没有啥异常,因为知道是测试集群,所以就是删除了一些 2021 年的 tikv 日志先将 KV 存储降低到 80%以内不报警了。
第二天.......
好好收拾下测试 TiDB 集群,解决 Tikv 存储问题,靠 2 种方法:
(1)找资源扩容 KV
(2)看看是不是有表过大或者其他异常。
因为是测试集群,不着急直接扩容,万一是有一些大表可以清理下数据啥的,资源就有了。所以我先通过下面的命令来统计库表资源使用情况(不太准,可以参考):
另外官方也提供了接口来统计 table 使用情况(比较准确):
先看下 SQL 的统计结果,我发现有些表都几亿,并且有些表 rows 为 0,竟然也有 size,因为我之前经常遇到统计信息的不准导致的 tables 系统表信息不准的情况,为此,我竟然回收了下集群所有 table 的统计信息。
然后做的操作就是跟业务沟通,删除一个没用的分区,或者 turncate 一些 table 数据,然后我就等待着资源回收了。但是我都等了半个多小时,在没有多少新写入的情况下,region 数量和磁盘空间丝毫没有动静,难道 GC 出了问题?
OK,那我就先从 mysql.tidb 表看下 GC 的情况,不看不知道,一看吓一跳啊,我的 gc-save-point 竟然还在 2021 年的 4 月份,那集群中到底累积了多少 MVCC 版本??我的天。
分析和解决 GC 的问题
通过上图已经可以发现是 GC 的问题,我们需要找出 GC 出了什么问题。一般通过日志和监控。先查看 tidb server 的日志:
通过日志发现 GC 一直等早期的 safe point:424280964185194498
查看下该 TSO 对应的系统时间,发现跟上面 mysql.tidb 截图的 tikv-gc-safe-point 对应的时间:2021-04-16 00:17:13 一致。
需要执行 pd-ctl service-gc-safepoint --pd 命令查询当前的 GC safepoint 与 service GC safepoint,发现卡住的 safe point 跟 ticdc 的 safe_point: 424280964185194498 一致。
查看该集群的 ticdc 任务,发现卡住的 safe point 跟 changefeed id 为 dxl-xxxx-task 这个同步任务的 TSO 一致:
到此终于找到 GC 问题的原因。ticdc 同步任务没有及时删除导致的。解决方案:删除 ticdc 中该同步任务
等一段时间观察 safe-point 的变化,发现已经开始 GC:
不过又卡在了另一个同步任务(ticdc-demo-xxxx-test-shbt-core)上,继续 remove
删除后,等待较长时间(几个小时),最终 GC safe point 恢复正常:
GC 回收完毕后单 KV 存储又之前的 800G 降低到 200G 左右,大家也可以从下图中右边的 cf size 的监控看出来,write CF 从之前的 3.2T 降低到 790G 左右,下降的最多,大家知道对于 tikv 的列簇来说,write cf 是存数据的版本信息(MVCC)的,这个的下降也印证了 TiCDC 导致的 MVCC 版本过多的问题,现在问题完全解决:
问题虽然解决完毕了,但是 Ticdc 默认有个 24 小时的 GC hold 的时间,超过这个时间,就不会再影响 GC,为啥有上面的问题,我也咨询了官方的产研同学:OK,首先定性:”是个 BUG“,这个问题在 4.0.13, 5.0.2, 5.1.0 这几个版本中修复了,因为测试集群,版本从 3.0 一路升级而来,因该是用了老版本踩到了坑,修复 PR 见后面的链接: https://github.com/pingcap/tiflow/pull/1731
GC 原理
虽然讲明白了 ticdc->gc->硬盘报警的问题处理,但是我们还需要对 GC 的原理进行下简单的说明。
TiDB server 架构中的 GC 模块
GC 作为 TiDB Server 的模块,主要的作用就是清理不再需要的旧数据。
大家都知道 Tikv 底层使用是基于 LSM 的数据架构,这种数据存储的方式在做数据 update 时,不会更新原来的数据,而是重新写一份新的数据,并且给每份数据都给定一个事务时间戳,这种机制也是我们经常提到的 MVCC(多版本并发控制)机制,为了避免同一条记录的版本过多,TiDB 设定了一个 tikv_gc_life_time 来控制版本的保留时间(默认 10min),并且每经过 tikv_gc_run_interval 这个时间间隔,就会触发 GC 的操作,清除历史版本的记录,下面详细聊下 GC 的流程。
GC 的流程
GC 都是由 GC Leader 触发的,一个 tidb server 的 cluster 会选举出一个 GC leader,具体是哪个节点可以查看 mysql.tidb 表,gc leader 只是一个身份状态,真正 run RC 的是该 Leader 节点的 gc worker,另外 GC 的流程其实从文章上面的日志可以看出来。
(1)Resolve Locks 阶段
从英文翻译过来很直白:该阶段主要是清理锁,通过 GC leader 日志可以看出,有 start resolve locks;finish resolve locks 的操作,并且都跟着具体的 safepoint,其实这个 safepoint 就是一个时间戳,该阶段会扫描所有的 region,只要在这个时间戳之前由 2PC 产生的锁,该提交的提交,该回滚的回滚。
(2)Delete Ranges 阶段
该阶段主要处理由 drop/truncate 等操作产生的大量连续数据的删除。tidb 会将要删除的 range 首先记录到 mysql.gc_delete_range,然后拿这些已经记录的 range 找对应的 sst 文件,调用 RocksDB 的 UnsafeDestroyRange 接口进行物理删除,删除后的 range 会记录到 mysql.gc_delete_range_done 表。从日志中也可以看到 start delete ranges;finish delete ranges 的操作。
(3)Do GC 阶段
这个阶段主要是清理由 DML 操作产生的大量历史数据版本,因为默认的保留时间为 10min,那么我一张元数据表一年都没有更新过,难道也会被清理?不要紧张,GC 会对每个 key 都保留 safe point 前的最后一次写入时的数据(也就是说,就算表数据不变化,GC 也不会“误清理”数据的)。另外这部分由 DML 产生的 GC,不会马上释放空间,需要 RocksDB 的 compaction 来真正的回收空间,对了还可能涉及“大量空 region 的 merge”(如何回收空 region 的解决方案)。这个阶段的日志有:start redo-delete ranges;finish delete ranges
(4)发送 safe point 给 PD,结束本轮的 GC。日志为:sent safe point to PD
GC 的监控查看
涉及到 GC 的主要看下面的几个监控即可:
tikv-detail 中的 GC 模块->GC task:跟上文所描述,如果执行了 drop/truncate 操作就看看下面监控中 total-unafe-destroy-range 的 metric 是否有值,另外日常的 DML 的 GC,可以看看 total-gc-keys 的 task 情况。
tikv-detail 中的 GC 模块->GC task duration:
不同 gc task 的删除耗时。
tikv-detail 中的 GC 模块->GC speed:
按照 keys/s 的旧 MVCC 版本的删除速度。
PS:想了解更多的 GC 内容可以查看官方文档或者详细阅读 asktug 中坤爷和娇姐写的 GC 三部曲:第一篇为 『GC 原理浅析』,第二篇为『GC 监控及日志解读』 ,而最后一篇则为『GC 处理案例 & FAQ』。
原文作者:@代晓磊_360 发表于: 2022-03-28
评论