Bug 1177220

Summary: RHEV: Failed to Delete First snapshot with live merge
Product: Red Hat Enterprise Virtualization Manager Reporter: rhev-integ
Component: ovirt-engineAssignee: Adam Litke <alitke>
Status: CLOSED ERRATA QA Contact: Kevin Alon Goldblatt <kgoldbla>
Severity: urgent Docs Contact:
Priority: urgent    
Version: 3.5.0CC: acanan, alitke, amureini, bkorren, ecohen, fsimonce, gklein, iheim, juwu, kgoldbla, lkuchlan, lpeer, lsurette, mst, nsoffer, pnovotny, rbalakri, Rhev-m-bugs, sbonazzo, scohen, sherold, tnisan, yeylon, ylavi
Target Milestone: ---Keywords: Reopened, ZStream
Target Release: 3.5.1Flags: ylavi: Triaged+
Hardware: x86_64   
OS: Unspecified   
Whiteboard: storage
Fixed In Version: vdsm-4.16.13.1-1.el6ev Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: 1158563 Environment:
Last Closed: 2015-04-28 18:42:16 UTC Type: ---
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: 1158563, 1199182    
Bug Blocks: 647386, 1193058, 1196199, 1197441    
Attachments:
Description Flags
server, engine and vdsm logs
none
vdsm log with libvirt debugging info
none
virsh-based reproducer none

Comment 2 Kevin Alon Goldblatt 2015-03-02 10:41:22 UTC 
I ran the original scenario again as follows with vt14on 3.5.1:

Steps to Reproduce:
1. Create a vm with 4 disks (2 thin provisioned and 2 preallocated nfs disks) ans start the VM
2. Created snapshots1, snapshot2, snapshot3 and snapshot4 
3. Deleted snapshot 3 successfully
4. Deleted snapshot 2 successfully
5. Deleted snapshot 4 successfully
6. Failed to delete snapshot 1 with 'failed to MergVDS'

Actual results:
Failed to delete snapshot1

Expected results:
Should be able to delete the first snapshot


Output from the engine log:
-----------------------------
Start delete snapshot of snapshot1
------------------------------------------------
2015-03-02 11:24:03,677 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp-/127.0.0.1:8702-11) Correlation ID: 53bc6a4d, Job ID: 0fa416a2-82fa-43d2-87c1-
d281f1fd2f7c, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'snapshot1' deletion for VM '1177220' was initiated by admin@internal.
.
.
.
2015-03-02 11:24:12,872 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-7) [5e6d7d84] Failed in MergeVDS method
2015-03-02 11:24:12,873 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-7) [5e6d7d84] Command org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand
 return value 
 StatusOnlyReturnForXmlRpc [mStatus=StatusForXmlRpc [mCode=52, mMessage=Merge failed]]
2015-03-02 11:24:12,873 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-7) [5e6d7d84] HostName = nott-vds2
2015-03-02 11:24:12,873 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-7) [5e6d7d84] Command MergeVDSCommand(HostName = nott-vds2, MergeVDSCommandPara
meters{HostId = 7173011f-fc6a-47c3-8ea9-753f2e32be6f, vmId=8337e66a-fdb5-4ec3-9a80-d28153294ebb, storagePoolId=6d96f52d-d791-4f66-83bd-2553ca0f3012, storageDomainId=17eac76f-4aaa-4d99-
8f1a-b7f6e68e4c70, imageGroupId=8a0a7339-b381-4ab3-8420-51bf203424e6, imageId=d093cd5a-7f4c-42f0-a311-6ee70d45c151, baseImageId=b833794f-9cc2-492b-8256-10fd1c8fbceb, topImageId=d093cd5
a-7f4c-42f0-a311-6ee70d45c151, bandwidth=0}) execution failed. Exception: VDSErrorException: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Merge failed, code = 52
2015-03-02 11:24:12,874 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-7) [5e6d7d84] FINISH, MergeVDSCommand, log id: 770ddf71
2015-03-02 11:24:12,874 ERROR [org.ovirt.engine.core.bll.MergeCommand] (pool-6-thread-7) [5e6d7d84] Command org.ovirt.engine.core.bll.MergeCommand throw Vdc Bll exception. With error m
essage VdcBLLException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Merge failed, code = 52 (Failed
 with error mergeErr and code 52)
