Bug 834356

Summary: Error message 'Image is not a legal chain' does not provide the user with any insight into what the problem is.
Product: Red Hat Enterprise Virtualization Manager Reporter: Stephen Gordon <sgordon>
Component: vdsmAssignee: Allon Mureinik <amureini>
Status: CLOSED WONTFIX QA Contact: yeylon <yeylon>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 3.2.0CC: abaron, acanan, amureini, bazulay, iheim, jbelka, jkt, lpeer, scohen, sgordon, srevivo, yeylon
Target Milestone: ---Keywords: Triaged
Target Release: 3.5.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard: storage
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-02-17 13:57:00 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:

Description Stephen Gordon 2012-06-21 16:07:49 UTC 
Description of problem:

I had a template import fail with 'Image is not a legal chain Error code: 262'. The export domain I was using is located in Brisbane (I am in Toronto), we are trying to move templates between the two locations. So I *assume* the issue is the latency, but the error message given on the UI is woeful, and the log just says the same thing.

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

Red Hat Enterprise Linux Server release 6.3 (Santiago)

vdsm-cli-4.9-113.1.el6.x86_64
vdsm-4.9-113.1.el6.x86_64

Steps to Reproduce:
1. Attach export domain from remote location (high latency)
2. Attempt to import templates
3. Receive 'Image is not a legal chain Error code: 262' on UI.

Additional info:

Thread-74190::DEBUG::2012-06-21 11:48:22,130::task::495::TaskManager.Task::(_debug) Task f179f1a4-2c80-4c07-aab2-88861dc085ba: moving from state preparing -> state finished
Thread-74190::DEBUG::2012-06-21 11:48:22,130::resourceManager::786::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-74190::DEBUG::2012-06-21 11:48:22,130::resourceManager::821::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-74190::DEBUG::2012-06-21 11:48:22,131::task::495::TaskManager.Task::(_debug) Task f179f1a4-2c80-4c07-aab2-88861dc085ba: ref 0 aborting False
Thread-74190::INFO::2012-06-21 11:48:22,131::dispatcher::100::Storage.Dispatcher.Protect::(run) Run and protect: repoStats, Return response: {'status': {'message': 'OK', 'code': 0}, '335287eb-d758-49fb-b0c9-ab69a1d21b71': {'delay': '0.00125503540039', 'lastCheck': 1340293693.7156701, 'valid': True, 'code': 0}, '9d8a0df1-1892-4198-bdfe-1b8ce76447fe': {'delay': '30.7394750118', 'lastCheck': 1340293642.41291, 'valid': False, 'code': 379}, '2f8969bb-b8bc-46d2-af3f-341158f7455c': {'delay': '0.00111317634583', 'lastCheck': 1340293700.610512, 'valid': True, 'code': 0}}
Thread-74103::ERROR::2012-06-21 11:48:26,845::task::868::TaskManager.Task::(_setError) Unexpected error
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/task.py", line 876, in _run
    return fn(*args, **kargs)
  File "/usr/share/vdsm/storage/spm.py", line 115, in run
    return self.func(*args, **kwargs)
  File "/usr/share/vdsm/storage/spm.py", line 1586, in public_copyImage
    image.Image(repoPath).validateVolumeChain(sdUUID=sdUUID, imgUUID=srcImgUUID)
  File "/usr/share/vdsm/storage/image.py", line 688, in validateVolumeChain
    raise se.ImageIsNotLegalChain(imgUUID)
