Bug 994463

Created attachment 783800 [details]
## Logs rhevm, vdsm, libvirt, thread dump, superVdsm

Description of problem:
Failed attached Export Storage Domain - Could not obtain lock

Version-Release number of selected component (if applicable):
RHEVM 3.3 - IS8 environment:

RHEVM:  rhevm-3.3.0-0.13.master.el6ev.noarch
VDSM:  vdsm-4.12.0-rc3.13.git06ed3cc.el6ev.x86_64
LIBVIRT:  libvirt-0.10.2-18.el6_4.9.x86_64
QEMU & KVM:  qemu-kvm-rhev-0.12.1.2-2.355.el6_4.5.x86_64
SANLOCK:  sanlock-2.6-2.el6.x86_64
PythonSDK:  rhevm-sdk-python-3.3.0.8-1.el6ev.noarch

How reproducible:
unknown

Steps to Reproduce:
 Import Preconfigured “Export / NFS” Domain

Actual results:
Get an error:
Error while executing action Attached Storage Domain: Could not obtain lock

Failed attached Export Storage Domain

Expected results:
No exception should be found
Succeed attached Export Storage Domain

Impact on user:
Failed attached Export Storage Domain

Workaround:
none

Additional info:

/var/log/ovirt-engine/engine.log

2013-08-07 12:00:15,643 ERROR [org.ovirt.engine.core.bll.storage.NFSStorageHelper] (pool-5-thread-47) The connection with details wolf.qa.lab.tlv.redhat.com:/volumes/wolf/kipi-export failed because of error code 477 and error message is: problem while trying to mount target
2013-08-07 12:00:15,646 ERROR [org.ovirt.engine.core.bll.storage.ConnectStorageToVdsCommand] (pool-5-thread-47) Transaction rolled-back for command: org.ovirt.engine.core.bll.storage.ConnectStorageToVdsCommand.
2013-08-07 12:00:15,647 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand] (ajp-/127.0.0.1:8702-2) START, AttachStorageDomainVDSCommand( storagePoolId = 9cde139a-d5be-4555-b054-c2edf95f33fd, ignoreFailoverLimit = false, storageDomainId = c82ed380-b1d9-4133-a380-e49f7d87b44e), log id: 3c9c261a
2013-08-07 12:00:15,722 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand] (ajp-/127.0.0.1:8702-2) Failed in AttachStorageDomainVDS method
2013-08-07 12:00:15,750 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand] (ajp-/127.0.0.1:8702-2) Error code AcquireLockFailure and error message IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS, error = Cannot obtain lock: "id=c82ed380-b1d9-4133-a380-e49f7d87b44e, rc=1, out=['error - lease file does not exist or is not writeable', 'usage: /usr/libexec/vdsm/spmprotect.sh COMMAND PARAMETERS', 'Commands:', '  start { sdUUID hostId renewal_interval_sec lease_path[:offset] lease_time_ms io_op_timeout_ms fail_retries }', 'Parameters:', '  sdUUID -                domain uuid', '  hostId -                host id in pool', '  renewal_interval_sec -  intervals for lease renewals attempts', '  lease_path -            path to lease file/volume', '  offset -                offset of lease within file', '  lease_time_ms -         time limit within which lease must be renewed (at least 2*renewal_interval_sec)', '  io_op_timeout_ms -      I/O operation timeout', '  fail_retries -          Maximal number of attempts to retry to renew the lease before fencing (<= lease_time_ms/renewal_interval_sec)'], err=[]"
2013-08-07 12:00:15,750 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand] (ajp-/127.0.0.1:8702-2) Command AttachStorageDomainVDS execution failed. Exception: IrsOperationFailedNoFailoverException: IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS, error = Cannot obtain lock: "id=c82ed380-b1d9-4133-a380-e49f7d87b44e, rc=1, out=['error - lease file does not exist or is not writeable', 'usage: /usr/libexec/vdsm/spmprotect.sh COMMAND PARAMETERS', 'Commands:', '  start { sdUUID hostId renewal_interval_sec lease_path[:offset] lease_time_ms io_op_timeout_ms fail_retries }', 'Parameters:', '  sdUUID -                domain uuid', '  hostId -                host id in pool', '  renewal_interval_sec -  intervals for lease renewals attempts', '  lease_path -            path to lease file/volume', '  offset -                offset of lease within file', '  lease_time_ms -         time limit within which lease must be renewed (at least 2*renewal_interval_sec)', '  io_op_timeout_ms -      I/O operation timeout', '  fail_retries -          Maximal number of attempts to retry to renew the lease before fencing (<= lease_time_ms/renewal_interval_sec)'], err=[]"
2013-08-07 12:00:15,750 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand] (ajp-/127.0.0.1:8702-2) FINISH, AttachStorageDomainVDSCommand, log id: 3c9c261a
2013-08-07 12:00:15,750 ERROR [org.ovirt.engine.core.bll.storage.AttachStorageDomainToPoolCommand] (ajp-/127.0.0.1:8702-2) Command org.ovirt.engine.core.bll.storage.AttachStorageDomainToPoolCommand throw Vdc Bll exception. With error message VdcBLLException: org.ovirt.engine.core.vdsbroker.irsbroker.IrsOperationFailedNoFailoverException: IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS, error = Cannot obtain lock: "id=c82ed380-b1d9-4133-a380-e49f7d87b44e, rc=1, out=['error - lease file does not exist or is not writeable', 'usage: /usr/libexec/vdsm/spmprotect.sh COMMAND PARAMETERS', 'Commands:', '  start { sdUUID hostId renewal_interval_sec lease_path[:offset] lease_time_ms io_op_timeout_ms fail_retries }', 'Parameters:', '  sdUUID -                domain uuid', '  hostId -                host id in pool', '  renewal_interval_sec -  intervals for lease renewals attempts', '  lease_path -            path to lease file/volume', '  offset -                offset of lease within file', '  lease_time_ms -         time limit within which lease must be renewed (at least 2*renewal_interval_sec)', '  io_op_timeout_ms -      I/O operation timeout', '  fail_retries -          Maximal number of attempts to retry to renew the lease before fencing (<= lease_time_ms/renewal_interval_sec)'], err=[]" (Failed with VDSM error AcquireLockFailure and code 651)
2013-08-07 12:00:15,752 INFO  [org.ovirt.engine.core.bll.storage.AttachStorageDomainToPoolCommand] (ajp-/127.0.0.1:8702-2) Command [id=9f2a76ed-d258-446f-bd1b-0ac1353e31a6]: Compensating NEW_ENTITY_ID of org.ovirt.engine.core.common.businessentities.StoragePoolIsoMap; snapshot: storagePoolId = 9cde139a-d5be-4555-b054-c2edf95f33fd, storageId = c82ed380-b1d9-4133-a380-e49f7d87b44e.


