Bug 2131470 - Image transfer status is changed to "Finalizing Success" if we finalize a "Finished Success" transfer
Summary: Image transfer status is changed to "Finalizing Success" if we finalize a "Fi...
Keywords:
Status: CLOSED DUPLICATE of bug 2123141
Alias: None
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: ovirt-engine
Version: 4.5.1
Hardware: All
OS: Linux
unspecified
urgent
Target Milestone: ---
: ---
Assignee: Nobody
QA Contact: Shir Fishbain
URL:
Whiteboard:
Depends On:
Blocks: 1541529
TreeView+ depends on / blocked
 
Reported: 2022-10-01 15:29 UTC by nijin ashok
Modified: 2022-11-09 12:35 UTC (History)
7 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2022-10-06 07:06:24 UTC
oVirt Team: Storage
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Issue Tracker RHV-47948 0 None None None 2022-10-01 15:32:31 UTC
Red Hat Knowledge Base (Solution) 6978885 0 None None None 2022-10-04 18:56:16 UTC

Description nijin ashok 2022-10-01 15:29:28 UTC
Description of problem:

Used download_disk_snapshot.py to download a snapshot image. The transfer was completed successfully and the transfer status was changed to 'Finished Success'.

~~~
2022-10-01 18:56:39,065+05 INFO  [org.ovirt.engine.core.bll.storage.disk.image.ImageTransferUpdater] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-2) [f2327d87-84a7-4f4b-b6fa-8015957ef713] Updating image transfer 'd5c3c9d3-ead1-4395-9186-a3994e1b5ad7' phase from 'Finalizing Success' to 'Finished Success'
2022-10-01 18:56:39,103+05 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-2) [f2327d87-84a7-4f4b-b6fa-8015957ef713] EVENT_ID: TRANSFER_IMAGE_SUCCEEDED(1,032), Image Download with disk myvn_Disk1 succeeded.
~~~

Send another "finalize" request to the same image transfer command.

~~~
# curl --insecure --request POST --header 'Version: 4' --header 'Accept: application/xml' --header 'Content-Type: application/xml'  --data '<action/>'  --user 'admin@internal:mypass'  https://manager.shiftvirt.com/ovirt-engine/api/imagetransfers/d5c3c9d3-ead1-4395-9186-a3994e1b5ad7/finalize
<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
<action>
    <status>complete</status>
</action>
~~~

The status is now back to `Finalizing Success` from `Finished Success`.

~~~
2022-10-01 19:14:53,469+05 INFO  [org.ovirt.engine.core.bll.storage.disk.image.ImageTransferUpdater] (default task-42) [d67caeb4-3686-4227-b605-b33e3a7af2f9] Updating image transfer 'd5c3c9d3-ead1-4395-9186-a3994e1b5ad7' phase from 'Finished Success' to 'Finalizing Success'
~~~

And this entry stays in the database and this can cause issues in snapshot flow as explained below.

Tried the same flow again which creates two imagetransfer entries for the disk.

~~~
engine=# select command_id,disk_id,phase from image_transfers where disk_id='6391823b-34fd-4ce8-9f7d-8a62319fcc94';
              command_id              |               disk_id                | phase
--------------------------------------+--------------------------------------+-------
 1c0e54bb-9519-4ea5-b297-5b12d03a267c | 6391823b-34fd-4ce8-9f7d-8a62319fcc94 |     7
 d5c3c9d3-ead1-4395-9186-a3994e1b5ad7 | 6391823b-34fd-4ce8-9f7d-8a62319fcc94 |     7
(2 rows)
~~~

Now the `images_storage_domain_view` give duplicate entries which are referred during snapshot create and delete operations.

~~~
engine=# select image_guid,image_group_id,vm_snapshot_id from images_storage_domain_view where disk_id = '6391823b-34fd-4ce8-9f7d-8a62319fcc94';
              image_guid              |            image_group_id            |            vm_snapshot_id
--------------------------------------+--------------------------------------+--------------------------------------
 a7a3c038-b788-4355-b35b-097b156312ec | 6391823b-34fd-4ce8-9f7d-8a62319fcc94 | a1600a79-8e65-4445-af54-5ff2781966f1
 a7a3c038-b788-4355-b35b-097b156312ec | 6391823b-34fd-4ce8-9f7d-8a62319fcc94 | a1600a79-8e65-4445-af54-5ff2781966f1
 4c88e42e-8f13-4c87-a40a-c72802e9ead9 | 6391823b-34fd-4ce8-9f7d-8a62319fcc94 | 5173281a-a966-47b0-9cb1-9dfac362b32e
 4c88e42e-8f13-4c87-a40a-c72802e9ead9 | 6391823b-34fd-4ce8-9f7d-8a62319fcc94 | 5173281a-a966-47b0-9cb1-9dfac362b32e
