crimson/os/seastore: report do_transaction latency in milliseconds

The do_transaction latency histograms were bucketed and summed in
microseconds, but with seastar::lowres_clock (~task_quota, ~0.5ms) and
the ms-scale buckets we keep - microsecond values only add noise to the
exported numbers.

Signed-off-by: Matan Breizman <mbreizma@redhat.com>

diff --git a/src/crimson/os/seastore/seastore.cc b/src/crimson/os/seastore/seastore.cc
index 679f670c013c78a727393bcac8179b55a33d0604..1c3947e8c3d2c9546d1093fe50d984ff1fc3147c 100644 (file)
--- a/src/crimson/os/seastore/seastore.cc
+++ b/src/crimson/os/seastore/seastore.cc
@@ -168,9 +168,9 @@ void SeaStore::Shard::register_metrics(store_index_t store_index)
   };
 
   for (auto& hist : stats.op_lat) {
-    hist.buckets.resize(lat_hist_bounds_us.size());
-    for (std::size_t i = 0; i < lat_hist_bounds_us.size(); ++i) {
-      hist.buckets[i].upper_bound = lat_hist_bounds_us[i];
+    hist.buckets.resize(lat_hist_bounds_ms.size());
+    for (std::size_t i = 0; i < lat_hist_bounds_ms.size(); ++i) {
+      hist.buckets[i].upper_bound = lat_hist_bounds_ms[i];
       hist.buckets[i].count = 0;
     }
   }
@@ -239,9 +239,9 @@ void SeaStore::Shard::register_metrics(store_index_t store_index)
     for (auto& [stage, label] : labels_by_stage) {
       auto idx = static_cast<std::size_t>(stage);
       auto& hist = (*arr_ptr)[idx];
-      hist.buckets.resize(STAGE_LAT_BUCKETS_US.size());
-      for (std::size_t i = 0; i < STAGE_LAT_BUCKETS_US.size(); ++i) {
-        hist.buckets[i].upper_bound = STAGE_LAT_BUCKETS_US[i];
+      hist.buckets.resize(STAGE_LAT_BUCKETS_MS.size());
+      for (std::size_t i = 0; i < STAGE_LAT_BUCKETS_MS.size(); ++i) {
+        hist.buckets[i].upper_bound = STAGE_LAT_BUCKETS_MS[i];
         hist.buckets[i].count = 0;
       }
       metrics.add_group(
@@ -252,7 +252,7 @@ void SeaStore::Shard::register_metrics(store_index_t store_index)
             [arr_ptr, idx]() -> seastar::metrics::histogram& {
               return (*arr_ptr)[idx];
             },
-            sm::description("per-stage latency (microseconds) of do_transaction"),
+            sm::description("per-stage latency (milliseconds) of do_transaction"),
             {label,
              sm::label_instance("tail", tail),
              sm::label_instance("shard_store_index", std::to_string(store_index))}
@@ -1835,8 +1835,8 @@ seastar::future<> SeaStore::Shard::do_transaction_no_callbacks(
   {
     auto& pd = ctx.transaction->get_phase_durations();
     auto total = seastar::lowres_clock::now() - ctx.begin_timestamp;
-    auto total_us = static_cast<uint64_t>(
-      std::chrono::duration_cast<std::chrono::microseconds>(total).count());
+    auto total_ms = std::chrono::duration_cast<
+      std::chrono::duration<double, std::milli>>(total).count();
 
     const std::array<
       std::pair<txn_stage_t, seastar::lowres_clock::duration>, STAGE_MAX>
@@ -1857,10 +1857,10 @@ seastar::future<> SeaStore::Shard::do_transaction_no_callbacks(
 
     for (auto& [stage, dur] : stage_samples) {
       add_stage_latency_sample(stats.stage_lat, stage, dur);
-      if (total_us > TAIL_SLOW_US) {
+      if (total_ms > TAIL_SLOW_MS) {
         add_stage_latency_sample(stats.stage_lat_slow, stage, dur);
       }
-      if (total_us > TAIL_VERY_SLOW_US) {
+      if (total_ms > TAIL_VERY_SLOW_MS) {
         add_stage_latency_sample(stats.stage_lat_very_slow, stage, dur);
       }
     }

diff --git a/src/crimson/os/seastore/seastore.h b/src/crimson/os/seastore/seastore.h
index 45eb52257a7b9510afb0783bf4ebd63b6a4e73b3..e4f65be42b30f74ea84c9089799bcebf484c94ed 100644 (file)
--- a/src/crimson/os/seastore/seastore.h
+++ b/src/crimson/os/seastore/seastore.h
@@ -440,34 +440,34 @@ public:
 
     static constexpr auto LAT_MAX = static_cast<std::size_t>(op_type_t::MAX);
 
-    // Histogram bucket upper bounds in microseconds (1ms–100ms).
+    // Histogram bucket upper bounds in milliseconds (1ms–100ms).
     // Ops above 100ms land in the last bucket as overflow. The smallest
     // bucket is 1ms: sub-ms latencies are below lowres_clock resolution
     // (~task_quota) and cannot be resolved, so no finer buckets are kept.
-    static constexpr std::array<double, 12> lat_hist_bounds_us = {
-      1000,
-      1500, 2000, 3000,
-      5000,
-      7500, 10000,
-      15000, 20000,
-      30000, 50000,
-      100000
+    static constexpr std::array<double, 12> lat_hist_bounds_ms = {
+      1,
+      1.5, 2, 3,
+      5,
+      7.5, 10,
+      15, 20,
+      30, 50,
+      100
     };
 
     // Buckets for the per-transaction conflict/replay distribution.
     static constexpr std::size_t REPLAY_BUCKETS = 16;
 
     static constexpr auto STAGE_MAX = static_cast<std::size_t>(txn_stage_t::MAX);
-    // Upper bounds (microseconds) for the per-stage do_transaction latency
+    // Upper bounds (milliseconds) for the per-stage do_transaction latency
     // histograms. Smallest bucket is 1ms; sub-ms is below lowres_clock
     // resolution (~task_quota) and cannot be resolved.
-    static constexpr std::array<uint64_t, 12> STAGE_LAT_BUCKETS_US = {
-      1000, 1500, 2000, 3000, 5000, 7500,
-      10000, 15000, 20000, 30000, 50000, 100000
+    static constexpr std::array<double, 12> STAGE_LAT_BUCKETS_MS = {
+      1, 1.5, 2, 3, 5, 7.5,
+      10, 15, 20, 30, 50, 100
     };
 
-    static constexpr uint64_t TAIL_SLOW_US = 5000;        // 5 ms
-    static constexpr uint64_t TAIL_VERY_SLOW_US = 10000;  // 10 ms
+    static constexpr double TAIL_SLOW_MS = 5;        // 5 ms
+    static constexpr double TAIL_VERY_SLOW_MS = 10;  // 10 ms
 
     struct {
       std::array<seastar::metrics::histogram, LAT_MAX> op_lat;
@@ -505,12 +505,13 @@ public:
     void add_latency_sample(op_type_t op_type,
         seastar::lowres_clock::duration dur) {
       seastar::metrics::histogram& lat = get_latency(op_type);
-      auto us = std::chrono::duration_cast<std::chrono::microseconds>(dur).count();
+      auto ms = std::chrono::duration_cast<
+        std::chrono::duration<double, std::milli>>(dur).count();
       lat.sample_count++;
-      lat.sample_sum += us;
+      lat.sample_sum += ms;
       bool found = false;
       for (auto& b : lat.buckets) {
-        if (static_cast<double>(us) <= b.upper_bound) {
+        if (ms <= b.upper_bound) {
           ++b.count;
           found = true;
           break;
@@ -536,7 +537,7 @@ public:
       hist.sample_sum += num_replays;
     }
 
-    // Record the latency of one do_transaction stage (microseconds). Buckets are
+    // Record the latency of one do_transaction stage (milliseconds). Buckets are
     // non-cumulative (bucket = first upper_bound >= value); values above the top
     // bound aren't bucketed but still land in sample_count/sample_sum.
     void add_stage_latency_sample(
@@ -548,15 +549,16 @@ public:
         // register_metrics() did not run (store inactive); nothing to record.
         return;
       }
-      auto us = std::chrono::duration_cast<std::chrono::microseconds>(dur).count();
+      auto ms = std::chrono::duration_cast<
+        std::chrono::duration<double, std::milli>>(dur).count();
       for (auto& b : hist.buckets) {
-        if (static_cast<double>(us) <= b.upper_bound) {
+        if (ms <= b.upper_bound) {
           ++b.count;
           break;
         }
       }
       ++hist.sample_count;
-      hist.sample_sum += us;
+      hist.sample_sum += ms;
     }
 
     /*