vmware: volumes stuck in error deleting

[dan wendlandt]

I was doing some scale testing, creating and deleting small hundreds of VMs and volumes in succession using the API.

At the end, two volumes where stuck in "error_deleting", apparently due to the exception below. Something seems wrong here, as clearly the provided credentials are correct, given that I successfully used them to create a bunch of volumes and to delete almost all of them.

2013-12-01 02:08:25.737 1833 ERROR cinder.openstack.common.loopingcall [-] in dynamic looping call

2013-12-01 02:08:25.737 1833 TRACE cinder.openstack.common.loopingcall Traceback (most recent call last):

2013-12-01 02:08:25.737 1833 TRACE cinder.openstack.common.loopingcall File "/opt/stack/cinder/cinder/openstack/common/loopingcall.py", line

125, in _inner

2013-12-01 02:08:25.737 1833 TRACE cinder.openstack.common.loopingcall idle = self.f(*self.args, **self.kw)

2013-12-01 02:08:25.737 1833 TRACE cinder.openstack.common.loopingcall File "/opt/stack/cinder/cinder/volume/drivers/vmware/api.py", line 86,

 in _func

2013-12-01 02:08:25.737 1833 TRACE cinder.openstack.common.loopingcall done.send_exception(excep)

2013-12-01 02:08:25.737 1833 TRACE cinder.openstack.common.loopingcall File "/usr/local/lib/python2.7/dist-packages/eventlet/event.py", line

208, in send_exception

2013-12-01 02:08:25.737 1833 TRACE cinder.openstack.common.loopingcall return self.send(None, args)

2013-12-01 02:08:25.737 1833 TRACE cinder.openstack.common.loopingcall File "/usr/local/lib/python2.7/dist-packages/eventlet/event.py", line

150, in send

2013-12-01 02:08:25.737 1833 TRACE cinder.openstack.common.loopingcall assert self._result is NOT_USED, 'Trying to re-send() an already-tri

ggered event.'

2013-12-01 02:08:25.737 1833 TRACE cinder.openstack.common.loopingcall AssertionError: Trying to re-send() an already-triggered event.

2013-12-01 02:08:25.737 1833 TRACE cinder.openstack.common.loopingcall

2013-12-01 02:08:25.780 1833 ERROR suds.client [-] <?xml version="1.0" encoding="UTF-8"?>

<SOAP-ENV:Envelope xmlns:ns0="urn:vim25" xmlns:ns1="http://schemas.xmlsoap.org/soap/envelope/" xmlns:xsi="http://www.w3.org/2001/XMLSchema-inst

ance" xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/">

   <ns1:Body>

      <ns0:ContinueRetrievePropertiesEx>

         <ns0:_this type="PropertyCollector">propertyCollector</ns0:_this>

         <ns0:token>1</ns0:token>

      </ns0:ContinueRetrievePropertiesEx>

   </ns1:Body>

</SOAP-ENV:Envelope>

2013-12-01 02:08:25.782 1833 DEBUG cinder.openstack.common.loopingcall [-] Dynamic looping call sleeping for 0.00 seconds _inner /opt/stack/cin

der/cinder/openstack/common/loopingcall.py:132

2013-12-01 02:08:25.907 1833 ERROR cinder.openstack.common.rpc.amqp [req-c562c78c-ee95-471b-92ce-04268c9604d9 24a6241f4d824182b07c51c7f664fb3f

78eed4a1f5bd4b1fa0eec5bf7967ebb9] Exception during message handling

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp Traceback (most recent call last):

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp File "/opt/stack/cinder/cinder/openstack/common/rpc/amqp.py", line 441, i

n _process_data

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp **args)

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp File "/opt/stack/cinder/cinder/openstack/common/rpc/dispatcher.py", line

148, in dispatch

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp return getattr(proxyobj, method)(ctxt, **kwargs)

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp File "/opt/stack/cinder/cinder/utils.py", line 808, in wrapper

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp return func(self, *args, **kwargs)

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp File "/opt/stack/cinder/cinder/volume/manager.py", line 302, in delete_vo

lume

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp {'status': 'error_deleting'})

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp self.gen.next()

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp File "/opt/stack/cinder/cinder/volume/manager.py", line 290, in delete_vo

lume

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp self.driver.delete_volume(volume_ref)

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp File "/opt/stack/cinder/cinder/volume/drivers/vmware/vmdk.py", line 221,

in delete_volume

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp self._delete_volume(volume)

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp File "/opt/stack/cinder/cinder/volume/drivers/vmware/vmdk.py", line 210,

in _delete_volume

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp backing = self.volumeops.get_backing(volume['name'])

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp File "/opt/stack/cinder/cinder/volume/drivers/vmware/volumeops.py", line

78, in get_backing

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp self._max_objects)

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp File "/opt/stack/cinder/cinder/volume/drivers/vmware/api.py", line 223, i

n invoke_api

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp return _invoke_api(module, method, *args, **kwargs)

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp File "/opt/stack/cinder/cinder/volume/drivers/vmware/api.py", line 93, in

 func

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp result = done.wait()

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp File "/usr/local/lib/python2.7/dist-packages/eventlet/event.py", line 116

, in wait

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp return hubs.get_hub().switch()

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp File "/usr/local/lib/python2.7/dist-packages/eventlet/hubs/hub.py", line 187, in switch

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp return self.greenlet.switch()

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp VimFaultException: Server raised fault: 'Cannot complete login due to an incorrect user name or password.'

2013-12-01 02:08:25.907 1833 TRACE cinder.openstack.common.rpc.amqp

2013-12-01 02:08:26.071 1833 DEBUG cinder.openstack.common.loopingcal

[Subbu (subramanian-neelakantan)]

I have saved away the cinder-vol and cinder-sch log files. Need to pour through the log files and analyze this failure.

[Vipin Balachandran (vbala)]

Fixed in release 0.9.0 of oslo.vmware.
https://bugs.launchpad.net/oslo.vmware/+bug/1409014