downgrade several log print frequency

src/logservice/logrpc/ob_log_request_handler.cpp

@@ -13,20 +13,21 @@
 #include "ob_log_request_handler.h"
 #include "ob_log_rpc_req.h"
 #include "logservice/ob_log_service.h"
+#include "logservice/palf/log_define.h"
 
 namespace oceanbase
 {
 namespace logservice
 {
-
-
-LogRequestHandler::LogRequestHandler(palf::PalfHandle *palf_handle) : palf_handle_(palf_handle)
+LogRequestHandler::LogRequestHandler(palf::PalfHandle *palf_handle) : palf_handle_(palf_handle),
+                                                                      handle_request_print_time_(OB_INVALID_TIMESTAMP)
 {
 }
 
 LogRequestHandler::~LogRequestHandler()
 {
   palf_handle_ = NULL;
+  handle_request_print_time_ = OB_INVALID_TIMESTAMP;
 }
 
 template <>
@@ -43,6 +44,7 @@ int LogRequestHandler::handle_sync_request<LogConfigChangeCmd, LogConfigChangeCm
   } else {
     ConfigChangeCmdHandler cmd_handler(palf_handle_);
     if (OB_FAIL(cmd_handler.handle_config_change_cmd(req))) {
+      if (palf::palf_reach_time_interval(100 * 1000, handle_request_print_time_))
       PALF_LOG(WARN, "handle_config_change_cmd failed", K(ret), K(palf_id), K(server), K(req), KPC(palf_handle_));
     } else {
       PALF_LOG(INFO, "handle_config_change_cmd success", K(ret), K(palf_id), K(server), K(req), K(resp), KPC(palf_handle_));

src/logservice/logrpc/ob_log_request_handler.h

@@ -34,6 +34,7 @@ public:
                           RespType &resp);
 private:
   palf::PalfHandle *palf_handle_;
+  int64_t handle_request_print_time_;
 };
 
 class ConfigChangeCmdHandler{

src/logservice/palf/log_config_mgr.cpp

@@ -48,6 +48,7 @@ LogConfigMgr::LogConfigMgr()
       persistent_config_version_(),
       barrier_print_log_time_(OB_INVALID_TIMESTAMP),
       last_check_state_ts_us_(OB_INVALID_TIMESTAMP),
+      check_config_print_time_(OB_INVALID_TIMESTAMP),
       parent_lock_(),
       register_ts_ns_(OB_INVALID_TIMESTAMP),
       parent_(),
@@ -480,7 +481,7 @@ const common::ObAddr &LogConfigMgr::get_parent() const
 
 // 1. switch config change state machine
 // 2. broadcasting leader info periodically
-// 3. resend config log to members and followers who haven't responsed ack 
+// 3. resend config log to members and followers who haven't responsed ack
 // after config change finished.
 int LogConfigMgr::leader_do_loop_work()
 {
@@ -771,8 +772,10 @@ int LogConfigMgr::check_config_change_args_(const LogConfigChangeArgs &args, boo
           if (args.type_ == ADD_MEMBER_AND_NUM || new_replica_num == paxos_replica_num_) {
             // config change has finished successfully, do not need change again
             is_already_finished = true;
-            PALF_LOG(INFO, "member already exists, don't need add_member/replace_member", KR(ret), K_(palf_id), K_(self),
-                K_(log_ms_meta), K(member), K(new_replica_num), K_(paxos_replica_num));
+            if (palf_reach_time_interval(100 * 1000, check_config_print_time_)) {
+              PALF_LOG(INFO, "member already exists, don't need add_member/replace_member", KR(ret), K_(palf_id), K_(self),
+                  K_(log_ms_meta), K(member), K(new_replica_num), K_(paxos_replica_num));
+            }
           } else {
             ret = OB_INVALID_ARGUMENT;
             PALF_LOG(INFO, "member already exists, but new_replica_num not equal to curr val", KR(ret), K_(palf_id), K_(self),
@@ -929,7 +932,7 @@ int LogConfigMgr::check_config_change_args_(const LogConfigChangeArgs &args, boo
       }
     }
     // check if reaches majority
-    LogConfigInfo new_config_info; 
+    LogConfigInfo new_config_info;
     common::ObMemberList new_paxos_memberlist;
     int64_t new_paxos_replica_num;
     GlobalLearnerList unused_list;
@@ -1618,7 +1621,7 @@ int LogConfigMgr::handle_register_parent_resp(const LogLearner &server,
       } else if (OB_FAIL(log_engine_->submit_register_parent_req(reg_dst, child_self, false))) {
         PALF_LOG(WARN, "submit_register_parent_req failed", KR(ret), K_(palf_id), K_(self), K(reg_dst));
       } else {
-        last_submit_register_req_ts_ns_ = common::ObTimeUtility::current_time_ns();  
+        last_submit_register_req_ts_ns_ = common::ObTimeUtility::current_time_ns();
       }
     } else if (REGISTER_DIFF_REGION == reg_ret) {
       const char *reason = "diff_region";

src/logservice/palf/log_config_mgr.h

@@ -421,6 +421,7 @@ private:
   LogConfigVersion persistent_config_version_;
   mutable int64_t barrier_print_log_time_;
   mutable int64_t last_check_state_ts_us_;
+  mutable int64_t check_config_print_time_;
   // ================= Config Change =================
   // ==================== Child ========================
   mutable common::ObSpinLock parent_lock_;

src/logservice/palf/log_sliding_window.cpp

@@ -69,6 +69,7 @@ LogSlidingWindow::LogSlidingWindow()
     cannot_fetch_log_warn_time_(OB_INVALID_TIMESTAMP),
     cannot_freeze_log_warn_time_(OB_INVALID_TIMESTAMP),
     larger_log_warn_time_(OB_INVALID_TIMESTAMP),
+    log_life_long_warn_time_(OB_INVALID_TIMESTAMP),
     lc_cb_get_warn_time_(OB_INVALID_TIMESTAMP),
     fetch_dst_invalid_warn_time_(OB_INVALID_TIMESTAMP),
     commit_log_handling_lease_(),
@@ -1769,8 +1770,10 @@ int LogSlidingWindow::sliding_cb(const int64_t sn, const FixedSlidingWindowSlot
       log_submit_to_slide_cost_stat_.stat(fs_cb_begin_ts - log_submit_ts);
 
       if (log_life_time > 100 * 1000) {
-        PALF_LOG(WARN, "log_task life cost too much time", K_(palf_id), K_(self), K(log_id), KPC(log_task),
-            K(fs_cb_begin_ts), K(log_life_time));
+        if (palf_reach_time_interval(10 * 1000, log_life_long_warn_time_)) {
+          PALF_LOG(WARN, "log_task life cost too much time", K_(palf_id), K_(self), K(log_id), KPC(log_task),
+              K(fs_cb_begin_ts), K(log_life_time));
+        }
       }
 
       if (OB_FAIL(checksum_.verify_accum_checksum(log_task_header.data_checksum_,
@@ -2470,7 +2473,9 @@ int LogSlidingWindow::receive_log(const common::ObAddr &src_server,
         "start_id", get_start_id());
   } else if (OB_FAIL(guard.get_log_task(log_id, log_task))) {
     if (OB_ERR_OUT_OF_LOWER_BOUND == ret) {
-      PALF_LOG(WARN, "this log has slide out, no need receive", K(ret), K(log_id), K_(palf_id), K_(self));
+      if (REACH_TIME_INTERVAL(100 * 1000)) {
+        PALF_LOG(WARN, "this log has slide out, no need receive", K(ret), K(log_id), K_(palf_id), K_(self));
+      }
     } else {
       PALF_LOG(ERROR, "get_log_task failed", K(ret), K(log_id), K_(palf_id), K_(self), K(group_entry_header));
     }

src/logservice/palf/log_sliding_window.h

@@ -418,6 +418,7 @@ private:
   mutable int64_t cannot_fetch_log_warn_time_;
   mutable int64_t cannot_freeze_log_warn_time_;
   mutable int64_t larger_log_warn_time_;
+  mutable int64_t log_life_long_warn_time_;
   mutable int64_t lc_cb_get_warn_time_;
   mutable int64_t fetch_dst_invalid_warn_time_;
   common::ObThreadLease commit_log_handling_lease_;  // thread lease for handling committed logs

src/logservice/palf/palf_handle_impl.cpp

@@ -57,6 +57,8 @@ PalfHandleImpl::PalfHandleImpl()
     last_check_parent_child_ts_us_(OB_INVALID_TIMESTAMP),
     wait_slide_print_time_us_(OB_INVALID_TIMESTAMP),
     append_size_stat_time_us_(OB_INVALID_TIMESTAMP),
+    replace_member_print_time_us_(OB_INVALID_TIMESTAMP),
+    config_change_print_time_us_(OB_INVALID_TIMESTAMP),
     last_rebuild_lsn_(),
     last_record_append_lsn_(PALF_INITIAL_LSN_VAL),
     has_set_deleted_(false),
@@ -611,7 +613,9 @@ int PalfHandleImpl::replace_member(
     } else if (FALSE_IT(args.server_ = removed_member)) {
     } else if (FALSE_IT(args.type_ = REMOVE_MEMBER_AND_NUM)) {
     } else if (OB_FAIL(one_stage_config_change_(args, timeout_ns + begin_ts_ns - common::ObTimeUtility::current_time_ns()))) {
-      PALF_LOG(WARN, "remove_member in replace_member failed", KR(ret), K(args), KPC(this));
+      if (palf_reach_time_interval(100 * 1000, replace_member_print_time_us_)) {
+        PALF_LOG(WARN, "remove_member in replace_member failed", KR(ret), K(args), KPC(this));
+      }
     } else if (OB_FAIL(config_mgr_.get_curr_member_list(curr_member_list))) {
       PALF_LOG(WARN, "get_curr_member_list failed", KR(ret), KPC(this));
     } else {
@@ -1077,12 +1081,16 @@ int PalfHandleImpl::one_stage_config_change_(const LogConfigChangeArgs &args,
     ret = OB_INVALID_ARGUMENT;
     PALF_LOG(WARN, "invalid argument", KR(ret), KPC(this), K(args));
   } else if (OB_FAIL(can_change_config_(args, curr_proposal_id))) {
-    PALF_LOG(WARN, "not active leader, can't change member", KR(ret), KPC(this),
-        "role", state_mgr_.get_role(), "state", state_mgr_.get_state());
+    if (palf_reach_time_interval(100 * 1000, config_change_print_time_us_)) {
+      PALF_LOG(WARN, "not active leader, can't change member", KR(ret), KPC(this),
+          "role", state_mgr_.get_role(), "state", state_mgr_.get_state());
+    }
   } else if (OB_FAIL(check_args_and_generate_config_(args, is_already_finished, new_log_sync_memberlist, new_log_sync_replica_num))) {
     PALF_LOG(WARN, "check_args_and_generate_config failed", KR(ret), KPC(this), K(args));
   } else if (is_already_finished) {
-    PALF_LOG(INFO, "one_stage_config_change has already finished", K(ret), KPC(this), K(args));
+    if (palf_reach_time_interval(100 * 1000, config_change_print_time_us_)) {
+      PALF_LOG(INFO, "one_stage_config_change has already finished", K(ret), KPC(this), K(args));
+    }
   } else {
     PALF_LOG(INFO, "one_stage_config_change start", KPC(this), K(curr_proposal_id), K(args), K(timeout_ns));
     TimeoutChecker not_timeout(timeout_ns);
@@ -2445,7 +2453,9 @@ int PalfHandleImpl::receive_log(const common::ObAddr &server,
         // rewrite -4023 to 0
         ret = OB_SUCCESS;
       } else {
-        PALF_LOG(WARN, "sw_ receive_log failed", K(ret), KPC(this), K(server), K(msg_proposal_id), K(lsn));
+        if (REACH_TIME_INTERVAL(100 * 1000)) {
+          PALF_LOG(WARN, "sw_ receive_log failed", K(ret), KPC(this), K(server), K(msg_proposal_id), K(lsn));
+        }
       }
     } else {
       PALF_LOG(TRACE, "receive_log success", K(ret), KPC(this), K(server), K(msg_proposal_id), K(lsn), K(buf_len));
@@ -2486,7 +2496,9 @@ int PalfHandleImpl::receive_log(const common::ObAddr &server,
     if (OB_FAIL(ret)) {
     } else if (OB_FAIL(sw_.receive_log(server, push_log_type, prev_lsn, prev_log_proposal_id, lsn, buf,
             buf_len, false, truncate_log_info))) {
-      PALF_LOG(WARN, "sw_ receive_log failed", K(ret), KPC(this), K(server), K(msg_proposal_id), K(lsn));
+      if (REACH_TIME_INTERVAL(100 * 1000)) {
+        PALF_LOG(WARN, "sw_ receive_log failed", K(ret), KPC(this), K(server), K(msg_proposal_id), K(lsn));
+      }
     } else {
       PALF_LOG(INFO, "receive_log success", K(ret), KPC(this), K(server), K_(self), K(msg_proposal_id), K(prev_lsn),
           K(prev_log_proposal_id), K(lsn), K(truncate_log_info));

src/logservice/palf/palf_handle_impl.h

@@ -1002,6 +1002,8 @@ private:
   int64_t last_check_parent_child_ts_us_;
   int64_t wait_slide_print_time_us_;
   int64_t append_size_stat_time_us_;
+  int64_t replace_member_print_time_us_;
+  int64_t config_change_print_time_us_;
   mutable SpinLock last_rebuild_lsn_lock_;
   LSN last_rebuild_lsn_;
   LSN last_record_append_lsn_;

src/logservice/replayservice/ob_replay_status.cpp

@@ -557,7 +557,8 @@ ObReplayStatus::ObReplayStatus():
     palf_handle_(),
     fs_cb_(),
     get_log_info_debug_time_(OB_INVALID_TIMESTAMP),
-    try_wrlock_debug_time_(OB_INVALID_TIMESTAMP)
+    try_wrlock_debug_time_(OB_INVALID_TIMESTAMP),
+    check_enable_debug_time_(OB_INVALID_TIMESTAMP)
 {
 }
 
@@ -586,6 +587,7 @@ int ObReplayStatus::init(const share::ObLSID &id,
     ls_id_ = id;
     get_log_info_debug_time_ = OB_INVALID_TIMESTAMP;
     try_wrlock_debug_time_ = OB_INVALID_TIMESTAMP;
+    check_enable_debug_time_ = OB_INVALID_TIMESTAMP;
     palf_env_ = palf_env;
     rp_sv_ = rp_sv;
     fs_cb_ = ObReplayFsCb(this);
@@ -634,6 +636,7 @@ void ObReplayStatus::destroy()
     fs_cb_.destroy();
     get_log_info_debug_time_ = OB_INVALID_TIMESTAMP;
     try_wrlock_debug_time_ = OB_INVALID_TIMESTAMP;
+    check_enable_debug_time_ = OB_INVALID_TIMESTAMP;
     palf_env_ = NULL;
     rp_sv_ = NULL;
   }
@@ -872,7 +875,9 @@ int ObReplayStatus::update_end_offset(const LSN &lsn)
     ret = OB_NOT_INIT;
     CLOG_LOG(ERROR, "replay status is not init", K(ls_id_), K(lsn), K(ret));
   } else if (!is_enabled_) {
-    CLOG_LOG(INFO, "replay status is not enabled", K(this), K(ret), K(lsn));
+    if (palf_reach_time_interval(100 * 1000, check_enable_debug_time_)) {
+      CLOG_LOG(INFO, "replay status is not enabled", K(this), K(ret), K(lsn));
+    }
   } else if (OB_UNLIKELY(!lsn.is_valid())) {
     ret = OB_INVALID_ARGUMENT;
     CLOG_LOG(ERROR, "invalid arguments", K(ls_id_), K(lsn), K(ret));

src/logservice/replayservice/ob_replay_status.h

@@ -598,6 +598,7 @@ private:
   ObReplayFsCb fs_cb_;
   mutable int64_t get_log_info_debug_time_;
   mutable int64_t try_wrlock_debug_time_;
+  mutable int64_t check_enable_debug_time_;
   DISALLOW_COPY_AND_ASSIGN(ObReplayStatus);
 };