crimson/.../circular_bounded_journal: add journal submission metrics

Signed-off-by: Samuel Just <sjust@redhat.com>

diff --git a/src/crimson/os/seastore/journal/circular_bounded_journal.cc b/src/crimson/os/seastore/journal/circular_bounded_journal.cc
index 4dbd5892e25001028e4052c6feab9ac5b0368603..88bade79a225cc7608debdb11931c72d59fd7fe0 100644 (file)
--- a/src/crimson/os/seastore/journal/circular_bounded_journal.cc
+++ b/src/crimson/os/seastore/journal/circular_bounded_journal.cc
@@ -29,7 +29,9 @@ CircularBoundedJournal::CircularBoundedJournal(
     crimson::common::get_conf<double>(
       "seastore_journal_batch_preferred_fullness"),
     cjs)
-  {}
+{
+  register_metrics();
+}
 
 CircularBoundedJournal::open_for_mkfs_ret
 CircularBoundedJournal::open_for_mkfs()
@@ -85,17 +87,42 @@ CircularBoundedJournal::do_submit_record(
   on_submission_func_t &&on_submission)
 {
   LOG_PREFIX(CircularBoundedJournal::do_submit_record);
+  stats.submit_record_count++;
+  stats.submit_record_size += record.size.get_raw_mdlength();
+  auto start = ceph::mono_clock::now();
 
   RecordSubmitter::action_t action;
+  bool waited = false;
+  bool rolled = false;
   while (true) {
     if (!record_submitter.is_available()) {
       DEBUG("H{} wait ...", (void*)&handle);
+
+      auto wait_start = ceph::mono_clock::now();
+
       co_await record_submitter.wait_available();
+
+      if (!waited) {
+       stats.submit_record_wait_count++;
+       waited = true;
+      }
+      stats.submit_record_wait_latency_total +=
+       ceph::mono_clock::now() - wait_start;
       continue;
     }
     action = record_submitter.check_action(record.size);
     if (action == RecordSubmitter::action_t::ROLL) {
+
+      auto roll_start = ceph::mono_clock::now();
+
       co_await record_submitter.roll_segment();
+
+      if (!rolled) {
+       stats.submit_record_roll_count++;
+       rolled = true;
+      }
+      stats.submit_record_roll_latency_total +=
+       ceph::mono_clock::now() - roll_start;
       continue;
     }
     break;
@@ -117,6 +144,8 @@ CircularBoundedJournal::do_submit_record(
   auto new_committed_to = result.write_result.get_end_seq();
   record_submitter.update_committed_to(new_committed_to);
   std::invoke(on_submission, result);
+
+  stats.submit_record_latency_total += ceph::mono_clock::now() - start;
 }
 
 Journal::replay_ret CircularBoundedJournal::replay_segment(
@@ -401,4 +430,84 @@ Journal::replay_ret CircularBoundedJournal::replay(
   });
 }
 
+void CircularBoundedJournal::register_metrics()
+{
+  namespace sm = seastar::metrics;
+  metrics.add_group(
+    "seastore_cbj",
+    {
+      sm::make_gauge(
+       "submit_record_count",
+       [this] {
+         return stats.submit_record_count;
+       }
+      ),
+      sm::make_gauge(
+       "submit_record_size",
+       [this] {
+         return stats.submit_record_size;
+       }
+      ),
+      sm::make_gauge(
+       "submit_record_latency_total",
+       [this] {
+         return stats.submit_record_latency_total.count();
+       }
+      ),
+      sm::make_gauge(
+       "submit_record_latency_average",
+       [this] {
+         return stats.submit_record_latency_total.count() /
+           stats.submit_record_count;
+       }
+      ),
+      sm::make_gauge(
+       "submit_record_size_average",
+       [this] {
+         return stats.submit_record_size /
+           stats.submit_record_count;
+       }
+      ),
+      sm::make_gauge(
+       "submit_record_roll_count",
+       [this] {
+         return stats.submit_record_roll_count;
+       }
+      ),
+      sm::make_gauge(
+       "submit_record_roll_latency_total",
+       [this] {
+         return stats.submit_record_roll_latency_total.count();
+       }
+      ),
+      sm::make_gauge(
+       "submit_record_roll_latency_average",
+       [this] {
+         return stats.submit_record_roll_latency_total.count() /
+           stats.submit_record_roll_count;
+       }
+      ),
+      sm::make_gauge(
+       "submit_record_wait_count",
+       [this] {
+         return stats.submit_record_wait_count;
+       }
+      ),
+      sm::make_gauge(
+       "submit_record_wait_latency_total",
+       [this] {
+         return stats.submit_record_wait_latency_total.count();
+       }
+      ),
+      sm::make_gauge(
+       "submit_record_wait_latency_average",
+       [this] {
+         return stats.submit_record_wait_latency_total.count() /
+           stats.submit_record_wait_count;
+       }
+      )
+    }
+  );
+}
+
 }

diff --git a/src/crimson/os/seastore/journal/circular_bounded_journal.h b/src/crimson/os/seastore/journal/circular_bounded_journal.h
index d5447ff687fa287119fe9be7d1661ab801a75bdb..c5ff686a953e9e636321eee7a2c177402e1738b8 100644 (file)
--- a/src/crimson/os/seastore/journal/circular_bounded_journal.h
+++ b/src/crimson/os/seastore/journal/circular_bounded_journal.h
@@ -23,6 +23,8 @@
 #include "crimson/os/seastore/journal/circular_journal_space.h"
 #include "crimson/os/seastore/record_scanner.h"
 
+using namespace std::literals;
+
 namespace crimson::os::seastore::journal {
 
 using RBMDevice = random_block_device::RBMDevice;
@@ -223,6 +225,20 @@ private:
   // the sequence to written records
   CircularJournalSpace cjs;
   RecordSubmitter record_submitter; 
+
+  struct {
+    uint64_t submit_record_count = 0;
+    uint64_t submit_record_size = 0;
+    std::chrono::duration<double> submit_record_latency_total = 0.0s;
+
+    uint64_t submit_record_roll_count = 0;
+    std::chrono::duration<double> submit_record_roll_latency_total = 0.0s;
+
+    uint64_t submit_record_wait_count = 0;
+    std::chrono::duration<double> submit_record_wait_latency_total = 0.0s;
+  } stats;
+  seastar::metrics::metric_group metrics;
+  void register_metrics();
 };
 
 }