Bug 1167090 - [Rhev-Upgrade] Live storage migration createTargetImage fails on mixed versioned cluster
Summary: [Rhev-Upgrade] Live storage migration createTargetImage fails on mixed versio...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: vdsm
Version: 3.5.0
Hardware: Unspecified
OS: Unspecified
unspecified
urgent
Target Milestone: ---
: 3.5.0
Assignee: Tal Nisan
QA Contact: Ori Gofen
URL:
Whiteboard: storage
Depends On: 1174791
Blocks:
TreeView+ depends on / blocked
 
Reported: 2014-11-23 14:45 UTC by Ori Gofen
Modified: 2016-02-10 17:12 UTC (History)
13 users (show)

Fixed In Version: vdsm-4.16.7.6-1.el6ev
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2015-02-16 13:38:47 UTC
oVirt Team: Storage
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
logs (1.95 MB, application/x-gzip)
2014-11-23 14:45 UTC, Ori Gofen
no flags Details

Description Ori Gofen 2014-11-23 14:45:34 UTC
Created attachment 960445 [details]
logs

Description of problem:
The flow is Part of Rhev-Upgrade simulation:
A costumer is having 3.4 DC with FC and NFS domains, one of the hosts is being upgrade to vt10.1, upgrade is done from the engine, after the upgrade is successfully ended, Live storage migration from one FC domain to another fails with creating the block volume on the targeted domain:

f49b24d7-d8fa-4c4e-9436-4db2f61449f0::ERROR::2014-11-23 16:34:05,996::volume::476::Storage.Volume::(create) Unexpected error
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/volume.py", line 435, in create
    srcVolUUID, volPath)
  File "/usr/share/vdsm/storage/blockVolume.py", line 146, in _create
    volPath, size * BLOCK_SIZE, volume.fmt2str(volFormat))
  File "/usr/lib/python2.6/site-packages/vdsm/qemuimg.py", line 137, in create
    raise QImgError(rc, out, err)
QImgError: ecode=1, stdout=["Formatting '/rhev/data-center/af395fd7-a6c4-436b-8cb7-58462456bc9c/ce78adff-cbef-441a-a717-c420480de323/images/a141de52-c2ff-4dc9-a1a7-157b79724933/04304ff1-67ba-4052-b520-f872d1ee8516', fmt=qcow2 size=10737418240 encryption=off cluster_size=65536 "], stderr=['/rhev/data-center/af395fd7-a6c4-436b-8cb7-58462456bc9c/ce78adff-cbef-441a-a717-c420480de323/images/a141de52-c2ff-4dc9-a1a7-157b79724933/04304ff1-67ba-4052-b520-f872d1ee8516: error while creating qcow2: Permission denied'], message=None
f49b24d7-d8fa-4c4e-9436-4db2f61449f0::ERROR::2014-11-23 16:34:06,053::image::401::Storage.Image::(_createTargetImage) Unexpected error
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/image.py", line 384, in _createTargetImage
    srcVolUUID=volParams['parent'])
  File "/usr/share/vdsm/storage/sd.py", line 430, in createVolume
    preallocate, diskType, volUUID, desc, srcImgUUID, srcVolUUID)
  File "/usr/share/vdsm/storage/volume.py", line 478, in create
    (volUUID, e))
VolumeCreationError: Error creating a new volume: ('Volume creation 04304ff1-67ba-4052-b520-f872d1ee8516 failed: ecode=1, stdout=["Formatting \'/rhev/data-center/af395fd7-a6c4-436b-8cb7-58462456bc9c/ce78adff-cbef-441a-a717-c420480de323/images/a141de52-c2ff-4dc9-a1a7-157b79724933/04304ff1-67ba-4052-b520-f872d1ee8516\', fmt=qcow2 size=10737418240 encryption=off cluster_size=65536 "], stderr=[\'/rhev/data-center/af395fd7-a6c4-436b-8cb7-58462456bc9c/ce78adff-cbef-441a-a717-c420480de323/images/a141de52-c2ff-4dc9-a1a7-157b79724933/04304ff1-67ba-4052-b520-f872d1ee8516: error while creating qcow2: Permission denied\'], message=None',)