ImageIsNotLegalChain: Image is not a legal chain: ('0b781eef-15ce-40ca-846d-d88495600230',)
Thread-70514::DEBUG::2012-06-21 11:48:26,845::lvm::439::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
Thread-74103::DEBUG::2012-06-21 11:48:26,846::task::495::TaskManager.Task::(_debug) Task e2e2e187-9aa3-4486-b189-db8b34e9fe90: Task._run: e2e2e187-9aa3-4486-b189-db8b34e9fe90 ('9d8a0df1-1892-4198-bdfe-1b8ce76447fe', '87f53c00-ba3f-11e1-8a01-0019b917ca79', 'd6c29001-6f5b-4768-a9d8-fd456ef87417', '0b781eef-15ce-40ca-846d-d88495600230', '6bda45db-9fdb-47a9-98d5-516960be4b80', '0b781eef-15ce-40ca-846d-d88495600230', '6bda45db-9fdb-47a9-98d5-516960be4b80', '_template_rhel6a_7/6/2011 1:01:10 PM_template', '2f8969bb-b8bc-46d2-af3f-341158f7455c', 6, 5, 2, 'false', 'true') {} failed - stopping task
Thread-70514::DEBUG::2012-06-21 11:48:26,847::lvm::374::Storage.Misc.excCmd::(cmd) '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free 9d8a0df1-1892-4198-bdfe-1b8ce76447fe' (cwd None)
Thread-74103::DEBUG::2012-06-21 11:48:26,847::task::495::TaskManager.Task::(_debug) Task e2e2e187-9aa3-4486-b189-db8b34e9fe90: stopping in state preparing (force False)
Thread-74103::DEBUG::2012-06-21 11:48:26,849::task::495::TaskManager.Task::(_debug) Task e2e2e187-9aa3-4486-b189-db8b34e9fe90: ref 1 aborting True
Thread-74103::INFO::2012-06-21 11:48:26,850::task::1171::TaskManager.Task::(prepare) aborting: Task is aborted: 'Image is not a legal chain' - code 262
Thread-74103::DEBUG::2012-06-21 11:48:26,851::task::495::TaskManager.Task::(_debug) Task e2e2e187-9aa3-4486-b189-db8b34e9fe90: Prepare: aborted: Image is not a legal chain
Thread-74103::DEBUG::2012-06-21 11:48:26,851::task::495::TaskManager.Task::(_debug) Task e2e2e187-9aa3-4486-b189-db8b34e9fe90: ref 0 aborting True
Thread-74103::DEBUG::2012-06-21 11:48:26,851::task::495::TaskManager.Task::(_debug) Task e2e2e187-9aa3-4486-b189-db8b34e9fe90: Task._doAbort: force False
Thread-74103::DEBUG::2012-06-21 11:48:26,851::resourceManager::821::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-74103::DEBUG::2012-06-21 11:48:26,852::task::495::TaskManager.Task::(_debug) Task e2e2e187-9aa3-4486-b189-db8b34e9fe90: moving from state preparing -> state aborting
Thread-74103::DEBUG::2012-06-21 11:48:26,852::task::495::TaskManager.Task::(_debug) Task e2e2e187-9aa3-4486-b189-db8b34e9fe90: _aborting: recover policy none
Thread-74103::DEBUG::2012-06-21 11:48:26,852::task::495::TaskManager.Task::(_debug) Task e2e2e187-9aa3-4486-b189-db8b34e9fe90: moving from state aborting -> state failed
Thread-74103::DEBUG::2012-06-21 11:48:26,853::resourceManager::786::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-74103::DEBUG::2012-06-21 11:48:26,853::resourceManager::821::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-74103::ERROR::2012-06-21 11:48:26,853::dispatcher::103::Storage.Dispatcher.Protect::(run) {'status': {'message': "Image is not a legal chain: ('0b781eef-15ce-40ca-846d-d88495600230',)", 'code': 262}}
Comment 4 Jiri Belka 2012-11-28 14:23:51 UTC 
I have same issue on 3.1 env:

vdsm-4.9.6-44.0.el6_3.x86_64
libvirt-0.9.10-21.el6_3.6.x86_64
qemu-kvm-rhev-0.12.1.2-2.295.el6_3.5.x86_64
Comment 6 Ayal Baron 2014-01-29 13:56:59 UTC 
Steve, suggestions for better phrasing?
Comment 7 Stephen Gordon 2014-01-29 13:59:06 UTC 
(In reply to Ayal Baron from comment #6)
> Steve, suggestions for better phrasing?

From my POV it was never confirmed what the actual issue is so it's hard to say. Is the "Image is not a legal chain Error code: 262" definitely a result of latency as I guessed in the description? What does it actually mean?
Comment 8 Ayal Baron 2014-02-02 17:06:37 UTC 
(In reply to Stephen Gordon from comment #7)
> (In reply to Ayal Baron from comment #6)
> > Steve, suggestions for better phrasing?
> 
> From my POV it was never confirmed what the actual issue is so it's hard to
> say. Is the "Image is not a legal chain Error code: 262" definitely a result
> of latency as I guessed in the description? What does it actually mean?

no, it means that the qcow chain is not valid (there is a problem with one or more of the files/devices)