Wind River Support Network

Description

Problem Description
======================
[selinux] Command CreateStoragePoolVDS execution failed due to 'sanlock lockspace add failure' while selinux in engforcing mode


Expected Behavior
======================
it works well

Observed Behavior
======================
while selinux in permission mode, it works well.


Logs
======================
engine.log at ovirt-engine side.
----------------------------------
2013-10-11 03:31:54,824 WARN  [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-3-thread-49) [635b4860] Weird return value: StatusForXmlRpc [mCode=661, mMessage=Cannot acquire host i
d: ('da39a06f-76b9-4672-a184-c8b4a8dddc09', SanlockException(-203, 'Sanlock lockspace add failure', 'Sanlock exception'))]
2013-10-11 03:31:54,824 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-3-thread-49) [635b4860] Failed in CreateStoragePoolVDS method
2013-10-11 03:31:54,825 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-3-thread-49) [635b4860] Error code unexpected and error message VDSGenericException: VDSErrorException
: Failed to CreateStoragePoolVDS, error = Cannot acquire host id: ('da39a06f-76b9-4672-a184-c8b4a8dddc09', SanlockException(-203, 'Sanlock lockspace add failure', 'Sanlock exception'))
2013-10-11 03:31:54,825 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-3-thread-49) [635b4860] Command org.ovirt.engine.core.vdsbroker.vdsbroker.CreateStoragePoolVDSCommand 
return value 
 StatusOnlyReturnForXmlRpc [mStatus=StatusForXmlRpc [mCode=661, mMessage=Cannot acquire host id: ('da39a06f-76b9-4672-a184-c8b4a8dddc09', SanlockException(-203, 'Sanlock lockspace add failure', 'Sanlo
ck exception'))]]
2013-10-11 03:31:54,826 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-3-thread-49) [635b4860] HostName = node211
2013-10-11 03:31:54,826 ERROR [org.ovirt.engine.core.vdsbroker.VDSCommandBase] (pool-3-thread-49) [635b4860] Command CreateStoragePoolVDS execution failed. Exception: VDSErrorException: VDSGenericExce
ption: VDSErrorException: Failed to CreateStoragePoolVDS, error = Cannot acquire host id: ('da39a06f-76b9-4672-a184-c8b4a8dddc09', SanlockException(-203, 'Sanlock lockspace add failure', 'Sanlock exce
ption'))
2013-10-11 03:31:54,827 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateStoragePoolVDSCommand] (pool-3-thread-49) [635b4860] FINISH, CreateStoragePoolVDSCommand, log id: 53997f8b
2013-10-11 03:31:54,828 ERROR [org.ovirt.engine.core.bll.storage.AddStoragePoolWithStoragesCommand] (pool-3-thread-49) [635b4860] Command org.ovirt.engine.core.bll.storage.AddStoragePoolWithStoragesCo
mmand 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: ('da39a06f-76b9-4672-a184-c8b4a8dddc09', SanlockException(-203, 'Sanlock lockspace add failure', 'Sanlock exception'))


vdsm.log at ovirt-node side.
---------------------------------
Thread-64::ERROR::2013-10-11 03:15:23,429::task::833::TaskManager.Task::(_setError) Task=`0568be07-4fe0-41d4-bd5e-47440d84a1ed`::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 892, in createStoragePool
    masterVersion, safeLease)
  File "/usr/share/vdsm/storage/sp.py", line 568, in create
    self._acquireTemporaryClusterLock(msdUUID, safeLease)
  File "/usr/share/vdsm/storage/sp.py", line 509, in _acquireTemporaryClusterLock
    msd.acquireHostId(self.id)
  File "/usr/share/vdsm/storage/sd.py", line 430, in acquireHostId
    self._clusterLock.acquireHostId(hostId, async)
  File "/usr/share/vdsm/storage/safelease.py", line 175, in acquireHostId
    raise se.AcquireHostIdFailure(self._sdUUID, e)
AcquireHostIdFailure: Cannot acquire host id: ('da39a06f-76b9-4672-a184-c8b4a8dddc09', SanlockException(-203, 'Sanlock lockspace add failure', 'Sanlock exception'))
Thread-64::DEBUG::2013-10-11 03:15:23,434::task::852::TaskManager.Task::(_run) Task=`0568be07-4fe0-41d4-bd5e-47440d84a1ed`::Task._run: 0568be07-4fe0-41d4-bd5e-47440d84a1ed (None, '5849b030-626e-47cb-ad90-3ce782d831b3', 'Default', 'da39a06f-76b9-4672-a184-c8b4a8dddc09', ['da39a06f-76b9-4672-a184-c8b4a8dddc09'], 1, None, 5, 60, 10, 3) {} failed - stopping task
Thread-64::DEBUG::2013-10-11 03:15:23,435::task::1177::TaskManager.Task::(stop) Task=`0568be07-4fe0-41d4-bd5e-47440d84a1ed`::stopping in state preparing (force False)
Thread-64::DEBUG::2013-10-11 03:15:23,435::task::957::TaskManager.Task::(_decref) Task=`0568be07-4fe0-41d4-bd5e-47440d84a1ed`::ref 1 aborting True
Thread-64::INFO::2013-10-11 03:15:23,435::task::1134::TaskManager.Task::(prepare) Task=`0568be07-4fe0-41d4-bd5e-47440d84a1ed`::aborting: Task is aborted: 'Cannot acquire host id' - code 661
Thread-64::DEBUG::2013-10-11 03:15:23,435::task::1139::TaskManager.Task::(prepare) Task=`0568be07-4fe0-41d4-bd5e-47440d84a1ed`::Prepare: aborted: Cannot acquire host id
Thread-64::DEBUG::2013-10-11 03:15:23,435::task::957::TaskManager.Task::(_decref) Task=`0568be07-4fe0-41d4-bd5e-47440d84a1ed`::ref 0 aborting True
Thread-64::DEBUG::2013-10-11 03:15:23,436::task::892::TaskManager.Task::(_doAbort) Task=`0568be07-4fe0-41d4-bd5e-47440d84a1ed`::Task._doAbort: force False
Thread-64::DEBUG::2013-10-11 03:15:23,436::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-64::DEBUG::2013-10-11 03:15:23,436::task::568::TaskManager.Task::(_updateState) Task=`0568be07-4fe0-41d4-bd5e-47440d84a1ed`::moving from state preparing -> state aborting
Thread-64::DEBUG::2013-10-11 03:15:23,436::task::523::TaskManager.Task::(__state_aborting) Task=`0568be07-4fe0-41d4-bd5e-47440d84a1ed`::_aborting: recover policy none
Thread-64::DEBUG::2013-10-11 03:15:23,436::task::568::TaskManager.Task::(_updateState) Task=`0568be07-4fe0-41d4-bd5e-47440d84a1ed`::moving from state aborting -> state failed
Thread-64::DEBUG::2013-10-11 03:15:23,436::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.da39a06f-76b9-4672-a184-c8b4a8dddc09': < ResourceRef 'Storage.da39a06f-76b9-4672-a184-c8b4a8dddc09', isValid: 'True' obj: 'None'>, 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3': < ResourceRef 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3', isValid: 'True' obj: 'None'>}
Thread-64::DEBUG::2013-10-11 03:15:23,437::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-64::DEBUG::2013-10-11 03:15:23,437::resourceManager::557::ResourceManager::(releaseResource) Trying to release resource 'Storage.da39a06f-76b9-4672-a184-c8b4a8dddc09'
Thread-64::DEBUG::2013-10-11 03:15:23,437::resourceManager::573::ResourceManager::(releaseResource) Released resource 'Storage.da39a06f-76b9-4672-a184-c8b4a8dddc09' (0 active users)
Thread-64::DEBUG::2013-10-11 03:15:23,437::resourceManager::578::ResourceManager::(releaseResource) Resource 'Storage.da39a06f-76b9-4672-a184-c8b4a8dddc09' is free, finding out if anyone is waiting for it.
Thread-64::DEBUG::2013-10-11 03:15:23,438::resourceManager::585::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.da39a06f-76b9-4672-a184-c8b4a8dddc09', Clearing records.
Thread-64::DEBUG::2013-10-11 03:15:23,438::resourceManager::557::ResourceManager::(releaseResource) Trying to release resource 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'
Thread-64::DEBUG::2013-10-11 03:15:23,438::resourceManager::573::ResourceManager::(releaseResource) Released resource 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3' (0 active users)
Thread-64::DEBUG::2013-10-11 03:15:23,438::resourceManager::578::ResourceManager::(releaseResource) Resource 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3' is free, finding out if anyone is waiting for it.
Thread-64::DEBUG::2013-10-11 03:15:23,439::resourceManager::585::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3', Clearing records.
Thread-64::ERROR::2013-10-11 03:15:23,439::dispatcher::67::Storage.Dispatcher.Protect::(run) {'status': {'message': "Cannot acquire host id: ('da39a06f-76b9-4672-a184-c8b4a8dddc09', SanlockException(-203, 'Sanlock lockspace add failure', 'Sanlock exception'))", 'code': 661}}

Steps to Reproduce

1) /lpg-build/cdc/fast_prod/wrlinuxovp501/dvd_install/lv27_13sp/wrlinux-5/wrlinux/configure --enable-jobs=24 --enable-parallel-pkgbuilds=24 --enable-kernel=preempt-rt --enable-addons=wr-ovp --enable-rootfs=ovp-ovirt-node --enable-board=intel_xeon_core --with-rcpl-version=0008
2) deploy images and startup with selinux.
3) makes this node up on ovirt-engine
4) create storage domain on default data-center nfs type.

Check the behaving and vdsm.log engine.log ..