from engine:

2014-11-23 16:34:19,023 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] (DefaultQuartzScheduler_Worker-15) [4dca5581] Failed in HSMGetAllTasksStatusesVDS m
ethod
2014-11-23 16:34:19,023 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-15) [4dca5581] SPMAsyncTask::PollTask: Polling task f49b24d7-d8fa-4c4e-9436-4db2f61449f0
 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'cleanSuccess'.
2014-11-23 16:34:19,114 ERROR [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-15) [4dca5581] BaseAsyncTask::LogEndTaskFailure: Task f49b24d7-d8fa-4c4e-9436-4db2f61449
f0 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended with failure:
-- Result: cleanSuccess
-- Message: VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = Error creating a new volume, code = 205,
-- Exception: VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = Error creating a new volume, code = 205
2014-11-23 16:34:19,115 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-15) [4dca5581] CommandAsyncTask::EndActionIfNecessary: All tasks of command 32a16f82
-434f-4e36-b4f3-24f57dc12dba has ended -> executing endAction
2014-11-23 16:34:19,115 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-15) [4dca5581] CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: 3
2a16f82-434f-4e36-b4f3-24f57dc12dba): calling endAction .
2014-11-23 16:34:19,115 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-4-thread-18) [4dca5581] CommandAsyncTask::EndCommandAction [within thread] context: Attempti
ng to endAction LiveMigrateDisk, executionIndex: 0
2014-11-23 16:34:19,374 ERROR [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-4-thread-18) [773e64b9] Ending command with failure: org.ovirt.engine.core.bll.lsm
.LiveMigrateDiskCommand
2014-11-23 16:34:19,382 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-4-thread-18) [773e64b9] Lock freed to object EngineLock [exclusiveLocks= , sharedLocks= key: 31c88ef3-1998-4a5e-9b03-b12b3a0ea0a3 value: VM


Version-Release number of selected component (if applicable):
purple-vds2:
vdsm-python-4.14.18-2.el6ev.x86_64
vdsm-python-zombiereaper-4.14.18-2.el6ev.noarch
vdsm-cli-4.14.18-2.el6ev.noarch
vdsm-4.14.18-2.el6ev.x86_64
vdsm-xmlrpc-4.14.18-2.el6ev.noarch

purple-vds3:
vdsm-yajsonrpc-4.16.7.4-1.el6ev.noarch
vdsm-python-4.16.7.4-1.el6ev.noarch
vdsm-cli-4.16.7.4-1.el6ev.noarch
vdsm-4.16.7.4-1.el6ev.x86_64
vdsm-python-zombiereaper-4.16.7.4-1.el6ev.noarch
vdsm-xmlrpc-4.16.7.4-1.el6ev.noarch
vdsm-jsonrpc-4.16.7.4-1.el6ev.noarch

engine:
rhevm-lib-3.4.4-2.2.el6ev.noarch
rhevm-setup-plugins-3.4.4-1.el6ev.noarch
rhevm-guest-agent-common-1.0.9-5.el6ev.noarch
rhevm-branding-rhev-3.4.0-2.el6ev.noarch
rhevm-dbscripts-3.4.4-2.2.el6ev.noarch
rhevm-setup-plugin-websocket-proxy-3.4.4-2.2.el6ev.noarch
rhevm-image-uploader-3.4.3-1.el6ev.noarch
redhat-support-plugin-rhev-3.4.0-4.el6ev.noarch
rhevm-tools-3.4.4-2.2.el6ev.noarch
rhevm-setup-base-3.4.4-2.2.el6ev.noarch
rhevm-cli-3.4.0.6-4.el6ev.noarch
rhevm-spice-client-x86-msi-3.4-4.el6_5.noarch
rhevm-spice-client-x86-cab-3.4-4.el6_5.noarch
rhevm-webadmin-portal-3.4.4-2.2.el6ev.noarch
rhevm-userportal-3.4.4-2.2.el6ev.noarch
rhevm-sdk-python-3.4.4.0-1.el6ev.noarch
rhevm-setup-plugin-ovirt-engine-common-3.4.4-2.2.el6ev.noarch
rhevm-websocket-proxy-3.4.4-2.2.el6ev.noarch
rhevm-iso-uploader-3.4.4-1.el6ev.noarch
rhevm-dependencies-3.4.1-1.el6ev.noarch
rhevm-spice-client-x64-msi-3.4-4.el6_5.noarch
rhevm-backend-3.4.4-2.2.el6ev.noarch
rhevm-3.4.4-2.2.el6ev.noarch
rhev-hypervisor6-6.5-20140930.1.el6ev.noarch
rhevm-setup-plugin-ovirt-engine-3.4.4-2.2.el6ev.noarch
rhevm-log-collector-3.4.5-1.el6ev.noarch
rhev-guest-tools-iso-3.4-9.el6ev.noarch
rhevm-restapi-3.4.4-2.2.el6ev.noarch
rhevm-setup-3.4.4-2.2.el6ev.noarch
rhevm-spice-client-x64-cab-3.4-4.el6_5.noarch
rhevm-doc-3.4.0-8.el6eng.noarch

How reproducible:
?


Actual results:
Live migration fails

Expected results:
this operation should be successful or be documented as illegal during upgrade

Additional info:

Comment 1 Tal Nisan 2014-11-24 10:17:30 UTC
Which EL6 version does the hosts have?
What is your DC level?
Which host was upgraded of the twe?
Please supply the relevant data otherwise we can't understand the flow.

Comment 2 Allon Mureinik 2014-11-26 21:59:24 UTC
The business end of the failure is a permission issue:
f49b24d7-d8fa-4c4e-9436-4db2f61449f0::ERROR::2014-11-23 16:34:05,996::volume::476::Storage.Volume::(create) Unexpected error
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/volume.py", line 435, in create
    srcVolUUID, volPath)
  File "/usr/share/vdsm/storage/blockVolume.py", line 146, in _create
    volPath, size * BLOCK_SIZE, volume.fmt2str(volFormat))
  File "/usr/lib/python2.6/site-packages/vdsm/qemuimg.py", line 137, in create
    raise QImgError(rc, out, err)
