Checkpoint Mgr 相关常见问题排查

本文总结了 Checkpoint Mgr 的一些 共性重复 的问题，提供快速定位。

冻结卡住

本文的冻结专指为了释放内存而进行的 data_memtable 日志流冻结，目前日志流冻结的触发方式包括租户内存检查，alter minor freeze 语法以及 clog 盘不足，通过转储推 checkpoint 等。日志流冻结中，memtable 的冻结和转储调度由 checkpoint mgr 进行，下图从 checkpoint mgr 的视角看 memtable 由创建到释放内存的过程。

1. memtable 创建之后会加入到 checkpoint mgr 的 new_create_list。
2. 当 memtable 的 recover log ts(rec_log_ts) 小于等于连续最大回调(放)点时，rec_log_ts 不会再改变 ,则被移到 active_list。
3. 当 memtable 将日志全部写完，冻结完成会被移到 prepare_list，并立刻发器转储 DAG。
4. 当 memtable 转储完成，会回调将 memtable 从 prepare_list 中移除。

日志流冻结由冻结主线程发起，进行 memtable 冻结包括提升 freeze_clock，写日志以及明确 memtable 右边界等，同时异步任务完成所有 forzen_memtable 在 checkpoint mgr 里 active_list 到 prepare_list 的调度，当所有 frozen_memtable 都转移到 prepare_list，日志流冻结结束。

问题排查

1. 明确日志流冻结状况。

   首先明确冻结卡住的 tenant_id, 以 1004 租户为例, 然后明确这个租户有哪些日志流，可以通过如下虚拟表查询：

   obclient> select * from __all_virtual_ls_info where tenant_id = 1004;
   

   明确对应的租户是否发起过日志流冻结。以 1004 租户为例。

   //表示日志流冻结开始
   grep "logstream_freeze start" observer.log | grep T1004
   

   以下日志为日志流冻结完成时打印的 flog , 以 1001 号日志流为例, 通过返回日志可以明确日志流冻结是否完成。

   grep "logstream_freeze success" observer.log | grep T1004 | grep id:1001
   

   如果只有 start， 没有 success，说明日志流冻结卡住。

2. 明确冻结卡住的模块。

   执行如下命令，如果有相关日志，说明是卡在了checkpoint mgr 的调度里。

   grep "finish ls_freeze costs too much time" observer.log | grep T1004  | grep id:1001
   

   如果不是 checkpoint mgr 调度卡住，请参考 冻结与转储流程对应日志情况。

3. 明确日志流冻结卡在 checkpoint mgr 的位置。

   日志流冻结需要从 new_create_list 开始，把所有 frozen_memtable 移动到 prepare_list，转移流程如下：

   new_create_list  -> ls_frozen_list -> active_list -> ls_frozen_list -> prepare_list
   

   整个过程会依次打印如下日志：

   STORAGE_LOG(INFO, "[Freezer] road_to_flush begin", K(ls_->get_ls_id()));
   STORAGE_LOG(INFO, "[Freezer] new_create_list to ls_frozen_list success",
               K(ls_->get_ls_id()));
   STORAGE_LOG(INFO, "[Freezer] ls_frozen_list to active_list success",
               K(ls_->get_ls_id()));
   STORAGE_LOG(INFO, "[Freezer] active_list to ls_frozen_list success",
               K(ls_->get_ls_id()));
   STORAGE_LOG(INFO, "[Freezer] ls_frozen_list to prepare_list success",
               K(ls_->get_ls_id()));
   STORAGE_LOG(INFO, "[Freezer] road_to_flush end", K(ls_->get_ls_id()));
   

   根据以上日志可以判断卡在了哪一步，另外下面一条日志，根据返回日志里信息判断卡在哪一步。

   grep "cost too much time in ls_frozen_list_" observer.log
   // ls_frozen_to_active_表示卡在了 ls_frozen_list to active_list
   // ls_frozen_to_prepare_ 表示卡在了 ls_frozen_list to prepare_list
   

   根据以下日志可以进一步明确卡住 memtable 的信息以及原因

   grep "the block obFreezecheckpoint is :" observer.log
   

   

   其中常见的卡住原因包括：

   1. 卡在 ls_frozen_list to active_list，因为有 memtable rec_log_ts 无法 stable。

      原因包括：

      1. 空 memtable 引用计数未清 0: 如果 rec_log_ts 是 INT64_MAX(922337...)，write_ref_cnt 或 unsynced_cnt 不为 0 。

      2. 如果 rec_log_ts 不是 INT64_MAX, 则是因为连续回调(放)点卡住或者推进慢。

   2. 卡在 ls_frozen_list to prepare_list，因为有 memtable 无法冻结成功，原因包括：

      1. memtable 相关引用计数未清 0: write_ref_cnt 或 unsynced_cnt 不为 0 。

      2. 连续回调(放)点卡住或者推进慢。

转储失败

memtable 被移到 prepare_list 会立刻发起一次转储 DAG，当 memtable 转储完成，会通过回调将 memtable 从 prepare_list 移除；同时有兜底线程定时 5 秒遍历 prepare_list 发起转储，避免因为特殊情况有 DAG 失败导致 memtable 无法最终转储的问题。