2015-03-02 11:24:12,890 ERROR [org.ovirt.engine.core.bll.MergeCommand] (pool-6-thread-7) [5e6d7d84] Transaction rolled-back for command: org.ovirt.engine.core.bll.MergeCommand.
2015-03-02 11:24:12,937 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-8) [4bdb13d1] Failed in MergeVDS method
2015-03-02 11:24:12,938 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-8) [4bdb13d1] Command org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand
 return value 
 StatusOnlyReturnForXmlRpc [mStatus=StatusForXmlRpc [mCode=52, mMessage=Merge failed]]
2015-03-02 11:24:12,938 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-8) [4bdb13d1] HostName = nott-vds2
2015-03-02 11:24:12,938 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-8) [4bdb13d1] Command MergeVDSCommand(HostName = nott-vds2, MergeVDSCommandPara
meters{HostId = 7173011f-fc6a-47c3-8ea9-753f2e32be6f, vmId=8337e66a-fdb5-4ec3-9a80-d28153294ebb, storagePoolId=6d96f52d-d791-4f66-83bd-2553ca0f3012, storageDomainId=17eac76f-4aaa-4d99-
8f1a-b7f6e68e4c70, imageGroupId=10eec39a-43f3-4acc-a76f-60fcc94b3020, imageId=276be698-8354-4173-ba69-280984c397c9, baseImageId=53544783-7eb5-4ee3-b60d-c9b50e2264bb, topImageId=276be69
8-8354-4173-ba69-280984c397c9, bandwidth=0}) execution failed. Exception: VDSErrorException: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Merge failed, code = 52
2015-03-02 11:24:12,938 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-8) [4bdb13d1] FINISH, MergeVDSCommand, log id: 48a85303
2015-03-02 11:24:12,939 ERROR [org.ovirt.engine.core.bll.MergeCommand] (pool-6-thread-8) [4bdb13d1] Command org.ovirt.engine.core.bll.MergeCommand throw Vdc Bll exception. With error m
essage VdcBLLException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Merge failed, code = 52 (Failed
 with error mergeErr and code 52)
2015-03-02 11:24:12,946 ERROR [org.ovirt.engine.core.bll.MergeCommand] (pool-6-thread-8) [4bdb13d1] Transaction rolled-back for command: org.ovirt.engine.core.bll.MergeCommand.
2015-03-02 11:24:12,981 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-9) [278f44a7] Failed in MergeVDS method
2015-03-02 11:24:12,982 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-9) [278f44a7] Command org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand
 return value 
 StatusOnlyReturnForXmlRpc [mStatus=StatusForXmlRpc [mCode=52, mMessage=Merge failed]]
2015-03-02 11:24:12,982 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-9) [278f44a7] HostName = nott-vds2
2015-03-02 11:24:12,982 ERROR [org.ovirt.engine.core.bll.MergeCommand] (pool-6-thread-9) [278f44a7] Command org.ovirt.engine.core.bll.MergeCommand throw Vdc Bll exception. With error m
essage VdcBLLException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Merge failed, code = 52 (Failed
 with error mergeErr and code 52)
2015-03-02 11:24:12,991 ERROR [org.ovirt.engine.core.bll.MergeCommand] (pool-6-thread-9) [278f44a7] Transaction rolled-back for command: org.ovirt.engine.core.bll.MergeCommand.
2015-03-02 11:24:13,156 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-1) [7791461f] Failed in MergeVDS method
2015-03-02 11:24:13,157 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-1) [7791461f] Command org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand
 return value 
 StatusOnlyReturnForXmlRpc [mStatus=StatusForXmlRpc [mCode=52, mMessage=Merge failed]]
2015-03-02 11:24:13,157 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-1) [7791461f] HostName = nott-vds2
2015-03-02 11:24:13,157 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-1) [7791461f] Command MergeVDSCommand(HostName = nott-vds2, MergeVDSCommandPara
meters{HostId = 7173011f-fc6a-47c3-8ea9-753f2e32be6f, vmId=8337e66a-fdb5-4ec3-9a80-d28153294ebb, storagePoolId=6d96f52d-d791-4f66-83bd-2553ca0f3012, storageDomainId=17eac76f-4aaa-4d99-
8f1a-b7f6e68e4c70, imageGroupId=93801238-31ac-4dbe-a666-586de6fb7aeb, imageId=d5d609c8-85f0-43b9-8dde-c6e15765a0b5, baseImageId=910fb15a-f231-418a-a942-98e920154513, topImageId=d5d609c
8-85f0-43b9-8dde-c6e15765a0b5, bandwidth=0}) execution failed. Exception: VDSErrorException: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Merge failed, code = 52
2015-03-02 11:24:13,157 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-6-thread-1) [7791461f] FINISH, MergeVDSCommand, log id: 5f2e2158
2015-03-02 11:24:13,158 ERROR [org.ovirt.engine.core.bll.MergeCommand] (pool-6-thread-1) [7791461f] Command org.ovirt.engine.core.bll.MergeCommand throw Vdc Bll exception. With error m
essage VdcBLLException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Merge failed, code = 52 (Failed
 with error mergeErr and code 52)
