gc breakdown metrics (#73)

src/blob_gc_job.cc

@@ -151,6 +151,7 @@ Status BlobGCJob::Run() {
 }
 
 Status BlobGCJob::SampleCandidateFiles() {
+  TitanStopWatch sw(env_, metrics_.blob_db_gc_sampling_micros);
   std::vector<BlobFileMeta*> result;
   for (const auto& file : blob_gc_->inputs()) {
     bool selected = false;
@@ -400,6 +401,7 @@ Status BlobGCJob::BuildIterator(
 
 Status BlobGCJob::DiscardEntry(const Slice& key, const BlobIndex& blob_index,
                                bool* discardable) {
+  TitanStopWatch sw(env_, metrics_.blob_db_gc_read_lsm_micros);
   assert(discardable != nullptr);
   PinnableSlice index_entry;
   bool is_blob_index = false;
@@ -523,6 +525,7 @@ Status BlobGCJob::InstallOutputBlobFiles() {
 }
 
 Status BlobGCJob::RewriteValidKeyToLSM() {
+  TitanStopWatch sw(env_, metrics_.blob_db_gc_update_lsm_micros);
   Status s;
   auto* db_impl = reinterpret_cast<DBImpl*>(this->base_db_);
 
@@ -620,6 +623,12 @@ void BlobGCJob::UpdateInternalOpStats() {
            metrics_.blob_db_gc_num_files);
   AddStats(internal_op_stats, InternalOpStatsType::OUTPUT_FILE_NUM,
            metrics_.blob_db_gc_num_new_files);
+  AddStats(internal_op_stats, InternalOpStatsType::GC_SAMPLING_MICROS,
+           metrics_.blob_db_gc_sampling_micros);
+  AddStats(internal_op_stats, InternalOpStatsType::GC_READ_LSM_MICROS,
+           metrics_.blob_db_gc_read_lsm_micros);
+  AddStats(internal_op_stats, InternalOpStatsType::GC_UPDATE_LSM_MICROS,
+           metrics_.blob_db_gc_update_lsm_micros);
 }
 
 }  // namespace titandb

src/blob_gc_job.h

@@ -72,6 +72,9 @@ class BlobGCJob {
     uint64_t blob_db_gc_bytes_relocated = 0;
     uint64_t blob_db_gc_num_new_files = 0;
     uint64_t blob_db_gc_num_files = 0;
+    uint64_t blob_db_gc_sampling_micros = 0;
+    uint64_t blob_db_gc_read_lsm_micros = 0;
+    uint64_t blob_db_gc_update_lsm_micros = 0;
   } metrics_;
 
   uint64_t prev_bytes_read_ = 0;

src/titan_stats.cc

@@ -50,6 +50,7 @@ const std::array<std::string,
 
 void TitanInternalStats::DumpAndResetInternalOpStats(LogBuffer* log_buffer) {
   constexpr double GB = 1.0 * 1024 * 1024 * 1024;
+  constexpr double SECOND = 1.0 * 1000000;
   LogToBuffer(log_buffer,
               "OP           COUNT READ(GB)  WRITE(GB) IO_READ(GB) IO_WRITE(GB) "
               " FILE_IN FILE_OUT");
@@ -59,7 +60,8 @@ void TitanInternalStats::DumpAndResetInternalOpStats(LogBuffer* log_buffer) {
   for (int op = 0; op < static_cast<int>(InternalOpType::INTERNAL_OP_ENUM_MAX);
        op++) {
     LogToBuffer(
-        log_buffer, "%s %5d %10.1f %10.1f  %10.1f   %10.1f %8d %8d",
+        log_buffer,
+        "%s %5d %10.1f %10.1f  %10.1f   %10.1f %8d %8d %10.1f %10.1f %10.1f",
         internal_op_names[op].c_str(),
         GetAndResetStats(&internal_op_stats_[op], InternalOpStatsType::COUNT),
         GetAndResetStats(&internal_op_stats_[op],
@@ -77,7 +79,16 @@ void TitanInternalStats::DumpAndResetInternalOpStats(LogBuffer* log_buffer) {
         GetAndResetStats(&internal_op_stats_[op],
                          InternalOpStatsType::INPUT_FILE_NUM),
         GetAndResetStats(&internal_op_stats_[op],
-                         InternalOpStatsType::OUTPUT_FILE_NUM));
+                         InternalOpStatsType::OUTPUT_FILE_NUM),
+        GetAndResetStats(&internal_op_stats_[op],
+                         InternalOpStatsType::GC_SAMPLING_MICROS) /
+            SECOND,
+        GetAndResetStats(&internal_op_stats_[op],
+                         InternalOpStatsType::GC_READ_LSM_MICROS) /
+            SECOND,
+        GetAndResetStats(&internal_op_stats_[op],
+                         InternalOpStatsType::GC_UPDATE_LSM_MICROS) /
+            SECOND);
   }
 }
 

src/titan_stats.h

@@ -23,6 +23,10 @@ enum class InternalOpStatsType : int {
   IO_BYTES_WRITTEN,
   INPUT_FILE_NUM,
   OUTPUT_FILE_NUM,
+  GC_SAMPLING_MICROS,
+  GC_READ_LSM_MICROS,
+  // Update lsm and write callback
+  GC_UPDATE_LSM_MICROS,
   INTERNAL_OP_STATS_ENUM_MAX,
 };
 
@@ -262,5 +266,18 @@ inline void UpdateIOBytes(uint64_t prev_bytes_read, uint64_t prev_bytes_written,
   }
 }
 
+class TitanStopWatch {
+ public:
+  TitanStopWatch(Env* env, uint64_t& stats)
+      : env_(env), stats_(stats), start_(env_->NowMicros()) {}
+
+  ~TitanStopWatch() { stats_ += env_->NowMicros() - start_; }
+
+ private:
+  Env* env_;
+  uint64_t& stats_;
+  uint64_t start_;
+};
+
 }  // namespace titandb
 }  // namespace rocksdb