问题排查

首先需要根据上述冻结卡住的问题排查，明确日志流冻结均正常进行，日志流冻结只要没有卡住，frozen_memtable 一定都已经到了 prepare_list 中。

1. 明确是否大量 memtable 堆积在 prepare_list 中。

   通过以下虚表可以看出目前在 prepare_list 里 memtable 的数量。

   obclient> select count(*) from oceanbase.__all_virtual_transaction_freeze_checkpoint where tenant_id = 1004 and ls_id = 1001 and location = 'PREPARE';
   

   如果发现大量 memtable 堆积在 prepare_list，则怀疑是未调度。

2. 明确是否转储调度线程正常。

   如果定时打印以下日志则说明调度线程正常，反之需要 pstack 根据线程号定位卡住的原因。每一次兜底转储完会打印。

   grep "traversal_flush successfully" observer.log | grep T1004 | grep id:1001
   

3. 明确发起转储任务是否失败。

   执行如下命令查询转储调度失败日志：

   grep "memtable flush failed" | grep "traversal_flush"
   

   其中返回错误码语义如下：

   • 4019 : 转储队列满 , 长时间报这个错误不符合预期。
   • 4023 : 对应的 memtable 已经在转储队列中(长时间连续报这个错误不符合预期)。

4. 明确转储调度失败或转储失败原因。

   查询 compaction 诊断虚拟表，判断是否存在该 tablet 的 compaction 执行问题。

   obclient> select * from oceanbase.__all_virtual_compaction_diagnose_info；
   

Clog Checkpoint 推进异常

目前的 clog checkpoint 的推进可以简单的理解为，定时遍历所有写 clog 的模块取 rec_log_ts 的最小值。 目前 checkpoint 的抽象包括三层, 其中每一个抽象的模块都维护着自己的 rec_log_ts(recovery_log_ts)，其中 data_memtable 在 data_checkpoint 的 list 中。

问题排查

1. 通过日志明确 checkpoint 推进情况。

   定时任务每次计算 checkpoint 都会打印一条下面 2 个日志中的一条，以 1004 租户，1001 日志流举例，可以根据日志返回明确当前 checkpoint_log_ts 是多少，以及哪个模块给了这个值。如果 checkpoint 推进异常，也就是预期应该推进却卡住不退，或者是 checkpoint 倒退了，则需要定位对应是哪个模块并联系技术支持处理。

   推进 checkpoint 的日志。

   grep "update clog checkpoint successfully" | grep T1004 | grep id:1001
   

   新一轮计算 checkpoint 发现没有变化。

   grep "clog checkpoint no change" | grep T1004 | grep id:1001
   

2. 通过虚拟表定位导致 checkpoint 推进异常的模块。

   虚拟表可以看到不同模块现在的 rec_log_ts， 参照上述的抽象，自下而上则可以定位出目前影响 checkpoint 推进的模块。

   • 明确最小的 rec_log_ts 所属的 service。

     select * from __all_virtual_checkpoint where tenant_id = 1004 and ls_id = 1001 order by rec_log_scn limit 1;
     

   • 如果最小的 rec_log_ts 是 trans_service, 进一步明确最小的 rec_log_ts 所属的 common_checkpoint。

     select * from __all_virtual_transaction_checkpoint where tenant_id = 1004 and ls_id = 1001 order by rec_log_scn limit 1;
     

   • 如果最小的 rec_log_ts 是 data_checkpoint, 进一步明确最小的 rec_log_ts 所属的 memtable。

     select * from __all_virtual_transaction_freeze_checkpoint where tenant_id = 1004 and ls_id = 1001 order by rec_log_scn limit 1;
     

3. 通过日志定位导致 checkpoint 推进异常的模块。

   根据上述的日志返回，对应的 k 表示提供最小的 rec_log_ts 的 servicetype, 具体 type 对应的 service，参考 ObLogBaseType；(如果 k=0，则最小 rec_log_ts 来自连续回调(放)点)。

   

   如果 k 为 1，可以进一步通过以下日志返回的 k 值明确是 trans_service 哪个模块提供了最小的 rec_log_ts，参考 ObCommonCheckpointType。

   grep "ObLSTxService::get_rec_log_ts" | grep T1004 | grep id:1001
   

   

   如果通过日志定位是 DATA_CHECKPOINT_TYPE 或者通过虚表定位是某个 memtable 给了最小 rec_log_ts, 大概率是因为冻结卡住或转储调度问题。

Clog 盘满

OceanBase 数据库 V4.0.x 架构下的 clog 盘，日志盘进行了租户级拆分，意味着无法再以 V3.x 版本的视角判断 clog 是否盘满，例如通过 df -h 命令查看 clog 盘是否使用超过 80%，而是需要通过查看租户的日志盘使用情况判断租户的日志盘是否满。

