crimson/common/tri_mutex: add debug logs

to be used only for testing

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

Author: Matan-B

src/crimson/common/tri_mutex.cc

@@ -5,6 +5,9 @@
 
 #include <seastar/util/later.hh>
 
+SET_SUBSYS(osd);
+//TODO: SET_SUBSYS(crimson_tri_mutex);
+
 seastar::future<> read_lock::lock()
 {
   return static_cast<tri_mutex*>(this)->lock_for_read();
@@ -57,20 +60,28 @@ void excl_lock_from_write::unlock()
 
 tri_mutex::~tri_mutex()
 {
+  LOG_PREFIX(tri_mutex::~tri_mutex());
+  DEBUGDPP("", *this);
   assert(!is_acquired());
 }
 
 seastar::future<> tri_mutex::lock_for_read()
 {
+  LOG_PREFIX(tri_mutex::lock_for_read());
+  DEBUGDPP("", *this);
   if (try_lock_for_read()) {
+    DEBUGDPP("lock_for_read successfully", *this);
     return seastar::now();
   }
+  DEBUGDPP("can't lock_for_read, adding to waiters", *this);
   waiters.emplace_back(seastar::promise<>(), type_t::read);
   return waiters.back().pr.get_future();
 }
 
 bool tri_mutex::try_lock_for_read() noexcept
 {
+  LOG_PREFIX(tri_mutex::try_lock_for_read());
+  DEBUGDPP("", *this);
   if (!writers && !exclusively_used && waiters.empty()) {
     ++readers;
     return true;
@@ -81,6 +92,8 @@ bool tri_mutex::try_lock_for_read() noexcept
 
 void tri_mutex::unlock_for_read()
 {
+  LOG_PREFIX(tri_mutex::unlock_for_read());
+  DEBUGDPP("", *this);
   assert(readers > 0);
   if (--readers == 0) {
     wake();
@@ -89,29 +102,39 @@ void tri_mutex::unlock_for_read()
 
 void tri_mutex::promote_from_read()
 {
+  LOG_PREFIX(tri_mutex::promote_from_read());
+  DEBUGDPP("", *this);
   assert(readers == 1);
   --readers;
   exclusively_used = true;
 }
 
 void tri_mutex::demote_to_read()
 {
+  LOG_PREFIX(tri_mutex::demote_to_read());
+  DEBUGDPP("", *this);
   assert(exclusively_used);
   exclusively_used = false;
   ++readers;
 }
 
 seastar::future<> tri_mutex::lock_for_write()
 {
+  LOG_PREFIX(tri_mutex::lock_for_write());
+  DEBUGDPP("", *this);
   if (try_lock_for_write()) {
+    DEBUGDPP("lock_for_write successfully", *this);
     return seastar::now();
   }
+  DEBUGDPP("can't lock_for_write, adding to waiters", *this);
   waiters.emplace_back(seastar::promise<>(), type_t::write);
   return waiters.back().pr.get_future();
 }
 
 bool tri_mutex::try_lock_for_write() noexcept
 {
+  LOG_PREFIX(tri_mutex::try_lock_for_write());
+  DEBUGDPP("", *this);
   if (!readers && !exclusively_used) {
     if (waiters.empty()) {
       ++writers;
@@ -123,6 +146,8 @@ bool tri_mutex::try_lock_for_write() noexcept
 
 void tri_mutex::unlock_for_write()
 {
+  LOG_PREFIX(tri_mutex::unlock_for_write());
+  DEBUGDPP("", *this);
   assert(writers > 0);
   if (--writers == 0) {
     wake();
@@ -131,13 +156,17 @@ void tri_mutex::unlock_for_write()
 
 void tri_mutex::promote_from_write()
 {
+  LOG_PREFIX(tri_mutex::promote_from_write());
+  DEBUGDPP("", *this);
   assert(writers == 1);
   --writers;
   exclusively_used = true;
 }
 
 void tri_mutex::demote_to_write()
 {
+  LOG_PREFIX(tri_mutex::demote_to_write());
+  DEBUGDPP("", *this);
   assert(exclusively_used);
   exclusively_used = false;
   ++writers;
@@ -146,15 +175,21 @@ void tri_mutex::demote_to_write()
 // for exclusive users
 seastar::future<> tri_mutex::lock_for_excl()
 {
+  LOG_PREFIX(tri_mutex::lock_for_excl());
+  DEBUGDPP("", *this);
   if (try_lock_for_excl()) {
+    DEBUGDPP("lock_for_excl, successfully", *this);
     return seastar::now();
   }
+  DEBUGDPP("can't lock_for_excl, adding to waiters", *this);
   waiters.emplace_back(seastar::promise<>(), type_t::exclusive);
   return waiters.back().pr.get_future();
 }
 
 bool tri_mutex::try_lock_for_excl() noexcept
 {
+  LOG_PREFIX(tri_mutex::try_lock_for_excl());
+  DEBUGDPP("", *this);
   if (readers == 0u && writers == 0u && !exclusively_used) {
     exclusively_used = true;
     return true;
@@ -165,13 +200,17 @@ bool tri_mutex::try_lock_for_excl() noexcept
 
 void tri_mutex::unlock_for_excl()
 {
+  LOG_PREFIX(tri_mutex::unlock_for_excl());
+  DEBUGDPP("", *this);
   assert(exclusively_used);
   exclusively_used = false;
   wake();
 }
 
 bool tri_mutex::is_acquired() const
 {
+  LOG_PREFIX(tri_mutex::is_acquired());
+  DEBUGDPP("", *this);
   if (readers != 0u) {
     return true;
   } else if (writers != 0u) {
@@ -185,6 +224,8 @@ bool tri_mutex::is_acquired() const
 
 void tri_mutex::wake()
 {
+  LOG_PREFIX(tri_mutex::wake());
+  DEBUGDPP("", *this);
   assert(!readers && !writers && !exclusively_used);
   type_t type = type_t::none;
   while (!waiters.empty()) {
@@ -210,7 +251,9 @@ void tri_mutex::wake()
     default:
       assert(0);
     }
+    // TODO: DEBUGDPP("waking up {} ", *this);
     waiter.pr.set_value();
     waiters.pop_front();
   }
+  DEBUGDPP("no waiters", *this);
 }

src/crimson/common/tri_mutex.h

@@ -5,6 +5,7 @@
 
 #include <seastar/core/future.hh>
 #include <seastar/core/circular_buffer.hh>
+#include "crimson/common/log.h"
 
 class read_lock {
 public:
@@ -62,6 +63,11 @@ class tri_mutex : private read_lock,
 {
 public:
   tri_mutex() = default;
+#ifdef NDEBUG
+  tri_mutex(const std::string obj_name) : name() {}
+#else
+  tri_mutex(const std::string obj_name) : name(obj_name) {}
+#endif
   ~tri_mutex();
 
   read_lock& for_read() {
@@ -120,6 +126,10 @@ class tri_mutex : private read_lock,
     }
   }
 
+  std::string_view get_name() const{
+    return name;
+  }
+
 private:
   void wake();
   unsigned readers = 0;
@@ -139,10 +149,25 @@ class tri_mutex : private read_lock,
     type_t type;
   };
   seastar::circular_buffer<waiter_t> waiters;
+  const std::string name;
   friend class read_lock;
   friend class write_lock;
   friend class excl_lock;
   friend class excl_lock_from_read;
   friend class excl_lock_from_write;
   friend class excl_lock_from_excl;
+  friend std::ostream& operator<<(std::ostream &lhs, const tri_mutex &rhs);
 };
+
+inline std::ostream& operator<<(std::ostream& os, const tri_mutex& tm)
+{
+  os << fmt::format("tri_mutex {} writers {} readers {}"
+                    " exclusively_used {} waiters: {}",
+                    tm.get_name(), tm.get_writers(), tm.get_readers(),
+                    tm.exclusively_used, tm.waiters.size());
+  return os;
+}
+
+#if FMT_VERSION >= 90000
+template <> struct fmt::formatter<tri_mutex> : fmt::ostream_formatter {};
+#endif

src/crimson/osd/object_context.h

@@ -61,6 +61,10 @@ class ObjectContext : public ceph::common::intrusive_lru_base<
   ceph::common::intrusive_lru_config<
     hobject_t, ObjectContext, obc_to_hoid<ObjectContext>>>
 {
+private:
+  tri_mutex lock;
+  bool recovery_read_marker = false;
+
 public:
   ObjectState obs;
   SnapSetContextRef ssc;
@@ -74,7 +78,8 @@ class ObjectContext : public ceph::common::intrusive_lru_base<
   // make other users of this obc to await for the loading to complete.
   seastar::shared_mutex loading_mutex;
 
-  ObjectContext(hobject_t hoid) : obs(std::move(hoid)) {}
+  ObjectContext(hobject_t hoid) : lock(hoid.oid.name),
+                                  obs(std::move(hoid)) {}
 
   const hobject_t &get_oid() const {
     return obs.oi.soid;
@@ -130,9 +135,6 @@ class ObjectContext : public ceph::common::intrusive_lru_base<
   }
 
 private:
-  tri_mutex lock;
-  bool recovery_read_marker = false;
-
   template <typename Lock, typename Func>
   auto _with_lock(Lock& lock, Func&& func) {
     Ref obc = this;