librbd: cleanup logging code under librbd/io

Signed-off-by: runsisi <runsisi@zte.com.cn>

diff --git a/src/librbd/io/AioCompletion.cc b/src/librbd/io/AioCompletion.cc
index 7f83f4deab5a4e4c139eb6225daa6652de1e8fbb..cc40e8ffbe1af53ad7a9a3e958ebe6b7eafa8239 100644 (file)
--- a/src/librbd/io/AioCompletion.cc
+++ b/src/librbd/io/AioCompletion.cc
@@ -23,7 +23,8 @@
 
 #define dout_subsys ceph_subsys_rbd
 #undef dout_prefix
-#define dout_prefix *_dout << "librbd::io::AioCompletion: "
+#define dout_prefix *_dout << "librbd::io::AioCompletion: " << this \
+                           << " " << __func__ << ": "
 
 namespace librbd {
 namespace io {
@@ -44,7 +45,7 @@ void AioCompletion::finalize(ssize_t rval)
   assert(ictx != nullptr);
   CephContext *cct = ictx->cct;
 
-  ldout(cct, 20) << this << " " << __func__ << ": r=" << rval << dendl;
+  ldout(cct, 20) << "r=" << rval << dendl;
   if (rval >= 0 && aio_type == AIO_TYPE_READ) {
     read_result.assemble_result(cct);
   }
@@ -133,8 +134,7 @@ void AioCompletion::fail(int r)
   assert(ictx != nullptr);
   CephContext *cct = ictx->cct;
 
-  lderr(cct) << this << " " << __func__ << ": " << cpp_strerror(r)
-             << dendl;
+  lderr(cct) << cpp_strerror(r) << dendl;
   assert(pending_count == 0);
   rval = r;
   complete();
@@ -146,7 +146,7 @@ void AioCompletion::set_request_count(uint32_t count) {
   assert(ictx != nullptr);
   CephContext *cct = ictx->cct;
 
-  ldout(cct, 20) << this << " " << __func__ << ": pending=" << count << dendl;
+  ldout(cct, 20) << "pending=" << count << dendl;
   assert(pending_count == 0);
   pending_count = count;
   lock.Unlock();
@@ -170,7 +170,7 @@ void AioCompletion::complete_request(ssize_t r)
   assert(pending_count);
   int count = --pending_count;
 
-  ldout(cct, 20) << this << " " << __func__ << ": cb=" << complete_cb << ", "
+  ldout(cct, 20) << "cb=" << complete_cb << ", "
                  << "pending=" << pending_count << dendl;
   if (!count && blockers == 0) {
     finalize(rval);

diff --git a/src/librbd/io/CopyupRequest.cc b/src/librbd/io/CopyupRequest.cc
index 9ce36388d080abf80cd4ff71736af510ccda01c9..0f1d34f2075749a3faa8aca80d1c9e9bc9377c03 100644 (file)
--- a/src/librbd/io/CopyupRequest.cc
+++ b/src/librbd/io/CopyupRequest.cc
@@ -23,7 +23,8 @@
 
 #define dout_subsys ceph_subsys_rbd
 #undef dout_prefix
-#define dout_prefix *_dout << "librbd::io::CopyupRequest: "
+#define dout_prefix *_dout << "librbd::io::CopyupRequest: " << this \
+                           << " " << __func__ << ": "
 
 namespace librbd {
 namespace io {
@@ -93,7 +94,7 @@ CopyupRequest::~CopyupRequest() {
 }
 
 void CopyupRequest::append_request(ObjectRequest<> *req) {
-  ldout(m_ictx->cct, 20) << __func__ << " " << this << ": " << req << dendl;
+  ldout(m_ictx->cct, 20) << req << dendl;
   m_pending_requests.push_back(req);
 }
 
@@ -101,8 +102,7 @@ void CopyupRequest::complete_requests(int r) {
   while (!m_pending_requests.empty()) {
     vector<ObjectRequest<> *>::iterator it = m_pending_requests.begin();
     ObjectRequest<> *req = *it;
-    ldout(m_ictx->cct, 20) << __func__ << " completing request " << req
-                           << dendl;
+    ldout(m_ictx->cct, 20) << "completing request " << req << dendl;
     req->complete(r);
     m_pending_requests.erase(it);
   }
@@ -117,8 +117,7 @@ bool CopyupRequest::send_copyup() {
     add_copyup_op = true;
   }
 
-  ldout(m_ictx->cct, 20) << __func__ << " " << this
-                         << ": oid " << m_oid << dendl;
+  ldout(m_ictx->cct, 20) << "oid " << m_oid << dendl;
   m_state = STATE_COPYUP;
 
   m_ictx->snap_lock.get_read();
@@ -145,8 +144,7 @@ bool CopyupRequest::send_copyup() {
     // actual modification.
     m_pending_copyups++;
 
-    ldout(m_ictx->cct, 20) << __func__ << " " << this << " copyup with "
-                           << "empty snapshot context" << dendl;
+    ldout(m_ictx->cct, 20) << "copyup with empty snapshot context" << dendl;
     librados::AioCompletion *comp = util::create_rados_callback(this);
 
     librados::Rados rados(m_ictx->data_ctx);
@@ -168,8 +166,7 @@ bool CopyupRequest::send_copyup() {
     // merge all pending write ops into this single RADOS op
     for (size_t i=0; i<m_pending_requests.size(); ++i) {
       ObjectRequest<> *req = m_pending_requests[i];
-      ldout(m_ictx->cct, 20) << __func__ << " add_copyup_ops " << req
-                             << dendl;
+      ldout(m_ictx->cct, 20) << "add_copyup_ops " << req << dendl;
       req->add_copyup_ops(&write_op);
     }
     assert(write_op.size() != 0);
@@ -201,8 +198,7 @@ void CopyupRequest::send()
   AioCompletion *comp = AioCompletion::create_and_start(
     this, m_ictx, AIO_TYPE_READ);
 
-  ldout(m_ictx->cct, 20) << __func__ << " " << this
-                         << ": completion " << comp
+  ldout(m_ictx->cct, 20) << "completion " << comp
                          << ", oid " << m_oid
                          << ", extents " << m_image_extents
                          << dendl;
@@ -221,8 +217,7 @@ void CopyupRequest::complete(int r)
 bool CopyupRequest::should_complete(int r)
 {
   CephContext *cct = m_ictx->cct;
-  ldout(cct, 20) << __func__ << " " << this
-                 << ": oid " << m_oid
+  ldout(cct, 20) << "oid " << m_oid
                  << ", r " << r << dendl;
 
   uint64_t pending_copyups;
@@ -232,7 +227,7 @@ bool CopyupRequest::should_complete(int r)
     remove_from_list();
     if (r >= 0 || r == -ENOENT) {
       if (is_copyup_required()) {
-        ldout(cct, 20) << __func__ << " " << this << " nop, skipping" << dendl;
+        ldout(cct, 20) << "nop, skipping" << dendl;
         return true;
       }
 
@@ -285,7 +280,7 @@ void CopyupRequest::remove_from_list()
 
 bool CopyupRequest::send_object_map_head() {
   CephContext *cct = m_ictx->cct;
-  ldout(cct, 20) << __func__ << " " << this << dendl;
+  ldout(cct, 20) << dendl;
 
   m_state = STATE_OBJECT_MAP_HEAD;
 
@@ -321,7 +316,7 @@ bool CopyupRequest::send_object_map_head() {
         }
 
         current_state = (*m_ictx->object_map)[m_object_no];
-        ldout(cct, 20) << __func__ << " " << req->get_op_type() << " object no "
+        ldout(cct, 20) << req->get_op_type() << " object no "
                        << m_object_no << " current state "
                        << stringify(static_cast<uint32_t>(current_state))
                        << " new state " << stringify(static_cast<uint32_t>(new_state))
@@ -348,8 +343,7 @@ bool CopyupRequest::send_object_map() {
     return send_copyup();
   } else {
     // update object maps for HEAD and all existing snapshots
-    ldout(m_ictx->cct, 20) << __func__ << " " << this
-                           << ": oid " << m_oid << dendl;
+    ldout(m_ictx->cct, 20) << "oid " << m_oid << dendl;
     m_state = STATE_OBJECT_MAP;
 
     RWLock::RLocker owner_locker(m_ictx->owner_lock);

diff --git a/src/librbd/io/ImageRequest.cc b/src/librbd/io/ImageRequest.cc
index 71ae944240e80a87f318e51b0da84a28e638882b..e1a5ae1ca8b700d3246dc4ab6512f7d92068a15f 100644 (file)
--- a/src/librbd/io/ImageRequest.cc
+++ b/src/librbd/io/ImageRequest.cc
@@ -16,7 +16,8 @@
 
 #define dout_subsys ceph_subsys_rbd
 #undef dout_prefix
-#define dout_prefix *_dout << "librbd::io::ImageRequest: "
+#define dout_prefix *_dout << "librbd::io::ImageRequest: " << this \
+                           << " " << __func__ << ": "
 
 namespace librbd {
 namespace io {
@@ -38,8 +39,7 @@ struct C_DiscardJournalCommit : public Context {
     : image_ctx(_image_ctx), aio_comp(_aio_comp),
       object_extents(_object_extents) {
     CephContext *cct = image_ctx.cct;
-    ldout(cct, 20) << this << " C_DiscardJournalCommit: "
-                   << "delaying cache discard until journal tid " << tid << " "
+    ldout(cct, 20) << "delaying cache discard until journal tid " << tid << " "
                    << "safe" << dendl;
 
     aio_comp->add_request();
@@ -47,7 +47,7 @@ struct C_DiscardJournalCommit : public Context {
 
   void finish(int r) override {
     CephContext *cct = image_ctx.cct;
-    ldout(cct, 20) << this << " C_DiscardJournalCommit: "
+    ldout(cct, 20) << "C_DiscardJournalCommit: "
                    << "journal committed: discarding from cache" << dendl;
 
     Mutex::Locker cache_locker(image_ctx.cache_lock);
@@ -65,8 +65,7 @@ struct C_FlushJournalCommit : public Context {
                        uint64_t tid)
     : image_ctx(_image_ctx), aio_comp(_aio_comp) {
     CephContext *cct = image_ctx.cct;
-    ldout(cct, 20) << this << " C_FlushJournalCommit: "
-                   << "delaying flush until journal tid " << tid << " "
+    ldout(cct, 20) << "delaying flush until journal tid " << tid << " "
                    << "safe" << dendl;
 
     aio_comp->add_request();
@@ -74,8 +73,7 @@ struct C_FlushJournalCommit : public Context {
 
   void finish(int r) override {
     CephContext *cct = image_ctx.cct;
-    ldout(cct, 20) << this << " C_FlushJournalCommit: journal committed"
-                   << dendl;
+    ldout(cct, 20) << "C_FlushJournalCommit: journal committed" << dendl;
     aio_comp->complete_request(r);
   }
 };
@@ -273,7 +271,7 @@ void ImageReadRequest<I>::send_request() {
   // issue the requests
   for (auto &object_extent : object_extents) {
     for (auto &extent : object_extent.second) {
-      ldout(cct, 20) << " oid " << extent.oid << " " << extent.offset << "~"
+      ldout(cct, 20) << "oid " << extent.oid << " " << extent.offset << "~"
                      << extent.length << " from " << extent.buffer_extents
                      << dendl;
 
@@ -395,7 +393,7 @@ void AbstractImageWriteRequest<I>::send_object_requests(
   AioCompletion *aio_comp = this->m_aio_comp;
   for (ObjectExtents::const_iterator p = object_extents.begin();
        p != object_extents.end(); ++p) {
-    ldout(cct, 20) << " oid " << p->oid << " " << p->offset << "~" << p->length
+    ldout(cct, 20) << "oid " << p->oid << " " << p->offset << "~" << p->length
                    << " from " << p->buffer_extents << dendl;
     C_AioRequest *req_comp = new C_AioRequest(aio_comp);
     ObjectRequestHandle *request = create_object_request(*p, snapc,
@@ -543,7 +541,7 @@ void ImageDiscardRequest<I>::prune_object_extents(ObjectExtents &object_extents)
 
   for (auto p = object_extents.begin(); p != object_extents.end(); ) {
     if (p->offset + p->length < image_ctx.layout.object_size) {
-      ldout(cct, 20) << " oid " << p->oid << " " << p->offset << "~"
+      ldout(cct, 20) << "oid " << p->oid << " " << p->offset << "~"
                     << p->length << " from " << p->buffer_extents
                     << ": skip partial discard" << dendl;
       p = object_extents.erase(p);

diff --git a/src/librbd/io/ImageRequestWQ.cc b/src/librbd/io/ImageRequestWQ.cc
index d45a658bca21975005e1eb3c027e81c558d29331..d7c9fa3524779b58d875e614508836aed6520f89 100644 (file)
--- a/src/librbd/io/ImageRequestWQ.cc
+++ b/src/librbd/io/ImageRequestWQ.cc
@@ -14,7 +14,8 @@
 
 #define dout_subsys ceph_subsys_rbd
 #undef dout_prefix
-#define dout_prefix *_dout << "librbd::io::ImageRequestWQ: "
+#define dout_prefix *_dout << "librbd::io::ImageRequestWQ: " << this \
+                           << " " << __func__ << ": "
 
 namespace librbd {
 namespace io {
@@ -28,14 +29,14 @@ ImageRequestWQ::ImageRequestWQ(ImageCtx *image_ctx, const string &name,
     m_queued_writes(0), m_in_flight_ops(0), m_refresh_in_progress(false),
     m_shutdown(false), m_on_shutdown(nullptr) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 5) << this << " " << ": ictx=" << image_ctx << dendl;
+  ldout(cct, 5) << "ictx=" << image_ctx << dendl;
   tp->add_work_queue(this);
 }
 
 ssize_t ImageRequestWQ::read(uint64_t off, uint64_t len,
                              ReadResult &&read_result, int op_flags) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << "read: ictx=" << &m_image_ctx << ", off=" << off << ", "
+  ldout(cct, 20) << "ictx=" << &m_image_ctx << ", off=" << off << ", "
                  << "len = " << len << dendl;
 
   C_SaferCond cond;
@@ -47,7 +48,7 @@ ssize_t ImageRequestWQ::read(uint64_t off, uint64_t len,
 ssize_t ImageRequestWQ::write(uint64_t off, uint64_t len,
                               bufferlist &&bl, int op_flags) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << "write: ictx=" << &m_image_ctx << ", off=" << off << ", "
+  ldout(cct, 20) << "ictx=" << &m_image_ctx << ", off=" << off << ", "
                  << "len = " << len << dendl;
 
   m_image_ctx.snap_lock.get_read();
@@ -71,7 +72,7 @@ ssize_t ImageRequestWQ::write(uint64_t off, uint64_t len,
 
 ssize_t ImageRequestWQ::discard(uint64_t off, uint64_t len, bool skip_partial_discard) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << "discard: ictx=" << &m_image_ctx << ", off=" << off << ", "
+  ldout(cct, 20) << "ictx=" << &m_image_ctx << ", off=" << off << ", "
                  << "len = " << len << dendl;
 
   m_image_ctx.snap_lock.get_read();
@@ -96,7 +97,7 @@ ssize_t ImageRequestWQ::discard(uint64_t off, uint64_t len, bool skip_partial_di
 ssize_t ImageRequestWQ::writesame(uint64_t off, uint64_t len, bufferlist &&bl,
                                   int op_flags) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << "writesame ictx=" << &m_image_ctx << ", off=" << off << ", "
+  ldout(cct, 20) << "ictx=" << &m_image_ctx << ", off=" << off << ", "
                  << "len = " << len << ", data_len " << bl.length() << dendl;
 
   m_image_ctx.snap_lock.get_read();
@@ -123,7 +124,7 @@ void ImageRequestWQ::aio_read(AioCompletion *c, uint64_t off, uint64_t len,
                               bool native_async) {
   c->init_time(&m_image_ctx, AIO_TYPE_READ);
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << "aio_read: ictx=" << &m_image_ctx << ", "
+  ldout(cct, 20) << "ictx=" << &m_image_ctx << ", "
                  << "completion=" << c << ", off=" << off << ", "
                  << "len=" << len << ", " << "flags=" << op_flags << dendl;
 
@@ -162,7 +163,7 @@ void ImageRequestWQ::aio_write(AioCompletion *c, uint64_t off, uint64_t len,
                                bool native_async) {
   c->init_time(&m_image_ctx, AIO_TYPE_WRITE);
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << "aio_write: ictx=" << &m_image_ctx << ", "
+  ldout(cct, 20) << "ictx=" << &m_image_ctx << ", "
                  << "completion=" << c << ", off=" << off << ", "
                  << "len=" << len << ", flags=" << op_flags << dendl;
 
@@ -191,7 +192,7 @@ void ImageRequestWQ::aio_discard(AioCompletion *c, uint64_t off,
                                  bool native_async) {
   c->init_time(&m_image_ctx, AIO_TYPE_DISCARD);
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << "aio_discard: ictx=" << &m_image_ctx << ", "
+  ldout(cct, 20) << "ictx=" << &m_image_ctx << ", "
                  << "completion=" << c << ", off=" << off << ", len=" << len
                  << dendl;
 
@@ -216,7 +217,7 @@ void ImageRequestWQ::aio_discard(AioCompletion *c, uint64_t off,
 void ImageRequestWQ::aio_flush(AioCompletion *c, bool native_async) {
   c->init_time(&m_image_ctx, AIO_TYPE_FLUSH);
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << "aio_flush: ictx=" << &m_image_ctx << ", "
+  ldout(cct, 20) << "ictx=" << &m_image_ctx << ", "
                  << "completion=" << c << dendl;
 
   if (native_async && m_image_ctx.event_socket.is_valid()) {
@@ -241,7 +242,7 @@ void ImageRequestWQ::aio_writesame(AioCompletion *c, uint64_t off, uint64_t len,
                                    bool native_async) {
   c->init_time(&m_image_ctx, AIO_TYPE_WRITESAME);
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << "aio_writesame: ictx=" << &m_image_ctx << ", "
+  ldout(cct, 20) << "ictx=" << &m_image_ctx << ", "
                  << "completion=" << c << ", off=" << off << ", "
                  << "len=" << len << ", data_len = " << bl.length() << ", "
                  << "flags=" << op_flags << dendl;
@@ -306,8 +307,8 @@ void ImageRequestWQ::block_writes(Context *on_blocked) {
   {
     RWLock::WLocker locker(m_lock);
     ++m_write_blockers;
-    ldout(cct, 5) << __func__ << ": " << &m_image_ctx << ", "
-                  << "num=" << m_write_blockers << dendl;
+    ldout(cct, 5) << &m_image_ctx << ", " << "num="
+                  << m_write_blockers << dendl;
     if (!m_write_blocker_contexts.empty() || m_in_progress_writes > 0) {
       m_write_blocker_contexts.push_back(on_blocked);
       return;
@@ -327,8 +328,8 @@ void ImageRequestWQ::unblock_writes() {
     assert(m_write_blockers > 0);
     --m_write_blockers;
 
-    ldout(cct, 5) << __func__ << ": " << &m_image_ctx << ", "
-                  << "num=" << m_write_blockers << dendl;
+    ldout(cct, 5) << &m_image_ctx << ", " << "num="
+                  << m_write_blockers << dendl;
     if (m_write_blockers == 0) {
       wake_up = true;
     }
@@ -341,7 +342,7 @@ void ImageRequestWQ::unblock_writes() {
 
 void ImageRequestWQ::set_require_lock_on_read() {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << __func__ << dendl;
+  ldout(cct, 20) << dendl;
 
   RWLock::WLocker locker(m_lock);
   m_require_lock_on_read = true;
@@ -349,7 +350,7 @@ void ImageRequestWQ::set_require_lock_on_read() {
 
 void ImageRequestWQ::clear_require_lock_on_read() {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << __func__ << dendl;
+  ldout(cct, 20) << dendl;
 
   {
     RWLock::WLocker locker(m_lock);
@@ -410,7 +411,7 @@ void *ImageRequestWQ::_void_dequeue() {
 
 void ImageRequestWQ::process(ImageRequest<> *req) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << __func__ << ": ictx=" << &m_image_ctx << ", "
+  ldout(cct, 20) << "ictx=" << &m_image_ctx << ", "
                  << "req=" << req << dendl;
 
   req->send();
@@ -477,7 +478,7 @@ void ImageRequestWQ::finish_in_flight_op() {
   }
 
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 5) << __func__ << ": completing shut down" << dendl;
+  ldout(cct, 5) << "completing shut down" << dendl;
 
   assert(on_shutdown != nullptr);
   m_image_ctx.flush(on_shutdown);
@@ -494,7 +495,7 @@ bool ImageRequestWQ::is_lock_required() const {
 
 void ImageRequestWQ::queue(ImageRequest<> *req) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << __func__ << ": ictx=" << &m_image_ctx << ", "
+  ldout(cct, 20) << "ictx=" << &m_image_ctx << ", "
                  << "req=" << req << dendl;
 
   assert(m_image_ctx.owner_lock.is_locked());

diff --git a/src/librbd/io/ObjectRequest.cc b/src/librbd/io/ObjectRequest.cc
index 2b2b030c052d706265c2db857a87dcb2ccb00f03..97cd2e40881466637368058817e6accd653fbd26 100644 (file)
--- a/src/librbd/io/ObjectRequest.cc
+++ b/src/librbd/io/ObjectRequest.cc
@@ -24,7 +24,8 @@
 
 #define dout_subsys ceph_subsys_rbd
 #undef dout_prefix
-#define dout_prefix *_dout << "librbd::io::ObjectRequest: "
+#define dout_prefix *_dout << "librbd::io::ObjectRequest: " << this \
+                           << " " << __func__ << ": "
 
 namespace librbd {
 namespace io {
@@ -105,7 +106,7 @@ template <typename I>
 void ObjectRequest<I>::complete(int r)
 {
   if (should_complete(r)) {
-    ldout(m_ictx->cct, 20) << "complete " << this << dendl;
+    ldout(m_ictx->cct, 20) << dendl;
     if (m_hide_enoent && r == -ENOENT) {
       r = 0;
     }
@@ -124,8 +125,8 @@ bool ObjectRequest<I>::compute_parent_extents() {
   if (r < 0) {
     // NOTE: it's possible for a snapshot to be deleted while we are
     // still reading from it
-    lderr(m_ictx->cct) << this << " compute_parent_extents: failed to "
-                       << "retrieve parent overlap: " << cpp_strerror(r)
+    lderr(m_ictx->cct) << "failed to retrieve parent overlap: "
+                       << cpp_strerror(r)
                        << dendl;
     m_has_parent = false;
     m_parent_extents.clear();
@@ -135,8 +136,7 @@ bool ObjectRequest<I>::compute_parent_extents() {
   uint64_t object_overlap = m_ictx->prune_parent_extents(
     m_parent_extents, parent_overlap);
   if (object_overlap > 0) {
-    ldout(m_ictx->cct, 20) << this << " compute_parent_extents: "
-                           << "overlap " << parent_overlap << " "
+    ldout(m_ictx->cct, 20) << "overlap " << parent_overlap << " "
                            << "extents " << m_parent_extents << dendl;
     m_has_parent = !m_parent_extents.empty();
     return true;
@@ -175,7 +175,7 @@ void ObjectReadRequest<I>::guard_read()
   RWLock::RLocker parent_locker(image_ctx->parent_lock);
 
   if (this->has_parent()) {
-    ldout(image_ctx->cct, 20) << __func__ << " guarding read" << dendl;
+    ldout(image_ctx->cct, 20) << "guarding read" << dendl;
     m_state = LIBRBD_AIO_READ_GUARD;
   }
 }
@@ -184,8 +184,7 @@ template <typename I>
 bool ObjectReadRequest<I>::should_complete(int r)
 {
   ImageCtx *image_ctx = this->m_ictx;
-  ldout(image_ctx->cct, 20) << "should_complete " << this << " "
-                            << this->m_oid << " "
+  ldout(image_ctx->cct, 20) << this->m_oid << " "
                             << this->m_object_off << "~" << this->m_object_len
                             << " r = " << r << dendl;
 
@@ -193,8 +192,7 @@ bool ObjectReadRequest<I>::should_complete(int r)
 
   switch (m_state) {
   case LIBRBD_AIO_READ_GUARD:
-    ldout(image_ctx->cct, 20) << "should_complete " << this
-                              << " READ_CHECK_GUARD" << dendl;
+    ldout(image_ctx->cct, 20) << "READ_CHECK_GUARD" << dendl;
 
     // This is the step to read from parent
     if (!m_tried_parent && r == -ENOENT) {
@@ -235,8 +233,7 @@ bool ObjectReadRequest<I>::should_complete(int r)
     }
     break;
   case LIBRBD_AIO_READ_COPYUP:
-    ldout(image_ctx->cct, 20) << "should_complete " << this << " READ_COPYUP"
-                              << dendl;
+    ldout(image_ctx->cct, 20) << "READ_COPYUP" << dendl;
     // This is the extra step for copy-on-read: kick off an asynchronous copyup.
     // It is different from copy-on-write as asynchronous copyup will finish
     // by itself so state won't go back to LIBRBD_AIO_READ_GUARD.
@@ -250,8 +247,7 @@ bool ObjectReadRequest<I>::should_complete(int r)
     }
     break;
   case LIBRBD_AIO_READ_FLAT:
-    ldout(image_ctx->cct, 20) << "should_complete " << this << " READ_FLAT"
-                              << dendl;
+    ldout(image_ctx->cct, 20) << "READ_FLAT" << dendl;
     // The read content should be deposit in m_read_data
     break;
   default:
@@ -265,8 +261,8 @@ bool ObjectReadRequest<I>::should_complete(int r)
 template <typename I>
 void ObjectReadRequest<I>::send() {
   ImageCtx *image_ctx = this->m_ictx;
-  ldout(image_ctx->cct, 20) << "send " << this << " " << this->m_oid << " "
-                            << this->m_object_off << "~" << this->m_object_len
+  ldout(image_ctx->cct, 20) << this->m_oid << " " << this->m_object_off
+                            << "~" << this->m_object_len
                             << dendl;
 
   {
@@ -304,6 +300,9 @@ template <typename I>
 void ObjectReadRequest<I>::send_copyup()
 {
   ImageCtx *image_ctx = this->m_ictx;
+  ldout(image_ctx->cct, 20) << this->m_oid << " " << this->m_object_off
+                            << "~" << this->m_object_len << dendl;
+
   {
     RWLock::RLocker snap_locker(image_ctx->snap_lock);
     RWLock::RLocker parent_locker(image_ctx->parent_lock);
@@ -336,10 +335,8 @@ void ObjectReadRequest<I>::read_from_parent(Extents&& parent_extents)
   AioCompletion *parent_completion = AioCompletion::create_and_start<
     ObjectRequest<I> >(this, image_ctx, AIO_TYPE_READ);
 
-  ldout(image_ctx->cct, 20) << "read_from_parent this = " << this
-                            << " parent completion " << parent_completion
-                            << " extents " << parent_extents
-                            << dendl;
+  ldout(image_ctx->cct, 20) << "parent completion " << parent_completion
+                            << " extents " << parent_extents << dendl;
   ImageRequest<>::aio_read(image_ctx->parent, parent_completion,
                            std::move(parent_extents),
                            ReadResult{&m_read_data}, 0);
@@ -367,15 +364,15 @@ void AbstractObjectWriteRequest::guard_write()
   if (has_parent()) {
     m_state = LIBRBD_AIO_WRITE_GUARD;
     m_write.assert_exists();
-    ldout(m_ictx->cct, 20) << __func__ << " guarding write" << dendl;
+    ldout(m_ictx->cct, 20) << "guarding write" << dendl;
   }
 }
 
 bool AbstractObjectWriteRequest::should_complete(int r)
 {
-  ldout(m_ictx->cct, 20) << get_op_type() << " " << this << " " << m_oid
-                         << " " << m_object_off << "~" << m_object_len
-                         << " should_complete: r = " << r << dendl;
+  ldout(m_ictx->cct, 20) << get_op_type() << m_oid << " "
+                         << m_object_off << "~" << m_object_len
+                         << " r = " << r << dendl;
 
   bool finished = true;
   switch (m_state) {
@@ -443,9 +440,8 @@ bool AbstractObjectWriteRequest::should_complete(int r)
 }
 
 void AbstractObjectWriteRequest::send() {
-  ldout(m_ictx->cct, 20) << "send " << get_op_type() << " " << this <<" "
-                         << m_oid << " " << m_object_off << "~"
-                         << m_object_len << dendl;
+  ldout(m_ictx->cct, 20) << get_op_type() << " " << m_oid << " "
+                         << m_object_off << "~" << m_object_len << dendl;
   {
     RWLock::RLocker snap_lock(m_ictx->snap_lock);
     if (m_ictx->object_map == nullptr) {
@@ -461,7 +457,7 @@ void AbstractObjectWriteRequest::send() {
 }
 
 void AbstractObjectWriteRequest::send_pre_object_map_update() {
-  ldout(m_ictx->cct, 20) << __func__ << dendl;
+  ldout(m_ictx->cct, 20) << dendl;
 
   {
     RWLock::RLocker snap_lock(m_ictx->snap_lock);
@@ -469,9 +465,8 @@ void AbstractObjectWriteRequest::send_pre_object_map_update() {
       uint8_t new_state;
       pre_object_map_update(&new_state);
       RWLock::WLocker object_map_locker(m_ictx->object_map_lock);
-      ldout(m_ictx->cct, 20) << __func__ << this << " " << m_oid << " "
-                             << m_object_off << "~" << m_object_len
-                             << dendl;
+      ldout(m_ictx->cct, 20) << m_oid << " " << m_object_off
+                             << "~" << m_object_len << dendl;
       m_state = LIBRBD_AIO_WRITE_PRE;
 
       if (m_ictx->object_map->aio_update<ObjectRequest>(
@@ -485,6 +480,8 @@ void AbstractObjectWriteRequest::send_pre_object_map_update() {
 }
 
 bool AbstractObjectWriteRequest::send_post_object_map_update() {
+  ldout(m_ictx->cct, 20) << dendl;
+
   RWLock::RLocker snap_locker(m_ictx->snap_lock);
   if (m_ictx->object_map == nullptr || !post_object_map_update()) {
     return true;
@@ -494,8 +491,8 @@ bool AbstractObjectWriteRequest::send_post_object_map_update() {
   assert(m_ictx->exclusive_lock->is_lock_owner());
 
   RWLock::WLocker object_map_locker(m_ictx->object_map_lock);
-  ldout(m_ictx->cct, 20) << __func__ << this << " " << m_oid << " "
-                         << m_object_off << "~" << m_object_len << dendl;
+  ldout(m_ictx->cct, 20) << m_oid << " " << m_object_off
+                         << "~" << m_object_len << dendl;
   m_state = LIBRBD_AIO_WRITE_POST;
 
   if (m_ictx->object_map->aio_update<ObjectRequest>(
@@ -507,8 +504,7 @@ bool AbstractObjectWriteRequest::send_post_object_map_update() {
 }
 
 void AbstractObjectWriteRequest::send_write() {
-  ldout(m_ictx->cct, 20) << "send_write " << this << " " << m_oid << " "
-                        << m_object_off << "~" << m_object_len
+  ldout(m_ictx->cct, 20) << m_oid << " " << m_object_off << "~" << m_object_len
                          << " object exist " << m_object_exist << dendl;
 
   if (!m_object_exist && has_parent()) {
@@ -521,8 +517,8 @@ void AbstractObjectWriteRequest::send_write() {
 
 void AbstractObjectWriteRequest::send_copyup()
 {
-  ldout(m_ictx->cct, 20) << "send_copyup " << this << " " << m_oid << " "
-                         << m_object_off << "~" << m_object_len << dendl;
+  ldout(m_ictx->cct, 20) << m_oid << " " << m_object_off
+                         << "~" << m_object_len << dendl;
   m_state = LIBRBD_AIO_WRITE_COPYUP;
 
   m_ictx->copyup_list_lock.Lock();
@@ -598,8 +594,7 @@ void ObjectWriteRequest::add_write_ops(librados::ObjectWriteOperation *wr) {
 
 void ObjectWriteRequest::send_write() {
   bool write_full = (m_object_off == 0 && m_object_len == m_ictx->get_object_size());
-  ldout(m_ictx->cct, 20) << "send_write " << this << " " << m_oid << " "
-                         << m_object_off << "~" << m_object_len
+  ldout(m_ictx->cct, 20) << m_oid << " " << m_object_off << "~" << m_object_len
                          << " object exist " << m_object_exist
                          << " write_full " << write_full << dendl;
   if (write_full && !has_parent()) {
@@ -617,14 +612,13 @@ void ObjectRemoveRequest::guard_write() {
   }
 }
 void ObjectRemoveRequest::send_write() {
-  ldout(m_ictx->cct, 20) << "send_write " << this << " " << m_oid << " "
-                         << m_object_off << "~" << m_object_len << dendl;
+  ldout(m_ictx->cct, 20) << m_oid << " " << m_object_off
+                         << "~" << m_object_len << dendl;
   send_pre_object_map_update();
 }
 
 void ObjectTruncateRequest::send_write() {
-  ldout(m_ictx->cct, 20) << "send_write " << this << " " << m_oid
-                         << " truncate " << m_object_off << dendl;
+  ldout(m_ictx->cct, 20) << m_oid << " truncate " << m_object_off << dendl;
   if (!m_object_exist && ! has_parent()) {
     m_state = LIBRBD_AIO_WRITE_FLAT;
     Context *ctx = util::create_context_callback<ObjectRequest>(this);
@@ -647,8 +641,7 @@ void ObjectWriteSameRequest::add_write_ops(librados::ObjectWriteOperation *wr) {
 
 void ObjectWriteSameRequest::send_write() {
   bool write_full = (m_object_off == 0 && m_object_len == m_ictx->get_object_size());
-  ldout(m_ictx->cct, 20) << "send_write " << this << " " << m_oid << " "
-                         << m_object_off << "~" << m_object_len
+  ldout(m_ictx->cct, 20) << m_oid << " " << m_object_off << "~" << m_object_len
                          << " write_full " << write_full << dendl;
   if (write_full && !has_parent()) {
     m_guard = false;

diff --git a/src/librbd/io/ReadResult.cc b/src/librbd/io/ReadResult.cc
index 433dac73ca84ae0033619edc6cfcb8d2f482e6b7..1b8cdb0e6acf21e765295686c96884cbc14975ab 100644 (file)
--- a/src/librbd/io/ReadResult.cc
+++ b/src/librbd/io/ReadResult.cc
@@ -10,7 +10,8 @@
 
 #define dout_subsys ceph_subsys_rbd
 #undef dout_prefix
-#define dout_prefix *_dout << "librbd::io::ReadResult: "
+#define dout_prefix *_dout << "librbd::io::ReadResult: " << this \
+                           << " " << __func__ << ": "
 
 namespace librbd {
 namespace io {
@@ -89,7 +90,7 @@ void ReadResult::C_ReadRequest::finish(int r) {
 
 void ReadResult::C_ImageReadRequest::finish(int r) {
   CephContext *cct = aio_completion->ictx->cct;
-  ldout(cct, 10) << "C_ImageReadRequest::finish() " << this << ": r=" << r
+  ldout(cct, 10) << "C_ImageReadRequest: r=" << r
                  << dendl;
   if (r >= 0) {
     size_t length = 0;
@@ -114,7 +115,7 @@ void ReadResult::C_SparseReadRequestBase::finish(ExtentMap &extent_map,
                                                  bufferlist &bl, int r) {
   aio_completion->lock.Lock();
   CephContext *cct = aio_completion->ictx->cct;
-  ldout(cct, 10) << "C_SparseReadRequest::finish() " << this << " r = " << r
+  ldout(cct, 10) << "C_SparseReadRequestBase: r = " << r
                  << dendl;
 
   if (r >= 0 || r == -ENOENT) { // this was a sparse_read operation