thr3ads.net - Libguestfs - [Libguestfs] [PATCH] v2v: rhv-upload-plugin: Fix waiting for finalize [Jul 2021]

If this information is useful, please help other people find it:
Share via:

Nir Soffer

2021-Jul-11 23:58 UTC

[Libguestfs] [PATCH] v2v: rhv-upload-plugin: Fix waiting for finalize

Waiting for image transfer finalize is complex. In the past we tried to
simplify the process by waiting on the disk status, but turns out that
due to the way oVirt lock the disk, this is not reliable.

These is finalize success flow:

1. User asks to finalize the transfer
2. oVirt sets transfer phase to FINALIZING_SUCCESS
3. oVirt finalizes the transfer
4. oVirt sets disk status to OK
5. oVirt unlocks the disk and changes transfer phase to FINISHED_SUCCESS
6. oVirt removes the transfer

In oVirt logs we can see that disk status changes to OK about 3 seconds
before the disk is actually unlocked. This is a very old problem that is
unlikely to be fixed.

The only way to wait for transfer completion is to poll the transfer
phase, but oVirt makes this hard by removing the transfer shortly after
it completes, so we may not be able to get the FINISHED_SUCCESS phase.
If the transfer was removed before we got one of the final phases, we
need to check the disk status to understand the result of transfer.

oVirt 4.4.7 made polling transfer phase easier by keeping the transfer
after completion, but we need to support older versions so we must have
generic code that work with any version.

To make debugging easier, we log the transfer phase during polling. Here
is a typical transfer log when finalizing transfer:

    finalizing transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa
    transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa is finalizing_success
    transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa is finalizing_success
    transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa is finalizing_success
    transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa is finalizing_success
    transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa is finished_success
    transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa finalized in 5.153 seconds

Signed-off-by: Nir Soffer <nsoffer at redhat.com>
---
 v2v/rhv-upload-plugin.py | 102 +++++++++++++++++++++++++++------------
 1 file changed, 71 insertions(+), 31 deletions(-)

