Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1509635

Summary: Live merge failed after failed to hotplug COW disk on gluster storage domain
Product: [oVirt] ovirt-engine Reporter: Raz Tamir <ratamir>
Component: BLL.StorageAssignee: Ala Hino <ahino>
Status: CLOSED CURRENTRELEASE QA Contact: Raz Tamir <ratamir>
Severity: high Docs Contact:
Priority: unspecified    
Version: 4.2.0CC: ahino, amureini, bugs
Target Milestone: ovirt-4.2.2Keywords: Automation
Target Release: ---Flags: rule-engine: ovirt-4.2+
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-03-29 11:05:23 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Storage RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 1506677    
Bug Blocks:    
Attachments:
Description Flags
engine and vdsm logs none

Description Raz Tamir 2017-11-05 11:02:56 UTC 
Created attachment 1348064 [details]
engine and vdsm logs

Description of problem:
In our automation (tier 1) a basic live merge scenario failed after hitting bug https://bugzilla.redhat.com/show_bug.cgi?id=1506677 with:

** Failure of hotplug disk (engine.log):
2017-11-02 20:53:46,417+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HotPlugDiskVDSCommand] (default task-20) [diskattachments_create_42886781-c3a4] Failed in 'HotPlugDiskVDS' method
2017-11-02 20:53:46,422+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-20) [diskattachments_create_42886781-c3a4] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM host_mixed_1 command HotPl
ugDiskVDS failed: internal error: unable to execute QEMU command '__com.redhat_drive_add': Device 'drive-scsi0-0-0-2' could not be initialized
2017-11-02 20:53:46,422+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HotPlugDiskVDSCommand] (default task-20) [diskattachments_create_42886781-c3a4] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.HotPlugDiskVDSCommand' return v
alue 'StatusOnlyReturn [status=Status [code=45, message=internal error: unable to execute QEMU command '__com.redhat_drive_add': Device 'drive-scsi0-0-0-2' could not be initialized]]'
2017-11-02 20:53:46,422+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HotPlugDiskVDSCommand] (default task-20) [diskattachments_create_42886781-c3a4] HostName = host_mixed_1
2017-11-02 20:53:46,422+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HotPlugDiskVDSCommand] (default task-20) [diskattachments_create_42886781-c3a4] Command 'HotPlugDiskVDSCommand(HostName = host_mixed_1, HotPlugDiskVDSParameters:{
hostId='76e1bc06-f12d-42f9-b451-8d1b0ddad1db', vmId='4367a8e1-8d41-4f5f-bef3-3c3ff79083ae', diskId='7e2c98fe-8017-44d1-8a70-03077755aaf6', addressMap='[bus=0, controller=0, unit=2, type=drive, target=0]'})' execution failed: VDSGenericExc
eption: VDSErrorException: Failed to HotPlugDiskVDS, error = internal error: unable to execute QEMU command '__com.redhat_drive_add': Device 'drive-scsi0-0-0-2' could not be initialized, code = 45
2017-11-02 20:53:46,422+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HotPlugDiskVDSCommand] (default task-20) [diskattachments_create_42886781-c3a4] FINISH, HotPlugDiskVDSCommand, log id: 733b323e
2017-11-02 20:53:46,422+02 ERROR [org.ovirt.engine.core.bll.storage.disk.AttachDiskToVmCommand] (default task-20) [diskattachments_create_42886781-c3a4] Command 'org.ovirt.engine.core.bll.storage.disk.AttachDiskToVmCommand' failed: Engine
Exception: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to HotPlugDiskVDS, error = internal error: unable to execute QEMU command '__com.redhat_drive_add': Device 'drive-scsi0
-0-0-2' could not be initialized, code = 45 (Failed with error FailedToPlugDisk and code 45)

