Add more debugging around seastore splits

Signed-off-by: Aishwarya Mathuria <amathuri@redhat.com>

diff --git a/src/crimson/os/seastore/seastore.cc b/src/crimson/os/seastore/seastore.cc
index 6a03ab801bd2da9efc6f622d6283c9bebcc5cf27..514cdda57cc22cc205c6683810d9e80cfdaadef7 100644 (file)
--- a/src/crimson/os/seastore/seastore.cc
+++ b/src/crimson/os/seastore/seastore.cc
@@ -719,14 +719,20 @@ seastar::future<> SeaStore::report_stats()
 TransactionManager::read_extent_iertr::future<std::optional<unsigned>>
 SeaStore::Shard::get_coll_bits(CollectionRef ch, Transaction &t) const
 {
+  LOG_PREFIX(SeaStoreS::get_coll_bits);
   return transaction_manager->read_collection_root(t)
     .si_then([this, ch, &t](auto coll_root) {
       return collection_manager->list(coll_root, t);
-    }).si_then([ch](auto colls) {
+    }).si_then([ch, FNAME](auto colls) {
       auto it = std::find_if(colls.begin(), colls.end(),
         [ch](const std::pair<coll_t, coll_info_t>& element) {
           return element.first == ch->get_cid();
       });
+      // #region agent log
+      INFO("[split-thrash] get_coll_bits cid={} bits={}",
+        ch->get_cid().to_str(),
+        it != colls.end() ? std::to_string(it->second.split_bits) : "null");
+      // #endregion
       if (it != colls.end()) {
         return TransactionManager::read_extent_iertr::make_ready_future<
           std::optional<unsigned>>(it->second.split_bits);
@@ -820,6 +826,11 @@ SeaStore::Shard::list_objects(CollectionRef ch,
   ++(shard_stats.pending_read_num);
 
   ceph_assert(start <= end);
+  LOG_PREFIX(SeaStoreS::list_objects);
+  // #region agent log
+  INFO("[split-thrash] list_objects_entry cid={} start={} end={} limit={}",
+    ch->get_cid().to_str(), start, end, limit);
+  // #endregion
   using list_iertr = OnodeManager::list_onodes_iertr;
   using RetType = typename OnodeManager::list_onodes_bare_ret;
   return seastar::do_with(
@@ -851,6 +862,11 @@ SeaStore::Shard::list_objects(CollectionRef ch,
           } else {
            DEBUGT("bits={} ...", t, *bits);
             auto filter = SeaStore::get_objs_range(ch, *bits);
+            // #region agent log
+            INFO("[split-thrash] list_objects_range cid={} bits={} obj_begin={} obj_end={}",
+              ch->get_cid().to_str(), *bits,
+              filter.obj_begin, filter.obj_end);
+            // #endregion
            using list_iertr = OnodeManager::list_onodes_iertr;
            using repeat_ret = list_iertr::future<seastar::stop_iteration>;
             return trans_intr::repeat(
@@ -893,9 +909,17 @@ SeaStore::Shard::list_objects(CollectionRef ch,
                    >(seastar::stop_iteration::no);
                });
              }
-            ).si_then([&ret, FNAME] {
+            ).si_then([&ret, FNAME, ch] {
               DEBUG("got {} objects, next={}",
                     std::get<0>(ret).size(), std::get<1>(ret));
+              // #region agent log
+              {
+                const auto& objs = std::get<0>(ret);
+                INFO("[split-thrash] list_objects_result cid={} num_objects={} next={} first_oid={}",
+                  ch->get_cid().to_str(), objs.size(), std::get<1>(ret),
+                  objs.empty() ? ghobject_t{} : objs.front());
+              }
+              // #endregion
               return list_iertr::make_ready_future<
                 OnodeManager::list_onodes_bare_ret>(std::move(ret));
             });
@@ -1596,6 +1620,10 @@ SeaStore::Shard::_do_transaction_step(
       coll_t dest_cid = i.get_cid(op->dest_cid);
       DEBUGT("op OP_SPLIT_COLLECTION2, cid={}, dest_cid={}, bits={}",
        *ctx.transaction, cid, dest_cid, bits);
+      // #region agent log
+      INFO("[split-thrash] op_split_collection2 parent_cid={} child_cid={} bits={}",
+        cid.to_str(), dest_cid.to_str(), bits);
+      // #endregion
       return _split_collection(ctx, cid, bits);
     }
   }
@@ -1612,6 +1640,9 @@ SeaStore::Shard::_do_transaction_step(
   }
   if (!onodes[op->oid]) {
     const ghobject_t& oid = i.get_oid(op->oid);
+    coll_t cid = i.get_cid(op->cid);
+    INFO("[split-thrash] onode_access op={} cid={} oid={} create={}",
+      static_cast<int>(op->op), cid.to_str(), oid.hobj.to_str(), create);
     if (!create) {
       DEBUGT("op {}, get oid={} ...",
              *ctx.transaction, (uint32_t)op->op, oid);
@@ -1657,6 +1688,11 @@ SeaStore::Shard::_do_transaction_step(
       case Transaction::OP_REMOVE:
       {
         DEBUGT("op REMOVE, oid={} ...", *ctx.transaction, oid);
+        {
+          coll_t cid = i.get_cid(op->cid);
+          INFO("[split-thrash] onode_remove cid={} oid={}",
+            cid.to_str(), oid.hobj.to_str());
+        }
         return _remove(ctx, onode
        ).si_then([&onode] {
          onode.reset();
@@ -1669,6 +1705,11 @@ SeaStore::Shard::_do_transaction_step(
                *ctx.transaction,
                op->op == Transaction::OP_CREATE ? "CREATE" : "TOUCH",
                oid);
+        {
+          coll_t cid = i.get_cid(op->cid);
+          INFO("[split-thrash] onode_create op={} cid={} oid={}",
+            static_cast<int>(op->op), cid.to_str(), oid.hobj.to_str());
+        }
         return _touch(ctx, *onode);
       }
       case Transaction::OP_WRITE:
@@ -1842,7 +1883,13 @@ SeaStore::Shard::_do_transaction_step(
     }
   }).handle_error_interruptible(
     tm_iertr::pass_further{},
-    crimson::ct_error::enoent::handle([op] {
+    crimson::ct_error::enoent::handle([op, &ctx, &i, FNAME] {
+      {
+        const ghobject_t& oid = i.get_oid(op->oid);
+        coll_t cid = i.get_cid(op->cid);
+        INFO("[split-thrash] enoent op={} cid={} oid={}",
+          static_cast<int>(op->op), cid.to_str(), oid.hobj.to_str());
+      }
       //OMAP_CLEAR, TRUNCATE, REMOVE etc ops will tolerate absent onode.
       if (op->op == Transaction::OP_CLONERANGE ||
           op->op == Transaction::OP_CLONE ||
@@ -2279,6 +2326,11 @@ SeaStore::Shard::_split_collection(
   const coll_t &cid,
   int bits)
 {
+  LOG_PREFIX(SeaStoreS::_split_collection);
+  // #region agent log
+  INFO("[split-thrash] split_collection cid={} bits={}",
+    cid.to_str(), bits);
+  // #endregion
   return transaction_manager->read_collection_root(
     *ctx.transaction
   ).si_then([=, this, &ctx](auto _cmroot) {
@@ -2312,6 +2364,11 @@ SeaStore::Shard::_create_collection(
   internal_context_t &ctx,
   const coll_t& cid, int bits)
 {
+  LOG_PREFIX(SeaStoreS::_create_collection);
+  // #region agent log
+  INFO("[split-thrash] create_collection cid={} bits={}",
+    cid.to_str(), bits);
+  // #endregion
   return transaction_manager->read_collection_root(
     *ctx.transaction
   ).si_then([=, this, &ctx](auto _cmroot) {

diff --git a/src/crimson/osd/pg.cc b/src/crimson/osd/pg.cc
index 59f5ff7c764ec49d31921fea03f234c394bda909..66adb8ff1e038ea7b2b80c75bdd778d02aeabd39 100644 (file)
--- a/src/crimson/osd/pg.cc
+++ b/src/crimson/osd/pg.cc
@@ -482,6 +482,10 @@ PG::do_delete_work(ceph::os::Transaction &t, ghobject_t _next)
 {
   LOG_PREFIX(PG::do_delete_work);
   DEBUGDPP("removing pg {}", *this, pgid);
+  // #region agent log
+  DEBUGDPP("[split-thrash] do_delete_work_start cid={} next={}",
+    *this, coll_ref->get_cid().to_str(), _next);
+  // #endregion
   auto fut = interruptor::make_interruptible(
     shard_services.get_store().list_objects(
       coll_ref,
@@ -490,6 +494,11 @@ PG::do_delete_work(ceph::os::Transaction &t, ghobject_t _next)
       local_conf()->osd_target_transaction_size));
 
   auto [objs_to_rm, next] = fut.get();
+  // #region agent log
+  DEBUGDPP("[split-thrash] do_delete_work_list_result num_objs={} next={} first_oid={}",
+    *this, objs_to_rm.size(), next,
+    objs_to_rm.empty() ? ghobject_t{} : objs_to_rm[0]);
+  // #endregion
   if (objs_to_rm.empty()) {
     DEBUGDPP("all objs removed, removing coll for {}", *this, pgid);
     t.remove(coll_ref->get_cid(), pgid.make_snapmapper_oid());
@@ -507,7 +516,7 @@ PG::do_delete_work(ceph::os::Transaction &t, ghobject_t _next)
       if (obj == pgmeta_oid || obj.is_internal_pg_local()) {
         continue;
       }
-      TRACEDPP("pg {}, removing obj {}", *this, pgid, obj);
+      DEBUGDPP("pg {}, removing obj {}", *this, pgid, obj);
       t.remove(coll_ref->get_cid(), obj);
     }
     t.register_on_commit(