From: Igor Fedotov <ifedotov@croit.io>
Date: Thu, 17 Apr 2025 14:39:56 +0000 (+0300)
Subject: osd: be more verbose in OSD::run_osd_bench_test
X-Git-Tag: v21.0.0~256^2~780^2
X-Git-Url: http://git-server-git.apps.pok.os.sepia.ceph.com/?a=commitdiff_plain;h=970b07923bb0271247c7d04a14a96af9b48ae192;p=ceph.git

osd: be more verbose in OSD::run_osd_bench_test

Likely build-in OSD benchmarking is a source for bluestore slow ops in
BlueStore at Teuthology runs.
Let's have more logging for this procedure.

Related-to: https://tracker.ceph.com/issues/68337
Signed-off-by: Igor Fedotov <igor.fedotov@croit.io>
---

diff --git a/src/osd/OSD.cc b/src/osd/OSD.cc
index 2ea6d25f4429..3c2d09ef462e 100644
--- a/src/osd/OSD.cc
+++ b/src/osd/OSD.cc
@@ -3488,10 +3488,14 @@ int OSD::run_osd_bench_test(
     bsize = osize;
   }
 
-  dout(1) << " bench count " << count
-          << " bsize " << byte_u_t(bsize) << dendl;
+  dout(0) << " bench count " << count
+          << " bsize " << byte_u_t(bsize)
+          << " onum " << onum
+          << " osize " << byte_u_t(osize)
+          << dendl;
 
   ObjectStore::Transaction cleanupt;
+  utime_t start = ceph_clock_now();
 
   if (osize && onum) {
     bufferlist bl;
@@ -3517,9 +3521,13 @@ int OSD::run_osd_bench_test(
       waiter.wait();
     }
   }
+  dout(0) << __func__
+          << " prefill took " << ceph_clock_now() - start
+          << dendl;
 
+
+  start = ceph_clock_now();
   bufferlist bl;
-  utime_t start = ceph_clock_now();
   for (int64_t pos = 0; pos < count; pos += bsize) {
     char nm[34];
     unsigned offset = 0;
@@ -3552,6 +3560,9 @@ int OSD::run_osd_bench_test(
   }
   utime_t end = ceph_clock_now();
   *elapsed = end - start;
+  dout(0) << __func__
+          << " benchmark took " << *elapsed
+          << dendl;
 
   // clean up
   store->queue_transaction(service.meta_ch, std::move(cleanupt), nullptr);