All of lore.kernel.org
 help / color / mirror / Atom feed
* [PULL 00/12] jobs: mirror: Handle errors after READY cancel
@ 2021-09-21 10:20 Vladimir Sementsov-Ogievskiy
  2021-09-21 10:20 ` [PULL 01/12] job: Context changes in job_completed_txn_abort() Vladimir Sementsov-Ogievskiy
                   ` (12 more replies)
  0 siblings, 13 replies; 19+ messages in thread
From: Vladimir Sementsov-Ogievskiy @ 2021-09-21 10:20 UTC (permalink / raw)
  To: qemu-block; +Cc: qemu-devel, peter.maydell, kwolf, hreitz, vsementsov, jsnow

The following changes since commit 326ff8dd09556fc2e257196c49f35009700794ac:

  Merge remote-tracking branch 'remotes/jasowang/tags/net-pull-request' into staging (2021-09-20 16:17:05 +0100)

are available in the Git repository at:

  https://src.openvz.org/scm/~vsementsov/qemu.git tags/pull-jobs-2021-09-21

for you to fetch changes up to c9489c04319cac75c76af8fc27c254f46e10214c:

  iotests: Add mirror-ready-cancel-error test (2021-09-21 11:56:11 +0300)

----------------------------------------------------------------
mirror: Handle errors after READY cancel

----------------------------------------------------------------
Hanna Reitz (12):
      job: Context changes in job_completed_txn_abort()
      mirror: Keep s->synced on error
      mirror: Drop s->synced
      job: Force-cancel jobs in a failed transaction
      job: @force parameter for job_cancel_sync()
      jobs: Give Job.force_cancel more meaning
      job: Add job_cancel_requested()
      mirror: Use job_is_cancelled()
      mirror: Check job_is_cancelled() earlier
      mirror: Stop active mirroring after force-cancel
      mirror: Do not clear .cancelled
      iotests: Add mirror-ready-cancel-error test

 include/qemu/job.h                                     |  29 ++++++---
 block/backup.c                                         |   3 +-
 block/mirror.c                                         |  56 +++++++++--------
 block/replication.c                                    |   4 +-
 blockdev.c                                             |   4 +-
 job.c                                                  |  64 +++++++++++++++----
 tests/unit/test-blockjob.c                             |   2 +-
 tests/qemu-iotests/109.out                             |  60 ++++++++----------
 tests/qemu-iotests/tests/mirror-ready-cancel-error     | 143 +++++++++++++++++++++++++++++++++++++++++++
 tests/qemu-iotests/tests/mirror-ready-cancel-error.out |   5 ++
 tests/qemu-iotests/tests/qsd-jobs.out                  |   2 +-
 11 files changed, 286 insertions(+), 86 deletions(-)
 create mode 100755 tests/qemu-iotests/tests/mirror-ready-cancel-error
 create mode 100644 tests/qemu-iotests/tests/mirror-ready-cancel-error.out

-- 
2.29.2



^ permalink raw reply	[flat|nested] 19+ messages in thread

* [PULL 01/12] job: Context changes in job_completed_txn_abort()
  2021-09-21 10:20 [PULL 00/12] jobs: mirror: Handle errors after READY cancel Vladimir Sementsov-Ogievskiy
@ 2021-09-21 10:20 ` Vladimir Sementsov-Ogievskiy
  2021-09-21 10:20 ` [PULL 02/12] mirror: Keep s->synced on error Vladimir Sementsov-Ogievskiy
                   ` (11 subsequent siblings)
  12 siblings, 0 replies; 19+ messages in thread
From: Vladimir Sementsov-Ogievskiy @ 2021-09-21 10:20 UTC (permalink / raw)
  To: qemu-block; +Cc: qemu-devel, peter.maydell, kwolf, hreitz, vsementsov, jsnow

From: Hanna Reitz <hreitz@redhat.com>

Finalizing the job may cause its AioContext to change.  This is noted by
job_exit(), which points at job_txn_apply() to take this fact into
account.

However, job_completed() does not necessarily invoke job_txn_apply()
(through job_completed_txn_success()), but potentially also
job_completed_txn_abort().  The latter stores the context in a local
variable, and so always acquires the same context at its end that it has
released in the beginning -- which may be a different context from the
one that job_exit() releases at its end.  If it is different, qemu
aborts ("qemu_mutex_unlock_impl: Operation not permitted").

Drop the local @outer_ctx variable from job_completed_txn_abort(), and
instead re-acquire the actual job's context at the end of the function,
so job_exit() will release the same.

Signed-off-by: Hanna Reitz <hreitz@redhat.com>
Reviewed-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
Message-Id: <20210907124245.143492-2-hreitz@redhat.com>
Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
---
 job.c | 22 +++++++++++++++++-----
 1 file changed, 17 insertions(+), 5 deletions(-)

diff --git a/job.c b/job.c
index e7a5d28854..810e6a2065 100644
--- a/job.c
+++ b/job.c
@@ -737,7 +737,6 @@ static void job_cancel_async(Job *job, bool force)
 
 static void job_completed_txn_abort(Job *job)
 {
-    AioContext *outer_ctx = job->aio_context;
     AioContext *ctx;
     JobTxn *txn = job->txn;
     Job *other_job;
@@ -751,10 +750,14 @@ static void job_completed_txn_abort(Job *job)
     txn->aborting = true;
     job_txn_ref(txn);
 
-    /* We can only hold the single job's AioContext lock while calling
+    /*
+     * We can only hold the single job's AioContext lock while calling
      * job_finalize_single() because the finalization callbacks can involve
-     * calls of AIO_WAIT_WHILE(), which could deadlock otherwise. */
-    aio_context_release(outer_ctx);
+     * calls of AIO_WAIT_WHILE(), which could deadlock otherwise.
+     * Note that the job's AioContext may change when it is finalized.
+     */
+    job_ref(job);
+    aio_context_release(job->aio_context);
 
     /* Other jobs are effectively cancelled by us, set the status for
      * them; this job, however, may or may not be cancelled, depending
@@ -769,6 +772,10 @@ static void job_completed_txn_abort(Job *job)
     }
     while (!QLIST_EMPTY(&txn->jobs)) {
         other_job = QLIST_FIRST(&txn->jobs);
+        /*
+         * The job's AioContext may change, so store it in @ctx so we
+         * release the same context that we have acquired before.
+         */
         ctx = other_job->aio_context;
         aio_context_acquire(ctx);
         if (!job_is_completed(other_job)) {
@@ -779,7 +786,12 @@ static void job_completed_txn_abort(Job *job)
         aio_context_release(ctx);
     }
 
-    aio_context_acquire(outer_ctx);
+    /*
+     * Use job_ref()/job_unref() so we can read the AioContext here
+     * even if the job went away during job_finalize_single().
+     */
+    aio_context_acquire(job->aio_context);
+    job_unref(job);
 
     job_txn_unref(txn);
 }
-- 
2.29.2



^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PULL 02/12] mirror: Keep s->synced on error
  2021-09-21 10:20 [PULL 00/12] jobs: mirror: Handle errors after READY cancel Vladimir Sementsov-Ogievskiy
  2021-09-21 10:20 ` [PULL 01/12] job: Context changes in job_completed_txn_abort() Vladimir Sementsov-Ogievskiy
@ 2021-09-21 10:20 ` Vladimir Sementsov-Ogievskiy
  2021-09-21 10:20 ` [PULL 03/12] mirror: Drop s->synced Vladimir Sementsov-Ogievskiy
                   ` (10 subsequent siblings)
  12 siblings, 0 replies; 19+ messages in thread
From: Vladimir Sementsov-Ogievskiy @ 2021-09-21 10:20 UTC (permalink / raw)
  To: qemu-block; +Cc: qemu-devel, peter.maydell, kwolf, hreitz, vsementsov, jsnow

From: Hanna Reitz <hreitz@redhat.com>

An error does not take us out of the READY phase, which is what
s->synced signifies.  It does of course mean that source and target are
no longer in sync, but that is what s->actively_sync is for -- s->synced
never meant that source and target are in sync, only that they were at
some point (and at that point we transitioned into the READY phase).

The tangible problem is that we transition to READY once we are in sync
and s->synced is false.  By resetting s->synced here, we will transition
from READY to READY once the error is resolved (if the job keeps
running), and that transition is not allowed.

Signed-off-by: Hanna Reitz <hreitz@redhat.com>
Reviewed-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
Reviewed-by: Kevin Wolf <kwolf@redhat.com>
Message-Id: <20210907124245.143492-3-hreitz@redhat.com>
Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
---
 block/mirror.c | 1 -
 1 file changed, 1 deletion(-)

diff --git a/block/mirror.c b/block/mirror.c
index 85b781bc21..cad61496c2 100644
--- a/block/mirror.c
+++ b/block/mirror.c
@@ -121,7 +121,6 @@ typedef enum MirrorMethod {
 static BlockErrorAction mirror_error_action(MirrorBlockJob *s, bool read,
                                             int error)
 {
-    s->synced = false;
     s->actively_synced = false;
     if (read) {
         return block_job_error_action(&s->common, s->on_source_error,
-- 
2.29.2



^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PULL 03/12] mirror: Drop s->synced
  2021-09-21 10:20 [PULL 00/12] jobs: mirror: Handle errors after READY cancel Vladimir Sementsov-Ogievskiy
  2021-09-21 10:20 ` [PULL 01/12] job: Context changes in job_completed_txn_abort() Vladimir Sementsov-Ogievskiy
  2021-09-21 10:20 ` [PULL 02/12] mirror: Keep s->synced on error Vladimir Sementsov-Ogievskiy
@ 2021-09-21 10:20 ` Vladimir Sementsov-Ogievskiy
  2021-09-21 10:20 ` [PULL 04/12] job: Force-cancel jobs in a failed transaction Vladimir Sementsov-Ogievskiy
                   ` (9 subsequent siblings)
  12 siblings, 0 replies; 19+ messages in thread
From: Vladimir Sementsov-Ogievskiy @ 2021-09-21 10:20 UTC (permalink / raw)
  To: qemu-block
  Cc: qemu-devel, peter.maydell, kwolf, hreitz, vsementsov, jsnow, Eric Blake

From: Hanna Reitz <hreitz@redhat.com>

As of HEAD^, there is no meaning to s->synced other than whether the job
is READY or not.  job_is_ready() gives us that information, too.

Suggested-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
Signed-off-by: Hanna Reitz <hreitz@redhat.com>
Reviewed-by: Eric Blake <eblake@redhat.com>
Reviewed-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
Reviewed-by: Kevin Wolf <kwolf@redhat.com>
Message-Id: <20210907124245.143492-4-hreitz@redhat.com>
Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
---
 block/mirror.c | 19 +++++++++----------
 1 file changed, 9 insertions(+), 10 deletions(-)

