How does OceanBase freeze the dump process through log observation?

This article aims to analyze OceanBase’s freeze dump process through logs, using its freeze check thread as the starting point, taking the thread name of tenant (1002) as an example.

Author: Chen Huiming, Axon test engineer, mainly involved in DMP and DBLE automated test projects.

Produced by the Aikeson open source community. Original content may not be used without authorization. Please contact the editor and indicate the source for reprinting.

This article has a total of 3200 words and is expected to take 10 minutes to read.

The following is based on version: 5.7.25 OceanBase_CE 4.2.0.0 (r100000152023080109-8024d8ff45c45cf7c62a548752b985648a5795c3)

The basic process is as follows:

T1002_Occam

1.1 Thread Introduction

The freeze check thread performs a check every 2 seconds. Once a freezing operation is required, a checkpoint task will be generated and processed by the freeze thread. You can verify that this thread is running normally by searching the logs for “tenant freeze timer task”.

1.2 Log Process

When a freeze operation is required, the system will log the output: “[TenantFreezer] A minor freeze is needed”. The trigger condition is that the tenant’s active_memstore_used_ exceeds the memstore_freeze_trigger threshold. After triggering, the system will traverse the tenant log stream, generate and submit the corresponding freezing tasks to the freezing thread.

succeed to start ls_freeze_task(ret=0, ls_id={id:xxx})

T1002_LSFreeze

2.1 Thread Introduction

The main responsibility of this thread is to transfer frozen checkpoints that meet the brushing conditions from new_create_list to prepare_list. During the execution of this process, it will operate based on the judgment conditions defined by the road_to_flush method and the ready_for_flush_ method. These conditions include checking whether the rec_scn of the memtable is frozen and whether a replay reference exists, among other factors.

Note: Whenever a memtable is initialized, the freeze checkpoint associated with it is registered in a doubly linked list named new_create_list. The specific implementation of this process can be found in the ObTabletMemtableMgr::create_memtable() method.

2.2 Log Process

The information recorded through the log does not show all the details of the process in detail, but the following information can be used to judge whether the process is executed normally. “road_to_flush end” also marks the completion of the freezing process.

[2023-08-18 06:44:51.285827] INFO [STORAGE] road_to_flush (ob_data_checkpoint.cpp:333) [1553][T1002_LSFreeze1][T1002][Y0-0000000000000000-0-0] [lt=7] [Freezer] road_to_flush begin(ls_->get_ls_id()={id:1001})
[2023-08-18 06:44:51.285846] INFO [STORAGE] road_to_flush (ob_data_checkpoint.cpp:341) [1553][T1002_LSFreeze1][T1002][Y0-0000000000000000-0-0] [lt=16] [Freezer] new_create_list to ls_frozen_list success(ls_->get_ls_id()={id:1001})
[2023-08-18 06:44:51.285861] INFO [STORAGE] road_to_flush (ob_data_checkpoint.cpp:345) [1553][T1002_LSFreeze1][T1002][Y0-0000000000000000-0-0] [lt=3] [Freezer] ls_frozen_list to active_list success(ls_->get_ls_id()={id:1001})
[2023-08-18 06:44:51.285867] INFO [STORAGE] road_to_flush (ob_data_checkpoint.cpp:355) [1553][T1002_LSFreeze1][T1002][Y0-0000000000000000-0-0] [lt=6] [Freezer] active_list to ls_frozen_list success(ls_->get_ls_id()={id:1001})
[2023-08-18 06:44:51.337395] INFO [STORAGE] road_to_flush (ob_data_checkpoint.cpp:358) [1553][T1002_LSFreeze1][T1002][Y0-0000000000000000-0-0] [lt=16] [Freezer] road_to_flush end(ls_->get_ls_id()={id:1001})

T1002_Flush

3.1 Thread Introduction

The Flush thread runs every 5 seconds, and its running status can be identified by the log information “traversal_flush timer task”. The main task of this thread is to traverse the checkpoint objects in prepare_list and generate the corresponding ObTabletMiniMergeDag object for execution as a DAG task.

3.2 Log Process

The dump execution object is data shards (Tablets), and each dump operation may involve multiple data shards. The following takes the data shard with the data shard ID 200001 as an example to describe the process:

First, for the data fragment ID 200001, create and add the corresponding DAG (Directed Acyclic Graph) to the task queue.

[2023-08-18 06:44:51.335124] INFO [COMMON] inner_add_dag (ob_dag_scheduler.cpp:3377) [1655][T1002_Flush][T1002][Y0-0000000000000000-0-0] [lt=29] add dag success(dag=0x7fa95f358b20, start_time=0, id=Y0-0000000000000000-0-0, dag->hash()=7887337314793470841, dag_cnt=23, dag_type_cnts=22)
[2023-08-18 06:44:51.335132] INFO [COMMON] create_and_add_dag (ob_dag_scheduler.h:1119) [1655][T1002_Flush][T1002][Y0-0000000000000000-0-0] [lt=3] success to create and add dag(ret=0, dag=0x7fa95f358b20)