(4 rows)
~~~

Deleting this snapshot will fail with the error below:

~~~
2022-10-01 19:48:44,786+05 INFO  [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand] (default task-47) [ca55a7e2-b675-4b74-a4e4-3e94ff4f1491] Lock freed to object 'EngineLock:{exclusiveLocks='[e110655d-06bb-41ec-b5cd-da7c75658550=VM]', sharedLocks=''}'
2022-10-01 19:48:45,075+05 ERROR [org.ovirt.engine.core.bll.GetVmConfigurationBySnapshotQuery] (default task-47) [d973b2ef-ebc1-4cd5-ada0-9794916bb7b6] Query 'GetVmConfigurationBySnapshotQuery' failed: Duplicate key 4c88e42e-8f13-4c87-a40a-c72802e9ead9 (attempted merging values org.ovirt.engine.core.common.businessentities.storage.DiskImage@ff49c3c5 and org.ovirt.engine.core.common.businessentities.storage.DiskImage@ff49c3c5)
2022-10-01 19:48:45,075+05 ERROR [org.ovirt.engine.core.bll.GetVmConfigurationBySnapshotQuery] (default task-47) [d973b2ef-ebc1-4cd5-ada0-9794916bb7b6] Exception: java.lang.IllegalStateException: Duplicate key 4c88e42e-8f13-4c87-a40a-c72802e9ead9 (attempted merging values org.ovirt.engine.core.common.businessentities.storage.DiskImage@ff49c3c5 and org.ovirt.engine.core.common.businessentities.storage.DiskImage@ff49c3c5)
	at java.base/java.util.stream.Collectors.duplicateKeyException(Collectors.java:133)
	at java.base/java.util.stream.Collectors.lambda$uniqKeysMapAccumulator$1(Collectors.java:180)
	at java.base/java.util.stream.ReduceOps$3ReducingSink.accept(ReduceOps.java:169)
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1655)
.....
......
	at io.undertow.servlet.13.SP2-redhat-00001//io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:79)
	at io.undertow.servlet.13.SP2-redhat-00001//io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:100)
	at io.undertow.core.13.SP2-redhat-00001//io.undertow.server.Connectors.executeRootHandler(Connectors.java:387)
	at io.undertow.core.13.SP2-redhat-00001//io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:852)
	at org.jboss.threads.0.Final-redhat-00001//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
	at org.jboss.threads.0.Final-redhat-00001//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990)
	at org.jboss.threads.0.Final-redhat-00001//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
	at org.jboss.threads.0.Final-redhat-00001//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
	at org.jboss.xnio.5.SP1-redhat-00001//org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1280)
	at java.base/java.lang.Thread.run(Thread.java:829)
~~~

Also it can cause duplicate entries in the images table if this two imagetransfer exists while creating a new snapshot.

Here, I deleted both the imagetransfer from the database, deleted the snapshot, and did the same flow to create two imagetrasfer entries with phase=7.

Now the view `all_disks_for_vms` which lists active images of the disks will have duplicate entries.

~~~
engine=# SELECT image_guid,disk_id from all_disks_for_vms where disk_id = '6391823b-34fd-4ce8-9f7d-8a62319fcc94';
              image_guid              |               disk_id
--------------------------------------+--------------------------------------
 4c88e42e-8f13-4c87-a40a-c72802e9ead9 | 6391823b-34fd-4ce8-9f7d-8a62319fcc94
 4c88e42e-8f13-4c87-a40a-c72802e9ead9 | 6391823b-34fd-4ce8-9f7d-8a62319fcc94
(2 rows)
~~~

This view is used by the function getdisksvmguid to get the list of active disks while creating the snapshot. So it gets two entries and attempts to create a snapshot on the same disk twice:

~~~
2022-10-01 20:43:39,398+05 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateVolumeVDSCommand] (EE-ManagedThreadFactory-engine-Thread-80383) [65023df7-3d8d-4a72-bc20-ec4525858d74] START, CreateVolumeVDSCommand( CreateVolumeVDSCommandParameters:{storagePoolId='71cf243c-edec-11eb-aa8c-002b6a01557c', ignoreFailoverLimit='false', storageDomainId='1bfb1005-b98d-4592-9c1d-5c04292584ed', imageGroupId='6391823b-34fd-4ce8-9f7d-8a62319fcc94', imageSizeInBytes='1073741824', volumeFormat='COW', newImageId='8ccd22de-11aa-4719-9010-9fa55f4af1ba', imageType='Sparse', newImageDescription='', imageInitialSizeInBytes='0', imageId='4c88e42e-8f13-4c87-a40a-c72802e9ead9', sourceImageGroupId='6391823b-34fd-4ce8-9f7d-8a62319fcc94', shouldAddBitmaps='true', legal='true', sequenceNumber='2', bitmap='null'}), log id: 75e95872

