tikv gc_worker一直运行

[yarthur]

为提高效率，提问时请提供以下信息，问题描述清晰可优先响应。

• 【TiDB 版本】：v4.0.8
• 【问题描述】：
  发现一个tikv的节点CPU明显比其他节点高很多，查看是gc_worker一直在运行，auto gc progress一直没有完成，10min又重新开始。
  
  
  
  
  

查看tikv日志只发现gc_worker: auto gc will go to rewind日志 （监控时间比日志时间早8H）
[2020/12/21 12:12:13.235 +00:00] [INFO] [gc_manager.rs:503] [“gc_worker: auto gc will go to rewind”] [next_rewind_key=7480000000000000FFE25F698000000000FF000002038E16E551FF234220000419A054FF77DB000000038000FF00000033F7380000FD] [safe_point=421672249726599168]
[2020/12/21 12:12:34.711 +00:00] [INFO] [gc_manager.rs:433] [“gc_worker: auto gc rewinds”] [processed_regions=1222]
tikv日志
tikv.log (12.9 KB)

tidb日志显示有写冲突，但时间点不能完全对上
[2020/12/21 12:09:37.899 +00:00] [INFO] [adapter.go:618] [“pessimistic write conflict, retry statement”] [txn=421672406973677575] [forUpdateTS=421672406973677575] [err=“[kv:9007]Write conflict, txnStartTS=421672406973677575, conflictStartTS=421672406973677570, conflictCommitTS=421672406973677576, key={tableID=21, indexID=2, indexValues={17, }} primary={tableID=21, indexID=2, indexValues={17, }} [try again later]”]
tidb日志
tidb.log.bak (7.8 MB)

[GangShen]

1. select VARIABLE_NAME, VARIABLE_VALUE from mysql.tidb where VARIABLE_NAME like "tikv_gc%"; 执行这个 SQL 确认一下 GC 相关的配置以及运行状态
2. 根据第一点 SQL 的执行结果，看 tikv_gc_leader_desc 确认 gc leader 是哪一个 tidb 节点，到对应的 tidb 节点上 grep -i gc_worker tidb.log 拿一下对应的 GC 相关日志。
3. 可以提供一下 TiKV-Details → GC 和 TiDB → GC 监控面板的完整监控信息看下
4. 悲观事务下，write conflict 日志不用特别关注，并且写冲突应该与 GC 也没有直接关系。所以先定位 GC 的问题。
   
   

[yarthur]

gc last run看着没啥问题

下面是tidb的日志
gc.log (5.1 MB)

[GangShen]

[2020/12/21 12:40:27.499 +00:00] [INFO] [<unknown>] ["New connected subchannel at 0x7fe1528eb420 for subchannel 0x7fded1d00240"]
[2020/12/21 12:40:27.501 +00:00] [INFO] [util.rs:419] ["connecting to PD endpoint"] [endpoints=http://10.66.105.154:2379]
[2020/12/21 12:40:27.502 +00:00] [INFO] [util.rs:484] ["connected to PD leader"] [endpoints=http://10.66.105.154:2379]
[2020/12/21 12:40:27.502 +00:00] [INFO] [util.rs:190] ["heartbeat sender and receiver are stale, refreshing ..."]

从日志中看到有这样的信息，能否重新一下这个 tikv 节点看下能够恢复正常

[yarthur]

那个节点我重启了，在观察一段时间吧；能给我说下是啥原因吗？因为连接过期导致的？

[GangShen]

看日志感觉像是 TiKV 卡住了，所以尝试重启下，看能不能恢复

[yarthur]

重启那个节点后还是复现了，我是在11：22左右重启的

tikv日志
tikv.log (6.3 MB)

[GangShen]

GC 一轮太慢了，如果 GC 在 interval 时间内完成就不会这样。可以上传一下 Overview 面板的完整监控看下么

[yarthur]

[GangShen]

看了下系统负载以及 region 和 leader 的数量并不是很多。
可以调整一下 gc interval 参数，调大一点，比如一个小时，让一轮 GC 运行完成看看么？

[yarthur]

ok 我调整下

[yarthur]

我interval调整为1h后gc完成了，我后面再观察下；
感觉通过调大间隔的方法不能解决根本问题，为啥新的gc会导致上一次未完成的gc中断，然后一直重复这个过程

[GangShen]

从日志看，每次 GC 的 safe point 点是不同的
如果在一轮 GC 运行过程中（如进行到 30% 时）TiKV 获取到了更新的 safepoint，下一轮 GC 则可能停止在上一轮更新 safepoint 时的进度（即下一次 GC 进度达到 30% 时停止

[yarthur]

下一轮 GC 则可能停止在上一轮更新 safepoint 时的进度（即下一次 GC 进度达到 30% 时停止

没读懂后半句的意思 当前gc进度达到30%，这时发现safepoint更新了，会怎么执行呢 ？当前GC停了,然后开启新的一轮GC？

[GangShen]

https://github.com/tikv/tikv/blob/3b2c5337c837b8bf9d37f954a4c17a407e253251/src/server/gc_worker/gc_manager.rs#L376

代码注释这块有相关的解释。
当一轮 GC 进行的时候，会扫描所有如果一轮 GC 没有完成，这个时候 safe_point 发生了更新，那么 GC 会继续进行，对后面 GC 扫描到的 region 会用新的 safe_point 进行 GC ，但是之前已经扫描过的 region 用的是旧的 safe_point 进行 GC 的，所以 TiKV 需要进行 rewind gc ，将之前使用旧 safe_point 进行 GC 的 region 使用新 safe_point 再 GC 一遍。

所以如果 GC 一直无法在一个 interval 中完成就一直会有这个 rewind 的问题。但是这个是没有影响的。

[yarthur]

明白了，多谢啦，需要保证gc interval间隔内gc能完成是吧

但这个gc_a_round一直运行doesn’t matter不太懂，至少会一直占用一个核吧 看不懂rust的代码

[GangShen]

就是这个不会影响 GC 的完整性，从监控上看到的 GC 一直没有 100% 完成，但是实际的话，还是对所有 region 进行了 GC 操作的，不是没有完成 GC 。