From: Ronen Friedman <rfriedma@redhat.com>
Date: Tue, 29 Dec 2020 09:24:24 +0000 (+0200)
Subject: osd: scrubber: minor modifications to debug logs and formatting
X-Git-Tag: v17.0.0~46^2~3
X-Git-Url: http://git.apps.os.sepia.ceph.com/?a=commitdiff_plain;h=942beb23b90d87ee390e4513c4ee83b22aed2a9c;p=ceph.git

osd: scrubber: minor modifications to debug logs and formatting

Signed-off-by: Ronen Friedman <rfriedma@redhat.com>
---

diff --git a/src/osd/PG.cc b/src/osd/PG.cc
index 2b97a6cc4eec2..c514da463a572 100644
--- a/src/osd/PG.cc
+++ b/src/osd/PG.cc
@@ -353,6 +353,8 @@ void PG::update_object_snap_mapping(
 /******* PG ***********/
 void PG::clear_primary_state()
 {
+  dout(20) << __func__ << dendl;
+
   projected_log = PGLog::IndexedLog();
 
   snap_trimq.clear();
diff --git a/src/osd/pg_scrubber.cc b/src/osd/pg_scrubber.cc
index fe57a9f2594c2..e2b4146c3fd86 100644
--- a/src/osd/pg_scrubber.cc
+++ b/src/osd/pg_scrubber.cc
@@ -114,7 +114,7 @@ bool PgScrubber::verify_against_abort(epoch_t epoch_to_verify)
     return true;
   }
 
-  dout(15) << __func__ << " aborting. incoming epoch: " << epoch_to_verify
+  dout(10) << __func__ << " aborting. incoming epoch: " << epoch_to_verify
 	   << " vs last-aborted: " << m_last_aborted << dendl;
 
   // if we were not aware of the abort before - kill the scrub.
@@ -371,9 +371,9 @@ void PgScrubber::reg_next_scrub(const requested_scrub_t& request_flags)
     return;
   }
 
-  dout(10) << __func__ << " planned.m.s: " << request_flags.must_scrub
-	   << ": planned.n.a.: " << request_flags.need_auto
-	   << " stamp: " << m_pg->info.history.last_scrub_stamp << dendl;
+  dout(10) << __func__ << " planned: must? " << request_flags.must_scrub << " need-auto? "
+	   << request_flags.need_auto << " stamp: " << m_pg->info.history.last_scrub_stamp
+	   << dendl;
 
   ceph_assert(!is_scrub_registered());
 
@@ -411,6 +411,8 @@ void PgScrubber::reg_next_scrub(const requested_scrub_t& request_flags)
 
 void PgScrubber::unreg_next_scrub()
 {
+  dout(10) << __func__ << " existing-" << m_scrub_reg_stamp << ". was registered? "
+	   << is_scrub_registered() << dendl;
   if (is_scrub_registered()) {
     m_osds->unreg_pg_scrub(m_pg->info.pgid, m_scrub_reg_stamp);
     m_scrub_reg_stamp = utime_t{};
@@ -618,11 +620,10 @@ void PgScrubber::add_delayed_scheduling()
   milliseconds sleep_time{0ms};
   if (m_needs_sleep) {
     double scrub_sleep = 1000.0 * m_osds->osd->scrub_sleep_time(m_flags.required);
-    dout(10) << __func__ << " sleep: " << scrub_sleep << dendl;
     sleep_time = milliseconds{long(scrub_sleep)};
   }
-  dout(15) << __func__ << " sleep: " << sleep_time.count() << " needed? " << m_needs_sleep
-	   << dendl;
+  dout(15) << __func__ << " sleep: " << sleep_time.count() << "ms. needed? "
+	   << m_needs_sleep << dendl;
 
   if (sleep_time.count()) {
     // schedule a transition for some 'sleep_time' ms in the future
@@ -1638,7 +1639,7 @@ void PgScrubber::scrub_finish()
 
 Scrub::FsmNext PgScrubber::on_digest_updates()
 {
-  dout(10) << __func__ << " #pending: " << num_digest_updates_pending << " are we done? "
+  dout(10) << __func__ << " #pending: " << num_digest_updates_pending << " pending? "
 	   << num_digest_updates_pending
 	   << (m_end.is_max() ? " <last chunk> " : " <mid chunk> ") << dendl;
 
diff --git a/src/osd/pg_scrubber.h b/src/osd/pg_scrubber.h
index e24ad422dfc41..226c5d41fca83 100644
--- a/src/osd/pg_scrubber.h
+++ b/src/osd/pg_scrubber.h
@@ -474,8 +474,6 @@ class PgScrubber : public ScrubPgIF, public ScrubMachineListener {
 
   epoch_t m_last_aborted{};  // last time we've noticed a request to abort
 
-
-
   /**
    * return true if any inconsistency/missing is repaired, false otherwise
    */
diff --git a/src/osd/scrub_machine.cc b/src/osd/scrub_machine.cc
index 9ae3e873f9575..2a2ee8732bda9 100644
--- a/src/osd/scrub_machine.cc
+++ b/src/osd/scrub_machine.cc
@@ -4,6 +4,9 @@
 #include "scrub_machine.h"
 
 #include <chrono>
+#include <typeinfo>
+
+#include <boost/core/demangle.hpp>
 
 #include "OSD.h"
 #include "OpRequest.h"
@@ -15,7 +18,6 @@
 #undef dout_prefix
 #define dout_prefix *_dout << " scrubberFSM "
 
-
 using namespace std::chrono;
 using namespace std::chrono_literals;
 namespace sc = boost::statechart;
@@ -32,19 +34,19 @@ namespace Scrub {
 
 void on_event_creation(std::string_view nm)
 {
-  dout(20) << " scrubberFSM event: --vvvv---- " << nm << dendl;
+  dout(20) << " event: --vvvv---- " << nm << dendl;
 }
 
 void on_event_discard(std::string_view nm)
 {
-  dout(20) << " scrubberFSM event: --^^^^---- " << nm << dendl;
+  dout(20) << " event: --^^^^---- " << nm << dendl;
 }
 
 void ScrubMachine::my_states() const
 {
   for (auto si = state_begin(); si != state_end(); ++si) {
     const auto& siw{*si};  // prevents a warning re side-effects
-    dout(20) << __func__ << " : scrub-states : " << typeid(siw).name() << dendl;
+    dout(20) << " state: " << boost::core::demangle(typeid(siw).name()) << dendl;
   }
 }
 
@@ -267,7 +269,7 @@ BuildMap::BuildMap(my_context ctx) : my_base(ctx)
   DECLARE_LOCALS;  // 'scrbr' & 'pg_id' aliases
 
   // no need to check for an epoch change, as all possible flows that brought us here have
-  // an check_interval() verification of their final event.
+  // a check_interval() verification of their final event.
 
   if (scrbr->get_preemptor().was_preempted()) {