From d91b42ee27cb7ef744a85ea8e18c0cfb7abf3090 Mon Sep 17 00:00:00 2001
From: Abhishek Kona <abhishekk@fb.com>
Date: Wed, 5 Jun 2013 11:06:21 -0700
Subject: [PATCH] [Rocksdb] Measure all FSYNC/SYNC times

Summary: Add stop watches around all sync calls.

Test Plan: db_bench check if respective histograms are printed

Reviewers: haobo, dhruba

Reviewed By: haobo

CC: leveldb

Differential Revision: https://reviews.facebook.net/D11073
---
 db/builder.cc                | 3 +++
 db/db_bench.cc               | 6 ++++++
 db/db_impl.cc                | 4 ++++
 db/version_set.cc            | 3 +++
 include/leveldb/statistics.h | 7 ++++++-
 5 files changed, 22 insertions(+), 1 deletion(-)

diff --git a/db/builder.cc b/db/builder.cc
index 98e43195c..afeafba2e 100644
--- a/db/builder.cc
+++ b/db/builder.cc
@@ -12,6 +12,7 @@
 #include "leveldb/db.h"
 #include "leveldb/env.h"
 #include "leveldb/iterator.h"
+#include "util/stop_watch.h"
 
 namespace leveldb {
 
@@ -147,8 +148,10 @@ Status BuildTable(const std::string& dbname,
     // Finish and check for file errors
     if (s.ok() && !options.disableDataSync) {
       if (options.use_fsync) {
+        StopWatch sw(env, options.statistics, TABLE_SYNC_MICROS);
         s = file->Fsync();
       } else {
+        StopWatch sw(env, options.statistics, TABLE_SYNC_MICROS);
         s = file->Sync();
       }
     }
diff --git a/db/db_bench.cc b/db/db_bench.cc
index 8a56f5d50..157ea34bf 100644
--- a/db/db_bench.cc
+++ b/db/db_bench.cc
@@ -736,6 +736,12 @@ class Benchmark {
       PrintHistogram(DB_GET, "DB_GET");
       PrintHistogram(DB_WRITE, "DB_WRITE");
       PrintHistogram(COMPACTION_TIME, "COMPACTION_TIME");
+      PrintHistogram(TABLE_SYNC_MICROS, "TABLE SYNC MICROS");
+      PrintHistogram(
+        COMPACTION_OUTFILE_SYNC_MICROS,
+        "COMPACTION OUT FILE SYNC MICROS");
+      PrintHistogram(WAL_FILE_SYNC_MICROS, "WAL FILE SYNC MICROS");
+      PrintHistogram(MANIFEST_FILE_SYNC_MICROS, "Manifest SYNC MICROS");
     }
   }
 
diff --git a/db/db_impl.cc b/db/db_impl.cc
index 72192f0e9..9551e9c5e 100644
--- a/db/db_impl.cc
+++ b/db/db_impl.cc
@@ -1523,8 +1523,10 @@ Status DBImpl::FinishCompactionOutputFile(CompactionState* compact,
   // Finish and check for file errors
   if (s.ok() && !options_.disableDataSync) {
     if (options_.use_fsync) {
+      StopWatch sw(env_, options_.statistics, COMPACTION_OUTFILE_SYNC_MICROS);
       s = compact->outfile->Fsync();
     } else {
+      StopWatch sw(env_, options_.statistics, COMPACTION_OUTFILE_SYNC_MICROS);
       s = compact->outfile->Sync();
     }
   }
@@ -2128,8 +2130,10 @@ Status DBImpl::Write(const WriteOptions& options, WriteBatch* my_batch) {
         status = log_->AddRecord(WriteBatchInternal::Contents(updates));
         if (status.ok() && options.sync) {
           if (options_.use_fsync) {
+            StopWatch(env_, options_.statistics, WAL_FILE_SYNC_MICROS);
             status = log_->file()->Fsync();
           } else {
+            StopWatch(env_, options_.statistics, WAL_FILE_SYNC_MICROS);
             status = log_->file()->Sync();
           }
         }
diff --git a/db/version_set.cc b/db/version_set.cc
index f3d192658..fb277e628 100644
--- a/db/version_set.cc
+++ b/db/version_set.cc
@@ -18,6 +18,7 @@
 #include "table/two_level_iterator.h"
 #include "util/coding.h"
 #include "util/logging.h"
+#include "util/stop_watch.h"
 
 namespace leveldb {
 
@@ -1123,8 +1124,10 @@ Status VersionSet::LogAndApply(VersionEdit* edit, port::Mutex* mu,
       }
       if (s.ok()) {
         if (options_->use_fsync) {
+          StopWatch sw(env_, options_->statistics, MANIFEST_FILE_SYNC_MICROS);
           s = descriptor_log_->file()->Fsync();
         } else {
+          StopWatch sw(env_, options_->statistics, MANIFEST_FILE_SYNC_MICROS);
           s = descriptor_log_->file()->Sync();
         }
       }
diff --git a/include/leveldb/statistics.h b/include/leveldb/statistics.h
index b4ba11f59..852603413 100644
--- a/include/leveldb/statistics.h
+++ b/include/leveldb/statistics.h
@@ -62,7 +62,12 @@ enum Histograms {
   DB_GET = 0,
   DB_WRITE = 1,
   COMPACTION_TIME = 2,
-  HISTOGRAM_ENUM_MAX = 3,
+  TABLE_SYNC_MICROS = 3,
+  COMPACTION_OUTFILE_SYNC_MICROS = 4,
+  WAL_FILE_SYNC_MICROS = 5,
+  MANIFEST_FILE_SYNC_MICROS = 6,
+  HISTOGRAM_ENUM_MAX = 7
+
 };
 
 struct HistogramData {