add time_guard in medium schedule loop

src/storage/CMakeLists.txt

@@ -586,6 +586,7 @@ ob_set_subtarget(ob_storage compaction
   compaction/ob_tenant_tablet_scheduler.cpp
   compaction/ob_tenant_tablet_scheduler_task_mgr.cpp
   compaction/ob_compaction_schedule_iterator.cpp
+  compaction/ob_compaction_schedule_util.cpp
   compaction/ob_schedule_dag_func.cpp
   compaction/ob_extra_medium_info.cpp
   compaction/ob_medium_compaction_func.cpp

src/storage/compaction/ob_compaction_schedule_util.cpp

@@ -0,0 +1,62 @@
+/**
+ * Copyright (c) 2023 OceanBase
+ * OceanBase is licensed under Mulan PubL v2.
+ * You can use this software according to the terms and conditions of the Mulan PubL v2.
+ * You may obtain a copy of Mulan PubL v2 at:
+ *          http://license.coscl.org.cn/MulanPubL-2.0
+ * THIS SOFTWARE IS PROVIDED ON AN "AS IS" BASIS, WITHOUT WARRANTIES OF ANY KIND,
+ * EITHER EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO NON-INFRINGEMENT,
+ * MERCHANTABILITY OR FIT FOR A PARTICULAR PURPOSE.
+ * See the Mulan PubL v2 for more details.
+ */
+
+#define USING_LOG_PREFIX STORAGE_COMPACTION
+#include "storage/compaction/ob_compaction_schedule_util.h"
+
+namespace oceanbase
+{
+namespace compaction
+{
+
+/**
+ * ObCompactionScheduleTimeGuard Impl
+ */
+const char *ObCompactionScheduleTimeGuard::CompactionEventStr[] = {
+    "GET_TABLET",
+    "UPDATE_TABLET_REPORT_STATUS",
+    "READ_MEDIUM_INFO",
+    "SCHEDULE_NEXT_MEDIUM",
+    "SCHEDULE_TABLET_MEDIUM",
+    "FAST_FREEZE",
+    "SEARCH_META_TABLE",
+    "CHECK_META_TABLE",
+    "SEARCH_CHECKSUM",
+    "CHECK_CHECKSUM",
+    "SCHEDULER_NEXT_ROUND"
+};
+
+const char *ObCompactionScheduleTimeGuard::get_comp_event_str(enum CompactionEvent event)
+{
+  STATIC_ASSERT(static_cast<int64_t>(COMPACTION_EVENT_MAX) == ARRAYSIZEOF(CompactionEventStr), "events str len is mismatch");
+  const char *str = "";
+  if (event >= COMPACTION_EVENT_MAX || event < GET_TABLET) {
+    str = "invalid_type";
+  } else {
+    str = CompactionEventStr[event];
+  }
+  return str;
+}
+
+int64_t ObCompactionScheduleTimeGuard::to_string(char *buf, const int64_t buf_len) const
+{
+  int64_t pos = 0;
+  for (int64_t idx = 0; idx < idx_; ++idx) {
+    if (0 < click_poinsts_[idx]) {
+      fmt_ts_to_meaningful_str(buf, buf_len, pos, get_comp_event_str((CompactionEvent)line_array_[idx]), click_poinsts_[idx]);
+    }
+  }
+  return pos;
+}
+
+} // namespace compaction
+} // namespace oceanbase

src/storage/compaction/ob_compaction_schedule_util.h

@@ -0,0 +1,93 @@
+/**
+ * Copyright (c) 2023 OceanBase
+ * OceanBase is licensed under Mulan PubL v2.
+ * You can use this software according to the terms and conditions of the Mulan PubL v2.
+ * You may obtain a copy of Mulan PubL v2 at:
+ *          http://license.coscl.org.cn/MulanPubL-2.0
+ * THIS SOFTWARE IS PROVIDED ON AN "AS IS" BASIS, WITHOUT WARRANTIES OF ANY KIND,
+ * EITHER EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO NON-INFRINGEMENT,
+ * MERCHANTABILITY OR FIT FOR A PARTICULAR PURPOSE.
+ * See the Mulan PubL v2 for more details.
+ */
+
+#ifndef OB_STORAGE_COMPACTION_COMPACTION_SCHEDULER_UTIL_H_
+#define OB_STORAGE_COMPACTION_COMPACTION_SCHEDULER_UTIL_H_
+
+#include "lib/ob_define.h"
+#include "lib/utility/ob_print_utils.h"
+#include "share/compaction/ob_compaction_time_guard.h"
+
+namespace oceanbase
+{
+namespace compaction
+{
+
+struct ObScheduleStatistics
+{
+public:
+  ObScheduleStatistics() { reset(); }
+  ~ObScheduleStatistics() {}
+  OB_INLINE void reset()
+  {
+    add_weak_read_ts_event_flag_ = false;
+    check_weak_read_ts_cnt_ = 0;
+    start_timestamp_ = 0;
+    clear_tablet_cnt();
+  }
+  OB_INLINE void clear_tablet_cnt()
+  {
+    schedule_dag_cnt_ = 0;
+    submit_clog_cnt_ = 0;
+    finish_cnt_ = 0;
+    wait_rs_validate_cnt_ = 0;
+  }
+  OB_INLINE void start_merge()
+  {
+    add_weak_read_ts_event_flag_ = true;
+    check_weak_read_ts_cnt_ = 0;
+    start_timestamp_ = ObTimeUtility::fast_current_time();
+    clear_tablet_cnt();
+  }
+  TO_STRING_KV(K_(schedule_dag_cnt), K_(submit_clog_cnt), K_(finish_cnt), K_(wait_rs_validate_cnt));
+  bool add_weak_read_ts_event_flag_;
+  int64_t check_weak_read_ts_cnt_;
+  int64_t start_timestamp_;
+  int64_t schedule_dag_cnt_;
+  int64_t submit_clog_cnt_;
+  int64_t finish_cnt_;
+  int64_t wait_rs_validate_cnt_;
+};
+
+struct ObCompactionScheduleTimeGuard : public ObCompactionTimeGuard
+{
+public:
+  ObCompactionScheduleTimeGuard()
+    : ObCompactionTimeGuard(UINT64_MAX, "[STORAGE] ")
+  {}
+  virtual ~ObCompactionScheduleTimeGuard() {}
+  enum CompactionEvent : uint16_t {
+    // medium scheduler
+    GET_TABLET,
+    UPDATE_TABLET_REPORT_STATUS,
+    READ_MEDIUM_INFO,
+    SCHEDULE_NEXT_MEDIUM,
+    SCHEDULE_TABLET_MEDIUM,
+    FAST_FREEZE,
+    // medium checker
+    SEARCH_META_TABLE,
+    CHECK_META_TABLE,
+    SEARCH_CHECKSUM,
+    CHECK_CHECKSUM,
+    SCHEDULER_NEXT_ROUND,
+    COMPACTION_EVENT_MAX
+  };
+  virtual int64_t to_string(char *buf, const int64_t buf_len) const override;
+private:
+  const static char *CompactionEventStr[];
+  static const char *get_comp_event_str(enum CompactionEvent event);
+};
+
+} // compaction
+} // oceanbase
+
+#endif // OB_STORAGE_COMPACTION_COMPACTION_SCHEDULER_UTIL_H_

src/storage/compaction/ob_medium_compaction_func.cpp

@@ -979,7 +979,7 @@ int ObMediumCompactionScheduleFunc::batch_check_medium_meta_table(
     } else if (OB_FAIL(ObTabletTableOperator::batch_get_tablet_info(GCTX.sql_proxy_, MTL_ID(), tablet_ls_infos, tablet_infos))) {
       LOG_WARN("failed to get tablet info", K(ret), K(tablet_ls_infos));
     } else {
-      time_guard.click(ObStorageCompactionTimeGuard::SEARCH_META_TABLE);
+      time_guard.click(ObCompactionScheduleTimeGuard::SEARCH_META_TABLE);
       for (int64_t i = 0, idx = 0; OB_SUCC(ret) && i < tablet_infos.count() && idx < tablet_ls_infos.count(); ++idx) {
         bool merge_finish = false;
         const ObTabletCheckInfo &tablet_ls_info = tablet_ls_infos.at(idx);
@@ -1000,7 +1000,7 @@ int ObMediumCompactionScheduleFunc::batch_check_medium_meta_table(
           ++i;
         }
       }
-      time_guard.click(ObStorageCompactionTimeGuard::CHECK_META_TABLE);
+      time_guard.click(ObCompactionScheduleTimeGuard::CHECK_META_TABLE);
     }
   }
   return ret;
