1366176 – Failed to import image from glance as template (as a result of RHEL 7.3 LVM issue - lvextend changed return code when called with current LV size)

Bug 1366176 - Failed to import image from glance as template (as a result of RHEL 7.3 LVM issue - lvextend changed return code when called with current LV size)

Summary: Failed to import image from glance as template (as a result of RHEL 7.3 LVM i...

Keywords:
Status:	CLOSED CURRENTRELEASE
Alias:	None
Product:	ovirt-engine
Classification:	oVirt
Component:	BLL.Storage
Sub Component:
Version:	3.6.7
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	high
Target Milestone:	ovirt-4.0.4
Target Release:	4.0.4
Assignee:	Nir Soffer
QA Contact:	Raz Tamir
Docs Contact:
URL:
Whiteboard:
Depends On:	1354396 1365186
Blocks:
TreeView+	depends on / blocked

Reported:	2016-08-11 08:51 UTC by Raz Tamir
Modified:	2017-02-17 02:46 UTC (History)
CC List:	4 users (show)
Fixed In Version:
Doc Type:	If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed:	2016-09-26 12:38:20 UTC
oVirt Team:	Storage
Embargoed:
Dependent Products:
Flags:	amureini: ovirt-4.0.z? rule-engine: blocker? rule-engine: planning_ack? amureini: devel_ack+ rule-engine: testing_ack+

Attachments	(Terms of Use)
engine and vdsm logs (1.29 MB, application/x-gzip) 2016-08-11 08:51 UTC, Raz Tamir	no flags	Details
engine and vdsm logs for extend VG (780.45 KB, application/x-gzip) 2016-08-11 11:38 UTC, Raz Tamir	no flags	Details
View All

Links
System	ID	Priority	Status	Summary	Last Updated
Red Hat Knowledge Base (Solution)	2933491	None	None	None	2017-02-17 02:46:28 UTC
oVirt gerrit	62338	master	MERGED	lvm: Fix error handling when resizing lvs	2016-08-23 22:02:48 UTC
oVirt gerrit	62734	ovirt-3.6	MERGED	lvm: Fix error handling when resizing lvs	2016-08-29 12:59:34 UTC
oVirt gerrit	62735	ovirt-3.6	MERGED	lvm: Separate lv reduce and extend	2016-08-29 12:59:53 UTC
oVirt gerrit	62739	ovirt-4.0	MERGED	lvm: Fix error handling when resizing lvs	2016-08-29 12:07:13 UTC
oVirt gerrit	62740	ovirt-4.0	MERGED	lvm: Separate lv reduce and extend	2016-08-29 12:07:44 UTC

Description Raz Tamir 2016-08-11 08:51:24 UTC

Created attachment 1189965 [details]
engine and vdsm logs

Description of problem:
When trying to import image from glance as template, the operation failed with "".
From the engine log we can see the the cause is failure to extend a logical volume:
2016-08-11 11:29:10,870 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-47) [5135a3b4] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Messag
e: VDSM host_mixed_1 command failed: Logical Volume extend failed
2016-08-11 11:29:10,870 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-47) [5135a3b4] SPMAsyncTask::PollTask: Polling task 'c35b7698-1a02-430a-b01a-744fd52e74e0' (Parent Command
 'ImportRepoImage', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'cleanSuccess'.
2016-08-11 11:29:10,878 ERROR [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-47) [5135a3b4] BaseAsyncTask::logEndTaskFailure: Task 'c35b7698-1a02-430a-b01a-744fd52e74e0' (Parent Comma
nd 'ImportRepoImage', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended with failure:
-- Result: 'cleanSuccess'
-- Message: 'VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = Logical Volume extend failed, code = 554',
-- Exception: 'VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = Logical Volume extend failed, code = 554'

** vdsm running on RHEL 7.3 **
From vdsm.log:
c35b7698-1a02-430a-b01a-744fd52e74e0::ERROR::2016-08-11 11:29:00,733::task::866::Storage.TaskManager.Task::(_setError) Task=`c35b7698-1a02-430a-b01a-744fd52e74e0`::Unexpected error
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/task.py", line 873, in _run
    return fn(*args, **kargs)
  File "/usr/share/vdsm/storage/task.py", line 332, in run
    return self.cmd(*self.argslist, **self.argsdict)
  File "/usr/share/vdsm/storage/securable.py", line 77, in wrapper
    return method(self, *args, **kwargs)
  File "/usr/share/vdsm/storage/sp.py", line 1742, in downloadImage
    .download(methodArgs, sdUUID, imgUUID, volUUID)
  File "/usr/share/vdsm/storage/image.py", line 1352, in download
    vol.extend(imageSharing.getSize(methodArgs) / volume.BLOCK_SIZE)
  File "/usr/share/vdsm/storage/blockVolume.py", line 310, in extend
    lvm.extendLV(self.sdUUID, self.volUUID, sizemb)
  File "/usr/share/vdsm/storage/lvm.py", line 1179, in extendLV
    _resizeLV("lvextend", vgName, lvName, size)
  File "/usr/share/vdsm/storage/lvm.py", line 1175, in _resizeLV
    raise se.LogicalVolumeExtendError(vgName, lvName, "%sM" % (size, ))
LogicalVolumeExtendError: Logical Volume extend failed: 'vgname=eceaf8e0-09d5-489c-9f9c-6dd9be4744bb lvname=9615077e-56fc-4038-98b1-6b1ec879a22e newsize=2882M'



Version-Release number of selected component (if applicable):
rhevm-doc-3.6.8-1.el6eng.noarch
vdsm-4.17.33-1.el7ev.noarch with Red Hat Enterprise Linux Server release 7.3 Beta

How reproducible:
100%

Steps to Reproduce:
1. Import image from glance as template
2. 
3.

Actual results:


Expected results:


Additional info:

Comment 1 Raz Tamir 2016-08-11 11:38:23 UTC

Also extend storage domain fails on the same Unexpected error (vdsm.log):
13d7ba04-fbce-42bf-964b-8722f0f3729e::ERROR::2016-08-11 14:35:01,107::task::866::Storage.TaskManager.Tas
k::(_setError) Task=`13d7ba04-fbce-42bf-964b-8722f0f3729e`::Unexpected error
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/task.py", line 873, in _run
    return fn(*args, **kargs)
  File "/usr/share/vdsm/storage/task.py", line 332, in run
    return self.cmd(*self.argslist, **self.argsdict)
  File "/usr/share/vdsm/storage/securable.py", line 77, in wrapper
    return method(self, *args, **kwargs)
  File "/usr/share/vdsm/storage/sp.py", line 1776, in downloadImageFromStream
    .copyToImage(methodArgs, sdUUID, imgUUID, volUUID)
  File "/usr/share/vdsm/storage/image.py", line 1373, in copyToImage
    / volume.BLOCK_SIZE)
  File "/usr/share/vdsm/storage/blockVolume.py", line 310, in extend
    lvm.extendLV(self.sdUUID, self.volUUID, sizemb)
  File "/usr/share/vdsm/storage/lvm.py", line 1179, in extendLV
    _resizeLV("lvextend", vgName, lvName, size)
  File "/usr/share/vdsm/storage/lvm.py", line 1175, in _resizeLV
    raise se.LogicalVolumeExtendError(vgName, lvName, "%sM" % (size, ))
LogicalVolumeExtendError: Logical Volume extend failed: 'vgname=d1ab09d1-ca2b-4c03-bb8e-0200e407b82c lvn
ame=3c302288-eb7c-4145-b89c-d473588c37fd newsize=1M'

In engine.log:
2016-08-11 14:32:56,432 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.ExtendStorageDomainVDSCommand] 
(ajp-/127.0.0.1:8702-3) [36ab77fb] Failed in 'ExtendStorageDomainVDS' method
2016-08-11 14:32:56,438 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (aj
p-/127.0.0.1:8702-3) [36ab77fb] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VD
SM command failed: Cannot extend Volume Group: "vgname=d1ab09d1-ca2b-4c03-bb8e-0200e407b82c, devname=['/
dev/mapper/3600a09803830347a625d467a79745247']"
2016-08-11 14:32:56,439 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (ajp-/127.0.0
.1:8702-3) [36ab77fb] IrsBroker::Failed::ExtendStorageDomainVDS: IRSGenericException: IRSErrorException:
 Failed to ExtendStorageDomainVDS, error = Cannot extend Volume Group: "vgname=d1ab09d1-ca2b-4c03-bb8e-0
