crimson/os/seastar: report transaction iops/conflicts/outstanding

Also report details in shard 0.

Signed-off-by: Yingxin Cheng <[email protected]>

Author: cyx1231st

src/crimson/os/seastore/seastore.cc

@@ -589,6 +589,7 @@ seastar::future<> SeaStore::report_stats()
 {
   ceph_assert(seastar::this_shard_id() == primary_core);
   shard_device_stats.resize(seastar::smp::count);
+  shard_io_stats.resize(seastar::smp::count);
   return shard_stores.invoke_on_all([this](const Shard &local_store) {
     bool report_detail = false;
     if (seastar::this_shard_id() == 0) {
@@ -597,6 +598,8 @@ seastar::future<> SeaStore::report_stats()
     }
     shard_device_stats[seastar::this_shard_id()] =
       local_store.get_device_stats(report_detail);
+    shard_io_stats[seastar::this_shard_id()] =
+      local_store.get_io_stats(report_detail);
   }).then([this] {
     LOG_PREFIX(SeaStore);
     auto now = seastar::lowres_clock::now();
@@ -607,27 +610,28 @@ seastar::future<> SeaStore::report_stats()
     std::chrono::duration<double> duration_d = now - last_tp;
     double seconds = duration_d.count();
     last_tp = now;
-    device_stats_t ts = {};
+
+    device_stats_t device_total = {};
     for (const auto &s : shard_device_stats) {
-      ts.add(s);
+      device_total.add(s);
     }
     constexpr const char* dfmt = "{:.2f}";
-    auto d_ts_num_io = static_cast<double>(ts.num_io);
+    auto device_total_num_io = static_cast<double>(device_total.num_io);
 
     std::ostringstream oss_iops;
-    auto iops = ts.num_io/seconds;
+    auto iops = device_total.num_io/seconds;
     oss_iops << "device IOPS: "
              << fmt::format(dfmt, iops)
              << " "
-             << fmt::format(dfmt, iops/shard_device_stats.size())
+             << fmt::format(dfmt, iops/seastar::smp::count)
              << "(";
 
     std::ostringstream oss_bd;
-    auto bd_mb = ts.total_bytes/seconds/(1<<20);
+    auto bd_mb = device_total.total_bytes/seconds/(1<<20);
     oss_bd << "device bandwidth(MiB): "
            << fmt::format(dfmt, bd_mb)
            << " "
-           << fmt::format(dfmt, bd_mb/shard_device_stats.size())
+           << fmt::format(dfmt, bd_mb/seastar::smp::count)
            << "(";
 
     for (const auto &s : shard_device_stats) {
@@ -639,8 +643,40 @@ seastar::future<> SeaStore::report_stats()
 
     INFO("{}", oss_iops.str());
     INFO("{}", oss_bd.str());
-    INFO("device IO depth per writer: {:.2f}", ts.total_depth/d_ts_num_io);
-    INFO("device bytes per write: {:.2f}", ts.total_bytes/d_ts_num_io);
+    INFO("device IO depth per writer: {:.2f}",
+         device_total.total_depth/device_total_num_io);
+    INFO("device bytes per write: {:.2f}",
+         device_total.total_bytes/device_total_num_io);
+
+    shard_stats_t io_total = {};
+    for (const auto &s : shard_io_stats) {
+      io_total.add(s);
+    }
+    INFO("trans IOPS: {:.2f},{:.2f},{:.2f},{:.2f} per-shard: {:.2f},{:.2f},{:.2f},{:.2f}",
+         io_total.io_num/seconds,
+         io_total.read_num/seconds,
+         io_total.get_bg_num()/seconds,
+         io_total.flush_num/seconds,
+         io_total.io_num/seconds/seastar::smp::count,
+         io_total.read_num/seconds/seastar::smp::count,
+         io_total.get_bg_num()/seconds/seastar::smp::count,
+         io_total.flush_num/seconds/seastar::smp::count);
+    auto calc_conflicts = [](uint64_t ios, uint64_t repeats) {
+      return (double)(repeats-ios)/ios;
+    };
+    INFO("trans conflicts: {:.2f},{:.2f},{:.2f}",
+         calc_conflicts(io_total.io_num, io_total.repeat_io_num),
+         calc_conflicts(io_total.read_num, io_total.repeat_read_num),
+         calc_conflicts(io_total.get_bg_num(), io_total.get_repeat_bg_num()));
+    INFO("trans outstanding: {},{},{},{} per-shard: {:.2f},{:.2f},{:.2f},{:.2f}",
+         io_total.pending_io_num,
+         io_total.pending_read_num,
+         io_total.pending_bg_num,
+         io_total.pending_flush_num,
+         (double)io_total.pending_io_num/seastar::smp::count,
+         (double)io_total.pending_read_num/seastar::smp::count,
+         (double)io_total.pending_bg_num/seastar::smp::count,
+         (double)io_total.pending_flush_num/seastar::smp::count);
     return seastar::now();
   });
 }
@@ -2481,6 +2517,60 @@ device_stats_t SeaStore::Shard::get_device_stats(bool report_detail) const
   return transaction_manager->get_device_stats(report_detail);
 }
 