2015-03-02 11:24:13,171 ERROR [org.ovirt.engine.core.bll.MergeCommand] (pool-6-thread-1) [7791461f] Transaction rolled-back for command: org.ovirt.engine.core.bll.MergeCommand.
2015-03-02 11:24:17,929 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-59) [3691c6ce] task id cdd8de82-e20a-4737-9bb7-79875e715142 is in pre-pollin
g  period and should not be polled. Pre-polling period is 60,000 millis. 
2015-03-02 11:24:17,930 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-59) [3691c6ce] task id df56ccf9-5a00-464b-a3a7-7e1267bbd867 is in pre-pollin
g  period and should not be polled. Pre-polling period is 60,000 millis. 
2015-03-02 11:24:22,381 ERROR [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-73) [6ec56323] Failed child command status for step MERGE
2015-03-02 11:24:22,390 ERROR [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-73) [74fc8f2a] Failed child command status for step MERGE
2015-03-02 11:24:22,398 ERROR [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-73) [450d784c] Failed child command status for step MERGE
2015-03-02 11:24:22,403 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-73) [450d784c] Waiting on Live Merge child commands to complete
2015-03-02 11:24:22,416 ERROR [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-73) [2e4efc4d] Failed child command status for step MERGE
2015-03-02 11:24:27,931 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-90) task id cdd8de82-e20a-4737-9bb7-79875e715142 is in pre-polling  period a
nd should not be polled. Pre-polling period is 60,000 millis. 
2015-03-02 11:24:27,931 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-90) task id df56ccf9-5a00-464b-a3a7-7e1267bbd867 is in pre-polling  period a
nd should not be polled. Pre-polling period is 60,000 millis. 
2015-03-02 11:24:32,443 ERROR [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-25) [6ec56323] Merging of snapshot ee76694c-f0f6-42d6-9f0d-
5c73918dbdbe images b833794f-9cc2-492b-8256-10fd1c8fbceb..d093cd5a-7f4c-42f0-a311-6ee70d45c151 failed. Images have been marked illegal and can no longer be previewed or reverted to. Pl
ease retry Live Merge on the snapshot to complete the operation.
2015-03-02 11:24:32,457 ERROR [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-25) [74fc8f2a] Merging of snapshot ee76694c-f0f6-42d6-9f0d-5c73918dbdbe images 53544783-7eb5-4ee3-b60d-c9b50e2264bb..276be698-8354-4173-ba69-280984c397c9 failed. Images have been marked illegal and can no longer be previewed or reverted to. Please retry Live Merge on the snapshot to complete the operation.
2015-03-02 11:24:32,479 ERROR [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-25) [450d784c] Merging of snapshot ee76694c-f0f6-42d6-9f0d-5c73918dbdbe images 31d92706-5eca-48e4-a27c-654e68b4be62..57801c1d-78e8-4692-b963-fd0226d5a878 failed. Images have been marked illegal and can no longer be previewed or reverted to. Please retry Live Merge on the snapshot to complete the operation
.
.
.
2015-03-02 11:24:32,486 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-25) [53bc6a4d] All Live Merge child commands have completed, status FAILED
2015-03-02 11:24:32,499 ERROR [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-25) [2e4efc4d] Merging of snapshot ee76694c-f0f6-42d6-9f0d-5c73918dbdbe images 910fb15a-f231-418a-a942-98e920154513..d5d609c8-85f0-43b9-8dde-c6e15765a0b5 failed. Images have been marked illegal and can no longer be previewed or reverted to. Please retry Live Merge on the snapshot to complete the operation.
2015-03-02 11:24:37,932 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-1) [791968d0] task id cdd8de82-e20a-4737-9bb7-79875e715142 is in pre-polling  period and should not be polled. Pre-polling period is 60,000 millis. 
2015-03-02 11:24:37,932 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-1) [791968d0] task id df56ccf9-5a00-464b-a3a7-7e1267bbd867 is in pre-polling  period and should not be polled. Pre-polling period is 60,000 millis. 
2015-03-02 11:24:42,510 ERROR [org.ovirt.engine.core.bll.RemoveSnapshotCommand] (DefaultQuartzScheduler_Worker-38) [53bc6a4d] Ending command with failure: org.ovirt.engine.core.bll.RemoveSnapshotCommand
2015-03-02 11:24:42,541 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-38) [53bc6a4d] Correlation ID: 53bc6a4d, Call Stack: null, Custom Event ID: -1, Message: Failed to delete snapshot 'snapshot1' for VM '1177220'.



