From e4dcf5fd22509ae6741733a0f02feb7b68421f55 Mon Sep 17 00:00:00 2001 From: sdong Date: Wed, 3 Jul 2019 19:03:29 -0700 Subject: [PATCH] db_bench to add a new "benchmark" to print out all stats history (#5532) Summary: Sometimes it is helpful to fetch the whole history of stats after benchmark runs. Add such an option Pull Request resolved: https://github.com/facebook/rocksdb/pull/5532 Test Plan: Run the benchmark manually and observe the output is as expected. Differential Revision: D16097764 fbshipit-source-id: 10b5b735a22a18be198b8f348be11f11f8806904 --- HISTORY.md | 1 + tools/db_bench_tool.cc | 36 ++++++++++++++++++++++++++++++++++++ tools/ldb_cmd.cc | 32 +++++++++++--------------------- util/string_util.cc | 11 +++++++++++ util/string_util.h | 4 ++++ 5 files changed, 63 insertions(+), 21 deletions(-) diff --git a/HISTORY.md b/HISTORY.md index c3af6ba06..6e0fcc54e 100644 --- a/HISTORY.md +++ b/HISTORY.md @@ -13,6 +13,7 @@ * Accessing a partition of a partitioned filter or index through a pinned reference is no longer considered a cache hit. * The semantics of the per-block-type block read counts in the performance context now match those of the generic block_read_count. * Add C bindings for secondary instance, i.e. DBImplSecondary. +* db_bench adds a "benchmark" stats_history, which prints out the whole stats history. ### New Features * Add an option `snap_refresh_nanos` (default to 0.1s) to periodically refresh the snapshot list in compaction jobs. Assign to 0 to disable the feature. diff --git a/tools/db_bench_tool.cc b/tools/db_bench_tool.cc index abffae5d9..39f9eebc7 100644 --- a/tools/db_bench_tool.cc +++ b/tools/db_bench_tool.cc @@ -49,6 +49,7 @@ #include "rocksdb/rate_limiter.h" #include "rocksdb/slice.h" #include "rocksdb/slice_transform.h" +#include "rocksdb/stats_history.h" #include "rocksdb/utilities/object_registry.h" #include "rocksdb/utilities/optimistic_transaction_db.h" #include "rocksdb/utilities/options_util.h" @@ -2867,6 +2868,8 @@ class Benchmark { PrintStats("rocksdb.levelstats"); } else if (name == "sstables") { PrintStats("rocksdb.sstables"); + } else if (name == "stats_history") { + PrintStatsHistory(); } else if (name == "replay") { if (num_threads > 1) { fprintf(stderr, "Multi-threaded replay is not yet supported\n"); @@ -6259,6 +6262,39 @@ class Benchmark { } } + void PrintStatsHistory() { + if (db_.db != nullptr) { + PrintStatsHistoryImpl(db_.db, false); + } + for (const auto& db_with_cfh : multi_dbs_) { + PrintStatsHistoryImpl(db_with_cfh.db, true); + } + } + + void PrintStatsHistoryImpl(DB* db, bool print_header) { + if (print_header) { + fprintf(stdout, "\n==== DB: %s ===\n", db->GetName().c_str()); + } + + std::unique_ptr shi; + Status s = db->GetStatsHistory(0, port::kMaxUint64, &shi); + if (!s.ok()) { + fprintf(stdout, "%s\n", s.ToString().c_str()); + return; + } + assert(shi); + while (shi->Valid()) { + uint64_t stats_time = shi->GetStatsTime(); + fprintf(stdout, "------ %s ------\n", + TimeToHumanString(static_cast(stats_time)).c_str()); + for (auto& entry : shi->GetStatsMap()) { + fprintf(stdout, " %" PRIu64 " %s %" PRIu64 "\n", stats_time, + entry.first.c_str(), entry.second); + } + shi->Next(); + } + } + void PrintStats(const char* key) { if (db_.db != nullptr) { PrintStats(db_.db, key, false); diff --git a/tools/ldb_cmd.cc b/tools/ldb_cmd.cc index a1507b188..fba32d9d6 100644 --- a/tools/ldb_cmd.cc +++ b/tools/ldb_cmd.cc @@ -859,8 +859,7 @@ void CompactorCommand::DoCommand() { delete end; } -// ---------------------------------------------------------------------------- - +// --------------------------------------------------------------------------- const std::string DBLoaderCommand::ARG_DISABLE_WAL = "disable_wal"; const std::string DBLoaderCommand::ARG_BULK_LOAD = "bulk_load"; const std::string DBLoaderCommand::ARG_COMPACT = "compact"; @@ -1168,19 +1167,8 @@ void DropColumnFamilyCommand::DoCommand() { } // ---------------------------------------------------------------------------- - namespace { -std::string ReadableTime(int unixtime) { - char time_buffer [80]; - time_t rawtime = unixtime; - struct tm tInfo; - struct tm* timeinfo = localtime_r(&rawtime, &tInfo); - assert(timeinfo == &tInfo); - strftime(time_buffer, 80, "%c", timeinfo); - return std::string(time_buffer); -} - // This function only called when it's the sane case of >1 buckets in time-range // Also called only when timekv falls between ttl_start and ttl_end provided void IncBucketCounts(std::vector& bucket_counts, int ttl_start, @@ -1202,13 +1190,13 @@ void PrintBucketCounts(const std::vector& bucket_counts, int time_point = ttl_start; for(int i = 0; i < num_buckets - 1; i++, time_point += bucket_size) { fprintf(stdout, "Keys in range %s to %s : %lu\n", - ReadableTime(time_point).c_str(), - ReadableTime(time_point + bucket_size).c_str(), + TimeToHumanString(time_point).c_str(), + TimeToHumanString(time_point + bucket_size).c_str(), (unsigned long)bucket_counts[i]); } fprintf(stdout, "Keys in range %s to %s : %lu\n", - ReadableTime(time_point).c_str(), - ReadableTime(ttl_end).c_str(), + TimeToHumanString(time_point).c_str(), + TimeToHumanString(ttl_end).c_str(), (unsigned long)bucket_counts[num_buckets - 1]); } @@ -1564,7 +1552,8 @@ void DBDumperCommand::DoDumpCommand() { std::vector bucket_counts(num_buckets, 0); if (is_db_ttl_ && !count_only_ && timestamp_ && !count_delim_) { fprintf(stdout, "Dumping key-values from %s to %s\n", - ReadableTime(ttl_start).c_str(), ReadableTime(ttl_end).c_str()); + TimeToHumanString(ttl_start).c_str(), + TimeToHumanString(ttl_end).c_str()); } HistogramImpl vsize_hist; @@ -1619,7 +1608,7 @@ void DBDumperCommand::DoDumpCommand() { if (!count_only_ && !count_delim_) { if (is_db_ttl_ && timestamp_) { - fprintf(stdout, "%s ", ReadableTime(rawtime).c_str()); + fprintf(stdout, "%s ", TimeToHumanString(rawtime).c_str()); } std::string str = PrintKeyValue(iter->key().ToString(), iter->value().ToString(), @@ -2397,7 +2386,8 @@ void ScanCommand::DoCommand() { } if (is_db_ttl_ && timestamp_) { fprintf(stdout, "Scanning key-values from %s to %s\n", - ReadableTime(ttl_start).c_str(), ReadableTime(ttl_end).c_str()); + TimeToHumanString(ttl_start).c_str(), + TimeToHumanString(ttl_end).c_str()); } for ( ; it->Valid() && (!end_key_specified_ || it->key().ToString() < end_key_); @@ -2409,7 +2399,7 @@ void ScanCommand::DoCommand() { continue; } if (timestamp_) { - fprintf(stdout, "%s ", ReadableTime(rawtime).c_str()); + fprintf(stdout, "%s ", TimeToHumanString(rawtime).c_str()); } } diff --git a/util/string_util.cc b/util/string_util.cc index 74f6afbf0..9b447d50c 100644 --- a/util/string_util.cc +++ b/util/string_util.cc @@ -18,6 +18,7 @@ #include #include "rocksdb/env.h" #include "port/port.h" +#include "port/sys_time.h" #include "rocksdb/slice.h" namespace rocksdb { @@ -139,6 +140,16 @@ std::string BytesToHumanString(uint64_t bytes) { return std::string(buf); } +std::string TimeToHumanString(int unixtime) { + char time_buffer[80]; + time_t rawtime = unixtime; + struct tm tInfo; + struct tm* timeinfo = localtime_r(&rawtime, &tInfo); + assert(timeinfo == &tInfo); + strftime(time_buffer, 80, "%c", timeinfo); + return std::string(time_buffer); +} + std::string EscapeString(const Slice& value) { std::string r; AppendEscapedStringTo(&r, value); diff --git a/util/string_util.h b/util/string_util.h index 6e125ddfa..faf763e54 100644 --- a/util/string_util.h +++ b/util/string_util.h @@ -50,6 +50,10 @@ extern std::string NumberToHumanString(int64_t num); // ex: 1048576 -> 1.00 GB extern std::string BytesToHumanString(uint64_t bytes); +// Return a human-readable version of unix time +// ex: 1562116015 -> "Tue Jul 2 18:06:55 2019" +extern std::string TimeToHumanString(int unixtime); + // Append a human-readable time in micros. int AppendHumanMicros(uint64_t micros, char* output, int len, bool fixed_format);