Description of problem: When attempting to display storage domain information, an error is displayed. The storage domain is in fact active and operational. Version-Release number of selected component (if applicable): vdsm-cli-4.13.2-0.13.el6ev.noarch vdsm-4.13.2-0.13.el6ev.x86_64 Steps to Reproduce: 1. list storage doamins on a hypervisor: # vdsClient -s 0 getStorageDomainsList b784393a-f5ce-4cb0-8b6d-4055bb9158b5 61726b62-e6d0-4b36-83de-1fa24a3899e5 2. try to get information about a storage domain: # vdsClient -s 0 getStorageDomainInfo b784393a-f5ce-4cb0-8b6d-4055bb9158b Actual results: # vdsClient -s 0 getStorageDomainInfo b784393a-f5ce-4cb0-8b6d-4055bb9158b5 Error in storage domain action: ('sdUUID=b784393a-f5ce-4cb0-8b6d-4055bb9158b5',) Expected results: # vdsClient -s 0 getStorageDomainInfo 61726b62-e6d0-4b36-83de-1fa24a3899e5 uuid = 61726b62-e6d0-4b36-83de-1fa24a3899e5 pool = ['207affff-2b56-4078-9414-439054bcbb70'] lver = -1 version = 0 role = Regular remotePath = test.lan:/var/lib/exports/iso spm_id = -1 type = NFS class = Iso master_ver = 0 name = ISO_DOMAIN
related thread in vdsm error.log Thread-255002::DEBUG::2014-04-17 16:33:50,666::BindingXMLRPC::167::vds::(wrapper) client [10.0.0.11] Thread-255002::DEBUG::2014-04-17 16:33:50,667::task::579::TaskManager.Task::(_updateState) Task=`065e1d60-f777-4d0d-9eae-cfd4f13e357d`::moving from state init -> state preparing Thread-255002::INFO::2014-04-17 16:33:50,667::logUtils::44::dispatcher::(wrapper) Run and protect: getStorageDomainInfo(sdUUID='b784393a-f5ce-4cb0-8b6d-4055bb9158b5', options=None) Thread-255002::INFO::2014-04-17 16:33:50,667::blockSD::828::Storage.StorageDomain::(validate) sdUUID=b784393a-f5ce-4cb0-8b6d-4055bb9158b5 Thread-255002::DEBUG::2014-04-17 16:33:50,668::lvm::309::Storage.Misc.excCmd::(cmd) '/usr/bin/sudo -n /sbin/lvm vgck --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 wr ite_cache_state=0 disable_after_error_count=3 obtain_device_list_from_udev=0 filter = [ \'a|/dev/mapper/1IET_00010001|\', \'r|.*|\' ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " b784393a-f5ce-4cb0-8b6d-4055bb9158b5' (cwd None) Dummy-46::DEBUG::2014-04-17 16:33:50,802::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) 'dd if=/rhev/data-center/207affff-2b56-4078-9414-439054bcbb70/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000' (cwd None) Thread-255002::DEBUG::2014-04-17 16:33:50,861::lvm::309::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ''; <rc> = 0 Thread-255002::DEBUG::2014-04-17 16:33:50,865::lvm::516::OperationMutex::(_invalidatevgs) Operation 'lvm invalidate operation' got the operation mutex Thread-255002::DEBUG::2014-04-17 16:33:50,867::lvm::518::OperationMutex::(_invalidatevgs) Operation 'lvm invalidate operation' released the operation mutex Thread-255002::DEBUG::2014-04-17 16:33:50,870::lvm::526::OperationMutex::(_invalidatelvs) Operation 'lvm invalidate operation' got the operation mutex Thread-255002::DEBUG::2014-04-17 16:33:50,872::lvm::538::OperationMutex::(_invalidatelvs) Operation 'lvm invalidate operation' released the operation mutex Thread-255002::DEBUG::2014-04-17 16:33:50,874::lvm::386::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex Thread-255002::DEBUG::2014-04-17 16:33:50,882::lvm::309::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 obtain_device_list_from_udev=0 filter = [ \'a|/dev/mapper/1IET_00010001|\', \'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 | --ignoreskippedcluster -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free,lv_count,pv_count,pv_name b784393a-f5ce-4cb0-8b6d-4055bb9158b5' (cwd None) Dummy-46::DEBUG::2014-04-17 16:33:50,950::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail) SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0399343 s, 25.6 MB/s\n'; <rc> = 0 Thread-255002::DEBUG::2014-04-17 16:33:51,066::lvm::309::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ''; <rc> = 0 Thread-255002::DEBUG::2014-04-17 16:33:51,069::lvm::428::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex Thread-255002::DEBUG::2014-04-17 16:33:51,069::persistentDict::234::Storage.PersistentDict::(refresh) read lines (VGTagMetadataRW)=['DESCRIPTION=111gb', 'LOCKPOLICY=', 'VERSION=3', 'TYPE=ISCSI', 'LOGBLKSIZE=512', 'LEASERETRIES=3', 'VGUUID=6vAOD7-dG1r-QEuP-SKp0-H31d-Qozv-QO25jX', 'LOCKRENEWALINTERVALSEC=5', 'PHYBLKSIZE=512', 'SDUUID=b784393a-f5ce-4cb0-8b6d-4055bb9158b5', u'PV0=pv:1IET_00010001,uuid:917cOt-vxn9-5gdd-gc6k-hoB0-F9eu-TJIOkz,pestart:0,pecount:885,mapoffset:0', 'CLASS=Data', 'LEASETIMESEC=60', 'IOOPTIMEOUTSEC=10', 'MASTER_VERSION=1', 'POOL_DESCRIPTION=jekader', 'ROLE=Master', 'POOL_UUID=207affff-2b56-4078-9414-439054bcbb70', 'POOL_SPM_ID=1', 'POOL_SPM_LVER=37', u'POOL_DOMAINS=61726b62-e6d0-4b36-83de-1fa24a3899e5:Active,b784393a-f5ce-4cb0-8b6d-4055bb9158b5:Active', '_SHA_CKSUM=276b99ce1ad9f3da59c8844a68990d463e75cb2f'] Thread-255002::DEBUG::2014-04-17 16:33:51,071::resourceManager::197::ResourceManager.Request::(__init__) ResName=`Storage.b784393a-f5ce-4cb0-8b6d-4055bb9158b5`ReqID=`e9b701bd-c3f5-4c2e-bb8d-30bb8a1e941a`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '2759' at 'getStorageDomainInfo' Thread-255002::DEBUG::2014-04-17 16:33:51,071::resourceManager::541::ResourceManager::(registerResource) Trying to register resource 'Storage.b784393a-f5ce-4cb0-8b6d-4055bb9158b5' for lock type 'shared' Thread-255002::DEBUG::2014-04-17 16:33:51,071::resourceManager::600::ResourceManager::(registerResource) Resource 'Storage.b784393a-f5ce-4cb0-8b6d-4055bb9158b5' is free. Now locking as 'shared' (1 active user) Thread-255002::DEBUG::2014-04-17 16:33:51,072::resourceManager::237::ResourceManager.Request::(grant) ResName=`Storage.b784393a-f5ce-4cb0-8b6d-4055bb9158b5`ReqID=`e9b701bd-c3f5-4c2e-bb8d-30bb8a1e941a`::Granted request Thread-255002::DEBUG::2014-04-17 16:33:51,072::task::811::TaskManager.Task::(resourceAcquired) Task=`065e1d60-f777-4d0d-9eae-cfd4f13e357d`::_resourcesAcquired: Storage.b784393a-f5ce-4cb0-8b6d-4055bb9158b5 (shared) Thread-255002::DEBUG::2014-04-17 16:33:51,072::task::974::TaskManager.Task::(_decref) Task=`065e1d60-f777-4d0d-9eae-cfd4f13e357d`::ref 1 aborting False Thread-255002::ERROR::2014-04-17 16:33:51,074::task::850::TaskManager.Task::(_setError) Task=`065e1d60-f777-4d0d-9eae-cfd4f13e357d`::Unexpected error Traceback (most recent call last): File "/usr/share/vdsm/storage/task.py", line 857, in _run return fn(*args, **kargs) File "/usr/share/vdsm/logUtils.py", line 45, in wrapper res = f(*args, **kwargs) File "/usr/share/vdsm/storage/hsm.py", line 2778, in getStorageDomainInfo info[key] = poolInfo['info'][key] KeyError: 'info' Thread-255002::DEBUG::2014-04-17 16:33:51,075::task::869::TaskManager.Task::(_run) Task=`065e1d60-f777-4d0d-9eae-cfd4f13e357d`::Task._run: 065e1d60-f777-4d0d-9eae-cfd4f13e357d ('b784393a-f5ce-4cb0-8b6d-4055bb9158b5',) {} failed - stopping task Thread-255002::DEBUG::2014-04-17 16:33:51,075::task::1194::TaskManager.Task::(stop) Task=`065e1d60-f777-4d0d-9eae-cfd4f13e357d`::stopping in state preparing (force False) Thread-255002::DEBUG::2014-04-17 16:33:51,075::task::974::TaskManager.Task::(_decref) Task=`065e1d60-f777-4d0d-9eae-cfd4f13e357d`::ref 1 aborting True Thread-255002::INFO::2014-04-17 16:33:51,076::task::1151::TaskManager.Task::(prepare) Task=`065e1d60-f777-4d0d-9eae-cfd4f13e357d`::aborting: Task is aborted: u"'info'" - code 100 Thread-255002::DEBUG::2014-04-17 16:33:51,076::task::1156::TaskManager.Task::(prepare) Task=`065e1d60-f777-4d0d-9eae-cfd4f13e357d`::Prepare: aborted: 'info' Thread-255002::DEBUG::2014-04-17 16:33:51,076::task::974::TaskManager.Task::(_decref) Task=`065e1d60-f777-4d0d-9eae-cfd4f13e357d`::ref 0 aborting True Thread-255002::DEBUG::2014-04-17 16:33:51,076::task::909::TaskManager.Task::(_doAbort) Task=`065e1d60-f777-4d0d-9eae-cfd4f13e357d`::Task._doAbort: force False Thread-255002::DEBUG::2014-04-17 16:33:51,077::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-255002::DEBUG::2014-04-17 16:33:51,077::task::579::TaskManager.Task::(_updateState) Task=`065e1d60-f777-4d0d-9eae-cfd4f13e357d`::moving from state preparing -> state aborting Thread-255002::DEBUG::2014-04-17 16:33:51,077::task::534::TaskManager.Task::(__state_aborting) Task=`065e1d60-f777-4d0d-9eae-cfd4f13e357d`::_aborting: recover policy none Thread-255002::DEBUG::2014-04-17 16:33:51,077::task::579::TaskManager.Task::(_updateState) Task=`065e1d60-f777-4d0d-9eae-cfd4f13e357d`::moving from state aborting -> state failed Thread-255002::DEBUG::2014-04-17 16:33:51,078::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.b784393a-f5ce-4cb0-8b6d-4055bb9158b5': < ResourceRef 'Storage.b784393a-f5ce-4cb0-8b6d-4055bb9158b5', isValid: 'True' obj: 'None'>} Thread-255002::DEBUG::2014-04-17 16:33:51,078::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-255002::DEBUG::2014-04-17 16:33:51,078::resourceManager::615::ResourceManager::(releaseResource) Trying to release resource 'Storage.b784393a-f5ce-4cb0-8b6d-4055bb9158b5' Thread-255002::DEBUG::2014-04-17 16:33:51,079::resourceManager::634::ResourceManager::(releaseResource) Released resource 'Storage.b784393a-f5ce-4cb0-8b6d-4055bb9158b5' (0 active users) Thread-255002::DEBUG::2014-04-17 16:33:51,079::resourceManager::640::ResourceManager::(releaseResource) Resource 'Storage.b784393a-f5ce-4cb0-8b6d-4055bb9158b5' is free, finding out if anyone is waiting for it. Thread-255002::DEBUG::2014-04-17 16:33:51,079::resourceManager::648::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.b784393a-f5ce-4cb0-8b6d-4055bb9158b5', Clearing records. Thread-255002::ERROR::2014-04-17 16:33:51,079::dispatcher::70::Storage.Dispatcher.Protect::(run) 'info' Traceback (most recent call last): File "/usr/share/vdsm/storage/dispatcher.py", line 62, in run result = ctask.prepare(self.func, *args, **kwargs) File "/usr/share/vdsm/storage/task.py", line 1159, in prepare raise self.error KeyError: 'info'
Yoav/Federico, didn't you already solve a similar issue>? *** This bug has been marked as a duplicate of bug 1084970 ***
(In reply to Allon Mureinik from comment #2) > Yoav/Federico, didn't you already solve a similar issue>? Yoav/Federico, feel free to ignore the question - started typing it and then found the dup myself. This is clearly the same issue as bug 1084970