From e2c6c063664cf66468f7fdcf4a3a5e4ed7e7bb2f Mon Sep 17 00:00:00 2001 From: Andrew Kryczka Date: Tue, 4 Apr 2017 11:12:47 -0700 Subject: [PATCH] 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 | 1 + Makefile | 4 + include/rocksdb/env.h | 5 ++ include/rocksdb/perf_context.h | 23 +++++ src.mk | 1 + util/perf_context.cc | 41 +++++++++ utilities/env_timed.cc | 148 +++++++++++++++++++++++++++++++++ utilities/env_timed_test.cc | 44 ++++++++++ 8 files changed, 267 insertions(+) create mode 100644 utilities/env_timed.cc create mode 100644 utilities/env_timed_test.cc diff --git a/CMakeLists.txt b/CMakeLists.txt index 678a32782..d87ff931b 100644 --- a/CMakeLists.txt +++ b/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 diff --git a/Makefile b/Makefile index dc8aaf09d..e7959e5f1 100644 --- a/Makefile +++ b/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) diff --git a/include/rocksdb/env.h b/include/rocksdb/env.h index 9ebba61c3..7337a5fc6 100644 --- a/include/rocksdb/env.h +++ b/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_ diff --git a/include/rocksdb/perf_context.h b/include/rocksdb/perf_context.h index 7d20c846b..80598bb2f 100644 --- a/include/rocksdb/perf_context.h +++ b/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) diff --git a/src.mk b/src.mk index 3ca56f98c..35c6fbf31 100644 --- a/src.mk +++ b/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 \ diff --git a/util/perf_context.cc b/util/perf_context.cc index 2eff8c192..b124f8d0f 100644 --- a/util/perf_context.cc +++ b/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 } diff --git a/utilities/env_timed.cc b/utilities/env_timed.cc new file mode 100644 index 000000000..fc4fe3714 --- /dev/null +++ b/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* 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* 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* 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* 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* 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* 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* result) override { + PERF_TIMER_GUARD(env_get_children_nanos); + return EnvWrapper::GetChildren(dir, result); + } + + virtual Status GetChildrenFileAttributes( + const std::string& dir, std::vector* 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* 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 diff --git a/utilities/env_timed_test.cc b/utilities/env_timed_test.cc new file mode 100644 index 000000000..8031f24f1 --- /dev/null +++ b/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 mem_env(NewMemEnv(Env::Default())); + std::unique_ptr timed_env(NewTimedEnv(mem_env.get())); + std::unique_ptr 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 + +int main(int argc, char** argv) { + fprintf(stderr, "SKIPPED as TimedEnv is not supported in ROCKSDB_LITE\n"); + return 0; +} + +#endif // ROCKSDB_LITE