If the DAG is created successfully, the corresponding success flag will be recorded, that is, “schedule tablet merge dag successfully” will appear in the log. At the same time, the task type of the DAG will be marked as “MINI_MERGE”.

[2023-08-18 06:44:51.335134] INFO [STORAGE.TRANS] flush (ob_memtable.cpp:2095) [1655][T1002_Flush][T1002][Y0-0000000000000000-0-0] [lt= 2] schedule tablet merge dag successfully(ret=0, param={merge_type:"MINI_MERGE", merge_version:0, ls_id:{id:1001}, tablet_id:{id:200001}, report_:null, for_diagnose:false ,
...
recommend_snapshot_version:{val:18446744073709551615, v:3}})

T1002_DagSchedu

4.1 Thread Introduction

According to the type of tasks in the DAG queue, the system will create corresponding threads to execute the tasks accordingly. During this process, a thread named “T1002_MINI_MERGE” will be created to perform the dump task. At the same time, the first task, ObTabletMergePrepareTask, will be created. The execution of this task will eventually trigger the generation of two other tasks: ObTabletMergeTask and ObTabletMergeFinishTask.

4.2 Log Process

In the “T1002_DagScheduler” thread, the corresponding logs can be filtered out by tablet_id. You can find the record of type “DAG_MINI_MERGE” and record the corresponding task_id (YB427F000001-0006032C0D448715-0-0).

[2023-08-18 06:44:51.420180] INFO [SERVER] add_task (ob_sys_task_stat.cpp:142) [1597][T1002_DagSchedu][T1002][Y0-0000000000000000-0-0] [lt=9] succeed to add sys task(task={start_time:1692341091420175, task_id:YB427F000001-0006032C0D448715-0-0, task_type:3, svr_ip:"127.0.0.1:2882", tenant_id:1002, is_cancel:false, comment:\ "info="DAG_MINI_MERGE";ls_id=1001;tablet_id=200001;compaction_scn=0;extra_info="merge_type="MINI_MERGE"";"})

In the thread “T1002_DagScheduler”, by filtering the task identifier task_id, you can clearly see the entire DAG task scheduling process, with a total of 3 tasks scheduled.

[2023-08-18 06:44:51.420180] INFO [SERVER] add_task (ob_sys_task_stat.cpp:142) [1597][T1002_DagSchedu][T1002][Y0-0000000000000000-0-0] [lt=9] succeed to add sys task(task={start_time:1692341091420175, task_id:YB427F000001-0006032C0D448715-0-0, task_type:3, svr_ip:"127.0.0.1:2882", tenant_id:1002, is_cancel:false, comment:\ "info="DAG_MINI_MERGE";ls_id=1001;tablet_id=200001;compaction_scn=0;extra_info="merge_type="MINI_MERGE"";"})
[2023-08-18 06:44:51.420192] INFO [COMMON] schedule_one (ob_dag_scheduler.cpp:2997) [1597][T1002_DagSchedu][T1002][YB427F000001-0006032C0D448715-0-0] [lt=12] schedule one task (task=0x7fa9264c8080, priority="PRIO_COMPACTION_HIGH", group id=0, total_running_task_cnt=6, running_task_cnts_[priority]=6, low_limits_[priority]=6, up_limits_[priority]=6, task->get_dag()- >get_dag_net()=NULL)
[2023-08-18 06: 44: 51.421879] Info [Common] schedule_one (ob_dag_scheduler.cpp: 2997) [1597] [t1002_dagschedu] [T1002] [yb427f000001-000606032c0d44871515 -0-0] [LT = 8] Schedule One Task (task=0x7fa9264c81b0, priority="PRIO_COMPACTION_HIGH", group id=0, total_running_task_cnt=6, running_task_cnts_[priority]=6, low_limits_[priority]=6, up_limits_[priority]=6, task->get_dag()- >get_dag_net()=NULL)
[2023-08-18 06:44:51.876070] INFO [COMMON] schedule_one (ob_dag_scheduler.cpp:2997) [1597][T1002_DagSchedu][T1002][YB427F000001-0006032C0D448715-0-0] [lt=16] schedule one task (task=0x7fa9264c8390, priority="PRIO_COMPACTION_HIGH", group id=0, total_running_task_cnt=6, running_task_cnts_[priority]=6, low_limits_[priority]=6, up_limits_[priority]=6, task->get_dag()- >get_dag_net()=NULL)

T1002_MINI_MERG

5.1 Thread Introduction

This thread is mainly responsible for executing tasks scheduled in “T1002_DagScheduler”.

5.2 Log Process