200e407b82c, devname=['/dev/mapper/3600a09803830347a625d467a79745247']", code = 503

.....

2016-08-11 14:33:05,764 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.ExtendStorageDomainVDSCommand] (ajp-/127.0.0.1:8702-3) [59bbc7fa] Failed in 'ExtendStorageDomainVDS' method
2016-08-11 14:33:05,769 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp-/127.0.0.1:8702-3) [59bbc7fa] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VDSM command failed: Cannot extend Volume Group: "vgname=d1ab09d1-ca2b-4c03-bb8e-0200e407b82c, devname=['/dev/mapper/3600a09803830347a625d467a79745247']"
2016-08-11 14:33:05,770 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (ajp-/127.0.0.1:8702-3) [59bbc7fa] IrsBroker::Failed::ExtendStorageDomainVDS: IRSGenericException: IRSErrorException: Failed to ExtendStorageDomainVDS, error = Cannot extend Volume Group: "vgname=d1ab09d1-ca2b-4c03-bb8e-0200e407b82c, devname=['/dev/mapper/3600a09803830347a625d467a79745247']", code = 503
2016-08-11 14:33:05,770 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.ExtendStorageDomainVDSCommand] (ajp-/127.0.0.1:8702-3) [59bbc7fa] FINISH, ExtendStorageDomainVDSCommand, log id: 5cd72ed4
2016-08-11 14:33:05,770 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetAllTasksInfoVDSCommand] (org.ovirt.thread.pool-6-thread-16) [59bbc7fa] -- executeIrsBrokerCommand: Attempting on storage pool 'bf9ebc38-f0e3-49d0-90ea-815a04347a42'
2016-08-11 14:33:05,772 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksInfoVDSCommand] (org.ovirt.thread.pool-6-thread-16) [59bbc7fa] START, HSMGetAllTasksInfoVDSCommand(HostName = host_mixed_3, VdsIdVDSCommandParametersBase:{runAsync='true', hostId='099eb463-890f-406e-a803-27f023b0e246'}), log id: aaa3c57
2016-08-11 14:33:05,772 ERROR [org.ovirt.engine.core.bll.storage.ExtendSANStorageDomainCommand] (ajp-/127.0.0.1:8702-3) [59bbc7fa] Command 'org.ovirt.engine.core.bll.storage.ExtendSANStorageDomainCommand' failed: EngineException: org.ovirt.engine.core.vdsbroker.irsbroker.IRSErrorException: IRSGenericException: IRSErrorException: Failed to ExtendStorageDomainVDS, error = Cannot extend Volume Group: "vgname=d1ab09d1-ca2b-4c03-bb8e-0200e407b82c, devname=['/dev/mapper/3600a09803830347a625d467a79745247']", code = 503 (Failed with error VolumeGroupExtendError and code 503)
2016-08-11 14:33:05,817 INFO  [org.ovirt.engine.core.bll.storage.ExtendSANStorageDomainCommand] (ajp-/127.0.0.1:8702-3) [59bbc7fa] Command [id=af8fb9db-8b5f-4a31-bb7d-c0a9ea9aa2fe]: Compensating CHANGED_STATUS_ONLY of org.ovirt.engine.core.common.businessentities.StoragePoolIsoMap; snapshot: EntityStatusSnapshot:{id='StoragePoolIsoMapId:{storagePoolId='bf9ebc38-f0e3-49d0-90ea-815a04347a42', storageId='d1ab09d1-ca2b-4c03-bb8e-0200e407b82c'}', status='Active'}.
2016-08-11 14:33:05,835 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp-/127.0.0.1:8702-3) [59bbc7fa] Correlation ID: 1f314c2b, Job ID: 84729315-23fb-44ac-a157-2ceb908229af, Call Stack: null, Custom Event ID: -1, Message: Failed to extend Storage Domain test_raz. (User: admin@internal)
2016-08-11 14:33:05,844 WARN  [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (ajp-/127.0.0.1:8702-3) [59bbc7fa] Trying to release exclusive lock which does not exist, lock key: 'd1ab09d1-ca2b-4c03-bb8e-0200e407b82cSTORAGE'
2016-08-11 14:33:05,847 INFO  [org.ovirt.engine.core.bll.storage.ExtendSANStorageDomainCommand] (ajp-/127.0.0.1:8702-3) [59bbc7fa] Lock freed to object 'EngineLock:{exclusiveLocks='[d1ab09d1-ca2b-4c03-bb8e-0200e407b82c=<STORAGE, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
2016-08-11 14:33:05,848 ERROR [org.ovirt.engine.api.restapi.resource.AbstractBackendResource] (ajp-/127.0.0.1:8702-3) [] Operation Failed: [Cannot extend Volume Group]


Attaching logs for this too

Comment 2 Raz Tamir 2016-08-11 11:38:51 UTC

Created attachment 1190034 [details]
engine and vdsm logs for extend VG

Comment 3 Raz Tamir 2016-08-11 11:42:57 UTC

FYI, This failure of extending a storage domain leads to data center initialization

The operation of extend storage domain:
PUT /api/storagedomains/{sd:id}

<storage_domain>
    <storage>
        <type>iscsi</type>
        <logical_unit id="<NEW_LUN_ID>">
            <port>3260</port>
            <target>TARGET</target>
            <address>ISCSI_SERVER_IP</address>
        </logical_unit>
        <override_luns>true</override_luns>
    </storage>
    <host>
        <name>host_mixed_2</name>
    </host>
</storage_domain>

Comment 4 Raz Tamir 2016-08-11 11:49:41 UTC

Also deactivate storage domain with the exact failure in logs

Comment 5 Allon Mureinik 2016-08-11 12:12:27 UTC

This is a known RHEL 7.3 issue with LVM changing behavior of lvextend. We need to see if LVM can fix this regression or whether we should change something on our side.

Comment 6 Red Hat Bugzilla Rules Engine 2016-08-11 12:12:33 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 7 Yaniv Kaul 2016-08-15 08:38:59 UTC


*** This bug has been marked as a duplicate of bug 1365186 ***

Comment 8 Allon Mureinik 2016-08-15 09:08:16 UTC

(In reply to Yaniv Kaul from comment #7)
> 
> *** This bug has been marked as a duplicate of bug 1365186 ***

I'm purposely leaving this open in case the eventual decision will be NOT to fix bug 1365186, so we can track all the places that should be examined in VDSM.

Comment 9 Nir Soffer 2016-08-15 21:54:41 UTC

Can be closed as duplicate of bug 1363734.

Comment 10 Allon Mureinik 2016-08-16 08:18:47 UTC

(In reply to Nir Soffer from comment #9)
> Can be closed as duplicate of bug 1363734.

The user facing flow is different, even if the same patch solves this. Let's leave them so QE can validate both flows.

Comment 11 Raz Tamir 2016-09-05 16:04:45 UTC

Verified on ovirt-engine-4.0.4-0.1.el7ev.noarch and with vdsm running on Red Hat Enterprise Linux Server release 7.3 Beta (Maipo).
Glance image was imported successfully as template

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