It looks like you were hit by this bug:

https://bugzilla.redhat.com/show_bug.cgi?id=875678

And the patch is here:
http://gerrit.ovirt.org/#/c/9193/


Itzik Brown:
Hi,
When trying to configure local storage domain I get an error.
Below some lines from vdsm.log:

Thread-46::DEBUG::2012-11-14 
02:16:13,568::task::568::TaskManager.Task::(_updateState) 
Task=`ff34ce79-4e9c-4e90-8598-4ec6bd9a682f`::moving from state init -> state 
preparing
Thread-46::INFO::2012-11-14 02:16:13,568::logUtils::37::dispatcher::(wrapper) 
Run and protect: repoStats(options=None)
Thread-46::INFO::2012-11-14 02:16:13,568::logUtils::39::dispatcher::(wrapper) 
Run and protect: repoStats, Return response: {}
Thread-46::DEBUG::2012-11-14 
02:16:13,568::task::1151::TaskManager.Task::(prepare) 
Task=`ff34ce79-4e9c-4e90-8598-4ec6bd9a682f`::finished: {}
Thread-46::DEBUG::2012-11-14 
02:16:13,568::task::568::TaskManager.Task::(_updateState) 
Task=`ff34ce79-4e9c-4e90-8598-4ec6bd9a682f`::moving from state preparing -> 
state finished
Thread-46::DEBUG::2012-11-14 
02:16:13,569::resourceManager::809::ResourceManager.Owner::(releaseAll) 
Owner.releaseAll requests {} resources {}
Thread-46::DEBUG::2012-11-14 
02:16:13,569::resourceManager::844::ResourceManager.Owner::(cancelAll) 
Owner.cancelAll requests {}
Thread-46::DEBUG::2012-11-14 
02:16:13,569::task::957::TaskManager.Task::(_decref) 
Task=`ff34ce79-4e9c-4e90-8598-4ec6bd9a682f`::ref 0 aborting False
Thread-49::DEBUG::2012-11-14 02:16:16,586::BindingXMLRPC::161::vds::(wrapper) 
[172.30.49.69]
Thread-49::DEBUG::2012-11-14 
02:16:16,586::task::568::TaskManager.Task::(_updateState) 
Task=`11fbe03e-edec-402c-a59a-9efa09d802a0`::moving from state init -> state 
preparing
Thread-49::INFO::2012-11-14 02:16:16,587::logUtils::37::dispatcher::(wrapper) 
Run and protect: validateStorageServerConnection(domType=4, 
spUUID='00000000-0000-0000-0000-000000000000', conList=[{'connection': 
'/data/images', 'iqn': '', 'portal': '', 'user': '', 'password': '******', 
'id': 'd64e9233-cfa5-407a-9d2d-8d3d012cb084', 'port': ''}], options=None)
Thread-49::INFO::2012-11-14 02:16:16,587::logUtils::39::dispatcher::(wrapper) 
Run and protect: validateStorageServerConnection, Return response: 
{'statuslist': [{'status': 0, 'id': 'd64e9233-cfa5-407a-9d2d-8d3d012cb084'}]}
Thread-49::DEBUG::2012-11-14 
02:16:16,587::task::1151::TaskManager.Task::(prepare) 
Task=`11fbe03e-edec-402c-a59a-9efa09d802a0`::finished: {'statuslist': 
[{'status': 0, 'id': 'd64e9233-cfa5-407a-9d2d-8d3d012cb084'}]}
Thread-49::DEBUG::2012-11-14 
02:16:16,587::task::568::TaskManager.Task::(_updateState) 
Task=`11fbe03e-edec-402c-a59a-9efa09d802a0`::moving from state preparing -> 
state finished
Thread-49::DEBUG::2012-11-14 
02:16:16,587::resourceManager::809::ResourceManager.Owner::(releaseAll) 
Owner.releaseAll requests {} resources {}
Thread-49::DEBUG::2012-11-14 
02:16:16,587::resourceManager::844::ResourceManager.Owner::(cancelAll) 
Owner.cancelAll requests {}
Thread-49::DEBUG::2012-11-14 
02:16:16,587::task::957::TaskManager.Task::(_decref) 
Task=`11fbe03e-edec-402c-a59a-9efa09d802a0`::ref 0 aborting False
Thread-50::DEBUG::2012-11-14 02:16:16,646::BindingXMLRPC::161::vds::(wrapper) 
[172.30.49.69]
Thread-50::DEBUG::2012-11-14 
02:16:16,646::task::568::TaskManager.Task::(_updateState) 
Task=`492eab31-c95c-42dd-8d15-73d30d37387c`::moving from state init -> state 
preparing
Thread-50::INFO::2012-11-14 02:16:16,646::logUtils::37::dispatcher::(wrapper) 
Run and protect: connectStorageServer(domType=4, 
spUUID='00000000-0000-0000-0000-000000000000', conList=[{'connection': 
'/data/images', 'iqn': '', 'portal': '', 'user': '', 'password': '******', 
'id': 'd64e9233-cfa5-407a-9d2d-8d3d012cb084', 'port': ''}], options=None)
Thread-50::ERROR::2012-11-14 
02:16:16,764::hsm::2046::Storage.HSM::(connectStorageServer) Could not connect 
to storageServer
Traceback (most recent call last):
   File "/usr/share/vdsm/storage/hsm.py", line 2043, in connectStorageServer
     conObj.connect()
   File "/usr/share/vdsm/storage/storageServer.py", line 462, in connect
     if not self.checkTarget():
   File "/usr/share/vdsm/storage/storageServer.py", line 449, in checkTarget
     fileSD.validateDirAccess(self._path))
   File "/usr/share/vdsm/storage/fileSD.py", line 52, in validateDirAccess
     getProcPool().fileUtils.validateAccess(dirPath)
   File "/usr/share/vdsm/storage/remoteFileHandler.py", line 277, in 
