Group rocksdb.sst.read.micros stat by IOActivity flush and compaction

[hx235]

Context:
The existing stat rocksdb.sst.read.micros does not reflect each of compaction and flush cases but aggregate them, which is not so helpful for us to understand IO read behavior of each of them.

Summary

• Update StopWatch and RandomAccessFileReader to record rocksdb.sst.read.micros and rocksdb.file.{flush/compaction}.read.micros
  • Fixed the default histogram in RandomAccessFileReader
• New field ReadOptions/IOOptions::io_activity; Pass ReadOptions through paths under db open, flush and compaction to where we can prepare IOOptions and pass it to RandomAccessFileReader
• Use thread_status_util for assertion in DbStressFSWrapper for continuous testing on we are passing correct io_activity under db open, flush and compaction

Test:

• Stress test
• Db bench 1: rocksdb.sst.read.micros COUNT ≈ sum of rocksdb.file.read.flush.micros's and rocksdb.file.read.compaction.micros's. (without blob)
  • May not be exactly the same due to HistogramStat::Add only guarantees atomic not accuracy across threads.

./db_bench -db=/dev/shm/testdb/ -statistics=true -benchmarks="fillseq" -key_size=32 -value_size=512 -num=50000 -write_buffer_size=655 -target_file_size_base=655 -disable_auto_compactions=false -compression_type=none -bloom_bits=3 (-use_plain_table=1 -prefix_size=10)

// BlockBasedTable
rocksdb.sst.read.micros P50 : 2.009374 P95 : 4.968548 P99 : 8.110362 P100 : 43.000000 COUNT : 40456 SUM : 114805
rocksdb.file.read.flush.micros P50 : 1.871841 P95 : 3.872407 P99 : 5.540541 P100 : 43.000000 COUNT : 2250 SUM : 6116
rocksdb.file.read.compaction.micros P50 : 2.023109 P95 : 5.029149 P99 : 8.196910 P100 : 26.000000 COUNT : 38206 SUM : 108689

// PlainTable
Does not apply

• Db bench 2: performance

Read

SETUP: db with 900 files

./db_bench -db=/dev/shm/testdb/ -benchmarks="fillseq" -key_size=32 -value_size=512 -num=50000 -write_buffer_size=655  -disable_auto_compactions=true -target_file_size_base=655 -compression_type=none

TEST: run till convergence

./db_bench -seed=1678564177044286 -use_existing_db=true -db=/dev/shm/testdb -benchmarks=readrandom[-X60] -statistics=true -num=1000000 -disable_auto_compactions=true -compression_type=none -bloom_bits=3

Pre-change
readrandom [AVG 60 runs] : 21568 (± 248) ops/sec
Post-change (no regression, -0.3%)
readrandom [AVG 60 runs] : 21486 (± 236) ops/sec

Compaction/Flush
TEST: run till convergence

./db_bench -db=/dev/shm/testdb2/ -seed=1678564177044286 -benchmarks="fillseq[-X60]" -key_size=32 -value_size=512 -num=50000 -write_buffer_size=655  -disable_auto_compactions=false -target_file_size_base=655 -compression_type=none

rocksdb.sst.read.micros  COUNT : 33820 
rocksdb.sst.read.flush.micros COUNT : 1800
rocksdb.sst.read.compaction.micros COUNT : 32020

Pre-change
fillseq [AVG 46 runs] : 1391 (± 214) ops/sec; 0.7 (± 0.1) MB/sec

Post-change (no regression, ~-0.4%)
fillseq [AVG 46 runs] : 1385 (± 216) ops/sec; 0.7 (± 0.1) MB/sec

[facebook-github-bot]

@hx235 has imported this pull request. If you are a Meta employee, you can view this diff on Phabricator.

[hx235]

Update: will try out the auto-vector of size 2 approach in StopWatch to fix regression of unordered_set as suggested by @ajkr by end of Wednesday.

[facebook-github-bot]

@hx235 has updated the pull request. You must reimport the pull request before landing.

[facebook-github-bot]

@hx235 has imported this pull request. If you are a Meta employee, you can view this diff on Phabricator.

[hx235]

@ajkr I made StopWatch able to accept 2 histograms using two-parameter approach and updated the perf result. I tried out the autovecotor as below but the perf regression is 1.88%

pre-change: readrandom [AVG 27 runs] : 21061 (± 220) ops/sec
post-change: readrandom [AVG 27 runs] : 20671 (± 216) ops/sec

