From 7ccb35f653865398e8e0f545db2489995b1546cd Mon Sep 17 00:00:00 2001 From: Siying Dong Date: Thu, 17 May 2018 12:46:23 -0700 Subject: [PATCH] In instrumented mutex, take timing once for both of perf_context and statistics Summary: Closes https://github.com/facebook/rocksdb/pull/3427 Differential Revision: D6827236 Pulled By: siying fbshipit-source-id: d8a2cc525c90df625510565669f2659014259a8a --- monitoring/instrumented_mutex.cc | 60 ++++++++++---------------------- monitoring/perf_context_imp.h | 10 +++--- monitoring/perf_step_timer.h | 31 ++++++++++++----- 3 files changed, 48 insertions(+), 53 deletions(-) diff --git a/monitoring/instrumented_mutex.cc b/monitoring/instrumented_mutex.cc index c07a5a17a..2255b35ae 100644 --- a/monitoring/instrumented_mutex.cc +++ b/monitoring/instrumented_mutex.cc @@ -10,25 +10,21 @@ namespace rocksdb { namespace { -bool ShouldReportToStats(Env* env, Statistics* stats) { - return env != nullptr && stats != nullptr && - stats->stats_level_ > kExceptTimeForMutex; +Statistics* stats_for_report(Env* env, Statistics* stats) { + if (env != nullptr && stats != nullptr && + stats->stats_level_ > kExceptTimeForMutex) { + return stats; + } else { + return nullptr; + } } } // namespace void InstrumentedMutex::Lock() { - PERF_CONDITIONAL_TIMER_FOR_MUTEX_GUARD(db_mutex_lock_nanos, - stats_code_ == DB_MUTEX_WAIT_MICROS); - uint64_t wait_time_micros = 0; - if (ShouldReportToStats(env_, stats_)) { - { - StopWatch sw(env_, nullptr, 0, &wait_time_micros); - LockInternal(); - } - RecordTick(stats_, stats_code_, wait_time_micros); - } else { - LockInternal(); - } + PERF_CONDITIONAL_TIMER_FOR_MUTEX_GUARD( + db_mutex_lock_nanos, stats_code_ == DB_MUTEX_WAIT_MICROS, + stats_for_report(env_, stats_), stats_code_); + LockInternal(); } void InstrumentedMutex::LockInternal() { @@ -39,18 +35,10 @@ void InstrumentedMutex::LockInternal() { } void InstrumentedCondVar::Wait() { - PERF_CONDITIONAL_TIMER_FOR_MUTEX_GUARD(db_condition_wait_nanos, - stats_code_ == DB_MUTEX_WAIT_MICROS); - uint64_t wait_time_micros = 0; - if (ShouldReportToStats(env_, stats_)) { - { - StopWatch sw(env_, nullptr, 0, &wait_time_micros); - WaitInternal(); - } - RecordTick(stats_, stats_code_, wait_time_micros); - } else { - WaitInternal(); - } + PERF_CONDITIONAL_TIMER_FOR_MUTEX_GUARD( + db_condition_wait_nanos, stats_code_ == DB_MUTEX_WAIT_MICROS, + stats_for_report(env_, stats_), stats_code_); + WaitInternal(); } void InstrumentedCondVar::WaitInternal() { @@ -61,20 +49,10 @@ void InstrumentedCondVar::WaitInternal() { } bool InstrumentedCondVar::TimedWait(uint64_t abs_time_us) { - PERF_CONDITIONAL_TIMER_FOR_MUTEX_GUARD(db_condition_wait_nanos, - stats_code_ == DB_MUTEX_WAIT_MICROS); - uint64_t wait_time_micros = 0; - bool result = false; - if (ShouldReportToStats(env_, stats_)) { - { - StopWatch sw(env_, nullptr, 0, &wait_time_micros); - result = TimedWaitInternal(abs_time_us); - } - RecordTick(stats_, stats_code_, wait_time_micros); - } else { - result = TimedWaitInternal(abs_time_us); - } - return result; + PERF_CONDITIONAL_TIMER_FOR_MUTEX_GUARD( + db_condition_wait_nanos, stats_code_ == DB_MUTEX_WAIT_MICROS, + stats_for_report(env_, stats_), stats_code_); + return TimedWaitInternal(abs_time_us); } bool InstrumentedCondVar::TimedWaitInternal(uint64_t abs_time_us) { diff --git a/monitoring/perf_context_imp.h b/monitoring/perf_context_imp.h index 90774e826..43a28e43c 100644 --- a/monitoring/perf_context_imp.h +++ b/monitoring/perf_context_imp.h @@ -41,10 +41,12 @@ extern __thread PerfContext perf_context; PerfStepTimer perf_step_timer_##metric(&(perf_context.metric)); \ perf_step_timer_##metric.Start(); -#define PERF_CONDITIONAL_TIMER_FOR_MUTEX_GUARD(metric, condition) \ - PerfStepTimer perf_step_timer_##metric(&(perf_context.metric), true); \ - if (condition) { \ - perf_step_timer_##metric.Start(); \ +#define PERF_CONDITIONAL_TIMER_FOR_MUTEX_GUARD(metric, condition, stats, \ + ticker_type) \ + PerfStepTimer perf_step_timer_##metric(&(perf_context.metric), true, stats, \ + ticker_type); \ + if (condition) { \ + perf_step_timer_##metric.Start(); \ } // Update metric with time elapsed since last START. start time is reset diff --git a/monitoring/perf_step_timer.h b/monitoring/perf_step_timer.h index 4cb48b125..246d6eb75 100644 --- a/monitoring/perf_step_timer.h +++ b/monitoring/perf_step_timer.h @@ -12,19 +12,25 @@ namespace rocksdb { class PerfStepTimer { public: - explicit PerfStepTimer(uint64_t* metric, bool for_mutex = false) - : enabled_(perf_level >= PerfLevel::kEnableTime || - (!for_mutex && perf_level >= kEnableTimeExceptForMutex)), - env_(enabled_ ? Env::Default() : nullptr), + explicit PerfStepTimer(uint64_t* metric, bool for_mutex = false, + Statistics* statistics = nullptr, + uint32_t ticker_type = 0) + : perf_counter_enabled_( + perf_level >= PerfLevel::kEnableTime || + (!for_mutex && perf_level >= kEnableTimeExceptForMutex)), + env_((perf_counter_enabled_ || statistics != nullptr) ? Env::Default() + : nullptr), start_(0), - metric_(metric) {} + metric_(metric), + statistics_(statistics), + ticker_type_(ticker_type) {} ~PerfStepTimer() { Stop(); } void Start() { - if (enabled_) { + if (perf_counter_enabled_ || statistics_ != nullptr) { start_ = env_->NowNanos(); } } @@ -39,16 +45,25 @@ class PerfStepTimer { void Stop() { if (start_) { - *metric_ += env_->NowNanos() - start_; + uint64_t duration = env_->NowNanos() - start_; + if (perf_counter_enabled_) { + *metric_ += duration; + } + + if (statistics_ != nullptr) { + RecordTick(statistics_, ticker_type_, duration); + } start_ = 0; } } private: - const bool enabled_; + const bool perf_counter_enabled_; Env* const env_; uint64_t start_; uint64_t* metric_; + Statistics* statistics_; + uint32_t ticker_type_; }; } // namespace rocksdb