osd: Cosmetic code cleanup and improve debug

All these changes are one of:
* Whitespace changes
* Addition/removal of debug
* Typos
* Make CPU-intensive debug statements deb ug level 30
* Remove unnecessary counter which did not really help with debug
* Extra comments

Signed-off-by: Alex Ainscow <aainscow@uk.ibm.com>

diff --git a/src/osd/ECBackend.cc b/src/osd/ECBackend.cc
index 2b093f3109de2c97c67afbe2caa621da84de8d7b..d219de97252a0c05c80e68dafc230a2b08e46203 100644 (file)
--- a/src/osd/ECBackend.cc
+++ b/src/osd/ECBackend.cc
@@ -200,7 +200,7 @@ void ECBackend::RecoveryBackend::handle_recovery_push(
   bool is_repair) {
   if (get_parent()->check_failsafe_full()) {
     dout(10) << __func__ << " Out of space (failsafe) processing push request."
- << dendl;
+             << dendl;
     ceph_abort();
   }
 
@@ -242,7 +242,7 @@ void ECBackend::RecoveryBackend::handle_recovery_push(
   }
 
   if (op.before_progress.first) {
-    ceph_assert(op.attrset.count(string("_")));
+    ceph_assert(op.attrset.contains(OI_ATTR));
     m->t.setattrs(
       coll,
       tobj,
@@ -290,9 +290,9 @@ void ECBackend::RecoveryBackend::handle_recovery_push(
 }
 
 void ECBackend::RecoveryBackend::handle_recovery_push_reply(
-  const PushReplyOp &op,
-  pg_shard_t from,
-  RecoveryMessages *m) {
+    const PushReplyOp &op,
+    pg_shard_t from,
+    RecoveryMessages *m) {
   if (!recovery_ops.count(op.soid))
     return;
   RecoveryOp &rop = recovery_ops[op.soid];
@@ -302,11 +302,11 @@ void ECBackend::RecoveryBackend::handle_recovery_push_reply(
 }
 
 void ECBackend::RecoveryBackend::handle_recovery_read_complete(
-  const hobject_t &hoid,
-  ECUtil::shard_extent_map_t &&buffers_read,
-  std::optional<map<string, bufferlist, less<>>> attrs,
-  const ECUtil::shard_extent_set_t &want_to_read,
-  RecoveryMessages *m) {
+    const hobject_t &hoid,
+    ECUtil::shard_extent_map_t &&buffers_read,
+    std::optional<map<string, bufferlist, less<>>> attrs,
+    const ECUtil::shard_extent_set_t &want_to_read,
+    RecoveryMessages *m) {
   dout(10) << __func__ << ": returned " << hoid << " " << buffers_read << dendl;
   ceph_assert(recovery_ops.contains(hoid));
   RecoveryBackend::RecoveryOp &op = recovery_ops[hoid];
@@ -393,8 +393,10 @@ void ECBackend::RecoveryBackend::handle_recovery_read_complete(
     }
   }
 
-  dout(20) << __func__ << ": oid=" << op.hoid << " "
-           << op.returned_data->debug_string(2048, 8) << dendl;
+  dout(20) << __func__ << ": oid=" << op.hoid << dendl;
+  dout(30) << __func__ << "EC_DEBUG_BUFFERS: "
+           << op.returned_data->debug_string(2048, 8)
+           << dendl;
 
   continue_recovery_op(op, m);
 }
@@ -1050,8 +1052,7 @@ void ECBackend::handle_sub_read(
                  << dendl;
         } else {
           get_parent()->clog_error() << "Error " << r
-            << " reading object "
-            << hoid;
+            << " reading object " << hoid;
           dout(5) << __func__ << ": Error " << r
                  << " reading " << hoid << dendl;
         }
@@ -1085,8 +1086,7 @@ void ECBackend::handle_sub_read(
         if (!hinfo) {
           r = -EIO;
           get_parent()->clog_error() << "Corruption detected: object "
-            << hoid
-            << " is missing hash_info";
+            << hoid << " is missing hash_info";
           dout(5) << __func__ << ": No hinfo for " << hoid << dendl;
           goto error;
         }
@@ -1102,8 +1102,8 @@ void ECBackend::handle_sub_read(
               << hex << h.digest() << " expected 0x" << hinfo->
               get_chunk_hash(shard) << dec;
             dout(5) << __func__ << ": Bad hash for " << hoid << " digest 0x"
-                   << hex << h.digest() << " expected 0x" << hinfo->
-get_chunk_hash(shard) << dec << dendl;
+                   << hex << h.digest() << " expected 0x"
+                    << hinfo->get_chunk_hash(shard) << dec << dendl;
             r = -EIO;
             goto error;
           }
@@ -1172,9 +1172,9 @@ void ECBackend::handle_sub_write_reply(
 }
 
 void ECBackend::handle_sub_read_reply(
-  pg_shard_t from,
-  ECSubReadReply &op,
-  const ZTracer::Trace &trace) {
+    pg_shard_t from,
+    ECSubReadReply &op,
+    const ZTracer::Trace &trace) {
   trace.event("ec sub read reply");
   dout(10) << __func__ << ": reply " << op << dendl;
   map<ceph_tid_t, ReadOp>::iterator iter = read_pipeline.tid_to_read_map.
@@ -1246,7 +1246,7 @@ void ECBackend::handle_sub_read_reply(
   for (auto &&[hoid, attr]: op.attrs_read) {
     ceph_assert(!op.errors.count(hoid));
     // if read error better not have sent an attribute
-    if (!rop.to_read.count(hoid)) {
+    if (!rop.to_read.contains(hoid)) {
       // We canceled this read! @see filter_read_op
       dout(20) << __func__ << " to_read skipping" << dendl;
       continue;
@@ -1290,6 +1290,8 @@ void ECBackend::handle_sub_read_reply(
       rop.to_read.at(oid).shard_want_to_read.
           populate_shard_id_set(want_to_read);
 
+      dout(20) << __func__ << " read_result: " << read_result << dendl;
+
       int err = ec_impl->minimum_to_decode(want_to_read, have, dummy_minimum,
                                             nullptr);
       if (err) {

diff --git a/src/osd/ECCommon.cc b/src/osd/ECCommon.cc
index 6a4d64ba41516b398474f35583fba5150d1195f4..56fe62457eeb84e2e293929e59d0fb1f2c3ebb90 100644 (file)
--- a/src/osd/ECCommon.cc
+++ b/src/osd/ECCommon.cc
@@ -161,8 +161,9 @@ void ECCommon::ReadPipeline::get_all_avail_shards(
 
   if (for_recovery) {
     for (auto &&pg_shard: get_parent()->get_backfill_shards()) {
-      if (error_shards && error_shards->contains(pg_shard))
+      if (error_shards && error_shards->contains(pg_shard)) {
         continue;
+      }
       const shard_id_t &shard = pg_shard.shard;
       if (have.contains(shard)) {
         ceph_assert(shards.contains(shard));
@@ -241,9 +242,7 @@ int ECCommon::ReadPipeline::get_min_avail_to_read_shards(
         (*need_sub_chunks)[i] = subchunks_list;
       }
     }
-    for (auto &&i: have) {
-      need_set.insert(i);
-    }
+    need_set.insert(have);
   }
 
   extent_set extra_extents;
@@ -488,18 +487,17 @@ struct ClientReadCompleter final : ECCommon::ReadCompleter {
     extent_map result;
     if (res.r == 0) {
       ceph_assert(res.errors.empty());
-#if DEBUG_EC_BUFFERS
-      dout(20) << __func__ << ": before decode: " << res.buffers_read.debug_string(2048, 8) << dendl;
-#endif
+      dout(30) << __func__ << ": before decode: "
+               << res.buffers_read.debug_string(2048, 8)
+               << dendl;
       /* Decode any missing buffers */
       int r = res.buffers_read.decode(read_pipeline.ec_impl,
                                   req.shard_want_to_read,
                                   req.object_size);
       ceph_assert( r == 0 );
-
-#if DEBUG_EC_BUFFERS
-      dout(20) << __func__ << ": after decode: " << res.buffers_read.debug_string(2048, 8) << dendl;
-#endif
+      dout(30) << __func__ << ": after decode: "
+               << res.buffers_read.debug_string(2048, 8)
+               << dendl;
 
       for (auto &&read: req.to_read) {
         result.insert(read.offset, read.size,
@@ -725,6 +723,8 @@ void ECCommon::RMWPipeline::cache_ready(Op &op) {
     if (transaction.empty()) {
       dout(20) << __func__ << " Transaction for osd." << pg_shard.osd << " shard " << shard << " is empty" << dendl;
     } else {
+      // NOTE: All code between dout and dendl is executed conditionally on
+      //       debug level.
       dout(20) << __func__ << " Transaction for osd." << pg_shard.osd << " shard " << shard << " contents ";
       Formatter *f = Formatter::create("json");
       f->open_object_section("t");
@@ -737,7 +737,7 @@ void ECCommon::RMWPipeline::cache_ready(Op &op) {
     if (op.skip_transaction(pending_roll_forward, shard, transaction)) {
       // Must be an empty transaction
       ceph_assert(transaction.empty());
-      dout(20) << __func__ << " Skipping transaction for osd." << shard << dendl;
+      dout(20) << __func__ << " Skipping transaction for shard " << shard << dendl;
       continue;
     }
     op.pending_commits++;
@@ -822,7 +822,7 @@ struct ECDummyOp final : ECCommon::RMWPipeline::Op {
       DoutPrefixProvider *dpp,
       const OSDMapRef &osdmap
     ) override {
-    // NOP, as -- in constrast to ECClassicalOp -- there is no
+    // NOP, as -- in contrast to ECClassicalOp -- there is no
     // transaction involved
   }
 
@@ -867,10 +867,7 @@ void ECCommon::RMWPipeline::finish_rmw(OpRef const &op) {
 
   if (extent_cache.idle()) {
     if (op->version > get_parent()->get_log().get_can_rollback_to()) {
-      const int transactions_since_last_idle = extent_cache.
-          get_and_reset_counter();
-      dout(20) << __func__ << " version=" << op->version << " ec_counter=" <<
-          transactions_since_last_idle << dendl;
+      dout(20) << __func__ << " cache idle " << op->version << dendl;
       // submit a dummy, transaction-empty op to kick the rollforward
       const auto tid = get_parent()->get_tid();
       const auto nop = std::make_shared<ECDummyOp>();

diff --git a/src/osd/ECCommon.h b/src/osd/ECCommon.h
index c1a490878e6e524d211f357545d403ab7b949f3e..d27cffabe113c82c57b60b796336c82aaa608f8a 100644 (file)
--- a/src/osd/ECCommon.h
+++ b/src/osd/ECCommon.h
@@ -181,7 +181,8 @@ struct ECCommon {
       } else {
         os << ", noattrs";
       }
-      os << ", buffers_read=" << buffers_read << ")";
+      os << ", buffers_read=" << buffers_read;
+      os << ", processed_read_requests=" << processed_read_requests << ")";
     }
   };
 

diff --git a/src/osd/ECExtentCache.cc b/src/osd/ECExtentCache.cc
index 8e8b5ac294ef9aba236d32642aad209b4a789550..8b5cd1635205b1d5edd0698dee654e380567feb3 100644 (file)
--- a/src/osd/ECExtentCache.cc
+++ b/src/osd/ECExtentCache.cc
@@ -334,7 +334,6 @@ void ECExtentCache::execute(list<OpRef> &op_list) {
     op->object.request(op);
   }
   waiting_ops.insert(waiting_ops.end(), op_list.begin(), op_list.end());
-  counter++;
   cache_maybe_ready();
 }
 
@@ -342,12 +341,6 @@ bool ECExtentCache::idle() const {
   return active_ios == 0;
 }
 
-uint32_t ECExtentCache::get_and_reset_counter() {
-  uint32_t ret = counter;
-  counter = 0;
-  return ret;
-}
-
 list<ECExtentCache::LRU::Key>::iterator ECExtentCache::LRU::erase(
     const list<Key>::iterator &it,
     bool do_update_mempool) {

diff --git a/src/osd/ECExtentCache.h b/src/osd/ECExtentCache.h
index 7945c507bf212cfbea414f2ff647e75235c65c4c..1b82cdbbee48d82d45eab0ec7611e793c9b3ee19 100644 (file)
--- a/src/osd/ECExtentCache.h
+++ b/src/osd/ECExtentCache.h
@@ -304,7 +304,6 @@ private:
   const ECUtil::stripe_info_t &sinfo;
   std::list<OpRef> waiting_ops;
   void cache_maybe_ready();
-  uint32_t counter = 0;
   uint32_t active_ios = 0;
   CephContext *cct;
 
@@ -360,7 +359,6 @@ private:
 
   void execute(std::list<OpRef> &op_list);
   [[nodiscard]] bool idle() const;
-  uint32_t get_and_reset_counter();
 
   void add_on_write(std::function<void(void)> &&cb) const {
     if (waiting_ops.empty()) {

diff --git a/src/osd/ECTransaction.cc b/src/osd/ECTransaction.cc
index d6de5274b8e61b863d822539743cca9159294922..1fbaaf31078bb50e563fbaff809224b799560db8 100644 (file)
--- a/src/osd/ECTransaction.cc
+++ b/src/osd/ECTransaction.cc
@@ -35,19 +35,11 @@ using ceph::encode;
 using ceph::ErasureCodeInterfaceRef;
 
 void debug(const hobject_t &oid, const std::string &str,
-           const ECUtil::shard_extent_map_t &map, DoutPrefixProvider *dpp
-  ) {
-#if DEBUG_EC_BUFFERS
+           const ECUtil::shard_extent_map_t &map, DoutPrefixProvider *dpp) {
   ldpp_dout(dpp, 20)
-    << "EC_DEBUG_BUFFERS: generate_transactions: "
-    << "oid: " << oid
-    << " " << str << " " << map.debug_string(2048, 8) << dendl;
-#else
-  ldpp_dout(dpp, 20)
-    << "generate_transactions: "
-    << "oid: " << oid
-    << str << map << dendl;
-#endif
+    << " generate_transactions: " << "oid: " << oid << str << map << dendl;
+  ldpp_dout(dpp, 30)
+    << "EC_DEBUG_BUFFERS: " << map.debug_string(2048, 8) << dendl;
 }
 
 void ECTransaction::Generate::encode_and_write() {
@@ -663,14 +655,18 @@ void ECTransaction::Generate::appends_and_clone_ranges() {
       }
       uint64_t new_shard_size = eset.range_end();
 
-      if (new_shard_size == old_shard_size) continue;
+      if (new_shard_size == old_shard_size) {
+        continue;
+      }
 
       uint64_t write_end = 0;
       if (plan.will_write.contains(shard)) {
         write_end = plan.will_write.at(shard).range_end();
       }
 
-      if (write_end == new_shard_size) continue;
+      if (write_end == new_shard_size) {
+        continue;
+      }
 
       /* If code is executing here, it means that the written part of the
        * shard does not reflect the size that EC believes the shard to be.
@@ -793,18 +789,18 @@ void ECTransaction::Generate::written_and_present_shards() {
         for (shard_id_t shard; shard < sinfo.get_k_plus_m(); ++shard) {
           if (sinfo.is_nonprimary_shard(shard)) {
             if (entry->is_written_shard(shard) || plan.orig_size != plan.
-              projected_size) {
-                // Written - erase per shard version
-                if (oi.shard_versions.erase(shard)) {
-                  update = true;
-                }
-              } else if (!oi.shard_versions.count(shard)) {
-                // Unwritten shard, previously up to date
-                oi.shard_versions[shard] = oi.prior_version;
+                projected_size) {
+              // Written - erase per shard version
+              if (oi.shard_versions.erase(shard)) {
                 update = true;
-              } else {
-                // Unwritten shard, already out of date
               }
+            } else if (!oi.shard_versions.count(shard)) {
+              // Unwritten shard, previously up to date
+              oi.shard_versions[shard] = oi.prior_version;
+              update = true;
+            } else {
+              // Unwritten shard, already out of date
+            }
           } else {
             // Primary shards are always written and use oi.version
           }
@@ -817,7 +813,8 @@ void ECTransaction::Generate::written_and_present_shards() {
         // Update cached OI
         obc->obs.oi.shard_versions = oi.shard_versions;
       }
-      ldpp_dout(dpp, 20) << __func__ << "shard_info: version=" << entry->version
+      ldpp_dout(dpp, 20) << __func__ << " shard_info: oid=" << oid
+                         << " version=" << entry->version
                          << " present=" << entry->present_shards
                          << " written=" << entry->written_shards
                          << " shard_versions=" << oi.shard_versions << dendl;

diff --git a/src/osd/ECTransaction.h b/src/osd/ECTransaction.h
index 64bb8eed1b4a566f7ec19232ab85cea15d86b40d..2393201db7399d20e0d57b820476ed3f233aa979 100644 (file)
--- a/src/osd/ECTransaction.h
+++ b/src/osd/ECTransaction.h
@@ -48,14 +48,16 @@ class WritePlanObj {
       const unsigned pdw_write_mode);
 
   void print(std::ostream &os) const {
-    os << "to_read: " << to_read
+    os << "{hoid: " << hoid
+       << " to_read: " << to_read
        << " will_write: " << will_write
        << " hinfo: " << hinfo
        << " shinfo: " << shinfo
        << " orig_size: " << orig_size
        << " projected_size: " << projected_size
        << " invalidates_cache: " << invalidates_cache
-       << " do_pdw: " << do_parity_delta_write;
+       << " do_pdw: " << do_parity_delta_write
+       << "}";
   }
 };
 
@@ -64,7 +66,7 @@ struct WritePlan {
   std::list<WritePlanObj> plans;
 
   void print(std::ostream &os) const {
-    os << " { plans : ";
+    os << " plans: [";
     bool first = true;
     for (auto && p : plans) {
       if (first) {
@@ -74,7 +76,7 @@ struct WritePlan {
       }
       os << p;
     }
-    os << "}";
+   os << "]";
   }
 };
 

diff --git a/src/osd/ECUtil.h b/src/osd/ECUtil.h
index d39b7a5c1bcb2e1f0d663f5ef777f482c17c39be..48cb70db37c857640cdb534c5a21b0a13d639cb2 100644 (file)
--- a/src/osd/ECUtil.h
+++ b/src/osd/ECUtil.h
@@ -209,10 +209,6 @@ public:
   }
 };
 
-// Setting to 1 turns on very large amounts of level 0 debug containing the
-// contents of buffers. Even on level 20 this is not really wanted.
-#define DEBUG_EC_BUFFERS 1
-
 namespace ECUtil {
 class shard_extent_map_t;
 
@@ -314,7 +310,9 @@ struct shard_extent_set_t {
   /** return the sum of extent_set.size */
   uint64_t size() const {
     uint64_t size = 0;
-    for (auto &&[_, e] : map) size += e.size();
+    for (auto &&[_, e] : map) {
+      size += e.size();
+    }
 
     return size;
   }

diff --git a/src/osd/PeeringState.cc b/src/osd/PeeringState.cc
index 119994d0d7baae0b666710a5d2ca21c6a2becbaa..a1a821bef26c0f900baf0bdd12dc297133871a95 100644 (file)
--- a/src/osd/PeeringState.cc
+++ b/src/osd/PeeringState.cc
@@ -2685,7 +2685,7 @@ bool PeeringState::search_for_missing(
     tinfo.partial_writes_last_complete = info.partial_writes_last_complete;
     if (!tinfo.partial_writes_last_complete.empty()) {
       psdout(20) << "sending info to " << from
-                << " pwcl=" << tinfo.partial_writes_last_complete
+                << " pwlc=" << tinfo.partial_writes_last_complete
                 << " info=" << tinfo
                 << dendl;
     }