diff --git a/db/perf_context_test.cc b/db/perf_context_test.cc index adab6d78e..487f6de7e 100644 --- a/db/perf_context_test.cc +++ b/db/perf_context_test.cc @@ -9,16 +9,16 @@ #include #include "rocksdb/db.h" +#include "rocksdb/memtablerep.h" #include "rocksdb/perf_context.h" #include "rocksdb/slice_transform.h" -#include "rocksdb/memtablerep.h" #include "util/histogram.h" #include "util/instrumented_mutex.h" #include "util/stop_watch.h" +#include "util/string_util.h" #include "util/testharness.h" #include "util/thread_status_util.h" -#include "util/string_util.h" - +#include "utilities/merge_operators.h" bool FLAGS_random_key = false; bool FLAGS_use_set_based_memetable = false; @@ -602,6 +602,41 @@ TEST_F(PerfContextTest, ToString) { ASSERT_EQ(std::string::npos, zero_excluded.find("= 0")); ASSERT_NE(std::string::npos, zero_excluded.find("= 12345")); } + +TEST_F(PerfContextTest, MergeOperatorTime) { + DestroyDB(kDbName, Options()); + DB* db; + Options options; + options.create_if_missing = true; + options.merge_operator = MergeOperators::CreateStringAppendOperator(); + Status s = DB::Open(options, kDbName, &db); + EXPECT_OK(s); + + std::string val; + ASSERT_OK(db->Merge(WriteOptions(), "k1", "val1")); + ASSERT_OK(db->Merge(WriteOptions(), "k1", "val2")); + ASSERT_OK(db->Merge(WriteOptions(), "k1", "val3")); + ASSERT_OK(db->Merge(WriteOptions(), "k1", "val4")); + + SetPerfLevel(kEnableTime); + perf_context.Reset(); + ASSERT_OK(db->Get(ReadOptions(), "k1", &val)); + EXPECT_GT(perf_context.merge_operator_time_nanos, 0); + + ASSERT_OK(db->Flush(FlushOptions())); + + perf_context.Reset(); + ASSERT_OK(db->Get(ReadOptions(), "k1", &val)); + EXPECT_GT(perf_context.merge_operator_time_nanos, 0); + + ASSERT_OK(db->CompactRange(CompactRangeOptions(), nullptr, nullptr)); + + perf_context.Reset(); + ASSERT_OK(db->Get(ReadOptions(), "k1", &val)); + EXPECT_GT(perf_context.merge_operator_time_nanos, 0); + + delete db; +} } int main(int argc, char** argv) { diff --git a/db/version_set.cc b/db/version_set.cc index 707de2f99..75140ed42 100644 --- a/db/version_set.cc +++ b/db/version_set.cc @@ -23,6 +23,7 @@ #include #include +#include "db/compaction.h" #include "db/filename.h" #include "db/internal_stats.h" #include "db/log_reader.h" @@ -30,22 +31,22 @@ #include "db/memtable.h" #include "db/merge_context.h" #include "db/table_cache.h" -#include "db/compaction.h" #include "db/version_builder.h" #include "db/writebuffer.h" #include "rocksdb/env.h" #include "rocksdb/merge_operator.h" +#include "table/format.h" +#include "table/get_context.h" #include "table/internal_iterator.h" -#include "table/table_reader.h" #include "table/merger.h" -#include "table/two_level_iterator.h" -#include "table/format.h" -#include "table/plain_table_factory.h" #include "table/meta_blocks.h" -#include "table/get_context.h" +#include "table/plain_table_factory.h" +#include "table/table_reader.h" +#include "table/two_level_iterator.h" #include "util/coding.h" #include "util/file_reader_writer.h" #include "util/logging.h" +#include "util/perf_context_imp.h" #include "util/stop_watch.h" #include "util/sync_point.h" @@ -948,9 +949,16 @@ void Version::Get(const ReadOptions& read_options, const LookupKey& k, } // merge_operands are in saver and we hit the beginning of the key history // do a final merge of nullptr and operands; - if (merge_operator_->FullMerge(user_key, nullptr, - merge_context->GetOperands(), value, - info_log_)) { + bool merge_success = false; + { + StopWatchNano timer(env_, db_statistics_ != nullptr); + PERF_TIMER_GUARD(merge_operator_time_nanos); + merge_success = merge_operator_->FullMerge( + user_key, nullptr, merge_context->GetOperands(), value, info_log_); + RecordTick(db_statistics_, MERGE_OPERATION_TOTAL_TIME, + timer.ElapsedNanos()); + } + if (merge_success) { *status = Status::OK(); } else { RecordTick(db_statistics_, NUMBER_MERGE_FAILURES);