From: Samuel Just <sjust@redhat.com>
Date: Thu, 6 Apr 2023 20:50:48 +0000 (+0000)
Subject: osd/: add per-op latency averages for each recovery related message
X-Git-Tag: v17.2.7~418^2~8
X-Git-Url: http://git.apps.os.sepia.ceph.com/?a=commitdiff_plain;h=6144db433fd6649b102157a6a66dc91c43b82a6a;p=ceph.git

osd/: add per-op latency averages for each recovery related message

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

diff --git a/src/osd/osd_perf_counters.cc b/src/osd/osd_perf_counters.cc
index ed63b4d3f6784..b1c1413bf61d9 100644
--- a/src/osd/osd_perf_counters.cc
+++ b/src/osd/osd_perf_counters.cc
@@ -162,6 +162,31 @@ PerfCounters *build_osd_logger(CephContext *cct) {
    "recovery bytes",
    "rbt", PerfCountersBuilder::PRIO_INTERESTING);
 
+  osd_plb.add_time_avg(
+    l_osd_recovery_push_queue_lat,
+    "l_osd_recovery_push_queue_latency",
+    "MOSDPGPush queue latency");
+  osd_plb.add_time_avg(
+    l_osd_recovery_push_reply_queue_lat,
+    "l_osd_recovery_push_reply_queue_latency",
+    "MOSDPGPushReply queue latency");
+  osd_plb.add_time_avg(
+    l_osd_recovery_pull_queue_lat,
+    "l_osd_recovery_pull_queue_latency",
+    "MOSDPGPull queue latency");
+  osd_plb.add_time_avg(
+    l_osd_recovery_backfill_queue_lat,
+    "l_osd_recovery_backfill_queue_latency",
+    "MOSDPGBackfill queue latency");
+  osd_plb.add_time_avg(
+    l_osd_recovery_backfill_remove_queue_lat,
+    "l_osd_recovery_backfill_remove_queue_latency",
+    "MOSDPGBackfillDelete queue latency");
+  osd_plb.add_time_avg(
+    l_osd_recovery_scan_queue_lat,
+    "l_osd_recovery_scan_queue_latency",
+    "MOSDPGScan queue latency");
+
   osd_plb.add_u64(l_osd_loadavg, "loadavg", "CPU load");
   osd_plb.add_u64(
     l_osd_cached_crc, "cached_crc", "Total number getting crc from crc_cache");
diff --git a/src/osd/osd_perf_counters.h b/src/osd/osd_perf_counters.h
index 9966a7f7df3c2..f8af01e0e4f56 100644
--- a/src/osd/osd_perf_counters.h
+++ b/src/osd/osd_perf_counters.h
@@ -58,6 +58,13 @@ enum {
   l_osd_rop,
   l_osd_rbytes,
 
+  l_osd_recovery_push_queue_lat,
+  l_osd_recovery_push_reply_queue_lat,
+  l_osd_recovery_pull_queue_lat,
+  l_osd_recovery_backfill_queue_lat,
+  l_osd_recovery_backfill_remove_queue_lat,
+  l_osd_recovery_scan_queue_lat,
+
   l_osd_loadavg,
   l_osd_cached_crc,
   l_osd_cached_crc_adjusted,
diff --git a/src/osd/scheduler/OpSchedulerItem.cc b/src/osd/scheduler/OpSchedulerItem.cc
index 4eab93bd9c350..f2cc3e3fd0217 100644
--- a/src/osd/scheduler/OpSchedulerItem.cc
+++ b/src/osd/scheduler/OpSchedulerItem.cc
@@ -254,6 +254,21 @@ void PGRecoveryMsg::run(
   PGRef& pg,
   ThreadPool::TPHandle &handle)
 {
+  auto latency = time_queued - ceph_clock_now();
+  switch (op->get_req()->get_type()) {
+  case MSG_OSD_PG_PUSH:
+    osd->logger->tinc(l_osd_recovery_push_queue_lat, latency);
+  case MSG_OSD_PG_PUSH_REPLY:
+    osd->logger->tinc(l_osd_recovery_push_reply_queue_lat, latency);
+  case MSG_OSD_PG_PULL:
+    osd->logger->tinc(l_osd_recovery_pull_queue_lat, latency);
+  case MSG_OSD_PG_BACKFILL:
+    osd->logger->tinc(l_osd_recovery_backfill_queue_lat, latency);
+  case MSG_OSD_PG_BACKFILL_REMOVE:
+    osd->logger->tinc(l_osd_recovery_backfill_remove_queue_lat, latency);
+  case MSG_OSD_PG_SCAN:
+    osd->logger->tinc(l_osd_recovery_scan_queue_lat, latency);
+  }
   osd->dequeue_op(pg, op, handle);
   pg->unlock();
 }
diff --git a/src/osd/scheduler/OpSchedulerItem.h b/src/osd/scheduler/OpSchedulerItem.h
index 2bc251c4633a4..e3f3a1a67af0c 100644
--- a/src/osd/scheduler/OpSchedulerItem.h
+++ b/src/osd/scheduler/OpSchedulerItem.h
@@ -572,10 +572,12 @@ public:
 };
 
 class PGRecoveryMsg : public PGOpQueueable {
+  utime_t time_queued;
   OpRequestRef op;
 
 public:
-  PGRecoveryMsg(spg_t pg, OpRequestRef op) : PGOpQueueable(pg), op(std::move(op)) {}
+  PGRecoveryMsg(spg_t pg, OpRequestRef op)
+    : PGOpQueueable(pg), time_queued(ceph_clock_now()), op(std::move(op)) {}
 
   static bool is_recovery_msg(OpRequestRef &op) {
     switch (op->get_req()->get_type()) {