From 00591653bce59ecf87ba06bc6c9b639de3949806 Mon Sep 17 00:00:00 2001
From: Jason Dillaman <dillaman@redhat.com>
Date: Fri, 3 Mar 2017 12:38:18 -0500
Subject: [PATCH] librbd: improve debug log messages for managed lock

Signed-off-by: Jason Dillaman <dillaman@redhat.com>
---
 src/librbd/ManagedLock.cc                 |  4 ++--
 src/librbd/managed_lock/AcquireRequest.cc |  3 ++-
 src/librbd/managed_lock/BreakRequest.cc   | 18 +++++++++++-------
 src/librbd/managed_lock/BreakRequest.h    |  3 ++-
 src/librbd/managed_lock/ReleaseRequest.cc |  3 ++-
 5 files changed, 19 insertions(+), 12 deletions(-)

diff --git a/src/librbd/ManagedLock.cc b/src/librbd/ManagedLock.cc
index 76594d3c0fd..3661e2fbdb9 100644
--- a/src/librbd/ManagedLock.cc
+++ b/src/librbd/ManagedLock.cc
@@ -19,7 +19,8 @@
 
 #define dout_subsys ceph_subsys_rbd
 #undef dout_prefix
-#define dout_prefix *_dout << "librbd::ManagedLock: " << this << " " <<  __func__
+#define dout_prefix *_dout << "librbd::ManagedLock: " << this << " " \
+                           <<  __func__
 
 namespace librbd {
 
@@ -663,7 +664,6 @@ void ManagedLock<I>::send_shutdown() {
     return;
   }
 
-  ldout(m_cct, 10) << dendl;
   assert(m_state == STATE_LOCKED);
   m_state = STATE_PRE_SHUTTING_DOWN;
 
diff --git a/src/librbd/managed_lock/AcquireRequest.cc b/src/librbd/managed_lock/AcquireRequest.cc
index b16c7597afe..0249be2a14e 100644
--- a/src/librbd/managed_lock/AcquireRequest.cc
+++ b/src/librbd/managed_lock/AcquireRequest.cc
@@ -103,7 +103,8 @@ void AcquireRequest<I>::handle_get_locker(int r) {
 
 template <typename I>
 void AcquireRequest<I>::send_lock() {
-  ldout(m_cct, 10) << "cookie=" << m_cookie << dendl;
+  ldout(m_cct, 10) << "entity=client." << m_ioctx.get_instance_id() << ", "
+                   << "cookie=" << m_cookie << dendl;
 
   librados::ObjectWriteOperation op;
   rados::cls::lock::lock(&op, RBD_LOCK_NAME,
diff --git a/src/librbd/managed_lock/BreakRequest.cc b/src/librbd/managed_lock/BreakRequest.cc
index 8d81af2f123..6c4d4d208fe 100644
--- a/src/librbd/managed_lock/BreakRequest.cc
+++ b/src/librbd/managed_lock/BreakRequest.cc
@@ -93,21 +93,25 @@ void BreakRequest<I>::handle_get_watchers(int r) {
     return;
   }
 
+  bool found_alive_locker = false;
   for (auto &watcher : m_watchers) {
+    ldout(m_cct, 20) << "watcher=["
+                     << "addr=" << watcher.addr << ", "
+                     << "entity=client." << watcher.watcher_id << "]" << dendl;
+
     if ((strncmp(m_locker.address.c_str(),
                  watcher.addr, sizeof(watcher.addr)) == 0) &&
         (m_locker.handle == watcher.cookie)) {
       ldout(m_cct, 10) << "lock owner is still alive" << dendl;
-
-      if (m_force_break_lock) {
-        break;
-      } else {
-        finish(-EAGAIN);
-        return;
-      }
+      found_alive_locker = true;
     }
   }
 
+  if (!m_force_break_lock && found_alive_locker) {
+    finish(-EAGAIN);
+    return;
+  }
+
   send_blacklist();
 }
 
diff --git a/src/librbd/managed_lock/BreakRequest.h b/src/librbd/managed_lock/BreakRequest.h
index 277e79eb927..045f629de29 100644
--- a/src/librbd/managed_lock/BreakRequest.h
+++ b/src/librbd/managed_lock/BreakRequest.h
@@ -34,7 +34,8 @@ public:
                               uint32_t blacklist_expire_seconds,
                               bool force_break_lock, Context *on_finish) {
     return new BreakRequest(ioctx, work_queue, oid, locker, blacklist_locker,
-                            blacklist_expire_seconds, force_break_lock, on_finish);
+                            blacklist_expire_seconds, force_break_lock,
+                            on_finish);
   }
 
   void send();
diff --git a/src/librbd/managed_lock/ReleaseRequest.cc b/src/librbd/managed_lock/ReleaseRequest.cc
index ddc5e9740bf..0ccf674f00c 100644
--- a/src/librbd/managed_lock/ReleaseRequest.cc
+++ b/src/librbd/managed_lock/ReleaseRequest.cc
@@ -55,7 +55,8 @@ void ReleaseRequest<I>::send() {
 template <typename I>
 void ReleaseRequest<I>::send_unlock() {
   CephContext *cct = reinterpret_cast<CephContext *>(m_ioctx.cct());
-  ldout(cct, 10) << "cookie=" << m_cookie << dendl;
+  ldout(cct, 10) << "entity=client." << m_ioctx.get_instance_id() << ", "
+                 << "cookie=" << m_cookie << dendl;
 
   librados::ObjectWriteOperation op;
   rados::cls::lock::unlock(&op, RBD_LOCK_NAME, m_cookie);