callCrabRPCFunction
     *args, **kwargs)
   File "/usr/share/vdsm/storage/remoteFileHandler.py", line 180, in 
callCrabRPCFunction
     rawLength = self._recvAll(LENGTH_STRUCT_LENGTH, timeout)
   File "/usr/share/vdsm/storage/remoteFileHandler.py", line 149, in _recvAll
     timeLeft):
   File "/usr/lib64/python2.7/contextlib.py", line 84, in helper
     return GeneratorContextManager(func(*args, **kwds))
   File "/usr/share/vdsm/storage/remoteFileHandler.py", line 136, in _poll
     raise Timeout()
Timeout
Thread-50::INFO::2012-11-14 02:16:16,766::logUtils::39::dispatcher::(wrapper) 
Run and protect: connectStorageServer, Return response: {'statuslist': 
[{'status': 100, 'id': 'd64e9233-cfa5-407a-9d2d-8d3d012cb084'}]}
Thread-50::DEBUG::2012-11-14 
02:16:16,767::task::1151::TaskManager.Task::(prepare) 
Task=`492eab31-c95c-42dd-8d15-73d30d37387c`::finished: {'statuslist': 
[{'status': 100, 'id': 'd64e9233-cfa5-407a-9d2d-8d3d012cb084'}]}
Thread-50::DEBUG::2012-11-14 
02:16:16,767::task::568::TaskManager.Task::(_updateState) 
Task=`492eab31-c95c-42dd-8d15-73d30d37387c`::moving from state preparing -> 
state finished
Thread-50::DEBUG::2012-11-14 
02:16:16,767::resourceManager::809::ResourceManager.Owner::(releaseAll) 
Owner.releaseAll requests {} resources {}
Thread-50::DEBUG::2012-11-14 
02:16:16,767::resourceManager::844::ResourceManager.Owner::(cancelAll) 
Owner.cancelAll requests {}
Thread-50::DEBUG::2012-11-14 
02:16:16,767::task::957::TaskManager.Task::(_decref) 
Task=`492eab31-c95c-42dd-8d15-73d30d37387c`::ref 0 aborting False
Thread-53::DEBUG::2012-11-14 02:16:17,228::BindingXMLRPC::161::vds::(wrapper) 
[172.30.49.69]
Thread-53::DEBUG::2012-11-14 
02:16:17,228::task::568::TaskManager.Task::(_updateState) 
Task=`8ea8b685-4aa1-40b2-af98-e3f6211e3379`::moving from state init -> state 
preparing
Thread-53::INFO::2012-11-14 02:16:17,229::logUtils::37::dispatcher::(wrapper) 
Run and protect: createStorageDomain(storageType=4, 
sdUUID='755d1288-13c8-4d3b-9455-6c14322dc712', domainName='store1', 
typeSpecificArg='/data/images', domClass=1, domVersion='0', options=None)
Thread-53::DEBUG::2012-11-14 
02:16:17,229::misc::1026::SamplingMethod::(__call__) Trying to enter sampling 
method (storage.sdc.refreshStorage)
Thread-53::DEBUG::2012-11-14 
02:16:17,229::misc::1028::SamplingMethod::(__call__) Got in to sampling method
Thread-53::DEBUG::2012-11-14 
02:16:17,229::misc::1026::SamplingMethod::(__call__) Trying to enter sampling 
method (storage.iscsi.rescan)
Thread-53::DEBUG::2012-11-14 
02:16:17,229::misc::1028::SamplingMethod::(__call__) Got in to sampling method
Thread-53::DEBUG::2012-11-14 
02:16:17,230::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo -n 
/usr/sbin/iscsiadm -m session -R' (cwd None)
Thread-53::DEBUG::2012-11-14 02:16:17,274::misc::84::Storage.Misc.excCmd::(<lambda>) 
FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
Thread-53::DEBUG::2012-11-14 
02:16:17,274::misc::1036::SamplingMethod::(__call__) Returning last result
MainProcess|Thread-53::DEBUG::2012-11-14 
02:16:17,276::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd 
of=/sys/class/scsi_host/host0/scan' (cwd None)
MainProcess|Thread-53::DEBUG::2012-11-14 
02:16:17,281::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/dd 
of=/sys/class/scsi_host/host1/scan' (cwd None)
MainProcess|Thread-53::DEBUG::2012-11-14 
02:16:17,285::iscsi::388::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, 
this will take up to 30 seconds
Thread-53::DEBUG::2012-11-14 
02:16:19,288::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo -n 
/sbin/multipath' (cwd None)
Thread-53::DEBUG::2012-11-14 02:16:19,371::misc::84::Storage.Misc.excCmd::(<lambda>) 
SUCCESS: <err> = ''; <rc> = 0
Thread-53::DEBUG::2012-11-14 
02:16:19,372::lvm::477::OperationMutex::(_invalidateAllPvs) Operation 'lvm 
invalidate operation' got the operation mutex
Thread-53::DEBUG::2012-11-14 
02:16:19,372::lvm::479::OperationMutex::(_invalidateAllPvs) Operation 'lvm 
invalidate operation' released the operation mutex
Thread-53::DEBUG::2012-11-14 
02:16:19,372::lvm::488::OperationMutex::(_invalidateAllVgs) Operation 'lvm 
invalidate operation' got the operation mutex
Thread-53::DEBUG::2012-11-14 
02:16:19,372::lvm::490::OperationMutex::(_invalidateAllVgs) Operation 'lvm 
invalidate operation' released the operation mutex
Thread-53::DEBUG::2012-11-14 
02:16:19,373::lvm::508::OperationMutex::(_invalidateAllLvs) Operation 'lvm 
invalidate operation' got the operation mutex
Thread-53::DEBUG::2012-11-14 
02:16:19,373::lvm::510::OperationMutex::(_invalidateAllLvs) Operation 'lvm 
invalidate operation' released the operation mutex
Thread-53::DEBUG::2012-11-14 
02:16:19,373::misc::1036::SamplingMethod::(__call__) Returning last result
Thread-53::DEBUG::2012-11-14 
02:16:19,373::lvm::368::OperationMutex::(_reloadvgs) Operation 'lvm reload 
operation' got the operation mutex
Thread-53::DEBUG::2012-11-14 02:16:19,374::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo -n 
/usr/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 
755d1288-13c8-4d3b-9455-6c14322dc712' (cwd None)
Thread-53::DEBUG::2012-11-14 02:16:19,423::misc::84::Storage.Misc.excCmd::(<lambda>) FAILED: 
<err> = '  Volume group "755d1288-13c8-4d3b-9455-6c14322dc712" not found\n'; <rc> = 5
Thread-53::WARNING::2012-11-14 02:16:19,423::lvm::373::Storage.LVM::(_reloadvgs) lvm vgs 
failed: 5 [] ['  Volume group "755d1288-13c8-4d3b-9455-6c14322dc712" not found']
Thread-53::DEBUG::2012-11-14 
02:16:19,424::lvm::397::OperationMutex::(_reloadvgs) Operation 'lvm reload 
operation' released the operation mutex
Thread-53::INFO::2012-11-14 
02:16:19,424::localFsSD::61::Storage.StorageDomain::(create) 
sdUUID=755d1288-13c8-4d3b-9455-6c14322dc712 domainName=store1 
remotePath=/data/images domClass=1
Thread-53::ERROR::2012-11-14 
02:16:19,541::task::833::TaskManager.Task::(_setError) 
Task=`8ea8b685-4aa1-40b2-af98-e3f6211e3379`::Unexpected error
Traceback (most recent call last):
   File "/usr/share/vdsm/storage/task.py", line 840, 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 2253, in createStorageDomain
     domClass, typeSpecificArg, storageType, domVersion)
   File "/usr/share/vdsm/storage/localFsSD.py", line 72, in create
     cls._preCreateValidation(sdUUID, mntPoint, remotePath, version)
   File "/usr/share/vdsm/storage/localFsSD.py", line 39, in _preCreateValidation
     fileSD.validateDirAccess(domPath)
   File "/usr/share/vdsm/storage/fileSD.py", line 52, in validateDirAccess
     getProcPool().fileUtils.validateAccess(dirPath)
   File "/usr/share/vdsm/storage/remoteFileHandler.py", line 277, in 
