[ovirt-users] Issue while importing the existing storage domain

Wed Apr 20 09:41:39 UTC 2016

Hi All,

I was testing the gluster geo-replication on RHEV storage domain backed 
by gluster volume.
In this case, storage domain ( data domain ) was created with gluster 
replica 3 volume.

The VMs additional disks are carved out from this storage domain.

Now I have geo-replicated[1] the gluster volume to the remote volume.
When I try importing this storage domain in another RHEVM instance, it 
fails with error "internal engine error"
  I see the following error in engine.log

<snip>
2016-04-20 05:13:47,685 ERROR 
[org.ovirt.engine.core.vdsbroker.irsbroker.DetachStorageDomainVDSCommand] (ajp-/127.0.0.1:8702-3) 
[20f6ea4c] Failed in 'DetachStorageDomainVDS' method
2016-04-20 05:13:47,708 ERROR 
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] 
(ajp-/127.0.0.1:8702-3) [20f6ea4c] Correlation ID: null, Call Stack: 
null, Custom Event ID: -1, Message: VDSM command failed: Cannot acquire 
host id: (u'89061d19-fb76-47c9-a4aa-22b0062b769e', 
SanlockException(-262, 'Sanlock lockspace add failure', 'Sanlock 
exception'))
2016-04-20 05:13:47,708 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.DetachStorageDomainVDSCommand] (ajp-/127.0.0.1:8702-3) 
[20f6ea4c] Command 
'org.ovirt.engine.core.vdsbroker.irsbroker.DetachStorageDomainVDSCommand' return 
value 'StatusOnlyReturnForXmlRpc [status=StatusForXmlRpc [code=661, 
message=Cannot acquire host id: 
(u'89061d19-fb76-47c9-a4aa-22b0062b769e', SanlockException(-262, 
'Sanlock lockspace add failure', 'Sanlock exception'))]]'
</snip>

The complete logs are available in the fpaste[2]
Attaching the part of vdsm log to this mail

[1] - geo-replication is the feature in glusterfs where the contents of 
volume are asynchronously replicated in remote volume.
This is used for disaster-recovery workflow

[2] - https://paste.fedoraproject.org/357701/11448771/

Thanks,
Satheesaran S
-------------- next part --------------
BindingXMLRPC::INFO::2016-04-20 10:42:10,604::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting request handler for 127.0.0.1:37704
Thread-4816::INFO::2016-04-20 10:42:10,605::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:37704 started
Thread-4816::INFO::2016-04-20 10:42:10,611::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request handler for 127.0.0.1:37704 stopped
jsonrpc.Executor/0::ERROR::2016-04-20 10:42:11,407::task::866::Storage.TaskManager.Task::(_setError) Task=`14b4ecd2-41f1-4cf3-bb21-8ba5e433f1c7`::Unexpected error
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/task.py", line 873, in _run
    return fn(*args, **kargs)
  File "/usr/share/vdsm/logUtils.py", line 49, in wrapper
    res = f(*args, **kwargs)
  File "/usr/share/vdsm/storage/hsm.py", line 805, in forcedDetachStorageDomain
    self._deatchStorageDomainFromOldPools(sdUUID)
  File "/usr/share/vdsm/storage/hsm.py", line 781, in _deatchStorageDomainFromOldPools
    dom.acquireHostId(pool.id)
  File "/usr/share/vdsm/storage/sd.py", line 533, in acquireHostId
    self._clusterLock.acquireHostId(hostId, async)
  File "/usr/share/vdsm/storage/clusterlock.py", line 234, in acquireHostId
    raise se.AcquireHostIdFailure(self._sdUUID, e)
