test_volume unittest failure

[Huang Zhiteng]

Test cases in test_volume.py failed a lot (46 out of 152) when only picking this module to run unit test. (./run_tests.sh cinder.tests.test_volume). Looks like taskflow is not properly mocked.

======================================================================
FAIL: cinder.tests.test_volume.VolumeTestCase.test_run_api_attach_detach_volume_with_wrong_attach_mode
----------------------------------------------------------------------
Traceback (most recent call last):
_StringException: Empty attachments:
  pythonlogging:''-1
  stderr
  stdout

pythonlogging:'': {{{
Failed to create manager volume flow
Traceback (most recent call last):
  File "/opt/stack/cinder/cinder/volume/manager.py", line 311, in create_volume
    filter_properties=filter_properties)
  File "/opt/stack/cinder/cinder/volume/flows/create_volume/__init__.py", line 1680, in get_manager_flow
    return taskflow.engines.load(volume_flow, store=create_what)
  File "/opt/stack/cinder/.venv/lib/python2.7/site-packages/taskflow/engines/helpers.py", line 80, in load
    'backend': backend
  File "/opt/stack/cinder/.venv/lib/python2.7/site-packages/stevedore/driver.py", line 31, in __init__
    invoke_kwds=invoke_kwds,
  File "/opt/stack/cinder/.venv/lib/python2.7/site-packages/stevedore/named.py", line 44, in __init__
    self._init_plugins(extensions)
  File "/opt/stack/cinder/.venv/lib/python2.7/site-packages/stevedore/driver.py", line 66, in _init_plugins
    (self.namespace, name))
RuntimeError: No 'taskflow.engines' driver found, looking for 'default'
}}}

Traceback (most recent call last):
  File "/opt/stack/cinder/cinder/tests/test_volume.py", line 1063, in test_run_api_attach_detach_volume_with_wrong_attach_mode
    self.volume.create_volume(self.context, volume_id)
  File "/opt/stack/cinder/cinder/utils.py", line 823, in wrapper
    return func(self, *args, **kwargs)
  File "/opt/stack/cinder/cinder/volume/manager.py", line 315, in create_volume
    _("Failed to create manager volume flow"))
CinderException: Failed to create manager volume flow

======================================================================
FAIL: cinder.tests.test_volume.VolumeTestCase.test_run_attach_detach_volume_for_host
----------------------------------------------------------------------
Traceback (most recent call last):
_StringException: Empty attachments:
  pythonlogging:''-1
  stderr
  stdout

pythonlogging:'': {{{
Failed to create manager volume flow
Traceback (most recent call last):
  File "/opt/stack/cinder/cinder/volume/manager.py", line 311, in create_volume
    filter_properties=filter_properties)
  File "/opt/stack/cinder/cinder/volume/flows/create_volume/__init__.py", line 1680, in get_manager_flow
    return taskflow.engines.load(volume_flow, store=create_what)
  File "/opt/stack/cinder/.venv/lib/python2.7/site-packages/taskflow/engines/helpers.py", line 80, in load
    'backend': backend
  File "/opt/stack/cinder/.venv/lib/python2.7/site-packages/stevedore/driver.py", line 31, in __init__
    invoke_kwds=invoke_kwds,
  File "/opt/stack/cinder/.venv/lib/python2.7/site-packages/stevedore/named.py", line 44, in __init__
    self._init_plugins(extensions)
  File "/opt/stack/cinder/.venv/lib/python2.7/site-packages/stevedore/driver.py", line 66, in _init_plugins
    (self.namespace, name))
RuntimeError: No 'taskflow.engines' driver found, looking for 'default'
}}}

Traceback (most recent call last):
  File "/opt/stack/cinder/cinder/tests/test_volume.py", line 894, in test_run_attach_detach_volume_for_host
    self.volume.create_volume(self.context, volume_id)
  File "/opt/stack/cinder/cinder/utils.py", line 823, in wrapper
    return func(self, *args, **kwargs)
  File "/opt/stack/cinder/cinder/volume/manager.py", line 315, in create_volume
    _("Failed to create manager volume flow"))
CinderException: Failed to create manager volume flow

======================================================================
FAIL: cinder.tests.test_volume.VolumeTestCase.test_run_attach_detach_volume_for_instance
----------------------------------------------------------------------
Traceback (most recent call last):
_StringException: Empty attachments:
  pythonlogging:''-1
  stderr
  stdout

