Bug 820113 - [ovirt] [vdsm] getDeviceSize is called and fails as lv is not activated
[ovirt] [vdsm] getDeviceSize is called and fails as lv is not activated
Status: CLOSED NEXTRELEASE
Product: oVirt
Classification: Community
Component: vdsm (Show other bugs)
unspecified
x86_64 Linux
unspecified Severity medium
: ---
: 3.3.4
Assigned To: Eduardo Warszawski
storage
: Reopened
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2012-05-09 04:20 EDT by Haim
Modified: 2016-02-10 11:53 EST (History)
9 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2013-02-12 03:28:28 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: Storage
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)


External Trackers
Tracker ID Priority Status Summary Last Updated
oVirt gerrit 9739 None None None Never

  None (edit)
Description Haim 2012-05-09 04:20:04 EDT
Description of problem:

getDeviceSize fails with the following error:

Thread-332::WARNING::2012-05-09 10:53:05,819::blockVolume::99::Storage.Volume::(getVSize) Could not get size for vol 8db25992-bacc-4a24-ae03-c288112db1b9/878e7
8a9-c3bd-4777-b992-fd2f8bd2f104 using optimized methods
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/blockVolume.py", line 92, in getVSize
    return _getDeviceSize(lvm.lvPath(sdobj.sdUUID, volUUID)) / bs
  File "/usr/share/vdsm/storage/blockVolume.py", line 63, in _getDeviceSize
    with open(devPath, "rb") as f:
IOError: [Errno 2] No such file or directory: '/dev/8db25992-bacc-4a24-ae03-c288112db1b9/878e78a9-c3bd-4777-b992-fd2f8bd2f104'

This comes as a part of getVolumeInfo which comes after moveImage: 

