<html><body><div style="font-family: times new roman, new york, times, serif; font-size: 10pt; color: #000000"><div>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!</div><div><br></div><div><p>[root@sbhost-58 vdsm]# df -k</p><p>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</p></div><div><p>[root@sbhost-58 dom_md]# pwd<br>/rhev/data-center/mnt/storage2.phx.salab.redhat.com:_data_sap_ovirt-domain/a7138327-930c-49d7-9f39-c34ee36fc7fb/dom_md</p></div><div><p>[root@sbhost-58 dom_md]# ls -la<br>total 2060<br>drwxr-xr-x. 2 vdsm kvm 4096 Apr 25 20:35 .<br>drwxr-xr-x. 4 vdsm kvm 4096 Apr 25 20:35 ..<br>-rw-rw----. 1 vdsm kvm 1048576 Apr 25 20:35 ids<br>-rw-rw----. 1 vdsm kvm 0 Apr 25 20:35 inbox<br>-rw-rw----. 1 vdsm kvm 2097152 Apr 25 20:35 leases<br>-rw-r--r--. 1 vdsm kvm 319 Apr 25 20:35 metadata<br>-rw-rw----. 1 vdsm kvm 0 Apr 25 20:35 outbox</p><p>vdsm.log:</p></div><div><p>Thread-186874::DEBUG::2013-04-29 12:16:05,229::BindingXMLRPC::161::vds::(wrapper) [10.3.76.215]<br>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<br>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)<br>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'}]}<br>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'}]}<br>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<br>Thread-186874::DEBUG::2013-04-29 12:16:05,231::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}<br>Thread-186874::DEBUG::2013-04-29 12:16:05,231::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>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<br>Thread-186875::DEBUG::2013-04-29 12:16:05,240::BindingXMLRPC::161::vds::(wrapper) [10.3.76.215]<br>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<br>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)<br>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'}]}<br>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'}]}<br>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<br>Thread-186875::DEBUG::2013-04-29 12:16:05,248::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}<br>Thread-186875::DEBUG::2013-04-29 12:16:05,249::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>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<br>Thread-186876::DEBUG::2013-04-29 12:16:05,272::BindingXMLRPC::161::vds::(wrapper) [10.3.76.215]<br>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<br>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)<br>Thread-186876::INFO::2013-04-29 12:16:05,273::fileSD::302::Storage.StorageDomain::(validate) sdUUID=a7138327-930c-49d7-9f39-c34ee36fc7fb<br>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']<br>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__'<br>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'<br>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)<br>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<br>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)<br>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<br>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__'<br>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'<br>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)<br>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<br>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)<br>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<br>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}<br>Thread-186876::INFO::2013-04-29 12:16:05,297::fileSD::302::Storage.StorageDomain::(validate) sdUUID=a7138327-930c-49d7-9f39-c34ee36fc7fb<br>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']<br>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']<br>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<br>Thread-186876::DEBUG::2013-04-29 12:16:05,327::persistentDict::167::Storage.PersistentDict::(transaction) Starting transaction<br>Thread-186876::DEBUG::2013-04-29 12:16:05,327::persistentDict::175::Storage.PersistentDict::(transaction) Finished transaction<br>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)<br>Thread-186876::ERROR::2013-04-29 12:16:06,329::task::833::TaskManager.Task::(_setError) Task=`c62d6d31-4888-40e2-857d-aded3936f6fe`::Unexpected error<br>Traceback (most recent call last):<br> File "/usr/share/vdsm/storage/task.py", line 840, in _run<br> return fn(*args, **kargs)<br> File "/usr/share/vdsm/logUtils.py", line 42, in wrapper<br> res = f(*args, **kwargs)<br> File "/usr/share/vdsm/storage/hsm.py", line 895, in createStoragePool<br> masterVersion, leaseParams)<br> File "/usr/share/vdsm/storage/sp.py", line 567, in create<br> self._acquireTemporaryClusterLock(msdUUID, leaseParams)<br> File "/usr/share/vdsm/storage/sp.py", line 509, in _acquireTemporaryClusterLock<br> msd.acquireHostId(self.id)<br> File "/usr/share/vdsm/storage/sd.py", line 436, in acquireHostId<br> self._clusterLock.acquireHostId(hostId, async)<br> File "/usr/share/vdsm/storage/clusterlock.py", line 187, in acquireHostId<br> raise se.AcquireHostIdFailure(self._sdUUID, e)<br>AcquireHostIdFailure: Cannot acquire host id: ('a7138327-930c-49d7-9f39-c34ee36fc7fb', SanlockException(19, 'Sanlock lockspace add failure', 'No such device'))<br>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<br>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)<br>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<br>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<br>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<br>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<br>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<br>Thread-186876::DEBUG::2013-04-29 12:16:06,332::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>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<br>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<br>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<br>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'>}<br>Thread-186876::DEBUG::2013-04-29 12:16:06,333::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>Thread-186876::DEBUG::2013-04-29 12:16:06,333::resourceManager::557::ResourceManager::(releaseResource) Trying to release resource 'Storage.a7138327-930c-49d7-9f39-c34ee36fc7fb'<br>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)<br>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.<br>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.<br>Thread-186876::DEBUG::2013-04-29 12:16:06,335::resourceManager::557::ResourceManager::(releaseResource) Trying to release resource 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'<br>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)<br>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.<br>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.<br>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}}<br>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<br>Thread-186878::INFO::2013-04-29 12:16:07,705::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None)<br>Thread-186878::INFO::2013-04-29 12:16:07,705::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}<br>Thread-186878::DEBUG::2013-04-29 12:16:07,705::task::1151::TaskManager.Task::(prepare) Task=`54200799-1659-4e8a-99d2-4a82a940468a`::finished: {}<br>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<br>Thread-186878::DEBUG::2013-04-29 12:16:07,705::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}<br>Thread-186878::DEBUG::2013-04-29 12:16:07,705::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>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<br>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<br>Thread-186884::INFO::2013-04-29 12:16:17,875::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None)<br>Thread-186884::INFO::2013-04-29 12:16:17,875::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}<br>Thread-186884::DEBUG::2013-04-29 12:16:17,875::task::1151::TaskManager.Task::(prepare) Task=`e4a57bc0-1b03-4048-baef-fc8862f332cd`::finished: {}<br>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<br>Thread-186884::DEBUG::2013-04-29 12:16:17,876::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}<br>Thread-186884::DEBUG::2013-04-29 12:16:17,876::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>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<br>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<br>Thread-186890::INFO::2013-04-29 12:16:28,124::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None)<br>Thread-186890::INFO::2013-04-29 12:16:28,124::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}<br>Thread-186890::DEBUG::2013-04-29 12:16:28,124::task::1151::TaskManager.Task::(prepare) Task=`9619cb33-4f18-4372-a619-b8cc6a1a82a8`::finished: {}<br>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<br>Thread-186890::DEBUG::2013-04-29 12:16:28,125::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}<br>Thread-186890::DEBUG::2013-04-29 12:16:28,125::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>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<br>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<br>Thread-186896::INFO::2013-04-29 12:16:38,520::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None)<br>Thread-186896::INFO::2013-04-29 12:16:38,520::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}<br>Thread-186896::DEBUG::2013-04-29 12:16:38,520::task::1151::TaskManager.Task::(prepare) Task=`0885f499-5f08-4e30-bc5e-a8fad600c67f`::finished: {}<br>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<br>Thread-186896::DEBUG::2013-04-29 12:16:38,520::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}<br>Thread-186896::DEBUG::2013-04-29 12:16:38,520::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>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<br>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<br>Thread-186902::INFO::2013-04-29 12:16:48,642::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None)<br>Thread-186902::INFO::2013-04-29 12:16:48,642::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}<br>Thread-186902::DEBUG::2013-04-29 12:16:48,642::task::1151::TaskManager.Task::(prepare) Task=`d7ffd21b-5b75-4b6b-b2f2-2b7fb02cd7be`::finished: {}<br>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<br>Thread-186902::DEBUG::2013-04-29 12:16:48,642::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}<br>Thread-186902::DEBUG::2013-04-29 12:16:48,642::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>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<br>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<br>Thread-186908::INFO::2013-04-29 12:16:58,841::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None)<br>Thread-186908::INFO::2013-04-29 12:16:58,841::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}<br>Thread-186908::DEBUG::2013-04-29 12:16:58,841::task::1151::TaskManager.Task::(prepare) Task=`5bd18ef7-5152-40c6-9d86-416ab53b6c37`::finished: {}<br>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<br>Thread-186908::DEBUG::2013-04-29 12:16:58,842::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}<br>Thread-186908::DEBUG::2013-04-29 12:16:58,842::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>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</p><p><br></p></div><div><br></div><hr id="zwchr"><blockquote style="border-left:2px solid #1010FF;margin-left:5px;padding-left:5px;color:#000;font-weight:normal;font-style:normal;text-decoration:none;font-family:Helvetica,Arial,sans-serif;font-size:12pt;" data-mce-style="border-left: 2px solid #1010FF; margin-left: 5px; padding-left: 5px; color: #000; font-weight: normal; font-style: normal; text-decoration: none; font-family: Helvetica,Arial,sans-serif; font-size: 12pt;"><div style="font-family: times new roman, new york, times, serif; font-size: 12pt; color: #000000" data-mce-style="font-family: times new roman, new york, times, serif; font-size: 12pt; color: #000000;"><div>Hi Sherry,</div><div><br></div><div>Please check the that vdsm has permissions to write to the directory you're trying to create.</div><div><br></div><div>Also, if you could attach the vdsm log that would be great.</div><div><br></div><hr id="zwchr"><blockquote style="border-left:2px solid #1010FF;margin-left:5px;padding-left:5px;color:#000;font-weight:normal;font-style:normal;text-decoration:none;font-family:Helvetica,Arial,sans-serif;font-size:12pt;" data-mce-style="border-left: 2px solid #1010FF; margin-left: 5px; padding-left: 5px; color: #000; font-weight: normal; font-style: normal; text-decoration: none; font-family: Helvetica,Arial,sans-serif; font-size: 12pt;"><b>From: </b>"Sherry Yu" <syu@redhat.com><br><b>To: </b>users@ovirt.org<br><b>Sent: </b>Friday, April 26, 2013 4:04:21 AM<br><b>Subject: </b>[Users] Error Attaching NFS Data Domain to Data Center - oVirt 3.3<br><div><br></div><div style="font-family: times new roman, new york, times, serif; font-size: 10pt; color: #000000" data-mce-style="font-family: times new roman, new york, times, serif; font-size: 10pt; color: #000000;"><div><p>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</p><div><p>/var/log/sanlock.log</p><p>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<br>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<br>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<br>2013-04-25 20:45:26-0400 3711 [941]: s8 add_lockspace fail result -19</p></div><div>/var/log/ovirt-engine/engine.log</div><div><p><span style="font-size: small; " data-mce-style="font-size: small;">2013-04-25 17:55:00,002 INFO [org.ovirt.engine.core.bll.AutoRecoveryManager] (DefaultQuartzScheduler_Worker-2) Autorecovering 0 hosts</span><br><span style="font-size: small; " data-mce-style="font-size: small;">2013-04-25 17:55:00,008 INFO [org.ovirt.engine.core.bll.AutoRecoveryManager] (DefaultQuartzScheduler_Worker-2) Autorecovering 0 storage domains</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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</span><br><span style="font-size: small; " data-mce-style="font-size: small;">, sharedLocks= ]</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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'))]</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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'))]</span><br><span style="font-size: small; " data-mce-style="font-size: small;">2013-04-25 17:55:02,912 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-3-thread-49) [783c9d00] Failed in CreateStoragePoolVDS method</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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'))</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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 </span><br><span style="font-size: small; " data-mce-style="font-size: small;"> StatusOnlyReturnForXmlRpc [mStatus=StatusForXmlRpc [mCode=661, mMessage=Cannot acquire host id: ('a7138327-930c-49d7-9f39-c34ee36fc7fb', SanlockException(19, 'Sanlock lockspace add failure', 'No such device'))]]</span><br><span style="font-size: small; " data-mce-style="font-size: small;">2013-04-25 17:55:02,924 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-3-thread-49) [783c9d00] HostName = sbhost-58</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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'))</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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'))</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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.</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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.</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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.</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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</span><br><span style="font-size: small; " data-mce-style="font-size: small;">, sharedLocks= ]</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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.</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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</span></p><p><span style="font-size: small; " data-mce-style="font-size: small;">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.</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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</span><br><span style="font-size: small; " data-mce-style="font-size: small;">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</span></p></div><p><span style="font-size: small; " data-mce-style="font-size: small;"><strong>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).</strong></span></p><p><img src="cid:eefbdae6b8a4a0d8edab47ddd50834b809179d28@zimbra" data-mce-src="cid:eefbdae6b8a4a0d8edab47ddd50834b809179d28@zimbra"></p><p>Thanks in advance for any input!</p><p>Sherry</p></div><div><div>-- </div><div><span></span>Sherry Yu, RHCE, RHCVA<br>Principal Enterprise Architect<br>Global Partner Enablement<br>Red Hat, Inc (www.redhat.com)<br>Mobile: 1-408-832-2160</div></div></div><br>_______________________________________________<br>Users mailing list<br>Users@ovirt.org<br>http://lists.ovirt.org/mailman/listinfo/users<br></blockquote><div><br></div></div></blockquote><div><br><br></div><div><br></div><div>-- <br></div><div><span name="x"></span>Sherry Yu, RHCE, RHCVA<br>Principal Enterprise Architect<br>Global Partner Enablement<br>Red Hat, Inc (www.redhat.com)<br>Mobile: 1-408-832-2160<br><span name="x"></span><br></div></div></body></html>