[Users] Ovirt 3.3.2 Cannot attach POSIX (gluster) storage domain
Nir Soffer
nsoffer at redhat.com
Tue Feb 4 20:26:07 UTC 2014
----- Original Message -----
> From: "Steve Dainard" <sdainard at miovision.com>
> To: "Elad Ben Aharon" <ebenahar at redhat.com>
> Cc: "Nir Soffer" <nsoffer at redhat.com>, "users" <users at ovirt.org>, "Aharon Canan" <acanan at redhat.com>
> Sent: Tuesday, February 4, 2014 10:14:10 PM
> Subject: Re: [Users] Ovirt 3.3.2 Cannot attach POSIX (gluster) storage domain
>
> I should be able to provide any logs required, I've reverted to my NFS
> storage domain but can move a host over to POSIX whenever necessary.
Hi Steve,
Can you reproduce this issue or it happens only once?
If you can reproduce it, can you send vdsm and engine logs that document
how the storage domain was created what happened before failure?
Thanks,
Nir
>
> *Steve Dainard *
> IT Infrastructure Manager
> Miovision <http://miovision.com/> | *Rethink Traffic*
> 519-513-2407 ex.250
> 877-646-8476 (toll-free)
>
> *Blog <http://miovision.com/blog> | **LinkedIn
> <https://www.linkedin.com/company/miovision-technologies> | Twitter
> <https://twitter.com/miovision> | Facebook
> <https://www.facebook.com/miovision>*
> ------------------------------
> Miovision Technologies Inc. | 148 Manitou Drive, Suite 101, Kitchener, ON,
> Canada | N2C 1L3
> This e-mail may contain information that is privileged or confidential. If
> you are not the intended recipient, please delete the e-mail and any
> attachments and notify us immediately.
>
>
> On Tue, Feb 4, 2014 at 10:20 AM, Elad Ben Aharon <ebenahar at redhat.com>wrote:
>
> > Nir,
> > Can you take a look? the user gets the same Sanlock exception as reported
> > here: https://bugzilla.redhat.com/show_bug.cgi?id=1046430
> >
> > ----- Original Message -----
> > From: "Steve Dainard" <sdainard at miovision.com>
> > To: "users" <users at ovirt.org>
> > Sent: Tuesday, February 4, 2014 5:09:43 PM
> > Subject: [Users] Ovirt 3.3.2 Cannot attach POSIX (gluster) storage domain
> >
> > I can successfully create a POSIX storage domain backed by gluster, but at
> > the end of creation I get an error message "failed to acquire host id".
> >
> > Note that I have successfully created/activated NFS DC/SD on the same
> > ovirt/hosts.
> >
> > I have some logs when I tried to attach to the DC after failure:
> >
> > engine.log
> >
> > 2014-02-04 09:54:04,324 INFO
> > [org.ovirt.engine.core.bll.storage.AddStoragePoolWithStoragesCommand]
> > (ajp--127.0.0.1-8702-3) [1dd40406] Lock Acquired to object EngineLock [ex
> > clusiveLocks= key: 8c4e8898-c91a-4d49-98e8-b6467791a9cc value: POOL
> > , sharedLocks= ]
> > 2014-02-04 09:54:04,473 INFO
> > [org.ovirt.engine.core.bll.storage.AddStoragePoolWithStoragesCommand]
> > (pool-6-thread-42) [1dd40406] Running command: AddStoragePoolWithStorages
> > Command internal: false. Entities affected : ID:
> > 8c4e8898-c91a-4d49-98e8-b6467791a9cc Type: StoragePool
> > 2014-02-04 09:54:04,673 INFO
> > [org.ovirt.engine.core.bll.storage.ConnectStorageToVdsCommand]
> > (pool-6-thread-42) [3f86c31b] Running command: ConnectStorageToVdsCommand
> > intern
> > al: true. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa
> > Type: System
> > 2014-02-04 09:54:04,682 INFO
> > [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand]
> > (pool-6-thread-42) [3f86c31b] START, ConnectStorageServerVDSCommand(
> > HostName = ovirt001, HostId = 48f13d47-8346-4ff6-81ca-4f4324069db3,
> > storagePoolId = 00000000-0000-0000-0000-000000000000, storageType =
> > POSIXFS, connectionList = [{ id: 87f9
> > ff74-93c4-4fe5-9a56-ed5338290af9, connection: 10.0.10.3:/rep2, iqn: null,
> > vfsType: glusterfs, mountOptions: null, nfsVersion: null, nfsRetrans: null,
> > nfsTimeo: null };]), lo
> > g id: 332ff091
> > 2014-02-04 09:54:05,089 INFO
> > [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand]
> > (pool-6-thread-42) [3f86c31b] FINISH, ConnectStorageServerVDSCommand
> > , return: {87f9ff74-93c4-4fe5-9a56-ed5338290af9=0}, log id: 332ff091
> > 2014-02-04 09:54:05,093 INFO
> > [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateStoragePoolVDSCommand]
> > (pool-6-thread-42) [3f86c31b] START, CreateStoragePoolVDSCommand(HostNa
> > me = ovirt001, HostId = 48f13d47-8346-4ff6-81ca-4f4324069db3,
> > storagePoolId=8c4e8898-c91a-4d49-98e8-b6467791a9cc, storageType=POSIXFS,
> > storagePoolName=IT, masterDomainId=471
> > 487ed-2946-4dfc-8ec3-96546006be12,
> > domainsIdList=[471487ed-2946-4dfc-8ec3-96546006be12], masterVersion=3), log
> > id: 1be84579
> > 2014-02-04 09:54:08,833 ERROR
> > [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateStorag
> > ePoolVDSCommand] (pool-6-thread-42) [3f86c31b] Failed in
> > CreateStoragePoolVDS method
> > 2014-02-04 09:54:08,834 ERROR
> > [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateStoragePoolVDSCommand]
> > (pool-6-thread-42) [3f86c31b] Error code AcquireHostIdFailure and error
> > message VDSGenericException: VDSErrorException: Failed to
> > CreateStoragePoolVDS, error = Cannot acquire host id:
> > ('471487ed-2946-4dfc-8ec3-96546006be12', SanlockException(22, 'Sanlock
> > lockspace add failure', 'Invalid argument'))
> > 2014-02-04 09:54:08,835 INFO
> > [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateStoragePoolVDSCommand]
> > (pool-6-thread-42) [3f86c31b] Command
> > org.ovirt.engine.core.vdsbroker.vdsbroker.CreateStoragePoolVDSCommand
> > return value
> > StatusOnlyReturnForXmlRpc [mStatus=StatusForXmlRpc [mCode=661,
> > mMessage=Cannot acquire host id: ('471487ed-2946-4dfc-8ec3-96546006be12',
> > SanlockException(22, 'Sanlock lockspace add failure', 'Invalid
> > argument'))]]
> > 2014-02-04 09:54:08,836 INFO
> > [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateStoragePoolVDSCommand]
> > (pool-6-thread-42) [3f86c31b] HostName = ovirt001
> > 2014-02-04 09:54:08,840 ERROR
> > [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateStoragePoolVDSCommand]
> > (pool-6-thread-42) [3f86c31b] Command CreateStoragePoolVDS execution
> > failed. Exception: VDSErrorException: VDSGenericException:
> > VDSErrorException: Failed to CreateStoragePoolVDS, error = Cannot acquire
> > host id: ('471487ed-2946-4dfc-8ec3-96546006be12', SanlockException(22,
> > 'Sanlock lockspace add failure', 'Invalid argument'))
> > 2014-02-04 09:54:08,840 INFO
> > [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateStoragePoolVDSCommand]
> > (pool-6-thread-42) [3f86c31b] FINISH, CreateStoragePoolVDSCommand, log id:
> > 1be84579
> > 2014-02-04 09:54:08,841 ERROR
> > [org.ovirt.engine.core.bll.storage.AddStoragePoolWithStoragesCommand]
> > (pool-6-thread-42) [3f86c31b] 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: ('471487ed-2946-4dfc-8ec3-96546006be12',
> > SanlockException(22, 'Sanlock lockspace add failure', 'Invalid argument'))
> > (Failed with error AcquireHostIdFailure and code 661)
> > 2014-02-04 09:54:08,867 INFO
> > [org.ovirt.engine.core.bll.storage.AddStoragePoolWithStoragesCommand]
> > (pool-6-thread-42) [3f86c31b] Command
> > [id=373987cb-b54d-4174-b4a9-195be631f0d7]: Compensating CHANGED_ENTITY of
> > org.ovirt.engine.core.common.businessentities.StoragePool; snapshot:
> > id=8c4e8898-c91a-4d49-98e8-b6467791a9cc.
> > 2014-02-04 09:54:08,871 INFO
> > [org.ovirt.engine.core.bll.storage.AddStoragePoolWithStoragesCommand]
> > (pool-6-thread-42) [3f86c31b] Command
> > [id=373987cb-b54d-4174-b4a9-195be631f0d7]: Compensating NEW_ENTITY_ID of
> > org.ovirt.engine.core.common.businessentities.StoragePoolIsoMap; snapshot:
> > storagePoolId = 8c4e8898-c91a-4d49-98e8-b6467791a9cc, storageId =
> > 471487ed-2946-4dfc-8ec3-96546006be12.
> > 2014-02-04 09:54:08,879 INFO
> > [org.ovirt.engine.core.bll.storage.AddStoragePoolWithStoragesCommand]
> > (pool-6-thread-42) [3f86c31b] Command
> > [id=373987cb-b54d-4174-b4a9-195be631f0d7]: Compensating CHANGED_ENTITY of
> > org.ovirt.engine.core.common.businessentities.StorageDomainStatic;
> > snapshot: id=471487ed-2946-4dfc-8ec3-96546006be12.
> > 2014-02-04 09:54:08,951 INFO
> > [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> > (pool-6-thread-42) [3f86c31b] Correlation ID: 1dd40406, Job ID:
> > 07003dff-9e0e-42ae-8f88-6b055b45f797, Call Stack: null, Custom Event ID:
> > -1, Message: Failed to attach Storage Domains to Data Center IT. (User:
> > admin at internal)
> > 2014-02-04 09:54:08,975 INFO
> > [org.ovirt.engine.core.bll.storage.AddStoragePoolWithStoragesCommand]
> > (pool-6-thread-42) [3f86c31b] Lock freed to object EngineLock
> > [exclusiveLocks= key: 8c4e8898-c91a-4d49-98e8-b6467791a9cc value: POOL
> > , sharedLocks= ]
> >
> > vdsm.log
> >
> > Thread-30::DEBUG::2014-02-04
> > 09:54:04,692::BindingXMLRPC::167::vds::(wrapper) client [10.0.10.2] flowID
> > [3f86c31b]
> > Thread-30::DEBUG::2014-02-04
> > 09:54:04,692::task::579::TaskManager.Task::(_updateState)
> > Task=`218dcde9-bbc7-4d5a-ad53-0bab556c6261`::moving from state init ->
> > state preparing
> > Thread-30::INFO::2014-02-04
> > 09:54:04,693::logUtils::44::dispatcher::(wrapper) Run and protect:
> > connectStorageServer(domType=6,
> > spUUID='00000000-0000-0000-0000-000000000000', conList=[{'port': '',
> > 'connection': '10.0.10.3:/rep2', 'iqn': '', 'portal': '', 'user': '',
> > 'vfs_type': 'glusterfs', 'password': '******', 'id':
> > '87f9ff74-93c4-4fe5-9a56-ed5338290af9'}], options=None)
> > Thread-30::DEBUG::2014-02-04
> > 09:54:04,698::mount::226::Storage.Misc.excCmd::(_runcmd) '/usr/bin/sudo -n
> > /bin/mount -t glusterfs 10.0.10.3:/rep2
> > /rhev/data-center/mnt/10.0.10.3:_rep2'
> > (cwd None)
> > Thread-30::DEBUG::2014-02-04
> > 09:54:05,067::hsm::2315::Storage.HSM::(__prefetchDomains) posix local path:
> > /rhev/data-center/mnt/10.0.10.3:_rep2
> > Thread-30::DEBUG::2014-02-04
> > 09:54:05,078::hsm::2333::Storage.HSM::(__prefetchDomains) Found SD uuids:
> > ('471487ed-2946-4dfc-8ec3-96546006be12',)
> > Thread-30::DEBUG::2014-02-04
> > 09:54:05,078::hsm::2389::Storage.HSM::(connectStorageServer) knownSDs:
> > {471487ed-2946-4dfc-8ec3-96546006be12: storage.nfsSD.findDomain}
> > Thread-30::INFO::2014-02-04
> > 09:54:05,078::logUtils::47::dispatcher::(wrapper) Run and protect:
> > connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id':
> > '87f9ff74-93c4-4fe5-9a56-ed5338290af9'}]}
> > Thread-30::DEBUG::2014-02-04
> > 09:54:05,079::task::1168::TaskManager.Task::(prepare)
> > Task=`218dcde9-bbc7-4d5a-ad53-0bab556c6261`::finished: {'statuslist':
> > [{'status': 0, 'id': '87f9ff74-93c4-4fe5-9a56-ed5338290af9'}]}
> > Thread-30::DEBUG::2014-02-04
> > 09:54:05,079::task::579::TaskManager.Task::(_updateState)
> > Task=`218dcde9-bbc7-4d5a-ad53-0bab556c6261`::moving from state preparing ->
> > state finished
> > Thread-30::DEBUG::2014-02-04
> > 09:54:05,079::resourceManager::939::ResourceManager.Owner::(releaseAll)
> > Owner.releaseAll requests {} resources {}
> > Thread-30::DEBUG::2014-02-04
> > 09:54:05,079::resourceManager::976::ResourceManager.Owner::(cancelAll)
> > Owner.cancelAll requests {}
> > Thread-30::DEBUG::2014-02-04
> > 09:54:05,079::task::974::TaskManager.Task::(_decref)
> > Task=`218dcde9-bbc7-4d5a-ad53-0bab556c6261`::ref 0 aborting False
> > Thread-31::DEBUG::2014-02-04
> > 09:54:05,098::BindingXMLRPC::167::vds::(wrapper) client [10.0.10.2] flowID
> > [3f86c31b]
> > Thread-31::DEBUG::2014-02-04
> > 09:54:05,099::task::579::TaskManager.Task::(_updateState)
> > Task=`66924dbf-5a1c-473e-a158-d038aae38dc3`::moving from state init ->
> > state preparing
> > Thread-31::INFO::2014-02-04
> > 09:54:05,099::logUtils::44::dispatcher::(wrapper) Run and protect:
> > createStoragePool(poolType=None,
> > spUUID='8c4e8898-c91a-4d49-98e8-b6467791a9cc', poolName='IT',
> > masterDom='471487ed-2946-4dfc-8ec3-96546006be12',
> > domList=['471487ed-2946-4dfc-8ec3-96546006be12'], masterVersion=3,
> > lockPolicy=None, lockRenewalIntervalSec=5, leaseTimeSec=60,
> > ioOpTimeoutSec=10, leaseRetries=3, options=None)
> > Thread-31::DEBUG::2014-02-04
> > 09:54:05,099::misc::809::SamplingMethod::(__call__) Trying to enter
> > sampling method (storage.sdc.refreshStorage)
> > Thread-31::DEBUG::2014-02-04
> > 09:54:05,100::misc::811::SamplingMethod::(__call__) Got in to sampling
> > method
> > Thread-31::DEBUG::2014-02-04
> > 09:54:05,100::misc::809::SamplingMethod::(__call__) Trying to enter
> > sampling method (storage.iscsi.rescan)
> > Thread-31::DEBUG::2014-02-04
> > 09:54:05,100::misc::811::SamplingMethod::(__call__) Got in to sampling
> > method
> > Thread-31::DEBUG::2014-02-04
> > 09:54:05,100::iscsiadm::91::Storage.Misc.excCmd::(_runCmd) '/usr/bin/sudo
> > -n /sbin/iscsiadm -m session -R' (cwd None)
> > Thread-31::DEBUG::2014-02-04
> > 09:54:05,114::iscsiadm::91::Storage.Misc.excCmd::(_runCmd) FAILED: <err> =
> > 'iscsiadm: No session found.\n'; <rc> = 21
> > Thread-31::DEBUG::2014-02-04
> > 09:54:05,115::misc::819::SamplingMethod::(__call__) Returning last result
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,144::multipath::112::Storage.Misc.excCmd::(rescan) '/usr/bin/sudo
> > -n /sbin/multipath -r' (cwd None)
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,331::multipath::112::Storage.Misc.excCmd::(rescan) SUCCESS: <err>
> > = ''; <rc> = 0
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,332::lvm::510::OperationMutex::(_invalidateAllPvs) Operation 'lvm
> > invalidate operation' got the operation mutex
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,333::lvm::512::OperationMutex::(_invalidateAllPvs) Operation 'lvm
> > invalidate operation' released the operation mutex
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,333::lvm::521::OperationMutex::(_invalidateAllVgs) Operation 'lvm
> > invalidate operation' got the operation mutex
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,333::lvm::523::OperationMutex::(_invalidateAllVgs) Operation 'lvm
> > invalidate operation' released the operation mutex
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,333::lvm::541::OperationMutex::(_invalidateAllLvs) Operation 'lvm
> > invalidate operation' got the operation mutex
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,334::lvm::543::OperationMutex::(_invalidateAllLvs) Operation 'lvm
> > invalidate operation' released the operation mutex
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,334::misc::819::SamplingMethod::(__call__) Returning last result
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,499::fileSD::137::Storage.StorageDomain::(__init__) Reading domain
> > in path /rhev/data-center/mnt/10.0.10.3:
> > _rep2/471487ed-2946-4dfc-8ec3-96546006be12
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,605::persistentDict::192::Storage.PersistentDict::(__init__)
> > Created a persistent dict with FileMetadataRW backend
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,647::persistentDict::234::Storage.PersistentDict::(refresh) read
> > lines (FileMetadataRW)=['CLASS=Data', 'DESCRIPTION=gluster-store-rep2',
> > 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=',
> > 'LOCKRENEWALINTERVALSEC=5', 'POOL_UUID=', 'REMOTE_PATH=10.0.10.3:/rep2',
> > 'ROLE=Regular', 'SDUUID=471487ed-2946-4dfc-8ec3-96546006be12',
> > 'TYPE=POSIXFS', 'VERSION=3',
> > '_SHA_CKSUM=469191aac3fb8ef504b6a4d301b6d8be6fffece1']
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,683::fileSD::558::Storage.StorageDomain::(imageGarbageCollector)
> > Removing remnants of deleted images []
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,684::resourceManager::420::ResourceManager::(registerNamespace)
> > Registering namespace '471487ed-2946-4dfc-8ec3-96546006be12_imageNS'
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,684::resourceManager::420::ResourceManager::(registerNamespace)
> > Registering namespace '471487ed-2946-4dfc-8ec3-96546006be12_volumeNS'
> > Thread-31::INFO::2014-02-04
> > 09:54:07,684::fileSD::299::Storage.StorageDomain::(validate)
> > sdUUID=471487ed-2946-4dfc-8ec3-96546006be12
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,692::persistentDict::234::Storage.PersistentDict::(refresh) read
> > lines (FileMetadataRW)=['CLASS=Data', 'DESCRIPTION=gluster-store-rep2',
> > 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=',
> > 'LOCKRENEWALINTERVALSEC=5', 'POOL_UUID=', 'REMOTE_PATH=10.0.10.3:/rep2',
> > 'ROLE=Regular', 'SDUUID=471487ed-2946-4dfc-8ec3-96546006be12',
> > 'TYPE=POSIXFS', 'VERSION=3',
> > '_SHA_CKSUM=469191aac3fb8ef504b6a4d301b6d8be6fffece1']
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,693::resourceManager::197::ResourceManager.Request::(__init__)
> > ResName=`Storage.8c4e8898-c91a-4d49-98e8-b6467791a9cc`ReqID=`e0a3d477-b953-49d9-ab78-67695a6bc6d5`::Request
> > was made in '/usr/share/vdsm/storage/hsm.py' line '971' at
> > 'createStoragePool'
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,693::resourceManager::541::ResourceManager::(registerResource)
> > Trying to register resource 'Storage.8c4e8898-c91a-4d49-98e8-b6467791a9cc'
> > for lock type 'exclusive'
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,693::resourceManager::600::ResourceManager::(registerResource)
> > Resource 'Storage.8c4e8898-c91a-4d49-98e8-b6467791a9cc' is free. Now
> > locking as 'exclusive' (1 active user)
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,693::resourceManager::237::ResourceManager.Request::(grant)
> > ResName=`Storage.8c4e8898-c91a-4d49-98e8-b6467791a9cc`ReqID=`e0a3d477-b953-49d9-ab78-67695a6bc6d5`::Granted
> > request
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,694::task::811::TaskManager.Task::(resourceAcquired)
> > Task=`66924dbf-5a1c-473e-a158-d038aae38dc3`::_resourcesAcquired:
> > Storage.8c4e8898-c91a-4d49-98e8-b6467791a9cc (exclusive)
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,694::task::974::TaskManager.Task::(_decref)
> > Task=`66924dbf-5a1c-473e-a158-d038aae38dc3`::ref 1 aborting False
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,694::resourceManager::197::ResourceManager.Request::(__init__)
> > ResName=`Storage.471487ed-2946-4dfc-8ec3-96546006be12`ReqID=`bc20dd7e-d351-47c5-8ed3-78b1b11d703a`::Request
> > was made in '/usr/share/vdsm/storage/hsm.py' line '973' at
> > 'createStoragePool'
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,694::resourceManager::541::ResourceManager::(registerResource)
> > Trying to register resource 'Storage.471487ed-2946-4dfc-8ec3-96546006be12'
> > for lock type 'exclusive'
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,695::resourceManager::600::ResourceManager::(registerResource)
> > Resource 'Storage.471487ed-2946-4dfc-8ec3-96546006be12' is free. Now
> > locking as 'exclusive' (1 active user)
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,695::resourceManager::237::ResourceManager.Request::(grant)
> > ResName=`Storage.471487ed-2946-4dfc-8ec3-96546006be12`ReqID=`bc20dd7e-d351-47c5-8ed3-78b1b11d703a`::Granted
> > request
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,695::task::811::TaskManager.Task::(resourceAcquired)
> > Task=`66924dbf-5a1c-473e-a158-d038aae38dc3`::_resourcesAcquired:
> > Storage.471487ed-2946-4dfc-8ec3-96546006be12 (exclusive)
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,695::task::974::TaskManager.Task::(_decref)
> > Task=`66924dbf-5a1c-473e-a158-d038aae38dc3`::ref 1 aborting False
> > Thread-31::INFO::2014-02-04
> > 09:54:07,696::sp::593::Storage.StoragePool::(create)
> > spUUID=8c4e8898-c91a-4d49-98e8-b6467791a9cc poolName=IT
> > master_sd=471487ed-2946-4dfc-8ec3-96546006be12
> > domList=['471487ed-2946-4dfc-8ec3-96546006be12'] masterVersion=3
> > {'LEASETIMESEC': 60, 'IOOPTIMEOUTSEC': 10, 'LEASERETRIES': 3,
> > 'LOCKRENEWALINTERVALSEC': 5}
> > Thread-31::INFO::2014-02-04
> > 09:54:07,696::fileSD::299::Storage.StorageDomain::(validate)
> > sdUUID=471487ed-2946-4dfc-8ec3-96546006be12
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,703::persistentDict::234::Storage.PersistentDict::(refresh) read
> > lines (FileMetadataRW)=['CLASS=Data', 'DESCRIPTION=gluster-store-rep2',
> > 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=',
> > 'LOCKRENEWALINTERVALSEC=5', 'POOL_UUID=', 'REMOTE_PATH=10.0.10.3:/rep2',
> > 'ROLE=Regular', 'SDUUID=471487ed-2946-4dfc-8ec3-96546006be12',
> > 'TYPE=POSIXFS', 'VERSION=3',
> > '_SHA_CKSUM=469191aac3fb8ef504b6a4d301b6d8be6fffece1']
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,710::persistentDict::234::Storage.PersistentDict::(refresh) read
> > lines (FileMetadataRW)=['CLASS=Data', 'DESCRIPTION=gluster-store-rep2',
> > 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=',
> > 'LOCKRENEWALINTERVALSEC=5', 'POOL_UUID=', 'REMOTE_PATH=10.0.10.3:/rep2',
> > 'ROLE=Regular', 'SDUUID=471487ed-2946-4dfc-8ec3-96546006be12',
> > 'TYPE=POSIXFS', 'VERSION=3',
> > '_SHA_CKSUM=469191aac3fb8ef504b6a4d301b6d8be6fffece1']
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,711::persistentDict::167::Storage.PersistentDict::(transaction)
> > Starting transaction
> > Thread-31::DEBUG::2014-02-04
> > 09:54:07,711::persistentDict::175::Storage.PersistentDict::(transaction)
> > Finished transaction
> > Thread-31::INFO::2014-02-04
> > 09:54:07,711::clusterlock::174::SANLock::(acquireHostId) Acquiring host id
> > for domain 471487ed-2946-4dfc-8ec3-96546006be12 (id: 250)
> > Thread-31::ERROR::2014-02-04
> > 09:54:08,722::task::850::TaskManager.Task::(_setError)
> > Task=`66924dbf-5a1c-473e-a158-d038aae38dc3`::Unexpected error
> > Traceback (most recent call last):
> > File "/usr/share/vdsm/storage/task.py", line 857, in _run
> > return fn(*args, **kargs)
> > File "/usr/share/vdsm/logUtils.py", line 45, in wrapper
> > res = f(*args, **kwargs)
> > File "/usr/share/vdsm/storage/hsm.py", line 977, in createStoragePool
> > masterVersion, leaseParams)
> > File "/usr/share/vdsm/storage/sp.py", line 618, in create
> > self._acquireTemporaryClusterLock(msdUUID, leaseParams)
> > File "/usr/share/vdsm/storage/sp.py", line 560, in
> > _acquireTemporaryClusterLock
> > msd.acquireHostId( self.id )
> > File "/usr/share/vdsm/storage/sd.py", line 458, in acquireHostId
> > self._clusterLock.acquireHostId(hostId, async)
> > File "/usr/share/vdsm/storage/clusterlock.py", line 189, in acquireHostId
> > raise se.AcquireHostIdFailure(self._sdUUID, e)
> > AcquireHostIdFailure: Cannot acquire host id:
> > ('471487ed-2946-4dfc-8ec3-96546006be12', SanlockException(22, 'Sanlock
> > lockspace add failure', 'Invalid argument'))
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,826::task::869::TaskManager.Task::(_run)
> > Task=`66924dbf-5a1c-473e-a158-d038aae38dc3`::Task._run:
> > 66924dbf-5a1c-473e-a158-d038aae38dc3 (None,
> > '8c4e8898-c91a-4d49-98e8-b6467791a9cc', 'IT',
> > '471487ed-2946-4dfc-8ec3-96546006be12',
> > ['471487ed-2946-4dfc-8ec3-96546006be12'], 3, None, 5, 60, 10, 3) {} failed
> > - stopping task
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,826::task::1194::TaskManager.Task::(stop)
> > Task=`66924dbf-5a1c-473e-a158-d038aae38dc3`::stopping in state preparing
> > (force False)
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,826::task::974::TaskManager.Task::(_decref)
> > Task=`66924dbf-5a1c-473e-a158-d038aae38dc3`::ref 1 aborting True
> > Thread-31::INFO::2014-02-04
> > 09:54:08,826::task::1151::TaskManager.Task::(prepare)
> > Task=`66924dbf-5a1c-473e-a158-d038aae38dc3`::aborting: Task is aborted:
> > 'Cannot acquire host id' - code 661
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,826::task::1156::TaskManager.Task::(prepare)
> > Task=`66924dbf-5a1c-473e-a158-d038aae38dc3`::Prepare: aborted: Cannot
> > acquire host id
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,827::task::974::TaskManager.Task::(_decref)
> > Task=`66924dbf-5a1c-473e-a158-d038aae38dc3`::ref 0 aborting True
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,827::task::909::TaskManager.Task::(_doAbort)
> > Task=`66924dbf-5a1c-473e-a158-d038aae38dc3`::Task._doAbort: force False
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,827::resourceManager::976::ResourceManager.Owner::(cancelAll)
> > Owner.cancelAll requests {}
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,827::task::579::TaskManager.Task::(_updateState)
> > Task=`66924dbf-5a1c-473e-a158-d038aae38dc3`::moving from state preparing ->
> > state aborting
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,827::task::534::TaskManager.Task::(__state_aborting)
> > Task=`66924dbf-5a1c-473e-a158-d038aae38dc3`::_aborting: recover policy none
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,827::task::579::TaskManager.Task::(_updateState)
> > Task=`66924dbf-5a1c-473e-a158-d038aae38dc3`::moving from state aborting ->
> > state failed
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,827::resourceManager::939::ResourceManager.Owner::(releaseAll)
> > Owner.releaseAll requests {} resources
> > {'Storage.471487ed-2946-4dfc-8ec3-96546006be12': < ResourceRef
> > 'Storage.471487ed-2946-4dfc-8ec3-96546006be12', isValid: 'True' obj:
> > 'None'>, 'Storage.8c4e8898-c91a-4d49-98e8-b6467791a9cc': < ResourceRef
> > 'Storage.8c4e8898-c91a-4d49-98e8-b6467791a9cc', isValid: 'True' obj:
> > 'None'>}
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,828::resourceManager::976::ResourceManager.Owner::(cancelAll)
> > Owner.cancelAll requests {}
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,828::resourceManager::615::ResourceManager::(releaseResource)
> > Trying to release resource 'Storage.471487ed-2946-4dfc-8ec3-96546006be12'
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,828::resourceManager::634::ResourceManager::(releaseResource)
> > Released resource 'Storage.471487ed-2946-4dfc-8ec3-96546006be12' (0 active
> > users)
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,828::resourceManager::640::ResourceManager::(releaseResource)
> > Resource 'Storage.471487ed-2946-4dfc-8ec3-96546006be12' is free, finding
> > out if anyone is waiting for it.
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,828::resourceManager::648::ResourceManager::(releaseResource) No
> > one is waiting for resource 'Storage.471487ed-2946-4dfc-8ec3-96546006be12',
> > Clearing records.
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,828::resourceManager::615::ResourceManager::(releaseResource)
> > Trying to release resource 'Storage.8c4e8898-c91a-4d49-98e8-b6467791a9cc'
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,829::resourceManager::634::ResourceManager::(releaseResource)
> > Released resource 'Storage.8c4e8898-c91a-4d49-98e8-b6467791a9cc' (0 active
> > users)
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,829::resourceManager::640::ResourceManager::(releaseResource)
> > Resource 'Storage.8c4e8898-c91a-4d49-98e8-b6467791a9cc' is free, finding
> > out if anyone is waiting for it.
> > Thread-31::DEBUG::2014-02-04
> > 09:54:08,829::resourceManager::648::ResourceManager::(releaseResource) No
> > one is waiting for resource 'Storage.8c4e8898-c91a-4d49-98e8-b6467791a9cc',
> > Clearing records.
> > Thread-31::ERROR::2014-02-04
> > 09:54:08,829::dispatcher::67::Storage.Dispatcher.Protect::(run) {'status':
> > {'message': "Cannot acquire host id:
> > ('471487ed-2946-4dfc-8ec3-96546006be12', SanlockException(22, 'Sanlock
> > lockspace add failure', 'Invalid argument'))", 'code': 661}}
> >
> >
> > Storage domain metadata file:
> >
> > CLASS=Data
> > DESCRIPTION=gluster-store-rep2
> > IOOPTIMEOUTSEC=10
> > LEASERETRIES=3
> > LEASETIMESEC=60
> > LOCKPOLICY=
> > LOCKRENEWALINTERVALSEC=5
> > POOL_UUID=
> > REMOTE_PATH=10.0.10.3:/rep2
> > ROLE=Regular
> > SDUUID=471487ed-2946-4dfc-8ec3-96546006be12
> > TYPE=POSIXFS
> > VERSION=3
> > _SHA_CKSUM=469191aac3fb8ef504b6a4d301b6d8be6fffece1
> >
> >
> >
> > Steve Dainard
> > IT Infrastructure Manager
> > Miovision | Rethink Traffic
> > 519-513-2407 ex.250
> > 877-646-8476 (toll-free)
> >
> > Blog | LinkedIn | Twitter | Facebook
> > Miovision Technologies Inc. | 148 Manitou Drive, Suite 101, Kitchener, ON,
> > Canada | N2C 1L3
> > This e-mail may contain information that is privileged or confidential. If
> > you are not the intended recipient, please delete the e-mail and any
> > attachments and notify us immediately.
> >
> > _______________________________________________
> > Users mailing list
> > Users at ovirt.org
> > http://lists.ovirt.org/mailman/listinfo/users
> >
>
More information about the Users
mailing list