diff --git a/block/mirror.c b/block/mirror.c
index cad61496c2..86ddecb86b 100644
--- a/block/mirror.c
+++ b/block/mirror.c
@@ -56,7 +56,6 @@ typedef struct MirrorBlockJob {
     bool zero_target;
     MirrorCopyMode copy_mode;
     BlockdevOnError on_source_error, on_target_error;
-    bool synced;
     /* Set when the target is synced (dirty bitmap is clean, nothing
      * in flight) and the job is running in active mode */
     bool actively_synced;
@@ -943,7 +942,6 @@ static int coroutine_fn mirror_run(Job *job, Error **errp)
     if (s->bdev_length == 0) {
         /* Transition to the READY state and wait for complete. */
         job_transition_to_ready(&s->common.job);
-        s->synced = true;
         s->actively_synced = true;
         while (!job_is_cancelled(&s->common.job) && !s->should_complete) {
             job_yield(&s->common.job);
@@ -1035,7 +1033,7 @@ static int coroutine_fn mirror_run(Job *job, Error **errp)
         should_complete = false;
         if (s->in_flight == 0 && cnt == 0) {
             trace_mirror_before_flush(s);
-            if (!s->synced) {
+            if (!job_is_ready(&s->common.job)) {
                 if (mirror_flush(s) < 0) {
                     /* Go check s->ret.  */
                     continue;
@@ -1046,7 +1044,6 @@ static int coroutine_fn mirror_run(Job *job, Error **errp)
                  * the target in a consistent state.
                  */
                 job_transition_to_ready(&s->common.job);
-                s->synced = true;
                 if (s->copy_mode != MIRROR_COPY_MODE_BACKGROUND) {
                     s->actively_synced = true;
                 }
@@ -1090,14 +1087,15 @@ static int coroutine_fn mirror_run(Job *job, Error **errp)
 
         ret = 0;
 
-        if (s->synced && !should_complete) {
+        if (job_is_ready(&s->common.job) && !should_complete) {
             delay_ns = (s->in_flight == 0 &&
                         cnt == 0 ? BLOCK_JOB_SLICE_TIME : 0);
         }
-        trace_mirror_before_sleep(s, cnt, s->synced, delay_ns);
+        trace_mirror_before_sleep(s, cnt, job_is_ready(&s->common.job),
+                                  delay_ns);
         job_sleep_ns(&s->common.job, delay_ns);
         if (job_is_cancelled(&s->common.job) &&
-            (!s->synced || s->common.job.force_cancel))
+            (!job_is_ready(&s->common.job) || s->common.job.force_cancel))
         {
             break;
         }
@@ -1110,8 +1108,9 @@ immediate_exit:
          * or it was cancelled prematurely so that we do not guarantee that
          * the target is a copy of the source.
          */
-        assert(ret < 0 || ((s->common.job.force_cancel || !s->synced) &&
-               job_is_cancelled(&s->common.job)));
+        assert(ret < 0 ||
+               ((s->common.job.force_cancel || !job_is_ready(&s->common.job)) &&
+                job_is_cancelled(&s->common.job)));
         assert(need_drain);
         mirror_wait_for_all_io(s);
     }
@@ -1134,7 +1133,7 @@ static void mirror_complete(Job *job, Error **errp)
 {
     MirrorBlockJob *s = container_of(job, MirrorBlockJob, common.job);
 
-    if (!s->synced) {
+    if (!job_is_ready(job)) {
         error_setg(errp, "The active block job '%s' cannot be completed",
                    job->id);
         return;
-- 
2.29.2



^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PULL 04/12] job: Force-cancel jobs in a failed transaction
  2021-09-21 10:20 [PULL 00/12] jobs: mirror: Handle errors after READY cancel Vladimir Sementsov-Ogievskiy
                   ` (2 preceding siblings ...)
  2021-09-21 10:20 ` [PULL 03/12] mirror: Drop s->synced Vladimir Sementsov-Ogievskiy
@ 2021-09-21 10:20 ` Vladimir Sementsov-Ogievskiy
  2021-09-21 10:20 ` [PULL 05/12] job: @force parameter for job_cancel_sync() Vladimir Sementsov-Ogievskiy
                   ` (8 subsequent siblings)
  12 siblings, 0 replies; 19+ messages in thread
From: Vladimir Sementsov-Ogievskiy @ 2021-09-21 10:20 UTC (permalink / raw)
  To: qemu-block
  Cc: qemu-devel, peter.maydell, kwolf, hreitz, vsementsov, jsnow, Eric Blake

From: Hanna Reitz <hreitz@redhat.com>

When a transaction is aborted, no result matters, and so all jobs within
should be force-cancelled.

Signed-off-by: Hanna Reitz <hreitz@redhat.com>
Reviewed-by: Eric Blake <eblake@redhat.com>
Reviewed-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
Message-Id: <20210907124245.143492-5-hreitz@redhat.com>
Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
---
 job.c | 7 ++++++-
 1 file changed, 6 insertions(+), 1 deletion(-)

diff --git a/job.c b/job.c
index 810e6a2065..e74d81928d 100644
--- a/job.c
+++ b/job.c
@@ -766,7 +766,12 @@ static void job_completed_txn_abort(Job *job)
         if (other_job != job) {
             ctx = other_job->aio_context;
             aio_context_acquire(ctx);
-            job_cancel_async(other_job, false);
+            /*
+             * This is a transaction: If one job failed, no result will matter.
+             * Therefore, pass force=true to terminate all other jobs as quickly
+             * as possible.
+             */
+            job_cancel_async(other_job, true);
             aio_context_release(ctx);
         }
     }
-- 
2.29.2



^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PULL 05/12] job: @force parameter for job_cancel_sync()
  2021-09-21 10:20 [PULL 00/12] jobs: mirror: Handle errors after READY cancel Vladimir Sementsov-Ogievskiy
                   ` (3 preceding siblings ...)
  2021-09-21 10:20 ` [PULL 04/12] job: Force-cancel jobs in a failed transaction Vladimir Sementsov-Ogievskiy
@ 2021-09-21 10:20 ` Vladimir Sementsov-Ogievskiy
  2021-09-21 10:20 ` [PULL 06/12] jobs: Give Job.force_cancel more meaning Vladimir Sementsov-Ogievskiy
                   ` (7 subsequent siblings)
  12 siblings, 0 replies; 19+ messages in thread
From: Vladimir Sementsov-Ogievskiy @ 2021-09-21 10:20 UTC (permalink / raw)
  To: qemu-block
  Cc: qemu-devel, peter.maydell, kwolf, hreitz, vsementsov, jsnow, Eric Blake

From: Hanna Reitz <hreitz@redhat.com>

Callers should be able to specify whether they want job_cancel_sync() to
force-cancel the job or not.

In fact, almost all invocations do not care about consistency of the
result and just want the job to terminate as soon as possible, so they
should pass force=true.  The replication block driver is the exception,
specifically the active commit job it runs.

As for job_cancel_sync_all(), all callers want it to force-cancel all
jobs, because that is the point of it: To cancel all remaining jobs as
quickly as possible (generally on process termination).  So make it
invoke job_cancel_sync() with force=true.

This changes some iotest outputs, because quitting qemu while a mirror
job is active will now lead to it being cancelled instead of completed,
which is what we want.  (Cancelling a READY mirror job with force=false
may take an indefinite amount of time, which we do not want when
quitting.  If users want consistent results, they must have all jobs be
done before they quit qemu.)

Buglink: https://gitlab.com/qemu-project/qemu/-/issues/462
Signed-off-by: Hanna Reitz <hreitz@redhat.com>
Message-Id: <20210907124245.143492-6-hreitz@redhat.com>
Reviewed-by: Eric Blake <eblake@redhat.com>
Reviewed-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
---
 include/qemu/job.h                    | 10 ++---
 block/replication.c                   |  4 +-
 blockdev.c                            |  4 +-
 job.c                                 | 18 ++++++--
 tests/unit/test-blockjob.c            |  2 +-
 tests/qemu-iotests/109.out            | 60 +++++++++++----------------
 tests/qemu-iotests/tests/qsd-jobs.out |  2 +-
 7 files changed, 50 insertions(+), 50 deletions(-)

diff --git a/include/qemu/job.h b/include/qemu/job.h
index 41162ed494..2eddf3b536 100644
--- a/include/qemu/job.h
+++ b/include/qemu/job.h
@@ -506,18 +506,18 @@ void job_user_cancel(Job *job, bool force, Error **errp);
 
 /**
  * Synchronously cancel the @job.  The completion callback is called
- * before the function returns.  The job may actually complete
- * instead of canceling itself; the circumstances under which this
- * happens depend on the kind of job that is active.
+ * before the function returns.  If @force is false, the job may
+ * actually complete instead of canceling itself; the circumstances
+ * under which this happens depend on the kind of job that is active.
  *
  * Returns the return value from the job if the job actually completed
  * during the call, or -ECANCELED if it was canceled.
  *
  * Callers must hold the AioContext lock of job->aio_context.
  */
-int job_cancel_sync(Job *job);
+int job_cancel_sync(Job *job, bool force);
 
-/** Synchronously cancels all jobs using job_cancel_sync(). */
+/** Synchronously force-cancels all jobs using job_cancel_sync(). */
 void job_cancel_sync_all(void);
 
 /**
diff --git a/block/replication.c b/block/replication.c
index 32444b9a8f..55c8f894aa 100644
--- a/block/replication.c
+++ b/block/replication.c
@@ -149,7 +149,7 @@ static void replication_close(BlockDriverState *bs)
     if (s->stage == BLOCK_REPLICATION_FAILOVER) {
         commit_job = &s->commit_job->job;
         assert(commit_job->aio_context == qemu_get_current_aio_context());
-        job_cancel_sync(commit_job);
+        job_cancel_sync(commit_job, false);
     }
 
     if (s->mode == REPLICATION_MODE_SECONDARY) {
@@ -726,7 +726,7 @@ static void replication_stop(ReplicationState *rs, bool failover, Error **errp)
          * disk, secondary disk in backup_job_completed().
          */
         if (s->backup_job) {
-            job_cancel_sync(&s->backup_job->job);
+            job_cancel_sync(&s->backup_job->job, true);
         }
 
         if (!failover) {
diff --git a/blockdev.c b/blockdev.c
index e79c5f3b5e..b35072644e 100644
--- a/blockdev.c
+++ b/blockdev.c
@@ -1847,7 +1847,7 @@ static void drive_backup_abort(BlkActionState *common)
         aio_context = bdrv_get_aio_context(state->bs);
         aio_context_acquire(aio_context);
 
-        job_cancel_sync(&state->job->job);
+        job_cancel_sync(&state->job->job, true);
 
         aio_context_release(aio_context);
     }
@@ -1948,7 +1948,7 @@ static void blockdev_backup_abort(BlkActionState *common)
         aio_context = bdrv_get_aio_context(state->bs);
         aio_context_acquire(aio_context);
 
-        job_cancel_sync(&state->job->job);
+        job_cancel_sync(&state->job->job, true);
 
         aio_context_release(aio_context);
     }
diff --git a/job.c b/job.c
index e74d81928d..dfac35d553 100644
--- a/job.c
+++ b/job.c
@@ -981,9 +981,21 @@ static void job_cancel_err(Job *job, Error **errp)
     job_cancel(job, false);
 }
 
-int job_cancel_sync(Job *job)
+/**
+ * Same as job_cancel_err(), but force-cancel.
+ */
+static void job_force_cancel_err(Job *job, Error **errp)
 {
-    return job_finish_sync(job, &job_cancel_err, NULL);
+    job_cancel(job, true);
+}
+
+int job_cancel_sync(Job *job, bool force)
+{
+    if (force) {
+        return job_finish_sync(job, &job_force_cancel_err, NULL);
+    } else {
+        return job_finish_sync(job, &job_cancel_err, NULL);
+    }
 }
 
 void job_cancel_sync_all(void)
@@ -994,7 +1006,7 @@ void job_cancel_sync_all(void)
     while ((job = job_next(NULL))) {
         aio_context = job->aio_context;
         aio_context_acquire(aio_context);
-        job_cancel_sync(job);
+        job_cancel_sync(job, true);
         aio_context_release(aio_context);
     }
 }
diff --git a/tests/unit/test-blockjob.c b/tests/unit/test-blockjob.c
index dcacfa6c7c..4c9e1bf1e5 100644
--- a/tests/unit/test-blockjob.c
+++ b/tests/unit/test-blockjob.c
@@ -230,7 +230,7 @@ static void cancel_common(CancelJob *s)
     ctx = job->job.aio_context;
     aio_context_acquire(ctx);
 
-    job_cancel_sync(&job->job);
+    job_cancel_sync(&job->job, true);
     if (sts != JOB_STATUS_CREATED && sts != JOB_STATUS_CONCLUDED) {
         Job *dummy = &job->job;
         job_dismiss(&dummy, &error_abort);
diff --git a/tests/qemu-iotests/109.out b/tests/qemu-iotests/109.out
index 8f839b4b7f..e29280015e 100644
--- a/tests/qemu-iotests/109.out
+++ b/tests/qemu-iotests/109.out
@@ -44,9 +44,8 @@ read 512/512 bytes at offset 0
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "SHUTDOWN", "data": {"guest": false, "reason": "host-qmp-quit"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "standby", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "src", "len": 1024, "offset": 1024, "speed": 0, "type": "mirror"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "src"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_CANCELLED", "data": {"device": "src", "len": 1024, "offset": 1024, "speed": 0, "type": "mirror"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "src"}}
 Images are identical.
@@ -95,9 +94,8 @@ read 512/512 bytes at offset 0
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "SHUTDOWN", "data": {"guest": false, "reason": "host-qmp-quit"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "standby", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "src", "len": 197120, "offset": 197120, "speed": 0, "type": "mirror"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "src"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_CANCELLED", "data": {"device": "src", "len": 197120, "offset": 197120, "speed": 0, "type": "mirror"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "src"}}
 Images are identical.
@@ -146,9 +144,8 @@ read 512/512 bytes at offset 0
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "SHUTDOWN", "data": {"guest": false, "reason": "host-qmp-quit"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "standby", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "src", "len": 327680, "offset": 327680, "speed": 0, "type": "mirror"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "src"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_CANCELLED", "data": {"device": "src", "len": 327680, "offset": 327680, "speed": 0, "type": "mirror"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "src"}}
 Images are identical.
@@ -197,9 +194,8 @@ read 512/512 bytes at offset 0
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "SHUTDOWN", "data": {"guest": false, "reason": "host-qmp-quit"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "standby", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "src", "len": 1024, "offset": 1024, "speed": 0, "type": "mirror"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "src"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_CANCELLED", "data": {"device": "src", "len": 1024, "offset": 1024, "speed": 0, "type": "mirror"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "src"}}
 Images are identical.
@@ -248,9 +244,8 @@ read 512/512 bytes at offset 0
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "SHUTDOWN", "data": {"guest": false, "reason": "host-qmp-quit"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "standby", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "src", "len": 65536, "offset": 65536, "speed": 0, "type": "mirror"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "src"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_CANCELLED", "data": {"device": "src", "len": 65536, "offset": 65536, "speed": 0, "type": "mirror"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "src"}}
 Images are identical.
@@ -299,9 +294,8 @@ read 512/512 bytes at offset 0
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "SHUTDOWN", "data": {"guest": false, "reason": "host-qmp-quit"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "standby", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "src", "len": 2560, "offset": 2560, "speed": 0, "type": "mirror"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "src"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_CANCELLED", "data": {"device": "src", "len": 2560, "offset": 2560, "speed": 0, "type": "mirror"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "src"}}
 Images are identical.
@@ -349,9 +343,8 @@ read 512/512 bytes at offset 0
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "SHUTDOWN", "data": {"guest": false, "reason": "host-qmp-quit"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "standby", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "src", "len": 2560, "offset": 2560, "speed": 0, "type": "mirror"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "src"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_CANCELLED", "data": {"device": "src", "len": 2560, "offset": 2560, "speed": 0, "type": "mirror"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "src"}}
 Images are identical.
@@ -399,9 +392,8 @@ read 512/512 bytes at offset 0
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "SHUTDOWN", "data": {"guest": false, "reason": "host-qmp-quit"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "standby", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "src", "len": 31457280, "offset": 31457280, "speed": 0, "type": "mirror"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "src"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_CANCELLED", "data": {"device": "src", "len": 31457280, "offset": 31457280, "speed": 0, "type": "mirror"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "src"}}
 Images are identical.
@@ -449,9 +441,8 @@ read 512/512 bytes at offset 0
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "SHUTDOWN", "data": {"guest": false, "reason": "host-qmp-quit"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "standby", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "src", "len": 327680, "offset": 327680, "speed": 0, "type": "mirror"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "src"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_CANCELLED", "data": {"device": "src", "len": 327680, "offset": 327680, "speed": 0, "type": "mirror"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "src"}}
 Images are identical.
@@ -499,9 +490,8 @@ read 512/512 bytes at offset 0
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "SHUTDOWN", "data": {"guest": false, "reason": "host-qmp-quit"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "standby", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "src", "len": 2048, "offset": 2048, "speed": 0, "type": "mirror"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "src"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_CANCELLED", "data": {"device": "src", "len": 2048, "offset": 2048, "speed": 0, "type": "mirror"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "src"}}
 Images are identical.
@@ -529,9 +519,8 @@ WARNING: Image format was not specified for 'TEST_DIR/t.raw' and probing guessed
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "SHUTDOWN", "data": {"guest": false, "reason": "host-qmp-quit"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "standby", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "src", "len": 512, "offset": 512, "speed": 0, "type": "mirror"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "src"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_CANCELLED", "data": {"device": "src", "len": 512, "offset": 512, "speed": 0, "type": "mirror"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "src"}}
 Images are identical.
@@ -552,9 +541,8 @@ Images are identical.
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "SHUTDOWN", "data": {"guest": false, "reason": "host-qmp-quit"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "standby", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "src"}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "src", "len": 512, "offset": 512, "speed": 0, "type": "mirror"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "src"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_CANCELLED", "data": {"device": "src", "len": 512, "offset": 512, "speed": 0, "type": "mirror"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "src"}}
 {"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "src"}}
 Images are identical.
diff --git a/tests/qemu-iotests/tests/qsd-jobs.out b/tests/qemu-iotests/tests/qsd-jobs.out
index 189423354b..c1bc9b8356 100644
--- a/tests/qemu-iotests/tests/qsd-jobs.out
+++ b/tests/qemu-iotests/tests/qsd-jobs.out
@@ -8,7 +8,7 @@ QMP_VERSION
 {"return": {}}
 {"return": {}}
 {"return": {}}
-{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "job0", "len": 0, "offset": 0, "speed": 0, "type": "commit"}}
+{"timestamp": {"seconds":  TIMESTAMP, "microseconds":  TIMESTAMP}, "event": "BLOCK_JOB_CANCELLED", "data": {"device": "job0", "len": 0, "offset": 0, "speed": 0, "type": "commit"}}
 
 === Streaming can't get permission on base node ===
 
-- 
2.29.2



^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PULL 06/12] jobs: Give Job.force_cancel more meaning
  2021-09-21 10:20 [PULL 00/12] jobs: mirror: Handle errors after READY cancel Vladimir Sementsov-Ogievskiy
                   ` (4 preceding siblings ...)
  2021-09-21 10:20 ` [PULL 05/12] job: @force parameter for job_cancel_sync() Vladimir Sementsov-Ogievskiy
@ 2021-09-21 10:20 ` Vladimir Sementsov-Ogievskiy
  2021-09-21 10:20 ` [PULL 07/12] job: Add job_cancel_requested() Vladimir Sementsov-Ogievskiy
                   ` (6 subsequent siblings)
  12 siblings, 0 replies; 19+ messages in thread
From: Vladimir Sementsov-Ogievskiy @ 2021-09-21 10:20 UTC (permalink / raw)
  To: qemu-block
  Cc: qemu-devel, peter.maydell, kwolf, hreitz, vsementsov, jsnow, Eric Blake

From: Hanna Reitz <hreitz@redhat.com>

We largely have two cancel modes for jobs:

First, there is actual cancelling.  The job is terminated as soon as
possible, without trying to reach a consistent result.

Second, we have mirror in the READY state.  Technically, the job is not
really cancelled, but it just is a different completion mode.  The job
can still run for an indefinite amount of time while it tries to reach a
consistent result.

We want to be able to clearly distinguish which cancel mode a job is in
(when it has been cancelled).  We can use Job.force_cancel for this, but
right now it only reflects cancel requests from the user with
force=true, but clearly, jobs that do not even distinguish between
force=false and force=true are effectively always force-cancelled.

So this patch has Job.force_cancel signify whether the job will
terminate as soon as possible (force_cancel=true) or whether it will
effectively remain running despite being "cancelled"
(force_cancel=false).

To this end, we let jobs that provide JobDriver.cancel() tell the
generic job code whether they will terminate as soon as possible or not,
and for jobs that do not provide that method we assume they will.

Signed-off-by: Hanna Reitz <hreitz@redhat.com>
Reviewed-by: Eric Blake <eblake@redhat.com>
Reviewed-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
Reviewed-by: Kevin Wolf <kwolf@redhat.com>
Message-Id: <20210907124245.143492-7-hreitz@redhat.com>
Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
---
 include/qemu/job.h | 11 ++++++++++-
 block/backup.c     |  3 ++-
 block/mirror.c     | 24 ++++++++++++++++++------
 job.c              |  6 +++++-
 4 files changed, 35 insertions(+), 9 deletions(-)

diff --git a/include/qemu/job.h b/include/qemu/job.h
index 2eddf3b536..90f6abbd6a 100644
--- a/include/qemu/job.h
+++ b/include/qemu/job.h
@@ -253,8 +253,17 @@ struct JobDriver {
 
     /**
      * If the callback is not NULL, it will be invoked in job_cancel_async
+     *
+     * This function must return true if the job will be cancelled
+     * immediately without any further I/O (mandatory if @force is
+     * true), and false otherwise.  This lets the generic job layer
+     * know whether a job has been truly (force-)cancelled, or whether
+     * it is just in a special completion mode (like mirror after
+     * READY).
+     * (If the callback is NULL, the job is assumed to terminate
+     * without I/O.)
      */
-    void (*cancel)(Job *job, bool force);
+    bool (*cancel)(Job *job, bool force);
 
 
     /** Called when the job is freed */
diff --git a/block/backup.c b/block/backup.c
index 687d2882bc..e8a13f9178 100644
--- a/block/backup.c
+++ b/block/backup.c
@@ -327,11 +327,12 @@ static void coroutine_fn backup_set_speed(BlockJob *job, int64_t speed)
     }
 }
 
-static void backup_cancel(Job *job, bool force)
+static bool backup_cancel(Job *job, bool force)
 {
     BackupBlockJob *s = container_of(job, BackupBlockJob, common.job);
 
     bdrv_cancel_in_flight(s->target_bs);
+    return true;
 }
 
 static const BlockJobDriver backup_job_driver = {
diff --git a/block/mirror.c b/block/mirror.c
index 86ddecb86b..7022d8011b 100644
--- a/block/mirror.c
+++ b/block/mirror.c
@@ -1094,9 +1094,7 @@ static int coroutine_fn mirror_run(Job *job, Error **errp)
         trace_mirror_before_sleep(s, cnt, job_is_ready(&s->common.job),
                                   delay_ns);
         job_sleep_ns(&s->common.job, delay_ns);
-        if (job_is_cancelled(&s->common.job) &&
-            (!job_is_ready(&s->common.job) || s->common.job.force_cancel))
-        {
+        if (job_is_cancelled(&s->common.job) && s->common.job.force_cancel) {
             break;
         }
         s->last_pause_ns = qemu_clock_get_ns(QEMU_CLOCK_REALTIME);
@@ -1109,7 +1107,7 @@ immediate_exit:
          * the target is a copy of the source.
          */
         assert(ret < 0 ||
-               ((s->common.job.force_cancel || !job_is_ready(&s->common.job)) &&
+               (s->common.job.force_cancel &&
                 job_is_cancelled(&s->common.job)));
         assert(need_drain);
         mirror_wait_for_all_io(s);
@@ -1195,14 +1193,27 @@ static bool mirror_drained_poll(BlockJob *job)
     return !!s->in_flight;
 }
 
-static void mirror_cancel(Job *job, bool force)
+static bool mirror_cancel(Job *job, bool force)
 {
     MirrorBlockJob *s = container_of(job, MirrorBlockJob, common.job);
     BlockDriverState *target = blk_bs(s->target);
 
-    if (force || !job_is_ready(job)) {
+    /*
+     * Before the job is READY, we treat any cancellation like a
+     * force-cancellation.
+     */
+    force = force || !job_is_ready(job);
+
+    if (force) {
         bdrv_cancel_in_flight(target);
     }
+    return force;
+}
+
+static bool commit_active_cancel(Job *job, bool force)
+{
+    /* Same as above in mirror_cancel() */
+    return force || !job_is_ready(job);
 }
 
 static const BlockJobDriver mirror_job_driver = {
@@ -1232,6 +1243,7 @@ static const BlockJobDriver commit_active_job_driver = {
         .abort                  = mirror_abort,
         .pause                  = mirror_pause,
         .complete               = mirror_complete,
+        .cancel                 = commit_active_cancel,
     },
     .drained_poll           = mirror_drained_poll,
 };
diff --git a/job.c b/job.c
index dfac35d553..81c016eb10 100644
--- a/job.c
+++ b/job.c
@@ -719,8 +719,12 @@ static int job_finalize_single(Job *job)
 static void job_cancel_async(Job *job, bool force)
 {
     if (job->driver->cancel) {
-        job->driver->cancel(job, force);
+        force = job->driver->cancel(job, force);
+    } else {
+        /* No .cancel() means the job will behave as if force-cancelled */
+        force = true;
     }
+
     if (job->user_paused) {
         /* Do not call job_enter here, the caller will handle it.  */
         if (job->driver->user_resume) {
-- 
2.29.2



^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PULL 07/12] job: Add job_cancel_requested()
  2021-09-21 10:20 [PULL 00/12] jobs: mirror: Handle errors after READY cancel Vladimir Sementsov-Ogievskiy
                   ` (5 preceding siblings ...)
  2021-09-21 10:20 ` [PULL 06/12] jobs: Give Job.force_cancel more meaning Vladimir Sementsov-Ogievskiy
@ 2021-09-21 10:20 ` Vladimir Sementsov-Ogievskiy
  2021-09-21 10:20 ` [PULL 08/12] mirror: Use job_is_cancelled() Vladimir Sementsov-Ogievskiy
                   ` (5 subsequent siblings)
  12 siblings, 0 replies; 19+ messages in thread
From: Vladimir Sementsov-Ogievskiy @ 2021-09-21 10:20 UTC (permalink / raw)
  To: qemu-block
  Cc: qemu-devel, peter.maydell, kwolf, hreitz, vsementsov, jsnow, Eric Blake

From: Hanna Reitz <hreitz@redhat.com>

Most callers of job_is_cancelled() actually want to know whether the job
is on its way to immediate termination.  For example, we refuse to pause
jobs that are cancelled; but this only makes sense for jobs that are
really actually cancelled.

A mirror job that is cancelled during READY with force=false should
absolutely be allowed to pause.  This "cancellation" (which is actually
a kind of completion) may take an indefinite amount of time, and so
should behave like any job during normal operation.  For example, with
on-target-error=stop, the job should stop on write errors.  (In
contrast, force-cancelled jobs should not get write errors, as they
should just terminate and not do further I/O.)

Therefore, redefine job_is_cancelled() to only return true for jobs that
are force-cancelled (which as of HEAD^ means any job that interprets the
cancellation request as a request for immediate termination), and add
job_cancel_requested() as the general variant, which returns true for
any jobs which have been requested to be cancelled, whether it be
immediately or after an arbitrarily long completion phase.

Finally, here is a justification for how different job_is_cancelled()
invocations are treated by this patch:

- block/mirror.c (mirror_run()):
  - The first invocation is a while loop that should loop until the job
    has been cancelled or scheduled for completion.  What kind of cancel
    does not matter, only the fact that the job is supposed to end.

  - The second invocation wants to know whether the job has been
    soft-cancelled.  Calling job_cancel_requested() is a bit too broad,
    but if the job were force-cancelled, we should leave the main loop
    as soon as possible anyway, so this should not matter here.

  - The last two invocations already check force_cancel, so they should
    continue to use job_is_cancelled().

- block/backup.c, block/commit.c, block/stream.c, anything in tests/:
  These jobs know only force-cancel, so there is no difference between
  job_is_cancelled() and job_cancel_requested().  We can continue using
  job_is_cancelled().

- job.c:
  - job_pause_point(), job_yield(), job_sleep_ns(): Only force-cancelled
    jobs should be prevented from being paused.  Continue using job_is_cancelled().

  - job_update_rc(), job_finalize_single(), job_finish_sync(): These
    functions are all called after the job has left its main loop.  The
    mirror job (the only job that can be soft-cancelled) will clear
    .cancelled before leaving the main loop if it has been
    soft-cancelled.  Therefore, these functions will observe .cancelled
    to be true only if the job has been force-cancelled.  We can
    continue to use job_is_cancelled().
    (Furthermore, conceptually, a soft-cancelled mirror job should not
    report to have been cancelled.  It should report completion (see
    also the block-job-cancel QAPI documentation).  Therefore, it makes
    sense for these functions not to distinguish between a
    soft-cancelled mirror job and a job that has completed as normal.)

  - job_completed_txn_abort(): All jobs other than @job have been
    force-cancelled.  job_is_cancelled() must be true for them.
    Regarding @job itself: job_completed_txn_abort() is mostly called
    when the job's return value is not 0.  A soft-cancelled mirror has a
    return value of 0, and so will not end up here then.
    However, job_cancel() invokes job_completed_txn_abort() if the job
    has been deferred to the main loop, which is mostly the case for
    completed jobs (which skip the assertion), but not for sure.
    To be safe, use job_cancel_requested() in this assertion.

  - job_complete(): This is function eventually invoked by the user
    (through qmp_block_job_complete() or qmp_job_complete(), or
    job_complete_sync(), which comes from qemu-img).  The intention here
    is to prevent a user from invoking job-complete after the job has
    been cancelled.  This should also apply to soft cancelling: After a
    mirror job has been soft-cancelled, the user should not be able to
    decide otherwise and have it complete as normal (i.e. pivoting to
    the target).

Buglink: https://gitlab.com/qemu-project/qemu/-/issues/462
Signed-off-by: Hanna Reitz <hreitz@redhat.com>
Reviewed-by: Eric Blake <eblake@redhat.com>
Reviewed-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
Message-Id: <20210907124245.143492-8-hreitz@redhat.com>
Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
---
 include/qemu/job.h |  8 +++++++-
 block/mirror.c     | 10 ++++------
 job.c              |  9 +++++++--
 3 files changed, 18 insertions(+), 9 deletions(-)

diff --git a/include/qemu/job.h b/include/qemu/job.h
index 90f6abbd6a..6e67b6977f 100644
--- a/include/qemu/job.h
+++ b/include/qemu/job.h
@@ -436,9 +436,15 @@ const char *job_type_str(const Job *job);
 /** Returns true if the job should not be visible to the management layer. */
 bool job_is_internal(Job *job);
 
-/** Returns whether the job is scheduled for cancellation. */
+/** Returns whether the job is being cancelled. */
 bool job_is_cancelled(Job *job);
 
+/**
+ * Returns whether the job is scheduled for cancellation (at an
+ * indefinite point).
+ */
+bool job_cancel_requested(Job *job);
+
 /** Returns whether the job is in a completed state. */
 bool job_is_completed(Job *job);
 
diff --git a/block/mirror.c b/block/mirror.c
index 7022d8011b..6c3d8379f8 100644
--- a/block/mirror.c
+++ b/block/mirror.c
@@ -943,7 +943,7 @@ static int coroutine_fn mirror_run(Job *job, Error **errp)
         /* Transition to the READY state and wait for complete. */
         job_transition_to_ready(&s->common.job);
         s->actively_synced = true;
-        while (!job_is_cancelled(&s->common.job) && !s->should_complete) {
+        while (!job_cancel_requested(&s->common.job) && !s->should_complete) {
             job_yield(&s->common.job);
         }
         s->common.job.cancelled = false;
@@ -1050,7 +1050,7 @@ static int coroutine_fn mirror_run(Job *job, Error **errp)
             }
 
             should_complete = s->should_complete ||
-                job_is_cancelled(&s->common.job);
+                job_cancel_requested(&s->common.job);
             cnt = bdrv_get_dirty_count(s->dirty_bitmap);
         }
 
@@ -1094,7 +1094,7 @@ static int coroutine_fn mirror_run(Job *job, Error **errp)
         trace_mirror_before_sleep(s, cnt, job_is_ready(&s->common.job),
                                   delay_ns);
         job_sleep_ns(&s->common.job, delay_ns);
-        if (job_is_cancelled(&s->common.job) && s->common.job.force_cancel) {
+        if (job_is_cancelled(&s->common.job)) {
             break;
         }
         s->last_pause_ns = qemu_clock_get_ns(QEMU_CLOCK_REALTIME);
@@ -1106,9 +1106,7 @@ immediate_exit:
          * or it was cancelled prematurely so that we do not guarantee that
          * the target is a copy of the source.
          */
-        assert(ret < 0 ||
-               (s->common.job.force_cancel &&
-                job_is_cancelled(&s->common.job)));
+        assert(ret < 0 || job_is_cancelled(&s->common.job));
         assert(need_drain);
         mirror_wait_for_all_io(s);
     }
diff --git a/job.c b/job.c
index 81c016eb10..be878ca5fc 100644
--- a/job.c
+++ b/job.c
@@ -216,6 +216,11 @@ const char *job_type_str(const Job *job)
 }
 
 bool job_is_cancelled(Job *job)
+{
+    return job->cancelled && job->force_cancel;
+}
+
+bool job_cancel_requested(Job *job)
 {
     return job->cancelled;
 }
@@ -788,7 +793,7 @@ static void job_completed_txn_abort(Job *job)
         ctx = other_job->aio_context;
         aio_context_acquire(ctx);
         if (!job_is_completed(other_job)) {
-            assert(job_is_cancelled(other_job));
+            assert(job_cancel_requested(other_job));
             job_finish_sync(other_job, NULL, NULL);
         }
         job_finalize_single(other_job);
@@ -1027,7 +1032,7 @@ void job_complete(Job *job, Error **errp)
     if (job_apply_verb(job, JOB_VERB_COMPLETE, errp)) {
         return;
     }
-    if (job_is_cancelled(job) || !job->driver->complete) {
+    if (job_cancel_requested(job) || !job->driver->complete) {
         error_setg(errp, "The active block job '%s' cannot be completed",
                    job->id);
         return;
-- 
2.29.2



^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PULL 08/12] mirror: Use job_is_cancelled()
  2021-09-21 10:20 [PULL 00/12] jobs: mirror: Handle errors after READY cancel Vladimir Sementsov-Ogievskiy
                   ` (6 preceding siblings ...)
  2021-09-21 10:20 ` [PULL 07/12] job: Add job_cancel_requested() Vladimir Sementsov-Ogievskiy
@ 2021-09-21 10:20 ` Vladimir Sementsov-Ogievskiy
  2021-09-21 10:20 ` [PULL 09/12] mirror: Check job_is_cancelled() earlier Vladimir Sementsov-Ogievskiy
                   ` (4 subsequent siblings)
  12 siblings, 0 replies; 19+ messages in thread
From: Vladimir Sementsov-Ogievskiy @ 2021-09-21 10:20 UTC (permalink / raw)
  To: qemu-block
  Cc: qemu-devel, peter.maydell, kwolf, hreitz, vsementsov, jsnow, Eric Blake

From: Hanna Reitz <hreitz@redhat.com>

mirror_drained_poll() returns true whenever the job is cancelled,
because "we [can] be sure that it won't issue more requests".  However,
this is only true for force-cancelled jobs, so use job_is_cancelled().

Signed-off-by: Hanna Reitz <hreitz@redhat.com>
Reviewed-by: Eric Blake <eblake@redhat.com>
Reviewed-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
Message-Id: <20210907124245.143492-9-hreitz@redhat.com>
Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
---
 block/mirror.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/block/mirror.c b/block/mirror.c
index 6c3d8379f8..cfebe50845 100644
--- a/block/mirror.c
+++ b/block/mirror.c
@@ -1184,7 +1184,7 @@ static bool mirror_drained_poll(BlockJob *job)
      * from one of our own drain sections, to avoid a deadlock waiting for
      * ourselves.
      */
-    if (!s->common.job.paused && !s->common.job.cancelled && !s->in_drain) {
+    if (!s->common.job.paused && !job_is_cancelled(&job->job) && !s->in_drain) {
         return true;
     }
 
-- 
2.29.2



^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PULL 09/12] mirror: Check job_is_cancelled() earlier
  2021-09-21 10:20 [PULL 00/12] jobs: mirror: Handle errors after READY cancel Vladimir Sementsov-Ogievskiy
                   ` (7 preceding siblings ...)
  2021-09-21 10:20 ` [PULL 08/12] mirror: Use job_is_cancelled() Vladimir Sementsov-Ogievskiy
@ 2021-09-21 10:20 ` Vladimir Sementsov-Ogievskiy
  2021-09-21 10:20 ` [PULL 10/12] mirror: Stop active mirroring after force-cancel Vladimir Sementsov-Ogievskiy
                   ` (3 subsequent siblings)
  12 siblings, 0 replies; 19+ messages in thread
From: Vladimir Sementsov-Ogievskiy @ 2021-09-21 10:20 UTC (permalink / raw)
  To: qemu-block
  Cc: qemu-devel, peter.maydell, kwolf, hreitz, vsementsov, jsnow, Eric Blake

From: Hanna Reitz <hreitz@redhat.com>

We must check whether the job is force-cancelled early in our main loop,
most importantly before any `continue` statement.  For example, we used
to have `continue`s before our current checking location that are
triggered by `mirror_flush()` failing.  So, if `mirror_flush()` kept
failing, force-cancelling the job would not terminate it.

Jobs can be cancelled while they yield, and once they are
(force-cancelled), they should not generate new I/O requests.
Therefore, we should put the check after the last yield before
mirror_iteration() is invoked.

Buglink: https://gitlab.com/qemu-project/qemu/-/issues/462
Signed-off-by: Hanna Reitz <hreitz@redhat.com>
Reviewed-by: Eric Blake <eblake@redhat.com>
Reviewed-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
Message-Id: <20210907124245.143492-10-hreitz@redhat.com>
Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
---
 block/mirror.c | 10 +++++-----
 1 file changed, 5 insertions(+), 5 deletions(-)

diff --git a/block/mirror.c b/block/mirror.c
index cfebe50845..1dbf648311 100644
--- a/block/mirror.c
+++ b/block/mirror.c
@@ -1007,6 +1007,11 @@ static int coroutine_fn mirror_run(Job *job, Error **errp)
 
         job_pause_point(&s->common.job);
 
+        if (job_is_cancelled(&s->common.job)) {
+            ret = 0;
+            goto immediate_exit;
+        }
+
         cnt = bdrv_get_dirty_count(s->dirty_bitmap);
         /* cnt is the number of dirty bytes remaining and s->bytes_in_flight is
          * the number of bytes currently being processed; together those are
@@ -1085,8 +1090,6 @@ static int coroutine_fn mirror_run(Job *job, Error **errp)
             break;
         }
 
-        ret = 0;
-
         if (job_is_ready(&s->common.job) && !should_complete) {
             delay_ns = (s->in_flight == 0 &&
                         cnt == 0 ? BLOCK_JOB_SLICE_TIME : 0);
@@ -1094,9 +1097,6 @@ static int coroutine_fn mirror_run(Job *job, Error **errp)
         trace_mirror_before_sleep(s, cnt, job_is_ready(&s->common.job),
                                   delay_ns);
         job_sleep_ns(&s->common.job, delay_ns);
-        if (job_is_cancelled(&s->common.job)) {
-            break;
-        }
         s->last_pause_ns = qemu_clock_get_ns(QEMU_CLOCK_REALTIME);
     }
 
-- 
2.29.2



^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PULL 10/12] mirror: Stop active mirroring after force-cancel
  2021-09-21 10:20 [PULL 00/12] jobs: mirror: Handle errors after READY cancel Vladimir Sementsov-Ogievskiy
                   ` (8 preceding siblings ...)
  2021-09-21 10:20 ` [PULL 09/12] mirror: Check job_is_cancelled() earlier Vladimir Sementsov-Ogievskiy
@ 2021-09-21 10:20 ` Vladimir Sementsov-Ogievskiy
  2021-09-21 10:20 ` [PULL 11/12] mirror: Do not clear .cancelled Vladimir Sementsov-Ogievskiy
                   ` (2 subsequent siblings)
  12 siblings, 0 replies; 19+ messages in thread
From: Vladimir Sementsov-Ogievskiy @ 2021-09-21 10:20 UTC (permalink / raw)
  To: qemu-block
  Cc: qemu-devel, peter.maydell, kwolf, hreitz, vsementsov, jsnow, Eric Blake

From: Hanna Reitz <hreitz@redhat.com>

Once the mirror job is force-cancelled (job_is_cancelled() is true), we
should not generate new I/O requests.  This applies to active mirroring,
too, so stop it once the job is cancelled.

(We must still forward all I/O requests to the source, though, of
course, but those are not really I/O requests generated by the job, so
this is fine.)

Signed-off-by: Hanna Reitz <hreitz@redhat.com>
Reviewed-by: Eric Blake <eblake@redhat.com>
Reviewed-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
Message-Id: <20210907124245.143492-11-hreitz@redhat.com>
Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
---
 block/mirror.c | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/block/mirror.c b/block/mirror.c
index 1dbf648311..bbf5815fd7 100644
--- a/block/mirror.c
+++ b/block/mirror.c
@@ -1425,6 +1425,7 @@ static int coroutine_fn bdrv_mirror_top_do_write(BlockDriverState *bs,
     bool copy_to_target;
 
     copy_to_target = s->job->ret >= 0 &&
+                     !job_is_cancelled(&s->job->common.job) &&
                      s->job->copy_mode == MIRROR_COPY_MODE_WRITE_BLOCKING;
 
     if (copy_to_target) {
@@ -1473,6 +1474,7 @@ static int coroutine_fn bdrv_mirror_top_pwritev(BlockDriverState *bs,
     bool copy_to_target;
 
     copy_to_target = s->job->ret >= 0 &&
+                     !job_is_cancelled(&s->job->common.job) &&
                      s->job->copy_mode == MIRROR_COPY_MODE_WRITE_BLOCKING;
 
     if (copy_to_target) {
-- 
2.29.2



^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PULL 11/12] mirror: Do not clear .cancelled
  2021-09-21 10:20 [PULL 00/12] jobs: mirror: Handle errors after READY cancel Vladimir Sementsov-Ogievskiy
                   ` (9 preceding siblings ...)
  2021-09-21 10:20 ` [PULL 10/12] mirror: Stop active mirroring after force-cancel Vladimir Sementsov-Ogievskiy
@ 2021-09-21 10:20 ` Vladimir Sementsov-Ogievskiy
  2021-09-21 10:20 ` [PULL 12/12] iotests: Add mirror-ready-cancel-error test Vladimir Sementsov-Ogievskiy
  2021-09-22 16:05 ` [PULL 00/12] jobs: mirror: Handle errors after READY cancel Richard Henderson
  12 siblings, 0 replies; 19+ messages in thread
From: Vladimir Sementsov-Ogievskiy @ 2021-09-21 10:20 UTC (permalink / raw)
  To: qemu-block
  Cc: qemu-devel, peter.maydell, kwolf, hreitz, vsementsov, jsnow, Eric Blake

From: Hanna Reitz <hreitz@redhat.com>

Clearing .cancelled before leaving the main loop when the job has been
soft-cancelled is no longer necessary since job_is_cancelled() only
returns true for jobs that have been force-cancelled.

Therefore, this only makes a differences in places that call
job_cancel_requested().  In block/mirror.c, this is done only before
.cancelled was cleared.

In job.c, there are two callers:
- job_completed_txn_abort() asserts that .cancelled is true, so keeping
  it true will not affect this place.

- job_complete() refuses to let a job complete that has .cancelled set.
  It is correct to refuse to let the user invoke job-complete on mirror
  jobs that have already been soft-cancelled.

With this change, there are no places that reset .cancelled to false and
so we can be sure that .force_cancel can only be true if .cancelled is
true as well.  Assert this in job_is_cancelled().

Signed-off-by: Hanna Reitz <hreitz@redhat.com>
Reviewed-by: Eric Blake <eblake@redhat.com>
Reviewed-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
Message-Id: <20210907124245.143492-12-hreitz@redhat.com>
Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
---
 block/mirror.c | 2 --
 job.c          | 4 +++-
 2 files changed, 3 insertions(+), 3 deletions(-)

diff --git a/block/mirror.c b/block/mirror.c
index bbf5815fd7..bb837db46e 100644
--- a/block/mirror.c
+++ b/block/mirror.c
@@ -946,7 +946,6 @@ static int coroutine_fn mirror_run(Job *job, Error **errp)
         while (!job_cancel_requested(&s->common.job) && !s->should_complete) {
             job_yield(&s->common.job);
         }
-        s->common.job.cancelled = false;
         goto immediate_exit;
     }
 
@@ -1085,7 +1084,6 @@ static int coroutine_fn mirror_run(Job *job, Error **errp)
              * completion.
              */
             assert(QLIST_EMPTY(&bs->tracked_requests));
-            s->common.job.cancelled = false;
             need_drain = false;
             break;
         }
diff --git a/job.c b/job.c
index be878ca5fc..85c0216734 100644
--- a/job.c
+++ b/job.c
@@ -217,7 +217,9 @@ const char *job_type_str(const Job *job)
 
 bool job_is_cancelled(Job *job)
 {
-    return job->cancelled && job->force_cancel;
+    /* force_cancel may be true only if cancelled is true, too */
+    assert(job->cancelled || !job->force_cancel);
+    return job->force_cancel;
 }
 
 bool job_cancel_requested(Job *job)
-- 
2.29.2



^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PULL 12/12] iotests: Add mirror-ready-cancel-error test
  2021-09-21 10:20 [PULL 00/12] jobs: mirror: Handle errors after READY cancel Vladimir Sementsov-Ogievskiy
                   ` (10 preceding siblings ...)
  2021-09-21 10:20 ` [PULL 11/12] mirror: Do not clear .cancelled Vladimir Sementsov-Ogievskiy
@ 2021-09-21 10:20 ` Vladimir Sementsov-Ogievskiy
  2021-09-22 16:05 ` [PULL 00/12] jobs: mirror: Handle errors after READY cancel Richard Henderson
  12 siblings, 0 replies; 19+ messages in thread
From: Vladimir Sementsov-Ogievskiy @ 2021-09-21 10:20 UTC (permalink / raw)
  To: qemu-block; +Cc: qemu-devel, peter.maydell, kwolf, hreitz, vsementsov, jsnow

From: Hanna Reitz <hreitz@redhat.com>

Test what happens when there is an I/O error after a mirror job in the
READY phase has been cancelled.

Signed-off-by: Hanna Reitz <hreitz@redhat.com>
Reviewed-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
Tested-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
Message-Id: <20210907124245.143492-13-hreitz@redhat.com>
Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
---
 .../tests/mirror-ready-cancel-error           | 143 ++++++++++++++++++
 .../tests/mirror-ready-cancel-error.out       |   5 +
 2 files changed, 148 insertions(+)
 create mode 100755 tests/qemu-iotests/tests/mirror-ready-cancel-error
 create mode 100644 tests/qemu-iotests/tests/mirror-ready-cancel-error.out

diff --git a/tests/qemu-iotests/tests/mirror-ready-cancel-error b/tests/qemu-iotests/tests/mirror-ready-cancel-error
new file mode 100755
index 0000000000..f2dc88881f
--- /dev/null
+++ b/tests/qemu-iotests/tests/mirror-ready-cancel-error
@@ -0,0 +1,143 @@
+#!/usr/bin/env python3
+# group: rw quick
+#
+# Test what happens when errors occur to a mirror job after it has
+# been cancelled in the READY phase
+#
+# Copyright (C) 2021 Red Hat, Inc.
+#
+# This program is free software; you can redistribute it and/or modify
+# it under the terms of the GNU General Public License as published by
+# the Free Software Foundation; either version 2 of the License, or
+# (at your option) any later version.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with this program.  If not, see <http://www.gnu.org/licenses/>.
+#
+
+import os
+import iotests
+
+
+image_size = 1 * 1024 * 1024
+source = os.path.join(iotests.test_dir, 'source.img')
+target = os.path.join(iotests.test_dir, 'target.img')
+
+
+class TestMirrorReadyCancelError(iotests.QMPTestCase):
+    def setUp(self) -> None:
+        assert iotests.qemu_img_create('-f', iotests.imgfmt, source,
+                                       str(image_size)) == 0
+        assert iotests.qemu_img_create('-f', iotests.imgfmt, target,
+                                       str(image_size)) == 0
+
+        self.vm = iotests.VM()
+        self.vm.launch()
+
+    def tearDown(self) -> None:
+        self.vm.shutdown()
+        os.remove(source)
+        os.remove(target)
+
+    def add_blockdevs(self, once: bool) -> None:
+        res = self.vm.qmp('blockdev-add',
+                          **{'node-name': 'source',
+                             'driver': iotests.imgfmt,
+                             'file': {
+                                 'driver': 'file',
+                                 'filename': source
+                             }})
+        self.assert_qmp(res, 'return', {})
+
+        # blkdebug notes:
+        # Enter state 2 on the first flush, which happens before the
+        # job enters the READY state.  The second flush will happen
+        # when the job is about to complete, and we want that one to
+        # fail.
+        res = self.vm.qmp('blockdev-add',
+                          **{'node-name': 'target',
+                             'driver': iotests.imgfmt,
+                             'file': {
+                                 'driver': 'blkdebug',
+                                 'image': {
+                                     'driver': 'file',
+                                     'filename': target
+                                 },
+                                 'set-state': [{
+                                     'event': 'flush_to_disk',
+                                     'state': 1,
+                                     'new_state': 2
+                                 }],
+                                 'inject-error': [{
+                                     'event': 'flush_to_disk',
+                                     'once': once,
+                                     'immediately': True,
+                                     'state': 2
+                                 }]}})
+        self.assert_qmp(res, 'return', {})
+
+    def start_mirror(self) -> None:
+        res = self.vm.qmp('blockdev-mirror',
+                          job_id='mirror',
+                          device='source',
+                          target='target',
+                          filter_node_name='mirror-top',
+                          sync='full',
+                          on_target_error='stop')
+        self.assert_qmp(res, 'return', {})
+
+    def cancel_mirror_with_error(self) -> None:
+        self.vm.event_wait('BLOCK_JOB_READY')
+
+        # Write something so will not leave the job immediately, but
+        # flush first (which will fail, thanks to blkdebug)
+        res = self.vm.qmp('human-monitor-command',
+                          command_line='qemu-io mirror-top "write 0 64k"')
+        self.assert_qmp(res, 'return', '')
+
+        # Drain status change events
+        while self.vm.event_wait('JOB_STATUS_CHANGE', timeout=0.0) is not None:
+            pass
+
+        res = self.vm.qmp('block-job-cancel', device='mirror')
+        self.assert_qmp(res, 'return', {})
+
+        self.vm.event_wait('BLOCK_JOB_ERROR')
+
+    def test_transient_error(self) -> None:
+        self.add_blockdevs(True)
+        self.start_mirror()
+        self.cancel_mirror_with_error()
+
+        while True:
+            e = self.vm.event_wait('JOB_STATUS_CHANGE')
+            if e['data']['status'] == 'standby':
+                # Transient error, try again
+                self.vm.qmp('block-job-resume', device='mirror')
+            elif e['data']['status'] == 'null':
+                break
+
+    def test_persistent_error(self) -> None:
+        self.add_blockdevs(False)
+        self.start_mirror()
+        self.cancel_mirror_with_error()
+
+        while True:
+            e = self.vm.event_wait('JOB_STATUS_CHANGE')
+            if e['data']['status'] == 'standby':
+                # Persistent error, no point in continuing
+                self.vm.qmp('block-job-cancel', device='mirror', force=True)
+            elif e['data']['status'] == 'null':
+                break
+
+
+if __name__ == '__main__':
+    # LUKS would require special key-secret handling in add_blockdevs()
+    iotests.main(supported_fmts=['generic'],
+                 unsupported_fmts=['luks'],
+                 supported_protocols=['file'])
diff --git a/tests/qemu-iotests/tests/mirror-ready-cancel-error.out b/tests/qemu-iotests/tests/mirror-ready-cancel-error.out
new file mode 100644
index 0000000000..fbc63e62f8
--- /dev/null
+++ b/tests/qemu-iotests/tests/mirror-ready-cancel-error.out
@@ -0,0 +1,5 @@
+..
+----------------------------------------------------------------------
+Ran 2 tests
+
+OK
-- 
2.29.2



^ permalink raw reply related	[flat|nested] 19+ messages in thread

* Re: [PULL 00/12] jobs: mirror: Handle errors after READY cancel
  2021-09-21 10:20 [PULL 00/12] jobs: mirror: Handle errors after READY cancel Vladimir Sementsov-Ogievskiy
                   ` (11 preceding siblings ...)
  2021-09-21 10:20 ` [PULL 12/12] iotests: Add mirror-ready-cancel-error test Vladimir Sementsov-Ogievskiy
@ 2021-09-22 16:05 ` Richard Henderson
  2021-09-22 19:19   ` Vladimir Sementsov-Ogievskiy
  12 siblings, 1 reply; 19+ messages in thread
From: Richard Henderson @ 2021-09-22 16:05 UTC (permalink / raw)
  To: Vladimir Sementsov-Ogievskiy, qemu-block
  Cc: kwolf, peter.maydell, hreitz, jsnow, qemu-devel

On 9/21/21 3:20 AM, Vladimir Sementsov-Ogievskiy wrote:
> The following changes since commit 326ff8dd09556fc2e257196c49f35009700794ac:
> 
>    Merge remote-tracking branch 'remotes/jasowang/tags/net-pull-request' into staging (2021-09-20 16:17:05 +0100)
> 
> are available in the Git repository at:
> 
>    https://src.openvz.org/scm/~vsementsov/qemu.git  tags/pull-jobs-2021-09-21
> 
> for you to fetch changes up to c9489c04319cac75c76af8fc27c254f46e10214c:
> 
>    iotests: Add mirror-ready-cancel-error test (2021-09-21 11:56:11 +0300)
> 
> ----------------------------------------------------------------
> mirror: Handle errors after READY cancel
> 
> ----------------------------------------------------------------
> Hanna Reitz (12):
>        job: Context changes in job_completed_txn_abort()
>        mirror: Keep s->synced on error
>        mirror: Drop s->synced
>        job: Force-cancel jobs in a failed transaction
>        job: @force parameter for job_cancel_sync()
>        jobs: Give Job.force_cancel more meaning
>        job: Add job_cancel_requested()
>        mirror: Use job_is_cancelled()
>        mirror: Check job_is_cancelled() earlier
>        mirror: Stop active mirroring after force-cancel
>        mirror: Do not clear .cancelled
>        iotests: Add mirror-ready-cancel-error test

This fails testing with errors like so:

Running test test-replication
test-replication: ../job.c:186: job_state_transition: Assertion `JobSTT[s0][s1]' failed.
ERROR test-replication - too few tests run (expected 13, got 8)
make: *** [Makefile.mtest:816: run-test-100] Error 1
Cleaning up project directory and file based variables
ERROR: Job failed: exit code 1

https://gitlab.com/qemu-project/qemu/-/pipelines/375324015/failures


r~


^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PULL 00/12] jobs: mirror: Handle errors after READY cancel
  2021-09-22 16:05 ` [PULL 00/12] jobs: mirror: Handle errors after READY cancel Richard Henderson
@ 2021-09-22 19:19   ` Vladimir Sementsov-Ogievskiy
  2021-09-23 22:01     ` Vladimir Sementsov-Ogievskiy
  0 siblings, 1 reply; 19+ messages in thread
From: Vladimir Sementsov-Ogievskiy @ 2021-09-22 19:19 UTC (permalink / raw)
  To: Richard Henderson, qemu-block
  Cc: qemu-devel, peter.maydell, kwolf, hreitz, jsnow

22.09.2021 19:05, Richard Henderson wrote:
> On 9/21/21 3:20 AM, Vladimir Sementsov-Ogievskiy wrote:
>> The following changes since commit 326ff8dd09556fc2e257196c49f35009700794ac:
>>
>>    Merge remote-tracking branch 'remotes/jasowang/tags/net-pull-request' into staging (2021-09-20 16:17:05 +0100)
>>
>> are available in the Git repository at:
>>
>>    https://src.openvz.org/scm/~vsementsov/qemu.git  tags/pull-jobs-2021-09-21
>>
>> for you to fetch changes up to c9489c04319cac75c76af8fc27c254f46e10214c:
>>
>>    iotests: Add mirror-ready-cancel-error test (2021-09-21 11:56:11 +0300)
>>
>> ----------------------------------------------------------------
>> mirror: Handle errors after READY cancel
>>
>> ----------------------------------------------------------------
>> Hanna Reitz (12):
>>        job: Context changes in job_completed_txn_abort()
>>        mirror: Keep s->synced on error
>>        mirror: Drop s->synced
>>        job: Force-cancel jobs in a failed transaction
>>        job: @force parameter for job_cancel_sync()
>>        jobs: Give Job.force_cancel more meaning
>>        job: Add job_cancel_requested()
>>        mirror: Use job_is_cancelled()
>>        mirror: Check job_is_cancelled() earlier
>>        mirror: Stop active mirroring after force-cancel
>>        mirror: Do not clear .cancelled
>>        iotests: Add mirror-ready-cancel-error test
> 
> This fails testing with errors like so:
> 
> Running test test-replication
> test-replication: ../job.c:186: job_state_transition: Assertion `JobSTT[s0][s1]' failed.
> ERROR test-replication - too few tests run (expected 13, got 8)
> make: *** [Makefile.mtest:816: run-test-100] Error 1
> Cleaning up project directory and file based variables
> ERROR: Job failed: exit code 1
> 
> https://gitlab.com/qemu-project/qemu/-/pipelines/375324015/failures
> 


Interesting :(

I've reproduced, starting test-replication in several parallel loops. (it doesn't reproduce for me if just start in one loop). So, that's some racy bug..

Hmm, and seems it doesn't reproduce so simple on master. I'll try to bisect the series tomorrow.

====

(gdb) bt
#0  0x00007f034a3d09d5 in raise () from /lib64/libc.so.6
#1  0x00007f034a3b9954 in abort () from /lib64/libc.so.6
#2  0x00007f034a3b9789 in __assert_fail_base.cold () from /lib64/libc.so.6
#3  0x00007f034a3c9026 in __assert_fail () from /lib64/libc.so.6
#4  0x000055d3b503d670 in job_state_transition (job=0x55d3b5e67020, s1=JOB_STATUS_CONCLUDED) at ../job.c:186
#5  0x000055d3b503e7c2 in job_conclude (job=0x55d3b5e67020) at ../job.c:652
#6  0x000055d3b503eaa1 in job_finalize_single (job=0x55d3b5e67020) at ../job.c:722
#7  0x000055d3b503ecd1 in job_completed_txn_abort (job=0x55d3b5e67020) at ../job.c:801
#8  0x000055d3b503f2ea in job_cancel (job=0x55d3b5e67020, force=false) at ../job.c:973
#9  0x000055d3b503f360 in job_cancel_err (job=0x55d3b5e67020, errp=0x7fffcc997a80) at ../job.c:992
#10 0x000055d3b503f576 in job_finish_sync (job=0x55d3b5e67020, finish=0x55d3b503f33f <job_cancel_err>, errp=0x0) at ../job.c:1054
#11 0x000055d3b503f3d0 in job_cancel_sync (job=0x55d3b5e67020, force=false) at ../job.c:1008
#12 0x000055d3b4ff14a3 in replication_close (bs=0x55d3b5e6ef80) at ../block/replication.c:152
#13 0x000055d3b50277fc in bdrv_close (bs=0x55d3b5e6ef80) at ../block.c:4677
#14 0x000055d3b50286cf in bdrv_delete (bs=0x55d3b5e6ef80) at ../block.c:5100
#15 0x000055d3b502ae3a in bdrv_unref (bs=0x55d3b5e6ef80) at ../block.c:6495
#16 0x000055d3b5023a38 in bdrv_root_unref_child (child=0x55d3b5e4c690) at ../block.c:3010
#17 0x000055d3b5047998 in blk_remove_bs (blk=0x55d3b5e73b40) at ../block/block-backend.c:845
#18 0x000055d3b5046e38 in blk_delete (blk=0x55d3b5e73b40) at ../block/block-backend.c:461
#19 0x000055d3b50470dc in blk_unref (blk=0x55d3b5e73b40) at ../block/block-backend.c:516
#20 0x000055d3b4fdb20a in teardown_secondary () at ../tests/unit/test-replication.c:367
#21 0x000055d3b4fdb632 in test_secondary_continuous_replication () at ../tests/unit/test-replication.c:504
#22 0x00007f034b26979e in g_test_run_suite_internal () from /lib64/libglib-2.0.so.0
#23 0x00007f034b26959b in g_test_run_suite_internal () from /lib64/libglib-2.0.so.0
#24 0x00007f034b26959b in g_test_run_suite_internal () from /lib64/libglib-2.0.so.0
#25 0x00007f034b269c8a in g_test_run_suite () from /lib64/libglib-2.0.so.0
#26 0x00007f034b269ca5 in g_test_run () from /lib64/libglib-2.0.so.0
#27 0x000055d3b4fdb9c0 in main (argc=1, argv=0x7fffcc998138) at ../tests/unit/test-replication.c:613
(gdb) fr 4
#4  0x000055d3b503d670 in job_state_transition (job=0x55d3b5e67020, s1=JOB_STATUS_CONCLUDED) at ../job.c:186
186         assert(JobSTT[s0][s1]);
(gdb) list
181         JobStatus s0 = job->status;
182         assert(s1 >= 0 && s1 < JOB_STATUS__MAX);
183         trace_job_state_transition(job, job->ret,
184                                    JobSTT[s0][s1] ? "allowed" : "disallowed",
185                                    JobStatus_str(s0), JobStatus_str(s1));
186         assert(JobSTT[s0][s1]);
187         job->status = s1;
188
189         if (!job_is_internal(job) && s1 != s0) {
190             qapi_event_send_job_status_change(job->id, job->status);
(gdb) p s0
$1 = JOB_STATUS_NULL
(gdb) p s1
$2 = JOB_STATUS_CONCLUDED



-- 
Best regards,
Vladimir


^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PULL 00/12] jobs: mirror: Handle errors after READY cancel
  2021-09-22 19:19   ` Vladimir Sementsov-Ogievskiy
@ 2021-09-23 22:01     ` Vladimir Sementsov-Ogievskiy
  2021-10-04 16:47       ` Hanna Reitz
  0 siblings, 1 reply; 19+ messages in thread
From: Vladimir Sementsov-Ogievskiy @ 2021-09-23 22:01 UTC (permalink / raw)
  To: Richard Henderson, qemu-block
  Cc: qemu-devel, peter.maydell, kwolf, hreitz, jsnow

22.09.2021 22:19, Vladimir Sementsov-Ogievskiy wrote:
> 22.09.2021 19:05, Richard Henderson wrote:
>> On 9/21/21 3:20 AM, Vladimir Sementsov-Ogievskiy wrote:
>>> The following changes since commit 326ff8dd09556fc2e257196c49f35009700794ac:
>>>
>>>    Merge remote-tracking branch 'remotes/jasowang/tags/net-pull-request' into staging (2021-09-20 16:17:05 +0100)
>>>
>>> are available in the Git repository at:
>>>
>>>    https://src.openvz.org/scm/~vsementsov/qemu.git  tags/pull-jobs-2021-09-21
>>>
>>> for you to fetch changes up to c9489c04319cac75c76af8fc27c254f46e10214c:
>>>
>>>    iotests: Add mirror-ready-cancel-error test (2021-09-21 11:56:11 +0300)
>>>
>>> ----------------------------------------------------------------
>>> mirror: Handle errors after READY cancel
>>>
>>> ----------------------------------------------------------------
>>> Hanna Reitz (12):
>>>        job: Context changes in job_completed_txn_abort()
>>>        mirror: Keep s->synced on error
>>>        mirror: Drop s->synced
>>>        job: Force-cancel jobs in a failed transaction
>>>        job: @force parameter for job_cancel_sync()
>>>        jobs: Give Job.force_cancel more meaning
>>>        job: Add job_cancel_requested()
>>>        mirror: Use job_is_cancelled()
>>>        mirror: Check job_is_cancelled() earlier
>>>        mirror: Stop active mirroring after force-cancel
>>>        mirror: Do not clear .cancelled
>>>        iotests: Add mirror-ready-cancel-error test
>>
>> This fails testing with errors like so:
>>
>> Running test test-replication
>> test-replication: ../job.c:186: job_state_transition: Assertion `JobSTT[s0][s1]' failed.
>> ERROR test-replication - too few tests run (expected 13, got 8)
>> make: *** [Makefile.mtest:816: run-test-100] Error 1
>> Cleaning up project directory and file based variables
>> ERROR: Job failed: exit code 1
>>
>> https://gitlab.com/qemu-project/qemu/-/pipelines/375324015/failures
>>
> 
> 
> Interesting :(
> 
> I've reproduced, starting test-replication in several parallel loops. (it doesn't reproduce for me if just start in one loop). So, that's some racy bug..
> 
> Hmm, and seems it doesn't reproduce so simple on master. I'll try to bisect the series tomorrow.
> 
> ====
> 
> (gdb) bt
> #0  0x00007f034a3d09d5 in raise () from /lib64/libc.so.6
> #1  0x00007f034a3b9954 in abort () from /lib64/libc.so.6
> #2  0x00007f034a3b9789 in __assert_fail_base.cold () from /lib64/libc.so.6
> #3  0x00007f034a3c9026 in __assert_fail () from /lib64/libc.so.6
> #4  0x000055d3b503d670 in job_state_transition (job=0x55d3b5e67020, s1=JOB_STATUS_CONCLUDED) at ../job.c:186
> #5  0x000055d3b503e7c2 in job_conclude (job=0x55d3b5e67020) at ../job.c:652
> #6  0x000055d3b503eaa1 in job_finalize_single (job=0x55d3b5e67020) at ../job.c:722
> #7  0x000055d3b503ecd1 in job_completed_txn_abort (job=0x55d3b5e67020) at ../job.c:801
> #8  0x000055d3b503f2ea in job_cancel (job=0x55d3b5e67020, force=false) at ../job.c:973
> #9  0x000055d3b503f360 in job_cancel_err (job=0x55d3b5e67020, errp=0x7fffcc997a80) at ../job.c:992
> #10 0x000055d3b503f576 in job_finish_sync (job=0x55d3b5e67020, finish=0x55d3b503f33f <job_cancel_err>, errp=0x0) at ../job.c:1054
> #11 0x000055d3b503f3d0 in job_cancel_sync (job=0x55d3b5e67020, force=false) at ../job.c:1008
> #12 0x000055d3b4ff14a3 in replication_close (bs=0x55d3b5e6ef80) at ../block/replication.c:152
> #13 0x000055d3b50277fc in bdrv_close (bs=0x55d3b5e6ef80) at ../block.c:4677
> #14 0x000055d3b50286cf in bdrv_delete (bs=0x55d3b5e6ef80) at ../block.c:5100
> #15 0x000055d3b502ae3a in bdrv_unref (bs=0x55d3b5e6ef80) at ../block.c:6495
> #16 0x000055d3b5023a38 in bdrv_root_unref_child (child=0x55d3b5e4c690) at ../block.c:3010
> #17 0x000055d3b5047998 in blk_remove_bs (blk=0x55d3b5e73b40) at ../block/block-backend.c:845
> #18 0x000055d3b5046e38 in blk_delete (blk=0x55d3b5e73b40) at ../block/block-backend.c:461
> #19 0x000055d3b50470dc in blk_unref (blk=0x55d3b5e73b40) at ../block/block-backend.c:516
> #20 0x000055d3b4fdb20a in teardown_secondary () at ../tests/unit/test-replication.c:367
> #21 0x000055d3b4fdb632 in test_secondary_continuous_replication () at ../tests/unit/test-replication.c:504
> #22 0x00007f034b26979e in g_test_run_suite_internal () from /lib64/libglib-2.0.so.0
> #23 0x00007f034b26959b in g_test_run_suite_internal () from /lib64/libglib-2.0.so.0
> #24 0x00007f034b26959b in g_test_run_suite_internal () from /lib64/libglib-2.0.so.0
> #25 0x00007f034b269c8a in g_test_run_suite () from /lib64/libglib-2.0.so.0
> #26 0x00007f034b269ca5 in g_test_run () from /lib64/libglib-2.0.so.0
> #27 0x000055d3b4fdb9c0 in main (argc=1, argv=0x7fffcc998138) at ../tests/unit/test-replication.c:613
> (gdb) fr 4
> #4  0x000055d3b503d670 in job_state_transition (job=0x55d3b5e67020, s1=JOB_STATUS_CONCLUDED) at ../job.c:186
> 186         assert(JobSTT[s0][s1]);
> (gdb) list
> 181         JobStatus s0 = job->status;
> 182         assert(s1 >= 0 && s1 < JOB_STATUS__MAX);
> 183         trace_job_state_transition(job, job->ret,
> 184                                    JobSTT[s0][s1] ? "allowed" : "disallowed",
> 185                                    JobStatus_str(s0), JobStatus_str(s1));
> 186         assert(JobSTT[s0][s1]);
> 187         job->status = s1;
> 188
> 189         if (!job_is_internal(job) && s1 != s0) {
> 190             qapi_event_send_job_status_change(job->id, job->status);
> (gdb) p s0
> $1 = JOB_STATUS_NULL
> (gdb) p s1
> $2 = JOB_STATUS_CONCLUDED
> 
> 
> 


bisect points to "job: Add job_cancel_requested()"

And "bisecting" within this commit shows that the following helps:

diff --git a/job.c b/job.c
index be878ca5fc..bb52a1b58f 100644
--- a/job.c
+++ b/job.c
@@ -655,7 +655,7 @@ static void job_conclude(Job *job)
  
  static void job_update_rc(Job *job)
  {
-    if (!job->ret && job_is_cancelled(job)) {
+    if (!job->ret && job_cancel_requested(job)) {
          job->ret = -ECANCELED;
      }
      if (job->ret) {


- this returns job_update_rc to pre-patch behavior.

But why, I don't know:) More investigation is needed. probably replication code is doing something wrong..

-- 
Best regards,
Vladimir


^ permalink raw reply related	[flat|nested] 19+ messages in thread

* Re: [PULL 00/12] jobs: mirror: Handle errors after READY cancel
  2021-09-23 22:01     ` Vladimir Sementsov-Ogievskiy
@ 2021-10-04 16:47       ` Hanna Reitz
  2021-10-04 17:59         ` Vladimir Sementsov-Ogievskiy
  0 siblings, 1 reply; 19+ messages in thread
From: Hanna Reitz @ 2021-10-04 16:47 UTC (permalink / raw)
  To: Vladimir Sementsov-Ogievskiy, Richard Henderson, qemu-block
  Cc: kwolf, peter.maydell, jsnow, qemu-devel

On 24.09.21 00:01, Vladimir Sementsov-Ogievskiy wrote:
> 22.09.2021 22:19, Vladimir Sementsov-Ogievskiy wrote:
>> 22.09.2021 19:05, Richard Henderson wrote:
>>> On 9/21/21 3:20 AM, Vladimir Sementsov-Ogievskiy wrote:
>>>> The following changes since commit 
>>>> 326ff8dd09556fc2e257196c49f35009700794ac:
>>>>
>>>>    Merge remote-tracking branch 
>>>> 'remotes/jasowang/tags/net-pull-request' into staging (2021-09-20 
>>>> 16:17:05 +0100)
>>>>
>>>> are available in the Git repository at:
>>>>
>>>>    https://src.openvz.org/scm/~vsementsov/qemu.git 
>>>> tags/pull-jobs-2021-09-21
>>>>
>>>> for you to fetch changes up to 
>>>> c9489c04319cac75c76af8fc27c254f46e10214c:
>>>>
>>>>    iotests: Add mirror-ready-cancel-error test (2021-09-21 11:56:11 
>>>> +0300)
>>>>
>>>> ----------------------------------------------------------------
>>>> mirror: Handle errors after READY cancel
>>>>
>>>> ----------------------------------------------------------------
>>>> Hanna Reitz (12):
>>>>        job: Context changes in job_completed_txn_abort()
>>>>        mirror: Keep s->synced on error
>>>>        mirror: Drop s->synced
>>>>        job: Force-cancel jobs in a failed transaction
>>>>        job: @force parameter for job_cancel_sync()
>>>>        jobs: Give Job.force_cancel more meaning
>>>>        job: Add job_cancel_requested()
>>>>        mirror: Use job_is_cancelled()
>>>>        mirror: Check job_is_cancelled() earlier
>>>>        mirror: Stop active mirroring after force-cancel
>>>>        mirror: Do not clear .cancelled
>>>>        iotests: Add mirror-ready-cancel-error test
>>>
>>> This fails testing with errors like so:
>>>
>>> Running test test-replication
>>> test-replication: ../job.c:186: job_state_transition: Assertion 
>>> `JobSTT[s0][s1]' failed.
>>> ERROR test-replication - too few tests run (expected 13, got 8)
>>> make: *** [Makefile.mtest:816: run-test-100] Error 1
>>> Cleaning up project directory and file based variables
>>> ERROR: Job failed: exit code 1
>>>
>>> https://gitlab.com/qemu-project/qemu/-/pipelines/375324015/failures
>>>
>>
>>
>> Interesting :(
>>
>> I've reproduced, starting test-replication in several parallel loops. 
>> (it doesn't reproduce for me if just start in one loop). So, that's 
>> some racy bug..
>>
>> Hmm, and seems it doesn't reproduce so simple on master. I'll try to 
>> bisect the series tomorrow.
>>
>> ====
>>
>> (gdb) bt
>> #0  0x00007f034a3d09d5 in raise () from /lib64/libc.so.6
>> #1  0x00007f034a3b9954 in abort () from /lib64/libc.so.6
>> #2  0x00007f034a3b9789 in __assert_fail_base.cold () from 
>> /lib64/libc.so.6
>> #3  0x00007f034a3c9026 in __assert_fail () from /lib64/libc.so.6
>> #4  0x000055d3b503d670 in job_state_transition (job=0x55d3b5e67020, 
>> s1=JOB_STATUS_CONCLUDED) at ../job.c:186
>> #5  0x000055d3b503e7c2 in job_conclude (job=0x55d3b5e67020) at 
>> ../job.c:652
>> #6  0x000055d3b503eaa1 in job_finalize_single (job=0x55d3b5e67020) at 
>> ../job.c:722
>> #7  0x000055d3b503ecd1 in job_completed_txn_abort 
>> (job=0x55d3b5e67020) at ../job.c:801
>> #8  0x000055d3b503f2ea in job_cancel (job=0x55d3b5e67020, 
>> force=false) at ../job.c:973
>> #9  0x000055d3b503f360 in job_cancel_err (job=0x55d3b5e67020, 
>> errp=0x7fffcc997a80) at ../job.c:992
>> #10 0x000055d3b503f576 in job_finish_sync (job=0x55d3b5e67020, 
>> finish=0x55d3b503f33f <job_cancel_err>, errp=0x0) at ../job.c:1054
>> #11 0x000055d3b503f3d0 in job_cancel_sync (job=0x55d3b5e67020, 
>> force=false) at ../job.c:1008
>> #12 0x000055d3b4ff14a3 in replication_close (bs=0x55d3b5e6ef80) at 
>> ../block/replication.c:152
>> #13 0x000055d3b50277fc in bdrv_close (bs=0x55d3b5e6ef80) at 
>> ../block.c:4677
>> #14 0x000055d3b50286cf in bdrv_delete (bs=0x55d3b5e6ef80) at 
>> ../block.c:5100
>> #15 0x000055d3b502ae3a in bdrv_unref (bs=0x55d3b5e6ef80) at 
>> ../block.c:6495
>> #16 0x000055d3b5023a38 in bdrv_root_unref_child 
>> (child=0x55d3b5e4c690) at ../block.c:3010
>> #17 0x000055d3b5047998 in blk_remove_bs (blk=0x55d3b5e73b40) at 
>> ../block/block-backend.c:845
>> #18 0x000055d3b5046e38 in blk_delete (blk=0x55d3b5e73b40) at 
>> ../block/block-backend.c:461
>> #19 0x000055d3b50470dc in blk_unref (blk=0x55d3b5e73b40) at 
>> ../block/block-backend.c:516
>> #20 0x000055d3b4fdb20a in teardown_secondary () at 
>> ../tests/unit/test-replication.c:367
>> #21 0x000055d3b4fdb632 in test_secondary_continuous_replication () at 
>> ../tests/unit/test-replication.c:504
>> #22 0x00007f034b26979e in g_test_run_suite_internal () from 
>> /lib64/libglib-2.0.so.0
>> #23 0x00007f034b26959b in g_test_run_suite_internal () from 
>> /lib64/libglib-2.0.so.0
>> #24 0x00007f034b26959b in g_test_run_suite_internal () from 
>> /lib64/libglib-2.0.so.0
>> #25 0x00007f034b269c8a in g_test_run_suite () from 
>> /lib64/libglib-2.0.so.0
>> #26 0x00007f034b269ca5 in g_test_run () from /lib64/libglib-2.0.so.0
>> #27 0x000055d3b4fdb9c0 in main (argc=1, argv=0x7fffcc998138) at 
>> ../tests/unit/test-replication.c:613
>> (gdb) fr 4
>> #4  0x000055d3b503d670 in job_state_transition (job=0x55d3b5e67020, 
>> s1=JOB_STATUS_CONCLUDED) at ../job.c:186
>> 186         assert(JobSTT[s0][s1]);
>> (gdb) list
>> 181         JobStatus s0 = job->status;
>> 182         assert(s1 >= 0 && s1 < JOB_STATUS__MAX);
>> 183         trace_job_state_transition(job, job->ret,
>> 184                                    JobSTT[s0][s1] ? "allowed" : 
>> "disallowed",
>> 185                                    JobStatus_str(s0), 
>> JobStatus_str(s1));
>> 186         assert(JobSTT[s0][s1]);
>> 187         job->status = s1;
>> 188
>> 189         if (!job_is_internal(job) && s1 != s0) {
>> 190             qapi_event_send_job_status_change(job->id, job->status);
>> (gdb) p s0
>> $1 = JOB_STATUS_NULL
>> (gdb) p s1
>> $2 = JOB_STATUS_CONCLUDED
>>
>>
>>
>
>
> bisect points to "job: Add job_cancel_requested()"
>
> And "bisecting" within this commit shows that the following helps:
>
> diff --git a/job.c b/job.c
> index be878ca5fc..bb52a1b58f 100644
> --- a/job.c
> +++ b/job.c
> @@ -655,7 +655,7 @@ static void job_conclude(Job *job)
>
>  static void job_update_rc(Job *job)
>  {
> -    if (!job->ret && job_is_cancelled(job)) {
> +    if (!job->ret && job_cancel_requested(job)) {
>          job->ret = -ECANCELED;
>      }
>      if (job->ret) {
>
>
> - this returns job_update_rc to pre-patch behavior.
>
> But why, I don't know:) More investigation is needed. probably 
> replication code is doing something wrong..

 From what I can tell, this is what happens:

(1) The mirror job completes, we go to job_co_entry(), and schedule 
job_exit().  It doesn’t run yet, though.
(2) replication_close() cancels the job.
(3) We get to job_completed_txn_abort().
(4) The job isn’t completed yet, so we invoke job_finish_sync().
(5) Now job_exit() finally gets to run, and this is how we end up in a 
situation where .cancelled is true, but .force_cancel is false: Yes, 
mirror clears .cancelled before exiting its main loop, but if the job is 
cancelled between it having been deferred to the main loop and 
job_exit() running, it may become true again.
(6) job_exit() leads to job_completed(), which invokes job_update_rc(), 
which however leaves job->ret == 0.
(7) job_completed() also calls job_completed_txn_success(), which is 
weird, because we still have job_completed_txn_abort() running 
concurrently...
(8) job_completed_txn_success() invokes job_do_finalize(), which goes to 
job_finalize_single(), which leaves the job in status null.
(9) job_finish_sync() is done, so we land back in 
job_completed_txn_abort(): We call job_finalize_single(), which tries to 
conclude the job, and that gives us the failed assertion (attempted 
transition from null to concluded).

(When everything works, it seems like the job is completed before 
replication_close() can cancel it.  Cancelling is then a no-op and 
nothing breaks.)

So now we could say the problem is that once a job completes and is 
deferred to the main loop, non-force cancel should do nothing. 
job_cancel_async() should not set job->cancelled to true if `!force && 
job->deferred_to_main_loop`.  job_cancel() should invoke 
job_completed_txn_abort() not if `job->deferred_to_main_loop`, but if 
`job->deferred_to_main_loop && job_is_cancelled(job)`. (Doing this seems 
to fix the bug for me.)

That I think would conform to the reasoning laid out in patch 7’s commit 
message, namely that some functions are called after the job has been 
deferred to the main loop, and because mirror clears .cancelled when it 
has been soft-cancelled, it’d be impossible to observe 
`.deferred_to_main_loop == true && .cancelled == true && 
.force_cancelled == false`.


Or we continue having soft-cancelled jobs still be -ECANCELED, which 
seems like the safe choice?  But it goes against what we’ve decided for 
patch 7, namely that soft-cancelled jobs should be treated like they’d 
complete as normal.

Hanna



^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PULL 00/12] jobs: mirror: Handle errors after READY cancel
  2021-10-04 16:47       ` Hanna Reitz
@ 2021-10-04 17:59         ` Vladimir Sementsov-Ogievskiy
  2021-10-05 15:03           ` Hanna Reitz
  0 siblings, 1 reply; 19+ messages in thread
From: Vladimir Sementsov-Ogievskiy @ 2021-10-04 17:59 UTC (permalink / raw)
  To: Hanna Reitz, Richard Henderson, qemu-block
  Cc: qemu-devel, peter.maydell, kwolf, jsnow

10/4/21 19:47, Hanna Reitz wrote:
> On 24.09.21 00:01, Vladimir Sementsov-Ogievskiy wrote:
>> 22.09.2021 22:19, Vladimir Sementsov-Ogievskiy wrote:
>>> 22.09.2021 19:05, Richard Henderson wrote:
>>>> On 9/21/21 3:20 AM, Vladimir Sementsov-Ogievskiy wrote:
>>>>> The following changes since commit 326ff8dd09556fc2e257196c49f35009700794ac:
>>>>>
>>>>>    Merge remote-tracking branch 'remotes/jasowang/tags/net-pull-request' into staging (2021-09-20 16:17:05 +0100)
>>>>>
>>>>> are available in the Git repository at:
>>>>>
>>>>>    https://src.openvz.org/scm/~vsementsov/qemu.git tags/pull-jobs-2021-09-21
>>>>>
>>>>> for you to fetch changes up to c9489c04319cac75c76af8fc27c254f46e10214c:
>>>>>
>>>>>    iotests: Add mirror-ready-cancel-error test (2021-09-21 11:56:11 +0300)
>>>>>
>>>>> ----------------------------------------------------------------
>>>>> mirror: Handle errors after READY cancel
>>>>>
>>>>> ----------------------------------------------------------------
>>>>> Hanna Reitz (12):
>>>>>        job: Context changes in job_completed_txn_abort()
>>>>>        mirror: Keep s->synced on error
>>>>>        mirror: Drop s->synced
>>>>>        job: Force-cancel jobs in a failed transaction
>>>>>        job: @force parameter for job_cancel_sync()
>>>>>        jobs: Give Job.force_cancel more meaning
>>>>>        job: Add job_cancel_requested()
>>>>>        mirror: Use job_is_cancelled()
>>>>>        mirror: Check job_is_cancelled() earlier
>>>>>        mirror: Stop active mirroring after force-cancel
>>>>>        mirror: Do not clear .cancelled
>>>>>        iotests: Add mirror-ready-cancel-error test
>>>>
>>>> This fails testing with errors like so:
>>>>
>>>> Running test test-replication
>>>> test-replication: ../job.c:186: job_state_transition: Assertion `JobSTT[s0][s1]' failed.
>>>> ERROR test-replication - too few tests run (expected 13, got 8)
>>>> make: *** [Makefile.mtest:816: run-test-100] Error 1
>>>> Cleaning up project directory and file based variables
>>>> ERROR: Job failed: exit code 1
>>>>
>>>> https://gitlab.com/qemu-project/qemu/-/pipelines/375324015/failures
>>>>
>>>
>>>
>>> Interesting :(
>>>
>>> I've reproduced, starting test-replication in several parallel loops. (it doesn't reproduce for me if just start in one loop). So, that's some racy bug..
>>>
>>> Hmm, and seems it doesn't reproduce so simple on master. I'll try to bisect the series tomorrow.
>>>
>>> ====
>>>
>>> (gdb) bt
>>> #0  0x00007f034a3d09d5 in raise () from /lib64/libc.so.6
>>> #1  0x00007f034a3b9954 in abort () from /lib64/libc.so.6
>>> #2  0x00007f034a3b9789 in __assert_fail_base.cold () from /lib64/libc.so.6
>>> #3  0x00007f034a3c9026 in __assert_fail () from /lib64/libc.so.6
>>> #4  0x000055d3b503d670 in job_state_transition (job=0x55d3b5e67020, s1=JOB_STATUS_CONCLUDED) at ../job.c:186
>>> #5  0x000055d3b503e7c2 in job_conclude (job=0x55d3b5e67020) at ../job.c:652
>>> #6  0x000055d3b503eaa1 in job_finalize_single (job=0x55d3b5e67020) at ../job.c:722
>>> #7  0x000055d3b503ecd1 in job_completed_txn_abort (job=0x55d3b5e67020) at ../job.c:801
>>> #8  0x000055d3b503f2ea in job_cancel (job=0x55d3b5e67020, force=false) at ../job.c:973
>>> #9  0x000055d3b503f360 in job_cancel_err (job=0x55d3b5e67020, errp=0x7fffcc997a80) at ../job.c:992
>>> #10 0x000055d3b503f576 in job_finish_sync (job=0x55d3b5e67020, finish=0x55d3b503f33f <job_cancel_err>, errp=0x0) at ../job.c:1054
>>> #11 0x000055d3b503f3d0 in job_cancel_sync (job=0x55d3b5e67020, force=false) at ../job.c:1008
>>> #12 0x000055d3b4ff14a3 in replication_close (bs=0x55d3b5e6ef80) at ../block/replication.c:152
>>> #13 0x000055d3b50277fc in bdrv_close (bs=0x55d3b5e6ef80) at ../block.c:4677
>>> #14 0x000055d3b50286cf in bdrv_delete (bs=0x55d3b5e6ef80) at ../block.c:5100
>>> #15 0x000055d3b502ae3a in bdrv_unref (bs=0x55d3b5e6ef80) at ../block.c:6495
>>> #16 0x000055d3b5023a38 in bdrv_root_unref_child (child=0x55d3b5e4c690) at ../block.c:3010
>>> #17 0x000055d3b5047998 in blk_remove_bs (blk=0x55d3b5e73b40) at ../block/block-backend.c:845
>>> #18 0x000055d3b5046e38 in blk_delete (blk=0x55d3b5e73b40) at ../block/block-backend.c:461
>>> #19 0x000055d3b50470dc in blk_unref (blk=0x55d3b5e73b40) at ../block/block-backend.c:516
>>> #20 0x000055d3b4fdb20a in teardown_secondary () at ../tests/unit/test-replication.c:367
>>> #21 0x000055d3b4fdb632 in test_secondary_continuous_replication () at ../tests/unit/test-replication.c:504
>>> #22 0x00007f034b26979e in g_test_run_suite_internal () from /lib64/libglib-2.0.so.0
>>> #23 0x00007f034b26959b in g_test_run_suite_internal () from /lib64/libglib-2.0.so.0
>>> #24 0x00007f034b26959b in g_test_run_suite_internal () from /lib64/libglib-2.0.so.0
>>> #25 0x00007f034b269c8a in g_test_run_suite () from /lib64/libglib-2.0.so.0
>>> #26 0x00007f034b269ca5 in g_test_run () from /lib64/libglib-2.0.so.0
>>> #27 0x000055d3b4fdb9c0 in main (argc=1, argv=0x7fffcc998138) at ../tests/unit/test-replication.c:613
>>> (gdb) fr 4
>>> #4  0x000055d3b503d670 in job_state_transition (job=0x55d3b5e67020, s1=JOB_STATUS_CONCLUDED) at ../job.c:186
>>> 186         assert(JobSTT[s0][s1]);
>>> (gdb) list
>>> 181         JobStatus s0 = job->status;
>>> 182         assert(s1 >= 0 && s1 < JOB_STATUS__MAX);
>>> 183         trace_job_state_transition(job, job->ret,
>>> 184                                    JobSTT[s0][s1] ? "allowed" : "disallowed",
>>> 185                                    JobStatus_str(s0), JobStatus_str(s1));
>>> 186         assert(JobSTT[s0][s1]);
>>> 187         job->status = s1;
>>> 188
>>> 189         if (!job_is_internal(job) && s1 != s0) {
>>> 190             qapi_event_send_job_status_change(job->id, job->status);
>>> (gdb) p s0
>>> $1 = JOB_STATUS_NULL
>>> (gdb) p s1
>>> $2 = JOB_STATUS_CONCLUDED
>>>
>>>
>>>
>>
>>
>> bisect points to "job: Add job_cancel_requested()"
>>
>> And "bisecting" within this commit shows that the following helps:
>>
>> diff --git a/job.c b/job.c
>> index be878ca5fc..bb52a1b58f 100644
>> --- a/job.c
>> +++ b/job.c
>> @@ -655,7 +655,7 @@ static void job_conclude(Job *job)
>>
>>  static void job_update_rc(Job *job)
>>  {
>> -    if (!job->ret && job_is_cancelled(job)) {
>> +    if (!job->ret && job_cancel_requested(job)) {
>>          job->ret = -ECANCELED;
>>      }
>>      if (job->ret) {
>>
>>
>> - this returns job_update_rc to pre-patch behavior.
>>
>> But why, I don't know:) More investigation is needed. probably replication code is doing something wrong..
> 
>  From what I can tell, this is what happens:
> 
> (1) The mirror job completes, we go to job_co_entry(), and schedule job_exit().  It doesn’t run yet, though.
> (2) replication_close() cancels the job.
> (3) We get to job_completed_txn_abort().
> (4) The job isn’t completed yet, so we invoke job_finish_sync().
> (5) Now job_exit() finally gets to run, and this is how we end up in a situation where .cancelled is true, but .force_cancel is false: Yes, mirror clears .cancelled before exiting its main loop, but if the job is cancelled between it having been deferred to the main loop and job_exit() running, it may become true again.
> (6) job_exit() leads to job_completed(), which invokes job_update_rc(), which however leaves job->ret == 0.
> (7) job_completed() also calls job_completed_txn_success(), which is weird, because we still have job_completed_txn_abort() running concurrently...
> (8) job_completed_txn_success() invokes job_do_finalize(), which goes to job_finalize_single(), which leaves the job in status null.
> (9) job_finish_sync() is done, so we land back in job_completed_txn_abort(): We call job_finalize_single(), which tries to conclude the job, and that gives us the failed assertion (attempted transition from null to concluded).
> 
> (When everything works, it seems like the job is completed before replication_close() can cancel it.  Cancelling is then a no-op and nothing breaks.)
> 
> So now we could say the problem is that once a job completes and is deferred to the main loop, non-force cancel should do nothing. job_cancel_async() should not set job->cancelled to true if `!force && job->deferred_to_main_loop`.  job_cancel() should invoke job_completed_txn_abort() not if `job->deferred_to_main_loop`, but if `job->deferred_to_main_loop && job_is_cancelled(job)`. (Doing this seems to fix the bug for me.)
> 
> That I think would conform to the reasoning laid out in patch 7’s commit message, namely that some functions are called after the job has been deferred to the main loop, and because mirror clears .cancelled when it has been soft-cancelled, it’d be impossible to observe `.deferred_to_main_loop == true && .cancelled == true && .force_cancelled == false`.
> 
> 
> Or we continue having soft-cancelled jobs still be -ECANCELED, which seems like the safe choice?  But it goes against what we’ve decided for patch 7, namely that soft-cancelled jobs should be treated like they’d complete as normal.
> 

I think, I can live with either way:)  I still think that best way is implementing "no graph change" mode for mirror instead of soft-cancelling and deprecate soft-cancel (together with block-job-cancel), but that doesn't work in short-term.

-- 
Best regards,
Vladimir


^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PULL 00/12] jobs: mirror: Handle errors after READY cancel
  2021-10-04 17:59         ` Vladimir Sementsov-Ogievskiy
@ 2021-10-05 15:03           ` Hanna Reitz
  0 siblings, 0 replies; 19+ messages in thread
From: Hanna Reitz @ 2021-10-05 15:03 UTC (permalink / raw)
  To: Vladimir Sementsov-Ogievskiy, Richard Henderson, qemu-block
  Cc: kwolf, peter.maydell, jsnow, qemu-devel

On 04.10.21 19:59, Vladimir Sementsov-Ogievskiy wrote:
> 10/4/21 19:47, Hanna Reitz wrote:
>> On 24.09.21 00:01, Vladimir Sementsov-Ogievskiy wrote:
>>> 22.09.2021 22:19, Vladimir Sementsov-Ogievskiy wrote:
>>>> 22.09.2021 19:05, Richard Henderson wrote:
>>>>> On 9/21/21 3:20 AM, Vladimir Sementsov-Ogievskiy wrote:
>>>>>> The following changes since commit 
>>>>>> 326ff8dd09556fc2e257196c49f35009700794ac:
>>>>>>
>>>>>>    Merge remote-tracking branch 
>>>>>> 'remotes/jasowang/tags/net-pull-request' into staging (2021-09-20 
>>>>>> 16:17:05 +0100)
>>>>>>
>>>>>> are available in the Git repository at:
>>>>>>
>>>>>>    https://src.openvz.org/scm/~vsementsov/qemu.git 
>>>>>> tags/pull-jobs-2021-09-21
>>>>>>
>>>>>> for you to fetch changes up to 
>>>>>> c9489c04319cac75c76af8fc27c254f46e10214c:
>>>>>>
>>>>>>    iotests: Add mirror-ready-cancel-error test (2021-09-21 
>>>>>> 11:56:11 +0300)
>>>>>>
>>>>>> ----------------------------------------------------------------
>>>>>> mirror: Handle errors after READY cancel
>>>>>>
>>>>>> ----------------------------------------------------------------
>>>>>> Hanna Reitz (12):
>>>>>>        job: Context changes in job_completed_txn_abort()
>>>>>>        mirror: Keep s->synced on error
>>>>>>        mirror: Drop s->synced
>>>>>>        job: Force-cancel jobs in a failed transaction
>>>>>>        job: @force parameter for job_cancel_sync()
>>>>>>        jobs: Give Job.force_cancel more meaning
>>>>>>        job: Add job_cancel_requested()
>>>>>>        mirror: Use job_is_cancelled()
>>>>>>        mirror: Check job_is_cancelled() earlier
>>>>>>        mirror: Stop active mirroring after force-cancel
>>>>>>        mirror: Do not clear .cancelled
>>>>>>        iotests: Add mirror-ready-cancel-error test
>>>>>
>>>>> This fails testing with errors like so:
>>>>>
>>>>> Running test test-replication
>>>>> test-replication: ../job.c:186: job_state_transition: Assertion 
>>>>> `JobSTT[s0][s1]' failed.
>>>>> ERROR test-replication - too few tests run (expected 13, got 8)
>>>>> make: *** [Makefile.mtest:816: run-test-100] Error 1
>>>>> Cleaning up project directory and file based variables
>>>>> ERROR: Job failed: exit code 1
>>>>>
>>>>> https://gitlab.com/qemu-project/qemu/-/pipelines/375324015/failures
>>>>>
>>>>
>>>>
>>>> Interesting :(
>>>>
>>>> I've reproduced, starting test-replication in several parallel 
>>>> loops. (it doesn't reproduce for me if just start in one loop). So, 
>>>> that's some racy bug..
>>>>
>>>> Hmm, and seems it doesn't reproduce so simple on master. I'll try 
>>>> to bisect the series tomorrow.
>>>>
>>>> ====
>>>>
>>>> (gdb) bt
>>>> #0  0x00007f034a3d09d5 in raise () from /lib64/libc.so.6
>>>> #1  0x00007f034a3b9954 in abort () from /lib64/libc.so.6
>>>> #2  0x00007f034a3b9789 in __assert_fail_base.cold () from 
>>>> /lib64/libc.so.6
>>>> #3  0x00007f034a3c9026 in __assert_fail () from /lib64/libc.so.6
>>>> #4  0x000055d3b503d670 in job_state_transition (job=0x55d3b5e67020, 
>>>> s1=JOB_STATUS_CONCLUDED) at ../job.c:186
>>>> #5  0x000055d3b503e7c2 in job_conclude (job=0x55d3b5e67020) at 
>>>> ../job.c:652
>>>> #6  0x000055d3b503eaa1 in job_finalize_single (job=0x55d3b5e67020) 
>>>> at ../job.c:722
>>>> #7  0x000055d3b503ecd1 in job_completed_txn_abort 
>>>> (job=0x55d3b5e67020) at ../job.c:801
>>>> #8  0x000055d3b503f2ea in job_cancel (job=0x55d3b5e67020, 
>>>> force=false) at ../job.c:973
>>>> #9  0x000055d3b503f360 in job_cancel_err (job=0x55d3b5e67020, 
>>>> errp=0x7fffcc997a80) at ../job.c:992
>>>> #10 0x000055d3b503f576 in job_finish_sync (job=0x55d3b5e67020, 
>>>> finish=0x55d3b503f33f <job_cancel_err>, errp=0x0) at ../job.c:1054
>>>> #11 0x000055d3b503f3d0 in job_cancel_sync (job=0x55d3b5e67020, 
>>>> force=false) at ../job.c:1008
>>>> #12 0x000055d3b4ff14a3 in replication_close (bs=0x55d3b5e6ef80) at 
>>>> ../block/replication.c:152
>>>> #13 0x000055d3b50277fc in bdrv_close (bs=0x55d3b5e6ef80) at 
>>>> ../block.c:4677
>>>> #14 0x000055d3b50286cf in bdrv_delete (bs=0x55d3b5e6ef80) at 
>>>> ../block.c:5100
>>>> #15 0x000055d3b502ae3a in bdrv_unref (bs=0x55d3b5e6ef80) at 
>>>> ../block.c:6495
>>>> #16 0x000055d3b5023a38 in bdrv_root_unref_child 
>>>> (child=0x55d3b5e4c690) at ../block.c:3010
>>>> #17 0x000055d3b5047998 in blk_remove_bs (blk=0x55d3b5e73b40) at 
>>>> ../block/block-backend.c:845
>>>> #18 0x000055d3b5046e38 in blk_delete (blk=0x55d3b5e73b40) at 
>>>> ../block/block-backend.c:461
>>>> #19 0x000055d3b50470dc in blk_unref (blk=0x55d3b5e73b40) at 
>>>> ../block/block-backend.c:516
>>>> #20 0x000055d3b4fdb20a in teardown_secondary () at 
>>>> ../tests/unit/test-replication.c:367
>>>> #21 0x000055d3b4fdb632 in test_secondary_continuous_replication () 
>>>> at ../tests/unit/test-replication.c:504
>>>> #22 0x00007f034b26979e in g_test_run_suite_internal () from 
>>>> /lib64/libglib-2.0.so.0
>>>> #23 0x00007f034b26959b in g_test_run_suite_internal () from 
>>>> /lib64/libglib-2.0.so.0
>>>> #24 0x00007f034b26959b in g_test_run_suite_internal () from 
>>>> /lib64/libglib-2.0.so.0
>>>> #25 0x00007f034b269c8a in g_test_run_suite () from 
>>>> /lib64/libglib-2.0.so.0
>>>> #26 0x00007f034b269ca5 in g_test_run () from /lib64/libglib-2.0.so.0
>>>> #27 0x000055d3b4fdb9c0 in main (argc=1, argv=0x7fffcc998138) at 
>>>> ../tests/unit/test-replication.c:613
>>>> (gdb) fr 4
>>>> #4  0x000055d3b503d670 in job_state_transition (job=0x55d3b5e67020, 
>>>> s1=JOB_STATUS_CONCLUDED) at ../job.c:186
>>>> 186         assert(JobSTT[s0][s1]);
>>>> (gdb) list
>>>> 181         JobStatus s0 = job->status;
>>>> 182         assert(s1 >= 0 && s1 < JOB_STATUS__MAX);
>>>> 183         trace_job_state_transition(job, job->ret,
>>>> 184                                    JobSTT[s0][s1] ? "allowed" : 
>>>> "disallowed",
>>>> 185                                    JobStatus_str(s0), 
>>>> JobStatus_str(s1));
>>>> 186         assert(JobSTT[s0][s1]);
>>>> 187         job->status = s1;
>>>> 188
>>>> 189         if (!job_is_internal(job) && s1 != s0) {
>>>> 190 qapi_event_send_job_status_change(job->id, job->status);
>>>> (gdb) p s0
>>>> $1 = JOB_STATUS_NULL
>>>> (gdb) p s1
>>>> $2 = JOB_STATUS_CONCLUDED
>>>>
>>>>
>>>>
>>>
>>>
>>> bisect points to "job: Add job_cancel_requested()"
>>>
>>> And "bisecting" within this commit shows that the following helps:
>>>
>>> diff --git a/job.c b/job.c
>>> index be878ca5fc..bb52a1b58f 100644
>>> --- a/job.c
>>> +++ b/job.c
>>> @@ -655,7 +655,7 @@ static void job_conclude(Job *job)
>>>
>>>  static void job_update_rc(Job *job)
>>>  {
>>> -    if (!job->ret && job_is_cancelled(job)) {
>>> +    if (!job->ret && job_cancel_requested(job)) {
>>>          job->ret = -ECANCELED;
>>>      }
>>>      if (job->ret) {
>>>
>>>
>>> - this returns job_update_rc to pre-patch behavior.
>>>
>>> But why, I don't know:) More investigation is needed. probably 
>>> replication code is doing something wrong..
>>
>>  From what I can tell, this is what happens:
>>
>> (1) The mirror job completes, we go to job_co_entry(), and schedule 
>> job_exit().  It doesn’t run yet, though.
>> (2) replication_close() cancels the job.
>> (3) We get to job_completed_txn_abort().
>> (4) The job isn’t completed yet, so we invoke job_finish_sync().
>> (5) Now job_exit() finally gets to run, and this is how we end up in 
>> a situation where .cancelled is true, but .force_cancel is false: 
>> Yes, mirror clears .cancelled before exiting its main loop, but if 
>> the job is cancelled between it having been deferred to the main loop 
>> and job_exit() running, it may become true again.
>> (6) job_exit() leads to job_completed(), which invokes 
>> job_update_rc(), which however leaves job->ret == 0.
>> (7) job_completed() also calls job_completed_txn_success(), which is 
>> weird, because we still have job_completed_txn_abort() running 
>> concurrently...
>> (8) job_completed_txn_success() invokes job_do_finalize(), which goes 
>> to job_finalize_single(), which leaves the job in status null.
>> (9) job_finish_sync() is done, so we land back in 
>> job_completed_txn_abort(): We call job_finalize_single(), which tries 
>> to conclude the job, and that gives us the failed assertion 
>> (attempted transition from null to concluded).
>>
>> (When everything works, it seems like the job is completed before 
>> replication_close() can cancel it.  Cancelling is then a no-op and 
>> nothing breaks.)
>>
>> So now we could say the problem is that once a job completes and is 
>> deferred to the main loop, non-force cancel should do nothing. 
>> job_cancel_async() should not set job->cancelled to true if `!force 
>> && job->deferred_to_main_loop`. job_cancel() should invoke 
>> job_completed_txn_abort() not if `job->deferred_to_main_loop`, but if 
>> `job->deferred_to_main_loop && job_is_cancelled(job)`. (Doing this 
>> seems to fix the bug for me.)
>>
>> That I think would conform to the reasoning laid out in patch 7’s 
>> commit message, namely that some functions are called after the job 
>> has been deferred to the main loop, and because mirror clears 
>> .cancelled when it has been soft-cancelled, it’d be impossible to 
>> observe `.deferred_to_main_loop == true && .cancelled == true && 
>> .force_cancelled == false`.
>>
>>
>> Or we continue having soft-cancelled jobs still be -ECANCELED, which 
>> seems like the safe choice?  But it goes against what we’ve decided 
>> for patch 7, namely that soft-cancelled jobs should be treated like 
>> they’d complete as normal.
>>
>
> I think, I can live with either way:)  I still think that best way is 
> implementing "no graph change" mode for mirror instead of 
> soft-cancelling and deprecate soft-cancel (together with 
> block-job-cancel), but that doesn't work in short-term.

Yes, sure.  When it’s just another completion mode, we won’t have this 
problem at all anyway, because then we’d skip job_cancel() altogether 
(and so nothing in the code would get the idea to invoke 
job_completed_txn_abort()).

(Btw, I’ll send a new version of the mirror series tomorrow.)

Hanna



^ permalink raw reply	[flat|nested] 19+ messages in thread

end of thread, other threads:[~2021-10-05 15:14 UTC | newest]

Thread overview: 19+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-09-21 10:20 [PULL 00/12] jobs: mirror: Handle errors after READY cancel Vladimir Sementsov-Ogievskiy
2021-09-21 10:20 ` [PULL 01/12] job: Context changes in job_completed_txn_abort() Vladimir Sementsov-Ogievskiy
2021-09-21 10:20 ` [PULL 02/12] mirror: Keep s->synced on error Vladimir Sementsov-Ogievskiy
2021-09-21 10:20 ` [PULL 03/12] mirror: Drop s->synced Vladimir Sementsov-Ogievskiy
2021-09-21 10:20 ` [PULL 04/12] job: Force-cancel jobs in a failed transaction Vladimir Sementsov-Ogievskiy
2021-09-21 10:20 ` [PULL 05/12] job: @force parameter for job_cancel_sync() Vladimir Sementsov-Ogievskiy
2021-09-21 10:20 ` [PULL 06/12] jobs: Give Job.force_cancel more meaning Vladimir Sementsov-Ogievskiy
2021-09-21 10:20 ` [PULL 07/12] job: Add job_cancel_requested() Vladimir Sementsov-Ogievskiy
2021-09-21 10:20 ` [PULL 08/12] mirror: Use job_is_cancelled() Vladimir Sementsov-Ogievskiy
2021-09-21 10:20 ` [PULL 09/12] mirror: Check job_is_cancelled() earlier Vladimir Sementsov-Ogievskiy
2021-09-21 10:20 ` [PULL 10/12] mirror: Stop active mirroring after force-cancel Vladimir Sementsov-Ogievskiy
2021-09-21 10:20 ` [PULL 11/12] mirror: Do not clear .cancelled Vladimir Sementsov-Ogievskiy
2021-09-21 10:20 ` [PULL 12/12] iotests: Add mirror-ready-cancel-error test Vladimir Sementsov-Ogievskiy
2021-09-22 16:05 ` [PULL 00/12] jobs: mirror: Handle errors after READY cancel Richard Henderson
2021-09-22 19:19   ` Vladimir Sementsov-Ogievskiy
2021-09-23 22:01     ` Vladimir Sementsov-Ogievskiy
2021-10-04 16:47       ` Hanna Reitz
2021-10-04 17:59         ` Vladimir Sementsov-Ogievskiy
2021-10-05 15:03           ` Hanna Reitz

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.