hcq/oceanbase
1
0
Fork 0
Code Issues Pull Requests Actions 1 Packages Projects Releases Wiki Activity

fix log_task statistics bug

Browse Source
This commit is contained in:
obdev
2023-10-11 09:43:33 +00:00
committed by ob-robot
parent 11be84be20
commit dac0a4a616
4 changed files with 20 additions and 114 deletions
Download Patch File Download Diff File Expand all files Collapse all files

107
src/logservice/palf/log_sliding_window.cpp
View File

@ -1641,9 +1641,6 @@ int LogSlidingWindow::try_advance_committed_lsn_(const LSN &end_lsn)
get_committed_end_lsn_(old_committed_end_lsn);
}
}
if (end_lsn > old_committed_end_lsn) {
(void) try_advance_log_task_committed_ts_();
}
PALF_LOG(TRACE, "try_advance_committed_lsn_ success", K_(palf_id), K_(self), K_(committed_end_lsn));
if (palf_reach_time_interval(PALF_STAT_PRINT_INTERVAL_US, end_lsn_stat_time_us_)) {
LSN curr_end_lsn;
@ -1655,58 +1652,6 @@ int LogSlidingWindow::try_advance_committed_lsn_(const LSN &end_lsn)
return ret;
}
int LogSlidingWindow::try_advance_log_task_committed_ts_()
{
int ret = OB_SUCCESS;
if (IS_NOT_INIT) {
ret = OB_NOT_INIT;
} else {
LSN new_committed_end_lsn;
get_committed_end_lsn(new_committed_end_lsn);
const int64_t commit_ts = ObTimeUtility::current_time();
int64_t last_submit_log_id = get_last_submit_log_id_();
int64_t log_start_id = get_start_id();
LogTask *log_task = NULL;
for (int64_t tmp_log_id = last_submit_log_id; OB_SUCC(ret) && tmp_log_id >= log_start_id; tmp_log_id--) {
LogTaskGuard guard(this);
if (OB_FAIL(guard.get_log_task(tmp_log_id, log_task))) {
// the log_task may has been slided
} else if (!log_task->is_freezed() || log_task->get_end_lsn() > new_committed_end_lsn) {
continue;
} else if (OB_INVALID_TIMESTAMP == log_task->get_committed_ts()) {
log_task->set_committed_ts(commit_ts);
} else {
break;
}
}
}
return ret;
}
int LogSlidingWindow::try_advance_log_task_first_ack_ts_(const LSN &end_lsn)
{
int ret = OB_SUCCESS;
if (IS_NOT_INIT) {
ret = OB_NOT_INIT;
} else {
const int64_t log_start_id = sw_.get_begin_sn();
LogTask *log_task = NULL;
for (int64_t tmp_log_id = last_submit_log_id_; OB_SUCC(ret) && tmp_log_id >= log_start_id; tmp_log_id--) {
LogTaskGuard guard(this);
if (OB_FAIL(guard.get_log_task(tmp_log_id, log_task))) {
// the log_task may has been slided
} else if (!log_task->is_freezed() || log_task->get_end_lsn() > end_lsn) {
continue;
} else if (OB_INVALID_TIMESTAMP == log_task->get_first_ack_ts()) {
log_task->set_first_ack_ts(ObTimeUtility::current_time());
} else {
break;
}
}
}
return ret;
}
int LogSlidingWindow::inc_update_scn_base(const SCN &scn)
{
int ret = OB_SUCCESS;
@ -2160,8 +2105,6 @@ int LogSlidingWindow::sliding_cb(const int64_t sn, const FixedSlidingWindowSlot
const int64_t log_freeze_ts = log_task->get_freeze_ts();
const int64_t log_submit_ts = log_task->get_submit_ts();
const int64_t log_flush_ts = log_task->get_flushed_ts();
const int64_t log_first_ack_ts = log_task->get_first_ack_ts();
const int64_t log_commit_ts = log_task->get_committed_ts();
log_task->unlock();
// Verifying accum_checksum firstly.
@ -2191,34 +2134,24 @@ int LogSlidingWindow::sliding_cb(const int64_t sn, const FixedSlidingWindowSlot
const int64_t log_life_time = fs_cb_begin_ts - log_gen_ts;
log_life_time_stat_.stat(log_life_time);
// Concurrency problem
// The first_ack_ts and committed_ts of log_task may havn't been updated when they were slided from sw.
if (OB_INVALID_TIMESTAMP != log_first_ack_ts && OB_INVALID_TIMESTAMP != log_commit_ts) {
const int64_t total_slide_log_cnt = ATOMIC_AAF(&accum_slide_log_cnt_, 1);
const int64_t total_log_gen_to_freeze_cost = ATOMIC_AAF(&accum_log_gen_to_freeze_cost_, log_freeze_ts - log_gen_ts);
const int64_t total_log_gen_to_submit_cost = ATOMIC_AAF(&accum_log_gen_to_submit_cost_, log_submit_ts - log_gen_ts);
const int64_t total_log_submit_to_flush_cost = ATOMIC_AAF(&accum_log_submit_to_flush_cost_, log_flush_ts - log_submit_ts);
const int64_t total_log_submit_to_first_ack_cost = ATOMIC_AAF(&accum_log_submit_to_first_ack_cost_, log_first_ack_ts - log_submit_ts);
const int64_t total_log_submit_to_commit_cost = ATOMIC_AAF(&accum_log_submit_to_commit_cost_, log_commit_ts - log_submit_ts);
const int64_t total_log_submit_to_slide_cost = ATOMIC_AAF(&accum_log_submit_to_slide_cost_, fs_cb_begin_ts - log_submit_ts);
if (palf_reach_time_interval(PALF_STAT_PRINT_INTERVAL_US, log_slide_stat_time_)) {
const int64_t avg_log_gen_to_freeze_time = total_log_gen_to_freeze_cost / total_slide_log_cnt;
const int64_t avg_log_gen_to_submit_time = total_log_gen_to_submit_cost / total_slide_log_cnt;
const int64_t avg_log_submit_to_flush_time = total_log_submit_to_flush_cost / total_slide_log_cnt;
const int64_t avg_log_submit_to_first_ack_time = total_log_submit_to_first_ack_cost / total_slide_log_cnt;
const int64_t avg_log_submit_to_commit_time = total_log_submit_to_commit_cost / total_slide_log_cnt;
const int64_t avg_log_submit_to_slide_time = total_log_submit_to_slide_cost / total_slide_log_cnt;
PALF_LOG(INFO, "[PALF STAT LOG TASK TIME]", K_(palf_id), K_(self), K(total_slide_log_cnt),
K(avg_log_gen_to_freeze_time), K(avg_log_gen_to_submit_time), K(avg_log_submit_to_flush_time),
K(avg_log_submit_to_first_ack_time), K(avg_log_submit_to_commit_time), K(avg_log_submit_to_slide_time));
ATOMIC_STORE(&accum_slide_log_cnt_, 0);
ATOMIC_STORE(&accum_log_gen_to_freeze_cost_, 0);
ATOMIC_STORE(&accum_log_gen_to_submit_cost_, 0);
ATOMIC_STORE(&accum_log_submit_to_flush_cost_, 0);
ATOMIC_STORE(&accum_log_submit_to_first_ack_cost_, 0);
ATOMIC_STORE(&accum_log_submit_to_commit_cost_, 0);
ATOMIC_STORE(&accum_log_submit_to_slide_cost_, 0);
}
const int64_t total_slide_log_cnt = ATOMIC_AAF(&accum_slide_log_cnt_, 1);
const int64_t total_log_gen_to_freeze_cost = ATOMIC_AAF(&accum_log_gen_to_freeze_cost_, log_freeze_ts - log_gen_ts);
const int64_t total_log_gen_to_submit_cost = ATOMIC_AAF(&accum_log_gen_to_submit_cost_, log_submit_ts - log_gen_ts);
const int64_t total_log_submit_to_flush_cost = ATOMIC_AAF(&accum_log_submit_to_flush_cost_, log_flush_ts - log_submit_ts);
const int64_t total_log_submit_to_slide_cost = ATOMIC_AAF(&accum_log_submit_to_slide_cost_, fs_cb_begin_ts - log_submit_ts);
if (palf_reach_time_interval(PALF_STAT_PRINT_INTERVAL_US, log_slide_stat_time_)) {
const int64_t avg_log_gen_to_freeze_time = total_log_gen_to_freeze_cost / total_slide_log_cnt;
const int64_t avg_log_gen_to_submit_time = total_log_gen_to_submit_cost / total_slide_log_cnt;
const int64_t avg_log_submit_to_flush_time = total_log_submit_to_flush_cost / total_slide_log_cnt;
const int64_t avg_log_submit_to_slide_time = total_log_submit_to_slide_cost / total_slide_log_cnt;
PALF_LOG(INFO, "[PALF STAT LOG TASK TIME]", K_(palf_id), K_(self), K(total_slide_log_cnt),
K(avg_log_gen_to_freeze_time), K(avg_log_gen_to_submit_time), K(avg_log_submit_to_flush_time),
K(avg_log_submit_to_slide_time));
ATOMIC_STORE(&accum_slide_log_cnt_, 0);
ATOMIC_STORE(&accum_log_gen_to_freeze_cost_, 0);
ATOMIC_STORE(&accum_log_gen_to_submit_cost_, 0);
ATOMIC_STORE(&accum_log_submit_to_flush_cost_, 0);
ATOMIC_STORE(&accum_log_submit_to_slide_cost_, 0);
}
if (log_life_time > 100 * 1000) {
@ -4168,10 +4101,6 @@ int LogSlidingWindow::ack_log(const common::ObAddr &src_server, const LSN &end_l
LSN old_committed_end_lsn;
get_committed_end_lsn_(old_committed_end_lsn);
LSN new_committed_end_lsn;
// first ack ts only needs to be updated when end_lsn >= old_committed_lsn
if (old_committed_end_lsn < end_lsn) {
(void) try_advance_log_task_first_ack_ts_(end_lsn);
}
if (state_mgr_->is_leader_active()) {
// Only leader with ACTIVE state can generate new committed_end_lsn.
(void) gen_committed_end_lsn_(new_committed_end_lsn);

2
src/logservice/palf/log_sliding_window.h
View File

@ -376,8 +376,6 @@ private:
const int64_t &proposal_id,
const int64_t accum_checksum);
int try_advance_committed_lsn_(const LSN &end_lsn);
int try_advance_log_task_committed_ts_();
int try_advance_log_task_first_ack_ts_(const LSN &end_lsn);
void get_last_submit_log_info_(LSN &lsn,
LSN &end_lsn,
int64_t &log_id,

13
src/logservice/palf/log_task.cpp
View File

@ -141,9 +141,7 @@ LogTask::LogTask()
gen_ts_(OB_INVALID_TIMESTAMP),
freeze_ts_(OB_INVALID_TIMESTAMP),
submit_ts_(OB_INVALID_TIMESTAMP),
first_ack_ts_(OB_INVALID_TIMESTAMP),
flushed_ts_(OB_INVALID_TIMESTAMP),
committed_ts_(OB_INVALID_TIMESTAMP),
lock_()
{
reset();
@ -167,9 +165,7 @@ void LogTask::reset()
gen_ts_ = OB_INVALID_TIMESTAMP;
freeze_ts_ = OB_INVALID_TIMESTAMP;
submit_ts_ = OB_INVALID_TIMESTAMP;
first_ack_ts_ = OB_INVALID_TIMESTAMP;
flushed_ts_ = OB_INVALID_TIMESTAMP;
committed_ts_ = OB_INVALID_TIMESTAMP;
}
bool LogTask::can_be_slid()
@ -435,19 +431,10 @@ void LogTask::set_submit_ts(const int64_t ts)
ATOMIC_STORE(&submit_ts_, ts);
}
void LogTask::set_first_ack_ts(const int64_t ts)
{
ATOMIC_STORE(&first_ack_ts_, ts);
}
void LogTask::set_flushed_ts(const int64_t ts)
{
ATOMIC_STORE(&flushed_ts_, ts);
}
void LogTask::set_committed_ts(const int64_t ts)
{
ATOMIC_STORE(&committed_ts_, ts);
}
} // namespace palf
} // namespace oceanbase

12
src/logservice/palf/log_task.h
View File

@ -140,22 +140,16 @@ public:
int64_t get_accum_checksum() const { return header_.accum_checksum_; }
void set_freeze_ts(const int64_t ts);
void set_submit_ts(const int64_t ts);
void set_first_ack_ts(const int64_t ts);
void set_flushed_ts(const int64_t ts);
void set_committed_ts(const int64_t ts);
int64_t get_gen_ts() const { return ATOMIC_LOAD(&(gen_ts_)); }
int64_t get_freeze_ts() const { return ATOMIC_LOAD(&(freeze_ts_)); }
int64_t get_submit_ts() const { return ATOMIC_LOAD(&(submit_ts_)); }
int64_t get_first_ack_ts() const { return ATOMIC_LOAD(&(first_ack_ts_)); }
int64_t get_flushed_ts() const { return ATOMIC_LOAD(&(flushed_ts_)); }
int64_t get_committed_ts() const { return ATOMIC_LOAD(&(committed_ts_)); }
TO_STRING_KV(K_(header), K_(state_map), K_(ref_cnt),
K_(gen_ts), K_(freeze_ts), K_(submit_ts), K_(flushed_ts), K_(first_ack_ts), K_(committed_ts),
K_(gen_ts), K_(freeze_ts), K_(submit_ts), K_(flushed_ts),
"gen_to_freeze cost time", freeze_ts_ - gen_ts_,
"gen_to_submit cost time", submit_ts_ - gen_ts_,
"submit_to_flush cost time", ((flushed_ts_ - submit_ts_) < 0 ? 0 : (flushed_ts_ - submit_ts_)),
"submit_to_first_ack cost time", ((first_ack_ts_ - submit_ts_) < 0 ? 0 : (first_ack_ts_ - submit_ts_)),
"submit_to_commit cost time", ((committed_ts_ - submit_ts_) < 0 ? 0 : (committed_ts_ - submit_ts_))
"submit_to_flush cost time", ((flushed_ts_ - submit_ts_) < 0 ? 0 : (flushed_ts_ - submit_ts_))
);
private:
int try_freeze_(const LSN &end_lsn);
@ -167,9 +161,7 @@ private:
mutable int64_t gen_ts_;
mutable int64_t freeze_ts_;
mutable int64_t submit_ts_;
mutable int64_t first_ack_ts_;
mutable int64_t flushed_ts_;
mutable int64_t committed_ts_;
mutable common::ObLatch lock_;
};
} // end namespace palf