Output from vdsm log on nott-vds2
-----------------------------------------
Thread-44056::DEBUG::2015-03-02 11:24:12,902::task::993::Storage.TaskManager.Task::(_decref) Task=`6c5f5272-658d-46f0-9453-5e1bbe8d1bf0`::ref 0 aborting False
Thread-44054::INFO::2015-03-02 11:24:12,915::vm::5865::vm.Vm::(merge) vmId=`8337e66a-fdb5-4ec3-9a80-d28153294ebb`::Starting merge with jobUUID='40d38c50-0c79-4d11-b391-9f108d8cdb48'
Thread-44054::DEBUG::2015-03-02 11:24:12,922::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 1 edom: 10 level: 2 message: internal error: unable to execute QEMU command 'block-commit': Top image file /rhev/data-center/6d96f52d-d791-4f66-83bd-2553ca0f3012/17eac76f-4aaa-4d99-8f1a-b7f6e68e4c70/images/10eec39a-43f3-4acc-a76f-60fcc94b3020/../10eec39a-43f3-4acc-a76f-60fcc94b3020/../10eec39a-43f3-4acc-a76f-60fcc94b3020/../10eec39a-43f3-4acc-a76f-60fcc94b3020/276be698-8354-4173-ba69-280984c397c9 not found
Thread-44054::ERROR::2015-03-02 11:24:12,922::vm::5873::vm.Vm::(merge) vmId=`8337e66a-fdb5-4ec3-9a80-d28153294ebb`::Live merge failed (job: 40d38c50-0c79-4d11-b391-9f108d8cdb48)
Traceback (most recent call last):
  File "/usr/share/vdsm/virt/vm.py", line 5869, in merge
    flags)
  File "/usr/share/vdsm/virt/vm.py", line 689, in f
    ret = attr(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/libvirtconnection.py", line 111, in wrapper
    ret = f(*args, **kwargs)
  File "/usr/lib64/python2.7/site-packages/libvirt.py", line 630, in blockCommit
    if ret == -1: raise libvirtError ('virDomainBlockCommit() failed', dom=self)
libvirtError: internal error: unable to execute QEMU command 'block-commit': Top image file /rhev/data-center/6d96f52d-d791-4f66-83bd-2553ca0f3012/17eac76f-4aaa-4d99-8f1a-b7f6e68e4c70/images/10eec39a-43f3-4acc-a76f-60fcc94b3020/../10eec39a-43f3-4acc-a76f-60fcc94b3020/../10eec39a-43f3-4acc-a76f-60fcc94b3020/../10eec39a-43f3-4acc-a76f-60fcc94b3020/276be698-8354-4173-ba69-280984c397c9 not found
Thread-44054::DEBUG::2015-03-02 11:24:12,938::stompReactor::163::yajsonrpc.StompServer::(send) Sending response
Thread-44055::INFO::2015-03-02 11:24:12,959::vm::5865::vm.Vm::(merge) vmId=`8337e66a-fdb5-4ec3-9a80-d28153294ebb`::Starting merge with jobUUID='5e6bf76d-ada3-4a4c-8eea-8ef8d92fe631'
Thread-44055::DEBUG::2015-03-02 11:24:12,966::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 1 edom: 10 level: 2 message: internal error: unable to execute QEMU command 'block-commit': Top image file /rhev/data-center/6d96f52d-d791-4f66-83bd-2553ca0f3012/17eac76f-4aaa-4d99-8f1a-b7f6e68e4c70/images/cc37393d-a848-4f72-b884-fb306c412702/../cc37393d-a848-4f72-b884-fb306c412702/../cc37393d-a848-4f72-b884-fb306c412702/../cc37393d-a848-4f72-b884-fb306c412702/57801c1d-78e8-4692-b963-fd0226d5a878 not found
Thread-44055::ERROR::2015-03-02 11:24:12,966::vm::5873::vm.Vm::(merge) vmId=`8337e66a-fdb5-4ec3-9a80-d28153294ebb`::Live merge failed (job: 5e6bf76d-ada3-4a4c-8eea-8ef8d92fe631)
Traceback (most recent call last):
  File "/usr/share/vdsm/virt/vm.py", line 5869, in merge
    flags)
  File "/usr/share/vdsm/virt/vm.py", line 689, in f
    ret = attr(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/libvirtconnection.py", line 111, in wrapper
    ret = f(*args, **kwargs)
  File "/usr/lib64/python2.7/site-packages/libvirt.py", line 630, in blockCommit
    if ret == -1: raise libvirtError ('virDomainBlockCommit() failed', dom=self)
libvirtError: internal error: unable to execute QEMU command 'block-commit': Top image file /rhev/data-center/6d96f52d-d791-4f66-83bd-2553ca0f3012/17eac76f-4aaa-4d99-8f1a-b7f6e68e4c70/images/cc37393d-a848-4f72-b884-fb306c412702/../cc37393d-a848-4f72-b884-fb306c412702/../cc37393d-a848-4f72-b884-fb306c412702/../cc37393d-a848-4f72-b884-fb306c412702/57801c1d-78e8-4692-b963-fd0226d5a878 not found
Thread-44055::DEBUG::2015-03-02 11:24:12,982::stompReactor::163::yajsonrpc.StompServer::(send) Sending response
Thread-44056::INFO::2015-03-02 11:24:13,048::vm::5865::vm.Vm::(merge) vmId=`8337e66a-fdb5-4ec3-9a80-d28153294ebb`::Starting merge with jobUUID='7f284384-575d-484b-a007-9470dc02728c'
Thread-44056::DEBUG::2015-03-02 11:24:13,057::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 1 edom: 10 level: 2 message: internal error: unable to execute QEMU command 'block-commit': Top image file /rhev/data-center/6d96f52d-d791-4f66-83bd-2553ca0f3012/17eac76f-4aaa-4d99-8f1a-b7f6e68e4c70/images/93801238-31ac-4dbe-a666-586de6fb7aeb/../93801238-31ac-4dbe-a666-586de6fb7aeb/../93801238-31ac-4dbe-a666-586de6fb7aeb/../93801238-31ac-4dbe-a666-586de6fb7aeb/d5d609c8-85f0-43b9-8dde-c6e15765a0b5 not found
Thread-44056::ERROR::2015-03-02 11:24:13,058::vm::5873::vm.Vm::(merge) vmId=`8337e66a-fdb5-4ec3-9a80-d28153294ebb`::Live merge failed (job: 7f284384-575d-484b-a007-9470dc02728c)
Traceback (most recent call last):
  File "/usr/share/vdsm/virt/vm.py", line 5869, in merge
Comment 3 Kevin Alon Goldblatt 2015-03-02 10:55:54 UTC 
Created attachment 997018 [details]
server, engine and vdsm logs

Reopend this bz. Added logs.

The relevant vdsm log is the log from nott-vds2
Comment 4 Nir Soffer 2015-03-02 21:55:03 UTC 
I have seen this error:

libvirtError: internal error: unable to execute QEMU command 'block-commit': Top image file /rhev/data-center/6d96f52d-d791-4f66-83bd-2553ca0f3012/17eac76f-4aaa-4d99-8f1a-b7f6e68e4c70/images/cc37393d-a848-4f72-b884-fb306c412702/../cc37393d-a848-4f72-b884-fb306c412702/../cc37393d-a848-4f72-b884-fb306c412702/../cc37393d-a848-4f72-b884-fb306c412702/57801c1d-78e8-4692-b963-fd0226d5a878 not found
Thread-44055::DEBUG::2015-03-02 

On Fedora 21, when deleting snapshot after live storage migration.
This error went away when using patch https://gerrit.ovirt.org/38201
using new VIR_DOMAIN_BLOCK_REBASE_COPY_DEV flag.

Kevin:

- can you share output of:
  rpm -qa | grep libvirt
- did you do live storage migration with this disk before the test?
Comment 5 Nir Soffer 2015-03-02 23:22:34 UTC 
Created attachment 997264 [details]
vdsm log with libvirt debugging info

Reproduced with block storage on Fedora 21 (the error did not went away as
I suggest in comment 4).

Using master with modified version of https://gerrit.ovirt.org/38018
adding domain xml before/after blockCommit and tryPivot
Comment 6 Kevin Alon Goldblatt 2015-03-03 08:50:02 UTC 
(In reply to Nir Soffer from comment #4)
> I have seen this error:
> 
> libvirtError: internal error: unable to execute QEMU command 'block-commit':
> Top image file
> /rhev/data-center/6d96f52d-d791-4f66-83bd-2553ca0f3012/17eac76f-4aaa-4d99-
> 8f1a-b7f6e68e4c70/images/cc37393d-a848-4f72-b884-fb306c412702/../cc37393d-
> a848-4f72-b884-fb306c412702/../cc37393d-a848-4f72-b884-fb306c412702/../
> cc37393d-a848-4f72-b884-fb306c412702/57801c1d-78e8-4692-b963-fd0226d5a878
> not found
> Thread-44055::DEBUG::2015-03-02 
> 
> On Fedora 21, when deleting snapshot after live storage migration.
> This error went away when using patch https://gerrit.ovirt.org/38201
> using new VIR_DOMAIN_BLOCK_REBASE_COPY_DEV flag.
> 
> Kevin:
> 
> - can you share output of:
>   rpm -qa | grep libvirt
Output as requested:
libvirt-daemon-driver-nwfilter-1.2.8-16.el7.x86_64
libvirt-daemon-driver-secret-1.2.8-16.el7.x86_64
libvirt-daemon-1.2.8-16.el7.x86_64
libvirt-python-1.2.8-7.el7.x86_64
libvirt-daemon-driver-interface-1.2.8-16.el7.x86_64
libvirt-lock-sanlock-1.2.8-16.el7.x86_64
libvirt-daemon-driver-qemu-1.2.8-16.el7.x86_64
libvirt-daemon-driver-storage-1.2.8-16.el7.x86_64
libvirt-client-1.2.8-16.el7.x86_64
libvirt-daemon-config-nwfilter-1.2.8-16.el7.x86_64
libvirt-daemon-driver-nodedev-1.2.8-16.el7.x86_64
libvirt-daemon-driver-network-1.2.8-16.el7.x86_64
libvirt-daemon-kvm-1.2.8-16.el7.x86_64

> - did you do live storage migration with this disk before the test?
No I did not do live storage migration before with this disk
Comment 7 Adam Litke 2015-03-03 14:08:12 UTC 
On December 10th you verified this bug.  Is there any way you can tell us which versions of libvirt and qemu you were using?  We're trying to identify any possible regressions in qemu or libvirt.
Comment 8 Kevin Alon Goldblatt 2015-03-04 08:45:32 UTC 
(In reply to Adam Litke from comment #7)
> On December 10th you verified this bug.  Is there any way you can tell us
> which versions of libvirt and qemu you were using?  We're trying to identify
> any possible regressions in qemu or libvirt.

I used the following:
wget /http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-1.2.8-10.el7ost.src.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-1.2.8-10.el7ost.x86_64.r/pm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-client-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-config-network-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-config-nwfilter-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-driver-interface-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-driver-lxc-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-driver-network-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-driver-nodedev-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-driver-nwfilter-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-driver-qemu-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-driver-secret-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-driver-storage-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-kvm-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-lxc-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-debuginfo-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-devel-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-docs-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-lock-sanlock-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-login-shell-1.2.8-10.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-python-1.2.8-6.el7ost.src.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-python-1.2.8-6.el7ost.x86_64.rpm
wget http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-python-debuginfo-1.2.8-6.el7ost.x86_64.rpm
Comment 9 Kevin Alon Goldblatt 2015-03-04 08:47:33 UTC 
(In reply to Kevin Alon Goldblatt from comment #8)
> (In reply to Adam Litke from comment #7)
> > On December 10th you verified this bug.  Is there any way you can tell us
> > which versions of libvirt and qemu you were using?  We're trying to identify
> > any possible regressions in qemu or libvirt.
> 
> I used the following:
> wget
> /http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-1.2.8-10.el7ost.src.
> rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-1.2.8-10.el7ost.x86_64.
> r/pm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-client-1.2.8-10.el7ost.
> x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-1.2.8-10.el7ost.
> x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-config-network-
> 1.2.8-10.el7ost.x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-config-nwfilter-
> 1.2.8-10.el7ost.x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-driver-
> interface-1.2.8-10.el7ost.x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-driver-lxc-1.2.
> 8-10.el7ost.x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-driver-network-
> 1.2.8-10.el7ost.x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-driver-nodedev-
> 1.2.8-10.el7ost.x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-driver-nwfilter-
> 1.2.8-10.el7ost.x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-driver-qemu-1.2.
> 8-10.el7ost.x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-driver-secret-1.
> 2.8-10.el7ost.x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-driver-storage-
> 1.2.8-10.el7ost.x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-kvm-1.2.8-10.
> el7ost.x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-daemon-lxc-1.2.8-10.
> el7ost.x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-debuginfo-1.2.8-10.
> el7ost.x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-devel-1.2.8-10.el7ost.
> x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-docs-1.2.8-10.el7ost.
> x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-lock-sanlock-1.2.8-10.
> el7ost.x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-login-shell-1.2.8-10.
> el7ost.x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-python-1.2.8-6.el7ost.
> src.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-python-1.2.8-6.el7ost.
> x86_64.rpm
> wget
> http://people.redhat.com/jdenemar/libvirt/7.0/libvirt-python-debuginfo-1.2.8-
> 6.el7ost.x86_64.rpm



I installed the above on 12/12/14
Comment 10 Allon Mureinik 2015-03-04 09:09:50 UTC 
libvirt-1.2.8-10? Doesn't RHEL7.1 deliver libvort-1.2.8-16?
Comment 11 Adam Litke 2015-03-05 14:53:06 UTC 
Created attachment 998419 [details]
virsh-based reproducer

Here is a script I created which reproduces the issue without oVirt involved.
Comment 12 Adam Litke 2015-03-05 15:11:37 UTC 
This is a confirmed issue with either libvirt or qemu.  Eric Blake is investigating the issue.  For now, the workaround is to power off and on the VM before attempting to live merge the snapshots :(
Comment 13 Nir Soffer 2015-03-11 13:06:39 UTC 
Not related to NFS, reproduced on block storage, see comment 5.
Comment 14 Adam Litke 2015-03-11 20:24:15 UTC 
I talked with Eric Blake today and his plan is to get a fix into libvirt in time for the next RHEL-7.1 z-stream build (probably end of March) and a Fedora build at that same time.
Comment 15 Allon Mureinik 2015-03-15 20:08:58 UTC 
(In reply to Adam Litke from comment #14)
> I talked with Eric Blake today and his plan is to get a fix into libvirt in
> time for the next RHEL-7.1 z-stream build (probably end of March) and a
> Fedora build at that same time.
Adam, is there any action item on us, besides requiring the newer libvirt build?
If not, I wonder if it's worth the effort for our QA to start engaging Eric's scratch build mentioned on bug 1199182.
Comment 16 Adam Litke 2015-03-17 20:36:47 UTC 
No action for us.  Yes, I'd recommend that QE use Eric's build since it seems to have resolved the issue for me locally.
Comment 17 Allon Mureinik 2015-03-18 13:43:47 UTC 
Kevin, can we early engage the libvirt version proposed in bug 1203119 ?
Comment 20 Julie 2015-03-20 05:41:10 UTC 
Hi Adam,
If this bug requires doc text for errata release, please provide draft text in the doc text field in the following format:

Cause:
Consequence:
Fix:
Result:

The documentation team will review, edit, and approve the text.

If this bug does not require doc text, please set the 'requires_doc_text' flag to -.
Comment 21 Kevin Alon Goldblatt 2015-03-22 12:53:50 UTC 
(In reply to Allon Mureinik from comment #17)
> Kevin, can we early engage the libvirt version proposed in bug 1203119 ?

I ran the scenario above with v3.5.1 vt14 and the libvirt rpms provided in:


The test PASSED successfully.


http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/


wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-client-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-daemon-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-daemon-config-network-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-daemon-config-nwfilter-1.2.8-16.el7_1.2.x86_64.rpm 
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-daemon-driver-interface-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-daemon-driver-lxc-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-daemon-driver-network-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-daemon-driver-nodedev-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-daemon-driver-nwfilter-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-daemon-driver-qemu-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-daemon-driver-secret-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-daemon-driver-storage-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-daemon-kvm-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-daemon-lxc-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-debuginfo-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-devel-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-docs-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-lock-sanlock-1.2.8-16.el7_1.2.x86_64.rpm
wget http://download.devel.redhat.com/brewroot/packages/libvirt/1.2.8/16.el7_1.2/x86_64/libvirt-login-shell-1.2.8-16.el7_1.2.x86_64.rpm
Comment 22 Allon Mureinik 2015-03-22 14:22:47 UTC 
(In reply to Kevin Alon Goldblatt from comment #21)
> (In reply to Allon Mureinik from comment #17)
> > Kevin, can we early engage the libvirt version proposed in bug 1203119 ?
> 
> I ran the scenario above with v3.5.1 vt14 and the libvirt rpms provided in:
> 
> 
> The test PASSED successfully.
Great news!
Thanks Kevin!

Adam - so the AI for us is just to require this version.
Comment 23 Yaniv Lavi 2015-03-30 14:00:19 UTC 
(In reply to Allon Mureinik from comment #22)
> (In reply to Kevin Alon Goldblatt from comment #21)
> > (In reply to Allon Mureinik from comment #17)
> > > Kevin, can we early engage the libvirt version proposed in bug 1203119 ?
> > 
> > I ran the scenario above with v3.5.1 vt14 and the libvirt rpms provided in:
> > 
> > 
> > The test PASSED successfully.
> Great news!
> Thanks Kevin!
> 
> Adam - so the AI for us is just to require this version.

Any reason not to merge this change?
7.1.z libvirt is out and we only need to update the spec file to require it.
Comment 24 Allon Mureinik 2015-03-31 09:02:01 UTC 
(In reply to Yaniv Dary from comment #23)
> (In reply to Allon Mureinik from comment #22)
> > (In reply to Kevin Alon Goldblatt from comment #21)
> > > (In reply to Allon Mureinik from comment #17)
> > > > Kevin, can we early engage the libvirt version proposed in bug 1203119 ?
> > > 
> > > I ran the scenario above with v3.5.1 vt14 and the libvirt rpms provided in:
> > > 
> > > 
> > > The test PASSED successfully.
> > Great news!
> > Thanks Kevin!
> > 
> > Adam - so the AI for us is just to require this version.
> 
> Any reason not to merge this change?
> 7.1.z libvirt is out and we only need to update the spec file to require it.
1. We need to fix bug 1206722, as this libvirt introduces a nasty regression
2. Agreed - but this is d/s only - upstream oVirt cannot rely on packages that are not available in CentOS
Comment 27 Allon Mureinik 2015-04-13 08:46:22 UTC 
*** Bug 1208012 has been marked as a duplicate of this bug. ***
Comment 28 Kevin Alon Goldblatt 2015-04-14 16:26:20 UTC 
3.5.1 Z-STREAM vt14.3
rhevm-3.5.1-0.4.el6ev.noarch
vdsm-4.16.13.1-1.el7ev.x86_64

libvirt-daemon-driver-nwfilter-1.2.8-16.el7_1.2.x86_64
libvirt-daemon-driver-nodedev-1.2.8-16.el7_1.2.x86_64
libvirt-lock-sanlock-1.2.8-16.el7_1.2.x86_64
libvirt-client-1.2.8-16.el7_1.2.x86_64
libvirt-daemon-driver-network-1.2.8-16.el7_1.2.x86_64
libvirt-daemon-driver-qemu-1.2.8-16.el7_1.2.x86_64
libvirt-daemon-driver-interface-1.2.8-16.el7_1.2.x86_64
libvirt-daemon-driver-storage-1.2.8-16.el7_1.2.x86_64
libvirt-daemon-config-nwfilter-1.2.8-16.el7_1.2.x86_64
libvirt-daemon-1.2.8-16.el7_1.2.x86_64
libvirt-daemon-driver-secret-1.2.8-16.el7_1.2.x86_64
libvirt-daemon-kvm-1.2.8-16.el7_1.2.x86_64
libvirt-python-1.2.8-7.el7_1.1.x86_64

I ran the scenario with the above version and all Live merges were successfull.

Moving to verified
Comment 30 errata-xmlrpc 2015-04-28 18:42:16 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, 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://rhn.redhat.com/errata/RHSA-2015-0888.html