@@ -1209,10 +1209,10 @@ int ObMediumCompactionScheduleFunc::batch_check_medium_finish(
         } else if (OB_FAIL(ObTabletReplicaChecksumOperator::get_tablets_replica_checksum(
             MTL_ID(), finish_tablet_ls_infos, checksum_items))) {
           LOG_WARN("failed to get tablet checksum", K(ret));
-        } else if (FALSE_IT(time_guard.click(ObStorageCompactionTimeGuard::SEARCH_CHECKSUM))) {
+        } else if (FALSE_IT(time_guard.click(ObCompactionScheduleTimeGuard::SEARCH_CHECKSUM))) {
         } else if (OB_FAIL(batch_check_medium_checksum(finish_tablet_ls_infos, checksum_items))) {
           LOG_WARN("failed to check medium tablets checksum", K(ret));
-        } else if (FALSE_IT(time_guard.click(ObStorageCompactionTimeGuard::CHECK_CHECKSUM))) {
+        } else if (FALSE_IT(time_guard.click(ObCompactionScheduleTimeGuard::CHECK_CHECKSUM))) {
         }
       }
     }

src/storage/compaction/ob_tablet_merge_task.cpp

@@ -69,12 +69,7 @@ const char *ObStorageCompactionTimeGuard::CompactionEventStr[] = {
     "UPDATE_TABLET",
     "RELEASE_MEMTABLE",
     "SCHEDULE_OTHER_COMPACTION",
-    "DAG_FINISH",
+    "DAG_FINISH"
-    "SEARCH_META_TABLE",
-    "CHECK_META_TABLE",
-    "SEARCH_CHECKSUM",
-    "CHECK_CHECKSUM",
-    "SCHEDULER_NEXT_ROUND"
 };
 
 const char *ObStorageCompactionTimeGuard::get_comp_event_str(enum CompactionEvent event)

