crimson/os/seastore: cleanup with empty transactions

* Add logs to identify OSD operation that submits transaction;
* Mark empty transactions as debug log;
* Misc cleanup;

Signed-off-by: Yingxin Cheng <yingxin.cheng@intel.com>

diff --git a/src/crimson/os/seastore/cache.cc b/src/crimson/os/seastore/cache.cc
index 2813864375629b4414849127fdec2d45b0a85c39..fdc591cf875944855491a7969418a12077e1779d 100644 (file)
--- a/src/crimson/os/seastore/cache.cc
+++ b/src/crimson/os/seastore/cache.cc
@@ -878,11 +878,12 @@ record_t Cache::prepare_record(Transaction &t)
   LOG_PREFIX(Cache::prepare_record);
   DEBUGT("enter", t);
 
+  auto trans_src = t.get_src();
   assert(!t.is_weak());
-  assert(t.get_src() != Transaction::src_t::READ);
+  assert(trans_src != Transaction::src_t::READ);
 
   auto& efforts = get_by_src(stats.committed_efforts_by_src,
-                             t.get_src());
+                             trans_src);
 
   // Should be valid due to interruptible future
   for (auto &i: t.read_set) {
@@ -1025,51 +1026,50 @@ record_t Cache::prepare_record(Transaction &t)
   auto& ool_stats = t.get_ool_write_stats();
   ceph_assert(ool_stats.extents.num == t.ool_block_list.size());
 
-  // FIXME: prevent submitting empty records
   if (record.is_empty()) {
-    ERRORT("record is empty!", t);
+    // XXX: improve osd logic to not submit empty transactions.
+    DEBUGT("record to submit is empty, src={}!", t, trans_src);
     assert(t.onode_tree_stats.is_clear());
     assert(t.lba_tree_stats.is_clear());
     assert(ool_stats.is_clear());
-    ++(efforts.num_trans);
-  } else {
-    DEBUGT("record is ready to submit, src={}, mdsize={}, dsize={}; "
-           "{} ool records, mdsize={}, dsize={}, fillness={}",
-           t, t.get_src(),
-           record.size.get_raw_mdlength(),
-           record.size.dlength,
-           ool_stats.num_records,
-           ool_stats.header_raw_bytes,
-           ool_stats.data_bytes,
-           ((double)(ool_stats.header_raw_bytes + ool_stats.data_bytes) /
-            (ool_stats.header_bytes + ool_stats.data_bytes)));
-    if (t.get_src() == Transaction::src_t::CLEANER_TRIM ||
-        t.get_src() == Transaction::src_t::CLEANER_RECLAIM) {
-      // CLEANER transaction won't contain any onode tree operations
-      assert(t.onode_tree_stats.is_clear());
-    } else {
-      if (t.onode_tree_stats.depth) {
-        stats.onode_tree_depth = t.onode_tree_stats.depth;
-      }
-      get_by_src(stats.committed_onode_tree_efforts, t.get_src()
-          ).increment(t.onode_tree_stats);
-    }
+  }
 
-    if (t.lba_tree_stats.depth) {
-      stats.lba_tree_depth = t.lba_tree_stats.depth;
+  DEBUGT("record is ready to submit, src={}, mdsize={}, dsize={}; "
+         "{} ool records, mdsize={}, dsize={}, fillness={}",
+         t, trans_src,
+         record.size.get_raw_mdlength(),
+         record.size.dlength,
+         ool_stats.num_records,
+         ool_stats.header_raw_bytes,
+         ool_stats.data_bytes,
+         ((double)(ool_stats.header_raw_bytes + ool_stats.data_bytes) /
+          (ool_stats.header_bytes + ool_stats.data_bytes)));
+  if (trans_src == Transaction::src_t::CLEANER_TRIM ||
+      trans_src == Transaction::src_t::CLEANER_RECLAIM) {
+    // CLEANER transaction won't contain any onode tree operations
+    assert(t.onode_tree_stats.is_clear());
+  } else {
+    if (t.onode_tree_stats.depth) {
+      stats.onode_tree_depth = t.onode_tree_stats.depth;
     }
-    get_by_src(stats.committed_lba_tree_efforts, t.get_src()
-        ).increment(t.lba_tree_stats);
+    get_by_src(stats.committed_onode_tree_efforts, trans_src
+        ).increment(t.onode_tree_stats);
+  }
 
-    ++(efforts.num_trans);
-    efforts.num_ool_records += ool_stats.num_records;
-    efforts.ool_record_padding_bytes +=
-      (ool_stats.header_bytes - ool_stats.header_raw_bytes);
-    efforts.ool_record_metadata_bytes += ool_stats.header_raw_bytes;
-    efforts.ool_record_data_bytes += ool_stats.data_bytes;
-    efforts.inline_record_metadata_bytes +=
-      (record.size.get_raw_mdlength() - record.get_delta_size());
+  if (t.lba_tree_stats.depth) {
+    stats.lba_tree_depth = t.lba_tree_stats.depth;
   }
+  get_by_src(stats.committed_lba_tree_efforts, trans_src
+      ).increment(t.lba_tree_stats);
+
+  ++(efforts.num_trans);
+  efforts.num_ool_records += ool_stats.num_records;
+  efforts.ool_record_padding_bytes +=
+    (ool_stats.header_bytes - ool_stats.header_raw_bytes);
+  efforts.ool_record_metadata_bytes += ool_stats.header_raw_bytes;
+  efforts.ool_record_data_bytes += ool_stats.data_bytes;
+  efforts.inline_record_metadata_bytes +=
+    (record.size.get_raw_mdlength() - record.get_delta_size());
 
   return record;
 }

diff --git a/src/crimson/os/seastore/seastore_types.cc b/src/crimson/os/seastore/seastore_types.cc
index d4adada28ab30fb19201643deb5f8d57ebecf383..ab8e2bcea558b80e7f2177808aeaa5a5a8727302 100644 (file)
--- a/src/crimson/os/seastore/seastore_types.cc
+++ b/src/crimson/os/seastore/seastore_types.cc
@@ -156,8 +156,7 @@ std::ostream &operator<<(std::ostream &out, const segment_header_t &header)
 
 extent_len_t record_size_t::get_raw_mdlength() const
 {
-  // FIXME: prevent submitting empty records
-  // assert(!is_empty());
+  // empty record is allowed to submit
   return plain_mdlength +
          ceph::encoded_sizeof_bounded<record_header_t>();
 }
@@ -186,8 +185,7 @@ void record_group_size_t::account(
     const record_size_t& rsize,
     extent_len_t _block_size)
 {
-  // FIXME: prevent submitting empty records
-  // assert(!rsize.is_empty());
+  // empty record is allowed to submit
   assert(_block_size > 0);
   assert(rsize.dlength % _block_size == 0);
   assert(block_size == 0 || block_size == _block_size);

diff --git a/src/crimson/osd/osd.cc b/src/crimson/osd/osd.cc
index 06f2209d3e964566738ce2f79a5ae012eb36adab..8f5a7f9d473e320cd5c4fe712b28d342481f9709 100644 (file)
--- a/src/crimson/osd/osd.cc
+++ b/src/crimson/osd/osd.cc
@@ -221,6 +221,7 @@ seastar::future<> OSD::_write_superblock()
         ceph::os::Transaction t;
         meta_coll->create(t);
         meta_coll->store_superblock(t, superblock);
+        logger().debug("OSD::_write_superblock: do_transaction...");
         return store.do_transaction(meta_coll->collection(), std::move(t));
       });
     }