Thread-332::DEBUG::2012-05-09 10:53:05,788::BindingXMLRPC::164::vds::(wrapper) [10.35.97.30]
Thread-332::DEBUG::2012-05-09 10:53:05,789::task::588::TaskManager.Task::(_updateState) Task=`fe83d9d6-3c7e-4ba2-93f7-590a1062386c`::moving from state init -> state preparing
Thread-332::INFO::2012-05-09 10:53:05,789::logUtils::37::dispatcher::(wrapper) Run and protect: getVolumeInfo(sdUUID='8db25992-bacc-4a24-ae03-c288112db1b9', spUUID='694cad94-9904-11e1-b249-ff853ff83f55', imgUUID='9a825828-c62d-454a-b2e4-59d4db1713bd', volUUID='878e78a9-c3bd-4777-b992-fd2f8bd2f104', options=None)
Thread-332::DEBUG::2012-05-09 10:53:05,790::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.8db25992-bacc-4a24-ae03-c288112db1b9`ReqID=`ee6aeeff-bc3a-46e6-b181-a24524469c94`::Request was made in '/usr/share/vdsm/storage/resourceManager.py' line '485' at 'registerResource'
Thread-332::DEBUG::2012-05-09 10:53:05,791::resourceManager::486::ResourceManager::(registerResource) Trying to register resource 'Storage.8db25992-bacc-4a24-ae03-c288112db1b9' for lock type 'shared'
Thread-332::DEBUG::2012-05-09 10:53:05,792::resourceManager::528::ResourceManager::(registerResource) Resource 'Storage.8db25992-bacc-4a24-ae03-c288112db1b9' is free. Now locking as 'shared' (1 active user)
Thread-332::DEBUG::2012-05-09 10:53:05,792::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.8db25992-bacc-4a24-ae03-c288112db1b9`ReqID=`ee6aeeff-bc3a-46e6-b181-a24524469c94`::Granted request
Thread-332::DEBUG::2012-05-09 10:53:05,793::task::817::TaskManager.Task::(resourceAcquired) Task=`fe83d9d6-3c7e-4ba2-93f7-590a1062386c`::_resourcesAcquired: Storage.8db25992-bacc-4a24-ae03-c288112db1b9 (shared)
Thread-332::DEBUG::2012-05-09 10:53:05,794::task::978::TaskManager.Task::(_decref) Task=`fe83d9d6-3c7e-4ba2-93f7-590a1062386c`::ref 1 aborting False
Thread-332::INFO::2012-05-09 10:53:05,795::volume::604::Storage.Volume::(getInfo) Info request: sdUUID=8db25992-bacc-4a24-ae03-c288112db1b9 imgUUID=9a825828-c62d-454a-b2e4-59d4db1713bd volUUID = 878e78a9-c3bd-4777-b992-fd2f8bd2f104 
Thread-332::DEBUG::2012-05-09 10:53:05,796::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd iflag=direct skip=4 bs=512 if=/dev/8db25992-bacc-4a24-ae03-c288112db1b9/metadata count=1' (cwd None)
Thread-332::DEBUG::2012-05-09 10:53:05,816::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '1+0 records in\n1+0 records out\n512 bytes (512 B) copied, 0.000859629 s, 596 kB/s\n'; <rc> = 0
Thread-332::DEBUG::2012-05-09 10:53:05,817::misc::318::Storage.Misc::(validateDDBytes) err: ['1+0 records in', '1+0 records out', '512 bytes (512 B) copied, 0.000859629 s, 596 kB/s'], size: 512
Thread-332::WARNING::2012-05-09 10:53:05,819::blockVolume::99::Storage.Volume::(getVSize) Could not get size for vol 8db25992-bacc-4a24-ae03-c288112db1b9/878e78a9-c3bd-4777-b992-fd2f8bd2f104 using optimized methods
Thread-332::WARNING::2012-05-09 10:53:05,821::blockVolume::99::Storage.Volume::(getVSize) Could not get size for vol 8db25992-bacc-4a24-ae03-c288112db1b9/878e78a9-c3bd-4777-b992-fd2f8bd2f104 using optimized methods
Thread-332::DEBUG::2012-05-09 10:53:05,823::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd iflag=direct skip=4 bs=512 if=/dev/8db25992-bacc-4a24-ae03-c288112db1b9/metadata count=1' (cwd None)
Thread-332::DEBUG::2012-05-09 10:53:05,841::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '1+0 records in\n1+0 records out\n512 bytes (512 B) copied, 0.00088936 s, 576 kB/s\n'; <rc> = 0
Thread-332::DEBUG::2012-05-09 10:53:05,842::misc::318::Storage.Misc::(validateDDBytes) err: ['1+0 records in', '1+0 records out', '512 bytes (512 B) copied, 0.00088936 s, 576 kB/s'], size: 512
Thread-332::DEBUG::2012-05-09 10:53:05,843::lvm::407::OperationMutex::(_reloadlvs) Operation 'lvm reload operation' got the operation mutex
Thread-332::DEBUG::2012-05-09 10:53:05,845::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"a%1hateya-ovirt-rc31327842|1hateya-ovirt-rc41327842%\\", \\"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,vg_name,attr,size,seg_start_pe,devices,tags 8db25992-bacc-4a24-ae03-c288112db1b9' (cwd None)
Thread-332::DEBUG::2012-05-09 10:53:06,114::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-332::DEBUG::2012-05-09 10:53:06,128::lvm::436::OperationMutex::(_reloadlvs) Operation 'lvm reload operation' released the operation mutex
Thread-332::INFO::2012-05-09 10:53:06,130::volume::632::Storage.Volume::(getInfo) 8db25992-bacc-4a24-ae03-c288112db1b9/9a825828-c62d-454a-b2e4-59d4db1713bd/878e78a9-c3bd-4777-b992-fd2f8bd2f104 info is {'status': 'OK', 'domain': '8db25992-bacc-4a24-ae03-c288112db1b9', 'truesize': '1073741824', 'voltype': 'LEAF', 'uuid': '878e78a9-c3bd-4777-b992-fd2f8bd2f104', 'parent': '00000000-0000-0000-0000-000000000000', 'format': 'RAW', 'description': '', 'children': [], 'ctime': '1336549905', 'disktype': '2', 'legality': 'LEGAL', 'mtime': '1336549907', 'capacity': '1073741824', 'apparentsize': '1073741824', 'type': 'PREALLOCATED', 'image': '9a825828-c62d-454a-b2e4-59d4db1713bd', 'pool': ''}
Thread-332::INFO::2012-05-09 10:53:06,131::logUtils::39::dispatcher::(wrapper) Run and protect: getVolumeInfo, Return response: {'info': {'status': 'OK', 'domain': '8db25992-bacc-4a24-ae03-c288112db1b9', 'truesize': '1073741824', 'voltype': 'LEAF', 'uuid': '878e78a9-c3bd-4777-b992-fd2f8bd2f104', 'parent': '00000000-0000-0000-0000-000000000000', 'format': 'RAW', 'description': '', 'children': [], 'ctime': '1336549905', 'disktype': '2', 'legality': 'LEGAL', 'mtime': '1336549907', 'capacity': '1073741824', 'apparentsize': '1073741824', 'type': 'PREALLOCATED', 'image': '9a825828-c62d-454a-b2e4-59d4db1713bd', 'pool': ''}}
Thread-332::DEBUG::2012-05-09 10:53:06,132::task::1172::TaskManager.Task::(prepare) Task=`fe83d9d6-3c7e-4ba2-93f7-590a1062386c`::finished: {'info': {'status': 'OK', 'domain': '8db25992-bacc-4a24-ae03-c288112db1b9', 'truesize': '1073741824', 'voltype': 'LEAF', 'uuid': '878e78a9-c3bd-4777-b992-fd2f8bd2f104', 'parent': '00000000-0000-0000-0000-000000000000', 'format': 'RAW', 'description': '', 'children': [], 'ctime': '1336549905', 'disktype': '2', 'legality': 'LEGAL', 'mtime': '1336549907', 'capacity': '1073741824', 'apparentsize': '1073741824', 'type': 'PREALLOCATED', 'image': '9a825828-c62d-454a-b2e4-59d4db1713bd', 'pool': ''}}
Thread-332::DEBUG::2012-05-09 10:53:06,133::task::588::TaskManager.Task::(_updateState) Task=`fe83d9d6-3c7e-4ba2-93f7-590a1062386c`::moving from state preparing -> state finished
Thread-332::DEBUG::2012-05-09 10:53:06,133::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.8db25992-bacc-4a24-ae03-c288112db1b9': < ResourceRef 'Storage.8db25992-bacc-4a24-ae03-c288112db1b9', isValid: 'True' obj: 'None'>}
Thread-332::DEBUG::2012-05-09 10:53:06,134::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-332::DEBUG::2012-05-09 10:53:06,135::resourceManager::538::ResourceManager::(releaseResource) Trying to release resource 'Storage.8db25992-bacc-4a24-ae03-c288112db1b9'
Thread-332::DEBUG::2012-05-09 10:53:06,136::resourceManager::553::ResourceManager::(releaseResource) Released resource 'Storage.8db25992-bacc-4a24-ae03-c288112db1b9' (0 active users)
Thread-332::DEBUG::2012-05-09 10:53:06,137::resourceManager::558::ResourceManager::(releaseResource) Resource 'Storage.8db25992-bacc-4a24-ae03-c288112db1b9' is free, finding out if anyone is waiting for it.
Thread-332::DEBUG::2012-05-09 10:53:06,138::resourceManager::565::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.8db25992-bacc-4a24-ae03-c288112db1b9', Clearing records.
Thread-332::DEBUG::2012-05-09 10:53:06,139::task::978::TaskManager.Task::(_decref) Task=`fe83d9d6-3c7e-4ba2-93f7-590a1062386c`::ref 0 aborting False
Comment 1 Haim 2012-05-09 04:20:52 EDT
git f2940e1717f23ffc4a1336f63623089d0c0051e2
Comment 2 Itamar Heim 2013-01-30 17:51:45 EST
Closing old bugs. If this issue is still relevant/important in current version, please re-open the bug.
Comment 3 Dan Kenigsberg 2013-01-31 04:31:42 EST
http://gerrit.ovirt.org/#/c/9739/
Comment 4 Eduardo Warszawski 2013-02-10 12:39:52 EST
Change-Id: I0a8b6da4d57cdf810769586c1959989d7a545d0c was verified by preintegration.
Comment 6 Eduardo Warszawski 2013-02-12 03:28:28 EST
This bug was moved to post by mistake. It is already merged upstream and will be available in a future release.

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