From d20915d52a8227fa4ecda2680254e668ca80bcc4 Mon Sep 17 00:00:00 2001
From: sdong <siying.d@fb.com>
Date: Mon, 25 Jan 2016 17:07:37 -0800
Subject: [PATCH] Disable stats about mutex duration by default

Summary: Measuring mutex duration will measure time inside DB mutex, which breaks our best practice. Add a stat level in Statistics class. By default, disable to measure the mutex operations.

Test Plan: Add a unit test to make sure it is off by default.

Reviewers: rven, anthony, IslamAbdelRahman, kradhakrishnan, andrewkr, yhchiang

Reviewed By: yhchiang

Subscribers: MarkCallaghan, leveldb, dhruba

Differential Revision: https://reviews.facebook.net/D53367
---
 HISTORY.md                   |  1 +
 db/db_test.cc                | 14 ++++++++++++++
 include/rocksdb/statistics.h | 13 +++++++++++++
 util/instrumented_mutex.cc   | 13 ++++++++++---
 4 files changed, 38 insertions(+), 3 deletions(-)

diff --git a/HISTORY.md b/HISTORY.md
index 13fc5e158..809cbf76c 100644
--- a/HISTORY.md
+++ b/HISTORY.md
@@ -2,6 +2,7 @@
 ## Unreleased
 ### Public API Changes
 * Add a new perf context level between kEnableCount and kEnableTime. Level 2 now doesn't include timers for mutexes.
+* Statistics of mutex operation durations will not be measured by default. If you want to have them enabled, you need to set Statistics::stats_level_ to kAll.
 
 ### New Features
 * ldb tool now supports operations to non-default column families.
diff --git a/db/db_test.cc b/db/db_test.cc
index 1296bad06..db3524345 100644
--- a/db/db_test.cc
+++ b/db/db_test.cc
@@ -7405,10 +7405,24 @@ TEST_F(DBTest, EncodeDecompressedBlockSizeTest) {
   }
 }
 
+TEST_F(DBTest, MutexWaitStatsDisabledByDefault) {
+  Options options = CurrentOptions();
+  options.create_if_missing = true;
+  options.statistics = rocksdb::CreateDBStatistics();
+  CreateAndReopenWithCF({"pikachu"}, options);
+  const uint64_t kMutexWaitDelay = 100;
+  ThreadStatusUtil::TEST_SetStateDelay(ThreadStatus::STATE_MUTEX_WAIT,
+                                       kMutexWaitDelay);
+  ASSERT_OK(Put("hello", "rocksdb"));
+  ASSERT_EQ(TestGetTickerCount(options, DB_MUTEX_WAIT_MICROS), 0);
+  ThreadStatusUtil::TEST_SetStateDelay(ThreadStatus::STATE_MUTEX_WAIT, 0);
+}
+
 TEST_F(DBTest, MutexWaitStats) {
   Options options = CurrentOptions();
   options.create_if_missing = true;
   options.statistics = rocksdb::CreateDBStatistics();
+  options.statistics->stats_level_ = StatsLevel::kAll;
   CreateAndReopenWithCF({"pikachu"}, options);
   const uint64_t kMutexWaitDelay = 100;
   ThreadStatusUtil::TEST_SetStateDelay(
diff --git a/include/rocksdb/statistics.h b/include/rocksdb/statistics.h
index 15c49439c..813104b99 100644
--- a/include/rocksdb/statistics.h
+++ b/include/rocksdb/statistics.h
@@ -109,6 +109,7 @@ enum Tickers : uint32_t {
   // Writer has to wait for compaction or flush to finish.
   STALL_MICROS,
   // The wait time for db mutex.
+  // Disabled by default. To enable it set stats level to kAll
   DB_MUTEX_WAIT_MICROS,
   RATE_LIMIT_DELAY_MILLIS,
   NO_ITERATORS,  // number of iterators currently open
@@ -316,6 +317,16 @@ struct HistogramData {
   double standard_deviation;
 };
 
+enum StatsLevel {
+  // Collect all stats except the counters requiring to get time inside the
+  // mutex lock.
+  kExceptTimeForMutex,
+  // Collect all stats, including measuring duration of mutex operations.
+  // If getting time is expensive on the platform to run, it can
+  // reduce scalability to more threads, especialy for writes.
+  kAll,
+};
+
 // Analyze the performance of a db
 class Statistics {
  public:
@@ -339,6 +350,8 @@ class Statistics {
   virtual bool HistEnabledForType(uint32_t type) const {
     return type < HISTOGRAM_ENUM_MAX;
   }
+
+  StatsLevel stats_level_ = kExceptTimeForMutex;
 };
 
 // Create a concrete DBStatistics object
diff --git a/util/instrumented_mutex.cc b/util/instrumented_mutex.cc
index e5c6527be..e5603fe08 100644
--- a/util/instrumented_mutex.cc
+++ b/util/instrumented_mutex.cc
@@ -8,11 +8,18 @@
 #include "util/thread_status_util.h"
 
 namespace rocksdb {
+namespace {
+bool ShouldReportToStats(Env* env, Statistics* stats) {
+  return env != nullptr && stats != nullptr &&
+         stats->stats_level_ != kExceptTimeForMutex;
+}
+}  // 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 (env_ != nullptr && stats_ != nullptr) {
+  if (ShouldReportToStats(env_, stats_)) {
     {
       StopWatch sw(env_, nullptr, 0, &wait_time_micros);
       LockInternal();
@@ -34,7 +41,7 @@ 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 (env_ != nullptr && stats_ != nullptr) {
+  if (ShouldReportToStats(env_, stats_)) {
     {
       StopWatch sw(env_, nullptr, 0, &wait_time_micros);
       WaitInternal();
@@ -57,7 +64,7 @@ bool InstrumentedCondVar::TimedWait(uint64_t abs_time_us) {
                                          stats_code_ == DB_MUTEX_WAIT_MICROS);
   uint64_t wait_time_micros = 0;
   bool result = false;
-  if (env_ != nullptr && stats_ != nullptr) {
+  if (ShouldReportToStats(env_, stats_)) {
     {
       StopWatch sw(env_, nullptr, 0, &wait_time_micros);
       result = TimedWaitInternal(abs_time_us);