@@ -1106,6 +1107,7 @@ seastar::future<> OSD::handle_osd_map(crimson::net::ConnectionRef conn,
         superblock.clean_thru = last;
       }
       meta_coll->store_superblock(t, superblock);
+      logger().debug("OSD::handle_osd_map: do_transaction...");
       return store.do_transaction(meta_coll->collection(), std::move(t));
     });
   }).then([=] {

diff --git a/src/crimson/osd/pg.cc b/src/crimson/osd/pg.cc
index a2d2d05304dbe324798c04d3c8c47f3921ac291a..aee8e833165726233b4f3e87227b03520b3916b6 100644 (file)
--- a/src/crimson/osd/pg.cc
+++ b/src/crimson/osd/pg.cc
@@ -130,6 +130,7 @@ PG::PG(
 PG::~PG() {}
 
 bool PG::try_flush_or_schedule_async() {
+  logger().debug("PG::try_flush_or_schedule_async: do_transaction...");
   (void)shard_services.get_store().do_transaction(
     coll_ref,
     ObjectStore::Transaction()).then(
@@ -1100,6 +1101,7 @@ PG::interruptible_future<> PG::handle_rep_op(Ref<MOSDRepOp> req)
   decode(log_entries, p);
   peering_state.append_log(std::move(log_entries), req->pg_trim_to,
       req->version, req->min_last_complete_ondisk, txn, !txn.empty(), false);
+  logger().debug("PG::handle_rep_op: do_transaction...");
   return interruptor::make_interruptible(shard_services.get_store().do_transaction(
        coll_ref, std::move(txn))).then_interruptible(
       [req, lcod=peering_state.get_info().last_complete, this] {

diff --git a/src/crimson/osd/recovery_backend.cc b/src/crimson/osd/recovery_backend.cc
index 8213525e3c6aa52591e1802bb6c5a803072ee7eb..04c9034a52c181854fbac86d9de39a1e9dc9bc6a 100644 (file)
--- a/src/crimson/osd/recovery_backend.cc
+++ b/src/crimson/osd/recovery_backend.cc
@@ -103,6 +103,7 @@ RecoveryBackend::handle_backfill_progress(
     m.stats,
     m.op == MOSDPGBackfill::OP_BACKFILL_PROGRESS,
     t);
+  logger().debug("RecoveryBackend::handle_backfill_progress: do_transaction...");
   return shard_services.get_store().do_transaction(
     pg.get_collection_ref(), std::move(t)).or_terminate();
 }
@@ -158,6 +159,7 @@ RecoveryBackend::handle_backfill_remove(
     t.remove(pg.get_collection_ref()->get_cid(),
              ghobject_t(soid, ghobject_t::NO_GEN, pg.get_pg_whoami().shard));
   }
+  logger().debug("RecoveryBackend::handle_backfill_remove: do_transaction...");
   return shard_services.get_store().do_transaction(
     pg.get_collection_ref(), std::move(t)).or_terminate();
 }

diff --git a/src/crimson/osd/replicated_backend.cc b/src/crimson/osd/replicated_backend.cc
index e4a21968b33f223f90ed628cf9140364973dc510..7cc0a6c8eb5ae5570c00cf2b20566b804dfc1f46 100644 (file)
--- a/src/crimson/osd/replicated_backend.cc
+++ b/src/crimson/osd/replicated_backend.cc
@@ -60,6 +60,7 @@ ReplicatedBackend::_submit_transaction(std::set<pg_shard_t>&& pg_shards,
   bufferlist encoded_txn;
   encode(txn, encoded_txn);
 
+  logger().debug("ReplicatedBackend::_submit_transaction: do_transaction...");
   auto all_completed = interruptor::make_interruptible(
       shard_services.get_store().do_transaction(coll, std::move(txn)))
   .then_interruptible([this, peers=pending_txn->second.weak_from_this()] {

diff --git a/src/crimson/osd/replicated_recovery_backend.cc b/src/crimson/osd/replicated_recovery_backend.cc
index d0cc5b3fc6701ebcde003c3a17c31b5aec19db6e..dae4c8ef853f85980faa674233f2ae3fb7b5f2f0 100644 (file)
--- a/src/crimson/osd/replicated_recovery_backend.cc
+++ b/src/crimson/osd/replicated_recovery_backend.cc
@@ -197,6 +197,7 @@ ReplicatedRecoveryBackend::on_local_recover_persist(
   logger().debug("{}", __func__);
   ceph::os::Transaction t;
   pg.get_recovery_handler()->on_local_recover(soid, _recovery_info, is_delete, t);
+  logger().debug("ReplicatedRecoveryBackend::on_local_recover_persist: do_transaction...");
   return interruptor::make_interruptible(
       shard_services.get_store().do_transaction(coll, std::move(t)))
   .then_interruptible(
@@ -220,6 +221,7 @@ ReplicatedRecoveryBackend::local_recover_delete(
        [this, lomt = std::move(lomt)](auto& txn) {
        return backend->remove(lomt->os, txn).then_interruptible(
          [this, &txn]() mutable {
+         logger().debug("ReplicatedRecoveryBackend::local_recover_delete: do_transaction...");
          return shard_services.get_store().do_transaction(coll,
                                                           std::move(txn));
        });
@@ -740,6 +742,7 @@ ReplicatedRecoveryBackend::handle_pull_response(
       return _handle_pull_response(from, pop, &response, &t).then_interruptible(
        [this, &t](bool complete) {
        epoch_t epoch_frozen = pg.get_osdmap_epoch();
+       logger().debug("ReplicatedRecoveryBackend::handle_pull_response: do_transaction...");
        return shard_services.get_store().do_transaction(coll, std::move(t))
          .then([this, epoch_frozen, complete,
          last_complete = pg.get_info().last_complete] {
@@ -824,6 +827,7 @@ ReplicatedRecoveryBackend::handle_push(
       return _handle_push(m->from, pop, &response, &t).then_interruptible(
        [this, &t] {
        epoch_t epoch_frozen = pg.get_osdmap_epoch();
+       logger().debug("ReplicatedRecoveryBackend::handle_push: do_transaction...");
        return interruptor::make_interruptible(
            shard_services.get_store().do_transaction(coll, std::move(t))).then_interruptible(
          [this, epoch_frozen, last_complete = pg.get_info().last_complete] {

diff --git a/src/crimson/osd/shard_services.cc b/src/crimson/osd/shard_services.cc
index 1723f775ef9d0e7e3de05adbcba848b0850e7ff3..17192e65d76a85e618d3ce95231906d464ce4714 100644 (file)
--- a/src/crimson/osd/shard_services.cc
+++ b/src/crimson/osd/shard_services.cc
@@ -106,6 +106,7 @@ seastar::future<> ShardServices::send_to_osd(
 
 seastar::future<> ShardServices::dispatch_context_transaction(
   crimson::os::CollectionRef col, PeeringCtx &ctx) {
+  logger().debug("ShardServices::dispatch_context_transaction: do_transaction...");
   auto ret = store.do_transaction(
     col,
     std::move(ctx.transaction));