Thank you for your reply. The check list are all okay. Do you have other check list?
I have created another volume. However, result is same. vdsm.log is as follows.
Thread-3849::DEBUG::2012-11-29 07:34:11,810::BindingXMLRPC::156::vds::(wrapper) [192.168.77.1]
Thread-3849::DEBUG::2012-11-29 07:34:11,811::task::588::TaskManager.Task::(_updateState) Task=`e2011748-ff36-4ffe-bb2d-4244ba461f29`::moving from state init -> state preparing
Thread-3849::INFO::2012-11-29 07:34:11,811::logUtils::37::dispatcher::(wrapper) Run and protect: validateStorageServerConnection(domType=6, spUUID='00000000-0000-0000-0000-000000000000', conList=[{'port': '', 'connection': 'localhost:/volume', 'mnt_options': 'vers=3', 'portal': '', 'user': '', 'iqn': '', 'vfs_type': 'glusterfs', 'password': '******', 'id': '00000000-0000-0000-0000-000000000000'}], options=None)
Thread-3849::INFO::2012-11-29 07:34:11,811::logUtils::39::dispatcher::(wrapper) Run and protect: validateStorageServerConnection, Return response: {'statuslist': [{'status': 0, 'id': '00000000-0000-0000-0000-000000000000'}]}
Thread-3849::DEBUG::2012-11-29 07:34:11,811::task::1172::TaskManager.Task::(prepare) Task=`e2011748-ff36-4ffe-bb2d-4244ba461f29`::finished: {'statuslist': [{'status': 0, 'id': '00000000-0000-0000-0000-000000000000'}]}
Thread-3849::DEBUG::2012-11-29 07:34:11,812::task::588::TaskManager.Task::(_updateState) Task=`e2011748-ff36-4ffe-bb2d-4244ba461f29`::moving from state preparing -> state finished
Thread-3849::DEBUG::2012-11-29 07:34:11,812::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-3849::DEBUG::2012-11-29 07:34:11,812::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-3849::DEBUG::2012-11-29 07:34:11,812::task::978::TaskManager.Task::(_decref) Task=`e2011748-ff36-4ffe-bb2d-4244ba461f29`::ref 0 aborting False
Thread-3850::DEBUG::2012-11-29 07:34:11,828::BindingXMLRPC::156::vds::(wrapper) [192.168.77.1]
Thread-3850::DEBUG::2012-11-29 07:34:11,828::task::588::TaskManager.Task::(_updateState) Task=`b21afac6-67df-49f2-9d5e-57888a8471a6`::moving from state init -> state preparing
Thread-3850::INFO::2012-11-29 07:34:11,829::logUtils::37::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=6, spUUID='00000000-0000-0000-0000-000000000000', conList=[{'port': '', 'connection': 'localhost:/volume', 'mnt_options': 'vers=3', 'portal': '', 'user': '', 'iqn': '', 'vfs_type': 'glusterfs', 'password': '******', 'id': 'a3675b5e-9433-435f-aecb-d9cad60f6d36'}], options=None)
Thread-3850::DEBUG::2012-11-29 07:34:11,840::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /usr/bin/mount -t glusterfs -o vers=3 localhost:/volume /rhev/data-center/mnt/localhost:_volume' (cwd None)
Thread-3850::ERROR::2012-11-29 07:34:11,906::hsm::1932::Storage.HSM::(connectStorageServer) Could not connect to storageServer
Traceback (most recent call last):
File "/usr/share/vdsm/storage/hsm.py", line 1929, in connectStorageServer
conObj.connect()
File "/usr/share/vdsm/storage/storageServer.py", line 179, in connect
self._mount.mount(self.options, self._vfsType)
File "/usr/share/vdsm/storage/mount.py", line 190, in mount
return self._runcmd(cmd, timeout)
File "/usr/share/vdsm/storage/mount.py", line 206, in _runcmd
raise MountError(rc, ";".join((out, err)))
MountError: (1, 'unknown option vers (ignored)\nMount failed. Please check the log file for more details.\n;ERROR: failed to create logfile "/var/log/glusterfs/rhev-data-center-mnt-localhost:_volume.log" (Permission denied)\nERROR: failed to open logfile /var/log/glusterfs/rhev-data-center-mnt-localhost:_volume.log\n')
Thread-3850::DEBUG::2012-11-29 07:34:11,907::lvm::457::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-3850::DEBUG::2012-11-29 07:34:11,907::lvm::459::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-3850::DEBUG::2012-11-29 07:34:11,907::lvm::469::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
Thread-3850::DEBUG::2012-11-29 07:34:11,908::lvm::471::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
Thread-3850::DEBUG::2012-11-29 07:34:11,908::lvm::490::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-3850::DEBUG::2012-11-29 07:34:11,908::lvm::492::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-3850::INFO::2012-11-29 07:34:11,909::logUtils::39::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 477, 'id': 'a3675b5e-9433-435f-aecb-d9cad60f6d36'}]}
Thread-3850::DEBUG::2012-11-29 07:34:11,909::task::1172::TaskManager.Task::(prepare) Task=`b21afac6-67df-49f2-9d5e-57888a8471a6`::finished: {'statuslist': [{'status': 477, 'id': 'a3675b5e-9433-435f-aecb-d9cad60f6d36'}]}
Thread-3850::DEBUG::2012-11-29 07:34:11,909::task::588::TaskManager.Task::(_updateState) Task=`b21afac6-67df-49f2-9d5e-57888a8471a6`::moving from state preparing -> state finished
Thread-3850::DEBUG::2012-11-29 07:34:11,909::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-3850::DEBUG::2012-11-29 07:34:11,910::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-3850::DEBUG::2012-11-29 07:34:11,910::task::978::TaskManager.Task::(_decref) Task=`b21afac6-67df-49f2-9d5e-57888a8471a6`::ref 0 aborting False
Thread-3851::DEBUG::2012-11-29 07:34:11,969::BindingXMLRPC::156::vds::(wrapper) [192.168.77.1]
Thread-3851::DEBUG::2012-11-29 07:34:11,969::task::588::TaskManager.Task::(_updateState) Task=`1262ec8a-3408-429c-a512-1e7bfcc9187d`::moving from state init -> state preparing
Thread-3851::INFO::2012-11-29 07:34:11,970::logUtils::37::dispatcher::(wrapper) Run and protect: createStorageDomain(storageType=6, sdUUID='e8bc9361-1e71-48ef-9e3f-dc4affb856f2', domainName='volume', typeSpecificArg='localhost:/volume', domClass=1, domVersion='0', options=None)
Thread-3851::DEBUG::2012-11-29 07:34:11,970::misc::1053::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
Thread-3851::DEBUG::2012-11-29 07:34:11,970::misc::1055::SamplingMethod::(__call__) Got in to sampling method
Thread-3851::DEBUG::2012-11-29 07:34:11,971::misc::1053::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
Thread-3851::DEBUG::2012-11-29 07:34:11,971::misc::1055::SamplingMethod::(__call__) Got in to sampling method
Thread-3851::DEBUG::2012-11-29 07:34:11,971::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
Thread-3851::DEBUG::2012-11-29 07:34:11,987::__init__::1249::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
Thread-3851::DEBUG::2012-11-29 07:34:11,987::misc::1063::SamplingMethod::(__call__) Returning last result
Thread-3852::DEBUG::2012-11-29 07:34:12,239::task::588::TaskManager.Task::(_updateState) Task=`b63dbf12-0e8c-4828-a475-7e5fa0d7dff0`::moving from state init -> state preparing
Thread-3852::INFO::2012-11-29 07:34:12,239::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
Thread-3852::INFO::2012-11-29 07:34:12,240::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
Thread-3852::DEBUG::2012-11-29 07:34:12,240::task::1172::TaskManager.Task::(prepare) Task=`b63dbf12-0e8c-4828-a475-7e5fa0d7dff0`::finished: {}
Thread-3852::DEBUG::2012-11-29 07:34:12,240::task::588::TaskManager.Task::(_updateState) Task=`b63dbf12-0e8c-4828-a475-7e5fa0d7dff0`::moving from state preparing -> state finished
Thread-3852::DEBUG::2012-11-29 07:34:12,240::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-3852::DEBUG::2012-11-29 07:34:12,241::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-3852::DEBUG::2012-11-29 07:34:12,241::task::978::TaskManager.Task::(_decref) Task=`b63dbf12-0e8c-4828-a475-7e5fa0d7dff0`::ref 0 aborting False
Thread-3851::DEBUG::2012-11-29 07:34:14,180::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None)
Thread-3851::DEBUG::2012-11-29 07:34:14,322::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-3851::DEBUG::2012-11-29 07:34:14,322::lvm::457::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-3851::DEBUG::2012-11-29 07:34:14,323::lvm::459::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-3851::DEBUG::2012-11-29 07:34:14,323::lvm::469::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
Thread-3851::DEBUG::2012-11-29 07:34:14,323::lvm::471::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
Thread-3851::DEBUG::2012-11-29 07:34:14,324::lvm::490::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-3851::DEBUG::2012-11-29 07:34:14,324::lvm::492::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-3851::DEBUG::2012-11-29 07:34:14,324::misc::1063::SamplingMethod::(__call__) Returning last result
Thread-3851::DEBUG::2012-11-29 07:34:14,324::lvm::349::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
Thread-3851::DEBUG::2012-11-29 07:34:14,325::__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 e8bc9361-1e71-48ef-9e3f-dc4affb856f2' (cwd None)
Thread-3851::DEBUG::2012-11-29 07:34:14,391::__init__::1249::Storage.Misc.excCmd::(_log) FAILED: <err> = ' Volume group "e8bc9361-1e71-48ef-9e3f-dc4affb856f2" not found\n'; <rc> = 5
Thread-3851::WARNING::2012-11-29 07:34:14,392::lvm::353::Storage.LVM::(_reloadvgs) lvm vgs failed: 5 [] [' Volume group "e8bc9361-1e71-48ef-9e3f-dc4affb856f2" not found']
Thread-3851::DEBUG::2012-11-29 07:34:14,392::lvm::376::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
Thread-3851::INFO::2012-11-29 07:34:14,396::nfsSD::64::Storage.StorageDomain::(create) sdUUID=e8bc9361-1e71-48ef-9e3f-dc4affb856f2 domainName=volume remotePath=localhost:/volume domClass=1
Thread-3851::ERROR::2012-11-29 07:34:14,407::task::853::TaskManager.Task::(_setError) Task=`1262ec8a-3408-429c-a512-1e7bfcc9187d`::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 2136, in createStorageDomain
typeSpecificArg, storageType, domVersion)
File "/usr/share/vdsm/storage/nfsSD.py", line 75, in create
cls._preCreateValidation(sdUUID, mntPoint, remotePath, version)
File "/usr/share/vdsm/storage/nfsSD.py", line 44, in _preCreateValidation
raise se.StorageDomainFSNotMounted(domPath)
StorageDomainFSNotMounted: Storage domain remote path not mounted: ('/rhev/data-center/mnt/localhost:_volume',)
Thread-3851::DEBUG::2012-11-29 07:34:14,408::task::872::TaskManager.Task::(_run) Task=`1262ec8a-3408-429c-a512-1e7bfcc9187d`::Task._run: 1262ec8a-3408-429c-a512-1e7bfcc9187d (6, 'e8bc9361-1e71-48ef-9e3f-dc4affb856f2', 'volume', 'localhost:/volume', 1, '0') {} failed - stopping task
Thread-3851::DEBUG::2012-11-29 07:34:14,408::task::1199::TaskManager.Task::(stop) Task=`1262ec8a-3408-429c-a512-1e7bfcc9187d`::stopping in state preparing (force False)
Thread-3851::DEBUG::2012-11-29 07:34:14,408::task::978::TaskManager.Task::(_decref) Task=`1262ec8a-3408-429c-a512-1e7bfcc9187d`::ref 1 aborting True
Thread-3851::INFO::2012-11-29 07:34:14,409::task::1157::TaskManager.Task::(prepare) Task=`1262ec8a-3408-429c-a512-1e7bfcc9187d`::aborting: Task is aborted: 'Storage domain remote path not mounted' - code 360
Thread-3851::DEBUG::2012-11-29 07:34:14,409::task::1162::TaskManager.Task::(prepare) Task=`1262ec8a-3408-429c-a512-1e7bfcc9187d`::Prepare: aborted: Storage domain remote path not mounted
Thread-3851::DEBUG::2012-11-29 07:34:14,409::task::978::TaskManager.Task::(_decref) Task=`1262ec8a-3408-429c-a512-1e7bfcc9187d`::ref 0 aborting True
Thread-3851::DEBUG::2012-11-29 07:34:14,409::task::913::TaskManager.Task::(_doAbort) Task=`1262ec8a-3408-429c-a512-1e7bfcc9187d`::Task._doAbort: force False
Thread-3851::DEBUG::2012-11-29 07:34:14,409::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-3851::DEBUG::2012-11-29 07:34:14,410::task::588::TaskManager.Task::(_updateState) Task=`1262ec8a-3408-429c-a512-1e7bfcc9187d`::moving from state preparing -> state aborting
Thread-3851::DEBUG::2012-11-29 07:34:14,410::task::537::TaskManager.Task::(__state_aborting) Task=`1262ec8a-3408-429c-a512-1e7bfcc9187d`::_aborting: recover policy none
Thread-3851::DEBUG::2012-11-29 07:34:14,410::task::588::TaskManager.Task::(_updateState) Task=`1262ec8a-3408-429c-a512-1e7bfcc9187d`::moving from state aborting -> state failed
Thread-3851::DEBUG::2012-11-29 07:34:14,410::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-3851::DEBUG::2012-11-29 07:34:14,411::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-3851::ERROR::2012-11-29 07:34:14,411::dispatcher::66::Storage.Dispatcher.Protect::(run) {'status': {'message': "Storage domain remote path not mounted: ('/rhev/data-center/mnt/localhost:_volume',)", 'code': 360}}
Thread-3861::DEBUG::2012-11-29 07:34:22,328::task::588::TaskManager.Task::(_updateState) Task=`56063337-848f-4f0e-8cc3-73db73b9617b`::moving from state init -> state preparing
Thread-3861::INFO::2012-11-29 07:34:22,328::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
Thread-3861::INFO::2012-11-29 07:34:22,328::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
Thread-3861::DEBUG::2012-11-29 07:34:22,329::task::1172::TaskManager.Task::(prepare) Task=`56063337-848f-4f0e-8cc3-73db73b9617b`::finished: {}
Thread-3861::DEBUG::2012-11-29 07:34:22,329::task::588::TaskManager.Task::(_updateState) Task=`56063337-848f-4f0e-8cc3-73db73b9617b`::moving from state preparing -> state finished
Thread-3861::DEBUG::2012-11-29 07:34:22,329::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-3861::DEBUG::2012-11-29 07:34:22,329::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-3861::DEBUG::2012-11-29 07:34:22,329::task::978::TaskManager.Task::(_decref) Task=`56063337-848f-4f0e-8cc3-73db73b9617b`::ref 0 aborting False