callCrabRPCFunction
     *args, **kwargs)
   File "/usr/share/vdsm/storage/remoteFileHandler.py", line 180, in 
callCrabRPCFunction
     rawLength = self._recvAll(LENGTH_STRUCT_LENGTH, timeout)
   File "/usr/share/vdsm/storage/remoteFileHandler.py", line 149, in _recvAll
     timeLeft):
   File "/usr/lib64/python2.7/contextlib.py", line 84, in helper
     return GeneratorContextManager(func(*args, **kwds))
   File "/usr/share/vdsm/storage/remoteFileHandler.py", line 136, in _poll
     raise Timeout()
Timeout
Thread-53::DEBUG::2012-11-14 02:16:19,542::task::852::TaskManager.Task::(_run) 
Task=`8ea8b685-4aa1-40b2-af98-e3f6211e3379`::Task._run: 
8ea8b685-4aa1-40b2-af98-e3f6211e3379 (4, 
'755d1288-13c8-4d3b-9455-6c14322dc712', 'store1', '/data/images', 1, '0') {} 
failed - stopping task
Thread-53::DEBUG::2012-11-14 02:16:19,542::task::1177::TaskManager.Task::(stop) 
Task=`8ea8b685-4aa1-40b2-af98-e3f6211e3379`::stopping in state preparing (force 
False)
Thread-53::DEBUG::2012-11-14 
02:16:19,543::task::957::TaskManager.Task::(_decref) 
Task=`8ea8b685-4aa1-40b2-af98-e3f6211e3379`::ref 1 aborting True
Thread-53::INFO::2012-11-14 
02:16:19,543::task::1134::TaskManager.Task::(prepare) 
Task=`8ea8b685-4aa1-40b2-af98-e3f6211e3379`::aborting: Task is aborted: u'' - 
code 100
Thread-53::DEBUG::2012-11-14 
02:16:19,543::task::1139::TaskManager.Task::(prepare) 
Task=`8ea8b685-4aa1-40b2-af98-e3f6211e3379`::Prepare: aborted:
Thread-53::DEBUG::2012-11-14 
02:16:19,543::task::957::TaskManager.Task::(_decref) 
Task=`8ea8b685-4aa1-40b2-af98-e3f6211e3379`::ref 0 aborting True
Thread-53::DEBUG::2012-11-14 
02:16:19,543::task::892::TaskManager.Task::(_doAbort) 
Task=`8ea8b685-4aa1-40b2-af98-e3f6211e3379`::Task._doAbort: force False
Thread-53::DEBUG::2012-11-14 
02:16:19,544::resourceManager::844::ResourceManager.Owner::(cancelAll) 
Owner.cancelAll requests {}
Thread-53::DEBUG::2012-11-14 
02:16:19,544::task::568::TaskManager.Task::(_updateState) 
Task=`8ea8b685-4aa1-40b2-af98-e3f6211e3379`::moving from state preparing -> 
state aborting
Thread-53::DEBUG::2012-11-14 
02:16:19,544::task::523::TaskManager.Task::(__state_aborting) 
Task=`8ea8b685-4aa1-40b2-af98-e3f6211e3379`::_aborting: recover policy none
Thread-53::DEBUG::2012-11-14 
02:16:19,544::task::568::TaskManager.Task::(_updateState) 
Task=`8ea8b685-4aa1-40b2-af98-e3f6211e3379`::moving from state aborting -> 
state failed
Thread-53::DEBUG::2012-11-14 
02:16:19,544::resourceManager::809::ResourceManager.Owner::(releaseAll) 
Owner.releaseAll requests {} resources {}
Thread-53::DEBUG::2012-11-14 
02:16:19,544::resourceManager::844::ResourceManager.Owner::(cancelAll) 
Owner.cancelAll requests {}
Thread-53::ERROR::2012-11-14 
02:16:19,544::dispatcher::69::Storage.Dispatcher.Protect::(run)
Traceback (most recent call last):
   File "/usr/share/vdsm/storage/dispatcher.py", line 61, in run
     result = ctask.prepare(self.func, *args, **kwargs)
   File "/usr/share/vdsm/storage/task.py", line 1142, in prepare
     raise self.error
