Update

[ghstack-poisoned]

db/db_impl/db_impl.cc

@@ -6675,6 +6675,13 @@ Status DBImpl::IngestExternalFile(
 Status DBImpl::IngestExternalFiles(
     const std::vector<IngestExternalFileArg>& args) {
   PERF_TIMER_GUARD(file_ingestion_nanos);
+  // Prepare/run ingestion latency, recorded only on success (below).
+  const bool record_ingest_micros =
+      stats_ != nullptr &&
+      stats_->get_stats_level() > StatsLevel::kExceptTimers;
+  const uint64_t ingest_start_micros =
+      record_ingest_micros ? immutable_db_options_.clock->NowMicros() : 0;
+  uint64_t prepare_micros = 0;
   // TODO: plumb Env::IOActivity, Env::IOPriority
   const WriteOptions write_options;
 
@@ -6826,6 +6833,13 @@ Status DBImpl::IngestExternalFiles(
     return status;
   }
 
+  // End of prepare phase; run phase starts here.
+  uint64_t run_start_micros = 0;
+  if (record_ingest_micros) {
+    run_start_micros = immutable_db_options_.clock->NowMicros();
+    prepare_micros = run_start_micros - ingest_start_micros;
+  }
+
   std::vector<SuperVersionContext> sv_ctxs;
   for (size_t i = 0; i != num_cfs; ++i) {
     sv_ctxs.emplace_back(true /* create_superversion */);
@@ -7067,6 +7081,14 @@ Status DBImpl::IngestExternalFiles(
       }
     }
   }
+  // Record latency only for successful ingestions.
+  if (record_ingest_micros && status.ok()) {
+    RecordTimeToHistogram(stats_, INGEST_EXTERNAL_FILE_PREPARE_TIME,
+                          prepare_micros);
+    RecordTimeToHistogram(
+        stats_, INGEST_EXTERNAL_FILE_RUN_TIME,
+        immutable_db_options_.clock->NowMicros() - run_start_micros);
+  }
   return status;
 }
 

db/external_sst_file_test.cc

@@ -298,6 +298,48 @@ class ExternalSSTFileTest
   int last_file_id_ = 0;
 };
 
