diff --git a/src/storage/tx/ob_dup_table_base.cpp b/src/storage/tx/ob_dup_table_base.cpp index 0205294a9..db2fb4fc0 100755 --- a/src/storage/tx/ob_dup_table_base.cpp +++ b/src/storage/tx/ob_dup_table_base.cpp @@ -573,12 +573,12 @@ int ObDupTableLogOperator::submit_log_entry() K(type_array), K(logging_lease_addrs_), K(logging_tablet_set_ids_), K(logging_scn_), K(logging_lsn_)); } else { - DUP_TABLE_LOG(INFO, "submit log entry successfully", K(ret), K(ls_id_), K(max_ser_size), + DUP_TABLE_LOG(DEBUG, "submit log entry successfully", K(ret), K(ls_id_), K(max_ser_size), K(type_array), K(logging_lease_addrs_), K(logging_tablet_set_ids_), K(logging_scn_), K(logging_lsn_)); } } else { - DUP_TABLE_LOG(INFO, "no need submit log entry", K(ret), K(ls_id_), K(max_ser_size), + DUP_TABLE_LOG(DEBUG, "no need submit log entry", K(ret), K(ls_id_), K(max_ser_size), K(type_array)); } @@ -694,12 +694,13 @@ int ObDupTableLogOperator::on_failure() LOG_OPERATOR_INIT_CHECK if (OB_SUCC(ret)) { + int64_t start_sync_time =ObTimeUtility::fast_current_time(); if (OB_FAIL(lease_mgr_ptr_->lease_log_synced(false /*sync_result*/, logging_scn_, false /*for_replay*/, logging_lease_addrs_))) { DUP_TABLE_LOG(WARN, "lease mgr on_success failed", K(ret)); } else if (OB_FAIL(tablet_mgr_ptr_->tablet_log_synced( false /*sync_result*/, logging_scn_, false /*for_replay*/, - logging_tablet_set_ids_, modify_readable))) { + logging_tablet_set_ids_, modify_readable, start_sync_time))) { DUP_TABLE_LOG(ERROR, "tablets mgr on_failure failed", K(ret), K(logging_scn_), K(logging_lease_addrs_), K(logging_tablet_set_ids_), K(modify_readable)); } else { @@ -739,8 +740,7 @@ int ObDupTableLogOperator::sync_log_succ_(const bool for_replay) bool modify_readable = false; bool contain_all_readable = false; int64_t logging_readable_cnt = 0; - const int64_t all_readable_set_cnt - = tablet_mgr_ptr_->get_readable_tablet_set_count(); + const int64_t all_readable_set_cnt = tablet_mgr_ptr_->get_readable_tablet_set_count(); ObDupTableLSCheckpoint::ObLSDupTableMeta tmp_dup_ls_meta; if (OB_SUCC(ret)) { @@ -764,26 +764,52 @@ int ObDupTableLogOperator::sync_log_succ_(const bool for_replay) } } + int64_t start_sync_time = ObTimeUtility::fast_current_time(); + int64_t lease_log_sync_cost_time, tablet_log_sync_cost_time, ckpt_update_cost_time; + lease_log_sync_cost_time = tablet_log_sync_cost_time = ckpt_update_cost_time = start_sync_time; + if (OB_SUCC(ret)) { if (OB_FAIL(lease_mgr_ptr_->lease_log_synced( true /*sync_result*/, logging_scn_, for_replay /*for_replay*/, logging_lease_addrs_))) { DUP_TABLE_LOG(WARN, "apply lease_log failed", K(ret), K(logging_scn_), K(logging_lease_addrs_)); + } else if (OB_FALSE_IT(lease_log_sync_cost_time = + ObTimeUtility::fast_current_time() - start_sync_time)) { + } else if (OB_FAIL(tablet_mgr_ptr_->tablet_log_synced( true /*sync_result*/, logging_scn_, for_replay /*for_replay*/, - logging_tablet_set_ids_, modify_readable))) { + logging_tablet_set_ids_, modify_readable, start_sync_time))) { DUP_TABLE_LOG(WARN, "apply tablet_log failed", K(ret), K(logging_scn_), K(logging_tablet_set_ids_)); + } else if (OB_FALSE_IT(tablet_log_sync_cost_time = ObTimeUtility::fast_current_time() + - start_sync_time + - lease_log_sync_cost_time)) { + } else if (OB_FAIL(dup_ls_ckpt_->update_ckpt_after_lease_log_synced( logging_lease_addrs_, logging_scn_, modify_readable /*modify_readable_sets*/, contain_all_readable /*contain_all_readable*/, for_replay /*for_replay*/))) { DUP_TABLE_LOG(WARN, "update lease log ckpt failed", K(ret), KPC(dup_ls_ckpt_)); + } else if (OB_FALSE_IT(ckpt_update_cost_time = ObTimeUtility::fast_current_time() + - start_sync_time - lease_log_sync_cost_time + - tablet_log_sync_cost_time)) { } else { reuse(); } } + if (lease_log_sync_cost_time + tablet_log_sync_cost_time + ckpt_update_cost_time > 500 * 1000) { + DUP_TABLE_LOG(INFO, "sync log succ cost too much time", K(ret), K(logging_scn_), + K(logging_lease_addrs_.count()), K(logging_tablet_set_ids_.count()), K(stat_log_), + K(start_sync_time), K(lease_log_sync_cost_time), K(tablet_log_sync_cost_time), + K(ckpt_update_cost_time)); + } + + if (OB_NOT_NULL(interface_stat_ptr_)) { + interface_stat_ptr_->dup_table_lease_log_sync_total_time_ += lease_log_sync_cost_time; + interface_stat_ptr_->dup_table_tablet_log_sync_total_time_ += tablet_log_sync_cost_time; + } + return ret; } @@ -838,7 +864,7 @@ int ObDupTableLogOperator::prepare_serialize_log_entry_(int64_t &max_ser_size, if (OB_FALSE_IT(max_ser_size += max_stat_log.get_serialize_size())) { // do nothing } else if (max_ser_size > 0 - && OB_FAIL(type_array.push_back(DupTableLogEntryType::DuptableStatLog))) { + && OB_FAIL(type_array.push_back(DupTableLogEntryType::DupTableStatLog))) { DUP_TABLE_LOG(WARN, "push back log entry_type failed", K(ret)); } } @@ -848,6 +874,7 @@ int ObDupTableLogOperator::prepare_serialize_log_entry_(int64_t &max_ser_size, tmp_entry_header.entry_type_ = DupTableLogEntryType::MAX; int64_t entry_log_size = 0; + //depend on the size of type_array int64_t entry_header_size = type_array.count() * (tmp_entry_header.get_serialize_size() + serialization::encoded_length_i64(entry_log_size)); @@ -878,7 +905,7 @@ int ObDupTableLogOperator::serialize_log_entry_(const int64_t max_ser_size, const DupTableLogEntryType &entry_type = type_array[i]; if (entry_type != DupTableLogEntryType::LeaseListLog && entry_type != DupTableLogEntryType::TabletChangeLog - && entry_type != DupTableLogEntryType::DuptableStatLog) { + && entry_type != DupTableLogEntryType::DupTableStatLog) { ret = OB_INVALID_ARGUMENT; DUP_TABLE_LOG(WARN, "invalid arguments", K(ret), K(entry_type)); } else { @@ -910,7 +937,7 @@ int ObDupTableLogOperator::serialize_log_entry_(const int64_t max_ser_size, } break; } - case DupTableLogEntryType::DuptableStatLog: { + case DupTableLogEntryType::DupTableStatLog: { DupTableStatLog stat_log; stat_log.lease_addr_cnt_ = logging_lease_addrs_.count(); stat_log.leader_readable_cnt_ = tablet_mgr_ptr_->get_readable_tablet_set_count(); @@ -953,6 +980,8 @@ int ObDupTableLogOperator::deserialize_log_entry_() { int ret = OB_SUCCESS; + common::ObTimeGuard timeguard("deserialize_log_entry", 500 * 1000); + int64_t data_pos = 0; data_pos = big_segment_buf_.get_deserialize_buf_pos(); @@ -994,7 +1023,7 @@ int ObDupTableLogOperator::deserialize_log_entry_() } break; } - case DupTableLogEntryType::DuptableStatLog: { + case DupTableLogEntryType::DupTableStatLog: { if (OB_FAIL(stat_log_.deserialize(big_segment_buf_.get_deserialize_buf(), data_pos + log_entry_size, data_pos))) { DUP_TABLE_LOG(WARN, "deserialize stat log failed", K(ret), K(data_pos)); @@ -1008,9 +1037,11 @@ int ObDupTableLogOperator::deserialize_log_entry_() } } + timeguard.click(get_entry_type_str(entry_header.entry_type_)); if (OB_SUCC(ret) && data_pos < after_header_pos + log_entry_size) { - DUP_TABLE_LOG(INFO, "try to deserialize a new version dup_table log in older observer", K(ret), K(data_pos), - K(after_header_pos), K(log_entry_size), K(entry_header)); + DUP_TABLE_LOG(INFO, "try to deserialize a new version dup_table log in older observer", + K(ret), K(data_pos), K(segment_buf_len), K(after_header_pos), + K(log_entry_size), K(entry_header)); data_pos = after_header_pos + log_entry_size; } } @@ -1021,10 +1052,16 @@ int ObDupTableLogOperator::deserialize_log_entry_() DUP_TABLE_LOG(WARN, "set deserialize pos failed", K(ret), K(after_header_pos), K(log_entry_size), K(big_segment_buf_)); } - DUP_TABLE_LOG(DEBUG, "deser log succ", K(ret), K(data_pos), K(after_header_pos), - K(log_entry_size)); - } else { - DUP_TABLE_LOG(WARN, "deser log failed", K(ret), K(data_pos)); + } + + int64_t time_diff = timeguard.get_diff(); + if (time_diff > 500 * 1000) { + DUP_TABLE_LOG(INFO, "deserialize dup table log entry cost too much time", K(ret), + K(logging_scn_), K(logging_lease_addrs_.count()), + K(logging_tablet_set_ids_.count()), K(stat_log_), K(timeguard)); + } + if (OB_NOT_NULL(interface_stat_ptr_)) { + interface_stat_ptr_->dup_table_log_deser_total_time_ += time_diff; } return ret; @@ -1074,6 +1111,11 @@ int ObDupTableLogOperator::retry_submit_log_block_() } else if (OB_FAIL(log_handler_->append(block_buf_, block_buf_pos, gts_base_scn, false, this, logging_lsn_, logging_scn_))) { DUP_TABLE_LOG(WARN, "append block failed", K(ret), K(ls_id_)); + } else { + if (OB_NOT_NULL(interface_stat_ptr_)) { + interface_stat_ptr_->dup_table_log_entry_cnt_ += 1; + interface_stat_ptr_->dup_table_log_entry_total_size_ += block_buf_pos; + } } } diff --git a/src/storage/tx/ob_dup_table_base.h b/src/storage/tx/ob_dup_table_base.h index da034cae9..0a1216c30 100644 --- a/src/storage/tx/ob_dup_table_base.h +++ b/src/storage/tx/ob_dup_table_base.h @@ -68,27 +68,54 @@ struct DupTableInterfaceStat int64_t dup_table_follower_read_tablet_not_exist_cnt_; int64_t dup_table_follower_read_tablet_not_ready_cnt_; int64_t dup_table_follower_read_lease_expired_cnt_; + int64_t dup_table_redo_sync_succ_cnt_; int64_t dup_table_redo_sync_fail_cnt_; + int64_t dup_table_log_entry_cnt_; + int64_t dup_table_log_entry_total_size_; + + int64_t dup_table_log_replay_total_time_; + int64_t dup_table_log_deser_total_time_; + int64_t dup_table_lease_log_sync_total_time_; + int64_t dup_table_tablet_log_sync_total_time_; + void reset() { dup_table_follower_read_succ_cnt_ = 0; dup_table_follower_read_tablet_not_exist_cnt_ = 0; dup_table_follower_read_tablet_not_ready_cnt_ = 0; dup_table_follower_read_lease_expired_cnt_ = 0; + dup_table_redo_sync_succ_cnt_ = 0; dup_table_redo_sync_fail_cnt_ = 0; + + dup_table_log_entry_cnt_ = 0; + dup_table_log_entry_total_size_ = 0; + + dup_table_log_replay_total_time_ = 0; + dup_table_log_deser_total_time_ = 0; + dup_table_lease_log_sync_total_time_ = 0; + dup_table_tablet_log_sync_total_time_ = 0; } TO_STRING_KV(K(dup_table_follower_read_succ_cnt_), K(dup_table_follower_read_tablet_not_exist_cnt_), - K(dup_table_follower_read_lease_expired_cnt_), + K(dup_table_follower_read_tablet_not_ready_cnt_), K(dup_table_follower_read_lease_expired_cnt_), K(dup_table_redo_sync_succ_cnt_), - K(dup_table_redo_sync_fail_cnt_)); + K(dup_table_redo_sync_fail_cnt_), + K(dup_table_log_entry_cnt_), + K(dup_table_log_entry_total_size_), + K(dup_table_log_replay_total_time_), + K(dup_table_log_deser_total_time_), + K(dup_table_lease_log_sync_total_time_), + K(dup_table_tablet_log_sync_total_time_)); }; +#define DUP_LEASE_LIFE_PREFIX "[DupLeaseLife] " +#define DUP_TABLET_LIFE_PREFIX "[DupTabletLife] " + /******************************************************* * Dup_Table LS Role State *******************************************************/ @@ -881,10 +908,36 @@ enum class DupTableLogEntryType { TabletChangeLog = 1, LeaseListLog, - DuptableStatLog, + DupTableStatLog, MAX + }; +static const char *get_entry_type_str(const DupTableLogEntryType &entry_type) +{ + const char *entry_str = nullptr; + switch (entry_type) { + case DupTableLogEntryType::TabletChangeLog: { + entry_str = "DupTabletLog"; + break; + } + case DupTableLogEntryType::LeaseListLog: { + entry_str = "DupLeaseLog"; + break; + } + + case DupTableLogEntryType::DupTableStatLog: { + entry_str = "DupStatLog"; + break; + } + default: { + entry_str = "UNKNOWN entry type"; + break; + } + } + return entry_str; +} + typedef common::ObSEArray DupLogTypeArray; // record log entry size after log entry header by int64_t @@ -928,9 +981,10 @@ public: logservice::ObLogHandler *log_handler, ObDupTableLSCheckpoint *dup_ls_ckpt, ObDupTableLSLeaseMgr *lease_mgr, - ObLSDupTabletsMgr *tablets_mgr) + ObLSDupTabletsMgr *tablets_mgr, + DupTableInterfaceStat *interface_stat) : ls_id_(ls_id), block_buf_(nullptr), log_handler_(log_handler), dup_ls_ckpt_(dup_ls_ckpt), - lease_mgr_ptr_(lease_mgr), tablet_mgr_ptr_(tablets_mgr) + lease_mgr_ptr_(lease_mgr), tablet_mgr_ptr_(tablets_mgr), interface_stat_ptr_(interface_stat) { reset(); } @@ -968,8 +1022,8 @@ public: K(logging_lsn_)); private: - static const int64_t MAX_LOG_BLOCK_SIZE ; - static const int64_t RESERVED_LOG_HEADER_SIZE ; //100 Byte + static const int64_t MAX_LOG_BLOCK_SIZE; + static const int64_t RESERVED_LOG_HEADER_SIZE; // 100 Byte int prepare_serialize_log_entry_(int64_t &max_ser_size, DupLogTypeArray &type_array); int serialize_log_entry_(const int64_t max_ser_size, const DupLogTypeArray &type_array); int deserialize_log_entry_(); @@ -979,13 +1033,13 @@ private: private: void after_submit_log(const bool submit_result, const bool for_replay); - #define LOG_OPERATOR_INIT_CHECK \ if (OB_SUCC(ret)) { \ - if (OB_ISNULL(log_handler_) || OB_ISNULL(lease_mgr_ptr_) || OB_ISNULL(tablet_mgr_ptr_)) { \ + if (OB_ISNULL(log_handler_) || OB_ISNULL(lease_mgr_ptr_) || OB_ISNULL(tablet_mgr_ptr_) \ + || OB_ISNULL(interface_stat_ptr_)) { \ ret = OB_NOT_INIT; \ DUP_TABLE_LOG(ERROR, "invalid log operator", K(ret), KP(log_handler_), KP(lease_mgr_ptr_), \ - KP(tablet_mgr_ptr_)); \ + KP(tablet_mgr_ptr_), KP(interface_stat_ptr_)); \ } \ } @@ -1006,6 +1060,8 @@ private: ObDupTableLSLeaseMgr *lease_mgr_ptr_; ObLSDupTabletsMgr *tablet_mgr_ptr_; + DupTableInterfaceStat *interface_stat_ptr_; + DupTabletSetIDArray logging_tablet_set_ids_; DupTableLeaseItemArray logging_lease_addrs_; @@ -1028,7 +1084,6 @@ private: uint64_t log_entry_count_; uint64_t total_log_entry_wait_time_; }; - /******************************************************* * Dup_Table Msg *******************************************************/ diff --git a/src/storage/tx/ob_dup_table_dump.cpp b/src/storage/tx/ob_dup_table_dump.cpp index 4c586baa1..a25d1108d 100644 --- a/src/storage/tx/ob_dup_table_dump.cpp +++ b/src/storage/tx/ob_dup_table_dump.cpp @@ -129,7 +129,7 @@ int ObDupTableLogDumpIterator::dump_dup_table_log() } break; } - case DupTableLogEntryType::DuptableStatLog: { + case DupTableLogEntryType::DupTableStatLog: { if (OB_FAIL(iter_stat_log_(deser_pos + log_entry_size, deser_pos))) { DUP_TABLE_LOG(WARN, "iter dup table stat log failed", K(ret), K(deser_pos), K(log_entry_size)); diff --git a/src/storage/tx/ob_dup_table_lease.cpp b/src/storage/tx/ob_dup_table_lease.cpp index 4bf711ef9..982c5ffb9 100644 --- a/src/storage/tx/ob_dup_table_lease.cpp +++ b/src/storage/tx/ob_dup_table_lease.cpp @@ -86,7 +86,7 @@ int ObDupTableLSLeaseMgr::recive_lease_request(const ObDupTableLeaseRequest &lea if (OB_HASH_NOT_EXIST != ret) { DUP_TABLE_LOG(WARN, "get from lease_req_cache_ failed", K(ret), K(lease_req)); } else { - DUP_TABLE_LOG(INFO, "first lease request from new dup_table follower", K(ret), K(lease_req)); + DUP_TABLE_LOG(INFO, "first lease request from the new dup_table follower", K(ret), K(lease_req)); } } else if (tmp_lease_info.cache_lease_req_.is_ready()) { DUP_TABLE_LOG(INFO, "leader lease info is logging which can not recive new lease request", @@ -105,7 +105,7 @@ int ObDupTableLSLeaseMgr::recive_lease_request(const ObDupTableLeaseRequest &lea } } - DUP_TABLE_LOG(INFO, "cache lease request", K(ret), K(leader_lease_map_.size()), K(lease_req), + DUP_TABLE_LOG(DEBUG, "cache lease request", K(ret), K(leader_lease_map_.size()), K(lease_req), K(tmp_lease_info)); return ret; } @@ -135,19 +135,22 @@ int ObDupTableLSLeaseMgr::prepare_serialize(int64_t &max_ser_size, if (OB_FAIL(hash_for_each_remove(tmp_addr, leader_lease_map_, req_handler))) { DUP_TABLE_LOG(WARN, "handle lease requests failed", K(ret)); } + + if (OB_SUCC(ret) && req_handler.get_renew_lease_count() > 0) { + DUP_TABLE_LOG(DEBUG, "renew lease list in the log", K(ret), K(req_handler), + K(lease_header_array), K(max_ser_size), K(loop_start_time), + K(last_lease_req_cache_handle_time_)); + } else if (OB_SUCC(ret) && req_handler.get_renew_lease_count() == 0) { + req_handler.clear_ser_content(); + } + if (req_handler.get_error_ret() != OB_SUCCESS) { - lease_header_array.reuse(); + req_handler.clear_ser_content(); ret = req_handler.get_error_ret(); } else { max_ser_size += req_handler.get_max_ser_size(); } - if (OB_SUCC(ret) && req_handler.get_renew_lease_count() > 0) { - DUP_TABLE_LOG(INFO, "renew lease list in the log", K(ret), K(req_handler), - K(lease_header_array), K(max_ser_size), K(loop_start_time), - K(last_lease_req_cache_handle_time_)); - } - if (OB_SUCC(ret) && req_handler.get_max_ser_size() > 0) { last_lease_req_cache_handle_time_ = loop_start_time; } @@ -233,6 +236,10 @@ int ObDupTableLSLeaseMgr::deserialize_lease_log(DupTableLeaseItemArray &lease_he } } } + + if (OB_SUCC(ret)) { + pos = tmp_pos; + } } return ret; } @@ -292,6 +299,11 @@ int ObDupTableLSLeaseMgr::lease_log_synced(const bool sync_result, // reset req cache to invalid state leader_lease_ptr->cache_lease_req_.set_invalid(); } + if (!for_replay) { + DUP_TABLE_LOG( + INFO, DUP_LEASE_LIFE_PREFIX "update lease expired ts in the leader_lease_map", + K(ret), K(lease_log_scn), K(for_replay), K(lease_owner), KPC(leader_lease_ptr)); + } } } else { // if log sync failed, allow renew lease req @@ -314,36 +326,6 @@ int ObDupTableLSLeaseMgr::lease_log_synced(const bool sync_result, return ret; } -// int ObDupTableLSLeaseMgr::log_cb_success() -// { -// int ret = OB_SUCCESS; -// SpinWLockGuard guard(lease_lock_); -// -// const bool is_success = true; -// LeaseDurableHandler durable_handler(is_success); -// -// if (OB_FAIL(hash_for_each_update(leader_lease_map_, durable_handler))) { -// DUP_TABLE_LOG(WARN, "update durable lease info", K(ret), K(is_success)); -// } -// -// return ret; -// } -// -// int ObDupTableLSLeaseMgr::log_cb_failure() -// { -// int ret = OB_SUCCESS; -// SpinWLockGuard guard(lease_lock_); -// -// const bool is_success = false; -// LeaseDurableHandler durable_handler(is_success); -// -// if (OB_FAIL(hash_for_each_update(leader_lease_map_, durable_handler))) { -// DUP_TABLE_LOG(WARN, "update durable lease info", K(ret), K(is_success)); -// } -// -// return ret; -// } - bool ObDupTableLSLeaseMgr::can_grant_lease_(const common::ObAddr &addr, const share::SCN &local_max_applyed_scn, const DupTableLeaderLeaseInfo &lease_info) @@ -355,12 +337,14 @@ bool ObDupTableLSLeaseMgr::can_grant_lease_(const common::ObAddr &addr, DupTableTsInfo cache_ts_info; if (OB_FAIL(dup_ls_handle_ptr_->get_cache_ts_info(addr, cache_ts_info))) { lease_success = false; - DUP_TABLE_LOG(WARN, "Not allowed to acquire lease - get cache ts info failed", K(ret), K(ls_id), - K(addr), K(cache_ts_info), K(local_max_applyed_scn), K(lease_info)); + DUP_TABLE_LOG( + WARN, DUP_LEASE_LIFE_PREFIX "Not allowed to acquire lease - get cache ts info failed", + K(ret), K(ls_id), K(addr), K(cache_ts_info), K(local_max_applyed_scn), K(lease_info)); } else if (!cache_ts_info.max_replayed_scn_.is_valid() || !local_max_applyed_scn.is_valid()) { lease_success = false; - DUP_TABLE_LOG(WARN, "Not allowed to acquire lease - invalid applyed scn", K(ret), K(ls_id), - K(addr), K(cache_ts_info), K(local_max_applyed_scn), K(lease_info)); + DUP_TABLE_LOG(WARN, DUP_LEASE_LIFE_PREFIX "Not allowed to acquire lease - invalid applyed scn", + K(ret), K(ls_id), K(addr), K(cache_ts_info), K(local_max_applyed_scn), + K(lease_info)); } else { uint64_t local_max_applied_ts = local_max_applyed_scn.get_val_for_gts(); @@ -370,12 +354,18 @@ bool ObDupTableLSLeaseMgr::can_grant_lease_(const common::ObAddr &addr, if (local_max_applied_ts > follower_replayed_ts && local_max_applied_ts - follower_replayed_ts >= MAX_APPLIED_SCN_INTERVAL) { lease_success = false; - DUP_TABLE_LOG(WARN, "Not allowed to acquire lease - slow replay", K(ret), K(ls_id), K(addr), - K(local_max_applied_ts), K(follower_replayed_ts), + DUP_TABLE_LOG(WARN, DUP_LEASE_LIFE_PREFIX "Not allowed to acquire lease - slow replay", + K(ret), K(ls_id), K(addr), K(local_max_applied_ts), K(follower_replayed_ts), K(local_max_applied_ts - follower_replayed_ts), K(MAX_APPLIED_SCN_INTERVAL), K(cache_ts_info), K(lease_info)); } } + + if (lease_success) { + DUP_TABLE_LOG(INFO, DUP_LEASE_LIFE_PREFIX "Lease will be granted to the follower", K(ret), + K(addr), K(local_max_applyed_scn), K(lease_info), K(cache_ts_info)); + } + return lease_success; } @@ -449,7 +439,7 @@ int ObDupTableLSLeaseMgr::follower_handle() DUP_TABLE_LOG(WARN, "post lease request failed", K(ret), K(leader_addr)); } else { last_lease_req_post_time_ = loop_start_time; - DUP_TABLE_LOG(INFO, "post lease request success", K(ret), K(leader_addr), K(req), + DUP_TABLE_LOG(DEBUG, "post lease request success", K(ret), K(leader_addr), K(req), K(cur_ls_id)); } } @@ -500,8 +490,9 @@ int ObDupTableLSLeaseMgr::follower_try_acquire_lease(const share::SCN &lease_log follower_lease_info_.durable_lease_.request_ts_ + follower_lease_info_.durable_lease_.lease_interval_us_; - DUP_TABLE_LOG(INFO, "The follower can get new lease from this lease log", K(ret), K(ls_id), - K(lease_log_scn), K(self_addr), K(acquire_new_lease), K(follower_lease_info_)); + DUP_TABLE_LOG( + INFO, DUP_LEASE_LIFE_PREFIX "The follower can get new lease from this lease log", K(ret), + K(ls_id), K(lease_log_scn), K(self_addr), K(acquire_new_lease), K(follower_lease_info_)); } else { DUP_TABLE_LOG(DEBUG, "No new lease in this lease log", K(ret), K(ls_id), K(lease_log_scn), K(self_addr), K(follower_lease_info_)); @@ -785,33 +776,6 @@ bool ObDupTableLSLeaseMgr::LeaseReqCacheHandler::operator()( return will_remove; } -// int ObDupTableLSLeaseMgr::LeaseDurableHandler::operator()( -// common::hash::HashMapPair &hash_pair) -// { -// int ret = OB_SUCCESS; -// -// if (hash_pair.second.cache_lease_req_.is_ready()) { -// if (is_success_) { -// // set durable lease info -// hash_pair.second.confirmed_lease_info_.request_ts_ = -// hash_pair.second.cache_lease_req_.request_ts_; -// -// hash_pair.second.confirmed_lease_info_.lease_interval_us_ = -// hash_pair.second.cache_lease_req_.lease_interval_us_; -// -// hash_pair.second.lease_expired_ts_ = -// hash_pair.second.cache_lease_req_.lease_acquire_ts_ -// + hash_pair.second.cache_lease_req_.lease_interval_us_; -// } -// hash_pair.second.cache_lease_req_.reset(); -// // avoid serializing older lease request than previous log -// hash_pair.second.cache_lease_req_.request_ts_ = -// hash_pair.second.confirmed_lease_info_.request_ts_; -// } -// -// return ret; -// } - int ObDupTableLSLeaseMgr::GetLeaseValidAddrFunctor::operator()( common::hash::HashMapPair &hash_pair) { @@ -966,158 +930,5 @@ int ObDupTableLSLeaseMgr::LeaderLeaseMgrStatFunctor::operator()( return ret; } -// OB_DEF_SERIALIZE(DupTableLeaderLeaseInfo) -// { -// int ret = OB_SUCCESS; -// int64_t tmp_pos = pos; -// -// int64_t tmp_request_ts_ = 0; -// int64_t tmp_lease_interval = 0; -// -// if (cache_lease_req_.is_ready()) { -// tmp_request_ts_ = cache_lease_req_.request_ts_; -// tmp_lease_interval = cache_lease_req_.lease_interval_us_; -// } else { -// tmp_request_ts_ = confirmed_lease_info_.request_ts_; -// tmp_lease_interval = confirmed_lease_info_.lease_interval_us_; -// } -// -// if (OB_FAIL(common::serialization::encode(buf, buf_len, tmp_pos, tmp_request_ts_))) { -// DUP_TABLE_LOG(WARN, "encode request_ts failed", K(ret)); -// } else if (OB_FAIL(common::serialization::encode(buf, buf_len, tmp_pos, tmp_lease_interval))) { -// DUP_TABLE_LOG(WARN, "encode lease_interval failed", K(ret)); -// } else { -// pos = tmp_pos; -// } -// -// return ret; -// } -// -// OB_DEF_DESERIALIZE(DupTableLeaderLeaseInfo) -// { -// int ret = OB_SUCCESS; -// int64_t tmp_pos = pos; -// -// if (OB_FAIL(common::serialization::decode(buf, data_len, tmp_pos, -// confirmed_lease_info_.request_ts_))) { -// DUP_TABLE_LOG(WARN, "decode request_ts failed", K(ret)); -// } else if (OB_FAIL(common::serialization::decode(buf, data_len, tmp_pos, -// confirmed_lease_info_.lease_interval_us_))) { -// DUP_TABLE_LOG(WARN, "decode lease_interval failed", K(ret)); -// } else { -// cache_lease_req_.request_ts_ = confirmed_lease_info_.request_ts_; -// pos = tmp_pos; -// } -// -// return ret; -// } -// -// OB_DEF_SERIALIZE_SIZE(DupTableLeaderLeaseInfo) -// { -// int64_t total_length = 0; -// -// int64_t tmp_request_ts_ = 0; -// int64_t tmp_lease_interval = 0; -// -// if (cache_lease_req_.is_ready()) { -// tmp_request_ts_ = cache_lease_req_.request_ts_; -// tmp_lease_interval = cache_lease_req_.lease_interval_us_; -// } else { -// tmp_request_ts_ = confirmed_lease_info_.request_ts_; -// tmp_lease_interval = confirmed_lease_info_.lease_interval_us_; -// } -// -// total_length += common::serialization::encoded_length(tmp_request_ts_); -// total_length += common::serialization::encoded_length(tmp_lease_interval); -// -// return total_length; -// } - -// int ObDupTableLSLeaseMgr::LeaderLeaseInfoSerCallBack::operator()( -// const common::hash::HashMapPair &hash_pair) -// { -// int ret = OB_SUCCESS; -// -// if (OB_FAIL(hash_pair.first.serialize(buf_, buf_len_, pos_))) { -// DUP_TABLE_LOG(WARN, "serialize key(addr) failed", K(ret), K(hash_pair.first)); -// } else if (OB_FAIL(hash_pair.second.serialize(buf_, buf_len_, pos_))) { -// DUP_TABLE_LOG(WARN, "serialize val(leader_lease_info) failed", K(ret), K(hash_pair.first)); -// } -// -// return ret; -// } -// -// int ObDupTableLSLeaseMgr::LeaderLeaseInfoDeSerCallBack::operator()( -// DupTableLeaderLeaseMap &lease_map) -// { -// int ret = OB_SUCCESS; -// -// common::ObAddr lease_addr; -// DupTableLeaderLeaseInfo lease_info; -// -// if (OB_FAIL(lease_addr.deserialize(buf_, buf_len_, pos_))) { -// DUP_TABLE_LOG(WARN, "deserialize key(addr) failed", K(ret), K(lease_addr)); -// } else if (OB_FAIL(lease_info.deserialize(buf_, buf_len_, pos_))) { -// DUP_TABLE_LOG(WARN, "deserialize val(leader_lease_info) failed", K(ret), K(lease_addr)); -// } else if (OB_FAIL(lease_map.set_refactored(lease_addr, lease_info, 1))) { -// DUP_TABLE_LOG(WARN, "insert into lease_map failed", K(ret)); -// } -// -// return ret; -// } -// -// int64_t ObDupTableLSLeaseMgr::LeaderLeaseInfoGetSizeCallBack::operator()( -// const common::hash::HashMapPair &hash_pair) -// { -// int64_t total_length = 0; -// total_length += hash_pair.first.get_serialize_size(); -// total_length += hash_pair.second.get_serialize_size(); -// return total_length; -// } -// -// OB_DEF_SERIALIZE(ObDupTableLSLeaseMgr) -// { -// int ret = OB_SUCCESS; -// -// SpinRLockGuard guard(lease_lock_); -// -// LeaderLeaseInfoSerCallBack ser_cb(buf, buf_len, pos); -// -// if (OB_FAIL(hash_for_each_serialize(leader_lease_map_, ser_cb))) { -// DUP_TABLE_LOG(WARN, "serialize leader_lease_map failed", K(ret)); -// } else { -// pos = ser_cb.get_pos(); -// } -// return ret; -// } -// -// OB_DEF_DESERIALIZE(ObDupTableLSLeaseMgr) -// { -// int ret = OB_SUCCESS; -// SpinWLockGuard guard(lease_lock_); -// -// LeaderLeaseInfoDeSerCallBack deser_cb(buf, data_len, pos); -// -// if (OB_FAIL(leader_lease_map_.clear())) { -// DUP_TABLE_LOG(WARN, "clear leader_lease_map_ failed", K(ret)); -// } else if (OB_FAIL(hash_for_each_deserialize(leader_lease_map_, deser_cb))) { -// DUP_TABLE_LOG(WARN, "serialize leader_lease_map failed", K(ret)); -// } else { -// pos = deser_cb.get_pos(); -// } -// return ret; -// } -// -// OB_DEF_SERIALIZE_SIZE(ObDupTableLSLeaseMgr) -// { -// int64_t serialize_size = 0; -// SpinRLockGuard guard(lease_lock_); -// -// LeaderLeaseInfoGetSizeCallBack get_size_cb; -// serialize_size += hash_for_each_serialize_size(leader_lease_map_, get_size_cb); -// -// return serialize_size; -// } - } // namespace transaction } // namespace oceanbase diff --git a/src/storage/tx/ob_dup_table_lease.h b/src/storage/tx/ob_dup_table_lease.h index beb4d6fa6..3ae233386 100644 --- a/src/storage/tx/ob_dup_table_lease.h +++ b/src/storage/tx/ob_dup_table_lease.h @@ -143,6 +143,12 @@ private: int get_error_ret() { return error_ret; } int64_t get_renew_lease_count() { return renew_lease_count_; } + void clear_ser_content() + { + lease_item_array_.reuse(); + max_ser_size_ = 0; + } + TO_STRING_KV(K(renew_lease_count_), K(max_ser_size_), K(loop_start_time_), diff --git a/src/storage/tx/ob_dup_table_tablets.cpp b/src/storage/tx/ob_dup_table_tablets.cpp index f0f478f22..3eb1664e2 100644 --- a/src/storage/tx/ob_dup_table_tablets.cpp +++ b/src/storage/tx/ob_dup_table_tablets.cpp @@ -461,6 +461,8 @@ void ObLSDupTabletsMgr::reset() gc_start_time_ = 0; readable_set_in_gc_ = nullptr; + last_readable_sync_succ_time_ = 0; + if (OB_NOT_NULL(tablet_set_diag_info_log_buf_)) { ob_free(tablet_set_diag_info_log_buf_); } @@ -704,7 +706,7 @@ int ObLSDupTabletsMgr::search_dup_tablet_for_read(const common::ObTabletID &tabl ERRSIM_POINT_DEF(ERRSIM_DUP_TABLE_GC_RIGHT_NOW); // for gc those not refreshed tablets -int ObLSDupTabletsMgr::gc_dup_tablets(const int64_t gc_ts, const int64_t max_task_interval) +int ObLSDupTabletsMgr::gc_tmporary_dup_tablets(const int64_t gc_ts, const int64_t max_task_interval) { int ret = OB_SUCCESS; SpinWLockGuard guard(dup_tablets_lock_); @@ -733,7 +735,13 @@ int ObLSDupTabletsMgr::gc_dup_tablets(const int64_t gc_ts, const int64_t max_tas int64_t gc_timeout = 0; if ((gc_ts - last_gc_succ_time_) > GC_DUP_TABLETS_FAILED_TIMEOUT && last_gc_succ_time_ != 0) { gc_timeout = INT64_MAX; - DUP_TABLE_LOG(WARN, "gc failed too much times, this time should not break"); + DUP_TABLE_LOG(WARN, + "gc failed too much times, this time should not break", + K(ret), + K(gc_timeout), + K(GC_DUP_TABLETS_FAILED_TIMEOUT), + K(gc_ts), + K(last_gc_succ_time_)); } else { gc_timeout = GC_TIMEOUT; } @@ -903,9 +911,12 @@ int ObLSDupTabletsMgr::scan_readable_set_for_gc() } else { return_tablet_set_(removing_old_set_); } - DUP_TABLE_LOG(DEBUG, "finish scan readable set", K(ret), K(gc_handler.get_gc_tablet_cnt()), - KPC(removing_old_set_), KPC(tmp_readable_gc_set_ptr), K(new_round), - K(gc_start_time_)); + if (gc_handler.get_gc_tablet_cnt() > 0) { + DUP_TABLE_LOG(INFO, DUP_TABLET_LIFE_PREFIX "scan a readable set for GC", K(ret), + K(gc_handler.get_gc_tablet_cnt()), KPC(removing_old_set_), + KPC(tmp_readable_gc_set_ptr), K(new_round), K(gc_start_time_), + K(tablet_gc_window_)); + } } } @@ -953,7 +964,7 @@ int ObLSDupTabletsMgr::remove_tablet_from_readable_set_() } if (OB_SUCC(ret)) { related_readable_set->set_related_set_op_type(DupTableRelatedSetOpType::INVALID); - DUP_TABLE_LOG(INFO, "finish remove tablet from readable set", K(ret), + DUP_TABLE_LOG(INFO, DUP_TABLET_LIFE_PREFIX "finish remove tablet from readable set", K(ret), KPC(removing_old_set_), KPC(related_readable_set)); } } @@ -1110,7 +1121,6 @@ int ObLSDupTabletsMgr::prepare_serialize(int64_t &max_ser_size, SpinRLockGuard guard(dup_tablets_lock_); - // max_ser_size = 0; unique_id_array.reuse(); if (OB_SUCC(ret)) { @@ -1161,15 +1171,18 @@ int ObLSDupTabletsMgr::prepare_serialize(int64_t &max_ser_size, } else if (false == need_confirm_new_queue_.add_last(changing_new_set_)) { ret = OB_ERR_UNEXPECTED; DUP_TABLE_LOG(WARN, "push back change_new_set_ failed", K(ret)); - } else if (OB_FALSE_IT(changing_new_set_ = nullptr)) { - // do nothing + } else { + DUP_TABLE_LOG(INFO, DUP_TABLET_LIFE_PREFIX "push change_new_set_ into need_confirm_queue", + K(ret), KPC(changing_new_set_), K(need_confirm_new_queue_.get_size()), + K(max_ser_size), K(unique_id_array.count())); + changing_new_set_ = nullptr; } } if (OB_SUCC(ret)) { if (max_ser_size > max_log_buf_len) { ret = OB_LOG_TOO_LARGE; - DUP_TABLE_LOG(INFO, "Too large tablet log, we will not serialize old or readable tablets", + DUP_TABLE_LOG(DEBUG, "Too large tablet log, we will not serialize old or readable tablets", K(ret), K(ls_id_), K(max_ser_size), K(max_log_buf_len), K(unique_id_array.count()), K(unique_id_array)); } @@ -1205,6 +1218,15 @@ int ObLSDupTabletsMgr::prepare_serialize(int64_t &max_ser_size, } } + if (OB_SUCC(ret) + && ObTimeUtility::fast_current_time() - ATOMIC_LOAD(&last_readable_sync_succ_time_) + <= 30 * 60 * 1000 * 1000) { + ret = OB_LOG_TOO_LARGE; + DUP_TABLE_LOG(DEBUG, + "Too many readable tablets log entry. Stop serializing readable tablet log", + K(ret), K(unique_id_array), K(max_ser_size), K(last_readable_sync_succ_time_)); + } + // TODO serialize readable tablets if (OB_SUCC(ret)) { if (readable_tablets_list_.get_size() > 200) { @@ -1226,16 +1248,18 @@ int ObLSDupTabletsMgr::prepare_serialize(int64_t &max_ser_size, readable_ptr->set_logging(); } } + DUP_TABLE_LOG(INFO, "serialize readable tablets in log for recovery", K(ret), + K(unique_id_array), K(max_ser_size), K(last_readable_sync_succ_time_), + K(last_readable_log_entry_scn_.atomic_load())); } } if (OB_LOG_TOO_LARGE == ret) { - DUP_TABLE_LOG(INFO, "Too many dup tablets, we can not submit all", K(ret), K(max_ser_size), + DUP_TABLE_LOG(DEBUG, "Too many dup tablets, we can not submit all", K(ret), K(max_ser_size), K(max_log_buf_len), K(unique_id_array), K(unique_id_array.count()), K(readable_tablets_list_.get_size())); ret = OB_SUCCESS; } - DUP_TABLE_LOG(DEBUG, "finish prepare ser", K(ret), K(max_ser_size), K(unique_id_array)); return ret; } @@ -1459,17 +1483,17 @@ int ObLSDupTabletsMgr::tablet_log_synced(const bool sync_result, const share::SCN &scn, const bool for_replay, const DupTabletSetIDArray &unique_id_array, - bool &modify_readable_set) + bool &modify_readable_set, + const int64_t start_sync_time) { int ret = OB_SUCCESS; - common::ObTimeGuard timeguard("tablet_log_synced", 500 * 1000); bool clean_readable = false; + bool contain_readable_set = false; modify_readable_set = false; SpinWLockGuard guard(dup_tablets_lock_); - timeguard.click(); for (int i = 0; OB_SUCC(ret) && i < unique_id_array.count(); i++) { const DupTabletSetCommonHeader logging_common_header = unique_id_array[i]; @@ -1490,6 +1514,7 @@ int ObLSDupTabletsMgr::tablet_log_synced(const bool sync_result, } else if (OB_FALSE_IT(logging_tablet_set->clean_logging())) { } else if (logging_common_header.is_readable_set()) { + contain_readable_set = true; // try return empty readable set bool need_remove = false; if (OB_FAIL(check_and_recycle_empty_readable_set_(logging_tablet_set, need_remove))) { @@ -1510,6 +1535,7 @@ int ObLSDupTabletsMgr::tablet_log_synced(const bool sync_result, if (OB_SUCC(ret) && logging_common_header.is_old_set() && !logging_tablet_set->empty()) { if (logging_tablet_set->get_related_set_op_type() == DupTableRelatedSetOpType::OLD_GC) { + //do nothing } else if (OB_FAIL(remove_tablet_from_readable_set_())) { DUP_TABLE_LOG(WARN, "try remove tablet from readable set failed", K(ret), KPC(removing_old_set_)); @@ -1529,7 +1555,8 @@ int ObLSDupTabletsMgr::tablet_log_synced(const bool sync_result, if (OB_SUCC(ret) && sync_result) { // if old is confirmed, clear it if (logging_common_header.is_old_set()) { - DUP_TABLE_LOG(DEBUG, "clean old set", K(ret), KPC(logging_tablet_set), K(for_replay)); + DUP_TABLE_LOG(INFO, DUP_TABLET_LIFE_PREFIX "clean confirmed old set", K(ret), + KPC(logging_tablet_set), K(for_replay)); return_tablet_set_(logging_tablet_set); // move need_confirm_queue to readable } else if (OB_FAIL(merge_into_readable_tablets_(logging_tablet_set, for_replay))) { @@ -1549,8 +1576,13 @@ int ObLSDupTabletsMgr::tablet_log_synced(const bool sync_result, } if (unique_id_array.count() > 0) { - DUP_TABLE_LOG(INFO, "tablet log sync", K(ret), K(sync_result), K(for_replay), K(is_master()), - K(unique_id_array), K(scn), K(modify_readable_set), K(timeguard)); + DUP_TABLE_LOG(DEBUG, "tablet log sync", K(ret), K(sync_result), K(for_replay), K(is_master()), + K(unique_id_array), K(scn), K(modify_readable_set)); + } + + if (contain_readable_set && sync_result) { + common::inc_update(&last_readable_sync_succ_time_, start_sync_time); + last_readable_log_entry_scn_.atomic_store(scn); } return ret; @@ -1679,6 +1711,9 @@ int ObLSDupTabletsMgr::merge_into_readable_tablets_(DupTabletChangeMap *change_m DUP_TABLE_LOG(WARN, "insert into readable_tablets_list_ failed", K(ret), KPC(change_map_ptr)); } else if (OB_FALSE_IT(change_map_ptr->get_common_header().set_readable())) { // do nothing + } else { + DUP_TABLE_LOG(INFO, DUP_TABLET_LIFE_PREFIX "merge into readable tablets", K(ret), + KPC(change_map_ptr), K(for_replay)); } // an empty set first merge into readable list, return it to free pool @@ -2067,11 +2102,14 @@ void ObLSDupTabletsMgr::print_tablet_diag_info_log(bool is_master) INFO, "[%sDup Tablet Info] tenant: %lu, ls: %lu, is_master: %s, total_tablet_count: %lu, " "need_confirm_new_set_count: %u, readable_set_count: %u, tablet_set_print_buf_used: " - "%lu/%lu, tablet_id_print_buf_used:%lu/%lu, %s %s", + "%lu/%lu, tablet_id_print_buf_used:%lu/%lu, last_readable_log_entry_scn: %s, " + "last_readable_sync_succ_time_: %s, %s %s", DupTableDiagStd::DUP_DIAG_COMMON_PREFIX, tenant_id, ls_id.id(), to_cstring(is_master), total_tablet_cnt, need_confirm_new_queue_.get_size(), readable_tablets_list_.get_size(), tablet_set_diag_pos, TABLET_SET_PRINT_BUF_LEN, tablet_id_diag_pos, TABLET_ID_PRINT_BUF_LEN, - tablet_set_diag_info_log_buf_, tablet_id_diag_info_log_buf_); + to_cstring(last_readable_log_entry_scn_.atomic_load()), + to_cstring(last_readable_sync_succ_time_), tablet_set_diag_info_log_buf_, + tablet_id_diag_info_log_buf_); } } @@ -2246,8 +2284,8 @@ int ObLSDupTabletsMgr::discover_dup_tablet_(const common::ObTabletID &tablet_id, } else if (OB_FAIL(changing_new_map->set_refactored(tablet_id, tmp_status, 1))) { DUP_TABLE_LOG(WARN, "insert into changing new tablets failed", K(ret)); } else { - DUP_TABLE_LOG(INFO, "insert a new dup tablet into set", K(ret), K(tablet_id), - KPC(changing_new_set_), K(need_confirm_new_queue_.get_size()), + DUP_TABLE_LOG(INFO, DUP_TABLET_LIFE_PREFIX "insert a new dup tablet into set", K(ret), + K(tablet_id), KPC(changing_new_set_), K(need_confirm_new_queue_.get_size()), KPC(removing_old_set_), K(readable_tablets_list_.get_size())); } } @@ -2257,7 +2295,6 @@ int ObLSDupTabletsMgr::discover_dup_tablet_(const common::ObTabletID &tablet_id, K(readable_tablets_list_.get_size())); return ret; } - int ObLSDupTabletsMgr::alloc_extra_free_tablet_set_() { int ret = OB_SUCCESS; diff --git a/src/storage/tx/ob_dup_table_tablets.h b/src/storage/tx/ob_dup_table_tablets.h index ac057d193..ba4e614f7 100644 --- a/src/storage/tx/ob_dup_table_tablets.h +++ b/src/storage/tx/ob_dup_table_tablets.h @@ -625,7 +625,7 @@ public: bool &is_dup_table, const share::SCN &from_scn, const share::SCN &to_scn); - int gc_dup_tablets(const int64_t gc_ts, const int64_t max_task_interval); + int gc_tmporary_dup_tablets(const int64_t gc_ts, const int64_t max_task_interval); // new gc methods int scan_readable_set_for_gc(); @@ -654,7 +654,8 @@ public: const share::SCN &scn, const bool for_replay, const DupTabletSetIDArray &unique_id_array, - bool &modify_readable_set); + bool &modify_readable_set, + const int64_t start_sync_time); int try_to_confirm_tablets(const share::SCN &confirm_scn); // bool need_log_tablets(); @@ -900,6 +901,9 @@ private: int64_t last_no_free_set_time_; int64_t extra_free_set_alloc_count_; + int64_t last_readable_sync_succ_time_; + share::SCN last_readable_log_entry_scn_; + char *tablet_set_diag_info_log_buf_; char *tablet_id_diag_info_log_buf_; }; diff --git a/src/storage/tx/ob_dup_table_util.cpp b/src/storage/tx/ob_dup_table_util.cpp index cd63560fd..85e978c2e 100755 --- a/src/storage/tx/ob_dup_table_util.cpp +++ b/src/storage/tx/ob_dup_table_util.cpp @@ -219,7 +219,7 @@ int ObDupTabletScanTask::execute_() if (OB_ITER_END == ret) { // ret = OB_SUCCESS; - if (OB_FAIL(cur_ls_ptr->get_dup_table_ls_handler()->gc_dup_tablets( + if (OB_FAIL(cur_ls_ptr->get_dup_table_ls_handler()->gc_temporary_dup_tablets( refresh_time, max_execute_interval_))) { DUP_TABLE_LOG(WARN, "ls gc dup_tablet failed", KR(ret), K(refresh_time), K(max_execute_interval_)); @@ -340,7 +340,7 @@ int ObDupTabletScanTask::execute_for_dup_ls_() if (OB_ITER_END == ret) { // ret = OB_SUCCESS; - if (OB_FAIL(cur_ls_ptr->get_dup_table_ls_handler()->gc_dup_tablets( + if (OB_FAIL(cur_ls_ptr->get_dup_table_ls_handler()->gc_temporary_dup_tablets( refresh_time, max_execute_interval_))) { DUP_TABLE_LOG(WARN, "ls gc dup_tablet failed", KR(ret), K(refresh_time), K(max_execute_interval_)); @@ -503,6 +503,7 @@ int ObDupTableLSHandler::offline() restore_state_container))) { DUP_TABLE_LOG(ERROR, "change ls role state error", K(ret), KPC(this)); } + interface_stat_.reset(); } return ret; } @@ -960,7 +961,7 @@ int ObDupTableLSHandler::block_confirm_with_dup_tablet_change_snapshot( return ret; } -int ObDupTableLSHandler::gc_dup_tablets(const int64_t gc_ts, const int64_t max_task_interval) +int ObDupTableLSHandler::gc_temporary_dup_tablets(const int64_t gc_ts, const int64_t max_task_interval) { int ret = OB_SUCCESS; @@ -973,7 +974,7 @@ int ObDupTableLSHandler::gc_dup_tablets(const int64_t gc_ts, const int64_t max_t } else if (0 > gc_ts || 0 > max_task_interval) { ret = OB_INVALID_ARGUMENT; DUP_TABLE_LOG(WARN, "invalid gc_time", K(ret), K(gc_ts), K(max_task_interval)); - } else if (OB_FAIL(tablets_mgr_ptr_->gc_dup_tablets(gc_ts, max_task_interval))) { + } else if (OB_FAIL(tablets_mgr_ptr_->gc_tmporary_dup_tablets(gc_ts, max_task_interval))) { DUP_TABLE_LOG(WARN, "lose dup tablet failed", KR(ret), K(gc_ts)); } @@ -1264,6 +1265,8 @@ int ObDupTableLSHandler::replay(const void *buffer, DUP_TABLE_LOG(WARN, "init dup_ls_handle in replay failed", K(ret)); } else if (OB_FAIL(prepare_log_operator_())) { DUP_TABLE_LOG(WARN, "init dup_table log operator failed", K(ret)); + } else if (OB_FALSE_IT(log_operator_->set_logging_scn(ts_ns))) { + } else if (OB_FAIL( log_operator_->merge_replay_block(static_cast(buffer), nbytes))) { if (OB_SUCCESS == ret) { @@ -1280,11 +1283,12 @@ int ObDupTableLSHandler::replay(const void *buffer, } else if (OB_FAIL(lease_mgr_ptr_->follower_try_acquire_lease(ts_ns))) { DUP_TABLE_LOG(WARN, "acquire lease from lease log error", K(ret), K(ts_ns)); } else { - log_operator_->set_logging_scn(ts_ns); ret = log_operator_->replay_succ(); - DUP_TABLE_LOG(INFO, "replay dup_table log success", K(ret), K(nbytes), K(lsn), K(ts_ns), + DUP_TABLE_LOG(DEBUG, "replay dup_table log success", K(ret), K(nbytes), K(lsn), K(ts_ns), KPC(tablets_mgr_ptr_), KPC(lease_mgr_ptr_)); // log_operator_->reuse();V + interface_stat_.dup_table_log_entry_cnt_ += 1; + interface_stat_.dup_table_log_entry_total_size_ += nbytes; } // start require lease instantly @@ -1300,7 +1304,6 @@ int ObDupTableLSHandler::replay(const void *buffer, return ret; } - void ObDupTableLSHandler::switch_to_follower_forcedly() { int ret = OB_SUCCESS; @@ -1477,7 +1480,6 @@ int ObDupTableLSHandler::leader_revoke_(const bool is_forcedly) } } - interface_stat_.reset(); DUP_TABLE_LOG(INFO, "Leader Revoke", K(ret), K(is_forcedly), KPC(this)); return ret; } @@ -1502,7 +1504,6 @@ int ObDupTableLSHandler::leader_takeover_(const bool is_resume) } } - interface_stat_.reset(); DUP_TABLE_LOG(INFO, "Leader Takeover", K(ret), K(is_resume), KPC(this)); return ret; } @@ -1519,7 +1520,7 @@ int ObDupTableLSHandler::prepare_log_operator_() DUP_TABLE_LOG(WARN, "malloc log operator failed", K(ret)); } else { new (log_operator_) ObDupTableLogOperator(ls_id_, log_handler_, &dup_ls_ckpt_, lease_mgr_ptr_, - tablets_mgr_ptr_); + tablets_mgr_ptr_, &interface_stat_); } } diff --git a/src/storage/tx/ob_dup_table_util.h b/src/storage/tx/ob_dup_table_util.h index 8a2fc168f..54fb1d5ee 100644 --- a/src/storage/tx/ob_dup_table_util.h +++ b/src/storage/tx/ob_dup_table_util.h @@ -184,7 +184,7 @@ public: bool check_tablet_set_exist(); bool has_dup_tablet(); bool is_dup_tablet(const common::ObTabletID &tablet_id); - int gc_dup_tablets(const int64_t gc_ts, const int64_t max_task_interval); + int gc_temporary_dup_tablets(const int64_t gc_ts, const int64_t max_task_interval); int get_local_ts_info(DupTableTsInfo &ts_info); int get_cache_ts_info(const common::ObAddr &addr, DupTableTsInfo &ts_info); int get_lease_mgr_stat(ObDupLSLeaseMgrStatIterator &collect_iter); diff --git a/src/storage/tx/ob_trans_part_ctx.cpp b/src/storage/tx/ob_trans_part_ctx.cpp index a254b28b8..30c0c1f6f 100755 --- a/src/storage/tx/ob_trans_part_ctx.cpp +++ b/src/storage/tx/ob_trans_part_ctx.cpp @@ -6937,7 +6937,7 @@ int ObPartTransCtx::dup_table_before_preapre_(const share::SCN &before_prepare_v } if (OB_SUCC(ret)) { - DUP_TABLE_LOG(INFO, "set dup_table before prepare version successfully", K(ret), + TRANS_LOG(INFO, "set dup_table before prepare version successfully", K(ret), K(before_prepare_version), K(before_replay), KPC(this)); } diff --git a/src/storage/tx/ob_tx_big_segment_buf.cpp b/src/storage/tx/ob_tx_big_segment_buf.cpp index 6550cfbf3..34abcc43c 100644 --- a/src/storage/tx/ob_tx_big_segment_buf.cpp +++ b/src/storage/tx/ob_tx_big_segment_buf.cpp @@ -197,7 +197,7 @@ int ObTxBigSegmentBuf::split_one_part(char *part_buf, } } - TRANS_LOG(INFO, "init part header for split_one_part", K(ret), K(part_header), KPC(this)); + TRANS_LOG(DEBUG, "init part header for split_one_part", K(ret), K(part_header), KPC(this)); tmp_pos = part_buf_pos; if (OB_FAIL(part_header.serialize(part_buf, part_buf_len, tmp_pos))) { @@ -269,7 +269,7 @@ int ObTxBigSegmentBuf::collect_one_part(const char *part_buf, } } - TRANS_LOG(INFO, "try to init big segment for deserialize", K(ret), K(part_header), KPC(this)); + TRANS_LOG(DEBUG, "try to init big segment for deserialize", K(ret), K(part_header), KPC(this)); if (OB_FAIL(ret)) { // do nothing