From: Jason Dillaman <dillaman@redhat.com>
Date: Tue, 8 Dec 2020 14:57:06 +0000 (-0500)
Subject: librbd: additional debug logging in support of live-migration
X-Git-Tag: v16.1.0~299^2~1
X-Git-Url: http://git-server-git.apps.pok.os.sepia.ceph.com/?a=commitdiff_plain;h=31426c162b9df804de3fedba74989b94281b941c;p=ceph.git

librbd: additional debug logging in support of live-migration

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

diff --git a/src/librbd/deep_copy/ObjectCopyRequest.cc b/src/librbd/deep_copy/ObjectCopyRequest.cc
index 4424e09484e1..35431391e417 100644
--- a/src/librbd/deep_copy/ObjectCopyRequest.cc
+++ b/src/librbd/deep_copy/ObjectCopyRequest.cc
@@ -340,6 +340,7 @@ void ObjectCopyRequest<I>::send_write_object() {
 
   librados::ObjectWriteOperation op;
   if (!m_dst_image_ctx->migration_info.empty()) {
+    ldout(m_cct, 20) << "assert_snapc_seq=" << dst_snap_seq << dendl;
     cls_client::assert_snapc_seq(&op, dst_snap_seq,
                                  cls::rbd::ASSERT_SNAPC_SEQ_GT_SNAPSET_SEQ);
   }
diff --git a/src/librbd/io/ObjectRequest.cc b/src/librbd/io/ObjectRequest.cc
index 0914d08ef190..00fea70d6093 100644
--- a/src/librbd/io/ObjectRequest.cc
+++ b/src/librbd/io/ObjectRequest.cc
@@ -232,7 +232,7 @@ void ObjectReadRequest<I>::read_object() {
   }
   image_locker.unlock();
 
-  ldout(image_ctx->cct, 20) << dendl;
+  ldout(image_ctx->cct, 20) << "snap_id=" << read_snap_id << dendl;
 
   neorados::ReadOp read_op;
   for (auto& extent: *this->m_extents) {
@@ -485,14 +485,16 @@ void AbstractObjectWriteRequest<I>::write_object() {
 
   neorados::WriteOp write_op;
   if (m_copyup_enabled) {
-    ldout(image_ctx->cct, 20) << "guarding write" << dendl;
     if (m_guarding_migration_write) {
+      auto snap_seq = (this->m_io_context->write_snap_context() ?
+          this->m_io_context->write_snap_context()->first : 0);
+      ldout(image_ctx->cct, 20) << "guarding write: snap_seq=" << snap_seq
+                                << dendl;
+
       cls_client::assert_snapc_seq(
-        &write_op,
-        (this->m_io_context->write_snap_context() ?
-          this->m_io_context->write_snap_context()->first : 0),
-        cls::rbd::ASSERT_SNAPC_SEQ_LE_SNAPSET_SEQ);
+        &write_op, snap_seq, cls::rbd::ASSERT_SNAPC_SEQ_LE_SNAPSET_SEQ);
     } else {
+      ldout(image_ctx->cct, 20) << "guarding write" << dendl;
       write_op.assert_exists();
     }
   }
@@ -844,7 +846,8 @@ void ObjectListSnapsRequest<I>::handle_list_snaps(int r) {
                    << "clone_end_snap_id=" << clone_end_snap_id << ", "
                    << "diff=" << diff << ", "
                    << "end_size=" << end_size << ", "
-                   << "exists=" << exists << dendl;
+                   << "exists=" << exists << ", "
+                   << "whole_object=" << read_whole_object << dendl;
     if (end_snap_id <= first_snap_id) {
       // don't include deltas from the starting snapshots, but we iterate over
       // it to track its existence and size
diff --git a/src/librbd/migration/OpenSourceImageRequest.cc b/src/librbd/migration/OpenSourceImageRequest.cc
index e19739b5e11f..8abdedf332d9 100644
--- a/src/librbd/migration/OpenSourceImageRequest.cc
+++ b/src/librbd/migration/OpenSourceImageRequest.cc
@@ -41,7 +41,7 @@ void OpenSourceImageRequest<I>::open_source() {
   ldout(m_cct, 10) << dendl;
 
   // note that all source image ctx properties are placeholders
-  *m_src_image_ctx = I::create("", "", m_src_snap_id, m_io_ctx, true);
+  *m_src_image_ctx = I::create("", "", CEPH_NOSNAP, m_io_ctx, true);
   auto src_image_ctx = *m_src_image_ctx;
   src_image_ctx->child = m_dst_image_ctx;
 
@@ -63,6 +63,10 @@ void OpenSourceImageRequest<I>::open_source() {
     import_only = false;
   }
 
+  ldout(m_cct, 15) << "source_spec=" << source_spec << ", "
+                   << "source_snap_id=" << m_src_snap_id << ", "
+                   << "import_only=" << import_only << dendl;
+
   SourceSpecBuilder<I> source_spec_builder{src_image_ctx};
   json_spirit::mObject source_spec_object;
   int r = source_spec_builder.parse_source_spec(source_spec,
@@ -169,6 +173,9 @@ void OpenSourceImageRequest<I>::handle_get_snapshots(int r) {
     auto& [snap_id, snap_info] = *it;
     snapc.snaps.push_back(snap_id);
 
+    ldout(m_cct, 10) << "adding snap: ns=" << snap_info.snap_namespace << ", "
+                     << "name=" << snap_info.name << ", "
+                     << "id=" << snap_id << dendl;
     src_image_ctx->add_snap(
       snap_info.snap_namespace, snap_info.name, snap_id,
       snap_info.size, snap_info.parent, snap_info.protection_status,
@@ -179,11 +186,22 @@ void OpenSourceImageRequest<I>::handle_get_snapshots(int r) {
   }
   src_image_ctx->snapc = snapc;
 
+  ldout(m_cct, 15) << "read snap id: " << m_src_snap_id << ", "
+                   << "write snapc={"
+                   << "seq=" << snapc.seq << ", "
+                   << "snaps=" << snapc.snaps << "}" << dendl;
+
   // ensure data_ctx and data_io_context are pointing to correct snapshot
-  if (src_image_ctx->open_snap_id != CEPH_NOSNAP) {
-    int r = src_image_ctx->snap_set(src_image_ctx->open_snap_id);
-    ceph_assert(r == 0);
-    src_image_ctx->open_snap_id = CEPH_NOSNAP;
+  if (m_src_snap_id != CEPH_NOSNAP) {
+    int r = src_image_ctx->snap_set(m_src_snap_id);
+    if (r < 0) {
+      src_image_ctx->image_lock.unlock();
+
+      lderr(m_cct) << "error setting source image snap id: "
+                   << cpp_strerror(r) << dendl;
+      finish(r);
+      return;
+    }
   }
 
   src_image_ctx->image_lock.unlock();