diff --git a/file/random_access_file_reader.cc b/file/random_access_file_reader.cc
index 9043af30f..02cb8033f 100644
--- a/file/random_access_file_reader.cc
+++ b/file/random_access_file_reader.cc
@@ -104,17 +104,44 @@ IOStatus RandomAccessFileReader::Read(const IOOptions& opts, uint64_t offset,
   {
     IOActivity io_activity_to_use =
         op_io_activity != IOActivity::kUnknown ? op_io_activity : io_activity_;
-    StopWatch sw_sst_read_mircos(
-        clock_, stats_, SST_READ_MICROS,
-        (stats_ != nullptr && (io_activity_to_use == IOActivity::kCompaction ||
-                               io_activity_to_use == IOActivity::kFlush))
-            ? &elapsed
-            : nullptr,
-        true /*overwrite*/, true /*delay_enabled*/);
-    StopWatch sw(clock_, stats_,
-                 kReadHistograms[(std::size_t)(io_activity_to_use)],
+
+    autovector<uint32_t, 2> hist_types;
+    hist_types.push_back(kReadHistograms[(std::size_t)(io_activity_to_use)]);
+
+    if (io_activity_to_use == IOActivity::kCompaction ||
+        io_activity_to_use == IOActivity::kFlush) {
+      hist_types.push_back(SST_READ_MICROS);
+    } else {
+      hist_types.push_back(Histograms::HISTOGRAM_ENUM_MAX);
+    }
+    StopWatch sw(clock_, stats_, hist_types,
                  (stats_ != nullptr) ? &elapsed : nullptr, true /*overwrite*/,
                  true /*delay_enabled*/);
+
+
     auto prev_perf_level = GetPerfLevel();
     IOSTATS_TIMER_GUARD(read_nanos);
     if (use_direct_io()) {
diff --git a/util/stop_watch.h b/util/stop_watch.h
index e26380d97..5e130ab72 100644
--- a/util/stop_watch.h
+++ b/util/stop_watch.h
@@ -4,8 +4,11 @@
 //  (found in the LICENSE.Apache file in the root directory).
 //
 #pragma once
+#include <bits/stdint-uintn.h>
+
 #include "monitoring/statistics.h"
 #include "rocksdb/system_clock.h"
+#include "util/autovector.h"
 
 namespace ROCKSDB_NAMESPACE {
 // Auto-scoped.
@@ -19,7 +22,7 @@ class StopWatch {
             bool overwrite = true, bool delay_enabled = false)
       : clock_(clock),
         statistics_(statistics),
-        hist_type_(hist_type),
+        // hist_type_(hist_type),
         elapsed_(elapsed),
         overwrite_(overwrite),
         stats_enabled_(statistics &&
@@ -29,6 +32,28 @@ class StopWatch {
         delay_enabled_(delay_enabled),
         total_delay_(0),
         delay_start_time_(0),
+        start_time_((stats_enabled_ || elapsed != nullptr) ? clock->NowMicros()
+                                                           : 0) {
+    hist_types_[0] = hist_type;
+  }
+
+  StopWatch(SystemClock* clock, Statistics* statistics,
+            const autovector<uint32_t, 2>& hist_types,
+            uint64_t* elapsed = nullptr, bool overwrite = true,
+            bool delay_enabled = false)
+      : clock_(clock),
+        statistics_(statistics),
+        hist_types_(hist_types),
+        elapsed_(elapsed),
+        overwrite_(overwrite),
+        stats_enabled_(statistics &&
+                       statistics->get_stats_level() >=
+                           StatsLevel::kExceptTimers &&
+                       statistics->HistEnabledForType(hist_types_[0]) &&
+                       statistics->HistEnabledForType(hist_types_[1])),
+        delay_enabled_(delay_enabled),
+        total_delay_(0),
+        delay_start_time_(0),
         start_time_((stats_enabled_ || elapsed != nullptr) ? clock->NowMicros()
                                                            : 0) {}
 
@@ -44,10 +69,14 @@ class StopWatch {
       *elapsed_ -= total_delay_;
     }
     if (stats_enabled_) {
-      statistics_->reportTimeToHistogram(
-          hist_type_, (elapsed_ != nullptr)
-                          ? *elapsed_
-                          : (clock_->NowMicros() - start_time_));
+      const uint64_t time = (elapsed_ != nullptr)
+                                ? *elapsed_
+                                : (clock_->NowMicros() - start_time_);
+      assert(hist_types_.size() == 2);
+      statistics_->reportTimeToHistogram(hist_types_[0], time);
+      if (hist_types_[1] != Histograms::HISTOGRAM_ENUM_MAX) {
+        statistics_->reportTimeToHistogram(hist_types_[1], time);
+      }
     }
   }
 
@@ -75,7 +104,8 @@ class StopWatch {
  private:
   SystemClock* clock_;
   Statistics* statistics_;
-  const uint32_t hist_type_;
+  autovector<uint32_t, 2> hist_types_ = {Histograms::HISTOGRAM_ENUM_MAX,
+                                         Histograms::HISTOGRAM_ENUM_MAX};
   uint64_t* elapsed_;
   bool overwrite_;
   bool stats_enabled_;

[facebook-github-bot]

@hx235 has imported this pull request. If you are a Meta employee, you can view this diff on Phabricator.

[facebook-github-bot]

@hx235 has updated the pull request. You must reimport the pull request before landing.

[facebook-github-bot]

@hx235 has updated the pull request. You must reimport the pull request before landing.

[facebook-github-bot]

@hx235 has updated the pull request. You must reimport the pull request before landing.

[facebook-github-bot]

@hx235 has updated the pull request. You must reimport the pull request before landing.

[facebook-github-bot]

@hx235 has updated the pull request. You must reimport the pull request before landing.

[facebook-github-bot]

@hx235 has updated the pull request. You must reimport the pull request before landing.

[facebook-github-bot]

@hx235 has updated the pull request. You must reimport the pull request before landing.

[facebook-github-bot]

@hx235 has imported this pull request. If you are a Meta employee, you can view this diff on Phabricator.

[facebook-github-bot]

@hx235 merged this pull request in 151242c.