** Failure of this bug (engine.log):
2017-11-02 20:56:17,216+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-9) [snapshots_delete_49ec362f-0df8-42c1] START, MergeVDSCommand(HostName = host_mixed_1, Merge
VDSCommandParameters:{hostId='76e1bc06-f12d-42f9-b451-8d1b0ddad1db', vmId='4367a8e1-8d41-4f5f-bef3-3c3ff79083ae', storagePoolId='e5c02cec-b01e-4220-9247-f06e72819fa6', storageDomainId='12b25a36-a4ad-49cf-8580-250db635173b', imageGroupId='
6ceaf5fb-5c9f-48b2-9a44-61ed134a6dc1', imageId='d9b6cf5e-d439-4a2d-b77b-b32dd24baeb4', baseImageId='ca8e2d63-c929-4404-bf39-8996d5b8fb7d', topImageId='5f470315-34d5-4c80-a6e3-e66d8b72385c', bandwidth='0'}), log id: 28fafeae
2017-11-02 20:56:17,221+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-9) [snapshots_delete_49ec362f-0df8-42c1] Failed in 'MergeVDS' method
2017-11-02 20:56:17,225+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-commandCoordinator-Thread-9) [snapshots_delete_49ec362f-0df8-42c1] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,80
2), VDSM host_mixed_1 command MergeVDS failed: Drive image file could not be found
2017-11-02 20:56:17,225+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-9) [snapshots_delete_49ec362f-0df8-42c1] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.Me
rgeVDSCommand' return value 'StatusOnlyReturn [status=Status [code=13, message=Drive image file could not be found]]'
2017-11-02 20:56:17,225+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-9) [snapshots_delete_49ec362f-0df8-42c1] HostName = host_mixed_1
2017-11-02 20:56:17,225+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-9) [snapshots_delete_49ec362f-0df8-42c1] Command 'MergeVDSCommand(HostName = host_mixed_1, MergeVDSCommandParameters:{hostId='76e1bc06-f12d-42f9-b451-8d1b0ddad1db', vmId='4367a8e1-8d41-4f5f-bef3-3c3ff79083ae', storagePoolId='e5c02cec-b01e-4220-9247-f06e72819fa6', storageDomainId='12b25a36-a4ad-49cf-8580-250db635173b', imageGroupId='6ceaf5fb-5c9f-48b2-9a44-61ed134a6dc1', imageId='d9b6cf5e-d439-4a2d-b77b-b32dd24baeb4', baseImageId='ca8e2d63-c929-4404-bf39-8996d5b8fb7d', topImageId='5f470315-34d5-4c80-a6e3-e66d8b72385c', bandwidth='0'})' execution failed: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Drive image file could not be found, code = 13
2017-11-02 20:56:17,225+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-9) [snapshots_delete_49ec362f-0df8-42c1] FINISH, MergeVDSCommand, log id: 28fafeae
2017-11-02 20:56:17,228+02 INFO  [org.ovirt.engine.core.bll.MergeCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-6) [snapshots_delete_49ec362f-0df8-42c1] Running command: MergeCommand internal: true. Entities affected :  ID: 12b25a36-a4ad-49cf-8580-250db635173b Type: Storage
2017-11-02 20:56:17,225+02 ERROR [org.ovirt.engine.core.bll.MergeCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-9) [snapshots_delete_49ec362f-0df8-42c1] Engine exception thrown while sending merge command: org.ovirt.engine.core.common.errors.EngineException: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Drive image file could not be found, code = 13 (Failed with error imageErr and code 13)
        at org.ovirt.engine.core.bll.VdsHandler.handleVdsResult(VdsHandler.java:118) [bll.jar:]

