Make perf_context.db_mutex_lock_nanos and db_condition_wait_nanos only measures DB Mutex

Summary:
In the current implementation, perf_context.db_mutex_lock_nanos and
perf_context.db_condition_wait_nanos also include the mutex-wait time
other than DB Mutex.

This patch fix this issue by incrementing the counters only when it detects
a DB mutex.

Test Plan: perf_context_test

Reviewers: anthony, IslamAbdelRahman, sdong, igor

Reviewed By: sdong

Subscribers: dhruba, leveldb

Differential Revision: https://reviews.facebook.net/D48555
This commit is contained in:
Yueh-Hsuan Chiang 2015-10-13 10:41:48 -07:00
parent 1fe78a4073
commit 7062d0ea68
3 changed files with 58 additions and 4 deletions

View File

@ -5,6 +5,7 @@
//
#include <algorithm>
#include <iostream>
#include <thread>
#include <vector>
#include "rocksdb/db.h"
@ -541,6 +542,49 @@ TEST_F(PerfContextTest, SeekKeyComparison) {
}
}
TEST_F(PerfContextTest, DBMutexLockCounter) {
SetPerfLevel(kEnableTime);
int stats_code[] = {0, static_cast<int>(DB_MUTEX_WAIT_MICROS)};
for (int c = 0; c < 2; ++c) {
InstrumentedMutex mutex(nullptr, Env::Default(), stats_code[c]);
mutex.Lock();
std::thread child_thread([&] {
SetPerfLevel(kEnableTime);
perf_context.Reset();
ASSERT_EQ(perf_context.db_mutex_lock_nanos, 0);
mutex.Lock();
mutex.Unlock();
if (stats_code[c] == DB_MUTEX_WAIT_MICROS) {
// increment the counter only when it's a DB Mutex
ASSERT_GT(perf_context.db_mutex_lock_nanos, 0);
} else {
ASSERT_EQ(perf_context.db_mutex_lock_nanos, 0);
}
});
Env::Default()->SleepForMicroseconds(100);
mutex.Unlock();
child_thread.join();
}
}
TEST_F(PerfContextTest, FalseDBMutexWait) {
SetPerfLevel(kEnableTime);
int stats_code[] = {0, static_cast<int>(DB_MUTEX_WAIT_MICROS)};
for (int c = 0; c < 2; ++c) {
InstrumentedMutex mutex(nullptr, Env::Default(), stats_code[c]);
InstrumentedCondVar lock(&mutex);
perf_context.Reset();
mutex.Lock();
lock.TimedWait(100);
mutex.Unlock();
if (stats_code[c] == static_cast<int>(DB_MUTEX_WAIT_MICROS)) {
// increment the counter only when it's a DB Mutex
ASSERT_GT(perf_context.db_condition_wait_nanos, 0);
} else {
ASSERT_EQ(perf_context.db_condition_wait_nanos, 0);
}
}
}
}
int main(int argc, char** argv) {

View File

@ -3,13 +3,14 @@
// LICENSE file in the root directory of this source tree. An additional grant
// of patent rights can be found in the PATENTS file in the same directory.
#include "util/perf_context_imp.h"
#include "util/instrumented_mutex.h"
#include "util/perf_context_imp.h"
#include "util/thread_status_util.h"
namespace rocksdb {
void InstrumentedMutex::Lock() {
PERF_TIMER_GUARD(db_mutex_lock_nanos);
PERF_CONDITIONAL_TIMER_GUARD(db_mutex_lock_nanos,
stats_code_ == DB_MUTEX_WAIT_MICROS);
uint64_t wait_time_micros = 0;
if (env_ != nullptr && stats_ != nullptr) {
{
@ -30,7 +31,8 @@ void InstrumentedMutex::LockInternal() {
}
void InstrumentedCondVar::Wait() {
PERF_TIMER_GUARD(db_condition_wait_nanos);
PERF_CONDITIONAL_TIMER_GUARD(db_condition_wait_nanos,
stats_code_ == DB_MUTEX_WAIT_MICROS);
uint64_t wait_time_micros = 0;
if (env_ != nullptr && stats_ != nullptr) {
{
@ -51,7 +53,8 @@ void InstrumentedCondVar::WaitInternal() {
}
bool InstrumentedCondVar::TimedWait(uint64_t abs_time_us) {
PERF_TIMER_GUARD(db_condition_wait_nanos);
PERF_CONDITIONAL_TIMER_GUARD(db_condition_wait_nanos,
stats_code_ == DB_MUTEX_WAIT_MICROS);
uint64_t wait_time_micros = 0;
bool result = false;
if (env_ != nullptr && stats_ != nullptr) {

View File

@ -13,6 +13,7 @@ namespace rocksdb {
#if defined(NPERF_CONTEXT) || defined(IOS_CROSS_COMPILE)
#define PERF_TIMER_GUARD(metric)
#define PERF_CONDITIONAL_TIMER_GUARD(metric, condition)
#define PERF_TIMER_MEASURE(metric)
#define PERF_TIMER_STOP(metric)
#define PERF_TIMER_START(metric)
@ -32,6 +33,12 @@ namespace rocksdb {
PerfStepTimer perf_step_timer_ ## metric(&(perf_context.metric)); \
perf_step_timer_ ## metric.Start();
#define PERF_CONDITIONAL_TIMER_GUARD(metric, condition) \
PerfStepTimer perf_step_timer_##metric(&(perf_context.metric)); \
if ((condition)) { \
perf_step_timer_##metric.Start(); \
}
// Update metric with time elapsed since last START. start time is reset
// to current timestamp.
#define PERF_TIMER_MEASURE(metric) \