Note: This is a beta release of Red Hat Bugzilla 5.0. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Also email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback here.
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
Version: 3.6.7
Hardware: Unspecified
OS: Unspecified
unspecified
high vote
Target Milestone: ovirt-4.0.4
: 4.0.4
Assignee: Nir Soffer
QA Contact: Raz Tamir
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)
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
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 (deleted)
2016-08-11 08:51 UTC, Raz Tamir
no flags Details
engine and vdsm logs for extend VG (deleted)
2016-08-11 11:38 UTC, Raz Tamir
no flags Details


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.