2022-10-01 20:43:39,822+05 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateVolumeVDSCommand] (EE-ManagedThreadFactory-engine-Thread-80383) [65023df7-3d8d-4a72-bc20-ec4525858d74] START, CreateVolumeVDSCommand( CreateVolumeVDSCommandParameters:{storagePoolId='71cf243c-edec-11eb-aa8c-002b6a01557c', ignoreFailoverLimit='false', storageDomainId='1bfb1005-b98d-4592-9c1d-5c04292584ed', imageGroupId='6391823b-34fd-4ce8-9f7d-8a62319fcc94', imageSizeInBytes='1073741824', volumeFormat='COW', newImageId='37bc17ca-ceec-4629-afc4-e2568bc0b6bf', imageType='Sparse', newImageDescription='', imageInitialSizeInBytes='0', imageId='4c88e42e-8f13-4c87-a40a-c72802e9ead9', sourceImageGroupId='6391823b-34fd-4ce8-9f7d-8a62319fcc94', shouldAddBitmaps='true', legal='true', sequenceNumber='3', bitmap='null'}), log id: 5dd824a5
~~~

Resulting in duplicate entries in the images table:

~~~
engine=# select image_guid,image_group_id,parentid,vm_snapshot_id from images where image_group_id = '6391823b-34fd-4ce8-9f7d-8a62319fcc94';
              image_guid              |            image_group_id            |               parentid               |            vm_snapshot_id
--------------------------------------+--------------------------------------+--------------------------------------+--------------------------------------
 8ccd22de-11aa-4719-9010-9fa55f4af1ba | 6391823b-34fd-4ce8-9f7d-8a62319fcc94 | 4c88e42e-8f13-4c87-a40a-c72802e9ead9 | 5e406256-45f2-489d-9a1f-b97136fc2e96 <<<
 37bc17ca-ceec-4629-afc4-e2568bc0b6bf | 6391823b-34fd-4ce8-9f7d-8a62319fcc94 | 4c88e42e-8f13-4c87-a40a-c72802e9ead9 | 5e406256-45f2-489d-9a1f-b97136fc2e96 <<<
 4c88e42e-8f13-4c87-a40a-c72802e9ead9 | 6391823b-34fd-4ce8-9f7d-8a62319fcc94 | 00000000-0000-0000-0000-000000000000 | a1600a79-8e65-4445-af54-5ff2781966f1
(3 rows)
~~~ 
 

Version-Release number of selected component (if applicable):

rhvm-4.5.1.3-0.28.el8ev.noarch

How reproducible:

100%

Steps to Reproduce:

1. Download a snapshot image using https://github.com/oVirt/python-ovirt-engine-sdk4/blob/main/examples/download_disk_snapshot.py
2. Once the disk is downloaded, send a finalize request to the same imagetransfer. The imagetransfer status moves to "Finalizing Success".
3. Do the same flow again which will create two "Finalizing Success" imagetransfer.
4. Try deleting the snapshot.

Actual results:

Image transfer status is changed to "Finalizing Success" if we finalize a "Finished Success" transfer 

Expected results:

The "Finished Success" is the last stage of an imagetransfer and the engine should prevent modifying the imagetransfer status at this stage. 

Additional info:

Comment 3 Michal Skrivanek 2022-10-05 12:20:20 UTC
a duplicate of bug 2123141 / bug 2092816 validating the final status transition

upcoming RHV build contains the fix already, please confirm it fixes this issue

Comment 4 nijin ashok 2022-10-06 03:59:19 UTC
(In reply to Michal Skrivanek from comment #3)
> a duplicate of bug 2123141 / bug 2092816 validating the final status
> transition
> 
> upcoming RHV build contains the fix already, please confirm it fixes this
> issue

Yes, it fixes the issue and blocks the transition.

2022-10-06 09:25:32,654+05 ERROR [org.ovirt.engine.core.bll.storage.disk.image.ImageTransferUpdater] (default task-7) [e562db0c-9f5f-41a6-919f-49b43878d3e8] Image transfer 'a6ff071f-86cb-4965-9979-303374710009' transition from phase 'Finished Success' to 'Finalizing Success' is invalid


Note You need to log in before you can comment on or make changes to this bug.