crimson/osd: Add logs around handling of osdmaps

Signed-off-by: Matan Breizman <mbreizma@redhat.com>

diff --git a/src/crimson/osd/osd.cc b/src/crimson/osd/osd.cc
index dfb4f1e3e3d0ab1d78a4ab2c1118fd5744e87d19..b9f96ade818ee80d542d7f12a5ff6218ffa43e67 100644 (file)
--- a/src/crimson/osd/osd.cc
+++ b/src/crimson/osd/osd.cc
@@ -997,6 +997,8 @@ seastar::future<> OSD::committed_osd_maps(version_t first,
     }
     return check_osdmap_features().then([this] {
       // yay!
+      logger().info("osd.{}: committed_osd_maps: broadcasting osdmaps up"
+                    " to {} epoch to pgs", whoami, osdmap->get_epoch());
       return pg_shard_manager.broadcast_map_to_pgs(osdmap->get_epoch());
     });
   }).then([m, this] {

diff --git a/src/crimson/osd/osd_operations/pg_advance_map.cc b/src/crimson/osd/osd_operations/pg_advance_map.cc
index 2514a0e748145810bdb7a0799f4b70a7dc5589d3..cd2ef615b417e53f61fd0747fa8c01900032c9b3 100644 (file)
--- a/src/crimson/osd/osd_operations/pg_advance_map.cc
+++ b/src/crimson/osd/osd_operations/pg_advance_map.cc
@@ -24,7 +24,10 @@ PGAdvanceMap::PGAdvanceMap(
   ShardServices &shard_services, Ref<PG> pg, epoch_t to,
   PeeringCtx &&rctx, bool do_init)
   : shard_services(shard_services), pg(pg), to(to),
-    rctx(std::move(rctx)), do_init(do_init) {}
+    rctx(std::move(rctx)), do_init(do_init)
+{
+  logger().debug("{}: created", *this);
+}
 
 PGAdvanceMap::~PGAdvanceMap() {}
 
@@ -71,10 +74,13 @@ seastar::future<> PGAdvanceMap::start()
       });
     }
     return fut.then([this] {
+      ceph_assert(std::cmp_less_equal(*from, to));
       return seastar::do_for_each(
        boost::make_counting_iterator(*from + 1),
        boost::make_counting_iterator(to + 1),
        [this](epoch_t next_epoch) {
+         logger().debug("{}: start: getting map {}",
+                        *this, next_epoch);
          return shard_services.get_map(next_epoch).then(
            [this] (cached_map_t&& next_map) {
              logger().debug("{}: advancing map to {}",

diff --git a/src/crimson/osd/pg_shard_manager.cc b/src/crimson/osd/pg_shard_manager.cc
index 03174b1df0509256048b729126e14ede02c67141..01dbd11c21458204f0c796018c0c0b43654194ec 100644 (file)
--- a/src/crimson/osd/pg_shard_manager.cc
+++ b/src/crimson/osd/pg_shard_manager.cc
@@ -117,6 +117,9 @@ seastar::future<> PGShardManager::broadcast_map_to_pgs(epoch_t epoch)
       local_service, epoch
     );
   }).then([this, epoch] {
+    logger().debug("PGShardManager::broadcast_map_to_pgs "
+                   "broadcasted up to {}",
+                    epoch);
     get_osd_singleton_state().osdmap_gate.got_map(epoch);
     return seastar::now();
   });

diff --git a/src/crimson/osd/shard_services.cc b/src/crimson/osd/shard_services.cc
index 647d8d6bee4a52b8ac60ca4931e6b6d57e07304b..6ec6b5cbcbeff94742faeda66780c11076b2be91 100644 (file)
--- a/src/crimson/osd/shard_services.cc
+++ b/src/crimson/osd/shard_services.cc
@@ -349,8 +349,10 @@ OSDSingletonState::get_local_map(epoch_t e)
 {
   // TODO: use LRU cache for managing osdmap, fallback to disk if we have to
   if (auto found = osdmaps.find(e); found) {
+    logger().debug("{} osdmap.{} found in cache", __func__, e);
     return seastar::make_ready_future<local_cached_map_t>(std::move(found));
   } else {
+    logger().debug("{} loading osdmap.{} from disk", __func__, e);
     return load_map(e).then([e, this](std::unique_ptr<OSDMap> osdmap) {
       return seastar::make_ready_future<local_cached_map_t>(
        osdmaps.insert(e, std::move(osdmap)));
@@ -370,8 +372,10 @@ seastar::future<bufferlist> OSDSingletonState::load_map_bl(
   epoch_t e)
 {
   if (std::optional<bufferlist> found = map_bl_cache.find(e); found) {
+    logger().debug("{} osdmap.{} found in cache", __func__, e);
     return seastar::make_ready_future<bufferlist>(*found);
   } else {
+    logger().debug("{} loading osdmap.{} from disk", __func__, e);
     return meta_coll->load_map(e);
   }
 }
@@ -421,12 +425,15 @@ seastar::future<> OSDSingletonState::store_maps(ceph::os::Transaction& t,
       if (auto p = m->maps.find(e); p != m->maps.end()) {
        auto o = std::make_unique<OSDMap>();
        o->decode(p->second);
-       logger().info("store_maps osdmap.{}", e);
+       logger().info("store_maps storing osdmap.{}", e);
        store_map_bl(t, e, std::move(std::move(p->second)));
        osdmaps.insert(e, std::move(o));
        return seastar::now();
       } else if (auto p = m->incremental_maps.find(e);
                 p != m->incremental_maps.end()) {
+       logger().info("store_maps found osdmap.{} incremental map, "
+                     "loading osdmap.{}", e, e - 1);
+       ceph_assert(std::cmp_greater(e, 0u));
        return load_map(e - 1).then([e, bl=p->second, &t, this](auto o) {
          OSDMap::Incremental inc;
          auto i = bl.cbegin();
@@ -434,6 +441,7 @@ seastar::future<> OSDSingletonState::store_maps(ceph::os::Transaction& t,
          o->apply_incremental(inc);
          bufferlist fbl;
          o->encode(fbl, inc.encode_features | CEPH_FEATURE_RESERVED);
+         logger().info("store_maps storing osdmap.{}", o->get_epoch());
          store_map_bl(t, e, std::move(fbl));
          osdmaps.insert(e, std::move(o));
          return seastar::now();
@@ -700,6 +708,9 @@ seastar::future<> OSDSingletonState::send_incremental_map(
   crimson::net::Connection &conn,
   epoch_t first)
 {
+  logger().info("{}: first osdmap: {} "
+                "superblock's oldest map: {}",
+                __func__, first, superblock.oldest_map);
   if (first >= superblock.oldest_map) {
     return load_map_bls(
       first, superblock.newest_map