diff --git a/v2v/rhv-upload-plugin.py b/v2v/rhv-upload-plugin.py
index 07e879c9..11050358 100644
--- a/v2v/rhv-upload-plugin.py
+++ b/v2v/rhv-upload-plugin.py
@@ -607,17 +607,29 @@ def finalize_transfer(connection, transfer, disk_id):
     """
     Finalize a transfer, making the transfer disk available.
 
-    If finalizing succeeds, transfer's phase will change to
FINISHED_SUCCESS
-    and the transer's disk status will change to OK.  On errors, the
transfer's
-    phase will change to FINISHED_FAILURE and the disk status will change to
-    ILLEGAL and it will be removed. In both cases the transfer entity will be
-    removed shortly after.
-
-    If oVirt fails to finalize the transfer, transfer's phase will change
to
-    PAUSED_SYSTEM. In this case the disk's status will change to ILLEGAL
and it
-    will not be removed.
-
-    For simplicity, we track only disk's status changes.
+    If finalizing succeeds, the transfer's disk status will change to OK
+    and transfer's phase will change to FINISHED_SUCCESS. Unfortunately,
+    the disk status is modified before the transfer finishes, and oVirt
+    may still hold a lock on the disk at this point.
+
+    The only way to make sure that the disk is unlocked, is to wait
+    until the transfer phase switches FINISHED_SUCCESS. Unfortunately
+    oVirt makes this hard to use because the transfer is removed shortly
+    after switching the phase to the final phase. However if the
+    transfer was removed, we can be sure that the disk is not unlocked,
+    since oVirt releases the locks before removing the transfer.
+
+    On errors, the transfer's phase will change to FINISHED_FAILURE and
+    the disk status will change to ILLEGAL and it will be removed. Again
+    the transfer will be removed shortly after that.
+
+    If oVirt fails to finalize the transfer, transfer's phase will
+    change to PAUSED_SYSTEM. In this case the disk's status will change
+    to ILLEGAL and it will not be removed.
+
+    oVirt 4.4.7 made waiting for transfer easier by keeping transfers
+    after they complete, but we must support older versions so we have
+    generic code that work with any version.
 
     For more info see:
     -
http://ovirt.github.io/ovirt-engine-api-model/4.4/#services/image_transfer
@@ -632,34 +644,62 @@ def finalize_transfer(connection, transfer, disk_id):
 
     transfer_service.finalize()
 
-    disk_service = (connection.system_service()
-                    .disks_service()
-                    .disk_service(disk_id))
-
     while True:
         time.sleep(1)
         try:
-            disk = disk_service.get()
+            transfer = transfer_service.get()
         except sdk.NotFoundError:
-            # Disk verification failed and the system removed the disk.
-            raise RuntimeError(
-                "transfer %s failed: disk %s was removed"
-                % (transfer.id, disk_id))
+            # Transfer was removed (ovirt < 4.4.7). We need to check the
+            # disk status to understand if the transfer was successful.
+            # Due to the way oVirt does locking, we know that the disk
+            # is unlocked at this point so we can check only once.
 
-        if disk.status == types.DiskStatus.ILLEGAL:
-            # Disk verification failed or transfer was paused by the system.
-            raise RuntimeError(
-                "transfer %s failed: disk is ILLEGAL" % transfer.id)
+            debug("transfer %s was removed, checking disk %s status"
+                  % (transfer.id, disk_id))
 
-        if disk.status == types.DiskStatus.OK:
-            debug("transfer %s finalized in %.3f seconds"
-                  % (transfer.id, time.time() - start))
-            break
+            disk_service = (connection.system_service()
+                            .disks_service()
+                            .disk_service(disk_id))
+
+            try:
+                disk = disk_service.get()
+            except sdk.NotFoundError:
+                raise RuntimeError(
+                    "transfer %s failed: disk %s was removed"
+                    % (transfer.id, disk_id))
+
+            debug("disk %s is %s" % (disk_id, disk.status))
+
+            if disk.status == types.DiskStatus.OK:
+                break
 
-        if time.time() > start + timeout:
             raise RuntimeError(
-                "timed out waiting for transfer %s to finalize"
-                % transfer.id)
+                "transfer %s failed: disk is %s" % (transfer.id,
disk.status))
+        else:
+            # Transfer exists, check if it reached one of the final
+            # phases, or we timed out.
+
+            debug("transfer %s is %s" % (transfer.id,
transfer.phase))
+
+            if transfer.phase == types.ImageTransferPhase.FINISHED_SUCCESS:
+                break
+
+            if transfer.phase == types.ImageTransferPhase.FINISHED_FAILURE:
+                raise RuntimeError(
+                    "transfer %s has failed" % (transfer.id,))
+
+            if transfer.phase == types.ImageTransferPhase.PAUSED_SYSTEM:
+                raise RuntimeError(
+                    "transfer %s was paused by system" %
(transfer.id,))
+
+            if time.time() > start + timeout:
+                raise RuntimeError(
+                    "timed out waiting for transfer %s to finalize, "
+                    "transfer is %s"
+                    % (transfer.id, transfer.phase))
+
+    debug("transfer %s finalized in %.3f seconds"
+          % (transfer.id, time.time() - start))
 
 
 def transfer_supports_format():
-- 
2.26.3

Nir Soffer

2021-Jul-12 00:23 UTC

head link

[Libguestfs] [PATCH] v2v: rhv-upload-plugin: Fix waiting for finalize

I tested this with:

1. ovirt 4.4.7.6 - keep image transfer for 15 minutes after completion
2. ovirt 4.4.7.5 - delete image transfer shortly after completion

With both versions, we always get the transfer status, since ovirt
seems to delete the transfer after 20 seconds. This is not documented
anywhere so I don't think we can depend on this implementation detail.

To make sure we the case when transfer is removed works, I added this
patch when testing 4.4.7.5:

$ git diff
diff --git a/v2v/rhv-upload-plugin.py b/v2v/rhv-upload-plugin.py
index 11050358..c0151557 100644
--- a/v2v/rhv-upload-plugin.py
+++ b/v2v/rhv-upload-plugin.py
@@ -644,6 +644,9 @@ def finalize_transfer(connection, transfer, disk_id):

     transfer_service.finalize()

+    # Test case when older ovirt delete the transfer before we check it.
+    time.sleep(20)
+
     while True:
         time.sleep(1)
         try:

I tested various runs with concurrent imports from local file using:

$ for i in $(seq 4); do (~/v2v.sh v2v-$i -v >~/v2v-logs/$i.log 2>&1
&); done

With concurrency from 2 to 10.

The test script is:

$ cat ~/v2v.sh
#!/bin/sh
vm_name=${1:-v2v}
shift

./run virt-v2v \
    -i disk /var/tmp/fedora-32.qcow2 \
    -o rhv-upload \
    -oc https://engine-dev/ovirt-engine/api \
    -op /var/tmp/password \
    -on $vm_name \
    -os iscsi-01 \
    -of qcow2 \
    -oo rhv-cafile=/etc/pki/vdsm/certs/cacert.pem \
    -oo rhv-cluster=el8 \
    -oo rhv-direct=true \
    "$@"

I tested both raw format to nfs storage, and qcow2 format
to iscsi storage.

1. ovirt 4.4.7.6 (keep image transfer for 15 minutes)

$ (cd ~/v2v-logs && egrep '^transfer|finalizing transfer' *.log)
1.log:transfer.id = 'c8b9b7d7-e2e4-489c-8bb6-33bd661ca582'
1.log:finalizing transfer c8b9b7d7-e2e4-489c-8bb6-33bd661ca582
1.log:transfer c8b9b7d7-e2e4-489c-8bb6-33bd661ca582 is finished_success
1.log:transfer c8b9b7d7-e2e4-489c-8bb6-33bd661ca582 finalized in 1.023 seconds
2.log:transfer.id = 'f9035d36-89ab-4045-aad5-5ad17fb58bae'
2.log:finalizing transfer f9035d36-89ab-4045-aad5-5ad17fb58bae
2.log:transfer f9035d36-89ab-4045-aad5-5ad17fb58bae is finalizing_success
2.log:transfer f9035d36-89ab-4045-aad5-5ad17fb58bae is finished_success
2.log:transfer f9035d36-89ab-4045-aad5-5ad17fb58bae finalized in 2.031 seconds
3.log:transfer.id = 'f0e4789d-e7e4-4d88-b110-e12bb1a4dae5'
3.log:finalizing transfer f0e4789d-e7e4-4d88-b110-e12bb1a4dae5
3.log:transfer f0e4789d-e7e4-4d88-b110-e12bb1a4dae5 is finalizing_success
3.log:transfer f0e4789d-e7e4-4d88-b110-e12bb1a4dae5 is finalizing_success
3.log:transfer f0e4789d-e7e4-4d88-b110-e12bb1a4dae5 is finalizing_success
3.log:transfer f0e4789d-e7e4-4d88-b110-e12bb1a4dae5 is finalizing_success
3.log:transfer f0e4789d-e7e4-4d88-b110-e12bb1a4dae5 is finalizing_success
3.log:transfer f0e4789d-e7e4-4d88-b110-e12bb1a4dae5 is finalizing_success
3.log:transfer f0e4789d-e7e4-4d88-b110-e12bb1a4dae5 is finalizing_success
3.log:transfer f0e4789d-e7e4-4d88-b110-e12bb1a4dae5 is finalizing_success
3.log:transfer f0e4789d-e7e4-4d88-b110-e12bb1a4dae5 is finished_success
3.log:transfer f0e4789d-e7e4-4d88-b110-e12bb1a4dae5 finalized in 9.438 seconds
4.log:transfer.id = 'ba79246c-8ada-4fbc-8584-b3a08f28503d'
4.log:finalizing transfer ba79246c-8ada-4fbc-8584-b3a08f28503d
4.log:transfer ba79246c-8ada-4fbc-8584-b3a08f28503d is finished_success
4.log:transfer ba79246c-8ada-4fbc-8584-b3a08f28503d finalized in 1.018 seconds


$ (cd ~/v2v-logs && egrep '^transfer|finalizing transfer' *.log)
1.log:transfer.id = '59e545f3-db1f-4a6b-90b1-80ac66572faa'
1.log:finalizing transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa
1.log:transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa is finalizing_success
1.log:transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa is finalizing_success
1.log:transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa is finalizing_success
1.log:transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa is finalizing_success
1.log:transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa is finished_success
1.log:transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa finalized in 5.153 seconds
2.log:transfer.id = 'eec44519-f0ae-4bdd-ab97-a07736e7a11e'
2.log:finalizing transfer eec44519-f0ae-4bdd-ab97-a07736e7a11e
2.log:transfer eec44519-f0ae-4bdd-ab97-a07736e7a11e is finalizing_success
2.log:transfer eec44519-f0ae-4bdd-ab97-a07736e7a11e is finalizing_success
2.log:transfer eec44519-f0ae-4bdd-ab97-a07736e7a11e is finalizing_success
2.log:transfer eec44519-f0ae-4bdd-ab97-a07736e7a11e is finalizing_success
2.log:transfer eec44519-f0ae-4bdd-ab97-a07736e7a11e is finished_success
2.log:transfer eec44519-f0ae-4bdd-ab97-a07736e7a11e finalized in 5.173 seconds
3.log:transfer.id = 'cd883134-0ad9-49cf-8abf-3bef44689e6f'
3.log:finalizing transfer cd883134-0ad9-49cf-8abf-3bef44689e6f
3.log:transfer cd883134-0ad9-49cf-8abf-3bef44689e6f is finalizing_success
3.log:transfer cd883134-0ad9-49cf-8abf-3bef44689e6f is finalizing_success
3.log:transfer cd883134-0ad9-49cf-8abf-3bef44689e6f is finalizing_success
3.log:transfer cd883134-0ad9-49cf-8abf-3bef44689e6f is finalizing_success
3.log:transfer cd883134-0ad9-49cf-8abf-3bef44689e6f is finalizing_success
3.log:transfer cd883134-0ad9-49cf-8abf-3bef44689e6f is finished_success
3.log:transfer cd883134-0ad9-49cf-8abf-3bef44689e6f finalized in 6.070 seconds
4.log:transfer.id = 'd49de70c-97d3-46db-9bde-c505a2891b74'
4.log:finalizing transfer d49de70c-97d3-46db-9bde-c505a2891b74
4.log:transfer d49de70c-97d3-46db-9bde-c505a2891b74 is finalizing_success
4.log:transfer d49de70c-97d3-46db-9bde-c505a2891b74 is finalizing_success
4.log:transfer d49de70c-97d3-46db-9bde-c505a2891b74 is finalizing_success
4.log:transfer d49de70c-97d3-46db-9bde-c505a2891b74 is finalizing_success
4.log:transfer d49de70c-97d3-46db-9bde-c505a2891b74 is finalizing_success
4.log:transfer d49de70c-97d3-46db-9bde-c505a2891b74 is finished_success
4.log:transfer d49de70c-97d3-46db-9bde-c505a2891b74 finalized in 6.091 seconds


$ (cd ~/v2v-logs && egrep '^transfer|finalizing transfer' *.log)
1.log:transfer.id = '07efe4f8-a7c6-4c70-a260-a164b02b1543'
1.log:finalizing transfer 07efe4f8-a7c6-4c70-a260-a164b02b1543
1.log:transfer 07efe4f8-a7c6-4c70-a260-a164b02b1543 is finalizing_success
1.log:transfer 07efe4f8-a7c6-4c70-a260-a164b02b1543 is finalizing_success
1.log:transfer 07efe4f8-a7c6-4c70-a260-a164b02b1543 is finished_success
1.log:transfer 07efe4f8-a7c6-4c70-a260-a164b02b1543 finalized in 3.379 seconds
2.log:transfer.id = '5d82aec3-92b0-428f-a6b2-9b9cc5ad781e'
2.log:finalizing transfer 5d82aec3-92b0-428f-a6b2-9b9cc5ad781e
2.log:transfer 5d82aec3-92b0-428f-a6b2-9b9cc5ad781e is finalizing_success
2.log:transfer 5d82aec3-92b0-428f-a6b2-9b9cc5ad781e is finished_success
2.log:transfer 5d82aec3-92b0-428f-a6b2-9b9cc5ad781e finalized in 2.361 seconds
3.log:transfer.id = '844f0e69-9fe2-430d-af02-6b8ca80498d6'
3.log:finalizing transfer 844f0e69-9fe2-430d-af02-6b8ca80498d6
3.log:transfer 844f0e69-9fe2-430d-af02-6b8ca80498d6 is finalizing_success
3.log:transfer 844f0e69-9fe2-430d-af02-6b8ca80498d6 is finalizing_success
3.log:transfer 844f0e69-9fe2-430d-af02-6b8ca80498d6 is finished_success
3.log:transfer 844f0e69-9fe2-430d-af02-6b8ca80498d6 finalized in 3.314 seconds
4.log:transfer.id = 'a7e2ddc5-35af-4b6e-94a1-a33f4571d281'
4.log:finalizing transfer a7e2ddc5-35af-4b6e-94a1-a33f4571d281
4.log:transfer a7e2ddc5-35af-4b6e-94a1-a33f4571d281 is finalizing_success
4.log:transfer a7e2ddc5-35af-4b6e-94a1-a33f4571d281 is finalizing_success
4.log:transfer a7e2ddc5-35af-4b6e-94a1-a33f4571d281 is finished_success
4.log:transfer a7e2ddc5-35af-4b6e-94a1-a33f4571d281 finalized in 3.383 seconds


$ (cd ~/v2v-logs && egrep '^transfer|finalizing transfer' *.log)
1.log:transfer.id = 'af159a55-a5a5-44bc-8246-3a66e5465a36'
1.log:finalizing transfer af159a55-a5a5-44bc-8246-3a66e5465a36
1.log:transfer af159a55-a5a5-44bc-8246-3a66e5465a36 is finalizing_success
1.log:transfer af159a55-a5a5-44bc-8246-3a66e5465a36 is finalizing_success
1.log:transfer af159a55-a5a5-44bc-8246-3a66e5465a36 is finalizing_success
1.log:transfer af159a55-a5a5-44bc-8246-3a66e5465a36 is finalizing_success
1.log:transfer af159a55-a5a5-44bc-8246-3a66e5465a36 is finalizing_success
1.log:transfer af159a55-a5a5-44bc-8246-3a66e5465a36 is finished_success
1.log:transfer af159a55-a5a5-44bc-8246-3a66e5465a36 finalized in 6.044 seconds
2.log:transfer.id = '29075c9d-5f2d-4e3d-8e4a-c2dc875ad1dc'
2.log:finalizing transfer 29075c9d-5f2d-4e3d-8e4a-c2dc875ad1dc
2.log:transfer 29075c9d-5f2d-4e3d-8e4a-c2dc875ad1dc is finalizing_success
2.log:transfer 29075c9d-5f2d-4e3d-8e4a-c2dc875ad1dc is finalizing_success
2.log:transfer 29075c9d-5f2d-4e3d-8e4a-c2dc875ad1dc is finalizing_success
2.log:transfer 29075c9d-5f2d-4e3d-8e4a-c2dc875ad1dc is finalizing_success
2.log:transfer 29075c9d-5f2d-4e3d-8e4a-c2dc875ad1dc is finalizing_success
2.log:transfer 29075c9d-5f2d-4e3d-8e4a-c2dc875ad1dc is finished_success
2.log:transfer 29075c9d-5f2d-4e3d-8e4a-c2dc875ad1dc finalized in 6.059 seconds
3.log:transfer.id = '353d89eb-65fc-4029-8d67-ca6f7628aba7'
3.log:finalizing transfer 353d89eb-65fc-4029-8d67-ca6f7628aba7
3.log:transfer 353d89eb-65fc-4029-8d67-ca6f7628aba7 is finalizing_success
3.log:transfer 353d89eb-65fc-4029-8d67-ca6f7628aba7 is finalizing_success
3.log:transfer 353d89eb-65fc-4029-8d67-ca6f7628aba7 is finalizing_success
3.log:transfer 353d89eb-65fc-4029-8d67-ca6f7628aba7 is finalizing_success
3.log:transfer 353d89eb-65fc-4029-8d67-ca6f7628aba7 is finalizing_success
3.log:transfer 353d89eb-65fc-4029-8d67-ca6f7628aba7 is finished_success
3.log:transfer 353d89eb-65fc-4029-8d67-ca6f7628aba7 finalized in 6.052 seconds
4.log:transfer.id = '26486597-0ed5-4b93-88fa-5f065cf0029f'
4.log:finalizing transfer 26486597-0ed5-4b93-88fa-5f065cf0029f
4.log:transfer 26486597-0ed5-4b93-88fa-5f065cf0029f is finalizing_success
4.log:transfer 26486597-0ed5-4b93-88fa-5f065cf0029f is finalizing_success
4.log:transfer 26486597-0ed5-4b93-88fa-5f065cf0029f is finalizing_success
4.log:transfer 26486597-0ed5-4b93-88fa-5f065cf0029f is finalizing_success
4.log:transfer 26486597-0ed5-4b93-88fa-5f065cf0029f is finalizing_success
4.log:transfer 26486597-0ed5-4b93-88fa-5f065cf0029f is finished_success
4.log:transfer 26486597-0ed5-4b93-88fa-5f065cf0029f finalized in 6.058 seconds


$ (cd ~/v2v-logs && egrep '^transfer|finalizing transfer' *.log)
1.log:transfer.id = '3bf1233c-3300-460c-9bca-a1da6dcfab5d'
1.log:finalizing transfer 3bf1233c-3300-460c-9bca-a1da6dcfab5d
1.log:transfer 3bf1233c-3300-460c-9bca-a1da6dcfab5d is finalizing_success
1.log:transfer 3bf1233c-3300-460c-9bca-a1da6dcfab5d is finalizing_success
1.log:transfer 3bf1233c-3300-460c-9bca-a1da6dcfab5d is finalizing_success
1.log:transfer 3bf1233c-3300-460c-9bca-a1da6dcfab5d is finalizing_success
1.log:transfer 3bf1233c-3300-460c-9bca-a1da6dcfab5d is finalizing_success
1.log:transfer 3bf1233c-3300-460c-9bca-a1da6dcfab5d is finished_success
1.log:transfer 3bf1233c-3300-460c-9bca-a1da6dcfab5d finalized in 6.050 seconds
2.log:transfer.id = 'c4a8bfd6-9e86-47b9-a4cc-6c5c6c2aa59c'
2.log:finalizing transfer c4a8bfd6-9e86-47b9-a4cc-6c5c6c2aa59c
2.log:transfer c4a8bfd6-9e86-47b9-a4cc-6c5c6c2aa59c is finalizing_success
2.log:transfer c4a8bfd6-9e86-47b9-a4cc-6c5c6c2aa59c is finalizing_success
2.log:transfer c4a8bfd6-9e86-47b9-a4cc-6c5c6c2aa59c is finalizing_success
2.log:transfer c4a8bfd6-9e86-47b9-a4cc-6c5c6c2aa59c is finalizing_success
2.log:transfer c4a8bfd6-9e86-47b9-a4cc-6c5c6c2aa59c is finalizing_success
2.log:transfer c4a8bfd6-9e86-47b9-a4cc-6c5c6c2aa59c is finalizing_success
2.log:transfer c4a8bfd6-9e86-47b9-a4cc-6c5c6c2aa59c is finalizing_success
2.log:transfer c4a8bfd6-9e86-47b9-a4cc-6c5c6c2aa59c is finished_success
2.log:transfer c4a8bfd6-9e86-47b9-a4cc-6c5c6c2aa59c finalized in 8.076 seconds
3.log:transfer.id = '1b8c5252-3035-443a-a33d-ebbff9887385'
3.log:finalizing transfer 1b8c5252-3035-443a-a33d-ebbff9887385
3.log:transfer 1b8c5252-3035-443a-a33d-ebbff9887385 is finalizing_success
3.log:transfer 1b8c5252-3035-443a-a33d-ebbff9887385 is finalizing_success
3.log:transfer 1b8c5252-3035-443a-a33d-ebbff9887385 is finalizing_success
3.log:transfer 1b8c5252-3035-443a-a33d-ebbff9887385 is finalizing_success
3.log:transfer 1b8c5252-3035-443a-a33d-ebbff9887385 is finalizing_success
3.log:transfer 1b8c5252-3035-443a-a33d-ebbff9887385 is finished_success
3.log:transfer 1b8c5252-3035-443a-a33d-ebbff9887385 finalized in 6.068 seconds
4.log:transfer.id = 'f09b5fd2-bbe3-480e-9f6f-9f6ecf6e2821'
4.log:finalizing transfer f09b5fd2-bbe3-480e-9f6f-9f6ecf6e2821
4.log:transfer f09b5fd2-bbe3-480e-9f6f-9f6ecf6e2821 is finalizing_success
4.log:transfer f09b5fd2-bbe3-480e-9f6f-9f6ecf6e2821 is finalizing_success
4.log:transfer f09b5fd2-bbe3-480e-9f6f-9f6ecf6e2821 is finalizing_success
4.log:transfer f09b5fd2-bbe3-480e-9f6f-9f6ecf6e2821 is finalizing_success
4.log:transfer f09b5fd2-bbe3-480e-9f6f-9f6ecf6e2821 is finished_success
4.log:transfer f09b5fd2-bbe3-480e-9f6f-9f6ecf6e2821 finalized in 5.041 seconds


2. ovirt 4.4.7.5 (delete image transfers shortly after completion)

$ (cd ~/v2v-logs && egrep '^transfer|finalizing transfer' *.log)
1.log:transfer.id = '2839a917-087d-4484-b30d-f16ac152ba17'
1.log:finalizing transfer 2839a917-087d-4484-b30d-f16ac152ba17
1.log:transfer 2839a917-087d-4484-b30d-f16ac152ba17 is finalizing_success
1.log:transfer 2839a917-087d-4484-b30d-f16ac152ba17 is finalizing_success
1.log:transfer 2839a917-087d-4484-b30d-f16ac152ba17 is finalizing_success
1.log:transfer 2839a917-087d-4484-b30d-f16ac152ba17 is finalizing_success
1.log:transfer 2839a917-087d-4484-b30d-f16ac152ba17 is finalizing_success
1.log:transfer 2839a917-087d-4484-b30d-f16ac152ba17 is finalizing_success
1.log:transfer 2839a917-087d-4484-b30d-f16ac152ba17 is finished_success
1.log:transfer 2839a917-087d-4484-b30d-f16ac152ba17 finalized in 7.102 seconds
2.log:transfer.id = 'f5013f77-ef7c-44af-b19a-6c145839eb5a'
2.log:finalizing transfer f5013f77-ef7c-44af-b19a-6c145839eb5a
2.log:transfer f5013f77-ef7c-44af-b19a-6c145839eb5a is finalizing_success
2.log:transfer f5013f77-ef7c-44af-b19a-6c145839eb5a is finalizing_success
2.log:transfer f5013f77-ef7c-44af-b19a-6c145839eb5a is finalizing_success
2.log:transfer f5013f77-ef7c-44af-b19a-6c145839eb5a is finalizing_success
2.log:transfer f5013f77-ef7c-44af-b19a-6c145839eb5a is finalizing_success
2.log:transfer f5013f77-ef7c-44af-b19a-6c145839eb5a is finished_success
2.log:transfer f5013f77-ef7c-44af-b19a-6c145839eb5a finalized in 6.061 seconds
3.log:transfer.id = '958579c9-c9da-4e51-ba3a-e23790f9d66a'
3.log:finalizing transfer 958579c9-c9da-4e51-ba3a-e23790f9d66a
3.log:transfer 958579c9-c9da-4e51-ba3a-e23790f9d66a is finalizing_success
3.log:transfer 958579c9-c9da-4e51-ba3a-e23790f9d66a is finalizing_success
3.log:transfer 958579c9-c9da-4e51-ba3a-e23790f9d66a is finalizing_success
3.log:transfer 958579c9-c9da-4e51-ba3a-e23790f9d66a is finalizing_success
3.log:transfer 958579c9-c9da-4e51-ba3a-e23790f9d66a is finalizing_success
3.log:transfer 958579c9-c9da-4e51-ba3a-e23790f9d66a is finished_success
3.log:transfer 958579c9-c9da-4e51-ba3a-e23790f9d66a finalized in 6.073 seconds
4.log:transfer.id = '28172fb1-be45-4d85-8213-b4fa036cb874'
4.log:finalizing transfer 28172fb1-be45-4d85-8213-b4fa036cb874
4.log:transfer 28172fb1-be45-4d85-8213-b4fa036cb874 is finalizing_success
4.log:transfer 28172fb1-be45-4d85-8213-b4fa036cb874 is finalizing_success
4.log:transfer 28172fb1-be45-4d85-8213-b4fa036cb874 is finalizing_success
4.log:transfer 28172fb1-be45-4d85-8213-b4fa036cb874 is finalizing_success
4.log:transfer 28172fb1-be45-4d85-8213-b4fa036cb874 is finalizing_success
4.log:transfer 28172fb1-be45-4d85-8213-b4fa036cb874 is finalizing_success
4.log:transfer 28172fb1-be45-4d85-8213-b4fa036cb874 is finalizing_success
4.log:transfer 28172fb1-be45-4d85-8213-b4fa036cb874 is finished_success
4.log:transfer 28172fb1-be45-4d85-8213-b4fa036cb874 finalized in 8.103 seconds

$ (cd ~/v2v-logs && egrep '^transfer|finalizing transfer' *.log)
1.log:transfer.id = 'b3a4f573-3e11-4915-8523-3e7349fdc4fa'
1.log:finalizing transfer b3a4f573-3e11-4915-8523-3e7349fdc4fa
1.log:transfer b3a4f573-3e11-4915-8523-3e7349fdc4fa is finalizing_success
1.log:transfer b3a4f573-3e11-4915-8523-3e7349fdc4fa is finalizing_success
1.log:transfer b3a4f573-3e11-4915-8523-3e7349fdc4fa is finalizing_success
1.log:transfer b3a4f573-3e11-4915-8523-3e7349fdc4fa is finalizing_success
1.log:transfer b3a4f573-3e11-4915-8523-3e7349fdc4fa is finalizing_success
1.log:transfer b3a4f573-3e11-4915-8523-3e7349fdc4fa is finalizing_success
1.log:transfer b3a4f573-3e11-4915-8523-3e7349fdc4fa is finalizing_success
1.log:transfer b3a4f573-3e11-4915-8523-3e7349fdc4fa is finalizing_success
1.log:transfer b3a4f573-3e11-4915-8523-3e7349fdc4fa is finished_success
1.log:transfer b3a4f573-3e11-4915-8523-3e7349fdc4fa finalized in 9.090 seconds
2.log:transfer.id = '711ecdce-fbeb-46e9-8265-1548b74adbcc'
2.log:finalizing transfer 711ecdce-fbeb-46e9-8265-1548b74adbcc
2.log:transfer 711ecdce-fbeb-46e9-8265-1548b74adbcc is finalizing_success
2.log:transfer 711ecdce-fbeb-46e9-8265-1548b74adbcc is finalizing_success
2.log:transfer 711ecdce-fbeb-46e9-8265-1548b74adbcc is finalizing_success
2.log:transfer 711ecdce-fbeb-46e9-8265-1548b74adbcc is finalizing_success
2.log:transfer 711ecdce-fbeb-46e9-8265-1548b74adbcc is finalizing_success
2.log:transfer 711ecdce-fbeb-46e9-8265-1548b74adbcc is finalizing_success
2.log:transfer 711ecdce-fbeb-46e9-8265-1548b74adbcc is finalizing_success
2.log:transfer 711ecdce-fbeb-46e9-8265-1548b74adbcc is finalizing_success
2.log:transfer 711ecdce-fbeb-46e9-8265-1548b74adbcc is finished_success
2.log:transfer 711ecdce-fbeb-46e9-8265-1548b74adbcc finalized in 9.108 seconds
3.log:transfer.id = '09d78420-3388-4af1-a4ca-48349dbb17fc'
3.log:finalizing transfer 09d78420-3388-4af1-a4ca-48349dbb17fc
3.log:transfer 09d78420-3388-4af1-a4ca-48349dbb17fc is finalizing_success
3.log:transfer 09d78420-3388-4af1-a4ca-48349dbb17fc is finalizing_success
3.log:transfer 09d78420-3388-4af1-a4ca-48349dbb17fc is finalizing_success
3.log:transfer 09d78420-3388-4af1-a4ca-48349dbb17fc is finalizing_success
3.log:transfer 09d78420-3388-4af1-a4ca-48349dbb17fc is finalizing_success
3.log:transfer 09d78420-3388-4af1-a4ca-48349dbb17fc is finalizing_success
3.log:transfer 09d78420-3388-4af1-a4ca-48349dbb17fc is finalizing_success
3.log:transfer 09d78420-3388-4af1-a4ca-48349dbb17fc is finalizing_success
3.log:transfer 09d78420-3388-4af1-a4ca-48349dbb17fc is finalizing_success
3.log:transfer 09d78420-3388-4af1-a4ca-48349dbb17fc is finalizing_success
3.log:transfer 09d78420-3388-4af1-a4ca-48349dbb17fc is finalizing_success
3.log:transfer 09d78420-3388-4af1-a4ca-48349dbb17fc is finished_success
3.log:transfer 09d78420-3388-4af1-a4ca-48349dbb17fc finalized in 12.112 seconds
4.log:transfer.id = '384a632b-2c2f-411d-ac7e-b795169594d0'
4.log:finalizing transfer 384a632b-2c2f-411d-ac7e-b795169594d0
4.log:transfer 384a632b-2c2f-411d-ac7e-b795169594d0 is finalizing_success
4.log:transfer 384a632b-2c2f-411d-ac7e-b795169594d0 is finalizing_success
4.log:transfer 384a632b-2c2f-411d-ac7e-b795169594d0 is finalizing_success
4.log:transfer 384a632b-2c2f-411d-ac7e-b795169594d0 is finalizing_success
4.log:transfer 384a632b-2c2f-411d-ac7e-b795169594d0 is finalizing_success
4.log:transfer 384a632b-2c2f-411d-ac7e-b795169594d0 is finalizing_success
4.log:transfer 384a632b-2c2f-411d-ac7e-b795169594d0 is finalizing_success
4.log:transfer 384a632b-2c2f-411d-ac7e-b795169594d0 is finalizing_success
4.log:transfer 384a632b-2c2f-411d-ac7e-b795169594d0 is finalizing_success
4.log:transfer 384a632b-2c2f-411d-ac7e-b795169594d0 is finalizing_success
4.log:transfer 384a632b-2c2f-411d-ac7e-b795169594d0 is finalizing_success
4.log:transfer 384a632b-2c2f-411d-ac7e-b795169594d0 is finished_success
4.log:transfer 384a632b-2c2f-411d-ac7e-b795169594d0 finalized in 12.236 seconds
5.log:transfer.id = 'd4661229-4f40-457b-b6e1-f90e3e285acf'
5.log:finalizing transfer d4661229-4f40-457b-b6e1-f90e3e285acf
5.log:transfer d4661229-4f40-457b-b6e1-f90e3e285acf is finalizing_success
5.log:transfer d4661229-4f40-457b-b6e1-f90e3e285acf is finalizing_success
5.log:transfer d4661229-4f40-457b-b6e1-f90e3e285acf is finalizing_success
5.log:transfer d4661229-4f40-457b-b6e1-f90e3e285acf is finalizing_success
5.log:transfer d4661229-4f40-457b-b6e1-f90e3e285acf is finalizing_success
5.log:transfer d4661229-4f40-457b-b6e1-f90e3e285acf is finalizing_success
5.log:transfer d4661229-4f40-457b-b6e1-f90e3e285acf is finalizing_success
5.log:transfer d4661229-4f40-457b-b6e1-f90e3e285acf is finalizing_success
5.log:transfer d4661229-4f40-457b-b6e1-f90e3e285acf is finalizing_success
5.log:transfer d4661229-4f40-457b-b6e1-f90e3e285acf is finalizing_success
5.log:transfer d4661229-4f40-457b-b6e1-f90e3e285acf is finalizing_success
5.log:transfer d4661229-4f40-457b-b6e1-f90e3e285acf is finished_success
5.log:transfer d4661229-4f40-457b-b6e1-f90e3e285acf finalized in 12.119 seconds
6.log:transfer.id = '5d88fb8b-478f-4a08-81a2-ad3aa02a77f9'
6.log:finalizing transfer 5d88fb8b-478f-4a08-81a2-ad3aa02a77f9
6.log:transfer 5d88fb8b-478f-4a08-81a2-ad3aa02a77f9 is finalizing_success
6.log:transfer 5d88fb8b-478f-4a08-81a2-ad3aa02a77f9 is finalizing_success
6.log:transfer 5d88fb8b-478f-4a08-81a2-ad3aa02a77f9 is finalizing_success
6.log:transfer 5d88fb8b-478f-4a08-81a2-ad3aa02a77f9 is finalizing_success
6.log:transfer 5d88fb8b-478f-4a08-81a2-ad3aa02a77f9 is finalizing_success
6.log:transfer 5d88fb8b-478f-4a08-81a2-ad3aa02a77f9 is finalizing_success
6.log:transfer 5d88fb8b-478f-4a08-81a2-ad3aa02a77f9 is finished_success
6.log:transfer 5d88fb8b-478f-4a08-81a2-ad3aa02a77f9 finalized in 7.107 seconds
7.log:transfer.id = 'cadf008d-2fbd-481d-adc4-4237825df12c'
7.log:finalizing transfer cadf008d-2fbd-481d-adc4-4237825df12c
7.log:transfer cadf008d-2fbd-481d-adc4-4237825df12c is finalizing_success
7.log:transfer cadf008d-2fbd-481d-adc4-4237825df12c is finalizing_success
7.log:transfer cadf008d-2fbd-481d-adc4-4237825df12c is finished_success
7.log:transfer cadf008d-2fbd-481d-adc4-4237825df12c finalized in 3.042 seconds
8.log:transfer.id = '0589671b-b981-4398-8279-247e5a8bcc31'
8.log:finalizing transfer 0589671b-b981-4398-8279-247e5a8bcc31
8.log:transfer 0589671b-b981-4398-8279-247e5a8bcc31 is finalizing_success
8.log:transfer 0589671b-b981-4398-8279-247e5a8bcc31 is finalizing_success
8.log:transfer 0589671b-b981-4398-8279-247e5a8bcc31 is finalizing_success
8.log:transfer 0589671b-b981-4398-8279-247e5a8bcc31 is finalizing_success
8.log:transfer 0589671b-b981-4398-8279-247e5a8bcc31 is finalizing_success
8.log:transfer 0589671b-b981-4398-8279-247e5a8bcc31 is finished_success
8.log:transfer 0589671b-b981-4398-8279-247e5a8bcc31 finalized in 6.074 seconds

$ (cd ~/v2v-logs && egrep '^transfer|finalizing transfer' *.log)
1.log:transfer.id = 'a539bdbe-5d4b-496d-9e53-0f378c8d5abe'
1.log:finalizing transfer a539bdbe-5d4b-496d-9e53-0f378c8d5abe
1.log:transfer a539bdbe-5d4b-496d-9e53-0f378c8d5abe is finalizing_success
1.log:transfer a539bdbe-5d4b-496d-9e53-0f378c8d5abe is finalizing_success
1.log:transfer a539bdbe-5d4b-496d-9e53-0f378c8d5abe is finalizing_success
1.log:transfer a539bdbe-5d4b-496d-9e53-0f378c8d5abe is finalizing_success
1.log:transfer a539bdbe-5d4b-496d-9e53-0f378c8d5abe is finalizing_success
1.log:transfer a539bdbe-5d4b-496d-9e53-0f378c8d5abe is finished_success
1.log:transfer a539bdbe-5d4b-496d-9e53-0f378c8d5abe finalized in 6.057 seconds
2.log:transfer.id = '190873ea-9318-4f04-b950-fb509d3fa527'
2.log:finalizing transfer 190873ea-9318-4f04-b950-fb509d3fa527
2.log:transfer 190873ea-9318-4f04-b950-fb509d3fa527 is finalizing_success
2.log:transfer 190873ea-9318-4f04-b950-fb509d3fa527 is finalizing_success
2.log:transfer 190873ea-9318-4f04-b950-fb509d3fa527 is finalizing_success
2.log:transfer 190873ea-9318-4f04-b950-fb509d3fa527 is finalizing_success
2.log:transfer 190873ea-9318-4f04-b950-fb509d3fa527 is finalizing_success
2.log:transfer 190873ea-9318-4f04-b950-fb509d3fa527 is finished_success
2.log:transfer 190873ea-9318-4f04-b950-fb509d3fa527 finalized in 6.049 seconds

Testing the case when ovirt remove the transfer using this patch:

$ grep -A4 finalizing ~/v2v-logs/*.log
/home/nsoffer/v2v-logs/1.log:finalizing transfer
0dc96682-4a48-4f2a-af10-b5d9e5a1f0c7
/home/nsoffer/v2v-logs/1.log-transfer
0dc96682-4a48-4f2a-af10-b5d9e5a1f0c7 is finished_success
/home/nsoffer/v2v-logs/1.log-transfer
0dc96682-4a48-4f2a-af10-b5d9e5a1f0c7 finalized in 21.054 seconds
/home/nsoffer/v2v-logs/1.log-[ 164.4] Creating output metadata
/home/nsoffer/v2v-logs/1.log-uuidgen -r
--
/home/nsoffer/v2v-logs/2.log:finalizing transfer
dff7f0b7-2ea7-4738-b867-c8c2ef4a23df
/home/nsoffer/v2v-logs/2.log-virtual copying rate: 1132.9 M bits/sec
/home/nsoffer/v2v-logs/2.log-transfer
dff7f0b7-2ea7-4738-b867-c8c2ef4a23df was removed, checking disk
a1b8a24e-1097-46fc-bb10-5849e960fed9 status
/home/nsoffer/v2v-logs/2.log-disk a1b8a24e-1097-46fc-bb10-5849e960fed9 is ok
/home/nsoffer/v2v-logs/2.log-transfer
dff7f0b7-2ea7-4738-b867-c8c2ef4a23df finalized in 21.049 seconds
--
/home/nsoffer/v2v-logs/3.log:finalizing transfer
7f17cca7-51d7-4f25-a311-c5ec70d51ed4
/home/nsoffer/v2v-logs/3.log-transfer
7f17cca7-51d7-4f25-a311-c5ec70d51ed4 was removed, checking disk
7a055d4d-b576-4e48-acc8-b8daa1bb6fab status
/home/nsoffer/v2v-logs/3.log-disk 7a055d4d-b576-4e48-acc8-b8daa1bb6fab is ok
/home/nsoffer/v2v-logs/3.log-transfer
7f17cca7-51d7-4f25-a311-c5ec70d51ed4 finalized in 21.054 seconds
/home/nsoffer/v2v-logs/3.log-[ 172.6] Creating output metadata
--
/home/nsoffer/v2v-logs/4.log:finalizing transfer
affded7d-2c0a-4f58-a1b9-849a90602cca
/home/nsoffer/v2v-logs/4.log-transfer
affded7d-2c0a-4f58-a1b9-849a90602cca was removed, checking disk
1ff71a02-16f2-483d-be55-accf50dc7767 status
/home/nsoffer/v2v-logs/4.log-disk 1ff71a02-16f2-483d-be55-accf50dc7767 is ok
/home/nsoffer/v2v-logs/4.log-transfer
affded7d-2c0a-4f58-a1b9-849a90602cca finalized in 21.048 seconds
/home/nsoffer/v2v-logs/4.log-[ 172.9] Creating output metadata

Nir

Vojtech Juranek

2021-Jul-16 08:18 UTC

head link

[Libguestfs] [PATCH] v2v: rhv-upload-plugin: Fix waiting for finalize

One issue in documentation, otherwise LGTM

On Monday, 12 July 2021 01:58:52 CEST Nir Soffer wrote:> Waiting for image transfer finalize is complex. In the past we tried to
> simplify the process by waiting on the disk status, but turns out that
> due to the way oVirt lock the disk, this is not reliable.
> 
> These is finalize success flow:
> 
> 1. User asks to finalize the transfer
> 2. oVirt sets transfer phase to FINALIZING_SUCCESS
> 3. oVirt finalizes the transfer
> 4. oVirt sets disk status to OK
> 5. oVirt unlocks the disk and changes transfer phase to FINISHED_SUCCESS
> 6. oVirt removes the transfer
> 
> In oVirt logs we can see that disk status changes to OK about 3 seconds
> before the disk is actually unlocked. This is a very old problem that is
> unlikely to be fixed.
> 
> The only way to wait for transfer completion is to poll the transfer
> phase, but oVirt makes this hard by removing the transfer shortly after
> it completes, so we may not be able to get the FINISHED_SUCCESS phase.
> If the transfer was removed before we got one of the final phases, we
> need to check the disk status to understand the result of transfer.
> 
> oVirt 4.4.7 made polling transfer phase easier by keeping the transfer
> after completion, but we need to support older versions so we must have
> generic code that work with any version.
> 
> To make debugging easier, we log the transfer phase during polling. Here
> is a typical transfer log when finalizing transfer:
> 
>     finalizing transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa
>     transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa is finalizing_success
>     transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa is finalizing_success
>     transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa is finalizing_success
>     transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa is finalizing_success
>     transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa is finished_success
>     transfer 59e545f3-db1f-4a6b-90b1-80ac66572faa finalized in 5.153
seconds
> 
> Signed-off-by: Nir Soffer <nsoffer at redhat.com>
> ---
>  v2v/rhv-upload-plugin.py | 102 +++++++++++++++++++++++++++------------
>  1 file changed, 71 insertions(+), 31 deletions(-)
> 
> diff --git a/v2v/rhv-upload-plugin.py b/v2v/rhv-upload-plugin.py
> index 07e879c9..11050358 100644
> --- a/v2v/rhv-upload-plugin.py
> +++ b/v2v/rhv-upload-plugin.py
> @@ -607,17 +607,29 @@ def finalize_transfer(connection, transfer, disk_id):
>      """
>      Finalize a transfer, making the transfer disk available.
> 
> -    If finalizing succeeds, transfer's phase will change to
> FINISHED_SUCCESS -    and the transer's disk status will change to OK. 
On
> errors, the transfer's -    phase will change to FINISHED_FAILURE and
the
> disk status will change to -    ILLEGAL and it will be removed. In both
> cases the transfer entity will be -    removed shortly after.
> -
> -    If oVirt fails to finalize the transfer, transfer's phase will
change
> to -    PAUSED_SYSTEM. In this case the disk's status will change to
> ILLEGAL and it -    will not be removed.
> -
> -    For simplicity, we track only disk's status changes.
> +    If finalizing succeeds, the transfer's disk status will change to
OK
> +    and transfer's phase will change to FINISHED_SUCCESS.
Unfortunately,
> +    the disk status is modified before the transfer finishes, and oVirt
> +    may still hold a lock on the disk at this point.
> +
> +    The only way to make sure that the disk is unlocked, is to wait
> +    until the transfer phase switches FINISHED_SUCCESS. Unfortunately
> +    oVirt makes this hard to use because the transfer is removed shortly
> +    after switching the phase to the final phase. However if the
> +    transfer was removed, we can be sure that the disk is not unlocked,
should be "disk is not locked"
> +    since oVirt releases the locks before removing the transfer.
> +
> +    On errors, the transfer's phase will change to FINISHED_FAILURE
and
> +    the disk status will change to ILLEGAL and it will be removed. Again
> +    the transfer will be removed shortly after that.
> +
> +    If oVirt fails to finalize the transfer, transfer's phase will
> +    change to PAUSED_SYSTEM. In this case the disk's status will
change
> +    to ILLEGAL and it will not be removed.
> +
> +    oVirt 4.4.7 made waiting for transfer easier by keeping transfers
> +    after they complete, but we must support older versions so we have
> +    generic code that work with any version.
> 
>      For more info see:
>      -
> http://ovirt.github.io/ovirt-engine-api-model/4.4/#services/image_transfer
> @@ -632,34 +644,62 @@ def finalize_transfer(connection, transfer, disk_id):
> 
>      transfer_service.finalize()
> 
> -    disk_service = (connection.system_service()
> -                    .disks_service()
> -                    .disk_service(disk_id))
> -
>      while True:
>          time.sleep(1)
>          try:
> -            disk = disk_service.get()
> +            transfer = transfer_service.get()
>          except sdk.NotFoundError:
> -            # Disk verification failed and the system removed the disk.
> -            raise RuntimeError(
> -                "transfer %s failed: disk %s was removed"
> -                % (transfer.id, disk_id))
> +            # Transfer was removed (ovirt < 4.4.7). We need to check
the
> +            # disk status to understand if the transfer was successful.
> +            # Due to the way oVirt does locking, we know that the disk
> +            # is unlocked at this point so we can check only once.
> 
> -        if disk.status == types.DiskStatus.ILLEGAL:
> -            # Disk verification failed or transfer was paused by the
> system. -            raise RuntimeError(
> -                "transfer %s failed: disk is ILLEGAL" %
transfer.id)
> +            debug("transfer %s was removed, checking disk %s
status"
> +                  % (transfer.id, disk_id))
> 
> -        if disk.status == types.DiskStatus.OK:
> -            debug("transfer %s finalized in %.3f seconds"
> -                  % (transfer.id, time.time() - start))
> -            break
> +            disk_service = (connection.system_service()
> +                            .disks_service()
> +                            .disk_service(disk_id))
> +
> +            try:
> +                disk = disk_service.get()
> +            except sdk.NotFoundError:
> +                raise RuntimeError(
> +                    "transfer %s failed: disk %s was removed"
> +                    % (transfer.id, disk_id))
> +
> +            debug("disk %s is %s" % (disk_id, disk.status))
> +
> +            if disk.status == types.DiskStatus.OK:
> +                break
> 
> -        if time.time() > start + timeout:
>              raise RuntimeError(
> -                "timed out waiting for transfer %s to finalize"
> -                % transfer.id)
> +                "transfer %s failed: disk is %s" % (transfer.id,
> disk.status)) +        else:
> +            # Transfer exists, check if it reached one of the final
> +            # phases, or we timed out.
> +
> +            debug("transfer %s is %s" % (transfer.id,
transfer.phase))
> +
> +            if transfer.phase ==
types.ImageTransferPhase.FINISHED_SUCCESS:
> +                break
> +
> +            if transfer.phase ==
types.ImageTransferPhase.FINISHED_FAILURE:
> +                raise RuntimeError(
> +                    "transfer %s has failed" % (transfer.id,))
> +
> +            if transfer.phase == types.ImageTransferPhase.PAUSED_SYSTEM:
> +                raise RuntimeError(
> +                    "transfer %s was paused by system" %
(transfer.id,))
> +
> +            if time.time() > start + timeout:
> +                raise RuntimeError(
> +                    "timed out waiting for transfer %s to finalize,
"
> +                    "transfer is %s"
> +                    % (transfer.id, transfer.phase))
> +
> +    debug("transfer %s finalized in %.3f seconds"
> +          % (transfer.id, time.time() - start))
> 
> 
>  def transfer_supports_format():
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 488 bytes
Desc: This is a digitally signed message part.
URL:
<http://listman.redhat.com/archives/libguestfs/attachments/20210716/e72a8093/attachment.sig>

Libguestfs - Jul 2021 - [PATCH] v2v: rhv-upload-plugin: Fix waiting for finalize

[Libguestfs] [PATCH] v2v: rhv-upload-plugin: Fix waiting for finalize

[Libguestfs] [PATCH] v2v: rhv-upload-plugin: Fix waiting for finalize

[Libguestfs] [PATCH] v2v: rhv-upload-plugin: Fix waiting for finalize