pythonlogging:'': {{{
Failed to create manager volume flow
Traceback (most recent call last):
  File "/opt/stack/cinder/cinder/volume/manager.py", line 311, in create_volume
    filter_properties=filter_properties)
  File "/opt/stack/cinder/cinder/volume/flows/create_volume/__init__.py", line 1680, in get_manager_flow
    return taskflow.engines.load(volume_flow, store=create_what)
  File "/opt/stack/cinder/.venv/lib/python2.7/site-packages/taskflow/engines/helpers.py", line 80, in load
    'backend': backend
  File "/opt/stack/cinder/.venv/lib/python2.7/site-packages/stevedore/driver.py", line 31, in __init__
    invoke_kwds=invoke_kwds,
  File "/opt/stack/cinder/.venv/lib/python2.7/site-packages/stevedore/named.py", line 44, in __init__
    self._init_plugins(extensions)
  File "/opt/stack/cinder/.venv/lib/python2.7/site-packages/stevedore/driver.py", line 66, in _init_plugins
    (self.namespace, name))
RuntimeError: No 'taskflow.engines' driver found, looking for 'default'
}}}

Traceback (most recent call last):
  File "/opt/stack/cinder/cinder/tests/test_volume.py", line 852, in test_run_attach_detach_volume_for_instance
    self.volume.create_volume(self.context, volume_id)
  File "/opt/stack/cinder/cinder/utils.py", line 823, in wrapper
    return func(self, *args, **kwargs)
  File "/opt/stack/cinder/cinder/volume/manager.py", line 315, in create_volume
    _("Failed to create manager volume flow"))
CinderException: Failed to create manager volume flow

[Yukihiro KAWADA (warp-kawada)]

I've also found this problem actually.
Havana latest stable release's create volume does not work at all.
I will attach the patch for this issue.

--- a/volume/manager.py
+++ b/volume/manager.py
@@ -293,22 +293,24 @@ class VolumeManager(manager.SchedulerDependentManager):
         context = context.elevated()
         if filter_properties is None:
             filter_properties = {}
         try:
             flow_engine = create_volume.get_manager_flow(
- context,
+# context, Y.Kawada
                 self.db,
                 self.driver,
                 self.scheduler_rpcapi,
                 self.host,
                 volume_id,
+ request_spec=request_spec,
+ filter_properties=filter_properties,
+ allow_reschedule=allow_reschedule,
                 snapshot_id=snapshot_id,
                 image_id=image_id,
                 source_volid=source_volid,
- allow_reschedule=allow_reschedule,
- reschedule_context=context_saved,
- request_spec=request_spec,
- filter_properties=filter_properties)
+ reschedule_context=context_saved)
         except Exception:
             LOG.exception(_("Failed to create manager volume flow"))
             raise exception.CinderException(
@@ -328,7 +330,7 @@ class VolumeManager(manager.SchedulerDependentManager):
             # flow reverts all job that was done and reraises an exception.
             # Otherwise, all data that was generated by flow becomes available
             # in flow engine's storage.
- flow_engine.run()
+ flow_engine.run(context) # Y.Kawada

[Andres Buraschi (andres-buraschi)]

Hi Yukihiro, I have been trying to fix the root cause for this bug (without success, yet). Till now, I followed the problem to the 'stevedore.driver.DriverManager' initialization (taskflow/engines/heplers.py, in .tox folder), where apparently the entry points for the taskflow namespace are not correctly resolved.

I tried your suggested patch, but unfortunately it fails anyway.

I'm running the specific test with:
python -m testtools.run discover --load-list mylist

Where 'mylist' invokes:

Reference for failure:
cinder.tests.test_volume.VolumeTestCase.test_run_api_attach_detach_volume_with_wrong_attach_mode

Reference for success (when running this test first, both work):
cinder.tests.test_gpfs.GPFSDriverTestCase.test_create_delete_volume_full_backing_file

Do you have any updates on this? I'll be happy to provide any further information that could be helpful.

Regards.

[Yukihiro KAWADA (warp-kawada)]

Hi Andres,

I'm sorry.
It was RDO codes that I saw.
My patch is not for orignal codes.
And I don't know stevedore module.

I'm sorry that we couldn't be of more help.
But I think taskflow maybe have some issue.

2014-01-25 Andres Buraschi <email address hidden>

> Hi Yukihiro, I have been trying to fix the root cause for this bug
> (without success, yet). Till now, I followed the problem to the
> 'stevedore.driver.DriverManager' initialization
> (taskflow/engines/heplers.py, in .tox folder), where apparently the
> entry points for the taskflow namespace are not correctly resolved.
>
> I tried your suggested patch, but unfortunately it fails anyway.
>
> I'm running the specific test with:
> python -m testtools.run discover --load-list mylist
>
> Where 'mylist' invokes:
>
> Reference for failure:
>
> cinder.tests.test_volume.VolumeTestCase.test_run_api_attach_detach_volume_with_wrong_attach_mode
>
> Reference for success (when running this test first, both work):
>
> cinder.tests.test_gpfs.GPFSDriverTestCase.test_create_delete_volume_full_backing_file
>
>
> Do you have any updates on this? I'll be happy to provide any further
> information that could be helpful.
>
> Regards.
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1263175
>
> Title:
> test_volume unittest failure
>
> Status in Cinder:
> Confirmed
>
> Bug description:
> Test cases in test_volume.py failed a lot (46 out of 152) when only
> picking this module to run unit test. (./run_tests.sh
> cinder.tests.test_volume). Looks like taskflow is not properly
> mocked.
>
> ======================================================================
> FAIL:
> cinder.tests.test_volume.VolumeTestCase.test_run_api_attach_detach_volume_with_wrong_attach_mode
> ----------------------------------------------------------------------
> Traceback (most recent call last):
> _StringException: Empty attachments:
> pythonlogging:''-1
> stderr
> stdout
>
> pythonlogging:'': {{{
> Failed to create manager volume flow
> Traceback (most recent call last):
> File "/opt/stack/cinder/cinder/volume/manager.py", line 311, in
> create_volume
> filter_properties=filter_properties)
> File
> "/opt/stack/cinder/cinder/volume/flows/create_volume/__init__.py", line
> 1680, in get_manager_flow
> return taskflow.engines.load(volume_flow, store=create_what)
> File
> "/opt/stack/cinder/.venv/lib/python2.7/site-packages/taskflow/engines/helpers.py",
> line 80, in load
> 'backend': backend
> File
> "/opt/stack/cinder/.venv/lib/python2.7/site-packages/stevedore/driver.py",
> line 31, in __init__
> invoke_kwds=invoke_kwds,
> File
> "/opt/stack/cinder/.venv/lib/python2.7/site-packages/stevedore/named.py",
> line 44, in __init__
> self._init_plugins(extensions)
> File
> "/opt/stack/cinder/.venv/lib/python2.7/site-packages/stevedore/driver.py",
> line 66, in _init_plugins
> (self.namespace, name))
> RuntimeError: No 'taskflow.engines' driver found, looking for 'default'
> }}}
>
> Traceback (most recent call last):
> File "/opt/stack/cinder/cind...