+TEST_F(ExternalSSTFileTest, IngestionTimingHistogram) {
+  Options options = CurrentOptions();
+  options.statistics = CreateDBStatistics();
+  options.statistics->set_stats_level(StatsLevel::kAll);  // enable timers
+  DestroyAndReopen(options);
+
+  ASSERT_OK(GenerateAndAddExternalFile(
+      options, {{"k1", "v1"}, {"k2", "v2"}, {"k3", "v3"}}, /*file_id=*/-1,
+      /*allow_global_seqno=*/true, /*write_global_seqno=*/false,
+      /*verify_checksums_before_ingest=*/true, /*ingest_behind=*/false,
+      /*sort_data=*/true));
+
+  auto hist = [&](Histograms h) {
+    HistogramData hd;
+    options.statistics->histogramData(h, &hd);
+    return hd;
+  };
+
+  // One sample per call (not per CF) in each phase histogram.
+  HistogramData prepare_hd = hist(INGEST_EXTERNAL_FILE_PREPARE_TIME);
+  HistogramData run_hd = hist(INGEST_EXTERNAL_FILE_RUN_TIME);
+  ASSERT_EQ(1, prepare_hd.count);
+  ASSERT_EQ(1, run_hd.count);
+  ASSERT_GT(prepare_hd.max, 0.0);
+  ASSERT_GT(run_hd.max, 0.0);
+
+  // A second call adds exactly one more sample to each histogram.
+  ASSERT_OK(GenerateAndAddExternalFile(
+      options, {{"k4", "v4"}, {"k5", "v5"}}, /*file_id=*/-1,
+      /*allow_global_seqno=*/true, /*write_global_seqno=*/false,
+      /*verify_checksums_before_ingest=*/true, /*ingest_behind=*/false,
+      /*sort_data=*/true));
+  ASSERT_EQ(2, hist(INGEST_EXTERNAL_FILE_PREPARE_TIME).count);
+  ASSERT_EQ(2, hist(INGEST_EXTERNAL_FILE_RUN_TIME).count);
+
+  // A failed ingestion records nothing (latency is logged only on success).
+  ASSERT_NOK(db_->IngestExternalFile({"/path/does/not/exist.sst"},
+                                     IngestExternalFileOptions()));
+  ASSERT_EQ(2, hist(INGEST_EXTERNAL_FILE_PREPARE_TIME).count);
+  ASSERT_EQ(2, hist(INGEST_EXTERNAL_FILE_RUN_TIME).count);
+}
+
 TEST_F(ExternalSSTFileTest, ComparatorMismatch) {
   Options options = CurrentOptions();
   Options options_diff_ucmp = options;

include/rocksdb/statistics.h

@@ -765,6 +765,16 @@ enum Histograms : uint32_t {
   // blocks for uniform key distribution tracking.
   BLOCK_KEY_DISTRIBUTION_CV,
 
+  // Time (microseconds) in the "prepare" phase of an IngestExternalFile(s) call
+  // (validation and reading/linking the files; does not block writes). One
+  // sample per successful call; requires stats level > kExceptTimers.
+  INGEST_EXTERNAL_FILE_PREPARE_TIME,
+
+  // Time (microseconds) in the "run" phase of an IngestExternalFile(s) call
+  // (work under the DB mutex while writes are blocked). One sample per
+  // successful call; requires stats level > kExceptTimers.
+  INGEST_EXTERNAL_FILE_RUN_TIME,
+
   HISTOGRAM_ENUM_MAX
 };
 

java/rocksjni/portal.h

@@ -5998,6 +5998,10 @@ class HistogramTypeJni {
         return 0x41;
       case ROCKSDB_NAMESPACE::Histograms::BLOCK_KEY_DISTRIBUTION_CV:
         return 0x42;
+      case ROCKSDB_NAMESPACE::Histograms::INGEST_EXTERNAL_FILE_PREPARE_TIME:
+        return 0x43;
+      case ROCKSDB_NAMESPACE::Histograms::INGEST_EXTERNAL_FILE_RUN_TIME:
+        return 0x44;
       case ROCKSDB_NAMESPACE::Histograms::HISTOGRAM_ENUM_MAX:
         // 0x3E is reserved for backwards compatibility on current minor
         // version.
@@ -6151,6 +6155,10 @@ class HistogramTypeJni {
         return ROCKSDB_NAMESPACE::Histograms::MULTISCAN_BLOCKS_PER_PREPARE;
       case 0x42:
         return ROCKSDB_NAMESPACE::Histograms::BLOCK_KEY_DISTRIBUTION_CV;
+      case 0x43:
+        return ROCKSDB_NAMESPACE::Histograms::INGEST_EXTERNAL_FILE_PREPARE_TIME;
+      case 0x44:
+        return ROCKSDB_NAMESPACE::Histograms::INGEST_EXTERNAL_FILE_RUN_TIME;
       case 0x3E:
         // 0x3E is reserved for backwards compatibility on current minor
         // version.

java/src/main/java/org/rocksdb/HistogramType.java

@@ -231,6 +231,16 @@ public enum HistogramType {
    */
   BLOCK_KEY_DISTRIBUTION_CV((byte) 0x42),
 
+  /**
+   * Time (us) in the prepare phase of an IngestExternalFile(s) call.
+   */
+  INGEST_EXTERNAL_FILE_PREPARE_TIME((byte) 0x43),
+
+  /**
+   * Time (us) in the run phase of an IngestExternalFile(s) call.
+   */
+  INGEST_EXTERNAL_FILE_RUN_TIME((byte) 0x44),
+
   // 0x3E is reserved for backwards compatibility on current minor version.
   HISTOGRAM_ENUM_MAX((byte) 0x3E);
 

monitoring/statistics.cc

@@ -386,6 +386,9 @@ const std::vector<std::pair<Histograms, std::string>> HistogramsNameMap = {
     {MULTISCAN_PREPARE_MICROS, "rocksdb.multiscan.prepare.micros"},
     {MULTISCAN_BLOCKS_PER_PREPARE, "rocksdb.multiscan.blocks.per.prepare"},
     {BLOCK_KEY_DISTRIBUTION_CV, "rocksdb.block.key.distribution.cv"},
+    {INGEST_EXTERNAL_FILE_PREPARE_TIME,
+     "rocksdb.ingest.external.file.prepare.micros"},
+    {INGEST_EXTERNAL_FILE_RUN_TIME, "rocksdb.ingest.external.file.run.micros"},
 };
 
 std::shared_ptr<Statistics> CreateDBStatistics() {

unreleased_history/new_features/ingest_external_file_phase_histograms.md

@@ -0,0 +1 @@
+Added two stats histograms reporting the per-call latency (in microseconds) of each successful `IngestExternalFile`/`IngestExternalFiles` call, split by phase: `rocksdb.ingest.external.file.prepare.micros` (argument validation and reading/validating/linking the external files, which does not block live writes) and `rocksdb.ingest.external.file.run.micros` (the ingestion performed under the DB mutex while live writes are blocked). Failed ingestions are not recorded.