AcquireHostIdFailure: Cannot acquire host id: (u'89061d19-fb76-47c9-a4aa-22b0062b769e', SanlockException(-262, 'Sanlock lockspace add failure', 'Sanlock exception'))
jsonrpc.Executor/0::DEBUG::2016-04-20 10:42:11,408::task::885::Storage.TaskManager.Task::(_run) Task=`14b4ecd2-41f1-4cf3-bb21-8ba5e433f1c7`::Task._run: 14b4ecd2-41f1-4cf3-bb21-8ba5e433f
1c7 (u'89061d19-fb76-47c9-a4aa-22b0062b769e', u'00000000-0000-0000-0000-000000000000') {} failed - stopping task
jsonrpc.Executor/0::DEBUG::2016-04-20 10:42:11,408::task::1246::Storage.TaskManager.Task::(stop) Task=`14b4ecd2-41f1-4cf3-bb21-8ba5e433f1c7`::stopping in state preparing (force False)
jsonrpc.Executor/0::DEBUG::2016-04-20 10:42:11,408::task::993::Storage.TaskManager.Task::(_decref) Task=`14b4ecd2-41f1-4cf3-bb21-8ba5e433f1c7`::ref 1 aborting True
jsonrpc.Executor/0::INFO::2016-04-20 10:42:11,408::task::1171::Storage.TaskManager.Task::(prepare) Task=`14b4ecd2-41f1-4cf3-bb21-8ba5e433f1c7`::aborting: Task is aborted: 'Cannot acquir
e host id' - code 661
jsonrpc.Executor/0::DEBUG::2016-04-20 10:42:11,408::task::1176::Storage.TaskManager.Task::(prepare) Task=`14b4ecd2-41f1-4cf3-bb21-8ba5e433f1c7`::Prepare: aborted: Cannot acquire host id
jsonrpc.Executor/0::DEBUG::2016-04-20 10:42:11,408::task::993::Storage.TaskManager.Task::(_decref) Task=`14b4ecd2-41f1-4cf3-bb21-8ba5e433f1c7`::ref 0 aborting True
jsonrpc.Executor/0::DEBUG::2016-04-20 10:42:11,408::task::928::Storage.TaskManager.Task::(_doAbort) Task=`14b4ecd2-41f1-4cf3-bb21-8ba5e433f1c7`::Task._doAbort: force False
jsonrpc.Executor/0::DEBUG::2016-04-20 10:42:11,409::resourceManager::980::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
jsonrpc.Executor/0::DEBUG::2016-04-20 10:42:11,409::task::595::Storage.TaskManager.Task::(_updateState) Task=`14b4ecd2-41f1-4cf3-bb21-8ba5e433f1c7`::moving from state preparing -> state
 aborting
jsonrpc.Executor/0::DEBUG::2016-04-20 10:42:11,409::task::550::Storage.TaskManager.Task::(__state_aborting) Task=`14b4ecd2-41f1-4cf3-bb21-8ba5e433f1c7`::_aborting: recover policy none
jsonrpc.Executor/0::DEBUG::2016-04-20 10:42:11,409::task::595::Storage.TaskManager.Task::(_updateState) Task=`14b4ecd2-41f1-4cf3-bb21-8ba5e433f1c7`::moving from state aborting -> state 
failed
jsonrpc.Executor/0::DEBUG::2016-04-20 10:42:11,409::resourceManager::943::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
jsonrpc.Executor/0::DEBUG::2016-04-20 10:42:11,409::resourceManager::980::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
jsonrpc.Executor/0::ERROR::2016-04-20 10:42:11,409::dispatcher::76::Storage.Dispatcher::(wrapper) {'status': {'message': "Cannot acquire host id: (u'89061d19-fb76-47c9-a4aa-22b0062b769e', SanlockException(-262, 'Sanlock lockspace add failure', 'Sanlock exception'))", 'code': 661}}
mailbox.SPMMonitor::DEBUG::2016-04-20 10:42:11,454::storage_mailbox::735::Storage.Misc.excCmd::(_checkForMail) /usr/bin/taskset --cpu-list 0-23 dd if=/rhev/data-center/62587ba0-26c3-4b0a-92c3-b651eccd29a0/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000 (cwd None)
mailbox.SPMMonitor::DEBUG::2016-04-20 10:42:11,477::storage_mailbox::735::Storage.Misc.excCmd::(_checkForMail) SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.00617171 s, 166 MB/s\n'; <rc> = 0
Thread-166::DEBUG::2016-04-20 10:42:11,985::fileSD::173::Storage.Misc.excCmd::(getReadDelay) /usr/bin/taskset --cpu-list 0-23 /usr/bin/dd if=/rhev/data-center/mnt/glusterSD/dhcp37-56.lab.eng.blr.redhat.com:_volume4/af8b8d1f-a1b9-4166-92a5-8a6950d5009d/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
Thread-166::DEBUG::2016-04-20 10:42:11,997::fileSD::173::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n483 bytes (483 B) copied, 0.00143139 s, 337 kB/s\n'; <rc> = 0