/var/log/vdsm/vdsm.log

Thread-166883::ERROR::2013-08-07 10:00:17,385::task::850::TaskManager.Task::(_setError) Task=`847814bb-7181-49a2-a63d-5b0e73aa3740`::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 1149, in attachStorageDomain
    pool.attachSD(sdUUID)
  File "/usr/share/vdsm/storage/securable.py", line 68, in wrapper
    return f(self, *args, **kwargs)
  File "/usr/share/vdsm/storage/sp.py", line 989, in attachSD
    dom.acquireClusterLock(self.id)
  File "/usr/share/vdsm/storage/sd.py", line 487, in acquireClusterLock
    self._clusterLock.acquire(hostID)
  File "/usr/share/vdsm/storage/clusterlock.py", line 112, in acquire
    raise se.AcquireLockFailure(self._sdUUID, rc, out, err)
AcquireLockFailure: Cannot obtain lock: "id=c82ed380-b1d9-4133-a380-e49f7d87b44e, rc=1, out=['error - lease file does not exist or is not writeable', 'usage: /usr/libexec/vdsm/s
pmprotect.sh COMMAND PARAMETERS', 'Commands:', '  start { sdUUID hostId renewal_interval_sec lease_path[:offset] lease_time_ms io_op_timeout_ms fail_retries }', 'Parameters:', '
  sdUUID -                domain uuid', '  hostId -                host id in pool', '  renewal_interval_sec -  intervals for lease renewals attempts', '  lease_path -          
  path to lease file/volume', '  offset -                offset of lease within file', '  lease_time_ms -         time limit within which lease must be renewed (at least 2*renew
al_interval_sec)', '  io_op_timeout_ms -      I/O operation timeout', '  fail_retries -          Maximal number of attempts to retry to renew the lease before fencing (<= lease_
time_ms/renewal_interval_sec)'], err=[]"

Thread-166883::DEBUG::2013-08-07 10:00:17,392::resourceManager::640::ResourceManager::(releaseResource) Resource 'Storage.9cde139a-d5be-4555-b054-c2edf95f33fd' is free, finding out if anyone is waiting for it.
Thread-166883::DEBUG::2013-08-07 10:00:17,392::resourceManager::648::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.9cde139a-d5be-4555-b054-c2edf95f33fd', Clearing records.
Thread-166883::ERROR::2013-08-07 10:00:17,393::dispatcher::67::Storage.Dispatcher.Protect::(run) {'status': {'message': 'Cannot obtain lock: "id=c82ed380-b1d9-4133-a380-e49f7d87b44e, rc=1, out=[\'error - lease file does not exist or is not writeable\', \'usage: /usr/libexec/vdsm/spmprotect.sh COMMAND PARAMETERS\', \'Commands:\', \'  start { sdUUID hostId renewal_interval_sec lease_path[:offset] lease_time_ms io_op_timeout_ms fail_retries }\', \'Parameters:\', \'  sdUUID -                domain uuid\', \'  hostId -                host id in pool\', \'  renewal_interval_sec -  intervals for lease renewals attempts\', \'  lease_path -            path to lease file/volume\', \'  offset -                offset of lease within file\', \'  lease_time_ms -         time limit within which lease must be renewed (at least 2*renewal_interval_sec)\', \'  io_op_timeout_ms -      I/O operation timeout\', \'  fail_retries -          Maximal number of attempts to retry to renew the lease before fencing (<= lease_time_ms/renewal_interval_sec)\'], err=[]"', 'code': 651}}