From e678a5947a5fda4c9133812b0f4ab0c0a76b47a9 Mon Sep 17 00:00:00 2001
From: Mark Callaghan <mcallaghan@fb.com>
Date: Wed, 3 Oct 2012 06:51:11 -0700
Subject: [PATCH] Add --stats_interval option to db_bench

Summary:
The option is zero by default and in that case reporting is unchanged.
By unchanged, the interval at which stats are reported is scaled after each
report and newline is not issued after each report so one line is rewritten.
When non-zero it specifies the constant interval (in operations) at which
statistics are reported and the stats include the rate per interval. This
makes it easier to determine whether QPS changes over the duration of the test.

Task ID: #

Blame Rev:

Test Plan:
run db_bench

Revert Plan:

Database Impact:

Memcache Impact:

Other Notes:

EImportant:

- begin *PUBLIC* platform impact section -
Bugzilla: #
- end platform impact -

Reviewers: dhruba

Reviewed By: dhruba

CC: heyongqiang

Differential Revision: https://reviews.facebook.net/D5817
---
 db/db_bench.cc | 60 +++++++++++++++++++++++++++++++++++++-------------
 1 file changed, 45 insertions(+), 15 deletions(-)

diff --git a/db/db_bench.cc b/db/db_bench.cc
index 886b38a80..476b0c856 100644
--- a/db/db_bench.cc
+++ b/db/db_bench.cc
@@ -171,6 +171,10 @@ static enum leveldb::CompressionType FLAGS_compression_type =
 // posix or hdfs environment
 static leveldb::Env* FLAGS_env = leveldb::Env::Default();
 
+// Stats are reported every N operations when this is greater
+// than zero. When 0 the interval grows over time.
+static int FLAGS_stats_interval = 0;
+
 extern bool useOsBuffer;
 extern bool useFsReadAhead;
 extern bool useMmapRead;
@@ -232,28 +236,34 @@ static void AppendWithSpace(std::string* str, Slice msg) {
 
 class Stats {
  private:
+  int id_;
   double start_;
   double finish_;
   double seconds_;
   long done_;
+  long last_report_done_;
   int next_report_;
   int64_t bytes_;
   double last_op_finish_;
+  double last_report_finish_;
   Histogram hist_;
   std::string message_;
 
  public:
-  Stats() { Start(); }
+  Stats() { Start(-1); }
 
-  void Start() {
-    next_report_ = 100;
+  void Start(int id) {
+    id_ = id;
+    next_report_ = FLAGS_stats_interval ? FLAGS_stats_interval : 100;
     last_op_finish_ = start_;
     hist_.Clear();
     done_ = 0;
+    last_report_done_ = 0;
     bytes_ = 0;
     seconds_ = 0;
     start_ = FLAGS_env->NowMicros();
     finish_ = start_;
+    last_report_finish_ = start_;
     message_.clear();
   }
 
@@ -278,12 +288,14 @@ class Stats {
     AppendWithSpace(&message_, msg);
   }
 
+  void SetId(int id) { id_ = id; }
+
   void FinishedSingleOp() {
     if (FLAGS_histogram) {
       double now = FLAGS_env->NowMicros();
       double micros = now - last_op_finish_;
       hist_.Add(micros);
-      if (micros > 20000) {
+      if (micros > 20000 && !FLAGS_stats_interval) {
         fprintf(stderr, "long op: %.1f micros%30s\r", micros, "");
         fflush(stderr);
       }
@@ -292,15 +304,30 @@ class Stats {
 
     done_++;
     if (done_ >= next_report_) {
-      if      (next_report_ < 1000)   next_report_ += 100;
-      else if (next_report_ < 5000)   next_report_ += 500;
-      else if (next_report_ < 10000)  next_report_ += 1000;
-      else if (next_report_ < 50000)  next_report_ += 5000;
-      else if (next_report_ < 100000) next_report_ += 10000;
-      else if (next_report_ < 500000) next_report_ += 50000;
-      else                            next_report_ += 100000;
-      fprintf(stderr, "... finished %ld ops%30s\r", done_, "");
-      fflush(stderr);
+      if (!FLAGS_stats_interval) {
+        if      (next_report_ < 1000)   next_report_ += 100;
+        else if (next_report_ < 5000)   next_report_ += 500;
+        else if (next_report_ < 10000)  next_report_ += 1000;
+        else if (next_report_ < 50000)  next_report_ += 5000;
+        else if (next_report_ < 100000) next_report_ += 10000;
+        else if (next_report_ < 500000) next_report_ += 50000;
+        else                            next_report_ += 100000;
+        fprintf(stderr, "... finished %ld ops%30s\r", done_, "");
+        fflush(stderr);
+      } else {
+        double now = FLAGS_env->NowMicros();
+        fprintf(stderr,
+                "... thread %d: %ld ops in %.6f seconds and %.2f ops/sec\n",
+                id_,
+                done_ - last_report_done_,
+                (now - last_report_finish_) / 1000000.0,
+                (done_ - last_report_done_) /
+                ((now - last_report_finish_) / 1000000.0));
+        fflush(stderr);
+        next_report_ += FLAGS_stats_interval;
+        last_report_finish_ = now;
+        last_report_done_ = done_;
+      }
     }
   }
 
@@ -695,7 +722,7 @@ class Benchmark {
       }
     }
 
-    thread->stats.Start();
+    thread->stats.Start(thread->tid);
     (arg->bm->*(arg->method))(thread);
     thread->stats.Stop();
 
@@ -1042,7 +1069,7 @@ class Benchmark {
       }
 
       // Do not count any of the preceding work/delay in stats.
-      thread->stats.Start();
+      thread->stats.Start(thread->tid);
     }
   }
 
@@ -1252,6 +1279,9 @@ int main(int argc, char** argv) {
     } else if (sscanf(argv[i], "--disable_seek_compaction=%d%c", &n, &junk) == 1
         && (n == 0 || n == 1)) {
       FLAGS_disable_seek_compaction = n;
+    } else if (sscanf(argv[i], "--stats_interval=%d%c", &n, &junk) == 1 &&
+               n >= 0 && n < 2000000000) {
+      FLAGS_stats_interval = n;
     } else {
       fprintf(stderr, "Invalid flag '%s'\n", argv[i]);
       exit(1);