src/storage/compaction/ob_tablet_merge_task.h

@@ -75,11 +75,6 @@ public:
     RELEASE_MEMTABLE,
     SCHEDULE_OTHER_COMPACTION,
     DAG_FINISH,
-    SEARCH_META_TABLE,
-    CHECK_META_TABLE,
-    SEARCH_CHECKSUM,
-    CHECK_CHECKSUM,
-    SCHEDULER_NEXT_ROUND,
     COMPACTION_EVENT_MAX
   };
   virtual int64_t to_string(char *buf, const int64_t buf_len) const override;

src/storage/compaction/ob_tenant_medium_checker.cpp

@@ -268,8 +268,6 @@ int ObTenantMediumChecker::check_medium_finish_schedule()
       while (start_idx < end_idx) {
         if (OB_TMP_FAIL(check_medium_finish(tablet_ls_infos, start_idx, end_idx, batch_tablet_ls_infos, finish_tablet_ls_infos, stat))) {
           LOG_WARN("failed to check medium finish", K(tmp_ret));
-        } else {
-          LOG_INFO("success to batch check medium finish", K(start_idx), K(end_idx), K(info_count));
         }
         start_idx = end_idx;
         end_idx = min(start_idx + batch_size, info_count);
@@ -318,7 +316,7 @@ int ObTenantMediumChecker::check_medium_finish(
         }
       }
     }
