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