Bug 1527861 - Live merge with continuous I/O to the VM fails with 'VolumeImageHasChildren: Cannot delete volume which has children'
Summary: Live merge with continuous I/O to the VM fails with 'VolumeImageHasChildren: ...
Keywords:
Status: CLOSED WORKSFORME
Alias: None
Product: vdsm
Classification: oVirt
Component: Core
Version: 4.20.9.3
Hardware: Unspecified
OS: Unspecified
unspecified
medium
Target Milestone: ovirt-4.3.7
: ---
Assignee: Fedor Gavrilov
QA Contact: Avihai
URL:
Whiteboard:
: 1576914 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-12-20 09:39 UTC by Raz Tamir
Modified: 2019-07-30 08:54 UTC (History)
6 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2019-07-30 08:54:25 UTC
oVirt Team: Storage
Embargoed:
rule-engine: ovirt-4.3+

Attachments (Terms of Use)
engine and vdsm logs (2.30 MB, application/x-gzip)
2017-12-20 09:39 UTC, Raz Tamir 		no flags Details
new logs (1.42 MB, application/x-gzip)
2017-12-20 12:29 UTC, Raz Tamir 		no flags Details
logs1 (3.09 MB, application/x-gzip)
2018-05-13 16:10 UTC, Elad 		no flags Details
logs, automation output and functions calls (3.47 MB, application/x-gzip)
2018-06-10 22:52 UTC, Elad 		no flags Details
logs-7.2.19 (4.51 MB, application/zip)
2019-02-07 08:46 UTC, Elad 		no flags Details
View All

Description Raz Tamir 2017-12-20 09:39:58 UTC 
Created attachment 1370376 [details]
engine and vdsm logs

Description of problem:
In our automation (Tier1) I see that live merge with continuous I/O is failing to remove the snapshot.

engine.log:

