crimson/os/seastore/async_cleaner: measure io block time

This is helpful for us to understand for how much time in some past
period of running the io requests are blocked.

Signed-off-by: Xuehan Xu <xuxuehan@qianxin.com>

diff --git a/src/crimson/os/seastore/extent_placement_manager.cc b/src/crimson/os/seastore/extent_placement_manager.cc
index 457cd1cf1dcf7fc3e440fd6f043c2b2dd9b4aeae..bd8e45ec99fb8b3a310289535d17e23e70630a2a 100644 (file)
--- a/src/crimson/os/seastore/extent_placement_manager.cc
+++ b/src/crimson/os/seastore/extent_placement_manager.cc
@@ -681,15 +681,20 @@ ExtentPlacementManager::BackgroundProcess::reserve_projected_usage(
     stats.io_blocked_sum += stats.io_blocking_num;
 
     blocking_io = seastar::promise<>();
+    auto begin_time = seastar::lowres_system_clock::now();
     return blocking_io->get_future(
-    ).then([this, usage, FNAME] {
-      return seastar::repeat([this, usage, FNAME] {
+    ).then([this, usage, FNAME, begin_time] {
+      return seastar::repeat([this, usage, FNAME, begin_time] {
         ceph_assert(!blocking_io);
         auto res = try_reserve_io(usage);
         if (res.is_successful()) {
           DEBUG("unblocked");
           assert(stats.io_blocking_num == 1);
           --stats.io_blocking_num;
+          auto end_time = seastar::lowres_system_clock::now();
+          auto duration = end_time - begin_time;
+          stats.io_blocked_time += std::chrono::duration_cast<
+            std::chrono::milliseconds>(duration).count();
           return seastar::make_ready_future<seastar::stop_iteration>(
             seastar::stop_iteration::yes);
         } else {
@@ -974,7 +979,9 @@ void ExtentPlacementManager::BackgroundProcess::register_metrics()
     sm::make_counter("io_blocked_count_clean", stats.io_blocked_count_clean,
                      sm::description("IOs that are blocked by cleaning")),
     sm::make_counter("io_blocked_sum", stats.io_blocked_sum,
-                     sm::description("the sum of blocking IOs"))
+                     sm::description("the sum of blocking IOs")),
+    sm::make_counter("io_blocked_time", stats.io_blocked_time,
+                     sm::description("the sum of the time(ms) in which IOs are blocked"))
   });
 }
 

diff --git a/src/crimson/os/seastore/extent_placement_manager.h b/src/crimson/os/seastore/extent_placement_manager.h
index 913e95ab647ef6034b561de26e3477681217a1a7..4734b6254e17ffaece944b92f004be4f8197302f 100644 (file)
--- a/src/crimson/os/seastore/extent_placement_manager.h
+++ b/src/crimson/os/seastore/extent_placement_manager.h
@@ -1063,6 +1063,7 @@ private:
       uint64_t io_blocked_count_trim = 0;
       uint64_t io_blocked_count_clean = 0;
       uint64_t io_blocked_sum = 0;
+      uint64_t io_blocked_time = 0;
     } stats;
     seastar::metrics::metric_group metrics;