[Users] Error Attaching NFS Data Domain to Data Center - oVirt 3.3
Sherry Yu
syu at redhat.com
Mon Apr 29 16:23:14 UTC 2013
Hi Allon, vdsm has write permission to the directory on NFS. I can see that on the hypervisor host the NFS share is mounted and directories have been created by vdsm. vdsm log is attached. The error is at "AcquireHostIdFailure: Cannot acquire host id: ('a7138327-930c-49d7-9f39-c34ee36fc7fb', SanlockException(19, 'Sanlock lockspace add failure', 'No such device'))". Appreciate any input!
[root at sbhost-58 vdsm]# df -k
storage2.phx.salab.redhat.com:/data/sap/ovirt-domain 309637120 187031552 106876928 64% /rhev/data-center/mnt/storage2.phx.salab.redhat.com:_data_sap_ovirt-domain
[root at sbhost-58 dom_md]# pwd
/rhev/data-center/mnt/storage2.phx.salab.redhat.com:_data_sap_ovirt-domain/a7138327-930c-49d7-9f39-c34ee36fc7fb/dom_md
[root at sbhost-58 dom_md]# ls -la
total 2060
drwxr-xr-x. 2 vdsm kvm 4096 Apr 25 20:35 .
drwxr-xr-x. 4 vdsm kvm 4096 Apr 25 20:35 ..
-rw-rw----. 1 vdsm kvm 1048576 Apr 25 20:35 ids
-rw-rw----. 1 vdsm kvm 0 Apr 25 20:35 inbox
-rw-rw----. 1 vdsm kvm 2097152 Apr 25 20:35 leases
-rw-r--r--. 1 vdsm kvm 319 Apr 25 20:35 metadata
-rw-rw----. 1 vdsm kvm 0 Apr 25 20:35 outbox
vdsm.log:
Thread-186874::DEBUG::2013-04-29 12:16:05,229::BindingXMLRPC::161::vds::(wrapper) [10.3.76.215]
Thread-186874::DEBUG::2013-04-29 12:16:05,229::task::568::TaskManager.Task::(_updateState) Task=`6a316ab2-3d08-44d4-b3d9-60620f23fc72`::moving from state init -> state preparing
Thread-186874::INFO::2013-04-29 12:16:05,230::logUtils::41::dispatcher::(wrapper) Run and protect: validateStorageServerConnection(domType=1, spUUID='00000000-0000-0000-0000-000000000000', conList=[{'port': '', 'connection': 'storage2.phx.salab.redhat.com:/data/sap/ovirt-domain', 'iqn': '', 'portal': '', 'user': '', 'protocol_version': 'auto', 'password': '******', 'id': 'c925e43f-ff52-45ae-8484-e4ac6b670143'}], options=None)
Thread-186874::INFO::2013-04-29 12:16:05,230::logUtils::44::dispatcher::(wrapper) Run and protect: validateStorageServerConnection, Return response: {'statuslist': [{'status': 0, 'id': 'c925e43f-ff52-45ae-8484-e4ac6b670143'}]}
Thread-186874::DEBUG::2013-04-29 12:16:05,230::task::1151::TaskManager.Task::(prepare) Task=`6a316ab2-3d08-44d4-b3d9-60620f23fc72`::finished: {'statuslist': [{'status': 0, 'id': 'c925e43f-ff52-45ae-8484-e4ac6b670143'}]}
Thread-186874::DEBUG::2013-04-29 12:16:05,230::task::568::TaskManager.Task::(_updateState) Task=`6a316ab2-3d08-44d4-b3d9-60620f23fc72`::moving from state preparing -> state finished
Thread-186874::DEBUG::2013-04-29 12:16:05,231::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-186874::DEBUG::2013-04-29 12:16:05,231::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-186874::DEBUG::2013-04-29 12:16:05,231::task::957::TaskManager.Task::(_decref) Task=`6a316ab2-3d08-44d4-b3d9-60620f23fc72`::ref 0 aborting False
Thread-186875::DEBUG::2013-04-29 12:16:05,240::BindingXMLRPC::161::vds::(wrapper) [10.3.76.215]
Thread-186875::DEBUG::2013-04-29 12:16:05,240::task::568::TaskManager.Task::(_updateState) Task=`e6da9cb6-f577-44bd-a8ba-d08d8946a027`::moving from state init -> state preparing
Thread-186875::INFO::2013-04-29 12:16:05,240::logUtils::41::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=1, spUUID='00000000-0000-0000-0000-000000000000', conList=[{'port': '', 'connection': 'storage2.phx.salab.redhat.com:/data/sap/ovirt-domain', 'iqn': '', 'portal': '', 'user': '', 'protocol_version': 'auto', 'password': '******', 'id': 'c925e43f-ff52-45ae-8484-e4ac6b670143'}], options=None)
Thread-186875::INFO::2013-04-29 12:16:05,247::logUtils::44::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': 'c925e43f-ff52-45ae-8484-e4ac6b670143'}]}
Thread-186875::DEBUG::2013-04-29 12:16:05,248::task::1151::TaskManager.Task::(prepare) Task=`e6da9cb6-f577-44bd-a8ba-d08d8946a027`::finished: {'statuslist': [{'status': 0, 'id': 'c925e43f-ff52-45ae-8484-e4ac6b670143'}]}
Thread-186875::DEBUG::2013-04-29 12:16:05,248::task::568::TaskManager.Task::(_updateState) Task=`e6da9cb6-f577-44bd-a8ba-d08d8946a027`::moving from state preparing -> state finished
Thread-186875::DEBUG::2013-04-29 12:16:05,248::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-186875::DEBUG::2013-04-29 12:16:05,249::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-186875::DEBUG::2013-04-29 12:16:05,249::task::957::TaskManager.Task::(_decref) Task=`e6da9cb6-f577-44bd-a8ba-d08d8946a027`::ref 0 aborting False
Thread-186876::DEBUG::2013-04-29 12:16:05,272::BindingXMLRPC::161::vds::(wrapper) [10.3.76.215]
Thread-186876::DEBUG::2013-04-29 12:16:05,272::task::568::TaskManager.Task::(_updateState) Task=`c62d6d31-4888-40e2-857d-aded3936f6fe`::moving from state init -> state preparing
Thread-186876::INFO::2013-04-29 12:16:05,273::logUtils::41::dispatcher::(wrapper) Run and protect: createStoragePool(poolType=None, spUUID='5849b030-626e-47cb-ad90-3ce782d831b3', poolName='Default', masterDom='a7138327-930c-49d7-9f39-c34ee36fc7fb', domList=['a7138327-930c-49d7-9f39-c34ee36fc7fb'], masterVersion=11, lockPolicy=None, lockRenewalIntervalSec=5, leaseTimeSec=60, ioOpTimeoutSec=10, leaseRetries=3, options=None)
Thread-186876::INFO::2013-04-29 12:16:05,273::fileSD::302::Storage.StorageDomain::(validate) sdUUID=a7138327-930c-49d7-9f39-c34ee36fc7fb
Thread-186876::DEBUG::2013-04-29 12:16:05,291::persistentDict::234::Storage.PersistentDict::(refresh) read lines (FileMetadataRW)=['CLASS=Data', 'DESCRIPTION=oVirt', 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=', 'LOCKRENEWALINTERVALSEC=5', 'POOL_UUID=', 'REMOTE_PATH=storage2.phx.salab.redhat.com:/data/sap/ovirt-domain', 'ROLE=Regular', 'SDUUID=a7138327-930c-49d7-9f39-c34ee36fc7fb', 'TYPE=NFS', 'VERSION=3', '_SHA_CKSUM=d25ce9538d484fbc938cde09f5247bbe709b1549']
Thread-186876::DEBUG::2013-04-29 12:16:05,292::resourceManager::190::ResourceManager.Request::(__init__) ResName=`Storage.5849b030-626e-47cb-ad90-3ce782d831b3`ReqID=`56e7c8fa-abb0-4247-8806-138b24dd95ad`::Request was made in '/usr/share/vdsm/storage/resourceManager.py' line '189' at '__init__'
Thread-186876::DEBUG::2013-04-29 12:16:05,293::resourceManager::504::ResourceManager::(registerResource) Trying to register resource 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3' for lock type 'exclusive'
Thread-186876::DEBUG::2013-04-29 12:16:05,293::resourceManager::547::ResourceManager::(registerResource) Resource 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3' is free. Now locking as 'exclusive' (1 active user)
Thread-186876::DEBUG::2013-04-29 12:16:05,293::resourceManager::227::ResourceManager.Request::(grant) ResName=`Storage.5849b030-626e-47cb-ad90-3ce782d831b3`ReqID=`56e7c8fa-abb0-4247-8806-138b24dd95ad`::Granted request
Thread-186876::DEBUG::2013-04-29 12:16:05,294::task::794::TaskManager.Task::(resourceAcquired) Task=`c62d6d31-4888-40e2-857d-aded3936f6fe`::_resourcesAcquired: Storage.5849b030-626e-47cb-ad90-3ce782d831b3 (exclusive)
Thread-186876::DEBUG::2013-04-29 12:16:05,294::task::957::TaskManager.Task::(_decref) Task=`c62d6d31-4888-40e2-857d-aded3936f6fe`::ref 1 aborting False
Thread-186876::DEBUG::2013-04-29 12:16:05,294::resourceManager::190::ResourceManager.Request::(__init__) ResName=`Storage.a7138327-930c-49d7-9f39-c34ee36fc7fb`ReqID=`818107d5-c2a5-4384-b81b-d0393b7727de`::Request was made in '/usr/share/vdsm/storage/resourceManager.py' line '189' at '__init__'
Thread-186876::DEBUG::2013-04-29 12:16:05,295::resourceManager::504::ResourceManager::(registerResource) Trying to register resource 'Storage.a7138327-930c-49d7-9f39-c34ee36fc7fb' for lock type 'exclusive'
Thread-186876::DEBUG::2013-04-29 12:16:05,295::resourceManager::547::ResourceManager::(registerResource) Resource 'Storage.a7138327-930c-49d7-9f39-c34ee36fc7fb' is free. Now locking as 'exclusive' (1 active user)
Thread-186876::DEBUG::2013-04-29 12:16:05,295::resourceManager::227::ResourceManager.Request::(grant) ResName=`Storage.a7138327-930c-49d7-9f39-c34ee36fc7fb`ReqID=`818107d5-c2a5-4384-b81b-d0393b7727de`::Granted request
Thread-186876::DEBUG::2013-04-29 12:16:05,296::task::794::TaskManager.Task::(resourceAcquired) Task=`c62d6d31-4888-40e2-857d-aded3936f6fe`::_resourcesAcquired: Storage.a7138327-930c-49d7-9f39-c34ee36fc7fb (exclusive)
Thread-186876::DEBUG::2013-04-29 12:16:05,296::task::957::TaskManager.Task::(_decref) Task=`c62d6d31-4888-40e2-857d-aded3936f6fe`::ref 1 aborting False
Thread-186876::INFO::2013-04-29 12:16:05,296::sp::542::Storage.StoragePool::(create) spUUID=5849b030-626e-47cb-ad90-3ce782d831b3 poolName=Default master_sd=a7138327-930c-49d7-9f39-c34ee36fc7fb domList=['a7138327-930c-49d7-9f39-c34ee36fc7fb'] masterVersion=11 {'LEASETIMESEC': 60, 'IOOPTIMEOUTSEC': 10, 'LEASERETRIES': 3, 'LOCKRENEWALINTERVALSEC': 5}
Thread-186876::INFO::2013-04-29 12:16:05,297::fileSD::302::Storage.StorageDomain::(validate) sdUUID=a7138327-930c-49d7-9f39-c34ee36fc7fb
Thread-186876::DEBUG::2013-04-29 12:16:05,311::persistentDict::234::Storage.PersistentDict::(refresh) read lines (FileMetadataRW)=['CLASS=Data', 'DESCRIPTION=oVirt', 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=', 'LOCKRENEWALINTERVALSEC=5', 'POOL_UUID=', 'REMOTE_PATH=storage2.phx.salab.redhat.com:/data/sap/ovirt-domain', 'ROLE=Regular', 'SDUUID=a7138327-930c-49d7-9f39-c34ee36fc7fb', 'TYPE=NFS', 'VERSION=3', '_SHA_CKSUM=d25ce9538d484fbc938cde09f5247bbe709b1549']
Thread-186876::DEBUG::2013-04-29 12:16:05,325::persistentDict::234::Storage.PersistentDict::(refresh) read lines (FileMetadataRW)=['CLASS=Data', 'DESCRIPTION=oVirt', 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=', 'LOCKRENEWALINTERVALSEC=5', 'POOL_UUID=', 'REMOTE_PATH=storage2.phx.salab.redhat.com:/data/sap/ovirt-domain', 'ROLE=Regular', 'SDUUID=a7138327-930c-49d7-9f39-c34ee36fc7fb', 'TYPE=NFS', 'VERSION=3', '_SHA_CKSUM=d25ce9538d484fbc938cde09f5247bbe709b1549']
Thread-186876::WARNING::2013-04-29 12:16:05,325::fileUtils::185::fileUtils::(createdir) Dir /rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3 already exists
Thread-186876::DEBUG::2013-04-29 12:16:05,327::persistentDict::167::Storage.PersistentDict::(transaction) Starting transaction
Thread-186876::DEBUG::2013-04-29 12:16:05,327::persistentDict::175::Storage.PersistentDict::(transaction) Finished transaction
Thread-186876::INFO::2013-04-29 12:16:05,327::clusterlock::172::SANLock::(acquireHostId) Acquiring host id for domain a7138327-930c-49d7-9f39-c34ee36fc7fb (id: 250)
Thread-186876::ERROR::2013-04-29 12:16:06,329::task::833::TaskManager.Task::(_setError) Task=`c62d6d31-4888-40e2-857d-aded3936f6fe`::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 42, in wrapper
res = f(*args, **kwargs)
File "/usr/share/vdsm/storage/hsm.py", line 895, in createStoragePool
masterVersion, leaseParams)
File "/usr/share/vdsm/storage/sp.py", line 567, in create
self._acquireTemporaryClusterLock(msdUUID, leaseParams)
File "/usr/share/vdsm/storage/sp.py", line 509, in _acquireTemporaryClusterLock
msd.acquireHostId(self.id)
File "/usr/share/vdsm/storage/sd.py", line 436, in acquireHostId
self._clusterLock.acquireHostId(hostId, async)
File "/usr/share/vdsm/storage/clusterlock.py", line 187, in acquireHostId
raise se.AcquireHostIdFailure(self._sdUUID, e)
AcquireHostIdFailure: Cannot acquire host id: ('a7138327-930c-49d7-9f39-c34ee36fc7fb', SanlockException(19, 'Sanlock lockspace add failure', 'No such device'))
Thread-186876::DEBUG::2013-04-29 12:16:06,330::task::852::TaskManager.Task::(_run) Task=`c62d6d31-4888-40e2-857d-aded3936f6fe`::Task._run: c62d6d31-4888-40e2-857d-aded3936f6fe (None, '5849b030-626e-47cb-ad90-3ce782d831b3', 'Default', 'a7138327-930c-49d7-9f39-c34ee36fc7fb', ['a7138327-930c-49d7-9f39-c34ee36fc7fb'], 11, None, 5, 60, 10, 3) {} failed - stopping task
Thread-186876::DEBUG::2013-04-29 12:16:06,330::task::1177::TaskManager.Task::(stop) Task=`c62d6d31-4888-40e2-857d-aded3936f6fe`::stopping in state preparing (force False)
Thread-186876::DEBUG::2013-04-29 12:16:06,330::task::957::TaskManager.Task::(_decref) Task=`c62d6d31-4888-40e2-857d-aded3936f6fe`::ref 1 aborting True
Thread-186876::INFO::2013-04-29 12:16:06,330::task::1134::TaskManager.Task::(prepare) Task=`c62d6d31-4888-40e2-857d-aded3936f6fe`::aborting: Task is aborted: 'Cannot acquire host id' - code 661
Thread-186876::DEBUG::2013-04-29 12:16:06,331::task::1139::TaskManager.Task::(prepare) Task=`c62d6d31-4888-40e2-857d-aded3936f6fe`::Prepare: aborted: Cannot acquire host id
Thread-186876::DEBUG::2013-04-29 12:16:06,331::task::957::TaskManager.Task::(_decref) Task=`c62d6d31-4888-40e2-857d-aded3936f6fe`::ref 0 aborting True
Thread-186876::DEBUG::2013-04-29 12:16:06,331::task::892::TaskManager.Task::(_doAbort) Task=`c62d6d31-4888-40e2-857d-aded3936f6fe`::Task._doAbort: force False
Thread-186876::DEBUG::2013-04-29 12:16:06,332::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-186876::DEBUG::2013-04-29 12:16:06,332::task::568::TaskManager.Task::(_updateState) Task=`c62d6d31-4888-40e2-857d-aded3936f6fe`::moving from state preparing -> state aborting
Thread-186876::DEBUG::2013-04-29 12:16:06,332::task::523::TaskManager.Task::(__state_aborting) Task=`c62d6d31-4888-40e2-857d-aded3936f6fe`::_aborting: recover policy none
Thread-186876::DEBUG::2013-04-29 12:16:06,332::task::568::TaskManager.Task::(_updateState) Task=`c62d6d31-4888-40e2-857d-aded3936f6fe`::moving from state aborting -> state failed
Thread-186876::DEBUG::2013-04-29 12:16:06,333::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.a7138327-930c-49d7-9f39-c34ee36fc7fb': < ResourceRef 'Storage.a7138327-930c-49d7-9f39-c34ee36fc7fb', isValid: 'True' obj: 'None'>, 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3': < ResourceRef 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3', isValid: 'True' obj: 'None'>}
Thread-186876::DEBUG::2013-04-29 12:16:06,333::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-186876::DEBUG::2013-04-29 12:16:06,333::resourceManager::557::ResourceManager::(releaseResource) Trying to release resource 'Storage.a7138327-930c-49d7-9f39-c34ee36fc7fb'
Thread-186876::DEBUG::2013-04-29 12:16:06,334::resourceManager::573::ResourceManager::(releaseResource) Released resource 'Storage.a7138327-930c-49d7-9f39-c34ee36fc7fb' (0 active users)
Thread-186876::DEBUG::2013-04-29 12:16:06,334::resourceManager::578::ResourceManager::(releaseResource) Resource 'Storage.a7138327-930c-49d7-9f39-c34ee36fc7fb' is free, finding out if anyone is waiting for it.
Thread-186876::DEBUG::2013-04-29 12:16:06,334::resourceManager::585::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.a7138327-930c-49d7-9f39-c34ee36fc7fb', Clearing records.
Thread-186876::DEBUG::2013-04-29 12:16:06,335::resourceManager::557::ResourceManager::(releaseResource) Trying to release resource 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'
Thread-186876::DEBUG::2013-04-29 12:16:06,335::resourceManager::573::ResourceManager::(releaseResource) Released resource 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3' (0 active users)
Thread-186876::DEBUG::2013-04-29 12:16:06,335::resourceManager::578::ResourceManager::(releaseResource) Resource 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3' is free, finding out if anyone is waiting for it.
Thread-186876::DEBUG::2013-04-29 12:16:06,335::resourceManager::585::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3', Clearing records.
Thread-186876::ERROR::2013-04-29 12:16:06,336::dispatcher::67::Storage.Dispatcher.Protect::(run) {'status': {'message': "Cannot acquire host id: ('a7138327-930c-49d7-9f39-c34ee36fc7fb', SanlockException(19, 'Sanlock lockspace add failure', 'No such device'))", 'code': 661}}
Thread-186878::DEBUG::2013-04-29 12:16:07,704::task::568::TaskManager.Task::(_updateState) Task=`54200799-1659-4e8a-99d2-4a82a940468a`::moving from state init -> state preparing
Thread-186878::INFO::2013-04-29 12:16:07,705::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None)
Thread-186878::INFO::2013-04-29 12:16:07,705::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
Thread-186878::DEBUG::2013-04-29 12:16:07,705::task::1151::TaskManager.Task::(prepare) Task=`54200799-1659-4e8a-99d2-4a82a940468a`::finished: {}
Thread-186878::DEBUG::2013-04-29 12:16:07,705::task::568::TaskManager.Task::(_updateState) Task=`54200799-1659-4e8a-99d2-4a82a940468a`::moving from state preparing -> state finished
Thread-186878::DEBUG::2013-04-29 12:16:07,705::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-186878::DEBUG::2013-04-29 12:16:07,705::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-186878::DEBUG::2013-04-29 12:16:07,706::task::957::TaskManager.Task::(_decref) Task=`54200799-1659-4e8a-99d2-4a82a940468a`::ref 0 aborting False
Thread-186884::DEBUG::2013-04-29 12:16:17,875::task::568::TaskManager.Task::(_updateState) Task=`e4a57bc0-1b03-4048-baef-fc8862f332cd`::moving from state init -> state preparing
Thread-186884::INFO::2013-04-29 12:16:17,875::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None)
Thread-186884::INFO::2013-04-29 12:16:17,875::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
Thread-186884::DEBUG::2013-04-29 12:16:17,875::task::1151::TaskManager.Task::(prepare) Task=`e4a57bc0-1b03-4048-baef-fc8862f332cd`::finished: {}
Thread-186884::DEBUG::2013-04-29 12:16:17,876::task::568::TaskManager.Task::(_updateState) Task=`e4a57bc0-1b03-4048-baef-fc8862f332cd`::moving from state preparing -> state finished
Thread-186884::DEBUG::2013-04-29 12:16:17,876::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-186884::DEBUG::2013-04-29 12:16:17,876::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-186884::DEBUG::2013-04-29 12:16:17,876::task::957::TaskManager.Task::(_decref) Task=`e4a57bc0-1b03-4048-baef-fc8862f332cd`::ref 0 aborting False
Thread-186890::DEBUG::2013-04-29 12:16:28,123::task::568::TaskManager.Task::(_updateState) Task=`9619cb33-4f18-4372-a619-b8cc6a1a82a8`::moving from state init -> state preparing
Thread-186890::INFO::2013-04-29 12:16:28,124::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None)
Thread-186890::INFO::2013-04-29 12:16:28,124::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
Thread-186890::DEBUG::2013-04-29 12:16:28,124::task::1151::TaskManager.Task::(prepare) Task=`9619cb33-4f18-4372-a619-b8cc6a1a82a8`::finished: {}
Thread-186890::DEBUG::2013-04-29 12:16:28,124::task::568::TaskManager.Task::(_updateState) Task=`9619cb33-4f18-4372-a619-b8cc6a1a82a8`::moving from state preparing -> state finished
Thread-186890::DEBUG::2013-04-29 12:16:28,125::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-186890::DEBUG::2013-04-29 12:16:28,125::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-186890::DEBUG::2013-04-29 12:16:28,125::task::957::TaskManager.Task::(_decref) Task=`9619cb33-4f18-4372-a619-b8cc6a1a82a8`::ref 0 aborting False
Thread-186896::DEBUG::2013-04-29 12:16:38,519::task::568::TaskManager.Task::(_updateState) Task=`0885f499-5f08-4e30-bc5e-a8fad600c67f`::moving from state init -> state preparing
Thread-186896::INFO::2013-04-29 12:16:38,520::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None)
Thread-186896::INFO::2013-04-29 12:16:38,520::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
Thread-186896::DEBUG::2013-04-29 12:16:38,520::task::1151::TaskManager.Task::(prepare) Task=`0885f499-5f08-4e30-bc5e-a8fad600c67f`::finished: {}
Thread-186896::DEBUG::2013-04-29 12:16:38,520::task::568::TaskManager.Task::(_updateState) Task=`0885f499-5f08-4e30-bc5e-a8fad600c67f`::moving from state preparing -> state finished
Thread-186896::DEBUG::2013-04-29 12:16:38,520::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-186896::DEBUG::2013-04-29 12:16:38,520::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-186896::DEBUG::2013-04-29 12:16:38,521::task::957::TaskManager.Task::(_decref) Task=`0885f499-5f08-4e30-bc5e-a8fad600c67f`::ref 0 aborting False
Thread-186902::DEBUG::2013-04-29 12:16:48,641::task::568::TaskManager.Task::(_updateState) Task=`d7ffd21b-5b75-4b6b-b2f2-2b7fb02cd7be`::moving from state init -> state preparing
Thread-186902::INFO::2013-04-29 12:16:48,642::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None)
Thread-186902::INFO::2013-04-29 12:16:48,642::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
Thread-186902::DEBUG::2013-04-29 12:16:48,642::task::1151::TaskManager.Task::(prepare) Task=`d7ffd21b-5b75-4b6b-b2f2-2b7fb02cd7be`::finished: {}
Thread-186902::DEBUG::2013-04-29 12:16:48,642::task::568::TaskManager.Task::(_updateState) Task=`d7ffd21b-5b75-4b6b-b2f2-2b7fb02cd7be`::moving from state preparing -> state finished
Thread-186902::DEBUG::2013-04-29 12:16:48,642::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-186902::DEBUG::2013-04-29 12:16:48,642::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-186902::DEBUG::2013-04-29 12:16:48,643::task::957::TaskManager.Task::(_decref) Task=`d7ffd21b-5b75-4b6b-b2f2-2b7fb02cd7be`::ref 0 aborting False
Thread-186908::DEBUG::2013-04-29 12:16:58,840::task::568::TaskManager.Task::(_updateState) Task=`5bd18ef7-5152-40c6-9d86-416ab53b6c37`::moving from state init -> state preparing
Thread-186908::INFO::2013-04-29 12:16:58,841::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None)
Thread-186908::INFO::2013-04-29 12:16:58,841::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
Thread-186908::DEBUG::2013-04-29 12:16:58,841::task::1151::TaskManager.Task::(prepare) Task=`5bd18ef7-5152-40c6-9d86-416ab53b6c37`::finished: {}
Thread-186908::DEBUG::2013-04-29 12:16:58,841::task::568::TaskManager.Task::(_updateState) Task=`5bd18ef7-5152-40c6-9d86-416ab53b6c37`::moving from state preparing -> state finished
Thread-186908::DEBUG::2013-04-29 12:16:58,842::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-186908::DEBUG::2013-04-29 12:16:58,842::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-186908::DEBUG::2013-04-29 12:16:58,842::task::957::TaskManager.Task::(_decref) Task=`5bd18ef7-5152-40c6-9d86-416ab53b6c37`::ref 0 aborting False
----- Original Message -----
| Hi Sherry,
| Please check the that vdsm has permissions to write to the directory you're
| trying to create.
| Also, if you could attach the vdsm log that would be great.
| ----- Original Message -----
| | From: "Sherry Yu" <syu at redhat.com>
|
| | To: users at ovirt.org
|
| | Sent: Friday, April 26, 2013 4:04:21 AM
|
| | Subject: [Users] Error Attaching NFS Data Domain to Data Center - oVirt 3.3
|
| | In oVirt 3.3, I created the first data domain in NFS but it failed to
| | attach
| | to the default data center. The hypervisor is a Fedora 18 minimum
| | installation. Below is the configuration and logs
|
| | /var/log/sanlock.log
|
| | 2013-04-25 20:45:25-0400 3710 [941]: s8 lockspace
| | a7138327-930c-49d7-9f39-c34ee36fc7fb:250:/rhev/data-center/mnt/storage2.phx.salab.redhat.com:_data_sap_ovirt-domain/a7138327-930c-49d7-9f39-c34ee36fc7fb/dom_md/ids:0
|
| | 2013-04-25 20:45:25-0400 3710 [5116]: open error -13
| | /rhev/data-center/mnt/storage2.phx.salab.redhat.com:_data_sap_ovirt-domain/a7138327-930c-49d7-9f39-c34ee36fc7fb/dom_md/ids
|
| | 2013-04-25 20:45:25-0400 3710 [5116]: s8 open_disk
| | /rhev/data-center/mnt/storage2.phx.salab.redhat.com:_data_sap_ovirt-domain/a7138327-930c-49d7-9f39-c34ee36fc7fb/dom_md/ids
| | error -13
|
| | 2013-04-25 20:45:26-0400 3711 [941]: s8 add_lockspace fail result -19
|
| | /var/log/ovirt-engine/engine.log
|
| | 2013-04-25 17:55:00,002 INFO
| | [org.ovirt.engine.core.bll.AutoRecoveryManager]
| | (DefaultQuartzScheduler_Worker-2) Autorecovering 0 hosts
|
| | 2013-04-25 17:55:00,008 INFO
| | [org.ovirt.engine.core.bll.AutoRecoveryManager]
| | (DefaultQuartzScheduler_Worker-2) Autorecovering 0 storage domains
|
| | 2013-04-25 17:55:01,574 INFO
| | [org.ovirt.engine.core.bll.storage.AddStoragePoolWithStoragesCommand]
| | (ajp--127.0.0.1-8702-2) Lock Acquired to object EngineLock [exclusiveLocks=
| | key: 5849b030-626e-47cb-ad90-3ce782d831b3 value: POOL
|
| | , sharedLocks= ]
|
| | 2013-04-25 17:55:01,687 INFO
| | [org.ovirt.engine.core.bll.storage.AddStoragePoolWithStoragesCommand]
| | (pool-3-thread-49) [1ed8155e] Running command:
| | AddStoragePoolWithStoragesCommand internal: false. Entities affected : ID:
| | 5849b030-626e-47cb-ad90-3ce782d831b3 Type: StoragePool
|
| | 2013-04-25 17:55:01,768 INFO
| | [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand]
| | (pool-3-thread-49) [783c9d00] START,
| | ValidateStorageServerConnectionVDSCommand(HostName = sbhost-58, HostId =
| | d576e7aa-c2fc-4fee-9125-d8dd61d005be, storagePoolId =
| | 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList =
| | [{
| | id: c925e43f-ff52-45ae-8484-e4ac6b670143, connection:
| | storage2.phx.salab.redhat.com:/data/sap/ovirt-domain, iqn: null, vfsType:
| | null, mountOptions: null, nfsVersion: AUTO, nfsRetrans: null, nfsTimeo:
| | null
| | };]), log id: 71197b7a
|
| | 2013-04-25 17:55:01,792 INFO
| | [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand]
| | (pool-3-thread-49) [783c9d00] FINISH,
| | ValidateStorageServerConnectionVDSCommand, return:
| | {c925e43f-ff52-45ae-8484-e4ac6b670143=0}, log id: 71197b7a
|
| | 2013-04-25 17:55:01,796 INFO
| | [org.ovirt.engine.core.bll.storage.ConnectStorageToVdsCommand]
| | (pool-3-thread-49) [783c9d00] Running command: ConnectStorageToVdsCommand
| | internal: true. Entities affected : ID:
| | aaa00000-0000-0000-0000-123456789aaa
| | Type: System
|
| | 2013-04-25 17:55:01,801 INFO
| | [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand]
| | (pool-3-thread-49) [783c9d00] START,
| | ConnectStorageServerVDSCommand(HostName
| | = sbhost-58, HostId = d576e7aa-c2fc-4fee-9125-d8dd61d005be, storagePoolId =
| | 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList =
| | [{
| | id: c925e43f-ff52-45ae-8484-e4ac6b670143, connection:
| | storage2.phx.salab.redhat.com:/data/sap/ovirt-domain, iqn: null, vfsType:
| | null, mountOptions: null, nfsVersion: AUTO, nfsRetrans: null, nfsTimeo:
| | null
| | };]), log id: 6a4d78ea
|
| | 2013-04-25 17:55:01,828 INFO
| | [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand]
| | (pool-3-thread-49) [783c9d00] FINISH, ConnectStorageServerVDSCommand,
| | return: {c925e43f-ff52-45ae-8484-e4ac6b670143=0}, log id: 6a4d78ea
|
| | 2013-04-25 17:55:01,830 INFO
| | [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateStoragePoolVDSCommand]
| | (pool-3-thread-49) [783c9d00] START, CreateStoragePoolVDSCommand(HostName =
| | sbhost-58, HostId = d576e7aa-c2fc-4fee-9125-d8dd61d005be,
| | storagePoolId=5849b030-626e-47cb-ad90-3ce782d831b3, storageType=NFS,
| | storagePoolName=Default,
| | masterDomainId=a7138327-930c-49d7-9f39-c34ee36fc7fb,
| | domainsIdList=[a7138327-930c-49d7-9f39-c34ee36fc7fb], masterVersion=9), log
| | id: 109f1d33
|
| | 2013-04-25 17:55:02,902 WARN
| | [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase]
| | (pool-3-thread-49) [783c9d00] Weird return value: StatusForXmlRpc
| | [mCode=661, mMessage=Cannot acquire host id:
| | ('a7138327-930c-49d7-9f39-c34ee36fc7fb', SanlockException(19, 'Sanlock
| | lockspace add failure', 'No such device'))]
|
| | 2013-04-25 17:55:02,908 WARN
| | [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase]
| | (pool-3-thread-49) [783c9d00] Weird return value: StatusForXmlRpc
| | [mCode=661, mMessage=Cannot acquire host id:
| | ('a7138327-930c-49d7-9f39-c34ee36fc7fb', SanlockException(19, 'Sanlock
| | lockspace add failure', 'No such device'))]
|
| | 2013-04-25 17:55:02,912 ERROR
| | [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase]
| | (pool-3-thread-49) [783c9d00] Failed in CreateStoragePoolVDS method
|
| | 2013-04-25 17:55:02,915 ERROR
| | [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase]
| | (pool-3-thread-49) [783c9d00] Error code unexpected and error message
| | VDSGenericException: VDSErrorException: Failed to CreateStoragePoolVDS,
| | error = Cannot acquire host id: ('a7138327-930c-49d7-9f39-c34ee36fc7fb',
| | SanlockException(19, 'Sanlock lockspace add failure', 'No such device'))
|
| | 2013-04-25 17:55:02,921 INFO
| | [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase]
| | (pool-3-thread-49) [783c9d00] Command
| | org.ovirt.engine.core.vdsbroker.vdsbroker.CreateStoragePoolVDSCommand
| | return
| | value
|
| | StatusOnlyReturnForXmlRpc [mStatus=StatusForXmlRpc [mCode=661,
| | mMessage=Cannot acquire host id: ('a7138327-930c-49d7-9f39-c34ee36fc7fb',
| | SanlockException(19, 'Sanlock lockspace add failure', 'No such device'))]]
|
| | 2013-04-25 17:55:02,924 INFO
| | [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase]
| | (pool-3-thread-49) [783c9d00] HostName = sbhost-58
|
| | 2013-04-25 17:55:02,926 ERROR
| | [org.ovirt.engine.core.vdsbroker.VDSCommandBase] (pool-3-thread-49)
| | [783c9d00] Command CreateStoragePoolVDS execution failed. Exception:
| | VDSErrorException: VDSGenericException: VDSErrorException: Failed to
| | CreateStoragePoolVDS, error = Cannot acquire host id:
| | ('a7138327-930c-49d7-9f39-c34ee36fc7fb', SanlockException(19, 'Sanlock
| | lockspace add failure', 'No such device'))
|
| | 2013-04-25 17:55:02,932 INFO
| | [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateStoragePoolVDSCommand]
| | (pool-3-thread-49) [783c9d00] FINISH, CreateStoragePoolVDSCommand, log id:
| | 109f1d33
|
| | 2013-04-25 17:55:02,936 ERROR
| | [org.ovirt.engine.core.bll.storage.AddStoragePoolWithStoragesCommand]
| | (pool-3-thread-49) [783c9d00] Command
| | org.ovirt.engine.core.bll.storage.AddStoragePoolWithStoragesCommand throw
| | Vdc Bll exception. With error message VdcBLLException:
| | org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException:
| | VDSGenericException: VDSErrorException: Failed to CreateStoragePoolVDS,
| | error = Cannot acquire host id: ('a7138327-930c-49d7-9f39-c34ee36fc7fb',
| | SanlockException(19, 'Sanlock lockspace add failure', 'No such device'))
|
| | 2013-04-25 17:55:02,952 INFO
| | [org.ovirt.engine.core.bll.storage.AddStoragePoolWithStoragesCommand]
| | (pool-3-thread-49) [783c9d00] Command
| | [id=c09e2511-3d69-41fd-9a4c-57d4a012d11b]: Compensating CHANGED_ENTITY of
| | org.ovirt.engine.core.common.businessentities.storage_pool; snapshot:
| | id=5849b030-626e-47cb-ad90-3ce782d831b3.
|
| | 2013-04-25 17:55:02,961 INFO
| | [org.ovirt.engine.core.bll.storage.AddStoragePoolWithStoragesCommand]
| | (pool-3-thread-49) [783c9d00] Command
| | [id=c09e2511-3d69-41fd-9a4c-57d4a012d11b]: Compensating NEW_ENTITY_ID of
| | org.ovirt.engine.core.common.businessentities.StoragePoolIsoMap; snapshot:
| | storagePoolId = 5849b030-626e-47cb-ad90-3ce782d831b3, storageId =
| | a7138327-930c-49d7-9f39-c34ee36fc7fb.
|
| | 2013-04-25 17:55:02,973 INFO
| | [org.ovirt.engine.core.bll.storage.AddStoragePoolWithStoragesCommand]
| | (pool-3-thread-49) [783c9d00] Command
| | [id=c09e2511-3d69-41fd-9a4c-57d4a012d11b]: Compensating CHANGED_ENTITY of
| | org.ovirt.engine.core.common.businessentities.StorageDomainStatic;
| | snapshot:
| | id=a7138327-930c-49d7-9f39-c34ee36fc7fb.
|
| | 2013-04-25 17:55:03,017 INFO
| | [org.ovirt.engine.core.bll.storage.AddStoragePoolWithStoragesCommand]
| | (pool-3-thread-49) [783c9d00] Lock freed to object EngineLock
| | [exclusiveLocks= key: 5849b030-626e-47cb-ad90-3ce782d831b3 value: POOL
|
| | , sharedLocks= ]
|
| | 2013-04-25 17:55:16,712 INFO [org.ovirt.engine.core.bll.LoginUserCommand]
| | (ajp--127.0.0.1-8702-2) Running command: LoginUserCommand internal: false.
|
| | 2013-04-25 17:55:16,758 WARN
| | [org.ovirt.engine.core.bll.GetConfigurationValueQuery]
| | (ajp--127.0.0.1-8702-2) calling GetConfigurationValueQuery
| | (ApplicationMode)
| | with null version, using default general for version
|
| | 2013-04-25 17:55:16,766 WARN
| | [org.ovirt.engine.core.bll.GetConfigurationValueQuery]
| | (ajp--127.0.0.1-8702-2) calling GetConfigurationValueQuery (VdcVersion)
| | with
| | null version, using default general for version
|
| | 2013-04-25 17:56:16,711 INFO [org.ovirt.engine.core.bll.LoginUserCommand]
| | (ajp--127.0.0.1-8702-8) Running command: LoginUserCommand internal: false.
|
| | 2013-04-25 17:56:16,757 WARN
| | [org.ovirt.engine.core.bll.GetConfigurationValueQuery]
| | (ajp--127.0.0.1-8702-8) calling GetConfigurationValueQuery
| | (ApplicationMode)
| | with null version, using default general for version
|
| | 2013-04-25 17:56:16,765 WARN
| | [org.ovirt.engine.core.bll.GetConfigurationValueQuery]
| | (ajp--127.0.0.1-8702-8) calling GetConfigurationValueQuery (VdcVersion)
| | with
| | null version, using default general for version
|
| | BTW, not sure if this is related, during New Domain, the Advanced
| | Parameters
| | has to set to "Auto Negotiation" for NFS version otherwise the creation
| | would fail (I saw similar behavior in RHEV 3.1).
|
| | Thanks in advance for any input!
|
| | Sherry
|
| | --
|
| | Sherry Yu, RHCE, RHCVA
|
| | Principal Enterprise Architect
|
| | Global Partner Enablement
|
| | Red Hat, Inc (www.redhat.com)
|
| | Mobile: 1-408-832-2160
|
| | _______________________________________________
|
| | Users mailing list
|
| | Users at ovirt.org
|
| | http://lists.ovirt.org/mailman/listinfo/users
|
--
Sherry Yu, RHCE, RHCVA
Principal Enterprise Architect
Global Partner Enablement
Red Hat, Inc (www.redhat.com)
Mobile: 1-408-832-2160
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ovirt.org/pipermail/users/attachments/20130429/d20ef438/attachment-0001.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: Screen shot 2013-04-25 at 5.10.07 PM.png
Type: image/png
Size: 43857 bytes
Desc: not available
URL: <http://lists.ovirt.org/pipermail/users/attachments/20130429/d20ef438/attachment-0001.png>
More information about the Users
mailing list