rbd-mirror: fixed potential bootstrap cancel race condition

If the image replay was canceled prior to the start of the bootstrap
stage, the image replayer would be stuck attempting to shut down if
the bootstrap is paused behind an image sync.

Signed-off-by: Jason Dillaman <dillaman@redhat.com>
(cherry picked from commit 91b8a24ea58aee01ec8567195b5aabe11f74b87f)

Conflicts:
	src/tools/rbd_mirror/ImageReplayer.cc: trivial resolution

diff --git a/src/test/rbd_mirror/test_mock_ImageReplayer.cc b/src/test/rbd_mirror/test_mock_ImageReplayer.cc
index 818813bf758eaf1ac2750ca7d57fc2c767f2a320..9dab1bb94b02cfc2406c53bcae961ddb3188b73d 100644 (file)
--- a/src/test/rbd_mirror/test_mock_ImageReplayer.cc
+++ b/src/test/rbd_mirror/test_mock_ImageReplayer.cc
@@ -851,7 +851,6 @@ TEST_F(TestMockImageReplayer, GetRemoteImageIdError) {
 }
 
 TEST_F(TestMockImageReplayer, BootstrapError) {
-
   create_local_image();
   librbd::MockTestImageCtx mock_local_image_ctx(*m_local_image_ctx);
 
@@ -887,6 +886,44 @@ TEST_F(TestMockImageReplayer, BootstrapError) {
   ASSERT_EQ(-EINVAL, start_ctx.wait());
 }
 
+TEST_F(TestMockImageReplayer, StopBeforeBootstrap) {
+  create_local_image();
+  librbd::MockTestImageCtx mock_local_image_ctx(*m_local_image_ctx);
+
+  journal::MockJournaler mock_remote_journaler;
+  MockThreads mock_threads(m_threads);
+  expect_work_queue_repeatedly(mock_threads);
+  expect_add_event_after_repeatedly(mock_threads);
+
+  MockImageDeleter mock_image_deleter;
+  MockPrepareLocalImageRequest mock_prepare_local_image_request;
+  MockPrepareRemoteImageRequest mock_prepare_remote_image_request;
+  MockReplayStatusFormatter mock_replay_status_formatter;
+
+  expect_get_or_send_update(mock_replay_status_formatter);
+
+  InSequence seq;
+  expect_wait_for_scheduled_deletion(mock_image_deleter, "global image id", 0);
+  expect_send(mock_prepare_local_image_request, mock_local_image_ctx.id,
+              mock_local_image_ctx.name, "remote mirror uuid", 0);
+  expect_send(mock_prepare_remote_image_request, "remote mirror uuid",
+              m_remote_image_ctx->id, 0);
+  EXPECT_CALL(mock_remote_journaler, construct())
+    .WillOnce(Invoke([this]() {
+                m_image_replayer->stop(nullptr, true);
+              }));
+
+  expect_cancel_waiter(mock_image_deleter);
+  EXPECT_CALL(mock_remote_journaler, remove_listener(_));
+  expect_shut_down(mock_remote_journaler, 0);
+
+  create_image_replayer(mock_threads, mock_image_deleter);
+
+  C_SaferCond start_ctx;
+  m_image_replayer->start(&start_ctx);
+  ASSERT_EQ(-ECANCELED, start_ctx.wait());
+}
+
 TEST_F(TestMockImageReplayer, StartExternalReplayError) {
   // START
 

diff --git a/src/tools/rbd_mirror/ImageReplayer.cc b/src/tools/rbd_mirror/ImageReplayer.cc
index 5ba3ee468db4523ba5a116da501a0b4980906aa9..77331d8c332a74655d8a3c66576b32ad5e1b6bed 100644 (file)
--- a/src/tools/rbd_mirror/ImageReplayer.cc
+++ b/src/tools/rbd_mirror/ImageReplayer.cc
@@ -332,7 +332,7 @@ void ImageReplayer<I>::add_peer(const std::string &peer_uuid,
 
 template <typename I>
 void ImageReplayer<I>::set_state_description(int r, const std::string &desc) {
-  dout(20) << r << " " << desc << dendl;
+  dout(10) << r << " " << desc << dendl;
 
   Mutex::Locker l(m_lock);
   m_last_r = r;
@@ -342,7 +342,7 @@ void ImageReplayer<I>::set_state_description(int r, const std::string &desc) {
 template <typename I>
 void ImageReplayer<I>::start(Context *on_finish, bool manual)
 {
-  dout(20) << "on_finish=" << on_finish << dendl;
+  dout(10) << "on_finish=" << on_finish << dendl;
 
   int r = 0;
   {
@@ -510,19 +510,22 @@ void ImageReplayer<I>::bootstrap() {
     return;
   }
 
-  Context *ctx = create_context_callback<
-    ImageReplayer, &ImageReplayer<I>::handle_bootstrap>(this);
-
-  BootstrapRequest<I> *request = BootstrapRequest<I>::create(
-    m_local_ioctx, m_remote_image.io_ctx, m_instance_watcher,
-    &m_local_image_ctx, m_local_image_id, m_remote_image.image_id,
-    m_global_image_id, m_threads->work_queue, m_threads->timer,
-    &m_threads->timer_lock, m_local_mirror_uuid, m_remote_image.mirror_uuid,
-    m_remote_journaler, &m_client_state, &m_client_meta, ctx,
-    &m_resync_requested, &m_progress_cxt);
-
+  BootstrapRequest<I> *request = nullptr;
   {
     Mutex::Locker locker(m_lock);
+    if (on_start_interrupted(m_lock)) {
+      return;
+    }
+
+    auto ctx = create_context_callback<
+      ImageReplayer, &ImageReplayer<I>::handle_bootstrap>(this);
+    request = BootstrapRequest<I>::create(
+      m_local_ioctx, m_remote_image.io_ctx, m_instance_watcher,
+      &m_local_image_ctx, m_local_image_id, m_remote_image.image_id,
+      m_global_image_id, m_threads->work_queue, m_threads->timer,
+      &m_threads->timer_lock, m_local_mirror_uuid, m_remote_image.mirror_uuid,
+      m_remote_journaler, &m_client_state, &m_client_meta, ctx,
+      &m_resync_requested, &m_progress_cxt);
     request->get();
     m_bootstrap_request = request;
   }
@@ -687,9 +690,9 @@ void ImageReplayer<I>::handle_start_replay(int r) {
     dout(20) << "m_remote_journaler=" << *m_remote_journaler << dendl;
   }
 
-  dout(20) << "start succeeded" << dendl;
+  dout(10) << "start succeeded" << dendl;
   if (on_finish != nullptr) {
-    dout(20) << "on finish complete, r=" << r << dendl;
+    dout(10) << "on finish complete, r=" << r << dendl;
     on_finish->complete(r);
   }
 }
@@ -697,7 +700,7 @@ void ImageReplayer<I>::handle_start_replay(int r) {
 template <typename I>
 void ImageReplayer<I>::on_start_fail(int r, const std::string &desc)
 {
-  dout(20) << "r=" << r << dendl;
+  dout(10) << "r=" << r << dendl;
   Context *ctx = new FunctionContext([this, r, desc](int _r) {
       {
         Mutex::Locker locker(m_lock);
@@ -706,7 +709,7 @@ void ImageReplayer<I>::on_start_fail(int r, const std::string &desc)
         if (r < 0 && r != -ECANCELED && r != -EREMOTEIO && r != -ENOENT) {
           derr << "start failed: " << cpp_strerror(r) << dendl;
         } else {
-          dout(20) << "start canceled" << dendl;
+          dout(10) << "start canceled" << dendl;
         }
       }
 
@@ -719,11 +722,16 @@ void ImageReplayer<I>::on_start_fail(int r, const std::string &desc)
 }
 
 template <typename I>
-bool ImageReplayer<I>::on_start_interrupted()
-{
+bool ImageReplayer<I>::on_start_interrupted() {
   Mutex::Locker locker(m_lock);
+  return on_start_interrupted(m_lock);
+}
+
+template <typename I>
+bool ImageReplayer<I>::on_start_interrupted(Mutex& lock) {
+  assert(m_lock.is_locked());
   assert(m_state == STATE_STARTING);
-  if (m_on_stop_finish == nullptr) {
+  if (!m_stop_requested) {
     return false;
   }
 
@@ -735,7 +743,7 @@ template <typename I>
 void ImageReplayer<I>::stop(Context *on_finish, bool manual, int r,
                            const std::string& desc)
 {
-  dout(20) << "on_finish=" << on_finish << ", manual=" << manual
+  dout(10) << "on_finish=" << on_finish << ", manual=" << manual
           << ", desc=" << desc << dendl;
 
   m_image_deleter->cancel_waiter(m_local_pool_id, m_global_image_id);
@@ -751,13 +759,13 @@ void ImageReplayer<I>::stop(Context *on_finish, bool manual, int r,
     } else {
       if (!is_stopped_()) {
        if (m_state == STATE_STARTING) {
-         dout(20) << "canceling start" << dendl;
-         if (m_bootstrap_request) {
+         dout(10) << "canceling start" << dendl;
+         if (m_bootstrap_request != nullptr) {
             bootstrap_request = m_bootstrap_request;
             bootstrap_request->get();
          }
        } else {
-         dout(20) << "interrupting replay" << dendl;
+         dout(10) << "interrupting replay" << dendl;
          shut_down_replay = true;
        }
 
@@ -771,6 +779,7 @@ void ImageReplayer<I>::stop(Context *on_finish, bool manual, int r,
 
   // avoid holding lock since bootstrap request will update status
   if (bootstrap_request != nullptr) {
+    dout(10) << "canceling bootstrap" << dendl;
     bootstrap_request->cancel();
     bootstrap_request->put();
   }
@@ -793,7 +802,7 @@ void ImageReplayer<I>::stop(Context *on_finish, bool manual, int r,
 template <typename I>
 void ImageReplayer<I>::on_stop_journal_replay(int r, const std::string &desc)
 {
-  dout(20) << "enter" << dendl;
+  dout(10) << dendl;
 
   {
     Mutex::Locker locker(m_lock);
@@ -814,7 +823,7 @@ void ImageReplayer<I>::on_stop_journal_replay(int r, const std::string &desc)
 template <typename I>
 void ImageReplayer<I>::handle_replay_ready()
 {
-  dout(20) << "enter" << dendl;
+  dout(20) << dendl;
   if (on_replay_interrupted()) {
     return;
   }
@@ -859,7 +868,7 @@ void ImageReplayer<I>::restart(Context *on_finish)
 template <typename I>
 void ImageReplayer<I>::flush(Context *on_finish)
 {
-  dout(20) << "enter" << dendl;
+  dout(10) << dendl;
 
   {
     Mutex::Locker locker(m_lock);
@@ -883,7 +892,7 @@ void ImageReplayer<I>::flush(Context *on_finish)
 template <typename I>
 void ImageReplayer<I>::on_flush_local_replay_flush_start(Context *on_flush)
 {
-  dout(20) << "enter" << dendl;
+  dout(10) << dendl;
   FunctionContext *ctx = new FunctionContext(
     [this, on_flush](int r) {
       on_flush_local_replay_flush_finish(on_flush, r);
@@ -898,7 +907,7 @@ template <typename I>
 void ImageReplayer<I>::on_flush_local_replay_flush_finish(Context *on_flush,
                                                           int r)
 {
-  dout(20) << "r=" << r << dendl;
+  dout(10) << "r=" << r << dendl;
   if (r < 0) {
     derr << "error flushing local replay: " << cpp_strerror(r) << dendl;
     on_flush->complete(r);
@@ -952,7 +961,7 @@ bool ImageReplayer<I>::on_replay_interrupted()
 template <typename I>
 void ImageReplayer<I>::print_status(Formatter *f, stringstream *ss)
 {
-  dout(20) << "enter" << dendl;
+  dout(10) << dendl;
 
   Mutex::Locker l(m_lock);
 
@@ -970,7 +979,7 @@ void ImageReplayer<I>::print_status(Formatter *f, stringstream *ss)
 template <typename I>
 void ImageReplayer<I>::handle_replay_complete(int r, const std::string &error_desc)
 {
-  dout(20) << "r=" << r << dendl;
+  dout(10) << "r=" << r << dendl;
   if (r < 0) {
     derr << "replay encountered an error: " << cpp_strerror(r) << dendl;
     set_state_description(r, error_desc);
@@ -985,13 +994,13 @@ void ImageReplayer<I>::handle_replay_complete(int r, const std::string &error_de
 
 template <typename I>
 void ImageReplayer<I>::replay_flush() {
-  dout(20) << dendl;
+  dout(10) << dendl;
 
   bool interrupted = false;
   {
     Mutex::Locker locker(m_lock);
     if (m_state != STATE_REPLAYING) {
-      dout(20) << "replay interrupted" << dendl;
+      dout(10) << "replay interrupted" << dendl;
       interrupted = true;
     } else {
       m_state = STATE_REPLAY_FLUSHING;
@@ -1023,7 +1032,7 @@ void ImageReplayer<I>::replay_flush() {
 
 template <typename I>
 void ImageReplayer<I>::handle_replay_flush(int r) {
-  dout(20) << "r=" << r << dendl;
+  dout(10) << "r=" << r << dendl;
 
   {
     Mutex::Locker locker(m_lock);
@@ -1269,7 +1278,7 @@ void ImageReplayer<I>::handle_process_entry_safe(const ReplayEntry& replay_entry
 template <typename I>
 bool ImageReplayer<I>::update_mirror_image_status(bool force,
                                                   const OptionalState &state) {
-  dout(20) << dendl;
+  dout(15) << dendl;
   {
     Mutex::Locker locker(m_lock);
     if (!start_mirror_image_status_update(force, false)) {
@@ -1288,10 +1297,10 @@ bool ImageReplayer<I>::start_mirror_image_status_update(bool force,
 
   if (!force && !is_stopped_()) {
     if (!is_running_()) {
-      dout(20) << "shut down in-progress: ignoring update" << dendl;
+      dout(15) << "shut down in-progress: ignoring update" << dendl;
       return false;
     } else if (m_in_flight_status_updates > (restarting ? 1 : 0)) {
-      dout(20) << "already sending update" << dendl;
+      dout(15) << "already sending update" << dendl;
       m_update_status_requested = true;
       return false;
     }
@@ -1327,7 +1336,7 @@ void ImageReplayer<I>::finish_mirror_image_status_update() {
 
 template <typename I>
 void ImageReplayer<I>::queue_mirror_image_status_update(const OptionalState &state) {
-  dout(20) << dendl;
+  dout(15) << dendl;
   FunctionContext *ctx = new FunctionContext(
     [this, state](int r) {
       send_mirror_status_update(state);
@@ -1389,7 +1398,7 @@ void ImageReplayer<I>::send_mirror_status_update(const OptionalState &opt_state)
     {
       Context *on_req_finish = new FunctionContext(
         [this](int r) {
-          dout(20) << "replay status ready: r=" << r << dendl;
+          dout(15) << "replay status ready: r=" << r << dendl;
           if (r >= 0) {
             send_mirror_status_update(boost::none);
           } else if (r == -EAGAIN) {
@@ -1401,7 +1410,7 @@ void ImageReplayer<I>::send_mirror_status_update(const OptionalState &opt_state)
       std::string desc;
       if (!m_replay_status_formatter->get_or_send_update(&desc,
                                                          on_req_finish)) {
-        dout(20) << "waiting for replay status" << dendl;
+        dout(15) << "waiting for replay status" << dendl;
         return;
       }
       status.description = "replaying, " + desc;
@@ -1551,7 +1560,7 @@ void ImageReplayer<I>::shut_down(int r) {
     // before proceeding
     if (m_in_flight_status_updates > 0) {
       if (m_on_update_status_finish == nullptr) {
-        dout(20) << "waiting for in-flight status update" << dendl;
+        dout(15) << "waiting for in-flight status update" << dendl;
         m_on_update_status_finish = new FunctionContext(
           [this, r](int _r) {
             shut_down(r);
@@ -1662,7 +1671,7 @@ void ImageReplayer<I>::handle_shut_down(int r) {
     // before proceeding
     if (m_in_flight_status_updates > 0) {
       if (m_on_update_status_finish == nullptr) {
-        dout(20) << "waiting for in-flight status update" << dendl;
+        dout(15) << "waiting for in-flight status update" << dendl;
         m_on_update_status_finish = new FunctionContext(
           [this, r](int _r) {
             handle_shut_down(r);
@@ -1720,12 +1729,12 @@ void ImageReplayer<I>::handle_shut_down(int r) {
   }
 
   if (on_start != nullptr) {
-    dout(20) << "on start finish complete, r=" << r << dendl;
+    dout(10) << "on start finish complete, r=" << r << dendl;
     on_start->complete(r);
     r = 0;
   }
   if (on_stop != nullptr) {
-    dout(20) << "on stop finish complete, r=" << r << dendl;
+    dout(10) << "on stop finish complete, r=" << r << dendl;
     on_stop->complete(r);
   }
 }
@@ -1775,7 +1784,7 @@ std::string ImageReplayer<I>::to_string(const State state) {
 
 template <typename I>
 void ImageReplayer<I>::resync_image(Context *on_finish) {
-  dout(20) << dendl;
+  dout(10) << dendl;
 
   m_resync_requested = true;
   stop(on_finish);

diff --git a/src/tools/rbd_mirror/ImageReplayer.h b/src/tools/rbd_mirror/ImageReplayer.h
index d47cccd137a87558a58d94f802adbd2ca669f9c0..e11fcd8f44fea52185c6b54c7e0fd504b3529b44 100644 (file)
--- a/src/tools/rbd_mirror/ImageReplayer.h
+++ b/src/tools/rbd_mirror/ImageReplayer.h
@@ -205,6 +205,7 @@ protected:
 
   virtual void on_start_fail(int r, const std::string &desc = "");
   virtual bool on_start_interrupted();
+  virtual bool on_start_interrupted(Mutex& lock);
 
   virtual void on_stop_journal_replay(int r = 0, const std::string &desc = "");