[John Griffith (john-griffith)]

It seems something in the api tests is setting up the fake or whatever it is that we need to get the taskflow module to load. The good (or bad) thing is that it's not cleaning whatever it does up afterwards, so that's why running the entire test suite works but not just the test_volume tests.

[Abhijeet Malawade (abhijeet-malawade)]

I think this issue is happening because we are stubbing 'os.path.exists' in setUp method of BaseVolumeTestCase (https://github.com/openstack/cinder/blob/master/cinder/tests/test_volume.py#L111).

Taskflow code uses stevedore module to load taskflow-engines and stevedore internally use pkg_resources.
Pkg_resources uses 'os'path.exists' to check if 'entry_pionts.txt' file is present or not. But because of stubbing 'os.path.exists' it returns
'True' every time. So even if 'entry_points.txt' is not present pkg_resources tries to open this file (https://bitbucket.org/pypa/setuptools/src/13a839bd8ad27a17543878068b996991357264d2/pkg_resources.py?at=default#cl-1454) and this call fails.

But when we run entire test suite, 'pkg_resurces' is getting called in 'cinder/openstack/common/scheduler/base_handler.py'. (base_handler uses stevedore)
This scheduler test cases are getting executed before 'test_volume' test cases. And I think 'pkg_resources' stores(caches) all distribution object
(https://bitbucket.org/pypa/setuptools/src/13a839bd8ad27a17543878068b996991357264d2/pkg_resources.py?at=default#cl-547). Because of this stevedore
loads 'taskflow.engines' successfully (gets entry points from cached distribution objects) when we run entire test suite.

If I stub pkg_resources's 'iter_entry_points' method as shown bellow then test_volume test cases are getting passed when we ran this single test module.(or entire test suite)

--- a/cinder/tests/test_volume.py
+++ b/cinder/tests/test_volume.py
@@ -29,6 +29,7 @@ import eventlet
 import mock
 import mox
 from oslo.config import cfg
+import pkg_resources
 from taskflow.engines.action_engine import engine

 from cinder.backup import driver as backup_driver
@@ -108,6 +109,30 @@ class BaseVolumeTestCase(test.TestCase):
         fake_image.stub_out_image_service(self.stubs)
         test_notifier.NOTIFICATIONS = []
         self.stubs.Set(brick_lvm.LVM, '_vg_exists', lambda x: True)
+
+ self.orignal_iter_entry_points = pkg_resources.iter_entry_points
+ def fake_iter_entry_points(group, name=None):
+ if group == 'taskflow.engines':
+ taskflow_entry_points = []
+ taskflow_entry_points.append(
+ pkg_resources.EntryPoint.parse(
+ 'default = taskflow.engines.action_engine.engine:'
+ 'SingleThreadedActionEngine'))
+ taskflow_entry_points.append(
+ pkg_resources.EntryPoint.parse(
+ 'serial = taskflow.engines.action_engine.engine:'
+ 'SingleThreadedActionEngine'))
+ taskflow_entry_points.append(
+ pkg_resources.EntryPoint.parse(
+ 'parallel = taskflow.engines.action_engine.engine:'
+ 'MultiThreadedActionEngine'))
+ return taskflow_entry_points
+ else:
+ return self.orignal_iter_entry_points(group, name=name)
+
+ # Stub iter_entry_points for taskflow
+ self.stubs.Set(pkg_resources, 'iter_entry_points',
+ fake_iter_entry_points)
         self.stubs.Set(os.path, 'exists', ...

[Abhijeet Malawade (abhijeet-malawade)]

Hi,

The patch attached bellow also fixes this issue:

--- a/cinder/tests/test_volume.py
+++ b/cinder/tests/test_volume.py
@@ -29,6 +29,7 @@ import eventlet
 import mock
 import mox
 from oslo.config import cfg
+from stevedore import extension
 from taskflow.engines.action_engine import engine

 from cinder.backup import driver as backup_driver
@@ -90,6 +91,8 @@ class BaseVolumeTestCase(test.TestCase):
     """Test Case for volumes."""
     def setUp(self):
         super(BaseVolumeTestCase, self).setUp()
+ self.extension_manager =\
+ extension.ExtensionManager("BaseVolumeTestCase")
         vol_tmpdir = tempfile.mkdtemp()
         self.flags(volumes_dir=vol_tmpdir,
                    notification_driver=[test_notifier.__name__])

The stevedor ExtensionManager uses pkg_resources, and I think pkg_resourses caches all distribution objects when it runs first time(see above comment no 6).
Because of this we get 'taskflow.engines' driver (I think we get this from pkg_resources cached distributions when we use above patch).

Let me know your opinion on this.

[Andres Buraschi (andres-buraschi)]

Hi Abihijeet,
your latest patch works perfectly for me too. I agree regarding the stevedore module caching the package resources. There is this pretty old patch regarding the mentioned caching:
https://github.com/dhellmann/stevedore/commit/7bdc14c62059a50fedb6c385ed8e7c57fc4bb135

Well, this is definitely your patch and solution. Do you want to assign the bug to yourself to be the solution owner?
Otherwise, I don't mind submitting the patch, but only if you are ok with it.

Thanks for the research!

Regards.

[John Griffith (john-griffith)]

Andres, you can always add the patch and put Abhijeet as the author or co-author in the commit. Depending on what comes back that way he gets the appropriate credit.

By the way, thanks to both of you for looking into this. I knew it was around there somewhere but had yet to find exactly where it was broken.

Thanks!!!

[Abhijeet Malawade (abhijeet-malawade)]

Hi Andres,

One of my team member will submit this patch.

Thanks for your comments.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/73984

[OpenStack Infra (hudson-openstack)]

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

commit c1853677d4637edb3c341589fad6aed0d5f71a3d
Author: Pranali Deore <email address hidden>
Date: Mon Feb 17 01:35:34 2014 -0800

    test_volume unittest fails if ran only this module

    Using stevedore ExtensionManager to load entry_points(extensions)
    before running any test case.

    In BaseVolumeTestCase we have stubbed 'os.path.exists' call,
    because of this stevedore is not able to load entry points paroperly.
    Stevedore internally use pkg_resources and pkg_resources use
    'os.path.exists' to check if entry_points.txt file exists or not.
    Because of stubbibg it is returning True even if file do not exists.

    Change-Id: I4fd6bee2e9f33c45ad3deacfe7359dc56171205e
    Closes-Bug: #1263175