Add a perf context level that doesn't measure time for mutex operations

Summary: Timing mutex operations can impact scalability of the system. Add a new perf context level that can measure time counters except for mutex.

Test Plan: Add a new unit test case to make sure it is not set.

Reviewers: IslamAbdelRahman, rven, kradhakrishnan, yhchiang, anthony

Reviewed By: anthony

Subscribers: MarkCallaghan, leveldb, dhruba

Differential Revision: https://reviews.facebook.net/D53199

HISTORY.md

@@ -1,5 +1,9 @@
 # Rocksdb Change Log
 
+## Unreleased
+### Public API Changes
+* Add a new perf context level between kEnableCount and kEnableTime. Level 2 now doesn't include timers for mutexes.
+
 ## 4.4.0 (1/14/2016)
 ### Public API Changes
 * Change names in CompactionPri and add a new one.

db/perf_context_test.cc

@@ -543,28 +543,31 @@ 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) {
+  for (PerfLevel perf_level :
+       {PerfLevel::kEnableTimeExceptForMutex, PerfLevel::kEnableTime}) {
+    for (int c = 0; c < 2; ++c) {
     InstrumentedMutex mutex(nullptr, Env::Default(), stats_code[c]);
     mutex.Lock();
     std::thread child_thread([&] {
-      SetPerfLevel(kEnableTime);
+      SetPerfLevel(perf_level);
       perf_context.Reset();
       ASSERT_EQ(perf_context.db_mutex_lock_nanos, 0);
       mutex.Lock();
       mutex.Unlock();
-      if (stats_code[c] == DB_MUTEX_WAIT_MICROS) {
+      if (perf_level == PerfLevel::kEnableTimeExceptForMutex ||
+          stats_code[c] != DB_MUTEX_WAIT_MICROS) {
+        ASSERT_EQ(perf_context.db_mutex_lock_nanos, 0);
+      } else {
         // 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) {

include/rocksdb/perf_level.h

@@ -14,9 +14,11 @@ namespace rocksdb {
 // How much perf stats to collect. Affects perf_context and iostats_context.
 
 enum PerfLevel {
-  kDisable        = 0,  // disable perf stats
-  kEnableCount    = 1,  // enable only count stats
-  kEnableTime     = 2   // enable time stats too
+  kDisable = 0,                   // disable perf stats
+  kEnableCount = 1,               // enable only count stats
+  kEnableTimeExceptForMutex = 2,  // Other than count stats, also enable time
+                                  // stats except for mutexes
+  kEnableTime = 3                 // enable count and time stats
 };
 
 // set the perf stats level for current thread

util/instrumented_mutex.cc

@@ -9,8 +9,8 @@
 
 namespace rocksdb {
 void InstrumentedMutex::Lock() {
-  PERF_CONDITIONAL_TIMER_GUARD(db_mutex_lock_nanos,
-                               stats_code_ == DB_MUTEX_WAIT_MICROS);
+  PERF_CONDITIONAL_TIMER_FOR_MUTEX_GUARD(db_mutex_lock_nanos,
+                                         stats_code_ == DB_MUTEX_WAIT_MICROS);
   uint64_t wait_time_micros = 0;
   if (env_ != nullptr && stats_ != nullptr) {
     {
@@ -31,8 +31,8 @@ void InstrumentedMutex::LockInternal() {
 }
 
 void InstrumentedCondVar::Wait() {
-  PERF_CONDITIONAL_TIMER_GUARD(db_condition_wait_nanos,
-                               stats_code_ == DB_MUTEX_WAIT_MICROS);
+  PERF_CONDITIONAL_TIMER_FOR_MUTEX_GUARD(db_condition_wait_nanos,
+                                         stats_code_ == DB_MUTEX_WAIT_MICROS);
   uint64_t wait_time_micros = 0;
   if (env_ != nullptr && stats_ != nullptr) {
     {
@@ -53,8 +53,8 @@ void InstrumentedCondVar::WaitInternal() {
 }
 
 bool InstrumentedCondVar::TimedWait(uint64_t abs_time_us) {
-  PERF_CONDITIONAL_TIMER_GUARD(db_condition_wait_nanos,
-                               stats_code_ == DB_MUTEX_WAIT_MICROS);
+  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 (env_ != nullptr && stats_ != nullptr) {

util/perf_context_imp.h

@@ -33,10 +33,10 @@ 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();                             \
+#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();                                   \
   }
 
 // Update metric with time elapsed since last START. start time is reset

util/perf_step_timer.h

@@ -12,12 +12,12 @@ namespace rocksdb {
 
 class PerfStepTimer {
  public:
-  PerfStepTimer(uint64_t* metric)
-    : enabled_(perf_level >= PerfLevel::kEnableTime),
-      env_(enabled_ ? Env::Default() : nullptr),
-      start_(0),
-      metric_(metric) {
-  }
+  explicit PerfStepTimer(uint64_t* metric, bool for_mutex = false)
+      : enabled_(perf_level >= PerfLevel::kEnableTime ||
+                 (!for_mutex && perf_level >= kEnableTimeExceptForMutex)),
+        env_(enabled_ ? Env::Default() : nullptr),
+        start_(0),
+        metric_(metric) {}
 
   ~PerfStepTimer() {
     Stop();