2017-12-20 11:25:45,039+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-78) [] Failed in 'HSMGetAllTasksStatusesVDS' method
2017-12-20 11:25:45,051+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-78) [] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM host
_mixed_2 command HSMGetAllTasksStatusesVDS failed: Cannot delete volume which has children (non-ethical): [u'sdUUID: 51e6ae90-c7b1-45c7-8c10-135c5efe113a', 'imgUUID: 7c5d7e62-ba09-45ee-bf96-94aaf6a4d8d0', 'volUUID:
 805946d4-6c32-4537-8a1b-9838523dacaf']
2017-12-20 11:25:45,051+02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-78) [] SPMAsyncTask::PollTask: Polling task 'd9c89945-cbd0-443b-bee6-05fc56d7b208' (Pa
rent Command 'DestroyImage', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'.
2017-12-20 11:25:45,052+02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-78) [] BaseAsyncTask::onTaskEndSuccess: Task 'd9c89945-cbd0-443b-bee6-05fc56d7b208' (Parent Command 'DestroyImage', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully.
2017-12-20 11:25:45,053+02 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-78) [] CommandAsyncTask::endActionIfNecessary: All tasks of command 'a5fd49c7-9a41-448c-b322-ca13688adc62' has ended -> executing 'endAction'
2017-12-20 11:25:45,053+02 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-78) [] CommandAsyncTask::endAction: Ending action for '1' tasks (command ID: 'a5fd49c7-9a41-448c-b322-ca13688adc62'): calling endAction '.
2017-12-20 11:25:45,053+02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-78) [] SPMAsyncTask::PollTask: Polling task '6bc41b6e-f1b0-4f56-9c30-7597733f1be2' (Parent Command 'DestroyImage', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'cleanSuccess'.
2017-12-20 11:25:45,054+02 ERROR [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-78) [] BaseAsyncTask::logEndTaskFailure: Task '6bc41b6e-f1b0-4f56-9c30-7597733f1be2' (Parent Command 'DestroyImage', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended with failure:
-- Result: 'cleanSuccess'
-- Message: 'VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = Cannot delete volume which has children (non-ethical): [u'sdUUID: 51e6ae90-c7b1-45c7-8c10-135c5efe113a', 'imgUUID: 7c5d7e62-ba09-45ee-bf96-94aaf6a4d8d0', 'volUUID: 805946d4-6c32-4537-8a1b-9838523dacaf'], code = 100',
-- Exception: 'VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = Cannot delete volume which has children (non-ethical): [u'sdUUID: 51e6ae90-c7b1-45c7-8c10-135c5efe113a', 'imgUUID: 7c5d7e62-ba09-45ee-bf96-94aaf6a4d8d0', 'volUUID: 805946d4-6c32-4537-8a1b-9838523dacaf'], code = 100'


vdsm.log:

2017-12-20 11:25:36,322+0200 ERROR (tasks/5) [storage.TaskManager.Task] (Task='6bc41b6e-f1b0-4f56-9c30-7597733f1be2') Unexpected error (task:875)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 882, in _run
    return fn(*args, **kargs)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 336, in run
    return self.cmd(*self.argslist, **self.argsdict)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/securable.py", line 79, in wrapper
    return method(self, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/sp.py", line 1963, in deleteVolume
    vol.delete(postZero=postZero, force=force, discard=discard)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/fileVolume.py", line 494, in delete
    self.validateDelete()
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volume.py", line 1213, in validateDelete
    self._manifest.validateDelete()
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volume.py", line 516, in validateDelete
    raise se.VolumeImageHasChildren(self)
VolumeImageHasChildren: Cannot delete volume which has children (non-ethical): [u'sdUUID: 51e6ae90-c7b1-45c7-8c10-135c5efe113a', 'imgUUID: 7c5d7e62-ba09-45ee-bf96-94aaf6a4d8d0', 'volUUID: 805946d4-6c32-4537-8a1b-9838523dacaf']



Version-Release number of selected component (if applicable):
rhvm-4.2.0.2-0.1.el7
vdsm-4.20.9.3-1.el7ev.x86_64

How reproducible:
reproduced on FILE based storage only

Steps to Reproduce:
1. Create VM with disk + OS
2. Add 4 disks to VM
3. Create live snapshot
4. Perform dd from the OS disk to one of the other disks
5. Try to live merge the snapshot

Actual results:
The snapshot is not removed and left with 1 'Illegal' disk (not the OS disk) - All other 4 removed

Expected results:


Additional info:
Comment 1 Raz Tamir 2017-12-20 09:43:14 UTC 
Regression flag because - bug #1509675
Comment 2 Red Hat Bugzilla Rules Engine 2017-12-20 10:00:20 UTC 
This bug report has Keywords: Regression or TestBlocker.
Since no regressions or test blockers are allowed between releases, it is also being identified as a blocker for this release. Please resolve ASAP.
Comment 3 Ala Hino 2017-12-20 10:09:11 UTC 
Raz,

Is the volume on the storage is ILLEGAL, or the snapshot disk is seen ILLEGAL in the UI?
Comment 4 Ala Hino 2017-12-20 10:11:36 UTC 
Can you please provide the volume info of:

volUUID: 805946d4-6c32-4537-8a1b-9838523dacaf
imgUUID: 7c5d7e62-ba09-45ee-bf96-94aaf6a4d8d0
sdUUID: 51e6ae90-c7b1-45c7-8c10-135c5efe113a
Comment 5 Ala Hino 2017-12-20 11:29:17 UTC 
Raz,

I need the log of the host running the VM.

In addition, please upload the volume info of volume 805946d4-6c32-4537-8a1b-9838523dacaf (same imgUUID and sdUUID)
Comment 6 Raz Tamir 2017-12-20 12:28:43 UTC 
I reproduce the issue (new logs attached including vdsm.log of the host running the VM):

engine.log:

2017-12-20 14:12:24,509+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [] Failed in 'HSMGetAllTasksStatusesVDS' method
2017-12-20 14:12:24,517+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM host
_mixed_2 command HSMGetAllTasksStatusesVDS failed: Cannot delete volume which has children (non-ethical): [u'sdUUID: 51e6ae90-c7b1-45c7-8c10-135c5efe113a', 'imgUUID: 892cc845-c2a4-428e-b6ab-df74be50aeee', 'volUUID:
 550a7e56-63df-48b2-acdd-2368b3168a50']
2017-12-20 14:12:24,517+02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [] SPMAsyncTask::PollTask: Polling task '18fad037-279e-4c25-87d4-469d0f57822e' (Pa
rent Command 'DestroyImage', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'.
2017-12-20 14:12:24,517+02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [] BaseAsyncTask::onTaskEndSuccess: Task '18fad037-279e-4c25-87d4-469d0f57822e' (P
arent Command 'DestroyImage', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully.
2017-12-20 14:12:24,519+02 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [] CommandAsyncTask::endActionIfNecessary: All tasks of command '7b62af6b-f44b
-48d8-b6bc-008e7a3bc128' has ended -> executing 'endAction'
2017-12-20 14:12:24,519+02 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [] CommandAsyncTask::endAction: Ending action for '1' tasks (command ID: '7b62
af6b-f44b-48d8-b6bc-008e7a3bc128'): calling endAction '.
2017-12-20 14:12:24,519+02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [] SPMAsyncTask::PollTask: Polling task '214d8bc8-fad4-47e3-a3ef-b3efb2beb4e5' (Pa
rent Command 'DestroyImage', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'cleanSuccess'.
2017-12-20 14:12:24,520+02 ERROR [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [] BaseAsyncTask::logEndTaskFailure: Task '214d8bc8-fad4-47e3-a3ef-b3efb2beb4e5' (
Parent Command 'DestroyImage', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended with failure:
-- Result: 'cleanSuccess'
-- Message: 'VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = Cannot delete volume which has children (non-ethical): [u'sdUUID: 51e6ae90-c7b1-45c7-8c10-135c5efe113a', 'imgUUID: 8
92cc845-c2a4-428e-b6ab-df74be50aeee', 'volUUID: 550a7e56-63df-48b2-acdd-2368b3168a50'], code = 100',
-- Exception: 'VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = Cannot delete volume which has children (non-ethical): [u'sdUUID: 51e6ae90-c7b1-45c7-8c10-135c5efe113a', 'imgUUID:
 892cc845-c2a4-428e-b6ab-df74be50aeee', 'volUUID: 550a7e56-63df-48b2-acdd-2368b3168a50'], code = 100'


vdsm.log:

2017-12-20 14:12:19,296+0200 ERROR (tasks/8) [storage.TaskManager.Task] (Task='214d8bc8-fad4-47e3-a3ef-b3efb2beb4e5') Unexpected error (task:875)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 882, in _run
    return fn(*args, **kargs)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 336, in run
    return self.cmd(*self.argslist, **self.argsdict)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/securable.py", line 79, in wrapper
    return method(self, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/sp.py", line 1963, in deleteVolume
    vol.delete(postZero=postZero, force=force, discard=discard)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/fileVolume.py", line 494, in delete
    self.validateDelete()
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volume.py", line 1213, in validateDelete
    self._manifest.validateDelete()
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volume.py", line 516, in validateDelete
    raise se.VolumeImageHasChildren(self)
VolumeImageHasChildren: Cannot delete volume which has children (non-ethical): [u'sdUUID: 51e6ae90-c7b1-45c7-8c10-135c5efe113a', 'imgUUID: 892cc845-c2a4-428e-b6ab-df74be50aeee', 'volUUID: 550a7e56-63df-48b2-acdd-2368b3168a50']


volume 550a7e56-63df-48b2-acdd-2368b3168a50 info:

[root@storage-ge10-vdsm2 images]# vdsm-client Volume getInfo storagedomainID=51e6ae90-c7b1-45c7-8c10-135c5efe113a storagepoolID=58ca604b-017d-0374-0220-00000000014e imageID=892cc845-c2a4-428e-b6ab-df74be50aeee volumeID=550a7e56-63df-48b2-acdd-2368b3168a50
{
    "status": "OK", 
    "lease": {
        "owners": [], 
        "version": null
    }, 
    "domain": "51e6ae90-c7b1-45c7-8c10-135c5efe113a", 
    "capacity": "1073741824", 
    "voltype": "INTERNAL", 
    "description": "", 
    "parent": "9a0d40c2-88d8-4c86-bd10-fd7f7bd89f4a", 
    "format": "COW", 
    "generation": 0, 
    "image": "892cc845-c2a4-428e-b6ab-df74be50aeee", 
    "uuid": "550a7e56-63df-48b2-acdd-2368b3168a50", 
    "disktype": "DATA", 
    "legality": "LEGAL", 
    "mtime": "0", 
    "apparentsize": "720896", 
    "truesize": "659456", 
    "type": "SPARSE", 
    "children": [], 
    "pool": "", 
    "ctime": "1513771709"
}

And it's parent volume info:
[root@storage-ge10-vdsm2 images]# vdsm-client Volume getInfo storagedomainID=51e6ae90-c7b1-45c7-8c10-135c5efe113a storagepoolID=58ca604b-017d-0374-0220-00000000014e imageID=892cc845-c2a4-428e-b6ab-df74be50aeee volumeID=9a0d40c2-88d8-4c86-bd10-fd7f7bd89f4a
{
    "status": "OK", 
    "lease": {
        "owners": [], 
        "version": null
    }, 
    "domain": "51e6ae90-c7b1-45c7-8c10-135c5efe113a", 
    "capacity": "1073741824", 
    "voltype": "INTERNAL", 
    "description": "{\"DiskAlias\":\"disk_virtioraw_2014061164\",\"DiskDescription\":\"\"}", 
    "parent": "00000000-0000-0000-0000-000000000000", 
    "format": "RAW", 
    "generation": 0, 
    "image": "892cc845-c2a4-428e-b6ab-df74be50aeee", 
    "uuid": "9a0d40c2-88d8-4c86-bd10-fd7f7bd89f4a", 
    "disktype": "DATA", 
    "legality": "LEGAL", 
    "mtime": "0", 
    "apparentsize": "1073741824", 
    "truesize": "34476032", 
    "type": "SPARSE", 
    "children": [], 
    "pool": "", 
    "ctime": "1513771575"
}
Comment 7 Raz Tamir 2017-12-20 12:29:21 UTC 
Created attachment 1370448 [details]
new logs
Comment 8 Ala Hino 2017-12-20 15:21:56 UTC 
Did this test run before this build or was marked as broken?

I also see that there was a hotplugin before the merge:

2017-12-20 14:06:36,611+0200 INFO  (jsonrpc/2) [api.virt] START hotplugDisk(params={'vmId': '5c18e5cf-325f-4dab-8946-add4757c24b3', 'drive': {'domainID': '51e6ae90-c7b1-45c7-8c10-135c5efe113a', 'format': 'raw', 'shared': 'false', 'type': 'disk', 'poolID': 'a4f4a084-28fe-4a4d-be85-991b174c32eb', 'volumeID': '9a0d40c2-88d8-4c86-bd10-fd7f7bd89f4a', 'imageID': '892cc845-c2a4-428e-b6ab-df74be50aeee', 'readonly': 'false', 'iface': 'virtio', 'deviceId': '892cc845-c2a4-428e-b6ab-df74be50aeee', 'address': u'', 'device': 'disk', 'discard': False, 'propagateErrors': 'off', 'optional': 'false', 'diskType': 'file'}}) from=::ffff:10.35.162.9,40322, flow_id=diskattachments_create_b0e4d468-68fe (api:46)

There were fixes in the hotplugin area (although supposed to be gluster related), BZ 1506677 (that is on_qa now), and I am trying to see if fixes introduced any regression.
Comment 9 Raz Tamir 2017-12-21 09:17:22 UTC 
This test passed on rhvm-4.2.0-11 and I verified bug #1509675.
Comment 10 Ala Hino 2017-12-21 12:00:18 UTC 
Can you please upload libvirt version?
Comment 11 Ala Hino 2017-12-21 15:42:26 UTC 
Can you please set log level of 'virt' component ([logger_virt] in etc/vdsm/logger.conf) to DEBUG and run again?
Comment 12 Raz Tamir 2017-12-24 10:03:30 UTC 
(In reply to Ala Hino from comment #10)
> Can you please upload libvirt version?

libvirt-3.2.0-14.el7_4.5.x86_64
Comment 13 Ala Hino 2017-12-31 10:51:44 UTC 
As I wasn't able to reproduce the bug in my environment, and the issue isn't encountered anymore by the automation (this is a 1st tier test that runs all the time), for now I am closing the bug as WORKSFORME.

Please set log level of virt component to DEBUG when running live merge tests, see comment #11.
Comment 14 Elad 2018-05-10 17:22:53 UTC 
Encountered again, see bug 1576914
Comment 15 Elad 2018-05-10 17:23:28 UTC 
*** Bug 1576914 has been marked as a duplicate of this bug. ***
Comment 16 Red Hat Bugzilla Rules Engine 2018-05-13 12:02:27 UTC 
This bug report has Keywords: Regression or TestBlocker.
Since no regressions or test blockers are allowed between releases, it is also being identified as a blocker for this release. Please resolve ASAP.
Comment 17 Ala Hino 2018-05-13 12:54:05 UTC 
Elad,

Can you please upload the recent logs?

Can you please confirm that 'Wipe After Delete' is checked?
Comment 18 Elad 2018-05-13 16:10:55 UTC 
Created attachment 1435747 [details]
logs1

The disks for this test are created without wipe after delete.
Comment 19 Elad 2018-05-13 16:17:45 UTC 
Snapshot merge for these disks is done with postZero='false':


2018-05-09 01:28:25,188+03 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DestroyImageVDSCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-5) [snapshots_delete_b5d9035f-1a67-4ae0] START, DestroyImageVDSCommand( DestroyImageVDSCommandParameters:{storagePoolId='5a84df72-52d3-11e8-8f7c-00163e7be006', ignoreFailoverLimit='false', storageDomainId='fa2fce36-621c-44a8-8c2f-1b9e6aae68b1', imageGroupId='40b9e763-a3ce-4a29-85ad-7aae024200bb', imageId='00000000-0000-0000-0000-000000000000', imageList='[b57af0a3-5fd7-4a85-bd62-a5261bdd2f24]', postZero='false', force='false'}), log id: 3687d1c
2018-05-09 01:28:25,198+03 INFO  [org.ovirt.engine.core.bll.storage.disk.image.DestroyImageCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [snapshots_delete_b5d9035f-1a67-4ae0] Running command: DestroyImageCommand internal: true. Entities affected :  ID: fa2fce36-621c-44a8-8c2f-1b9e6aae68b1 Type: Storage
2018-05-09 01:28:25,233+03 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DestroyImageVDSCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-4) [snapshots_delete_b5d9035f-1a67-4ae0] START, DestroyImageVDSCommand( DestroyImageVDSCommandParameters:{storagePoolId='5a84df72-52d3-11e8-8f7c-00163e7be006', ignoreFailoverLimit='false', storageDomainId='fa2fce36-621c-44a8-8c2f-1b9e6aae68b1', imageGroupId='0188808d-18ef-4ceb-9302-2312fbe045bc', imageId='00000000-0000-0000-0000-000000000000', imageList='[e51da635-f982-4906-bfdf-d3de3edbfe6c]', postZero='false', force='false'}), log id: 5e773dd
2018-05-09 01:28:25,249+03 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DestroyImageVDSCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [snapshots_delete_b5d9035f-1a67-4ae0] START, DestroyImageVDSCommand( DestroyImageVDSCommandParameters:{storagePoolId='5a84df72-52d3-11e8-8f7c-00163e7be006', ignoreFailoverLimit='false', storageDomainId='fa2fce36-621c-44a8-8c2f-1b9e6aae68b1', imageGroupId='7197220c-22a9-4c00-aece-1788c1116244', imageId='00000000-0000-0000-0000-000000000000', imageList='[6cfd3eee-a99d-4f4e-9eaf-7f0ae579a82f]', postZero='false', force='false'}), log id: 154ebe61
2018-05-09 01:28:25,288+03 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DestroyImageVDSCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-5) [snapshots_delete_b5d9035f-1a67-4ae0] FINISH, DestroyImageVDSCommand, log id: 3687d1c
Comment 20 Yaniv Kaul 2018-05-23 10:40:15 UTC 
What's the latest status here?
Comment 21 Ala Hino 2018-05-23 10:54:26 UTC 
Elad,

I know the QE tried to reproduce using the customer script, but it wasn't very clear, and we got no reply from the customer regarding the questions that we had. 

Can we try again to reproduce? 
My understanding is that the customer uses the script for backup purposes.
As a first step, can we have a script that automatically creates and remove snapshots?
Comment 22 Raz Tamir 2018-05-23 12:39:22 UTC 
Ala,

What customer script are you referring to?
This was found by our automation
Comment 23 Ala Hino 2018-05-23 12:55:47 UTC 
(In reply to Raz Tamir from comment #22)
> Ala,
> 
> What customer script are you referring to?
> This was found by our automation

My bad. I confused this bug with bug 1554369.
Comment 24 Elad 2018-06-10 22:52:37 UTC 
Created attachment 1449822 [details]
logs, automation output and functions calls

Encountered again while testing an extensive usage of snapshots (create and delete) as per requested for bz 1583424 and in https://bugzilla.redhat.com/show_bug.cgi?id=1554369#c21.

Attached logs, automation output and functions calls. 


2018-06-11 00:34:36,766+0300 ERROR (tasks/2) [storage.TaskManager.Task] (Task='19ed42bc-4ab7-417e-9c8e-b0066e5905f5') Unexpected error (task:875)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 882, in _run
    return fn(*args, **kargs)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 336, in run
    return self.cmd(*self.argslist, **self.argsdict)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/securable.py", line 79, in wrapper
    return method(self, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/sp.py", line 1970, in deleteVolume
    vol.delete(postZero=postZero, force=force, discard=discard)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/blockVolume.py", line 593, in delete
    self.validateDelete()
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volume.py", line 1260, in validateDelete
    self._manifest.validateDelete()
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volume.py", line 524, in validateDelete
    raise se.VolumeImageHasChildren(self)
VolumeImageHasChildren: Cannot delete volume which has children (non-ethical): ['sdUUID: 5d058f90-8604-491e-b2a4-e63ccf84188c', 'imgUUID: 077870f9-66b1-4563-abfb-d2757d9bd0e6', 'volUUID: f286a710-789b-4455-9027-
0b7d932803a6']
Comment 26 Sandro Bonazzola 2019-01-28 09:36:49 UTC 
This bug has not been marked as blocker for oVirt 4.3.0.
Since we are releasing it tomorrow, January 29th, this bug has been re-targeted to 4.3.1.
Comment 27 Elad 2019-02-07 08:46:21 UTC 
Created attachment 1527779 [details]
logs-7.2.19

Still occurs:


2019-02-07 05:09:21,212+0200 ERROR (tasks/3) [storage.TaskManager.Task] (Task='dbe1db85-d192-410c-bd5d-0eff47306ddf') Unexpected error (task:875)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 882, in _run
    return fn(*args, **kargs)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 336, in run
    return self.cmd(*self.argslist, **self.argsdict)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/securable.py", line 79, in wrapper
    return method(self, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/sp.py", line 1970, in deleteVolume
    vol.delete(postZero=postZero, force=force, discard=discard)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/fileVolume.py", line 502, in delete
    self.validateDelete()
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volume.py", line 1263, in validateDelete
    self._manifest.validateDelete()
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volume.py", line 527, in validateDelete
    raise se.VolumeImageHasChildren(self)
VolumeImageHasChildren: Cannot delete volume which has children (non-ethical): [u'sdUUID: f3eac415-3d1e-494b-9ef9-c6af7343c3b6', u'imgUUID: f08a4555-85ff-47f4-a81f-99f9e7cc3f7e', u'volUUID: d1ae26d1-b437-4654-af
78-bca7bb654291']



==========
ovirt-engine-4.2.8.2-0.1.el7ev.noarch
vdsm-4.20.46-1.el7ev.x86_64
libvirt-4.5.0-10.el7_6.4.x86_64
qemu-img-rhev-2.12.0-18.el7_6.3.x86_64
kernel - 3.10.0-957.5.1.el7.x86_64
Note You need to log in before you can comment on or make changes to this bug.