EMC driver fails to create volumes from images as CMI returns incosistent state

[Giulio Fidente]

When Cinder is configured to use the EMC driver(*), creation of volumes from images fails.

* cinder.volume.drivers.emc.emc_smis_iscsi.EMCSMISISCSIDriver

The trace is as follows:

2014-01-07 16:21:59.463 1213 ERROR cinder.openstack.common.rpc.amqp [req-2ff1de60-b7a2-44dd-84ed-fad6c884fab1 defb70cace454644abec36f3950d0dc8 ac339accb67247c6b9988070f1b2cbcd] Excep[11/1863]
ng message handling
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp Traceback (most recent call last):
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/amqp.py", line 441, in _process_data
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp **args)
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/openstack/common/rpc/dispatcher.py", line 148, in dispatch
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp return getattr(proxyobj, method)(ctxt, **kwargs)
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/utils.py", line 823, in wrapper
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp return func(self, *args, **kwargs)
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 589, in copy_volume_to_image
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp payload['message'] = unicode(error)
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp self.gen.next()
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/manager.py", line 583, in copy_volume_to_image
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp image_meta)
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/driver.py", line 356, in copy_volume_to_image
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp attach_info = self._attach_volume(context, volume, properties)
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/driver.py", line 373, in _attach_volume
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp conn = self.initialize_connection(volume, properties)
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/emc/emc_smis_iscsi.py", line 105, in initialize_connection
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp self.common.initialize_connection(volume, connector)
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/emc/emc_smis_common.py", line 836, in initialize_connection
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp device_info = self.find_device_number(volume)
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/cinder/volume/drivers/emc/emc_smis_common.py", line 1380, in find_device_number
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp ResultClass='CIM_ProtocolControllerForUnit')
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/pywbem/cim_operations.py", line 775, in ReferenceNames
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp **params)
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp File "/usr/lib/python2.6/site-packages/pywbem/cim_operations.py", line 219, in imethodcall
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp raise CIMError(code, tt[1]['DESCRIPTION'])
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp CIMError: (1, u'A general error occurred that is not covered by a more specific error code. (com.emc.cmp.osls.se.osl.Masking.StorMaskGroupShow():138 C:ERROR_CLASS_SOFTWARE F:ERROR_FAMILY_FAILED R:1200019 C:ERROR_CLASS_SOFTWARE F:ERROR_FAMILY_FAILED R:1200019 The internal database is in an inconsistent state, and must be fully synchronized before performing this operation.)')
2014-01-07 16:21:59.463 1213 TRACE cinder.openstack.common.rpc.amqp

While it seems a problem with the CIM software itself, this is instead working fine when creating regular volumes.

The emc_smis_iscsi.py file is versioned 1.0.0

Steps to Reproduce:

1. configure Cinder with the EMC driver
2. try to create a volume using the "--image-id" option

[Giulio Fidente (gfidente)]

hi, thanks for picking this up ... good news is that I'm currently *not* experiencing this issue anymore.

there is a test in tempest covering this (in tempest/api/volume/test_volumes_get.py) which is passing with no failures.

you may want to double check before closing the bug though.

[Xing Yang (xing-yang)]

Giulio Fidente said this is not happening any more.

[Xing Yang (xing-yang)]

The error indicated that your SE db is out of sync.

"The internal database is in an inconsistent state, and must be fully synchronized before performing this operation."

So you need to do a sync in TestSmiProvider.exe to fix that.

If you run into this problem in the future, please feel free to open this bug again or contact me.