Bug 1977276 - Uploading ISO through RHV-M portal intermittently fails with error "Failed to add disk for image transfer command"
Summary: Uploading ISO through RHV-M portal intermittently fails with error "Failed to...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: ovirt-engine
Version: 4.4.6
Hardware: All
OS: Linux
unspecified
medium
Target Milestone: ovirt-4.4.9
: ---
Assignee: Nir Soffer
QA Contact: sshmulev
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2021-06-29 11:24 UTC by nijin ashok
Modified: 2021-12-23 16:32 UTC (History)
8 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Previously, in some cases, adding a new disk for the upload succeeded, but the system handled the operation as a failure. AS a result, the upload failed silently without uploading any data and ending in an empty new disk. In this release, the add disk success is detected correctly, and uploading completes successfully.
Clone Of:
Environment:
Last Closed: 2021-11-16 14:46:53 UTC
oVirt Team: Storage
Target Upstream Version:
Embargoed:
sshmulev: testing_plan_complete+

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Knowledge Base (Solution) 6150002 0 None None None 2021-06-29 19:38:24 UTC
Red Hat Product Errata RHSA-2021:4626 0 None None None 2021-11-16 14:47:14 UTC
oVirt gerrit 116520 0 master MERGED core: Fix bogus add disk failure 2021-09-12 11:16:08 UTC
oVirt gerrit 116861 0 ovirt-engine-4.4 MERGED core: Fix bogus add disk failure 2021-09-30 19:43:34 UTC

Description nijin ashok 2021-06-29 11:24:25 UTC 
Description of problem:

Uploading ISO through the RHV-M portal is intermittently failing with the below error in the engine log.

===
2021-06-29 16:27:59,373+05 ERROR [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-48) [efbee3a9-c19d-4bd9-957d-959e8cbb48dd] Failed to add disk for image transfer command '599af07b-3421-481a-b300-99affe1e5002'
===

However, the disk was added successfully.

===
2021-06-29 16:27:58,365+05 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-58) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'CentOS-7-x86_64-Minimal-2009.iso' was successfully added.
====

I was able to add the same ISO on the third attempt.

===
2021-06-29 16:30:48,799+05 INFO  [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-83) [a9caa7a8-e6e5-4f2d-88a8-8fff39b3f569] Successfully added Upload disk 'CentOS-7-x86_64-Minimal-2009-2.iso' (disk id: '97b31fab-4a72-44e9-bb35-a5a3ac7d533c', image id: '1dc5061f-622e-4523-9b62-7f9fa35cd942') for image transfer command '9a5f0631-89ec-4b61-9c9a-403e39c057ed'

2021-06-29 16:30:51,039+05 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-25) [] EVENT_ID: USER_ADD_DISK_FINISHED_SUCCESS(2,021), The disk 'CentOS-7-x86_64-Minimal-2009-2.iso' was successfully added.

2021-06-29 16:37:28,000+05 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-51) [a9caa7a8-e6e5-4f2d-88a8-8fff39b3f569] EVENT_ID: TRANSFER_IMAGE_SUCCEEDED(1,032), Image Upload with disk CentOS-7-x86_64-Minimal-2009-2.iso succeeded.
===

It looks like some sync issue in adding the disk and "image transfer command".

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

rhvm-4.4.6.8-0.1.el8ev.noarch

How reproducible:

3 out of 4 attempts failed in my test environment.

Steps to Reproduce:

1. Upload an ISO to the data storage domain. 

Actual results:

Uploading ISO through RHV-M portal intermittently fails with error "Failed to add disk for image transfer command"

Expected results:

Uploading should work.

Additional info:
Comment 4 Nir Soffer 2021-09-09 09:33:04 UTC 
Also reported on users mailing lists several times. Last report was here:
https://lists.ovirt.org/archives/list/users@ovirt.org/thread/CJISJIDQKSINIJUA5UO6Y4BRFQYEOYLA/
Comment 5 W. de Heiden 2021-09-22 11:55:41 UTC 
Confirmed for oVirt 4.4.8.5-1.el8 on CentOS Stream 8.
Comment 8 sshmulev 2021-10-10 08:18:48 UTC 
Verified.

Version:
ovirt-engine-4.4.9.1-0.13.el8ev.noarch

Steps:
Upload ISO to same storage domains and also different ones successfully.

10 times passed without error log:

