librbd: improve journaling debug log messages

Signed-off-by: Jason Dillaman <dillaman@redhat.com>

diff --git a/src/librbd/Journal.cc b/src/librbd/Journal.cc
index 231089f507ae6303f277557eacf58bbff686f8cc..5b8e305a908a8141efa058b4f04c4d64c4aeb126 100644 (file)
--- a/src/librbd/Journal.cc
+++ b/src/librbd/Journal.cc
@@ -50,7 +50,8 @@ struct C_DecodeTag : public Context {
 
   int process(int r) {
     if (r < 0) {
-      lderr(cct) << "failed to allocate tag: " << cpp_strerror(r) << dendl;
+      lderr(cct) << this << " " << __func__ << ": "
+                 << "failed to allocate tag: " << cpp_strerror(r) << dendl;
       return r;
     }
 
@@ -60,11 +61,13 @@ struct C_DecodeTag : public Context {
     bufferlist::iterator data_it = tag.data.begin();
     r = decode(&data_it, tag_data);
     if (r < 0) {
-      lderr(cct) << "failed to decode allocated tag" << dendl;
+      lderr(cct) << this << " " << __func__ << ": "
+                 << "failed to decode allocated tag" << dendl;
       return r;
     }
 
-    ldout(cct, 20) << "allocated journal tag: "
+    ldout(cct, 20) << this << " " << __func__ << ": "
+                   << "allocated journal tag: "
                    << "tid=" << tag.tid << ", "
                    << "data=" << *tag_data << dendl;
     return 0;
@@ -106,13 +109,15 @@ struct C_DecodeTags : public Context {
 
   int process(int r) {
     if (r < 0) {
-      lderr(cct) << "failed to retrieve journal tags: " << cpp_strerror(r)
+      lderr(cct) << this << " " << __func__ << ": "
+                 << "failed to retrieve journal tags: " << cpp_strerror(r)
                  << dendl;
       return r;
     }
 
     if (tags.empty()) {
-      lderr(cct) << "no journal tags retrieved" << dendl;
+      lderr(cct) << this << " " << __func__ << ": "
+                 << "no journal tags retrieved" << dendl;
       return -ENOENT;
     }
 
@@ -122,11 +127,13 @@ struct C_DecodeTags : public Context {
     bufferlist::iterator data_it = tags.back().data.begin();
     r = C_DecodeTag::decode(&data_it, tag_data);
     if (r < 0) {
-      lderr(cct) << "failed to decode journal tag" << dendl;
+      lderr(cct) << this << " " << __func__ << ": "
+                 << "failed to decode journal tag" << dendl;
       return r;
     }
 
-    ldout(cct, 20) << "most recent journal tag: "
+    ldout(cct, 20) << this << " " << __func__ << ": "
+                   << "most recent journal tag: "
                    << "tid=" << *tag_tid << ", "
                    << "data=" << *tag_data << dendl;
     return 0;
@@ -232,7 +239,8 @@ int allocate_journaler_tag(CephContext *cct, J *journaler,
 
   int r = allocate_tag_ctx.wait();
   if (r < 0) {
-    lderr(cct) << "failed to allocate tag: " << cpp_strerror(r) << dendl;
+    lderr(cct) << __func__ << ": "
+               << "failed to allocate tag: " << cpp_strerror(r) << dendl;
     return r;
   }
   return 0;
@@ -357,7 +365,8 @@ int Journal<I>::create(librados::IoCtx &io_ctx, const std::string &image_id,
     IoCtx data_io_ctx;
     int r = rados.ioctx_create(object_pool.c_str(), data_io_ctx);
     if (r != 0) {
-      lderr(cct) << "failed to create journal: "
+      lderr(cct) << __func__ << ": "
+                 << "failed to create journal: "
                 << "error opening journal objects pool '" << object_pool
                 << "': " << cpp_strerror(r) << dendl;
       return r;
@@ -370,7 +379,8 @@ int Journal<I>::create(librados::IoCtx &io_ctx, const std::string &image_id,
 
   int r = journaler.create(order, splay_width, pool_id);
   if (r < 0) {
-    lderr(cct) << "failed to create journal: " << cpp_strerror(r) << dendl;
+    lderr(cct) << __func__ << ": "
+               << "failed to create journal: " << cpp_strerror(r) << dendl;
     return r;
   }
 
@@ -391,7 +401,8 @@ int Journal<I>::create(librados::IoCtx &io_ctx, const std::string &image_id,
 
   r = journaler.register_client(client_data);
   if (r < 0) {
-    lderr(cct) << "failed to register client: " << cpp_strerror(r) << dendl;
+    lderr(cct) << __func__ << ": "
+               << "failed to register client: " << cpp_strerror(r) << dendl;
     return r;
   }
   return 0;
@@ -408,7 +419,8 @@ int Journal<I>::remove(librados::IoCtx &io_ctx, const std::string &image_id) {
   bool journal_exists;
   int r = journaler.exists(&journal_exists);
   if (r < 0) {
-    lderr(cct) << "failed to stat journal header: " << cpp_strerror(r) << dendl;
+    lderr(cct) << __func__ << ": "
+               << "failed to stat journal header: " << cpp_strerror(r) << dendl;
     return r;
   } else if (!journal_exists) {
     return 0;
@@ -424,13 +436,15 @@ int Journal<I>::remove(librados::IoCtx &io_ctx, const std::string &image_id) {
   if (r == -ENOENT) {
     return 0;
   } else if (r < 0) {
-    lderr(cct) << "failed to initialize journal: " << cpp_strerror(r) << dendl;
+    lderr(cct) << __func__ << ": "
+               << "failed to initialize journal: " << cpp_strerror(r) << dendl;
     return r;
   }
 
   r = journaler.remove(true);
   if (r < 0) {
-    lderr(cct) << "failed to remove journal: " << cpp_strerror(r) << dendl;
+    lderr(cct) << __func__ << ": "
+               << "failed to remove journal: " << cpp_strerror(r) << dendl;
     return r;
   }
   return 0;
@@ -454,7 +468,8 @@ int Journal<I>::reset(librados::IoCtx &io_ctx, const std::string &image_id) {
   if (r == -ENOENT) {
     return 0;
   } else if (r < 0) {
-    lderr(cct) << "failed to initialize journal: " << cpp_strerror(r) << dendl;
+    lderr(cct) << __func__ << ": "
+               << "failed to initialize journal: " << cpp_strerror(r) << dendl;
     return r;
   }
 
@@ -467,20 +482,23 @@ int Journal<I>::reset(librados::IoCtx &io_ctx, const std::string &image_id) {
     librados::Rados rados(io_ctx);
     r = rados.pool_reverse_lookup(pool_id, &pool_name);
     if (r < 0) {
-      lderr(cct) << "failed to lookup data pool: " << cpp_strerror(r) << dendl;
+      lderr(cct) << __func__ << ": "
+                 << "failed to lookup data pool: " << cpp_strerror(r) << dendl;
       return r;
     }
   }
 
   r = journaler.remove(true);
   if (r < 0) {
-    lderr(cct) << "failed to reset journal: " << cpp_strerror(r) << dendl;
+    lderr(cct) << __func__ << ": "
+               << "failed to reset journal: " << cpp_strerror(r) << dendl;
     return r;
   }
 
   r = create(io_ctx, image_id, order, splay_width, pool_name, false, "");
   if (r < 0) {
-    lderr(cct) << "failed to create journal: " << cpp_strerror(r) << dendl;
+    lderr(cct) << __func__ << ": "
+               << "failed to create journal: " << cpp_strerror(r) << dendl;
     return r;
   }
   return 0;
@@ -562,7 +580,8 @@ int Journal<I>::request_resync(I *image_ctx) {
 
   r = update_client_ctx.wait();
   if (r < 0) {
-    lderr(cct) << "failed to update client: " << cpp_strerror(r) << dendl;
+    lderr(cct) << __func__ << ": "
+               << "failed to update client: " << cpp_strerror(r) << dendl;
     return r;
   }
   return 0;
@@ -688,7 +707,8 @@ int Journal<I>::demote() {
   cls::journal::Client client;
   int r = m_journaler->get_cached_client(IMAGE_CLIENT_ID, &client);
   if (r < 0) {
-    lderr(cct) << "failed to retrieve client: " << cpp_strerror(r) << dendl;
+    lderr(cct) << this << " " << __func__ << ": "
+               << "failed to retrieve client: " << cpp_strerror(r) << dendl;
     return r;
   }
 
@@ -702,7 +722,8 @@ int Journal<I>::demote() {
   bufferlist::iterator tag_data_bl_it = new_tag.data.begin();
   r = C_DecodeTag::decode(&tag_data_bl_it, &m_tag_data);
   if (r < 0) {
-    lderr(cct) << "failed to decode newly allocated tag" << dendl;
+    lderr(cct) << this << " " << __func__ << ": "
+               << "failed to decode newly allocated tag" << dendl;
     return r;
   }
 
@@ -717,7 +738,8 @@ int Journal<I>::demote() {
 
   r = ctx.wait();
   if (r < 0) {
-    lderr(cct) << "failed to append demotion journal event: " << cpp_strerror(r)
+    lderr(cct) << this << " " << __func__ << ": "
+               << "failed to append demotion journal event: " << cpp_strerror(r)
                << dendl;
     return r;
   }
@@ -728,7 +750,8 @@ int Journal<I>::demote() {
 
   r = flush_ctx.wait();
   if (r < 0) {
-    lderr(cct) << "failed to flush demotion commit position: "
+    lderr(cct) << this << " " << __func__ << ": "
+               << "failed to flush demotion commit position: "
                << cpp_strerror(r) << dendl;
     return r;
   }
@@ -751,7 +774,8 @@ void Journal<I>::allocate_local_tag(Context *on_finish) {
     cls::journal::Client client;
     int r = m_journaler->get_cached_client(IMAGE_CLIENT_ID, &client);
     if (r < 0) {
-      lderr(cct) << "failed to retrieve client: " << cpp_strerror(r) << dendl;
+      lderr(cct) << this << " " << __func__ << ": "
+                 << "failed to retrieve client: " << cpp_strerror(r) << dendl;
       m_image_ctx.op_work_queue->queue(on_finish, r);
       return;
     }
@@ -947,7 +971,8 @@ void Journal<I>::commit_io_event_extent(uint64_t tid, uint64_t offset,
 
   event.pending_extents.subtract(intersect);
   if (!event.pending_extents.empty()) {
-    ldout(cct, 20) << "pending extents: " << event.pending_extents << dendl;
+    ldout(cct, 20) << this << " " << __func__ << ": "
+                   << "pending extents: " << event.pending_extents << dendl;
     return;
   }
   complete_event(it, event.ret_val);
@@ -1069,7 +1094,8 @@ typename Journal<I>::Future Journal<I>::wait_event(Mutex &lock, uint64_t tid,
   Event &event = it->second;
   if (event.safe) {
     // journal entry already safe
-    ldout(cct, 20) << "journal entry already safe" << dendl;
+    ldout(cct, 20) << this << " " << __func__ << ": "
+                   << "journal entry already safe" << dendl;
     m_image_ctx.op_work_queue->queue(on_safe, event.ret_val);
     return Future();
   }
@@ -1115,7 +1141,8 @@ void Journal<I>::handle_start_external_replay(int r,
   assert(m_journal_replay == nullptr);
 
   if (r < 0) {
-    lderr(cct) << "failed to stop recording: " << cpp_strerror(r) << dendl;
+    lderr(cct) << this << " " << __func__ << ": "
+               << "failed to stop recording: " << cpp_strerror(r) << dendl;
     *journal_replay = nullptr;
 
     if (m_on_replay_close_request != nullptr) {
@@ -1227,7 +1254,8 @@ void Journal<I>::complete_event(typename Events::iterator it, int r) {
     // event recorded to journal but failed to update disk, we cannot
     // commit this IO event. this event must be replayed.
     assert(event.safe);
-    lderr(cct) << "failed to commit IO to disk, replay required: "
+    lderr(cct) << this << " " << __func__ << ": "
+               << "failed to commit IO to disk, replay required: "
                << cpp_strerror(r) << dendl;
   }
 
@@ -1275,7 +1303,8 @@ void Journal<I>::handle_initialized(int r) {
   r = m_journaler->get_cached_client(Journal<ImageCtx>::IMAGE_CLIENT_ID,
                                      &client);
   if (r < 0) {
-    lderr(cct) << "failed to locate master image client" << dendl;
+    lderr(cct) << this << " " << __func__ << ": "
+               << "failed to locate master image client" << dendl;
     destroy_journaler(r);
     return;
   }
@@ -1285,7 +1314,8 @@ void Journal<I>::handle_initialized(int r) {
   try {
     ::decode(client_data, bl);
   } catch (const buffer::error &err) {
-    lderr(cct) << "failed to decode client meta data: " << err.what()
+    lderr(cct) << this << " " << __func__ << ": "
+               << "failed to decode client meta data: " << err.what()
                << dendl;
     destroy_journaler(-EINVAL);
     return;
@@ -1294,13 +1324,15 @@ void Journal<I>::handle_initialized(int r) {
   journal::ImageClientMeta *image_client_meta =
     boost::get<journal::ImageClientMeta>(&client_data.client_meta);
   if (image_client_meta == nullptr) {
-    lderr(cct) << "failed to extract client meta data" << dendl;
+    lderr(cct) << this << " " << __func__ << ": "
+               << "failed to extract client meta data" << dendl;
     destroy_journaler(-EINVAL);
     return;
   }
 
   m_tag_class = image_client_meta->tag_class;
-  ldout(cct, 20) << "client: " << client << ", "
+  ldout(cct, 20) << this << " " << __func__ << ": "
+                 << "client: " << client << ", "
                  << "image meta: " << *image_client_meta << dendl;
 
   C_DecodeTags *tags_ctx = new C_DecodeTags(
@@ -1356,8 +1388,8 @@ void Journal<I>::handle_replay_ready() {
   journal::EventEntry event_entry;
   int r = m_journal_replay->decode(&it, &event_entry);
   if (r < 0) {
-    lderr(cct) << this << " " << __func__
-               << ": failed to decode journal event entry" << dendl;
+    lderr(cct) << this << " " << __func__ << ": "
+               << "failed to decode journal event entry" << dendl;
     handle_replay_process_safe(replay_entry, r);
     return;
   }
@@ -1441,7 +1473,8 @@ void Journal<I>::handle_replay_process_safe(ReplayEntry replay_entry, int r) {
 
   ldout(cct, 20) << this << " " << __func__ << ": r=" << r << dendl;
   if (r < 0) {
-    lderr(cct) << "failed to commit journal event to disk: " << cpp_strerror(r)
+    lderr(cct) << this << " " << __func__ << ": "
+               << "failed to commit journal event to disk: " << cpp_strerror(r)
                << dendl;
 
     if (m_state == STATE_REPLAYING) {
@@ -1561,7 +1594,8 @@ void Journal<I>::handle_io_event_safe(int r, uint64_t tid) {
   // journal will be flushed before closing
   assert(m_state == STATE_READY || m_state == STATE_STOPPING);
   if (r < 0) {
-    lderr(cct) << "failed to commit IO event: "  << cpp_strerror(r) << dendl;
+    lderr(cct) << this << " " << __func__ << ": "
+               << "failed to commit IO event: "  << cpp_strerror(r) << dendl;
   }
 
   AioObjectRequests aio_object_requests;
@@ -1591,7 +1625,8 @@ void Journal<I>::handle_io_event_safe(int r, uint64_t tid) {
     }
   }
 
-  ldout(cct, 20) << "completing tid=" << tid << dendl;
+  ldout(cct, 20) << this << " " << __func__ << ": "
+                 << "completing tid=" << tid << dendl;
   for (AioObjectRequests::iterator it = aio_object_requests.begin();
        it != aio_object_requests.end(); ++it) {
     if (r < 0) {
@@ -1622,7 +1657,8 @@ void Journal<I>::handle_op_event_safe(int r, uint64_t tid,
   // journal will be flushed before closing
   assert(m_state == STATE_READY || m_state == STATE_STOPPING);
   if (r < 0) {
-    lderr(cct) << "failed to commit op event: "  << cpp_strerror(r) << dendl;
+    lderr(cct) << this << " " << __func__ << ": "
+               << "failed to commit op event: "  << cpp_strerror(r) << dendl;
   }
 
   m_journaler->committed(op_start_future);
@@ -1712,7 +1748,8 @@ int Journal<I>::check_resync_requested_internal(bool *do_resync) {
   cls::journal::Client client;
   int r = m_journaler->get_cached_client(IMAGE_CLIENT_ID, &client);
   if (r < 0) {
-     lderr(cct) << "failed to retrieve client: " << cpp_strerror(r) << dendl;
+     lderr(cct) << this << " " << __func__ << ": "
+                << "failed to retrieve client: " << cpp_strerror(r) << dendl;
      return r;
   }
 
@@ -1721,14 +1758,16 @@ int Journal<I>::check_resync_requested_internal(bool *do_resync) {
   try {
     ::decode(client_data, bl_it);
   } catch (const buffer::error &err) {
-    lderr(cct) << "failed to decode client data: " << err << dendl;
+    lderr(cct) << this << " " << __func__ << ": "
+               << "failed to decode client data: " << err << dendl;
     return -EINVAL;
   }
 
   journal::ImageClientMeta *image_client_meta =
     boost::get<journal::ImageClientMeta>(&client_data.client_meta);
   if (image_client_meta == nullptr) {
-    lderr(cct) << "failed to access image client meta struct" << dendl;
+    lderr(cct) << this << " " << __func__ << ": "
+               << "failed to access image client meta struct" << dendl;
     return -EINVAL;
   }
 
@@ -1755,7 +1794,8 @@ void Journal<I>::handle_metadata_updated() {
     bool do_resync = false;
     int r = check_resync_requested_internal(&do_resync);
     if (r < 0) {
-      lderr(cct) << "failed to check if a resync was requested" << dendl;
+      lderr(cct) << this << " " << __func__ << ": "
+                 << "failed to check if a resync was requested" << dendl;
       return;
     }
 

diff --git a/src/librbd/journal/Replay.cc b/src/librbd/journal/Replay.cc
index 0228e315a87ebd05de0d917b2d5e949970580f34..e306b708466f66bf395b1aeea75d9e0d062c7739 100644 (file)
--- a/src/librbd/journal/Replay.cc
+++ b/src/librbd/journal/Replay.cc
@@ -15,7 +15,7 @@
 
 #define dout_subsys ceph_subsys_rbd
 #undef dout_prefix
-#define dout_prefix *_dout << "librbd::journal::Replay: "
+#define dout_prefix *_dout << "librbd::journal::Replay: " << this << " "
 
 namespace librbd {
 namespace journal {
@@ -92,12 +92,12 @@ struct ExecuteOp : public Context {
   virtual void finish(int r) override {
     CephContext *cct = image_ctx.cct;
     if (r < 0) {
-      lderr(cct) << "ExecuteOp: " << __func__ << ": r=" << r << dendl;
+      lderr(cct) << ": ExecuteOp::" << __func__ << ": r=" << r << dendl;
       on_op_complete->complete(r);
       return;
     }
 
-    ldout(cct, 20) << "ExecuteOp: " << __func__ << dendl;
+    ldout(cct, 20) << ": ExecuteOp::" << __func__ << dendl;
     RWLock::RLocker owner_locker(image_ctx.owner_lock);
     execute(event);
   }
@@ -121,13 +121,13 @@ struct C_RefreshIfRequired : public Context {
     on_finish = nullptr;
 
     if (r < 0) {
-      lderr(cct) << "C_RefreshIfRequired: " << __func__ << ": r=" << r << dendl;
+      lderr(cct) << ": C_RefreshIfRequired::" << __func__ << ": r=" << r << dendl;
       image_ctx.op_work_queue->queue(ctx, r);
       return;
     }
 
     if (image_ctx.state->is_refresh_required()) {
-      ldout(cct, 20) << "C_RefreshIfRequired: " << __func__ << ": "
+      ldout(cct, 20) << ": C_RefreshIfRequired::" << __func__ << ": "
                      << "refresh required" << dendl;
       image_ctx.state->refresh(ctx);
       return;
@@ -139,6 +139,10 @@ struct C_RefreshIfRequired : public Context {
 
 } // anonymous namespace
 
+#undef dout_prefix
+#define dout_prefix *_dout << "librbd::journal::Replay: " << this << " " \
+                           << __func__
+
 template <typename I>
 Replay<I>::Replay(I &image_ctx)
   : m_image_ctx(image_ctx), m_lock("Replay<I>::m_lock") {
@@ -168,8 +172,8 @@ template <typename I>
 void Replay<I>::process(const EventEntry &event_entry,
                         Context *on_ready, Context *on_safe) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": "
-                 << "on_ready=" << on_ready << ", on_safe=" << on_safe << dendl;
+  ldout(cct, 20) << ": on_ready=" << on_ready << ", on_safe=" << on_safe
+                 << dendl;
 
   on_ready = util::create_async_context_callback(m_image_ctx, on_ready);
 
@@ -181,7 +185,7 @@ void Replay<I>::process(const EventEntry &event_entry,
 template <typename I>
 void Replay<I>::shut_down(bool cancel_ops, Context *on_finish) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << dendl;
+  ldout(cct, 20) << dendl;
 
   AioCompletion *flush_comp = nullptr;
   on_finish = util::create_async_context_callback(
@@ -249,7 +253,7 @@ void Replay<I>::flush(Context *on_finish) {
 template <typename I>
 void Replay<I>::replay_op_ready(uint64_t op_tid, Context *on_resume) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": op_tid=" << op_tid << dendl;
+  ldout(cct, 20) << ": op_tid=" << op_tid << dendl;
 
   Mutex::Locker locker(m_lock);
   auto op_it = m_op_events.find(op_tid);
@@ -289,7 +293,7 @@ template <typename I>
 void Replay<I>::handle_event(const journal::AioDiscardEvent &event,
                              Context *on_ready, Context *on_safe) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": AIO discard event" << dendl;
+  ldout(cct, 20) << ": AIO discard event" << dendl;
 
   bool flush_required;
   AioCompletion *aio_comp = create_aio_modify_completion(on_ready, on_safe,
@@ -309,7 +313,7 @@ template <typename I>
 void Replay<I>::handle_event(const journal::AioWriteEvent &event,
                              Context *on_ready, Context *on_safe) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": AIO write event" << dendl;
+  ldout(cct, 20) << ": AIO write event" << dendl;
 
   bufferlist data = event.data;
   bool flush_required;
@@ -330,7 +334,7 @@ template <typename I>
 void Replay<I>::handle_event(const journal::AioFlushEvent &event,
                             Context *on_ready, Context *on_safe) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": AIO flush event" << dendl;
+  ldout(cct, 20) << ": AIO flush event" << dendl;
 
   AioCompletion *aio_comp;
   {
@@ -346,7 +350,7 @@ template <typename I>
 void Replay<I>::handle_event(const journal::OpFinishEvent &event,
                              Context *on_ready, Context *on_safe) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": Op finish event: "
+  ldout(cct, 20) << ": Op finish event: "
                  << "op_tid=" << event.op_tid << dendl;
 
   bool op_in_progress;
@@ -357,7 +361,7 @@ void Replay<I>::handle_event(const journal::OpFinishEvent &event,
     Mutex::Locker locker(m_lock);
     auto op_it = m_op_events.find(event.op_tid);
     if (op_it == m_op_events.end()) {
-      ldout(cct, 10) << "unable to locate associated op: assuming previously "
+      ldout(cct, 10) << ": unable to locate associated op: assuming previously "
                      << "committed." << dendl;
       on_ready->complete(0);
       m_image_ctx.op_work_queue->queue(on_safe, 0);
@@ -401,7 +405,7 @@ template <typename I>
 void Replay<I>::handle_event(const journal::SnapCreateEvent &event,
                             Context *on_ready, Context *on_safe) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": Snap create event" << dendl;
+  ldout(cct, 20) << ": Snap create event" << dendl;
 
   Mutex::Locker locker(m_lock);
   OpEvent *op_event;
@@ -430,7 +434,7 @@ template <typename I>
 void Replay<I>::handle_event(const journal::SnapRemoveEvent &event,
                             Context *on_ready, Context *on_safe) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": Snap remove event" << dendl;
+  ldout(cct, 20) << ": Snap remove event" << dendl;
 
   Mutex::Locker locker(m_lock);
   OpEvent *op_event;
@@ -454,7 +458,7 @@ template <typename I>
 void Replay<I>::handle_event(const journal::SnapRenameEvent &event,
                             Context *on_ready, Context *on_safe) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": Snap rename event" << dendl;
+  ldout(cct, 20) << ": Snap rename event" << dendl;
 
   Mutex::Locker locker(m_lock);
   OpEvent *op_event;
@@ -478,7 +482,7 @@ template <typename I>
 void Replay<I>::handle_event(const journal::SnapProtectEvent &event,
                             Context *on_ready, Context *on_safe) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": Snap protect event" << dendl;
+  ldout(cct, 20) << ": Snap protect event" << dendl;
 
   Mutex::Locker locker(m_lock);
   OpEvent *op_event;
@@ -502,8 +506,7 @@ template <typename I>
 void Replay<I>::handle_event(const journal::SnapUnprotectEvent &event,
                             Context *on_ready, Context *on_safe) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": Snap unprotect event"
-                 << dendl;
+  ldout(cct, 20) << ": Snap unprotect event" << dendl;
 
   Mutex::Locker locker(m_lock);
   OpEvent *op_event;
@@ -531,8 +534,7 @@ template <typename I>
 void Replay<I>::handle_event(const journal::SnapRollbackEvent &event,
                             Context *on_ready, Context *on_safe) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": Snap rollback start event"
-                 << dendl;
+  ldout(cct, 20) << ": Snap rollback start event" << dendl;
 
   Mutex::Locker locker(m_lock);
   OpEvent *op_event;
@@ -554,7 +556,7 @@ template <typename I>
 void Replay<I>::handle_event(const journal::RenameEvent &event,
                             Context *on_ready, Context *on_safe) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": Rename event" << dendl;
+  ldout(cct, 20) << ": Rename event" << dendl;
 
   Mutex::Locker locker(m_lock);
   OpEvent *op_event;
@@ -578,7 +580,7 @@ template <typename I>
 void Replay<I>::handle_event(const journal::ResizeEvent &event,
                             Context *on_ready, Context *on_safe) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": Resize start event" << dendl;
+  ldout(cct, 20) << ": Resize start event" << dendl;
 
   Mutex::Locker locker(m_lock);
   OpEvent *op_event;
@@ -603,7 +605,7 @@ template <typename I>
 void Replay<I>::handle_event(const journal::FlattenEvent &event,
                             Context *on_ready, Context *on_safe) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": Flatten start event" << dendl;
+  ldout(cct, 20) << ": Flatten start event" << dendl;
 
   Mutex::Locker locker(m_lock);
   OpEvent *op_event;
@@ -627,7 +629,7 @@ template <typename I>
 void Replay<I>::handle_event(const journal::DemoteEvent &event,
                             Context *on_ready, Context *on_safe) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": Demote event" << dendl;
+  ldout(cct, 20) << ": Demote event" << dendl;
   on_ready->complete(0);
   on_safe->complete(0);
 }
@@ -636,8 +638,7 @@ template <typename I>
 void Replay<I>::handle_event(const journal::SnapLimitEvent &event,
                             Context *on_ready, Context *on_safe) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": Snap limit event"
-                 << dendl;
+  ldout(cct, 20) << ": Snap limit event" << dendl;
 
   Mutex::Locker locker(m_lock);
   OpEvent *op_event;
@@ -659,7 +660,7 @@ template <typename I>
 void Replay<I>::handle_event(const journal::UnknownEvent &event,
                             Context *on_ready, Context *on_safe) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": unknown event" << dendl;
+  ldout(cct, 20) << ": unknown event" << dendl;
   on_ready->complete(0);
   on_safe->complete(0);
 }
@@ -669,14 +670,14 @@ void Replay<I>::handle_aio_modify_complete(Context *on_ready, Context *on_safe,
                                            int r) {
   Mutex::Locker locker(m_lock);
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": on_ready=" << on_ready << ", "
+  ldout(cct, 20) << ": on_ready=" << on_ready << ", "
                  << "on_safe=" << on_safe << ", r=" << r << dendl;
 
   if (on_ready != nullptr) {
     on_ready->complete(0);
   }
   if (r < 0) {
-    lderr(cct) << "AIO modify op failed: " << cpp_strerror(r) << dendl;
+    lderr(cct) << ": AIO modify op failed: " << cpp_strerror(r) << dendl;
     on_safe->complete(r);
     return;
   }
@@ -689,10 +690,10 @@ template <typename I>
 void Replay<I>::handle_aio_flush_complete(Context *on_flush_safe,
                                           Contexts &on_safe_ctxs, int r) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": " << "r=" << r << dendl;
+  ldout(cct, 20) << ": r=" << r << dendl;
 
   if (r < 0) {
-    lderr(cct) << "AIO flush failed: " << cpp_strerror(r) << dendl;
+    lderr(cct) << ": AIO flush failed: " << cpp_strerror(r) << dendl;
   }
 
   Context *on_aio_ready = nullptr;
@@ -721,7 +722,7 @@ void Replay<I>::handle_aio_flush_complete(Context *on_flush_safe,
   }
 
   if (on_aio_ready != nullptr) {
-    ldout(cct, 10) << "resuming paused AIO" << dendl;
+    ldout(cct, 10) << ": resuming paused AIO" << dendl;
     on_aio_ready->complete(0);
   }
 
@@ -729,12 +730,12 @@ void Replay<I>::handle_aio_flush_complete(Context *on_flush_safe,
     on_safe_ctxs.push_back(on_flush_safe);
   }
   for (auto ctx : on_safe_ctxs) {
-    ldout(cct, 20) << "completing safe context: " << ctx << dendl;
+    ldout(cct, 20) << ": completing safe context: " << ctx << dendl;
     ctx->complete(r);
   }
 
   if (on_flush != nullptr) {
-    ldout(cct, 20) << "completing flush context: " << on_flush << dendl;
+    ldout(cct, 20) << ": completing flush context: " << on_flush << dendl;
     on_flush->complete(r);
   }
 }
@@ -748,7 +749,7 @@ Context *Replay<I>::create_op_context_callback(uint64_t op_tid,
 
   assert(m_lock.is_locked());
   if (m_op_events.count(op_tid) != 0) {
-    lderr(cct) << "duplicate op tid detected: " << op_tid << dendl;
+    lderr(cct) << ": duplicate op tid detected: " << op_tid << dendl;
 
     // on_ready is already async but on failure invoke on_safe async
     // as well
@@ -769,7 +770,7 @@ Context *Replay<I>::create_op_context_callback(uint64_t op_tid,
 template <typename I>
 void Replay<I>::handle_op_complete(uint64_t op_tid, int r) {
   CephContext *cct = m_image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << ": op_tid=" << op_tid << ", "
+  ldout(cct, 20) << ": op_tid=" << op_tid << ", "
                  << "r=" << r << dendl;
 
   OpEvent op_event;
@@ -851,7 +852,7 @@ AioCompletion *Replay<I>::create_aio_modify_completion(Context *on_ready,
   *flush_required = (m_aio_modify_unsafe_contexts.size() ==
                        IN_FLIGHT_IO_LOW_WATER_MARK);
   if (*flush_required) {
-    ldout(cct, 10) << "hit AIO replay low-water mark: scheduling flush"
+    ldout(cct, 10) << ": hit AIO replay low-water mark: scheduling flush"
                    << dendl;
   }
 
@@ -861,7 +862,7 @@ AioCompletion *Replay<I>::create_aio_modify_completion(Context *on_ready,
   //   shrink has adjusted clip boundary, etc) -- should have already been
   //   flagged not-ready
   if (m_in_flight_aio_modify == IN_FLIGHT_IO_HIGH_WATER_MARK) {
-    ldout(cct, 10) << "hit AIO replay high-water mark: pausing replay"
+    ldout(cct, 10) << ": hit AIO replay high-water mark: pausing replay"
                    << dendl;
     assert(m_on_aio_ready == nullptr);
     std::swap(m_on_aio_ready, on_ready);