Login
[x]
Log in using an account from:
Fedora Account System
Red Hat Associate
Red Hat Customer
Or login using a Red Hat Bugzilla account
Forgot Password
Login:
Hide Forgot
Create an Account
Red Hat Bugzilla – Attachment 641526 Details for
Bug 874120
While installing VM following error is displyed File "/usr/share/vdsm/storage/task.py", line 861, in _run
[?]
New
Simple Search
Advanced Search
My Links
Browse
Requests
Reports
Current State
Search
Tabular reports
Graphical reports
Duplicates
Other Reports
User Changes
Plotly Reports
Bug Status
Bug Severity
Non-Defaults
|
Product Dashboard
Help
Page Help!
Bug Writing Guidelines
What's new
Browser Support Policy
5.0.4.rh83 Release notes
FAQ
Guides index
User guide
Web Services
Contact
Legal
This site requires JavaScript to be enabled to function correctly, please enable it.
Full vdsm.log
vdsm.log (text/x-log), 74.10 KB, created by
Valentin Bajrami
on 2012-11-09 13:11:09 UTC
(
hide
)
Description:
Full vdsm.log
Filename:
MIME Type:
Creator:
Valentin Bajrami
Created:
2012-11-09 13:11:09 UTC
Size:
74.10 KB
patch
obsolete
>Thread-551::DEBUG::2012-11-09 06:06:32,118::BindingXMLRPC::156::vds::(wrapper) [192.168.2.113] >Thread-551::DEBUG::2012-11-09 06:06:32,119::task::588::TaskManager.Task::(_updateState) Task=`c2dc6cf5-bb5b-47d9-8228-a7f9ed8e1735`::moving from state init -> state preparing >Thread-551::INFO::2012-11-09 06:06:32,119::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='c02503a4-274e-11e2-b33c-002590730631', options=None) >Thread-551::ERROR::2012-11-09 06:06:32,119::task::853::TaskManager.Task::(_setError) Task=`c2dc6cf5-bb5b-47d9-8228-a7f9ed8e1735`::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 528, in getSpmStatus > pool = self.getPool(spUUID) > File "/usr/share/vdsm/storage/hsm.py", line 265, in getPool > raise se.StoragePoolUnknown(spUUID) >StoragePoolUnknown: Unknown pool id, pool not connected: ('c02503a4-274e-11e2-b33c-002590730631',) >Thread-551::DEBUG::2012-11-09 06:06:32,119::task::872::TaskManager.Task::(_run) Task=`c2dc6cf5-bb5b-47d9-8228-a7f9ed8e1735`::Task._run: c2dc6cf5-bb5b-47d9-8228-a7f9ed8e1735 ('c02503a4-274e-11e2-b33c-002590730631',) {} failed - stopping task >Thread-551::DEBUG::2012-11-09 06:06:32,120::task::1199::TaskManager.Task::(stop) Task=`c2dc6cf5-bb5b-47d9-8228-a7f9ed8e1735`::stopping in state preparing (force False) >Thread-551::DEBUG::2012-11-09 06:06:32,120::task::978::TaskManager.Task::(_decref) Task=`c2dc6cf5-bb5b-47d9-8228-a7f9ed8e1735`::ref 1 aborting True >Thread-551::INFO::2012-11-09 06:06:32,120::task::1157::TaskManager.Task::(prepare) Task=`c2dc6cf5-bb5b-47d9-8228-a7f9ed8e1735`::aborting: Task is aborted: 'Unknown pool id, pool not connected' - code 309 >Thread-551::DEBUG::2012-11-09 06:06:32,120::task::1162::TaskManager.Task::(prepare) Task=`c2dc6cf5-bb5b-47d9-8228-a7f9ed8e1735`::Prepare: aborted: Unknown pool id, pool not connected >Thread-551::DEBUG::2012-11-09 06:06:32,120::task::978::TaskManager.Task::(_decref) Task=`c2dc6cf5-bb5b-47d9-8228-a7f9ed8e1735`::ref 0 aborting True >Thread-551::DEBUG::2012-11-09 06:06:32,121::task::913::TaskManager.Task::(_doAbort) Task=`c2dc6cf5-bb5b-47d9-8228-a7f9ed8e1735`::Task._doAbort: force False >Thread-551::DEBUG::2012-11-09 06:06:32,121::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-551::DEBUG::2012-11-09 06:06:32,121::task::588::TaskManager.Task::(_updateState) Task=`c2dc6cf5-bb5b-47d9-8228-a7f9ed8e1735`::moving from state preparing -> state aborting >Thread-551::DEBUG::2012-11-09 06:06:32,121::task::537::TaskManager.Task::(__state_aborting) Task=`c2dc6cf5-bb5b-47d9-8228-a7f9ed8e1735`::_aborting: recover policy none >Thread-551::DEBUG::2012-11-09 06:06:32,121::task::588::TaskManager.Task::(_updateState) Task=`c2dc6cf5-bb5b-47d9-8228-a7f9ed8e1735`::moving from state aborting -> state failed >Thread-551::DEBUG::2012-11-09 06:06:32,121::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-551::DEBUG::2012-11-09 06:06:32,121::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-551::ERROR::2012-11-09 06:06:32,122::dispatcher::66::Storage.Dispatcher.Protect::(run) {'status': {'message': "Unknown pool id, pool not connected: ('c02503a4-274e-11e2-b33c-002590730631',)", 'code': 309}} >Thread-552::DEBUG::2012-11-09 06:06:32,162::BindingXMLRPC::156::vds::(wrapper) [192.168.2.113] >Thread-552::DEBUG::2012-11-09 06:06:32,162::task::588::TaskManager.Task::(_updateState) Task=`0157a04c-67e2-4a37-a709-2e8bbb390f0d`::moving from state init -> state preparing >Thread-552::INFO::2012-11-09 06:06:32,162::logUtils::37::dispatcher::(wrapper) Run and protect: connectStoragePool(spUUID='c02503a4-274e-11e2-b33c-002590730631', hostID=1, scsiKey='c02503a4-274e-11e2-b33c-002590730631', msdUUID='b1658676-2dc3-4357-b112-3852a056c663', masterVersion=1, options=None) >Thread-552::DEBUG::2012-11-09 06:06:32,163::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.c02503a4-274e-11e2-b33c-002590730631`ReqID=`510acdb7-c7ec-4738-86b5-3d332b895362`::Request was made in '/usr/share/vdsm/storage/resourceManager.py' line '485' at 'registerResource' >Thread-552::DEBUG::2012-11-09 06:06:32,163::resourceManager::486::ResourceManager::(registerResource) Trying to register resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' for lock type 'exclusive' >Thread-552::DEBUG::2012-11-09 06:06:32,163::resourceManager::528::ResourceManager::(registerResource) Resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' is free. Now locking as 'exclusive' (1 active user) >Thread-552::DEBUG::2012-11-09 06:06:32,164::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.c02503a4-274e-11e2-b33c-002590730631`ReqID=`510acdb7-c7ec-4738-86b5-3d332b895362`::Granted request >Thread-552::INFO::2012-11-09 06:06:32,164::sp::625::Storage.StoragePool::(connect) Connect host #1 to the storage pool c02503a4-274e-11e2-b33c-002590730631 with master domain: b1658676-2dc3-4357-b112-3852a056c663 (ver = 1) >Thread-552::DEBUG::2012-11-09 06:06:32,164::lvm::457::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-552::DEBUG::2012-11-09 06:06:32,165::lvm::459::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-552::DEBUG::2012-11-09 06:06:32,165::lvm::469::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex >Thread-552::DEBUG::2012-11-09 06:06:32,165::lvm::471::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex >Thread-552::DEBUG::2012-11-09 06:06:32,165::lvm::490::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-552::DEBUG::2012-11-09 06:06:32,166::lvm::492::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-552::DEBUG::2012-11-09 06:06:32,166::misc::1053::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) >Thread-552::DEBUG::2012-11-09 06:06:32,166::misc::1055::SamplingMethod::(__call__) Got in to sampling method >Thread-552::DEBUG::2012-11-09 06:06:32,166::misc::1053::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) >Thread-552::DEBUG::2012-11-09 06:06:32,166::misc::1055::SamplingMethod::(__call__) Got in to sampling method >Thread-552::DEBUG::2012-11-09 06:06:32,167::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) >Thread-552::DEBUG::2012-11-09 06:06:32,182::__init__::1249::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21 >Thread-552::DEBUG::2012-11-09 06:06:32,182::misc::1063::SamplingMethod::(__call__) Returning last result >Thread-552::DEBUG::2012-11-09 06:06:32,868::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None) >Thread-552::DEBUG::2012-11-09 06:06:32,929::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0 >Thread-552::DEBUG::2012-11-09 06:06:32,929::lvm::457::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-552::DEBUG::2012-11-09 06:06:32,930::lvm::459::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-552::DEBUG::2012-11-09 06:06:32,930::lvm::469::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex >Thread-552::DEBUG::2012-11-09 06:06:32,930::lvm::471::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex >Thread-552::DEBUG::2012-11-09 06:06:32,930::lvm::490::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-552::DEBUG::2012-11-09 06:06:32,930::lvm::492::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-552::DEBUG::2012-11-09 06:06:32,931::misc::1063::SamplingMethod::(__call__) Returning last result >Thread-552::DEBUG::2012-11-09 06:06:32,931::lvm::349::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex >Thread-552::DEBUG::2012-11-09 06:06:32,932::__init__::1249::Storage.Misc.excCmd::(_log) '/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 = [ \\"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 b1658676-2dc3-4357-b112-3852a056c663' (cwd None) >Thread-552::DEBUG::2012-11-09 06:06:32,980::__init__::1249::Storage.Misc.excCmd::(_log) FAILED: <err> = ' Volume group "b1658676-2dc3-4357-b112-3852a056c663" not found\n'; <rc> = 5 >Thread-552::WARNING::2012-11-09 06:06:32,981::lvm::353::Storage.LVM::(_reloadvgs) lvm vgs failed: 5 [] [' Volume group "b1658676-2dc3-4357-b112-3852a056c663" not found'] >Thread-552::DEBUG::2012-11-09 06:06:32,982::lvm::376::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex >Thread-552::DEBUG::2012-11-09 06:06:32,984::resourceManager::538::ResourceManager::(releaseResource) Trying to release resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' >Thread-552::DEBUG::2012-11-09 06:06:32,985::resourceManager::553::ResourceManager::(releaseResource) Released resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' (0 active users) >Thread-552::DEBUG::2012-11-09 06:06:32,985::resourceManager::558::ResourceManager::(releaseResource) Resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' is free, finding out if anyone is waiting for it. >Thread-552::DEBUG::2012-11-09 06:06:32,985::resourceManager::565::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.c02503a4-274e-11e2-b33c-002590730631', Clearing records. >Thread-552::ERROR::2012-11-09 06:06:32,985::task::853::TaskManager.Task::(_setError) Task=`0157a04c-67e2-4a37-a709-2e8bbb390f0d`::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 817, in connectStoragePool > return self._connectStoragePool(spUUID, hostID, scsiKey, msdUUID, masterVersion, options) > File "/usr/share/vdsm/storage/hsm.py", line 859, in _connectStoragePool > res = pool.connect(hostID, scsiKey, msdUUID, masterVersion) > File "/usr/share/vdsm/storage/sp.py", line 641, in connect > self.__rebuild(msdUUID=msdUUID, masterVersion=masterVersion) > File "/usr/share/vdsm/storage/sp.py", line 1109, in __rebuild > self.masterDomain = self.getMasterDomain(msdUUID=msdUUID, masterVersion=masterVersion) > File "/usr/share/vdsm/storage/sp.py", line 1448, in getMasterDomain > raise se.StoragePoolMasterNotFound(self.spUUID, msdUUID) >StoragePoolMasterNotFound: Cannot find master domain: 'spUUID=c02503a4-274e-11e2-b33c-002590730631, msdUUID=b1658676-2dc3-4357-b112-3852a056c663' >Thread-552::DEBUG::2012-11-09 06:06:32,985::task::872::TaskManager.Task::(_run) Task=`0157a04c-67e2-4a37-a709-2e8bbb390f0d`::Task._run: 0157a04c-67e2-4a37-a709-2e8bbb390f0d ('c02503a4-274e-11e2-b33c-002590730631', 1, 'c02503a4-274e-11e2-b33c-002590730631', 'b1658676-2dc3-4357-b112-3852a056c663', 1) {} failed - stopping task >Thread-552::DEBUG::2012-11-09 06:06:32,986::task::1199::TaskManager.Task::(stop) Task=`0157a04c-67e2-4a37-a709-2e8bbb390f0d`::stopping in state preparing (force False) >Thread-552::DEBUG::2012-11-09 06:06:32,986::task::978::TaskManager.Task::(_decref) Task=`0157a04c-67e2-4a37-a709-2e8bbb390f0d`::ref 1 aborting True >Thread-552::INFO::2012-11-09 06:06:32,986::task::1157::TaskManager.Task::(prepare) Task=`0157a04c-67e2-4a37-a709-2e8bbb390f0d`::aborting: Task is aborted: 'Cannot find master domain' - code 304 >Thread-552::DEBUG::2012-11-09 06:06:32,986::task::1162::TaskManager.Task::(prepare) Task=`0157a04c-67e2-4a37-a709-2e8bbb390f0d`::Prepare: aborted: Cannot find master domain >Thread-552::DEBUG::2012-11-09 06:06:32,986::task::978::TaskManager.Task::(_decref) Task=`0157a04c-67e2-4a37-a709-2e8bbb390f0d`::ref 0 aborting True >Thread-552::DEBUG::2012-11-09 06:06:32,986::task::913::TaskManager.Task::(_doAbort) Task=`0157a04c-67e2-4a37-a709-2e8bbb390f0d`::Task._doAbort: force False >Thread-552::DEBUG::2012-11-09 06:06:32,986::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-552::DEBUG::2012-11-09 06:06:32,986::task::588::TaskManager.Task::(_updateState) Task=`0157a04c-67e2-4a37-a709-2e8bbb390f0d`::moving from state preparing -> state aborting >Thread-552::DEBUG::2012-11-09 06:06:32,987::task::537::TaskManager.Task::(__state_aborting) Task=`0157a04c-67e2-4a37-a709-2e8bbb390f0d`::_aborting: recover policy none >Thread-552::DEBUG::2012-11-09 06:06:32,987::task::588::TaskManager.Task::(_updateState) Task=`0157a04c-67e2-4a37-a709-2e8bbb390f0d`::moving from state aborting -> state failed >Thread-552::DEBUG::2012-11-09 06:06:32,987::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-552::DEBUG::2012-11-09 06:06:32,987::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-552::ERROR::2012-11-09 06:06:32,987::dispatcher::66::Storage.Dispatcher.Protect::(run) {'status': {'message': "Cannot find master domain: 'spUUID=c02503a4-274e-11e2-b33c-002590730631, msdUUID=b1658676-2dc3-4357-b112-3852a056c663'", 'code': 304}} >Thread-555::DEBUG::2012-11-09 06:06:33,987::task::588::TaskManager.Task::(_updateState) Task=`3ab39083-7264-4792-ace0-2169806975c4`::moving from state init -> state preparing >Thread-555::INFO::2012-11-09 06:06:33,988::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) >Thread-555::INFO::2012-11-09 06:06:33,988::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} >Thread-555::DEBUG::2012-11-09 06:06:33,988::task::1172::TaskManager.Task::(prepare) Task=`3ab39083-7264-4792-ace0-2169806975c4`::finished: {} >Thread-555::DEBUG::2012-11-09 06:06:33,988::task::588::TaskManager.Task::(_updateState) Task=`3ab39083-7264-4792-ace0-2169806975c4`::moving from state preparing -> state finished >Thread-555::DEBUG::2012-11-09 06:06:33,988::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-555::DEBUG::2012-11-09 06:06:33,989::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-555::DEBUG::2012-11-09 06:06:33,989::task::978::TaskManager.Task::(_decref) Task=`3ab39083-7264-4792-ace0-2169806975c4`::ref 0 aborting False >Thread-561::DEBUG::2012-11-09 06:06:43,196::BindingXMLRPC::156::vds::(wrapper) [192.168.2.113] >Thread-561::DEBUG::2012-11-09 06:06:43,196::task::588::TaskManager.Task::(_updateState) Task=`9438b74e-4503-4aea-ab24-b70987d9c74e`::moving from state init -> state preparing >Thread-561::INFO::2012-11-09 06:06:43,196::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='c02503a4-274e-11e2-b33c-002590730631', options=None) >Thread-561::ERROR::2012-11-09 06:06:43,196::task::853::TaskManager.Task::(_setError) Task=`9438b74e-4503-4aea-ab24-b70987d9c74e`::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 528, in getSpmStatus > pool = self.getPool(spUUID) > File "/usr/share/vdsm/storage/hsm.py", line 265, in getPool > raise se.StoragePoolUnknown(spUUID) >StoragePoolUnknown: Unknown pool id, pool not connected: ('c02503a4-274e-11e2-b33c-002590730631',) >Thread-561::DEBUG::2012-11-09 06:06:43,197::task::872::TaskManager.Task::(_run) Task=`9438b74e-4503-4aea-ab24-b70987d9c74e`::Task._run: 9438b74e-4503-4aea-ab24-b70987d9c74e ('c02503a4-274e-11e2-b33c-002590730631',) {} failed - stopping task >Thread-561::DEBUG::2012-11-09 06:06:43,197::task::1199::TaskManager.Task::(stop) Task=`9438b74e-4503-4aea-ab24-b70987d9c74e`::stopping in state preparing (force False) >Thread-561::DEBUG::2012-11-09 06:06:43,197::task::978::TaskManager.Task::(_decref) Task=`9438b74e-4503-4aea-ab24-b70987d9c74e`::ref 1 aborting True >Thread-561::INFO::2012-11-09 06:06:43,197::task::1157::TaskManager.Task::(prepare) Task=`9438b74e-4503-4aea-ab24-b70987d9c74e`::aborting: Task is aborted: 'Unknown pool id, pool not connected' - code 309 >Thread-561::DEBUG::2012-11-09 06:06:43,197::task::1162::TaskManager.Task::(prepare) Task=`9438b74e-4503-4aea-ab24-b70987d9c74e`::Prepare: aborted: Unknown pool id, pool not connected >Thread-561::DEBUG::2012-11-09 06:06:43,197::task::978::TaskManager.Task::(_decref) Task=`9438b74e-4503-4aea-ab24-b70987d9c74e`::ref 0 aborting True >Thread-561::DEBUG::2012-11-09 06:06:43,197::task::913::TaskManager.Task::(_doAbort) Task=`9438b74e-4503-4aea-ab24-b70987d9c74e`::Task._doAbort: force False >Thread-561::DEBUG::2012-11-09 06:06:43,197::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-561::DEBUG::2012-11-09 06:06:43,197::task::588::TaskManager.Task::(_updateState) Task=`9438b74e-4503-4aea-ab24-b70987d9c74e`::moving from state preparing -> state aborting >Thread-561::DEBUG::2012-11-09 06:06:43,197::task::537::TaskManager.Task::(__state_aborting) Task=`9438b74e-4503-4aea-ab24-b70987d9c74e`::_aborting: recover policy none >Thread-561::DEBUG::2012-11-09 06:06:43,197::task::588::TaskManager.Task::(_updateState) Task=`9438b74e-4503-4aea-ab24-b70987d9c74e`::moving from state aborting -> state failed >Thread-561::DEBUG::2012-11-09 06:06:43,197::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-561::DEBUG::2012-11-09 06:06:43,198::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-561::ERROR::2012-11-09 06:06:43,198::dispatcher::66::Storage.Dispatcher.Protect::(run) {'status': {'message': "Unknown pool id, pool not connected: ('c02503a4-274e-11e2-b33c-002590730631',)", 'code': 309}} >Thread-562::DEBUG::2012-11-09 06:06:43,239::BindingXMLRPC::156::vds::(wrapper) [192.168.2.113] >Thread-562::DEBUG::2012-11-09 06:06:43,239::task::588::TaskManager.Task::(_updateState) Task=`8dad86d1-15e1-4d1b-bec7-c29f8075b323`::moving from state init -> state preparing >Thread-562::INFO::2012-11-09 06:06:43,239::logUtils::37::dispatcher::(wrapper) Run and protect: connectStoragePool(spUUID='c02503a4-274e-11e2-b33c-002590730631', hostID=1, scsiKey='c02503a4-274e-11e2-b33c-002590730631', msdUUID='b1658676-2dc3-4357-b112-3852a056c663', masterVersion=1, options=None) >Thread-562::DEBUG::2012-11-09 06:06:43,239::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.c02503a4-274e-11e2-b33c-002590730631`ReqID=`356f7a98-2db7-43d6-bbc9-0c5a6d3c7af1`::Request was made in '/usr/share/vdsm/storage/resourceManager.py' line '485' at 'registerResource' >Thread-562::DEBUG::2012-11-09 06:06:43,239::resourceManager::486::ResourceManager::(registerResource) Trying to register resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' for lock type 'exclusive' >Thread-562::DEBUG::2012-11-09 06:06:43,240::resourceManager::528::ResourceManager::(registerResource) Resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' is free. Now locking as 'exclusive' (1 active user) >Thread-562::DEBUG::2012-11-09 06:06:43,240::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.c02503a4-274e-11e2-b33c-002590730631`ReqID=`356f7a98-2db7-43d6-bbc9-0c5a6d3c7af1`::Granted request >Thread-562::INFO::2012-11-09 06:06:43,240::sp::625::Storage.StoragePool::(connect) Connect host #1 to the storage pool c02503a4-274e-11e2-b33c-002590730631 with master domain: b1658676-2dc3-4357-b112-3852a056c663 (ver = 1) >Thread-562::DEBUG::2012-11-09 06:06:43,240::lvm::457::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-562::DEBUG::2012-11-09 06:06:43,240::lvm::459::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-562::DEBUG::2012-11-09 06:06:43,240::lvm::469::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex >Thread-562::DEBUG::2012-11-09 06:06:43,240::lvm::471::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex >Thread-562::DEBUG::2012-11-09 06:06:43,241::lvm::490::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-562::DEBUG::2012-11-09 06:06:43,241::lvm::492::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-562::DEBUG::2012-11-09 06:06:43,241::misc::1053::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) >Thread-562::DEBUG::2012-11-09 06:06:43,241::misc::1055::SamplingMethod::(__call__) Got in to sampling method >Thread-562::DEBUG::2012-11-09 06:06:43,241::misc::1053::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) >Thread-562::DEBUG::2012-11-09 06:06:43,241::misc::1055::SamplingMethod::(__call__) Got in to sampling method >Thread-562::DEBUG::2012-11-09 06:06:43,241::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) >Thread-562::DEBUG::2012-11-09 06:06:43,252::__init__::1249::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21 >Thread-562::DEBUG::2012-11-09 06:06:43,252::misc::1063::SamplingMethod::(__call__) Returning last result >Thread-562::DEBUG::2012-11-09 06:06:43,933::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None) >Thread-562::DEBUG::2012-11-09 06:06:43,993::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0 >Thread-562::DEBUG::2012-11-09 06:06:43,993::lvm::457::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-562::DEBUG::2012-11-09 06:06:43,994::lvm::459::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-562::DEBUG::2012-11-09 06:06:43,994::lvm::469::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex >Thread-562::DEBUG::2012-11-09 06:06:43,994::lvm::471::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex >Thread-562::DEBUG::2012-11-09 06:06:43,994::lvm::490::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-562::DEBUG::2012-11-09 06:06:43,995::lvm::492::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-562::DEBUG::2012-11-09 06:06:43,995::misc::1063::SamplingMethod::(__call__) Returning last result >Thread-562::DEBUG::2012-11-09 06:06:43,995::lvm::349::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex >Thread-562::DEBUG::2012-11-09 06:06:43,996::__init__::1249::Storage.Misc.excCmd::(_log) '/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 = [ \\"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 b1658676-2dc3-4357-b112-3852a056c663' (cwd None) >Thread-562::DEBUG::2012-11-09 06:06:44,047::__init__::1249::Storage.Misc.excCmd::(_log) FAILED: <err> = ' Volume group "b1658676-2dc3-4357-b112-3852a056c663" not found\n'; <rc> = 5 >Thread-562::WARNING::2012-11-09 06:06:44,049::lvm::353::Storage.LVM::(_reloadvgs) lvm vgs failed: 5 [] [' Volume group "b1658676-2dc3-4357-b112-3852a056c663" not found'] >Thread-562::DEBUG::2012-11-09 06:06:44,049::lvm::376::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex >Thread-562::DEBUG::2012-11-09 06:06:44,051::resourceManager::538::ResourceManager::(releaseResource) Trying to release resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' >Thread-562::DEBUG::2012-11-09 06:06:44,051::resourceManager::553::ResourceManager::(releaseResource) Released resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' (0 active users) >Thread-562::DEBUG::2012-11-09 06:06:44,052::resourceManager::558::ResourceManager::(releaseResource) Resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' is free, finding out if anyone is waiting for it. >Thread-562::DEBUG::2012-11-09 06:06:44,052::resourceManager::565::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.c02503a4-274e-11e2-b33c-002590730631', Clearing records. >Thread-562::ERROR::2012-11-09 06:06:44,052::task::853::TaskManager.Task::(_setError) Task=`8dad86d1-15e1-4d1b-bec7-c29f8075b323`::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 817, in connectStoragePool > return self._connectStoragePool(spUUID, hostID, scsiKey, msdUUID, masterVersion, options) > File "/usr/share/vdsm/storage/hsm.py", line 859, in _connectStoragePool > res = pool.connect(hostID, scsiKey, msdUUID, masterVersion) > File "/usr/share/vdsm/storage/sp.py", line 641, in connect > self.__rebuild(msdUUID=msdUUID, masterVersion=masterVersion) > File "/usr/share/vdsm/storage/sp.py", line 1109, in __rebuild > self.masterDomain = self.getMasterDomain(msdUUID=msdUUID, masterVersion=masterVersion) > File "/usr/share/vdsm/storage/sp.py", line 1448, in getMasterDomain > raise se.StoragePoolMasterNotFound(self.spUUID, msdUUID) >StoragePoolMasterNotFound: Cannot find master domain: 'spUUID=c02503a4-274e-11e2-b33c-002590730631, msdUUID=b1658676-2dc3-4357-b112-3852a056c663' >Thread-562::DEBUG::2012-11-09 06:06:44,053::task::872::TaskManager.Task::(_run) Task=`8dad86d1-15e1-4d1b-bec7-c29f8075b323`::Task._run: 8dad86d1-15e1-4d1b-bec7-c29f8075b323 ('c02503a4-274e-11e2-b33c-002590730631', 1, 'c02503a4-274e-11e2-b33c-002590730631', 'b1658676-2dc3-4357-b112-3852a056c663', 1) {} failed - stopping task >Thread-562::DEBUG::2012-11-09 06:06:44,053::task::1199::TaskManager.Task::(stop) Task=`8dad86d1-15e1-4d1b-bec7-c29f8075b323`::stopping in state preparing (force False) >Thread-562::DEBUG::2012-11-09 06:06:44,053::task::978::TaskManager.Task::(_decref) Task=`8dad86d1-15e1-4d1b-bec7-c29f8075b323`::ref 1 aborting True >Thread-562::INFO::2012-11-09 06:06:44,053::task::1157::TaskManager.Task::(prepare) Task=`8dad86d1-15e1-4d1b-bec7-c29f8075b323`::aborting: Task is aborted: 'Cannot find master domain' - code 304 >Thread-562::DEBUG::2012-11-09 06:06:44,053::task::1162::TaskManager.Task::(prepare) Task=`8dad86d1-15e1-4d1b-bec7-c29f8075b323`::Prepare: aborted: Cannot find master domain >Thread-562::DEBUG::2012-11-09 06:06:44,053::task::978::TaskManager.Task::(_decref) Task=`8dad86d1-15e1-4d1b-bec7-c29f8075b323`::ref 0 aborting True >Thread-562::DEBUG::2012-11-09 06:06:44,054::task::913::TaskManager.Task::(_doAbort) Task=`8dad86d1-15e1-4d1b-bec7-c29f8075b323`::Task._doAbort: force False >Thread-562::DEBUG::2012-11-09 06:06:44,054::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-562::DEBUG::2012-11-09 06:06:44,054::task::588::TaskManager.Task::(_updateState) Task=`8dad86d1-15e1-4d1b-bec7-c29f8075b323`::moving from state preparing -> state aborting >Thread-562::DEBUG::2012-11-09 06:06:44,054::task::537::TaskManager.Task::(__state_aborting) Task=`8dad86d1-15e1-4d1b-bec7-c29f8075b323`::_aborting: recover policy none >Thread-562::DEBUG::2012-11-09 06:06:44,054::task::588::TaskManager.Task::(_updateState) Task=`8dad86d1-15e1-4d1b-bec7-c29f8075b323`::moving from state aborting -> state failed >Thread-562::DEBUG::2012-11-09 06:06:44,054::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-562::DEBUG::2012-11-09 06:06:44,055::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-562::ERROR::2012-11-09 06:06:44,055::dispatcher::66::Storage.Dispatcher.Protect::(run) {'status': {'message': "Cannot find master domain: 'spUUID=c02503a4-274e-11e2-b33c-002590730631, msdUUID=b1658676-2dc3-4357-b112-3852a056c663'", 'code': 304}} >Thread-565::DEBUG::2012-11-09 06:06:44,172::task::588::TaskManager.Task::(_updateState) Task=`8a257d95-8410-435f-998d-e9adb8a54dde`::moving from state init -> state preparing >Thread-565::INFO::2012-11-09 06:06:44,172::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) >Thread-565::INFO::2012-11-09 06:06:44,172::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} >Thread-565::DEBUG::2012-11-09 06:06:44,172::task::1172::TaskManager.Task::(prepare) Task=`8a257d95-8410-435f-998d-e9adb8a54dde`::finished: {} >Thread-565::DEBUG::2012-11-09 06:06:44,172::task::588::TaskManager.Task::(_updateState) Task=`8a257d95-8410-435f-998d-e9adb8a54dde`::moving from state preparing -> state finished >Thread-565::DEBUG::2012-11-09 06:06:44,172::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-565::DEBUG::2012-11-09 06:06:44,173::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-565::DEBUG::2012-11-09 06:06:44,173::task::978::TaskManager.Task::(_decref) Task=`8a257d95-8410-435f-998d-e9adb8a54dde`::ref 0 aborting False >Thread-571::DEBUG::2012-11-09 06:06:54,253::BindingXMLRPC::156::vds::(wrapper) [192.168.2.113] >Thread-571::DEBUG::2012-11-09 06:06:54,253::task::588::TaskManager.Task::(_updateState) Task=`aa96819f-4da1-4665-95ca-bd1b3afc24b4`::moving from state init -> state preparing >Thread-571::INFO::2012-11-09 06:06:54,254::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='c02503a4-274e-11e2-b33c-002590730631', options=None) >Thread-571::ERROR::2012-11-09 06:06:54,254::task::853::TaskManager.Task::(_setError) Task=`aa96819f-4da1-4665-95ca-bd1b3afc24b4`::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 528, in getSpmStatus > pool = self.getPool(spUUID) > File "/usr/share/vdsm/storage/hsm.py", line 265, in getPool > raise se.StoragePoolUnknown(spUUID) >StoragePoolUnknown: Unknown pool id, pool not connected: ('c02503a4-274e-11e2-b33c-002590730631',) >Thread-571::DEBUG::2012-11-09 06:06:54,254::task::872::TaskManager.Task::(_run) Task=`aa96819f-4da1-4665-95ca-bd1b3afc24b4`::Task._run: aa96819f-4da1-4665-95ca-bd1b3afc24b4 ('c02503a4-274e-11e2-b33c-002590730631',) {} failed - stopping task >Thread-571::DEBUG::2012-11-09 06:06:54,254::task::1199::TaskManager.Task::(stop) Task=`aa96819f-4da1-4665-95ca-bd1b3afc24b4`::stopping in state preparing (force False) >Thread-571::DEBUG::2012-11-09 06:06:54,254::task::978::TaskManager.Task::(_decref) Task=`aa96819f-4da1-4665-95ca-bd1b3afc24b4`::ref 1 aborting True >Thread-571::INFO::2012-11-09 06:06:54,255::task::1157::TaskManager.Task::(prepare) Task=`aa96819f-4da1-4665-95ca-bd1b3afc24b4`::aborting: Task is aborted: 'Unknown pool id, pool not connected' - code 309 >Thread-571::DEBUG::2012-11-09 06:06:54,255::task::1162::TaskManager.Task::(prepare) Task=`aa96819f-4da1-4665-95ca-bd1b3afc24b4`::Prepare: aborted: Unknown pool id, pool not connected >Thread-571::DEBUG::2012-11-09 06:06:54,255::task::978::TaskManager.Task::(_decref) Task=`aa96819f-4da1-4665-95ca-bd1b3afc24b4`::ref 0 aborting True >Thread-571::DEBUG::2012-11-09 06:06:54,255::task::913::TaskManager.Task::(_doAbort) Task=`aa96819f-4da1-4665-95ca-bd1b3afc24b4`::Task._doAbort: force False >Thread-571::DEBUG::2012-11-09 06:06:54,255::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-571::DEBUG::2012-11-09 06:06:54,255::task::588::TaskManager.Task::(_updateState) Task=`aa96819f-4da1-4665-95ca-bd1b3afc24b4`::moving from state preparing -> state aborting >Thread-571::DEBUG::2012-11-09 06:06:54,256::task::537::TaskManager.Task::(__state_aborting) Task=`aa96819f-4da1-4665-95ca-bd1b3afc24b4`::_aborting: recover policy none >Thread-571::DEBUG::2012-11-09 06:06:54,256::task::588::TaskManager.Task::(_updateState) Task=`aa96819f-4da1-4665-95ca-bd1b3afc24b4`::moving from state aborting -> state failed >Thread-571::DEBUG::2012-11-09 06:06:54,256::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-571::DEBUG::2012-11-09 06:06:54,256::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-571::ERROR::2012-11-09 06:06:54,256::dispatcher::66::Storage.Dispatcher.Protect::(run) {'status': {'message': "Unknown pool id, pool not connected: ('c02503a4-274e-11e2-b33c-002590730631',)", 'code': 309}} >Thread-572::DEBUG::2012-11-09 06:06:54,299::BindingXMLRPC::156::vds::(wrapper) [192.168.2.113] >Thread-572::DEBUG::2012-11-09 06:06:54,299::task::588::TaskManager.Task::(_updateState) Task=`95a6bdac-98f0-4e3e-9110-e5cd3e3fd6dd`::moving from state init -> state preparing >Thread-572::INFO::2012-11-09 06:06:54,300::logUtils::37::dispatcher::(wrapper) Run and protect: connectStoragePool(spUUID='c02503a4-274e-11e2-b33c-002590730631', hostID=1, scsiKey='c02503a4-274e-11e2-b33c-002590730631', msdUUID='b1658676-2dc3-4357-b112-3852a056c663', masterVersion=1, options=None) >Thread-572::DEBUG::2012-11-09 06:06:54,300::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.c02503a4-274e-11e2-b33c-002590730631`ReqID=`f4a920f3-1f7e-45f6-9ade-1336497c5f36`::Request was made in '/usr/share/vdsm/storage/resourceManager.py' line '485' at 'registerResource' >Thread-572::DEBUG::2012-11-09 06:06:54,300::resourceManager::486::ResourceManager::(registerResource) Trying to register resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' for lock type 'exclusive' >Thread-572::DEBUG::2012-11-09 06:06:54,301::resourceManager::528::ResourceManager::(registerResource) Resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' is free. Now locking as 'exclusive' (1 active user) >Thread-572::DEBUG::2012-11-09 06:06:54,301::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.c02503a4-274e-11e2-b33c-002590730631`ReqID=`f4a920f3-1f7e-45f6-9ade-1336497c5f36`::Granted request >Thread-572::INFO::2012-11-09 06:06:54,301::sp::625::Storage.StoragePool::(connect) Connect host #1 to the storage pool c02503a4-274e-11e2-b33c-002590730631 with master domain: b1658676-2dc3-4357-b112-3852a056c663 (ver = 1) >Thread-572::DEBUG::2012-11-09 06:06:54,302::lvm::457::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-572::DEBUG::2012-11-09 06:06:54,302::lvm::459::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-572::DEBUG::2012-11-09 06:06:54,302::lvm::469::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex >Thread-572::DEBUG::2012-11-09 06:06:54,302::lvm::471::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex >Thread-572::DEBUG::2012-11-09 06:06:54,303::lvm::490::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-572::DEBUG::2012-11-09 06:06:54,303::lvm::492::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-572::DEBUG::2012-11-09 06:06:54,303::misc::1053::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) >Thread-572::DEBUG::2012-11-09 06:06:54,303::misc::1055::SamplingMethod::(__call__) Got in to sampling method >Thread-572::DEBUG::2012-11-09 06:06:54,303::misc::1053::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) >Thread-572::DEBUG::2012-11-09 06:06:54,303::misc::1055::SamplingMethod::(__call__) Got in to sampling method >Thread-572::DEBUG::2012-11-09 06:06:54,304::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) >Thread-572::DEBUG::2012-11-09 06:06:54,315::__init__::1249::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21 >Thread-572::DEBUG::2012-11-09 06:06:54,316::misc::1063::SamplingMethod::(__call__) Returning last result >Thread-573::DEBUG::2012-11-09 06:06:54,392::task::588::TaskManager.Task::(_updateState) Task=`a6ea5515-ae33-4540-8dd6-d49e4c745674`::moving from state init -> state preparing >Thread-573::INFO::2012-11-09 06:06:54,393::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) >Thread-573::INFO::2012-11-09 06:06:54,393::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} >Thread-573::DEBUG::2012-11-09 06:06:54,393::task::1172::TaskManager.Task::(prepare) Task=`a6ea5515-ae33-4540-8dd6-d49e4c745674`::finished: {} >Thread-573::DEBUG::2012-11-09 06:06:54,393::task::588::TaskManager.Task::(_updateState) Task=`a6ea5515-ae33-4540-8dd6-d49e4c745674`::moving from state preparing -> state finished >Thread-573::DEBUG::2012-11-09 06:06:54,393::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-573::DEBUG::2012-11-09 06:06:54,394::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-573::DEBUG::2012-11-09 06:06:54,394::task::978::TaskManager.Task::(_decref) Task=`a6ea5515-ae33-4540-8dd6-d49e4c745674`::ref 0 aborting False >Thread-572::DEBUG::2012-11-09 06:06:55,026::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None) >Thread-572::DEBUG::2012-11-09 06:06:55,093::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0 >Thread-572::DEBUG::2012-11-09 06:06:55,093::lvm::457::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-572::DEBUG::2012-11-09 06:06:55,093::lvm::459::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-572::DEBUG::2012-11-09 06:06:55,094::lvm::469::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex >Thread-572::DEBUG::2012-11-09 06:06:55,094::lvm::471::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex >Thread-572::DEBUG::2012-11-09 06:06:55,094::lvm::490::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-572::DEBUG::2012-11-09 06:06:55,094::lvm::492::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-572::DEBUG::2012-11-09 06:06:55,095::misc::1063::SamplingMethod::(__call__) Returning last result >Thread-572::DEBUG::2012-11-09 06:06:55,095::lvm::349::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex >Thread-572::DEBUG::2012-11-09 06:06:55,096::__init__::1249::Storage.Misc.excCmd::(_log) '/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 = [ \\"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 b1658676-2dc3-4357-b112-3852a056c663' (cwd None) >Thread-572::DEBUG::2012-11-09 06:06:55,143::__init__::1249::Storage.Misc.excCmd::(_log) FAILED: <err> = ' Volume group "b1658676-2dc3-4357-b112-3852a056c663" not found\n'; <rc> = 5 >Thread-572::WARNING::2012-11-09 06:06:55,144::lvm::353::Storage.LVM::(_reloadvgs) lvm vgs failed: 5 [] [' Volume group "b1658676-2dc3-4357-b112-3852a056c663" not found'] >Thread-572::DEBUG::2012-11-09 06:06:55,144::lvm::376::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex >Thread-572::DEBUG::2012-11-09 06:06:55,147::resourceManager::538::ResourceManager::(releaseResource) Trying to release resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' >Thread-572::DEBUG::2012-11-09 06:06:55,147::resourceManager::553::ResourceManager::(releaseResource) Released resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' (0 active users) >Thread-572::DEBUG::2012-11-09 06:06:55,147::resourceManager::558::ResourceManager::(releaseResource) Resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' is free, finding out if anyone is waiting for it. >Thread-572::DEBUG::2012-11-09 06:06:55,147::resourceManager::565::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.c02503a4-274e-11e2-b33c-002590730631', Clearing records. >Thread-572::ERROR::2012-11-09 06:06:55,148::task::853::TaskManager.Task::(_setError) Task=`95a6bdac-98f0-4e3e-9110-e5cd3e3fd6dd`::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 817, in connectStoragePool > return self._connectStoragePool(spUUID, hostID, scsiKey, msdUUID, masterVersion, options) > File "/usr/share/vdsm/storage/hsm.py", line 859, in _connectStoragePool > res = pool.connect(hostID, scsiKey, msdUUID, masterVersion) > File "/usr/share/vdsm/storage/sp.py", line 641, in connect > self.__rebuild(msdUUID=msdUUID, masterVersion=masterVersion) > File "/usr/share/vdsm/storage/sp.py", line 1109, in __rebuild > self.masterDomain = self.getMasterDomain(msdUUID=msdUUID, masterVersion=masterVersion) > File "/usr/share/vdsm/storage/sp.py", line 1448, in getMasterDomain > raise se.StoragePoolMasterNotFound(self.spUUID, msdUUID) >StoragePoolMasterNotFound: Cannot find master domain: 'spUUID=c02503a4-274e-11e2-b33c-002590730631, msdUUID=b1658676-2dc3-4357-b112-3852a056c663' >Thread-572::DEBUG::2012-11-09 06:06:55,148::task::872::TaskManager.Task::(_run) Task=`95a6bdac-98f0-4e3e-9110-e5cd3e3fd6dd`::Task._run: 95a6bdac-98f0-4e3e-9110-e5cd3e3fd6dd ('c02503a4-274e-11e2-b33c-002590730631', 1, 'c02503a4-274e-11e2-b33c-002590730631', 'b1658676-2dc3-4357-b112-3852a056c663', 1) {} failed - stopping task >Thread-572::DEBUG::2012-11-09 06:06:55,148::task::1199::TaskManager.Task::(stop) Task=`95a6bdac-98f0-4e3e-9110-e5cd3e3fd6dd`::stopping in state preparing (force False) >Thread-572::DEBUG::2012-11-09 06:06:55,149::task::978::TaskManager.Task::(_decref) Task=`95a6bdac-98f0-4e3e-9110-e5cd3e3fd6dd`::ref 1 aborting True >Thread-572::INFO::2012-11-09 06:06:55,149::task::1157::TaskManager.Task::(prepare) Task=`95a6bdac-98f0-4e3e-9110-e5cd3e3fd6dd`::aborting: Task is aborted: 'Cannot find master domain' - code 304 >Thread-572::DEBUG::2012-11-09 06:06:55,149::task::1162::TaskManager.Task::(prepare) Task=`95a6bdac-98f0-4e3e-9110-e5cd3e3fd6dd`::Prepare: aborted: Cannot find master domain >Thread-572::DEBUG::2012-11-09 06:06:55,149::task::978::TaskManager.Task::(_decref) Task=`95a6bdac-98f0-4e3e-9110-e5cd3e3fd6dd`::ref 0 aborting True >Thread-572::DEBUG::2012-11-09 06:06:55,149::task::913::TaskManager.Task::(_doAbort) Task=`95a6bdac-98f0-4e3e-9110-e5cd3e3fd6dd`::Task._doAbort: force False >Thread-572::DEBUG::2012-11-09 06:06:55,150::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-572::DEBUG::2012-11-09 06:06:55,150::task::588::TaskManager.Task::(_updateState) Task=`95a6bdac-98f0-4e3e-9110-e5cd3e3fd6dd`::moving from state preparing -> state aborting >Thread-572::DEBUG::2012-11-09 06:06:55,150::task::537::TaskManager.Task::(__state_aborting) Task=`95a6bdac-98f0-4e3e-9110-e5cd3e3fd6dd`::_aborting: recover policy none >Thread-572::DEBUG::2012-11-09 06:06:55,150::task::588::TaskManager.Task::(_updateState) Task=`95a6bdac-98f0-4e3e-9110-e5cd3e3fd6dd`::moving from state aborting -> state failed >Thread-572::DEBUG::2012-11-09 06:06:55,150::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-572::DEBUG::2012-11-09 06:06:55,150::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-572::ERROR::2012-11-09 06:06:55,151::dispatcher::66::Storage.Dispatcher.Protect::(run) {'status': {'message': "Cannot find master domain: 'spUUID=c02503a4-274e-11e2-b33c-002590730631, msdUUID=b1658676-2dc3-4357-b112-3852a056c663'", 'code': 304}} >Thread-581::DEBUG::2012-11-09 06:07:04,873::task::588::TaskManager.Task::(_updateState) Task=`8a4f4e69-256d-4f0f-815d-17d512ad3876`::moving from state init -> state preparing >Thread-581::INFO::2012-11-09 06:07:04,873::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) >Thread-581::INFO::2012-11-09 06:07:04,873::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} >Thread-581::DEBUG::2012-11-09 06:07:04,873::task::1172::TaskManager.Task::(prepare) Task=`8a4f4e69-256d-4f0f-815d-17d512ad3876`::finished: {} >Thread-581::DEBUG::2012-11-09 06:07:04,873::task::588::TaskManager.Task::(_updateState) Task=`8a4f4e69-256d-4f0f-815d-17d512ad3876`::moving from state preparing -> state finished >Thread-581::DEBUG::2012-11-09 06:07:04,873::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-581::DEBUG::2012-11-09 06:07:04,874::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-581::DEBUG::2012-11-09 06:07:04,874::task::978::TaskManager.Task::(_decref) Task=`8a4f4e69-256d-4f0f-815d-17d512ad3876`::ref 0 aborting False >Thread-583::DEBUG::2012-11-09 06:07:05,368::BindingXMLRPC::156::vds::(wrapper) [192.168.2.113] >Thread-583::DEBUG::2012-11-09 06:07:05,368::task::588::TaskManager.Task::(_updateState) Task=`18c112d3-f450-479e-92ae-d17f583a6ec6`::moving from state init -> state preparing >Thread-583::INFO::2012-11-09 06:07:05,368::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='c02503a4-274e-11e2-b33c-002590730631', options=None) >Thread-583::ERROR::2012-11-09 06:07:05,369::task::853::TaskManager.Task::(_setError) Task=`18c112d3-f450-479e-92ae-d17f583a6ec6`::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 528, in getSpmStatus > pool = self.getPool(spUUID) > File "/usr/share/vdsm/storage/hsm.py", line 265, in getPool > raise se.StoragePoolUnknown(spUUID) >StoragePoolUnknown: Unknown pool id, pool not connected: ('c02503a4-274e-11e2-b33c-002590730631',) >Thread-583::DEBUG::2012-11-09 06:07:05,369::task::872::TaskManager.Task::(_run) Task=`18c112d3-f450-479e-92ae-d17f583a6ec6`::Task._run: 18c112d3-f450-479e-92ae-d17f583a6ec6 ('c02503a4-274e-11e2-b33c-002590730631',) {} failed - stopping task >Thread-583::DEBUG::2012-11-09 06:07:05,369::task::1199::TaskManager.Task::(stop) Task=`18c112d3-f450-479e-92ae-d17f583a6ec6`::stopping in state preparing (force False) >Thread-583::DEBUG::2012-11-09 06:07:05,369::task::978::TaskManager.Task::(_decref) Task=`18c112d3-f450-479e-92ae-d17f583a6ec6`::ref 1 aborting True >Thread-583::INFO::2012-11-09 06:07:05,369::task::1157::TaskManager.Task::(prepare) Task=`18c112d3-f450-479e-92ae-d17f583a6ec6`::aborting: Task is aborted: 'Unknown pool id, pool not connected' - code 309 >Thread-583::DEBUG::2012-11-09 06:07:05,369::task::1162::TaskManager.Task::(prepare) Task=`18c112d3-f450-479e-92ae-d17f583a6ec6`::Prepare: aborted: Unknown pool id, pool not connected >Thread-583::DEBUG::2012-11-09 06:07:05,369::task::978::TaskManager.Task::(_decref) Task=`18c112d3-f450-479e-92ae-d17f583a6ec6`::ref 0 aborting True >Thread-583::DEBUG::2012-11-09 06:07:05,369::task::913::TaskManager.Task::(_doAbort) Task=`18c112d3-f450-479e-92ae-d17f583a6ec6`::Task._doAbort: force False >Thread-583::DEBUG::2012-11-09 06:07:05,369::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-583::DEBUG::2012-11-09 06:07:05,369::task::588::TaskManager.Task::(_updateState) Task=`18c112d3-f450-479e-92ae-d17f583a6ec6`::moving from state preparing -> state aborting >Thread-583::DEBUG::2012-11-09 06:07:05,370::task::537::TaskManager.Task::(__state_aborting) Task=`18c112d3-f450-479e-92ae-d17f583a6ec6`::_aborting: recover policy none >Thread-583::DEBUG::2012-11-09 06:07:05,370::task::588::TaskManager.Task::(_updateState) Task=`18c112d3-f450-479e-92ae-d17f583a6ec6`::moving from state aborting -> state failed >Thread-583::DEBUG::2012-11-09 06:07:05,370::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-583::DEBUG::2012-11-09 06:07:05,370::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-583::ERROR::2012-11-09 06:07:05,370::dispatcher::66::Storage.Dispatcher.Protect::(run) {'status': {'message': "Unknown pool id, pool not connected: ('c02503a4-274e-11e2-b33c-002590730631',)", 'code': 309}} >Thread-584::DEBUG::2012-11-09 06:07:05,408::BindingXMLRPC::156::vds::(wrapper) [192.168.2.113] >Thread-584::DEBUG::2012-11-09 06:07:05,409::task::588::TaskManager.Task::(_updateState) Task=`f0fb030b-f840-4953-8ff2-369c5f6f3be7`::moving from state init -> state preparing >Thread-584::INFO::2012-11-09 06:07:05,409::logUtils::37::dispatcher::(wrapper) Run and protect: connectStoragePool(spUUID='c02503a4-274e-11e2-b33c-002590730631', hostID=1, scsiKey='c02503a4-274e-11e2-b33c-002590730631', msdUUID='b1658676-2dc3-4357-b112-3852a056c663', masterVersion=1, options=None) >Thread-584::DEBUG::2012-11-09 06:07:05,410::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.c02503a4-274e-11e2-b33c-002590730631`ReqID=`47eeee21-c889-47ee-b352-646d8709e5ed`::Request was made in '/usr/share/vdsm/storage/resourceManager.py' line '485' at 'registerResource' >Thread-584::DEBUG::2012-11-09 06:07:05,410::resourceManager::486::ResourceManager::(registerResource) Trying to register resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' for lock type 'exclusive' >Thread-584::DEBUG::2012-11-09 06:07:05,410::resourceManager::528::ResourceManager::(registerResource) Resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' is free. Now locking as 'exclusive' (1 active user) >Thread-584::DEBUG::2012-11-09 06:07:05,410::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.c02503a4-274e-11e2-b33c-002590730631`ReqID=`47eeee21-c889-47ee-b352-646d8709e5ed`::Granted request >Thread-584::INFO::2012-11-09 06:07:05,411::sp::625::Storage.StoragePool::(connect) Connect host #1 to the storage pool c02503a4-274e-11e2-b33c-002590730631 with master domain: b1658676-2dc3-4357-b112-3852a056c663 (ver = 1) >Thread-584::DEBUG::2012-11-09 06:07:05,411::lvm::457::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-584::DEBUG::2012-11-09 06:07:05,411::lvm::459::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-584::DEBUG::2012-11-09 06:07:05,412::lvm::469::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex >Thread-584::DEBUG::2012-11-09 06:07:05,412::lvm::471::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex >Thread-584::DEBUG::2012-11-09 06:07:05,412::lvm::490::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-584::DEBUG::2012-11-09 06:07:05,412::lvm::492::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-584::DEBUG::2012-11-09 06:07:05,412::misc::1053::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) >Thread-584::DEBUG::2012-11-09 06:07:05,413::misc::1055::SamplingMethod::(__call__) Got in to sampling method >Thread-584::DEBUG::2012-11-09 06:07:05,413::misc::1053::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) >Thread-584::DEBUG::2012-11-09 06:07:05,413::misc::1055::SamplingMethod::(__call__) Got in to sampling method >Thread-584::DEBUG::2012-11-09 06:07:05,413::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) >Thread-584::DEBUG::2012-11-09 06:07:05,425::__init__::1249::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21 >Thread-584::DEBUG::2012-11-09 06:07:05,426::misc::1063::SamplingMethod::(__call__) Returning last result >Thread-584::DEBUG::2012-11-09 06:07:06,062::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None) >Thread-584::DEBUG::2012-11-09 06:07:06,133::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0 >Thread-584::DEBUG::2012-11-09 06:07:06,134::lvm::457::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-584::DEBUG::2012-11-09 06:07:06,134::lvm::459::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-584::DEBUG::2012-11-09 06:07:06,134::lvm::469::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex >Thread-584::DEBUG::2012-11-09 06:07:06,134::lvm::471::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex >Thread-584::DEBUG::2012-11-09 06:07:06,135::lvm::490::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-584::DEBUG::2012-11-09 06:07:06,135::lvm::492::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-584::DEBUG::2012-11-09 06:07:06,135::misc::1063::SamplingMethod::(__call__) Returning last result >Thread-584::DEBUG::2012-11-09 06:07:06,135::lvm::349::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex >Thread-584::DEBUG::2012-11-09 06:07:06,136::__init__::1249::Storage.Misc.excCmd::(_log) '/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 = [ \\"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 b1658676-2dc3-4357-b112-3852a056c663' (cwd None) >Thread-584::DEBUG::2012-11-09 06:07:06,182::__init__::1249::Storage.Misc.excCmd::(_log) FAILED: <err> = ' Volume group "b1658676-2dc3-4357-b112-3852a056c663" not found\n'; <rc> = 5 >Thread-584::WARNING::2012-11-09 06:07:06,183::lvm::353::Storage.LVM::(_reloadvgs) lvm vgs failed: 5 [] [' Volume group "b1658676-2dc3-4357-b112-3852a056c663" not found'] >Thread-584::DEBUG::2012-11-09 06:07:06,184::lvm::376::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex >Thread-584::DEBUG::2012-11-09 06:07:06,187::resourceManager::538::ResourceManager::(releaseResource) Trying to release resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' >Thread-584::DEBUG::2012-11-09 06:07:06,187::resourceManager::553::ResourceManager::(releaseResource) Released resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' (0 active users) >Thread-584::DEBUG::2012-11-09 06:07:06,187::resourceManager::558::ResourceManager::(releaseResource) Resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' is free, finding out if anyone is waiting for it. >Thread-584::DEBUG::2012-11-09 06:07:06,187::resourceManager::565::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.c02503a4-274e-11e2-b33c-002590730631', Clearing records. >Thread-584::ERROR::2012-11-09 06:07:06,187::task::853::TaskManager.Task::(_setError) Task=`f0fb030b-f840-4953-8ff2-369c5f6f3be7`::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 817, in connectStoragePool > return self._connectStoragePool(spUUID, hostID, scsiKey, msdUUID, masterVersion, options) > File "/usr/share/vdsm/storage/hsm.py", line 859, in _connectStoragePool > res = pool.connect(hostID, scsiKey, msdUUID, masterVersion) > File "/usr/share/vdsm/storage/sp.py", line 641, in connect > self.__rebuild(msdUUID=msdUUID, masterVersion=masterVersion) > File "/usr/share/vdsm/storage/sp.py", line 1109, in __rebuild > self.masterDomain = self.getMasterDomain(msdUUID=msdUUID, masterVersion=masterVersion) > File "/usr/share/vdsm/storage/sp.py", line 1448, in getMasterDomain > raise se.StoragePoolMasterNotFound(self.spUUID, msdUUID) >StoragePoolMasterNotFound: Cannot find master domain: 'spUUID=c02503a4-274e-11e2-b33c-002590730631, msdUUID=b1658676-2dc3-4357-b112-3852a056c663' >Thread-584::DEBUG::2012-11-09 06:07:06,187::task::872::TaskManager.Task::(_run) Task=`f0fb030b-f840-4953-8ff2-369c5f6f3be7`::Task._run: f0fb030b-f840-4953-8ff2-369c5f6f3be7 ('c02503a4-274e-11e2-b33c-002590730631', 1, 'c02503a4-274e-11e2-b33c-002590730631', 'b1658676-2dc3-4357-b112-3852a056c663', 1) {} failed - stopping task >Thread-584::DEBUG::2012-11-09 06:07:06,187::task::1199::TaskManager.Task::(stop) Task=`f0fb030b-f840-4953-8ff2-369c5f6f3be7`::stopping in state preparing (force False) >Thread-584::DEBUG::2012-11-09 06:07:06,187::task::978::TaskManager.Task::(_decref) Task=`f0fb030b-f840-4953-8ff2-369c5f6f3be7`::ref 1 aborting True >Thread-584::INFO::2012-11-09 06:07:06,188::task::1157::TaskManager.Task::(prepare) Task=`f0fb030b-f840-4953-8ff2-369c5f6f3be7`::aborting: Task is aborted: 'Cannot find master domain' - code 304 >Thread-584::DEBUG::2012-11-09 06:07:06,188::task::1162::TaskManager.Task::(prepare) Task=`f0fb030b-f840-4953-8ff2-369c5f6f3be7`::Prepare: aborted: Cannot find master domain >Thread-584::DEBUG::2012-11-09 06:07:06,188::task::978::TaskManager.Task::(_decref) Task=`f0fb030b-f840-4953-8ff2-369c5f6f3be7`::ref 0 aborting True >Thread-584::DEBUG::2012-11-09 06:07:06,188::task::913::TaskManager.Task::(_doAbort) Task=`f0fb030b-f840-4953-8ff2-369c5f6f3be7`::Task._doAbort: force False >Thread-584::DEBUG::2012-11-09 06:07:06,188::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-584::DEBUG::2012-11-09 06:07:06,188::task::588::TaskManager.Task::(_updateState) Task=`f0fb030b-f840-4953-8ff2-369c5f6f3be7`::moving from state preparing -> state aborting >Thread-584::DEBUG::2012-11-09 06:07:06,188::task::537::TaskManager.Task::(__state_aborting) Task=`f0fb030b-f840-4953-8ff2-369c5f6f3be7`::_aborting: recover policy none >Thread-584::DEBUG::2012-11-09 06:07:06,188::task::588::TaskManager.Task::(_updateState) Task=`f0fb030b-f840-4953-8ff2-369c5f6f3be7`::moving from state aborting -> state failed >Thread-584::DEBUG::2012-11-09 06:07:06,188::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-584::DEBUG::2012-11-09 06:07:06,188::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-584::ERROR::2012-11-09 06:07:06,189::dispatcher::66::Storage.Dispatcher.Protect::(run) {'status': {'message': "Cannot find master domain: 'spUUID=c02503a4-274e-11e2-b33c-002590730631, msdUUID=b1658676-2dc3-4357-b112-3852a056c663'", 'code': 304}} >Thread-591::DEBUG::2012-11-09 06:07:15,061::task::588::TaskManager.Task::(_updateState) Task=`798c9ac6-bfa9-4d1e-818a-67e9d7295e40`::moving from state init -> state preparing >Thread-591::INFO::2012-11-09 06:07:15,061::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) >Thread-591::INFO::2012-11-09 06:07:15,061::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} >Thread-591::DEBUG::2012-11-09 06:07:15,062::task::1172::TaskManager.Task::(prepare) Task=`798c9ac6-bfa9-4d1e-818a-67e9d7295e40`::finished: {} >Thread-591::DEBUG::2012-11-09 06:07:15,062::task::588::TaskManager.Task::(_updateState) Task=`798c9ac6-bfa9-4d1e-818a-67e9d7295e40`::moving from state preparing -> state finished >Thread-591::DEBUG::2012-11-09 06:07:15,062::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-591::DEBUG::2012-11-09 06:07:15,062::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-591::DEBUG::2012-11-09 06:07:15,062::task::978::TaskManager.Task::(_decref) Task=`798c9ac6-bfa9-4d1e-818a-67e9d7295e40`::ref 0 aborting False >Thread-593::DEBUG::2012-11-09 06:07:16,412::BindingXMLRPC::156::vds::(wrapper) [192.168.2.113] >Thread-593::DEBUG::2012-11-09 06:07:16,412::task::588::TaskManager.Task::(_updateState) Task=`23005315-3aae-4ca7-bbe4-8c71b4e850c6`::moving from state init -> state preparing >Thread-593::INFO::2012-11-09 06:07:16,413::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='c02503a4-274e-11e2-b33c-002590730631', options=None) >Thread-593::ERROR::2012-11-09 06:07:16,413::task::853::TaskManager.Task::(_setError) Task=`23005315-3aae-4ca7-bbe4-8c71b4e850c6`::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 528, in getSpmStatus > pool = self.getPool(spUUID) > File "/usr/share/vdsm/storage/hsm.py", line 265, in getPool > raise se.StoragePoolUnknown(spUUID) >StoragePoolUnknown: Unknown pool id, pool not connected: ('c02503a4-274e-11e2-b33c-002590730631',) >Thread-593::DEBUG::2012-11-09 06:07:16,413::task::872::TaskManager.Task::(_run) Task=`23005315-3aae-4ca7-bbe4-8c71b4e850c6`::Task._run: 23005315-3aae-4ca7-bbe4-8c71b4e850c6 ('c02503a4-274e-11e2-b33c-002590730631',) {} failed - stopping task >Thread-593::DEBUG::2012-11-09 06:07:16,413::task::1199::TaskManager.Task::(stop) Task=`23005315-3aae-4ca7-bbe4-8c71b4e850c6`::stopping in state preparing (force False) >Thread-593::DEBUG::2012-11-09 06:07:16,414::task::978::TaskManager.Task::(_decref) Task=`23005315-3aae-4ca7-bbe4-8c71b4e850c6`::ref 1 aborting True >Thread-593::INFO::2012-11-09 06:07:16,414::task::1157::TaskManager.Task::(prepare) Task=`23005315-3aae-4ca7-bbe4-8c71b4e850c6`::aborting: Task is aborted: 'Unknown pool id, pool not connected' - code 309 >Thread-593::DEBUG::2012-11-09 06:07:16,414::task::1162::TaskManager.Task::(prepare) Task=`23005315-3aae-4ca7-bbe4-8c71b4e850c6`::Prepare: aborted: Unknown pool id, pool not connected >Thread-593::DEBUG::2012-11-09 06:07:16,414::task::978::TaskManager.Task::(_decref) Task=`23005315-3aae-4ca7-bbe4-8c71b4e850c6`::ref 0 aborting True >Thread-593::DEBUG::2012-11-09 06:07:16,414::task::913::TaskManager.Task::(_doAbort) Task=`23005315-3aae-4ca7-bbe4-8c71b4e850c6`::Task._doAbort: force False >Thread-593::DEBUG::2012-11-09 06:07:16,414::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-593::DEBUG::2012-11-09 06:07:16,415::task::588::TaskManager.Task::(_updateState) Task=`23005315-3aae-4ca7-bbe4-8c71b4e850c6`::moving from state preparing -> state aborting >Thread-593::DEBUG::2012-11-09 06:07:16,415::task::537::TaskManager.Task::(__state_aborting) Task=`23005315-3aae-4ca7-bbe4-8c71b4e850c6`::_aborting: recover policy none >Thread-593::DEBUG::2012-11-09 06:07:16,415::task::588::TaskManager.Task::(_updateState) Task=`23005315-3aae-4ca7-bbe4-8c71b4e850c6`::moving from state aborting -> state failed >Thread-593::DEBUG::2012-11-09 06:07:16,415::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-593::DEBUG::2012-11-09 06:07:16,415::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-593::ERROR::2012-11-09 06:07:16,415::dispatcher::66::Storage.Dispatcher.Protect::(run) {'status': {'message': "Unknown pool id, pool not connected: ('c02503a4-274e-11e2-b33c-002590730631',)", 'code': 309}} >Thread-594::DEBUG::2012-11-09 06:07:16,460::BindingXMLRPC::156::vds::(wrapper) [192.168.2.113] >Thread-594::DEBUG::2012-11-09 06:07:16,460::task::588::TaskManager.Task::(_updateState) Task=`d9aea9c2-6d55-4074-bf80-2044dc33a908`::moving from state init -> state preparing >Thread-594::INFO::2012-11-09 06:07:16,460::logUtils::37::dispatcher::(wrapper) Run and protect: connectStoragePool(spUUID='c02503a4-274e-11e2-b33c-002590730631', hostID=1, scsiKey='c02503a4-274e-11e2-b33c-002590730631', msdUUID='b1658676-2dc3-4357-b112-3852a056c663', masterVersion=1, options=None) >Thread-594::DEBUG::2012-11-09 06:07:16,461::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.c02503a4-274e-11e2-b33c-002590730631`ReqID=`c92a49a1-a9c1-4896-b504-3abd2d7213a7`::Request was made in '/usr/share/vdsm/storage/resourceManager.py' line '485' at 'registerResource' >Thread-594::DEBUG::2012-11-09 06:07:16,461::resourceManager::486::ResourceManager::(registerResource) Trying to register resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' for lock type 'exclusive' >Thread-594::DEBUG::2012-11-09 06:07:16,461::resourceManager::528::ResourceManager::(registerResource) Resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' is free. Now locking as 'exclusive' (1 active user) >Thread-594::DEBUG::2012-11-09 06:07:16,461::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.c02503a4-274e-11e2-b33c-002590730631`ReqID=`c92a49a1-a9c1-4896-b504-3abd2d7213a7`::Granted request >Thread-594::INFO::2012-11-09 06:07:16,462::sp::625::Storage.StoragePool::(connect) Connect host #1 to the storage pool c02503a4-274e-11e2-b33c-002590730631 with master domain: b1658676-2dc3-4357-b112-3852a056c663 (ver = 1) >Thread-594::DEBUG::2012-11-09 06:07:16,462::lvm::457::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-594::DEBUG::2012-11-09 06:07:16,463::lvm::459::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-594::DEBUG::2012-11-09 06:07:16,463::lvm::469::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex >Thread-594::DEBUG::2012-11-09 06:07:16,463::lvm::471::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex >Thread-594::DEBUG::2012-11-09 06:07:16,463::lvm::490::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-594::DEBUG::2012-11-09 06:07:16,463::lvm::492::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-594::DEBUG::2012-11-09 06:07:16,464::misc::1053::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) >Thread-594::DEBUG::2012-11-09 06:07:16,464::misc::1055::SamplingMethod::(__call__) Got in to sampling method >Thread-594::DEBUG::2012-11-09 06:07:16,464::misc::1053::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) >Thread-594::DEBUG::2012-11-09 06:07:16,464::misc::1055::SamplingMethod::(__call__) Got in to sampling method >Thread-594::DEBUG::2012-11-09 06:07:16,464::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) >Thread-594::DEBUG::2012-11-09 06:07:16,476::__init__::1249::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21 >Thread-594::DEBUG::2012-11-09 06:07:16,476::misc::1063::SamplingMethod::(__call__) Returning last result >Thread-594::DEBUG::2012-11-09 06:07:17,124::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None) >Thread-594::DEBUG::2012-11-09 06:07:17,190::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0 >Thread-594::DEBUG::2012-11-09 06:07:17,191::lvm::457::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-594::DEBUG::2012-11-09 06:07:17,191::lvm::459::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-594::DEBUG::2012-11-09 06:07:17,191::lvm::469::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex >Thread-594::DEBUG::2012-11-09 06:07:17,192::lvm::471::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex >Thread-594::DEBUG::2012-11-09 06:07:17,192::lvm::490::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex >Thread-594::DEBUG::2012-11-09 06:07:17,192::lvm::492::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex >Thread-594::DEBUG::2012-11-09 06:07:17,192::misc::1063::SamplingMethod::(__call__) Returning last result >Thread-594::DEBUG::2012-11-09 06:07:17,193::lvm::349::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex >Thread-594::DEBUG::2012-11-09 06:07:17,194::__init__::1249::Storage.Misc.excCmd::(_log) '/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 = [ \\"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 b1658676-2dc3-4357-b112-3852a056c663' (cwd None) >Thread-594::DEBUG::2012-11-09 06:07:17,242::__init__::1249::Storage.Misc.excCmd::(_log) FAILED: <err> = ' Volume group "b1658676-2dc3-4357-b112-3852a056c663" not found\n'; <rc> = 5 >Thread-594::WARNING::2012-11-09 06:07:17,243::lvm::353::Storage.LVM::(_reloadvgs) lvm vgs failed: 5 [] [' Volume group "b1658676-2dc3-4357-b112-3852a056c663" not found'] >Thread-594::DEBUG::2012-11-09 06:07:17,243::lvm::376::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex >Thread-594::DEBUG::2012-11-09 06:07:17,246::resourceManager::538::ResourceManager::(releaseResource) Trying to release resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' >Thread-594::DEBUG::2012-11-09 06:07:17,246::resourceManager::553::ResourceManager::(releaseResource) Released resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' (0 active users) >Thread-594::DEBUG::2012-11-09 06:07:17,246::resourceManager::558::ResourceManager::(releaseResource) Resource 'Storage.c02503a4-274e-11e2-b33c-002590730631' is free, finding out if anyone is waiting for it. >Thread-594::DEBUG::2012-11-09 06:07:17,247::resourceManager::565::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.c02503a4-274e-11e2-b33c-002590730631', Clearing records. >Thread-594::ERROR::2012-11-09 06:07:17,247::task::853::TaskManager.Task::(_setError) Task=`d9aea9c2-6d55-4074-bf80-2044dc33a908`::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 817, in connectStoragePool > return self._connectStoragePool(spUUID, hostID, scsiKey, msdUUID, masterVersion, options) > File "/usr/share/vdsm/storage/hsm.py", line 859, in _connectStoragePool > res = pool.connect(hostID, scsiKey, msdUUID, masterVersion) > File "/usr/share/vdsm/storage/sp.py", line 641, in connect > self.__rebuild(msdUUID=msdUUID, masterVersion=masterVersion) > File "/usr/share/vdsm/storage/sp.py", line 1109, in __rebuild > self.masterDomain = self.getMasterDomain(msdUUID=msdUUID, masterVersion=masterVersion) > File "/usr/share/vdsm/storage/sp.py", line 1448, in getMasterDomain > raise se.StoragePoolMasterNotFound(self.spUUID, msdUUID) >StoragePoolMasterNotFound: Cannot find master domain: 'spUUID=c02503a4-274e-11e2-b33c-002590730631, msdUUID=b1658676-2dc3-4357-b112-3852a056c663' >Thread-594::DEBUG::2012-11-09 06:07:17,247::task::872::TaskManager.Task::(_run) Task=`d9aea9c2-6d55-4074-bf80-2044dc33a908`::Task._run: d9aea9c2-6d55-4074-bf80-2044dc33a908 ('c02503a4-274e-11e2-b33c-002590730631', 1, 'c02503a4-274e-11e2-b33c-002590730631', 'b1658676-2dc3-4357-b112-3852a056c663', 1) {} failed - stopping task >Thread-594::DEBUG::2012-11-09 06:07:17,247::task::1199::TaskManager.Task::(stop) Task=`d9aea9c2-6d55-4074-bf80-2044dc33a908`::stopping in state preparing (force False) >Thread-594::DEBUG::2012-11-09 06:07:17,248::task::978::TaskManager.Task::(_decref) Task=`d9aea9c2-6d55-4074-bf80-2044dc33a908`::ref 1 aborting True >Thread-594::INFO::2012-11-09 06:07:17,248::task::1157::TaskManager.Task::(prepare) Task=`d9aea9c2-6d55-4074-bf80-2044dc33a908`::aborting: Task is aborted: 'Cannot find master domain' - code 304 >Thread-594::DEBUG::2012-11-09 06:07:17,248::task::1162::TaskManager.Task::(prepare) Task=`d9aea9c2-6d55-4074-bf80-2044dc33a908`::Prepare: aborted: Cannot find master domain >Thread-594::DEBUG::2012-11-09 06:07:17,248::task::978::TaskManager.Task::(_decref) Task=`d9aea9c2-6d55-4074-bf80-2044dc33a908`::ref 0 aborting True >Thread-594::DEBUG::2012-11-09 06:07:17,249::task::913::TaskManager.Task::(_doAbort) Task=`d9aea9c2-6d55-4074-bf80-2044dc33a908`::Task._doAbort: force False >Thread-594::DEBUG::2012-11-09 06:07:17,249::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-594::DEBUG::2012-11-09 06:07:17,249::task::588::TaskManager.Task::(_updateState) Task=`d9aea9c2-6d55-4074-bf80-2044dc33a908`::moving from state preparing -> state aborting >Thread-594::DEBUG::2012-11-09 06:07:17,249::task::537::TaskManager.Task::(__state_aborting) Task=`d9aea9c2-6d55-4074-bf80-2044dc33a908`::_aborting: recover policy none >Thread-594::DEBUG::2012-11-09 06:07:17,249::task::588::TaskManager.Task::(_updateState) Task=`d9aea9c2-6d55-4074-bf80-2044dc33a908`::moving from state aborting -> state failed >Thread-594::DEBUG::2012-11-09 06:07:17,249::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} >Thread-594::DEBUG::2012-11-09 06:07:17,250::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} >Thread-594::ERROR::2012-11-09 06:07:17,250::dispatcher::66::Storage.Dispatcher.Protect::(run) {'status': {'message': "Cannot find master domain: 'spUUID=c02503a4-274e-11e2-b33c-002590730631, msdUUID=b1658676-2dc3-4357-b112-3852a056c663'", 'code': 304}}
You cannot view the attachment while viewing its details because your browser does not support IFRAMEs.
View the attachment on a separate page
.
View Attachment As Raw
Actions:
View
Attachments on
bug 874120
:
640114
| 641526 |
641527