Filtering out the corresponding task ID task_id from the complete log, we can clearly see that a total of 3 task schedules were performed. The log is divided into the following 3 parts.

5.2.1 ObTabletMergePrepareTask

Prepare task: mainly involves some initialization work and check items to prepare for subsequent tasks.

[2023-08-18 06:44:51.420180] INFO [SERVER] add_task (ob_sys_task_stat.cpp:142) [1597][T1002_DagSchedu][T1002][Y0-0000000000000000-0-0] [lt=9] succeed to add sys task(task={start_time:1692341091420175, task_id:YB427F000001-0006032C0D448715-0-0, task_type:3, svr_ip:"127.0.0.1:2882", tenant_id:1002, is_cancel:false, comment:\ "info="DAG_MINI_MERGE";ls_id=1001;tablet_id=200001;compaction_scn=0;extra_info="merge_type="MINI_MERGE"";"})
[2023-08-18 06:44:51.420192] INFO [COMMON] schedule_one (ob_dag_scheduler.cpp:2997) [1597][T1002_DagSchedu][T1002][YB427F000001-0006032C0D448715-0-0] [lt=12] schedule one task (task=0x7fa9264c8080, priority="PRIO_COMPACTION_HIGH", group id=0, total_running_task_cnt=6, running_task_cnts_[priority]=6, low_limits_[priority]=6, up_limits_[priority]=6, task->get_dag()- >get_dag_net()=NULL)
...
[2023-08-18 06:44:51.421833] INFO [STORAGE.COMPACTION] process (ob_tablet_merge_task.cpp:976) [1561][T1002_MINI_MERG][T1002][YB427F000001-0006032C0D448715-0-0] [lt=2 0] succeed to init merge ctx(task={this:0x7fa9264c8080, type:15, status:2, dag:{ObIDag:{this:0x7fa95f358b20, type:0, name:"MINI_MERGE", id:YB427F000001-0006032C0D448715-0- 0, dag_ret:0, dag_status:2, start_time:1692341091420191, running_task_cnt:1, indegree:0, consumer_group_id:0, hash:7887337314793470841}, param:{merge_type:"MINI_MERGE", merge_version:0, ls_id:{id :1001}, tablet_id:{id:200001}, report_:null, for_diagnose:false, is_tenant_major_merge:false, need_swap_tablet_flag:false}, compat_mode:0, ctx:{sstable_version_range:{multi_version_start:1, base_version:0, snapshot_version:169234109111367145 1 }, scn_range:{start_scn:{val:1, v:0}, end_scn:{val:1692341091275445526, v:0}}}}})

5.2.2 ObTabletMergeTask

Merge task: The focus of this task is to write macro blocks and merge multiple versions of records into one record to organize and merge data.

[2023-08-18 06:44:51.421879] INFO  [COMMON] schedule_one (ob_dag_scheduler.cpp:2997) [1597][T1002_DagSchedu][T1002][YB427F000001-0006032C0D448715-0-0] [lt=8] schedule one task(task=0x7fa9264c81b0, priority="PRIO_COMPACTION_HIGH", group id=0, total_running_task_cnt=6, running_task_cnts_[priority]=6, low_limits_[priority]=6, up_limits_[priority]=6, task->get_dag ()->get_dag_net()=NULL)
...
...
[2023-08-18 06:44:51.875958] INFO [STORAGE.COMPACTION] process (ob_tablet_merge_task.cpp:1555) [1595][T1002_MINI_MERG][T1002][YB427F000001-0006032C0D448715-0-0] [lt= 25] merge macro blocks ok(idx_=0, task={this:0x7fa9264c81b0, type:1, status:2, dag:{ObIDag:{this:0x7fa95f358b20, type:0, name:"MINI_MERGE", id:YB427F000001-0006032C0D448715 -0-0, dag_ret:0, dag_status:2, start_time:1692341091420191, running_task_cnt:1, indegree:0, consumer_group_id:0, hash:7887337314793470841}, param:{merge_type:"MINI_MERGE", merge_version:0, ls_id :{id:1001}, tablet_id:{id:200001}, report_:null, for_diagnose:false, is_tenant_major_merge:false, need_swap_tablet_flag:false}, compat_mode:0, ctx:{sstable_version_range:{multi_version_start:1, base_version:0, snapshot_version:1692341091113671451}, scn_range:{start_scn:{val:1, v:0}, end_scn:{val:1692341091275445526, v:0}}}}})

5.2.3 ObTabletMergeFinishTask

Finish task: Mainly responsible for generating new MINI SSTable and releasing related MemTable.

 [2023-08-18 06:44:51.876070] INFO [COMMON] schedule_one (ob_dag_scheduler.cpp:2997) [1597][T1002_DagSchedu][T1002][YB427F000001-0006032C0D448715-0-0] [lt=16 ] schedule one task(task=0x7fa9264c8390, priority="PRIO_COMPACTION_HIGH", group id=0, total_running_task_cnt=6, running_task_cnts_[priority]=6, low_limits_[priority]=6, up_limits_[priority]=6, task->get_dag ()->get_dag_net()=NULL)