-    ObStorageCompactionTimeGuard time_guard;
+    ObCompactionScheduleTimeGuard time_guard;
     stat.filter_cnt_ += (end_idx - start_idx - check_tablet_ls_infos.count());
     if (FAILEDx(ObMediumCompactionScheduleFunc::batch_check_medium_finish(
         ls_info_map_, finish_tablet_ls_infos, check_tablet_ls_infos, time_guard))) {
@@ -339,11 +337,11 @@ int ObTenantMediumChecker::check_medium_finish(
       if (OB_FAIL(MTL(ObTenantTabletScheduler*)->schedule_next_round_for_leader(check_tablet_ls_infos, finish_tablet_ls_infos))) {
         LOG_WARN("failed to leader schedule", K(ret));
       } else {
-        time_guard.click(ObStorageCompactionTimeGuard::SCHEDULER_NEXT_ROUND);
+        time_guard.click(ObCompactionScheduleTimeGuard::SCHEDULER_NEXT_ROUND);
-        LOG_INFO("success to leader schedule", K(ret),
-          K(check_tablet_ls_infos.count()), K(finish_tablet_ls_infos.count()), K(time_guard));
       }
     }
+    LOG_INFO("finish medium check", K(ret), K(start_idx), K(end_idx),
+          K(check_tablet_ls_infos.count()), K(finish_tablet_ls_infos.count()), K(time_guard));
   }
   return ret;
 }

src/storage/compaction/ob_tenant_medium_checker.h

@@ -24,10 +24,6 @@
 
 namespace oceanbase
 {
-namespace storage
-{
-  class ObScheduleStatistics;
-}
 namespace compaction
 {
 class ObTabletCheckInfo

src/storage/compaction/ob_tenant_tablet_scheduler.cpp

@@ -211,6 +211,7 @@ ObTenantTabletScheduler::ObTenantTabletScheduler()
    merged_version_(INIT_COMPACTION_SCN),
    inner_table_merged_scn_(INIT_COMPACTION_SCN),
    min_data_version_(0),
+   time_guard_(),
    schedule_stats_(),
    fast_freeze_checker_(),
    minor_ls_tablet_iter_(false/*is_major*/),
@@ -247,6 +248,7 @@ void ObTenantTabletScheduler::reset()
   merged_version_ = 0;
   inner_table_merged_scn_ = 0;
   min_data_version_ = 0;
+  time_guard_.reuse();
   schedule_stats_.reset();
   minor_ls_tablet_iter_.reset();
   medium_ls_tablet_iter_.reset();
@@ -1384,6 +1386,8 @@ int ObTenantTabletScheduler::schedule_ls_medium_merge(
     ret = OB_STATE_NOT_MATCH;
     LOG_WARN("could not to merge now", K(ret), K(need_merge), K(ls_id));
   } else {
+    ObCompactionScheduleTimeGuard ls_time_guard;
+    ObCompactionScheduleTimeGuard tablet_time_guard;
     ObTabletID tablet_id;
     ObTabletHandle tablet_handle;
     ObTablet *tablet = nullptr;
@@ -1424,6 +1428,7 @@ int ObTenantTabletScheduler::schedule_ls_medium_merge(
     bool tablet_need_freeze_flag = false;
 
     while (OB_SUCC(ret)) { // loop all tablet in ls
+      tablet_time_guard.reuse();
       bool tablet_merge_finish = false;
       tablet_need_freeze_flag = false;
       // ATTENTION!!! load weak ts before get tablet
@@ -1435,6 +1440,7 @@ int ObTenantTabletScheduler::schedule_ls_medium_merge(
         } else {
           LOG_WARN("failed to get tablet", K(ret), K(ls_id), K(tablet_handle));
         }
+      } else if (FALSE_IT(tablet_time_guard.click(ObCompactionScheduleTimeGuard::GET_TABLET))) {
       } else if (OB_UNLIKELY(!tablet_handle.is_valid())) {
         ret = OB_ERR_UNEXPECTED;
         LOG_WARN("invalid tablet handle", K(ret), K(ls_id), K(tablet_handle));
@@ -1451,7 +1457,7 @@ int ObTenantTabletScheduler::schedule_ls_medium_merge(
       } else if (OB_TMP_FAIL(schedule_tablet_medium(
                      ls, tablet_handle, major_frozen_scn, weak_read_ts,
                      could_major_merge, ls_could_schedule_medium, merge_version, enable_adaptive_compaction,
-                     is_leader, tablet_merge_finish, tablet_need_freeze_flag))) {
+                     is_leader, tablet_merge_finish, tablet_need_freeze_flag, tablet_time_guard))) {
         LOG_WARN("failed to schedule tablet medium", KR(tmp_ret), K(ls_id), K(tablet_id));
       }
       medium_ls_tablet_iter_.update_merge_finish(tablet_merge_finish);
@@ -1460,6 +1466,7 @@ int ObTenantTabletScheduler::schedule_ls_medium_merge(
           LOG_WARN("failed to push back tablet_id for batch_freeze", KR(tmp_ret), K(ls_id), K(tablet_id));
         }
       }
+      ls_time_guard.add_time_guard(tablet_time_guard);
     } // end of while
 
     // TODO(@chengkong): submit a async task
@@ -1470,10 +1477,12 @@ int ObTenantTabletScheduler::schedule_ls_medium_merge(
     }
 
     // clear flags set by ls_start_schedule_medium
-    if (ls_could_schedule_medium
+    if (FALSE_IT(ls_time_guard.click(ObCompactionScheduleTimeGuard::FAST_FREEZE))) {
+    } else if (ls_could_schedule_medium
         && OB_TMP_FAIL(clear_prohibit_medium_flag(ls_id, ObProhibitScheduleMediumMap::ProhibitFlag::MEDIUM))) {
       LOG_WARN("failed to clear prohibit schedule medium flag", K(tmp_ret), K(ret), K(ls_id));
     }
+    time_guard_.add_time_guard(ls_time_guard);
   } // else
   return ret;
 }