目前 clog 的回收以每个 ls 上的 clog checkpoint 为依据，确保大于等于 checkpoint 的日志不会被回收，当定时任务判断 clog 容量不足时(租户 clog 使用超过 60% && 租户根据 checkpoint 算得的不可回收的日志量超过60%)，会根据 (end_log_ts(连续已确认的 logts) - clog_checkpoint_ts) * percent 得出一个 recycle_scn 通知所有 rec_log_ts 小于 recycle_scn 的模块进行转储，从而达到推进 checkpoint 的目的。

问题排查

1. 明确租户下哪个日志流导致日志文件无法回收。

   V4.0.x 版本的日志盘进行租户隔离，当租户出现日志盘爆时，需要首先明确哪个日志流（哪些日志流）导致日志盘爆，通常我们只需要观察当出现日志盘爆时，哪些日志流的日志盘空间使用超过 128MB。

   根据视图 gv$ob_log_stat 可以查看日志流日志盘使用超过磁盘回收水位线（默认是 80%，可以通过配置项调整）情况:

   select tenant_id, svr_ip, svr_port, LOG_DISK_IN_USE, LOG_DISK_SIZE from gv$ob_units where LOG_DISK_IN_USE > LOG_DISK_SIZE*0.8;
   

   如果发现有租户的磁盘使用超过租户日志盘规格的 80%，需要进一步查询 __all_virtual_log_stat，其中(endlsn - baselsn)表示对应日志流还不能回收的日志量(字节)，当使用超过 128MB 时，同时日志盘存在爆的情况，那么该日志流一定阻塞日志回收，具体的 SQL 语句如下：

   select * from __all_virtual_log_stat where tenant_id = xxxx and svr_ip = 'xxxx' and svr_port = xxxx and end_lsn-base_lsn >128*1024*1024 ;
   

   若虚拟表无法访问，可以通过 grep 以下几条日志，确定是哪个日志流：

   grep 'ERROR.*Txxxx_PalfGC' observer.log.* 
   
   [2022-07-19 21:34:37.191950] ERROR [PALF] try_recycle_blocks (palf_env_impl.cpp:637) [147234][T1010_PalfGC][T1010][Y0-0000000000000000-0-0] [lt=21] clog disk space is almost full(total_size(MB)=165888, used_size(MB)=132710, used_percent(%)=80, warn_size(MB)=132710, warn_percent(%)=80, limit_size(MB)=157593, limit_percent(%)=95, maximum_used_size(MB)=74026, maximum_log_stream=1006, oldest_log_stream=1004, oldest_timestamp=1658223124759857784) BACKTRACE:0x434d92e 0xc1a323a 0xc194b93 0x44726d4 0x447239f 0x44721cb 0x4471ffd 0x45b102c 0x45b0339 0x43671aa 0x4365b6d 0x521ebf9 0xc396ec6 0xc391b19 0x7f337d6bfe24 0x7f337cf68f1c
   

   • maximum_log_stream 表示使用日志盘空间最多的日志流。
   • oldest_log_stream 表示日志最旧的日志流。

2. 明确是否 checkpoint 没有推进，具体请参考上述文档中的 clog checkpoint 推进异常的内容。

3. 明确是否在盘满前触发了转储。

   首先根据日志判断有没有在盘满前触发冻结转储, 以 1004 租户 1001 日志流为例：

   grep 'advance checkpoint by flush to avoid clog disk full' observer.log.* ｜ grep T1004 | grep id:1001
   

   该日志是在盘满前触发转储前打印的日志。 返回日志重要字段语义如下：

   • recycle_scn: 预期转储以后 checkpoint_log_ts 一定推过 recycle_scn。
   • clog_checkpoint_lsn: 目前这个 ls 的 checkpoint_lsn (end_lsn - clog_checkpoint_lsn 即为当前这个日志流不可回收的日志量，单位字节)。
   • max_decided_scn: 日志流的连续回放/回调位点，clog可回收位点不可能超过该位点。
   • min_recycle_scn: 为了避免过于频繁的冻结和回收，设定了日志回收的最小阈值，确保单次冻结一定能回收一定量（整个日志流的x%）的 clog 。
   • expected_recycle_scn: 根据公式计算得到的回收位点，实际可回收位点小于该点时，会选择实际可回收位点。

   如果没有触发的日志，可能是如下三点： 1）复用了旧的回收位点：grep 'clog checkpoint has not changed yet. use previous recycle_scn to advance checkpoint'

   2）回放落后较多，可回收量少，跳过了本次触发冻结回收：grep 'recycle_scn too small, skip trigger flush once' 3）其他。

   对于第三点，可以根据以下 2 个日志查看是否达到了触发条件，只有租户的 clog 使用量以及 cannot_recycle_log_size 都达到租户 clog 盘 total_size 的 60% 才会触发转储。

   如果某个租户日志盘使用超过 60% 一定会打这个日志。 这个日志每 2s 打一次，如果 cannot_recycle_log_size / threshold > 60%, 才会触发转储

   grep "cannot_recycle_log_size statistics" observer.log | grep T1004
   

4. 明确是否冻结卡住。

   如果定期打印以下日志说明没有卡住，如果卡住参考上述文档中的冻结卡住相关内容。

   grep "check clog disk timer task" observer.log
   

5. 明确是否转储失败，具体参考上述文档转储失败相关内容。