...

[2023-08-18 06:44:51.876907] INFO [STORAGE.COMPACTION] create_sstable (ob_tablet_merge_ctx.cpp:344) [1589][T1002_MINI_MERG][T1002][YB427F000001-0006032C0D448715-0-0] [lt=50] succeed to merge sstable(param={table_key:{tablet_id:{id:200001}, column_group_idx:0, table_type:"MINI", scn_range:{start_scn:{val:1, v:0}, end_scn:{val: 1692341091275445526, v:0}}}, sstable_logic_seq:0, schema_version:1692341087064224, ...
...

[2023-08-18 06:44:51.889896] INFO [STORAGE] release_memtables (ob_i_memtable_mgr.cpp:164) [1589][T1002_MINI_MERG][T1002][YB427F000001-0006032C0D448715-0-0] [lt= 6] succeed to release memtable(ret=0, i=1, scn={val:1692341091275445526, v:0})
[2023-08-18 06:44:51.889938] INFO [STORAGE.COMPACTION] process (ob_tablet_merge_task.cpp:1209) [1589][T1002_MINI_MERG][T1002][YB427F000001-0006032C0D448715-0-0] [lt= 12] sstable merge finish(ret=0, merge_info={is_inited:true, sstable_merge_info:{tenant_id:1002, ls_id:{id:1001}, tablet_id:{id:200001}, compaction_scn:1692341091275445526, merge_type:"MINI_MERGE", merge_cost_time :454652, merge_start_time:1692341091421154, merge_finish_time:1692341091875806, dag_id:YB427F000001-0006032C0D448715-0-0, occupy_size:63203471, new_flush_occupy_size:632034 71, original_size:75545791, compressed_size:62951855, macro_block_count:31, multiplexed_macro_block_count:0, new_micro_count_in_new_macro:3823, multiplexed_micro_count_in_new_macro :0, total_row_count:333312, incremental_row_count:333312,
...

Finally, after the DAG task is executed, the related tasks will be cleared, marking the successful execution of the data freezing and dumping process.

[2023-08-18 06:44:51.890015] INFO [COMMON] finish_dag_ (ob_dag_scheduler.cpp:2563) [1589][T1002_MINI_MERG][T1002][YB427F000001-0006032C0D448715-0-0] [lt =19] dag finished(dag_ret=0, runtime=469823, dag_cnt=9, dag_cnts_[dag.get_type()]=9, & amp;dag=0x7fa95f358b20, dag={ObIDag:{this:0x7fa95f358b20, type:0, name:\ "MINI_MERGE", id:YB427F000001-0006032C0D448715-0-0, dag_ret:0, dag_status:3, start_time:1692341091420191, running_task_cnt:0, indegree:0, consumer_group_id:0, hash:788733731479347 0841}, param:{merge_type:\ "MINI_MERGE", merge_version:0, ls_id:{id:1001}, tablet_id:{id:200001}, report_:null, for_diagnose:false, is_tenant_major_merge:false, need_swap_tablet_flag:false}, compat_mode:0, ctx:{sstable_version_range :{multi_version_start:1, base_version:0, snapshot_version:1692341091113671451}, scn_range:{start_scn:{val:1, v:0}, end_scn:{val:1692341091275445526, v:0}}}})
[2023-08-18 06:44:51.890035] INFO [SERVER] del_task (ob_sys_task_stat.cpp:171) [1589][T1002_MINI_MERG][T1002][YB427F000001-0006032C0D448715-0-0] [lt=18] succeed to del sys task(removed_task={start_time:1692341091420175, task_id:YB427F000001-0006032C0D448715-0-0, task_type:3, svr_ip:"127.0.0.1:2882", tenant_id:1002, is_cancel:false, comment:\ "info= "DAG_MINI_MERGE";ls_id=1001;tablet_id=200001;compaction_scn=0;extra_info="merge_type="MINI_MERGE"";"})

For more technical articles, please visit: https://opensource.actionsky.com/

About SQLE

SQLE is a comprehensive SQL quality management platform that covers SQL auditing and management from development to production environments. It supports mainstream open source, commercial, and domestic databases, provides process automation capabilities for development and operation and maintenance, improves online efficiency, and improves data quality.

SQLE get

Type	Address
Repository	https://github.com/actiontech/sqle
Documentation	https://actiontech.github.io/sqle-docs/
Release information	https://github.com/actiontech/sqle/releases
Data review Plug-in development documentation	https://actiontech.github.io/sqle-docs/docs/dev-manual/plugins/howtouse