2021-10-10 11:05:21,538+03 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-80) [44eb4fc6-01d6-4ec0-bc00-1aa873148d28] EVENT_ID: TRANSFER_IMAGE_SUCCEEDED(1,032), Image Upload with disk hdat2cd_lite_74.iso succeeded.
2021-10-10 11:05:57,002+03 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-95) [e75d21b8-efee-40e5-ab15-64ea81f253d6] EVENT_ID: TRANSFER_IMAGE_SUCCEEDED(1,032), Image Upload with disk hdat2cd_lite_74.iso succeeded.
2021-10-10 11:06:08,722+03 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-85) [430a0590-c938-4cdb-9c14-6ad69d053197] EVENT_ID: TRANSFER_IMAGE_SUCCEEDED(1,032), Image Upload with disk hdat2cd_lite_74.iso succeeded.
2021-10-10 11:06:56,357+03 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-93) [0a2f9d2e-18c1-41ab-bf8d-52d58847bcb5] EVENT_ID: TRANSFER_IMAGE_SUCCEEDED(1,032), Image Upload with disk hdat2cd_lite_74.iso succeeded.
2021-10-10 11:07:24,157+03 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-54) [47fe8cf8-54e4-4098-83d7-3c0914a03a68] EVENT_ID: TRANSFER_IMAGE_SUCCEEDED(1,032), Image Upload with disk hdat2cd_lite_74.iso succeeded.
2021-10-10 11:08:04,109+03 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-26) [8d761818-0d4b-488d-83b5-ea84d4af276c] EVENT_ID: TRANSFER_IMAGE_SUCCEEDED(1,032), Image Upload with disk hdat2cd_lite_74.iso succeeded.
2021-10-10 11:08:46,860+03 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-63) [26c21258-a423-4019-88b2-67643283d651] EVENT_ID: TRANSFER_IMAGE_SUCCEEDED(1,032), Image Upload with disk hdat2cd_lite_74.iso succeeded.
2021-10-10 11:08:46,965+03 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-63) [903faf9d-93e5-48fa-9a7e-709300239408] EVENT_ID: TRANSFER_IMAGE_SUCCEEDED(1,032), Image Upload with disk hdat2cd_lite_74.iso succeeded.
2021-10-10 11:08:56,652+03 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-60) [89d119a5-f068-48e9-b145-09502aacf26d] EVENT_ID: TRANSFER_IMAGE_SUCCEEDED(1,032), Image Upload with disk hdat2cd_lite_74.iso succeeded.
2021-10-10 11:09:06,942+03 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-83) [d1d2c6e6-a636-4d37-bb91-80457e96fdc1] EVENT_ID: TRANSFER_IMAGE_SUCCEEDED(1,032), Image Upload with disk hdat2cd_lite_74.iso succeeded.




Tried the same steps on an older version and it failed on the first try (ovirt-engine-4.4.9-0.6.el8ev.noarch)

2021-10-10 10:51:40,217+03 ERROR [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-22) [660be426-0276-42b7-bc83-df60abe14a21] Failed to add disk for image transfer command '75be1e9d-43ab-4914-acf2-94c0b18f4308'
2021-10-10 10:51:41,259+03 ERROR [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-13) [61eca765] Failed to transfer disk '00000000-0000-0000-0000-000000000000' (command id '75be1e9d-43ab-4914-acf2-94c0b18f4308')
2021-10-10 10:51:41,340+03 ERROR [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-13) [660be426-0276-42b7-bc83-df60abe14a21] Error during log command: org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand: 'NullPointerException: '

2021-10-10 11:07:21,184+03 ERROR [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-53) [2eea4228-ad4f-4206-92cc-1e481367640a] Failed to add disk for image transfer command '13100453-8e42-4142-a168-f2730736126e'
2021-10-10 11:07:22,258+03 ERROR [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-35) [251286ff] Failed to transfer disk '00000000-0000-0000-0000-000000000000' (command id '13100453-8e42-4142-a168-f2730736126e')
2021-10-10 11:07:22,263+03 ERROR [org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-35) [2eea4228-ad4f-4206-92cc-1e481367640a] Error during log command: org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand: 'NullPointerException: '
Comment 12 errata-xmlrpc 2021-11-16 14:46:53 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (Moderate: RHV Manager (ovirt-engine) security update [ovirt-4.4.9]), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2021:4626
Note You need to log in before you can comment on or make changes to this bug.