Nimble driver cinder create failed without specifying display_description

[Jay Wang]

When use cinder create <size> and Nimble iSCSI driver backend, the volume creation failed with:

2015-01-23 13:13:01.794 16750 WARNING cinder.volume.manager [req-ad47227a-180a-4676-bc06-9e1a549aae1c 81d857a3e43b40ef9f09554411ff5476 c666316bbd164b4ca2d7faf427db3f13 - - -] Task 'cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create' (d4009d29-14ff-4110-ae34-1a18d1a3277a) transitioned into state 'FAILURE'
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager Traceback (most recent call last):
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/executor.py", line 34, in _execute_task
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager result = task.execute(**arguments)
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py", line 624, in execute
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager **volume_spec)
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py", line 598, in _create_raw_volume
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager return self.driver.create_volume(volume_ref)
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 105, in wrapper
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager return f(*args, **kwargs)
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/nimble.py", line 168, in create_volume
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager self.configuration.nimble_pool_name, reserve)
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/nimble.py", line 499, in create_vol
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager response = self._execute_create_vol(volume, pool_name, reserve)
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/nimble.py", line 386, in inner_connection_checker
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager return func(self, *args, **kwargs)
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/nimble.py", line 364, in inner_response_checker
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager response = func(self, *args, **kwargs)
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/nimble.py", line 473, in _execute_create_vol
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager if 'display_description' in volume else '')
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager TypeError: cannot concatenate 'str' and 'NoneType' objects
2015-01-23 13:13:01.794 16750 TRACE cinder.volume.manager

[Jay Wang (jwang-6)]

This also caused the CI failure.

May need to use format string instead of + here:
472 display_description = (': %s' % volume['display_description']

[John Griffith (john-griffith)]

I'm curious why none of these issues were picked up during the cert run that you did? It appears that the code is the same there, I'm also a bit worried that something so basic as "cinder create 1" fails?

[Mike Perez (thingee)]

I agree John, this really makes things look fishy with the cert tests that were given in the initial commit on June 26th:

https://review.openstack.org/#/c/73446/12
https://bugs.launchpad.net/cinder/+bug/1308624

I'm very unhappy with this as the cert tests should've definitely caught this case. Jay, I want an honest explanation of why your driver passed the cert tests when it shouldn't have.

[Jay Wang (jwang-6)]

Hi John / Mike,

The issue was first observed in early last November:

    474 display_description = (': ' + volume['display_description']
    475 if 'display_description' in volume else '')

at line 475, when running test with master/release in Juno and after, [if 'display_description' in volume] statement would return true. When running test with master/release before Juno, [if 'display_description' in volume] statement would return false. So the '' would be set to '' instead of None. That was why we didn't hit this issue when we run the certification. And the code and cert test would work/pass (before last November).

The volume class definition has the new __contains__ special method. It may define how an object behaves at the right side of in, such as [if 'display_description' in volume]. I'm suspecting this might be the cause of this statement returning false. I'm still looking into this.

The concerns are fair and good points. We're reviewing our process:

    1. Should open upstream bug as soon as there is issue (we've observed this issue, but didn't open a bug and fix it asap)
    2. Set up CI to meet all requirements (run certification test manually before that regularly) and fix any issue at upstream asap

In addition, will use this bug to:

    1. Use hasattr when evaluate if an object has attribute, such as
        if hasattr(volume, 'display_description)
            instead of
        if 'display_description' in volume
    2. Use string format to concatenate strings instead of +

Please let me know if there is more concern. Very appreciate it.

[Jay Wang (jwang-6)]

additionally
    3. Check attribute value directly as:
        if volume['display_description']:
            # if display_description is not None or empty
            do something

        instead of

        if 'display_description' in volume
            # this may not evaluate the content of the attribute

will go over the driver to see if there's other similar place; then submit the patch and review soon.

[Mike Perez (thingee)]

Jay, thanks for your response back. I'm still trying to make sense of all of this.

So you're saying that before the release of Juno, which I'm assuming is June 25th, when you last posted cert tests [1] to show the Nimble driver passing, things broke after the Juno release in the Volume Base class because of a method __contains__.

I tried to view the differences:

Cinder master: 9e712de6f57d5dbc998444c327f0c2c7825f4827
Last patch in June 25th when your cert tests passed: c9d4bd7c04ad3ca664906c4a528ab5da8d8c0b6f
File: cinder/db/sqlalchemy/models.py

See attachment for the differences. I was not able to find the changes to break your integration. Can you let me know the particular commit hash id please?

In addition I did search in Cinder master today for __contains__ and was not able to find it in the relevant Volume base class you spoke of.

$ ag __contains__
cinder/api/xmlutil.py
202: def __contains__(self, key):

cinder/quota.py
601: def __contains__(self, resource):

[1] - https://bugs.launchpad.net/cinder/+bug/1308624/+attachment/4139788/+files/cinder_nimble_driver_cert_log_2014_06_25.txt

[Jay Wang (jwang-6)]

Hi Mike,

It could probably be traced back to the base. In Icehouse, the volume class is based on CinderBase/models.ModelBase, where models is imported from cinder.openstack.common.db.sqlalchemy. The Icehouse cinder\openstack\common\db\sqlalchemy\models.py doesn't have __contains__ defined.

While in Juno, volume class is based on CinderBase/models.ModelBase, where models is imported from oslo.db.sqlalchemy. The Juno oslo\db\sqlalchemy\models.py has the __contains__ defined as:

56 def __contains__(self, key):
57 return hasattr(self, key)

therefore in Juno, the statement:

475 if 'display_description' in volume

would return true, but not in Icehouse.

At any rate the driver should not use the "in" operator in this case. It's not trying to check if an attribute exists in the volume class, but to check if the content is empty or not. It's fixed in this bug.

I did a quick search and found the possible patch for this change: https://review.openstack.org/#/c/104543/

Again we should have reported and fixed it as soon as we found the issue last nov. The process has been reviewed. We will focus first on upstream and community. The CI will definitely help in this case. We're making good progress on setting up CI. We can reliably run volume test on devstack through upstream/Jenkins. Now we're working on how to join the Jenkins check vote and result report. Very appreciate that you and John raise the concern. Please let me know if you need more info or suggestion.

[Mike Perez (thingee)]

Thanks for your patience and explanation Jay.

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/150669
Committed: https://git.openstack.org/cgit/openstack/cinder/commit/?id=7f88689a2038b50d0f7b7f01c5086e648f15e81a
Submitter: Jenkins
Branch: master

commit 7f88689a2038b50d0f7b7f01c5086e648f15e81a
Author: Jay Wang <email address hidden>
Date: Tue Jan 27 12:02:59 2015 -0800

    Fixes attribute content checking

    Use proper way to check the volume attribute contents in display_name
    and display_description. If they are not empty, translate them to
    volume backend description. Modify other places where return empty
    string makes sense than None as well as the return value checking.

    Closes-Bug: 1414247
    Change-Id: I87b8d09baf75b227b479f8a79ace90a85cf84177