Bug 1550117 - Fail to take live snapshot on Gluster
Summary: Fail to take live snapshot on Gluster
Keywords:
Status: CLOSED WORKSFORME
Alias: None
Product: ovirt-engine
Classification: oVirt
Component: BLL.Storage
Version: 4.2.1.2
Hardware: Unspecified
OS: Unspecified
medium
medium
Target Milestone: ovirt-4.2.2
: ---
Assignee: Allon Mureinik
QA Contact: Raz Tamir
URL:
Whiteboard:
Depends On:
Blocks: 1532133
TreeView+ depends on / blocked
 
Reported: 2018-02-28 14:29 UTC by Yosi Ben Shimon
Modified: 2018-03-01 08:37 UTC (History)
2 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2018-03-01 08:25:16 UTC
oVirt Team: Storage
Embargoed:
rule-engine: ovirt-4.2?


Attachments (Terms of Use)

Description Yosi Ben Shimon 2018-02-28 14:29:17 UTC
Description of problem:
Taking a snapshot on gluster fails 

Version-Release number of selected component (if applicable):
ovirt-engine-4.2.2.1-0.1.el7.noarch
vdsm-4.20.19-1.el7ev.x86_64

How reproducible:
100%

Steps to Reproduce:
1. Create a VM with:
- 1 bootable disk (doesn't matter type).
- 1 preallocated disk on gluster SD (5 GB in my case).
2. Start the VM.
3. Under Compute -> Virtual Machines, select the newly created VM and click on name.
4. Switch to Snapshot tab.
5. Click on 'Create' and in the dialog window:
- Give the snapshot a descripiton.
- select the second disk (gluster)
- uncheck the 'Save Memory'.
6. click 'OK'

Actual results:
The Snapshot is been created.
The actual size of the disk is been appended by the size of the Virtual size.
The Allocation type changes to thin provision.

Expected results:
The Snapshot is been created.
The actual size of the disk is the same as the Virtual size.
The Allocation type stays preallocated.

Additional info:
Error from engine log:
2018-02-28 16:18:40,392+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-6) [a17e4adb-3f23-4852-a62b-15e164efdffc] Command 'CreateAllSnapshotsFromVm' id: 'e767d659-c360-4ffb-ad76-1f9ca7066f4a' child commands '[5aff62a3-02ef-4d57-bc71-ccca71b56175]' executions were completed, status 'SUCCEEDED'
2018-02-28 16:18:41,443+02 INFO  [org.ovirt.engine.core.bll.snapshots.CreateAllSnapshotsFromVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [a17e4adb-3f23-4852-a62b-15e164efdffc] Ending command 'org.ovirt.engine.core.bll.snapshots.CreateAllSnapshotsFromVmCommand' successfully.
2018-02-28 16:18:41,462+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [a17e4adb-3f23-4852-a62b-15e164efdffc] START, SnapshotVDSCommand(HostName = new_Host_13, SnapshotVDSCommandParameters:{hostId='c361762d-115c-4850-a1de-ae6cbe5d3561', vmId='b8e5be38-b5af-4e92-9d0d-16a70c888440'}), log id: 4abe668f
2018-02-28 16:18:41,468+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [a17e4adb-3f23-4852-a62b-15e164efdffc] Failed in 'SnapshotVDS' method
2018-02-28 16:18:41,480+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [a17e4adb-3f23-4852-a62b-15e164efdffc] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM new_Host_13 command SnapshotVDS failed: Snapshot failed
2018-02-28 16:18:41,480+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [a17e4adb-3f23-4852-a62b-15e164efdffc] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand' return value 'StatusOnlyReturn [status=Status [code=48, message=Snapshot failed]]'
2018-02-28 16:18:41,480+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [a17e4adb-3f23-4852-a62b-15e164efdffc] HostName = new_Host_13
2018-02-28 16:18:41,481+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [a17e4adb-3f23-4852-a62b-15e164efdffc] Command 'SnapshotVDSCommand(HostName = new_Host_13, SnapshotVDSCommandParameters:{hostId='c361762d-115c-4850-a1de-ae6cbe5d3561', vmId='b8e5be38-b5af-4e92-9d0d-16a70c888440'})' execution failed: VDSGenericException: VDSErrorException: Failed to SnapshotVDS, error = Snapshot failed, code = 48
2018-02-28 16:18:41,481+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [a17e4adb-3f23-4852-a62b-15e164efdffc] FINISH, SnapshotVDSCommand, log id: 4abe668f
2018-02-28 16:18:41,481+02 WARN  [org.ovirt.engine.core.bll.snapshots.CreateAllSnapshotsFromVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [a17e4adb-3f23-4852-a62b-15e164efdffc] Could not perform live snapshot due to error, VM will still be configured to the new created snapshot: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to SnapshotVDS, error = Snapshot failed, code = 48 (Failed with error SNAPSHOT_FAILED and code 48)
2018-02-28 16:18:41,510+02 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [a17e4adb-3f23-4852-a62b-15e164efdffc] EVENT_ID: USER_CREATE_LIVE_SNAPSHOT_FINISHED_FAILURE(170), Failed to create live snapshot 'aaa' for VM 'test_VM'. VM restart is recommended. Note that using the created snapshot might cause data inconsistency.
2018-02-28 16:18:41,530+02 INFO  [org.ovirt.engine.core.bll.snapshots.CreateSnapshotCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [a17e4adb-3f23-4852-a62b-15e164efdffc] Ending command 'org.ovirt.engine.core.bll.snapshots.CreateSnapshotCommand' successfully.
2018-02-28 16:18:41,550+02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [a17e4adb-3f23-4852-a62b-15e164efdffc] START, GetImageInfoVDSCommand( GetImageInfoVDSCommandParameters:{storagePoolId='5d567ca7-069a-490c-9800-09ac6fd3a781', ignoreFailoverLimit='false', storageDomainId='52838d3c-11d1-4a21-98f7-dfc4f8271583', imageGroupId='25ba3048-1114-4461-97e5-0d3a571b61a6', imageId='16fca9e1-af93-4832-b764-23f16562d34e'}), log id: 54504a99
2018-02-28 16:18:41,558+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [a17e4adb-3f23-4852-a62b-15e164efdffc] START, GetVolumeInfoVDSCommand(HostName = new_Host_12, GetVolumeInfoVDSCommandParameters:{hostId='25f281cf-0dbf-42c8-98d9-a9154b0f242b', storagePoolId='5d567ca7-069a-490c-9800-09ac6fd3a781', storageDomainId='52838d3c-11d1-4a21-98f7-dfc4f8271583', imageGroupId='25ba3048-1114-4461-97e5-0d3a571b61a6', imageId='16fca9e1-af93-4832-b764-23f16562d34e'}), log id: 2ac6dfb8
2018-02-28 16:18:41,609+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [a17e4adb-3f23-4852-a62b-15e164efdffc] FINISH, GetVolumeInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.DiskImage@27d0786d, log id: 2ac6dfb8
2018-02-28 16:18:41,609+02 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [a17e4adb-3f23-4852-a62b-15e164efdffc] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.DiskImage@27d0786d, log id: 54504a99
2018-02-28 16:18:41,630+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetQemuImageInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [a17e4adb-3f23-4852-a62b-15e164efdffc] START, GetQemuImageInfoVDSCommand(HostName = new_Host_13, GetVolumeInfoVDSCommandParameters:{hostId='c361762d-115c-4850-a1de-ae6cbe5d3561', storagePoolId='5d567ca7-069a-490c-9800-09ac6fd3a781', storageDomainId='52838d3c-11d1-4a21-98f7-dfc4f8271583', imageGroupId='25ba3048-1114-4461-97e5-0d3a571b61a6', imageId='16fca9e1-af93-4832-b764-23f16562d34e'}), log id: 53b0f4d1
2018-02-28 16:18:42,211+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetQemuImageInfoVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [a17e4adb-3f23-4852-a62b-15e164efdffc] FINISH, GetQemuImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.QemuImageInfo@552e5224, log id: 53b0f4d1
2018-02-28 16:18:42,241+02 INFO  [org.ovirt.engine.core.bll.snapshots.CreateAllSnapshotsFromVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [] Lock freed to object 'EngineLock:{exclusiveLocks='[b8e5be38-b5af-4e92-9d0d-16a70c888440=VM]', sharedLocks=''}'
2018-02-28 16:18:42,258+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [] EVENT_ID: USER_CREATE_SNAPSHOT_FINISHED_FAILURE(69), Failed to complete snapshot 'aaa' creation for VM 'test_VM'.
2018-02-28 16:18:42,259+02 WARN  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-39) [] Command 'CreateAllSnapshotsFromVm' id: 'e767d659-c360-4ffb-ad76-1f9ca7066f4a' end method execution failed, as the command isn't marked for endAction() retries silently ignoring


Error from vdsm log:
2018-02-28 16:18:41,462+0200 INFO  (jsonrpc/6) [api.virt] START snapshot(snapDrives=[{'baseVolumeID': '62a8d8e9-d381-49b5-a200-d79c0c1e503d', 'domainID': '52838d3c-11d1-4a21-98f7-dfc4f8271583', 'volumeID': '16fca9e1-af93-4832-b764-23f16562d34e', 'imageID': '25ba3048-1114-4461-97e5-0d3a571b61a6'}], snapMemory=None, frozen=False) from=::ffff:10.35.163.132,56226, flow_id=a17e4adb-3f23-4852-a62b-15e164efdffc (api:46)
2018-02-28 16:18:41,463+0200 ERROR (jsonrpc/6) [virt.vm] (vmId='b8e5be38-b5af-4e92-9d0d-16a70c888440') The base volume doesn't exist: {'device': 'disk', 'domainID': '52838d3c-11d1-4a21-98f7-dfc4f8271583', 'volumeID': '62a8d8e9-d381-49b5-a200-d79c0c1e503d', 'imageID': '25ba3048-1114-4461-97e5-0d3a571b61a6'} (vm:4387)
2018-02-28 16:18:41,463+0200 INFO  (jsonrpc/6) [api.virt] FINISH snapshot return={'status': {'message': 'Snapshot failed', 'code': 48}} from=::ffff:10.35.163.132,56226, flow_id=a17e4adb-3f23-4852-a62b-15e164efdffc (api:52)
2018-02-28 16:18:41,463+0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call VM.snapshot failed (error 48) in 0.00 seconds (__init__:573)

Comment 1 Allon Mureinik 2018-02-28 16:28:39 UTC
Can we have the full engine and vdsm logs please?

Comment 2 Yosi Ben Shimon 2018-03-01 08:25:16 UTC
Hi Allon,
I wanted to be sure that this is a real bug and didn't failed as a result of bad environment, i checked it again on other clean environment.
It worked fine.
I'm closing it as NOTABUG and if it will come up again, i'll reopen it.

Comment 3 Allon Mureinik 2018-03-01 08:35:48 UTC
(In reply to Yosi Ben Shimon from comment #2)
> Hi Allon,
> I wanted to be sure that this is a real bug and didn't failed as a result of
> bad environment, i checked it again on other clean environment.
> It worked fine.
> I'm closing it as NOTABUG and if it will come up again, i'll reopen it.

Great news, actually!
Thanks Yosi


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