+shard_stats_t SeaStore::Shard::get_io_stats(bool report_detail) const
+{
+  auto now = seastar::lowres_clock::now();
+  if (last_tp == seastar::lowres_clock::time_point::min()) {
+    last_tp = now;
+    last_shard_stats = shard_stats;
+    return {};
+  }
+  std::chrono::duration<double> duration_d = now - last_tp;
+  double seconds = duration_d.count();
+  last_tp = now;
+
+  shard_stats_t ret = shard_stats;
+  ret.minus(last_shard_stats);
+  last_shard_stats = shard_stats;
+  if (report_detail) {
+    LOG_PREFIX(SeaStore::get_io_stats);
+    auto calc_conflicts = [](uint64_t ios, uint64_t repeats) {
+      return (double)(repeats-ios)/ios;
+    };
+    INFO("iops={:.2f},{:.2f},{:.2f}({:.2f},{:.2f},{:.2f},{:.2f}),{:.2f} "
+         "conflicts={:.2f},{:.2f},{:.2f}({:.2f},{:.2f},{:.2f},{:.2f}) "
+         "outstanding={}({},{},{},{},{}),{},{},{}",
+         // iops
+         ret.io_num/seconds,
+         ret.read_num/seconds,
+         ret.get_bg_num()/seconds,
+         ret.trim_alloc_num/seconds,
+         ret.trim_dirty_num/seconds,
+         ret.cleaner_main_num/seconds,
+         ret.cleaner_cold_num/seconds,
+         ret.flush_num/seconds,
+         // conflicts
+         calc_conflicts(ret.io_num, ret.repeat_io_num),
+         calc_conflicts(ret.read_num, ret.repeat_read_num),
+         calc_conflicts(ret.get_bg_num(), ret.get_repeat_bg_num()),
+         calc_conflicts(ret.trim_alloc_num, ret.repeat_trim_alloc_num),
+         calc_conflicts(ret.trim_dirty_num, ret.repeat_trim_dirty_num),
+         calc_conflicts(ret.cleaner_main_num, ret.repeat_cleaner_main_num),
+         calc_conflicts(ret.cleaner_cold_num, ret.repeat_cleaner_cold_num),
+         // outstanding
+         ret.pending_io_num,
+         ret.starting_io_num,
+         ret.waiting_collock_io_num,
+         ret.waiting_throttler_io_num,
+         ret.processing_inlock_io_num,
+         ret.processing_postlock_io_num,
+         ret.pending_read_num,
+         ret.pending_bg_num,
+         ret.pending_flush_num);
+  }
+  return ret;
+}
+
 std::unique_ptr<SeaStore> make_seastore(
   const std::string &device)
 {

src/crimson/os/seastore/seastore.h

@@ -206,6 +206,8 @@ class SeaStore final : public FuturizedStore {
 
     device_stats_t get_device_stats(bool report_detail) const;
 
+    shard_stats_t get_io_stats(bool report_detail) const;
+
   private:
     struct internal_context_t {
       CollectionRef ch;
@@ -501,6 +503,9 @@ class SeaStore final : public FuturizedStore {
     void register_metrics();
 
     mutable shard_stats_t shard_stats;
+    mutable seastar::lowres_clock::time_point last_tp =
+      seastar::lowres_clock::time_point::min();
+    mutable shard_stats_t last_shard_stats;
   };
 
 public:
@@ -577,6 +582,7 @@ class SeaStore final : public FuturizedStore {
   mutable seastar::lowres_clock::time_point last_tp =
     seastar::lowres_clock::time_point::min();
   mutable std::vector<device_stats_t> shard_device_stats;
+  mutable std::vector<shard_stats_t> shard_io_stats;
 };
 
 std::unique_ptr<SeaStore> make_seastore(

src/crimson/os/seastore/seastore_types.h

@@ -2396,6 +2396,65 @@ struct shard_stats_t {
 
   uint64_t flush_num = 0;
   uint64_t pending_flush_num = 0;
+
+  uint64_t get_bg_num() const {
+    return trim_alloc_num +
+           trim_dirty_num +
+           cleaner_main_num +
+           cleaner_cold_num;
+  }
+
+  uint64_t get_repeat_bg_num() const {
+    return repeat_trim_alloc_num +
+           repeat_trim_dirty_num +
+           repeat_cleaner_main_num +
+           repeat_cleaner_cold_num;
+  }
+
+  void add(const shard_stats_t &o) {
+    io_num += o.io_num;
+    repeat_io_num += o.repeat_io_num;
+    pending_io_num += o.pending_io_num;
+    starting_io_num += o.starting_io_num;
+    waiting_collock_io_num += o.waiting_collock_io_num;
+    waiting_throttler_io_num += o.waiting_throttler_io_num;
+    processing_inlock_io_num += o.processing_inlock_io_num;
+    processing_postlock_io_num += o.processing_postlock_io_num;
+
+    read_num += o.read_num;
+    repeat_read_num += o.repeat_read_num;
+    pending_read_num += o.pending_read_num;
+
+    pending_bg_num += o.pending_bg_num;
+    trim_alloc_num += o.trim_alloc_num;
+    repeat_trim_alloc_num += o.repeat_trim_alloc_num;
+    trim_dirty_num += o.trim_dirty_num;
+    repeat_trim_dirty_num += o.repeat_trim_dirty_num;
+    cleaner_main_num += o.cleaner_main_num;
+    repeat_cleaner_main_num += o.repeat_cleaner_main_num;
+    cleaner_cold_num += o.cleaner_cold_num;
+    repeat_cleaner_cold_num += o.repeat_cleaner_cold_num;
+
+    flush_num += o.flush_num;
+    pending_flush_num += o.pending_flush_num;
+  }
+
+  void minus(const shard_stats_t &o) {
+    // realtime(e.g. pending) stats are not related
+    io_num -= o.io_num;
+    repeat_io_num -= o.repeat_io_num;
+    read_num -= o.read_num;
+    repeat_read_num -= o.repeat_read_num;
+    trim_alloc_num -= o.trim_alloc_num;
+    repeat_trim_alloc_num -= o.repeat_trim_alloc_num;
+    trim_dirty_num -= o.trim_dirty_num;
+    repeat_trim_dirty_num -= o.repeat_trim_dirty_num;
+    cleaner_main_num -= o.cleaner_main_num;
+    repeat_cleaner_main_num -= o.repeat_cleaner_main_num;
+    cleaner_cold_num -= o.cleaner_cold_num;
+    repeat_cleaner_cold_num -= o.repeat_cleaner_cold_num;
+    flush_num -= o.flush_num;
+  }
 };
 
 }