Timeout
Thread-59::DEBUG::2012-11-14 
02:16:23,767::task::568::TaskManager.Task::(_updateState) 
Task=`2e64438f-64c1-4f55-82bc-1f871bba1c56`::moving from state init -> state 
preparing
Thread-59::INFO::2012-11-14 02:16:23,768::logUtils::37::dispatcher::(wrapper) 
Run and protect: repoStats(options=None)
Thread-59::INFO::2012-11-14 02:16:23,768::logUtils::39::dispatcher::(wrapper) 
Run and protect: repoStats, Return response: {}
Thread-59::DEBUG::2012-11-14 
02:16:23,768::task::1151::TaskManager.Task::(prepare) 
Task=`2e64438f-64c1-4f55-82bc-1f871bba1c56`::finished: {}
Thread-59::DEBUG::2012-11-14 
02:16:23,768::task::568::TaskManager.Task::(_updateState) 
Task=`2e64438f-64c1-4f55-82bc-1f871bba1c56`::moving from state preparing -> 
state finished
Thread-59::DEBUG::2012-11-14 
02:16:23,768::resourceManager::809::ResourceManager.Owner::(releaseAll) 
Owner.releaseAll requests {} resources {}
Thread-59::DEBUG::2012-11-14 
02:16:23,768::resourceManager::844::ResourceManager.Owner::(cancelAll) 
Owner.cancelAll requests {}
Thread-59::DEBUG::2012-11-14 
02:16:23,768::task::957::TaskManager.Task::(_decref) 
Task=`2e64438f-64c1-4f55-82bc-1f871bba1c56`::ref 0 aborting False
Thread-65::DEBUG::2012-11-14 
02:16:33,921::task::568::TaskManager.Task::(_updateState) 
Task=`2f5bd3d8-ada8-4931-a76c-fff7dad79d3d`::moving from state init -> state 
preparing
Thread-65::INFO::2012-11-14 02:16:33,921::logUtils::37::dispatcher::(wrapper) 
Run and protect: repoStats(options=None)
Thread-65::INFO::2012-11-14 02:16:33,921::logUtils::39::dispatcher::(wrapper) 
Run and protect: repoStats, Return response: {}
Thread-65::DEBUG::2012-11-14 
02:16:33,922::task::1151::TaskManager.Task::(prepare) 
Task=`2f5bd3d8-ada8-4931-a76c-fff7dad79d3d`::finished: {}
Thread-65::DEBUG::2012-11-14 
02:16:33,922::task::568::TaskManager.Task::(_updateState) 
Task=`2f5bd3d8-ada8-4931-a76c-fff7dad79d3d`::moving from state preparing -> 
state finished
Thread-65::DEBUG::2012-11-14 
02:16:33,922::resourceManager::809::ResourceManager.Owner::(releaseAll) 
Owner.releaseAll requests {} resources {}
Thread-65::DEBUG::2012-11-14 
02:16:33,922::resourceManager::844::ResourceManager.Owner::(cancelAll) 
Owner.cancelAll requests {}
Thread-65::DEBUG::2012-11-14 
02:16:33,922::task::957::TaskManager.Task::(_decref) 
Task=`2f5bd3d8-ada8-4931-a76c-fff7dad79d3d`::ref 0 aborting False


Machine with VDSM is Running on Fedora17.
Any idea?

Thanks,
Itzik
_______________________________________________
vdsm-devel mailing list
vdsm-devel@lists.fedorahosted.org
https://lists.fedorahosted.org/mailman/listinfo/vdsm-devel


--
---
舒明 Shu Ming
Open Virtualization Engineerning; CSTL, IBM Corp.
Tel: 86-10-82451626  Tieline: 9051626 E-mail: shum...@cn.ibm.com or 
shum...@linux.vnet.ibm.com
Address: 3/F Ring Building, ZhongGuanCun Software Park, Haidian District, 
Beijing 100193, PRC


_______________________________________________
vdsm-devel mailing list
vdsm-devel@lists.fedorahosted.org
https://lists.fedorahosted.org/mailman/listinfo/vdsm-devel

Reply via email to