add TimedEnv

Summary:
I've needed Env timing measurements a few times now, so finally built something for it.
Closes https://github.com/facebook/rocksdb/pull/2073

Differential Revision: D4811231

Pulled By: ajkr

fbshipit-source-id: 218a249

CMakeLists.txt

@@ -435,6 +435,7 @@ set(SOURCES
         utilities/document/json_document.cc
         utilities/document/json_document_builder.cc
         utilities/env_mirror.cc
+        utilities/env_timed.cc
         utilities/geodb/geodb_impl.cc
         utilities/leveldb_options/leveldb_options.cc
         utilities/lua/rocks_lua_compaction_filter.cc

Makefile

@@ -426,6 +426,7 @@ TESTS = \
 	lru_cache_test \
 	object_registry_test \
 	repair_test \
+	env_timed_test \
 
 PARALLEL_TEST = \
 	backupable_db_test \
@@ -1094,6 +1095,9 @@ spatial_db_test: utilities/spatialdb/spatial_db_test.o $(LIBOBJECTS) $(TESTHARNE
 env_mirror_test: utilities/env_mirror_test.o $(LIBOBJECTS) $(TESTHARNESS)
 	$(AM_LINK)
 
+env_timed_test: utilities/env_timed_test.o $(LIBOBJECTS) $(TESTHARNESS)
+	$(AM_LINK)
+
 ifdef ROCKSDB_USE_LIBRADOS
 env_librados_test: utilities/env_librados_test.o $(LIBOBJECTS) $(TESTHARNESS)
 	$(AM_V_CCLD)$(CXX) $^ $(EXEC_LDFLAGS) -o $@ $(LDFLAGS) $(COVERAGEFLAGS)

include/rocksdb/env.h

@@ -1093,6 +1093,11 @@ Env* NewMemEnv(Env* base_env);
 // This is a factory method for HdfsEnv declared in hdfs/env_hdfs.h
 Status NewHdfsEnv(Env** hdfs_env, const std::string& fsname);
 
+// Returns a new environment that measures function call times for filesystem
+// operations, reporting results to variables in PerfContext.
+// This is a factory method for TimedEnv defined in utilities/env_timed.cc.
+Env* NewTimedEnv(Env* base_env);
+
 }  // namespace rocksdb
 
 #endif  // STORAGE_ROCKSDB_INCLUDE_ENV_H_

include/rocksdb/perf_context.h

@@ -125,6 +125,29 @@ struct PerfContext {
   uint64_t bloom_sst_hit_count;
   // total number of SST table bloom misses
   uint64_t bloom_sst_miss_count;
+
+  // Total time spent in Env filesystem operations. These are only populated
+  // when TimedEnv is used.
+  uint64_t env_new_sequential_file_nanos;
+  uint64_t env_new_random_access_file_nanos;
+  uint64_t env_new_writable_file_nanos;
+  uint64_t env_reuse_writable_file_nanos;
+  uint64_t env_new_random_rw_file_nanos;
+  uint64_t env_new_directory_nanos;
+  uint64_t env_file_exists_nanos;
+  uint64_t env_get_children_nanos;
+  uint64_t env_get_children_file_attributes_nanos;
+  uint64_t env_delete_file_nanos;
+  uint64_t env_create_dir_nanos;
+  uint64_t env_create_dir_if_missing_nanos;
+  uint64_t env_delete_dir_nanos;
+  uint64_t env_get_file_size_nanos;
+  uint64_t env_get_file_modification_time_nanos;
+  uint64_t env_rename_file_nanos;
+  uint64_t env_link_file_nanos;
+  uint64_t env_lock_file_nanos;
+  uint64_t env_unlock_file_nanos;
+  uint64_t env_new_logger_nanos;
 };
 
 #if defined(NPERF_CONTEXT) || defined(IOS_CROSS_COMPILE)

src.mk

@@ -153,6 +153,7 @@ LIB_SOURCES =                                                   \
   utilities/document/json_document_builder.cc                   \
   utilities/document/json_document.cc                           \
   utilities/env_mirror.cc                                       \
+  utilities/env_timed.cc                                        \
   utilities/geodb/geodb_impl.cc                                 \
   utilities/leveldb_options/leveldb_options.cc                  \
   utilities/lua/rocks_lua_compaction_filter.cc                  \

util/perf_context.cc

@@ -62,6 +62,27 @@ void PerfContext::Reset() {
   bloom_memtable_miss_count = 0;
   bloom_sst_hit_count = 0;
   bloom_sst_miss_count = 0;
+
+  env_new_sequential_file_nanos = 0;
+  env_new_random_access_file_nanos = 0;
+  env_new_writable_file_nanos = 0;
+  env_reuse_writable_file_nanos = 0;
+  env_new_random_rw_file_nanos = 0;
+  env_new_directory_nanos = 0;
+  env_file_exists_nanos = 0;
+  env_get_children_nanos = 0;
+  env_get_children_file_attributes_nanos = 0;
+  env_delete_file_nanos = 0;
+  env_create_dir_nanos = 0;
+  env_create_dir_if_missing_nanos = 0;
+  env_delete_dir_nanos = 0;
+  env_get_file_size_nanos = 0;
+  env_get_file_modification_time_nanos = 0;
+  env_rename_file_nanos = 0;
+  env_link_file_nanos = 0;
+  env_lock_file_nanos = 0;
+  env_unlock_file_nanos = 0;
+  env_new_logger_nanos = 0;
 #endif
 }
 
@@ -117,6 +138,26 @@ std::string PerfContext::ToString(bool exclude_zero_counters) const {
   PERF_CONTEXT_OUTPUT(bloom_memtable_miss_count);
   PERF_CONTEXT_OUTPUT(bloom_sst_hit_count);
   PERF_CONTEXT_OUTPUT(bloom_sst_miss_count);
+  PERF_CONTEXT_OUTPUT(env_new_sequential_file_nanos);
+  PERF_CONTEXT_OUTPUT(env_new_random_access_file_nanos);
+  PERF_CONTEXT_OUTPUT(env_new_writable_file_nanos);
+  PERF_CONTEXT_OUTPUT(env_reuse_writable_file_nanos);
+  PERF_CONTEXT_OUTPUT(env_new_random_rw_file_nanos);
+  PERF_CONTEXT_OUTPUT(env_new_directory_nanos);
+  PERF_CONTEXT_OUTPUT(env_file_exists_nanos);
+  PERF_CONTEXT_OUTPUT(env_get_children_nanos);
+  PERF_CONTEXT_OUTPUT(env_get_children_file_attributes_nanos);
+  PERF_CONTEXT_OUTPUT(env_delete_file_nanos);
+  PERF_CONTEXT_OUTPUT(env_create_dir_nanos);
+  PERF_CONTEXT_OUTPUT(env_create_dir_if_missing_nanos);
+  PERF_CONTEXT_OUTPUT(env_delete_dir_nanos);
+  PERF_CONTEXT_OUTPUT(env_get_file_size_nanos);
+  PERF_CONTEXT_OUTPUT(env_get_file_modification_time_nanos);
+  PERF_CONTEXT_OUTPUT(env_rename_file_nanos);
+  PERF_CONTEXT_OUTPUT(env_link_file_nanos);
+  PERF_CONTEXT_OUTPUT(env_lock_file_nanos);
+  PERF_CONTEXT_OUTPUT(env_unlock_file_nanos);
+  PERF_CONTEXT_OUTPUT(env_new_logger_nanos);
   return ss.str();
 #endif
 }

utilities/env_timed.cc

@@ -0,0 +1,148 @@
+// Copyright (c) 2017-present, Facebook, Inc.  All rights reserved.
+// This source code is licensed under the BSD-style license found in the
+// 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 "rocksdb/env.h"
+#include "rocksdb/status.h"
+#include "util/perf_context_imp.h"
+
+namespace rocksdb {
+
+#ifndef ROCKSDB_LITE
+
+// An environment that measures function call times for filesystem
+// operations, reporting results to variables in PerfContext.
+class TimedEnv : public EnvWrapper {
+ public:
+  explicit TimedEnv(Env* base_env) : EnvWrapper(base_env) {}
+
+  virtual Status NewSequentialFile(const std::string& fname,
+                                   unique_ptr<SequentialFile>* result,
+                                   const EnvOptions& options) override {
+    PERF_TIMER_GUARD(env_new_sequential_file_nanos);
+    return EnvWrapper::NewSequentialFile(fname, result, options);
+  }
+
+  virtual Status NewRandomAccessFile(const std::string& fname,
+                                     unique_ptr<RandomAccessFile>* result,
+                                     const EnvOptions& options) override {
+    PERF_TIMER_GUARD(env_new_random_access_file_nanos);
+    return EnvWrapper::NewRandomAccessFile(fname, result, options);
+  }
+
+  virtual Status NewWritableFile(const std::string& fname,
+                                 unique_ptr<WritableFile>* result,
+                                 const EnvOptions& options) override {
+    PERF_TIMER_GUARD(env_new_writable_file_nanos);
+    return EnvWrapper::NewWritableFile(fname, result, options);
+  }
+
+  virtual Status ReuseWritableFile(const std::string& fname,
+                                   const std::string& old_fname,
+                                   unique_ptr<WritableFile>* result,
+                                   const EnvOptions& options) override {
+    PERF_TIMER_GUARD(env_reuse_writable_file_nanos);
+    return EnvWrapper::ReuseWritableFile(fname, old_fname, result, options);
+  }
+
+  virtual Status NewRandomRWFile(const std::string& fname,
+                                 unique_ptr<RandomRWFile>* result,
+                                 const EnvOptions& options) override {
+    PERF_TIMER_GUARD(env_new_random_rw_file_nanos);
+    return EnvWrapper::NewRandomRWFile(fname, result, options);
+  }
+
+  virtual Status NewDirectory(const std::string& name,
+                              unique_ptr<Directory>* result) override {
+    PERF_TIMER_GUARD(env_new_directory_nanos);
+    return EnvWrapper::NewDirectory(name, result);
+  }
+
+  virtual Status FileExists(const std::string& fname) override {
+    PERF_TIMER_GUARD(env_file_exists_nanos);
+    return EnvWrapper::FileExists(fname);
+  }
+
+  virtual Status GetChildren(const std::string& dir,
+                             std::vector<std::string>* result) override {
+    PERF_TIMER_GUARD(env_get_children_nanos);
+    return EnvWrapper::GetChildren(dir, result);
+  }
+
+  virtual Status GetChildrenFileAttributes(
+      const std::string& dir, std::vector<FileAttributes>* result) override {
+    PERF_TIMER_GUARD(env_get_children_file_attributes_nanos);
+    return EnvWrapper::GetChildrenFileAttributes(dir, result);
+  }
+
+  virtual Status DeleteFile(const std::string& fname) override {
+    PERF_TIMER_GUARD(env_delete_file_nanos);
+    return EnvWrapper::DeleteFile(fname);
+  }
+
+  virtual Status CreateDir(const std::string& dirname) override {
+    PERF_TIMER_GUARD(env_create_dir_nanos);
+    return EnvWrapper::CreateDir(dirname);
+  }
+
+  virtual Status CreateDirIfMissing(const std::string& dirname) override {
+    PERF_TIMER_GUARD(env_create_dir_if_missing_nanos);
+    return EnvWrapper::CreateDirIfMissing(dirname);
+  }
+
+  virtual Status DeleteDir(const std::string& dirname) override {
+    PERF_TIMER_GUARD(env_delete_dir_nanos);
+    return EnvWrapper::DeleteDir(dirname);
+  }
+
+  virtual Status GetFileSize(const std::string& fname,
+                             uint64_t* file_size) override {
+    PERF_TIMER_GUARD(env_get_file_size_nanos);
+    return EnvWrapper::GetFileSize(fname, file_size);
+  }
+
+  virtual Status GetFileModificationTime(const std::string& fname,
+                                         uint64_t* file_mtime) override {
+    PERF_TIMER_GUARD(env_get_file_modification_time_nanos);
+    return EnvWrapper::GetFileModificationTime(fname, file_mtime);
+  }
+
+  virtual Status RenameFile(const std::string& src,
+                            const std::string& dst) override {
+    PERF_TIMER_GUARD(env_rename_file_nanos);
+    return EnvWrapper::RenameFile(src, dst);
+  }
+
+  virtual Status LinkFile(const std::string& src,
+                          const std::string& dst) override {
+    PERF_TIMER_GUARD(env_link_file_nanos);
+    return EnvWrapper::LinkFile(src, dst);
+  }
+
+  virtual Status LockFile(const std::string& fname, FileLock** lock) override {
+    PERF_TIMER_GUARD(env_lock_file_nanos);
+    return EnvWrapper::LockFile(fname, lock);
+  }
+
+  virtual Status UnlockFile(FileLock* lock) override {
+    PERF_TIMER_GUARD(env_unlock_file_nanos);
+    return EnvWrapper::UnlockFile(lock);
+  }
+
+  virtual Status NewLogger(const std::string& fname,
+                           shared_ptr<Logger>* result) override {
+    PERF_TIMER_GUARD(env_new_logger_nanos);
+    return EnvWrapper::NewLogger(fname, result);
+  }
+};
+
+Env* NewTimedEnv(Env* base_env) { return new TimedEnv(base_env); }
+
+#else  // ROCKSDB_LITE
+
+Env* NewTimedEnv(Env* base_env) { return nullptr; }
+
+#endif  // !ROCKSDB_LITE
+
+}  // namespace rocksdb

utilities/env_timed_test.cc

@@ -0,0 +1,44 @@
+// Copyright (c) 2017-present, Facebook, Inc.  All rights reserved.
+// This source code is licensed under the BSD-style license found in the
+// 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.
+
+#ifndef ROCKSDB_LITE
+
+#include "rocksdb/env.h"
+#include "rocksdb/perf_context.h"
+#include "util/testharness.h"
+
+namespace rocksdb {
+
+class TimedEnvTest : public testing::Test {
+};
+
+TEST_F(TimedEnvTest, BasicTest) {
+  SetPerfLevel(PerfLevel::kEnableTime);
+  ASSERT_EQ(0, perf_context.env_new_writable_file_nanos);
+
+  std::unique_ptr<Env> mem_env(NewMemEnv(Env::Default()));
+  std::unique_ptr<Env> timed_env(NewTimedEnv(mem_env.get()));
+  std::unique_ptr<WritableFile> writable_file;
+  timed_env->NewWritableFile("f", &writable_file, EnvOptions());
+
+  ASSERT_GT(perf_context.env_new_writable_file_nanos, 0);
+}
+
+}  // namespace rocksdb
+
+int main(int argc, char** argv) {
+  ::testing::InitGoogleTest(&argc, argv);
+  return RUN_ALL_TESTS();
+}
+
+#else  // ROCKSDB_LITE
+#include <stdio.h>
+
+int main(int argc, char** argv) {
+  fprintf(stderr, "SKIPPED as TimedEnv is not supported in ROCKSDB_LITE\n");
+  return 0;
+}
+
+#endif  // ROCKSDB_LITE