Bug 803751 - [ovirt] [vdsm] pool upgrade: hsm using 'dd' instead of 'vgs' to read metadata and fails
[ovirt] [vdsm] pool upgrade: hsm using 'dd' instead of 'vgs' to read metadata...
Status: CLOSED WONTFIX
Product: oVirt
Classification: Community
Component: vdsm (Show other bugs)
unspecified
Unspecified Unspecified
unspecified Severity high
: ---
: 3.3.4
Assigned To: Saggi Mizrahi
storage
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2012-03-15 11:14 EDT by Haim
Modified: 2016-02-10 12:10 EST (History)
8 users (show)

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


Attachments (Terms of Use)

  None (edit)
Description Haim 2012-03-15 11:14:32 EDT
Description of problem:

- upgrade pool with 2 hosts in it 
- backend send refreshStoragePool to hsm
- hsm use dd to read metadata, however, since all data resides within vg tags, it gets none. 

Example: 

SPM HOST - 

Thread-707092::INFO::2012-03-15 14:26:25,028::logUtils::37::dispatcher::(wrapper) Run and protect: refreshStoragePool(spUUID='535071a7-d5bb-4984-bce9-20effde5b793', msdUUID='218fdf2c-021b-4236-8f70-4aaa8af3e000', masterVersion=1, options=None)
Thread-707092::DEBUG::2012-03-15 14:26:25,029::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.535071a7-d5bb-4984-bce9-20effde5b793`ReqID=`06f7ed36-3a67-470c-ad50-fc21e1d0c221`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '687' at 'refreshStoragePool'
Thread-707092::DEBUG::2012-03-15 14:26:25,030::resourceManager::486::ResourceManager::(registerResource) Trying to register resource 'Storage.535071a7-d5bb-4984-bce9-20effde5b793' for lock type 'shared'
Thread-707092::DEBUG::2012-03-15 14:26:25,030::resourceManager::528::ResourceManager::(registerResource) Resource 'Storage.535071a7-d5bb-4984-bce9-20effde5b793' is free. Now locking as 'shared' (1 active user)
Thread-707092::DEBUG::2012-03-15 14:26:25,031::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.535071a7-d5bb-4984-bce9-20effde5b793`ReqID=`06f7ed36-3a67-470c-ad50-fc21e1d0c221`::Granted request
Thread-707092::DEBUG::2012-03-15 14:26:25,031::task::817::TaskManager.Task::(resourceAcquired) Task=`4fbaff3e-e4b2-4eca-9129-160467eea354`::_resourcesAcquired: Storage.535071a7-d5bb-4984-bce9-20effde5b793 (shared)
Thread-707092::DEBUG::2012-03-15 14:26:25,032::task::978::TaskManager.Task::(_decref) Task=`4fbaff3e-e4b2-4eca-9129-160467eea354`::ref 1 aborting False
Thread-707092::INFO::2012-03-15 14:26:25,032::blockSD::699::Storage.StorageDomain::(validate) sdUUID=218fdf2c-021b-4236-8f70-4aaa8af3e000
Thread-707092::DEBUG::2012-03-15 14:26:25,033::lvm::349::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
Thread-707092::DEBUG::2012-03-15 14:26:25,034::lvm::284::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 = [ \\"a%1locking-type-lun1-rami-5|1locking-type-lun2-rami-5|1locking-type-lun3-rami-5|3514f0c51afe00012|3514f0c51afe00013|3514f0c51afe00014|3514f0c51afe00015|3514f0c51afe00016|3514f0c51afe00017|3514f0c51afe00018|3514f0c51afe00019|3514f0c51afe0001a|3514f0c51afe0001b|3514f0c51afe0001c|3514f0c51afe0001d|3514f0c51afe0001e|3514f0c51afe0001f|3514f0c51afe00020|3514f0c51afe00021|3514f0c51afe00022|3514f0c51afe00023|3514f0c51afe00024|3514f0c51afe00025|3514f0c51afe00026|3514f0c51afe00027|3514f0c51afe00028|3514f0c51afe00029|3514f0c51afe0002a|3514f0c51afe0002b|3514f0c51afe0002c|3514f0c51afe0002d|3514f0c51afe0002e|3514f0c51afe0002f%\\", \\"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 218fdf2c-021b-4236-8f70-4aaa8af3e000' (cwd None)


HSM Host:

hread-7495::INFO::2012-03-15 14:25:54,697::logUtils::37::dispatcher::(wrapper) Run and protect: refreshStoragePool(spUUID='535071a7-d5bb-4984-bce9-20effde5b793', msdUUID='218fdf2c-021b-4236-8f70-4aaa8af3e000', masterVersion=1, options=
None)
Thread-7495::DEBUG::2012-03-15 14:25:54,698::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.535071a7-d5bb-4984-bce9-20effde5b793`ReqID=`eaa9e978-dbb8-4a40-ba07-17d950ae4c26`::Request was made in '/usr/share/v
dsm/storage/hsm.py' line '693' at 'refreshStoragePool'
Thread-7495::DEBUG::2012-03-15 14:25:54,698::resourceManager::486::ResourceManager::(registerResource) Trying to register resource 'Storage.535071a7-d5bb-4984-bce9-20effde5b793' for lock type 'shared'
Thread-7495::DEBUG::2012-03-15 14:25:54,699::resourceManager::528::ResourceManager::(registerResource) Resource 'Storage.535071a7-d5bb-4984-bce9-20effde5b793' is free. Now locking as 'shared' (1 active user)
Thread-7495::DEBUG::2012-03-15 14:25:54,699::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.535071a7-d5bb-4984-bce9-20effde5b793`ReqID=`eaa9e978-dbb8-4a40-ba07-17d950ae4c26`::Granted request
Thread-7495::DEBUG::2012-03-15 14:25:54,700::task::817::TaskManager.Task::(resourceAcquired) Task=`4675dffc-e455-47a1-be23-8ad59fe3f674`::_resourcesAcquired: Storage.535071a7-d5bb-4984-bce9-20effde5b793 (shared)
Thread-7495::DEBUG::2012-03-15 14:25:54,700::task::978::TaskManager.Task::(_decref) Task=`4675dffc-e455-47a1-be23-8ad59fe3f674`::ref 1 aborting False
Thread-7495::INFO::2012-03-15 14:25:54,701::blockSD::701::Storage.StorageDomain::(validate) sdUUID=218fdf2c-021b-4236-8f70-4aaa8af3e000
Thread-7495::DEBUG::2012-03-15 14:25:54,702::blockSD::177::Storage.Misc.excCmd::(readlines) '/bin/dd iflag=direct skip=0 bs=2048 if=/dev/218fdf2c-021b-4236-8f70-4aaa8af3e000/metadata count=1' (cwd None)
Thread-7495::DEBUG::2012-03-15 14:25:54,711::blockSD::177::Storage.Misc.excCmd::(readlines) SUCCESS: <err> = '1+0 records in\n1+0 records out\n2048 bytes (2.0 kB) copied, 0.000550194 s, 3.7 MB/s\n'; <rc> = 0
Thread-7495::DEBUG::2012-03-15 14:25:54,711::misc::318::Storage.Misc::(validateDDBytes) err: ['1+0 records in', '1+0 records out', '2048 bytes (2.0 kB) copied, 0.000550194 s, 3.7 MB/s'], size: 2048
Thread-7495::DEBUG::2012-03-15 14:25:54,712::persistentDict::216::Storage.PersistentDict::(refresh) read lines (LvMetadataRW)=['_SHA_CKSUM=da39a3ee5e6b4b0d3255bfef95601890afd80709']
Thread-7495::DEBUG::2012-03-15 14:25:54,713::lvm::457::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-7495::DEBUG::2012-03-15 14:25:54,713::lvm::459::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-7495::DEBUG::2012-03-15 14:25:54,714::lvm::469::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
Thread-7495::DEBUG::2012-03-15 14:25:54,714::lvm::471::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
Thread-7495::DEBUG::2012-03-15 14:25:54,715::lvm::490::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-7495::DEBUG::2012-03-15 14:25:54,716::lvm::492::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-7495::INFO::2012-03-15 14:25:54,716::sp::668::Storage.StoragePool::(disconnect) Disconnect from the storage pool 535071a7-d5bb-4984-bce9-20effde5b793
Thread-7495::ERROR::2012-03-15 14:25:54,717::task::853::TaskManager.Task::(_setError) Task=`4675dffc-e455-47a1-be23-8ad59fe3f674`::Unexpected error
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/task.py", line 861, in _run
    return fn(*args, **kargs)
  File "/usr/share/vdsm/logUtils.py", line 38, in wrapper
    res = f(*args, **kwargs)
  File "/usr/share/vdsm/storage/hsm.py", line 699, in refreshStoragePool
    self._disconnectPool(pool, pool.id, pool.scsiKey, False)
  File "/usr/share/vdsm/storage/hsm.py", line 898, in _disconnectPool
    res = pool.disconnect()
  File "/usr/share/vdsm/storage/sp.py", line 671, in disconnect
    for sdUUID in self.getDomains(activeOnly=True):
  File "/usr/share/vdsm/storage/sp.py", line 1496, in getDomains
    for sdUUID, status in self.getMetaParam(PMDK_DOMAINS).iteritems() \
  File "/usr/share/vdsm/storage/sp.py", line 1428, in getMetaParam
    return self._metadata[key]
  File "/usr/share/vdsm/storage/persistentDict.py", line 75, in __getitem__
    return dec(self._dict[key])
  File "/usr/share/vdsm/storage/persistentDict.py", line 185, in __getitem__
    raise KeyError(key)
KeyError: 'POOL_DOMAINS'
Comment 1 Itamar Heim 2013-03-12 05:37:51 EDT
Closing old bugs. If this issue is still relevant/important in current version, please re-open the bug.

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