@@ -1516,7 +1525,8 @@ int ObTenantTabletScheduler::schedule_tablet_medium(
   const bool enable_adaptive_compaction,
   bool &is_leader,
   bool &tablet_merge_finish,
-  bool &tablet_need_freeze_flag)
+  bool &tablet_need_freeze_flag,
+  ObCompactionTimeGuard &time_guard)
 {
   int ret = OB_SUCCESS;
   int tmp_ret = OB_SUCCESS;
@@ -1545,6 +1555,7 @@ int ObTenantTabletScheduler::schedule_tablet_medium(
     if (OB_CHECKSUM_ERROR == tmp_ret) {
       ret = tmp_ret;
     }
+  } else if (FALSE_IT(time_guard.click(ObCompactionScheduleTimeGuard::UPDATE_TABLET_REPORT_STATUS))){
   }
   LOG_DEBUG("schedule tablet medium", K(ret), K(ls_id), K(tablet_id),
             K(tablet_merge_finish), K(last_major_snapshot_version), K(merge_version), K(is_leader));
@@ -1552,6 +1563,7 @@ int ObTenantTabletScheduler::schedule_tablet_medium(
     // follower or no major: do nothing
   } else if (OB_FAIL(tablet.read_medium_info_list(tmp_allocator, medium_list))) {
     LOG_WARN("failed to load medium info list", K(ret), K(tablet_id));
+  } else if (FALSE_IT(time_guard.click(ObCompactionScheduleTimeGuard::READ_MEDIUM_INFO))){
   } else if (medium_list->need_check_finish()) { // need check finished
     schedule_stats_.wait_rs_validate_cnt_++;
     if (OB_TMP_FAIL(MTL(ObTenantMediumChecker *)->add_tablet_ls(
@@ -1571,6 +1583,7 @@ int ObTenantTabletScheduler::schedule_tablet_medium(
         LOG_WARN("failed to schedule next medium", K(tmp_ret), K(ls_id), K(tablet_id));
       }
       need_diagnose = true;
+    } else if (FALSE_IT(time_guard.click(ObCompactionScheduleTimeGuard::SCHEDULE_NEXT_MEDIUM))){
     }
   }
 
@@ -1585,6 +1598,7 @@ int ObTenantTabletScheduler::schedule_tablet_medium(
       need_diagnose = true;
     } else if (create_dag_flag) {
       ++schedule_stats_.schedule_dag_cnt_;
+    } else if (FALSE_IT(time_guard.click(ObCompactionScheduleTimeGuard::SCHEDULE_TABLET_MEDIUM))){
     }
   } else if (major_frozen_scn > merged_version_ // could_major_merge = false
     && OB_TMP_FAIL(ADD_SUSPECT_INFO(
@@ -1648,7 +1662,7 @@ int ObTenantTabletScheduler::schedule_all_tablets_medium()
     ObLSHandle ls_handle;
     ObLS *ls = nullptr;
     LOG_INFO("start schedule all tablet merge", K(merge_version), K(medium_ls_tablet_iter_));
-
+    time_guard_.reuse();
     if (INIT_COMPACTION_SCN == merge_version) {
       merge_version = 0;
     } else if (merge_version > merged_version_) {
@@ -1753,7 +1767,7 @@ int ObTenantTabletScheduler::after_schedule_tenant_medium(
 
   LOG_INFO("finish schedule all tablet merge", K(merge_version), K(schedule_stats_),
       "tenant_merge_finish", medium_ls_tablet_iter_.tenant_merge_finish(),
-      K(merged_version_), "is_scan_all_tablet_finish", medium_ls_tablet_iter_.is_scan_finish());
+      K(merged_version_), "is_scan_all_tablet_finish", medium_ls_tablet_iter_.is_scan_finish(), K_(time_guard));
   if (medium_ls_tablet_iter_.is_scan_finish()) {
     schedule_stats_.clear_tablet_cnt();
   }

src/storage/compaction/ob_tenant_tablet_scheduler.h

@@ -24,6 +24,7 @@
 #include "storage/compaction/ob_tenant_tablet_scheduler_task_mgr.h"
 #include "storage/compaction/ob_compaction_schedule_iterator.h"
 #include "share/compaction/ob_schedule_batch_size_mgr.h"
+#include "storage/compaction/ob_compaction_schedule_util.h"
 
 namespace oceanbase
 {
@@ -46,42 +47,6 @@ struct ObTabletStatKey;
 namespace compaction
 {
 
-struct ObScheduleStatistics
-{
-public:
-  ObScheduleStatistics() { reset(); }
-  ~ObScheduleStatistics() {}
-  OB_INLINE void reset()
-  {
-    add_weak_read_ts_event_flag_ = false;
-    check_weak_read_ts_cnt_ = 0;
-    start_timestamp_ = 0;
-    clear_tablet_cnt();
-  }
-  OB_INLINE void clear_tablet_cnt()
-  {
-    schedule_dag_cnt_ = 0;
-    submit_clog_cnt_ = 0;
-    finish_cnt_ = 0;
-    wait_rs_validate_cnt_ = 0;
-  }
-  OB_INLINE void start_merge()
-  {
-    add_weak_read_ts_event_flag_ = true;
-    check_weak_read_ts_cnt_ = 0;
-    start_timestamp_ = ObTimeUtility::fast_current_time();
-    clear_tablet_cnt();
-  }
-  TO_STRING_KV(K_(schedule_dag_cnt), K_(submit_clog_cnt), K_(finish_cnt), K_(wait_rs_validate_cnt));
-  bool add_weak_read_ts_event_flag_;
-  int64_t check_weak_read_ts_cnt_;
-  int64_t start_timestamp_;
-  int64_t schedule_dag_cnt_;
-  int64_t submit_clog_cnt_;
-  int64_t finish_cnt_;
-  int64_t wait_rs_validate_cnt_;
-};
-
 class ObFastFreezeChecker
 {
 public:
@@ -303,7 +268,8 @@ private:
     const bool enable_adaptive_compaction,
     bool &is_leader,
     bool &tablet_merge_finish,
-    bool &tablet_need_freeze_flag);
+    bool &tablet_need_freeze_flag,
+    ObCompactionTimeGuard &time_guard);
   int after_schedule_tenant_medium(
     const int64_t merge_version,
     bool all_ls_weak_read_ts_ready);
@@ -360,6 +326,7 @@ private:
   int64_t merged_version_; // the merged major version of the local server, may be not accurate after reboot
   int64_t inner_table_merged_scn_;
   uint64_t min_data_version_;
+  ObCompactionScheduleTimeGuard time_guard_;
   ObScheduleStatistics schedule_stats_;
   ObFastFreezeChecker fast_freeze_checker_;
   ObCompactionScheduleIterator minor_ls_tablet_iter_;