** Failure in vdsm side:
2017-11-02 20:56:17,218+0200 INFO  (jsonrpc/2) [api.virt] START merge(drive={'poolID': 'e5c02cec-b01e-4220-9247-f06e72819fa6', 'volumeID': 'd9b6cf5e-d439-4a2d-b77b-b32dd24baeb4', 'domainID': '12b25a36-a4ad-49cf-8580-250db635173b', 'imageID': '6ceaf5fb-5c9f-48b2-9a44-61ed134a6dc1'}, baseVolUUID='ca8e2d63-c929-4404-bf39-8996d5b8fb7d', topVolUUID='5f470315-34d5-4c80-a6e3-e66d8b72385c', bandwidth='0', jobUUID='93add9d8-bb2e-4b99-992c-7e5a03c9a4eb') from=::ffff:10.35.69.94,56944, flow_id=snapshots_delete_49ec362f-0df8-42c1 (api:46)
2017-11-02 20:56:17,219+0200 INFO  (jsonrpc/2) [api.virt] FINISH merge return={'status': {'message': 'Drive image file could not be found', 'code': 13}} from=::ffff:10.35.69.94,56944, flow_id=snapshots_delete_49ec362f-0df8-42c1 (api:52)
2017-11-02 20:56:17,219+0200 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call VM.merge failed (error 13) in 0.00 seconds (__init__:630)
2017-11-02 20:56:17,232+0200 INFO  (jsonrpc/1) [api.virt] START merge(drive={'poolID': 'e5c02cec-b01e-4220-9247-f06e72819fa6', 'volumeID': 'ad193f43-ea92-45a4-832d-bd5fa7277429', 'domainID': '12b25a36-a4ad-49cf-8580-250db635173b', 'imageID': '51bec397-38a9-46ae-9f47-6e8ddab75d71'}, baseVolUUID='c404644c-0df1-4a87-8895-5963ff87030d', topVolUUID='e283982f-cf55-4f6c-91bc-56157ceafae2', bandwidth='0', jobUUID='ed6a7086-835e-4474-9bf3-5641795869e5') from=::ffff:10.35.69.94,56944, flow_id=snapshots_delete_49ec362f-0df8-42c1 (api:46)


Version-Release number of selected component (if applicable):
ovirt-engine-4.2.0-0.0.master.20171101152059.git8b85834.el7.centos.noarch

How reproducible:
Failed only on gluster storage type 

Steps to Reproduce:
1. Create a VM + os disk and + 4 disks from all permutations available (alloc policy, format, interface)
2. Hotplug disks to VM. --> COW disk will fail on bug #1506677
3. Create snapshot
4. live merge it

Actual results:


Expected results:


Additional info:
Comment 1 Allon Mureinik 2017-11-22 09:29:50 UTC 
No RCA, pushing out.
Comment 2 Allon Mureinik 2017-12-20 11:46:36 UTC 
Ala, once 1506677 is resolved, is there any AI on live merge's side?
Comment 3 Ala Hino 2017-12-20 11:57:53 UTC 
(In reply to Allon Mureinik from comment #2)
> Ala, once 1506677 is resolved, is there any AI on live merge's side?

Not really. Once 1506677 is verified, this one can be moved to ON_QA.
Comment 4 Yaniv Kaul 2017-12-31 11:48:21 UTC 
(In reply to Ala Hino from comment #3)
> (In reply to Allon Mureinik from comment #2)
> > Ala, once 1506677 is resolved, is there any AI on live merge's side?
> 
> Not really. Once 1506677 is verified, this one can be moved to ON_QA.

Bug 1506677 is ON_QA - can we move this one as well?
Comment 5 Ala Hino 2017-12-31 12:13:19 UTC 
While I don't expect any work from my side, I wanted to wait until bug 1506677 is verified.

Moving to ON_QA.
Comment 6 Raz Tamir 2018-01-01 12:01:55 UTC 
Verified on rhvm-4.2.0.2-0.1
Passed automation run
Comment 7 Sandro Bonazzola 2018-03-29 11:05:23 UTC 
This bugzilla is included in oVirt 4.2.2 release, published on March 28th 2018.

Since the problem described in this bug report should be
resolved in oVirt 4.2.2 release, it has been closed with a resolution of CURRENT RELEASE.

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