QImgError: ecode=1, stdout=["Formatting '/rhev/data-center/af395fd7-a6c4-436b-8cb7-58462456bc9c/ce78adff-cbef-441a-a717-c420480de323/images/a141de52-c2ff-4dc9-a1a7-157b79724933/04304ff1-67ba-4052-b520-f872d1ee8516', fmt=qcow2 size=10737418240 encryption=off cluster_size=65536 "], stderr=['/rhev/data-center/af395fd7-a6c4-436b-8cb7-58462456bc9c/ce78adff-cbef-441a-a717-c420480de323/images/a141de52-c2ff-4dc9-a1a7-157b79724933/04304ff1-67ba-4052-b520-f872d1ee8516: error while creating qcow2: Permission denied'], message=None

This error has nothing to do with the upgrade - it's an EL regression that was handled in bug 1160620.
Moving to ON_QA to verify with vdsm-4.16.7.6-1.el6ev

Comment 3 Ori Gofen 2014-12-16 14:01:31 UTC
encountered BZ #1174791 while attempting to verify this bug.
live migration process loops through lvextend command, until the snapshot covers the whole free space limit

Comment 4 Ori Gofen 2014-12-22 15:37:41 UTC
Steps to reproduce:
Setup is consisted of mixed versioned hosts

1.create 5 vm's+thin disks+install OS
2. while installing OS attempt lsm

operation fails , "VolumeCreationError: Error creating a new volume"

Comment 5 Nir Soffer 2014-12-23 07:41:32 UTC
Ori, which version of rhev is installed on this host?

Comment 6 Ori Gofen 2014-12-23 15:52:28 UTC
verified on host:vt13.4 engine:av13.4


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