test_rescue_preserve_disk_on_failure unittest broken

[Bhuvan Arumugam]

One of following commits broke unittests. I am not quite sure how it's related, but they are broken ever since these changes were merged.

https://github.com/openstack/nova/commit/f99641f09965b8f5036a976e9a5f5f28a542d800
https://github.com/openstack/nova/commit/eaf5636544a9b2ae1e87f74d0cdb989f8a41b008

running=OS_STDOUT_CAPTURE=${OS_STDOUT_CAPTURE:-1} \
OS_STDERR_CAPTURE=${OS_STDERR_CAPTURE:-1} \
OS_TEST_TIMEOUT=${OS_TEST_TIMEOUT:-60} \
${PYTHON:-python} -m subunit.run discover -t ./ ./nova/tests
======================================================================
FAIL: nova.tests.virt.xenapi.test_xenapi.XenAPIVMTestCase.test_instance_snapshot_fails_with_no_primary_vdi
tags: worker-0
----------------------------------------------------------------------
Empty attachments:
  stderr
  stdout

pythonlogging:'': {{{
Loading network driver 'nova.network.linux_net'
Loading network driver 'nova.network.linux_net'
Loading network driver 'nova.network.linux_net'
glance.upload_vhd attempt 1/1
}}}

Traceback (most recent call last):
  File "nova/tests/virt/xenapi/test_xenapi.py", line 522, in test_instance_snapshot_fails_with_no_primary_vdi
    lambda *args, **kwargs: None)
  File "/home/jenkins/workspace/csi-nova-upstream/.tox/py26/lib/python2.6/site-packages/testtools/testcase.py", line 394, in assertRaises
    self.assertThat(our_callable, matcher)
  File "/home/jenkins/workspace/csi-nova-upstream/.tox/py26/lib/python2.6/site-packages/testtools/testcase.py", line 417, in assertThat
    raise MismatchError(matchee, matcher, mismatch, verbose)
MismatchError: <bound method XenAPIDriver.snapshot of <nova.virt.xenapi.driver.XenAPIDriver object at 0x19e61490>> returned None
======================================================================
FAIL: nova.tests.virt.xenapi.test_xenapi.XenAPIVMTestCase.test_rescue_preserve_disk_on_failure
tags: worker-0
----------------------------------------------------------------------
Empty attachments:
  stderr
  stdout

pythonlogging:'': {{{
Loading network driver 'nova.network.linux_net'
Loading network driver 'nova.network.linux_net'
Loading network driver 'nova.network.linux_net'
glance.download_vhd attempt 1/1
glance.download_vhd attempt 1/1
Failed to spawn, rolling back
Traceback (most recent call last):
  File "nova/virt/xenapi/vmops.py", line 498, in _spawn
    boot_instance_step(undo_mgr, vm_ref)
  File "nova/virt/xenapi/vmops.py", line 152, in inner
    rv = f(*args, **kwargs)
  File "nova/virt/xenapi/vmops.py", line 461, in boot_instance_step
    self._start(instance, vm_ref)
  File "nova/tests/virt/xenapi/test_xenapi.py", line 1276, in fake_start
    raise test.TestingException('Start Error')
TestingException: Start Error
VM already halted, skipping shutdown...
['HANDLE_INVALID', 'VDI', '8c985bc1-998b-4dd2-b797-cbe86bf2abb2']
Traceback (most recent call last):
  File "nova/virt/xenapi/vm_utils.py", line 439, in destroy_vdi
    session.call_xenapi('VDI.destroy', vdi_ref)
  File "nova/virt/xenapi/driver.py", line 779, in call_xenapi
    return session.xenapi_request(method, args)
  File "nova/virt/xenapi/fake.py", line 756, in xenapi_request
    return meth(*full_params)
  File "nova/virt/xenapi/fake.py", line 801, in <lambda>
    return lambda *params: self._destroy(name, params)
  File "nova/virt/xenapi/fake.py", line 917, in _destroy
    raise Failure(['HANDLE_INVALID', table, ref])
Failure: ['HANDLE_INVALID', 'VDI', '8c985bc1-998b-4dd2-b797-cbe86bf2abb2']
Unable to destroy VDI 8c985bc1-998b-4dd2-b797-cbe86bf2abb2
}}}

Traceback (most recent call last):
  File "nova/tests/virt/xenapi/test_xenapi.py", line 1285, in test_rescue_preserve_disk_on_failure
    self.assertEqual(vdi_ref, vdi_ref2)
  File "/home/jenkins/workspace/csi-nova-upstream/.tox/py26/lib/python2.6/site-packages/testtools/testcase.py", line 322, in assertEqual
    self.assertThat(observed, matcher, message)
  File "/home/jenkins/workspace/csi-nova-upstream/.tox/py26/lib/python2.6/site-packages/testtools/testcase.py", line 417, in assertThat
    raise MismatchError(matchee, matcher, mismatch, verbose)
MismatchError: !=:
reference = '62ba4799-a2bf-4a47-aef6-9341b70a2ad1'
actual = '8a4dcae5-7a8f-49db-92af-775f80f935fc'
======================================================================
FAIL: process-returncode
tags: worker-0
----------------------------------------------------------------------
Binary content:
  traceback (test/plain; charset="utf8")
Ran 19145 tests in 2223.014s
FAILED (id=0, failures=3, skips=12)
error: testr failed (1)
ERROR: InvocationError: '/home/jenkins/workspace/csi-nova-upstream/.tox/py26/bin/python setup.py test --slowest --testr-args='

[Stanislaw Pitucha (stanislaw-pitucha)]

Change https://github.com/openstack/nova/commit/eaf5636544a9b2ae1e87f74d0cdb989f8a41b008 is broken (but the code before was broken too). There's bug 1239890 open for it with a fix.

It doesn't look likely that it's got anything to do with this failure unfortunately :(

[Bhuvan Arumugam (bhuvan)]

Stanislaw, yep. Commit https://github.com/openstack/nova/commit/eaf5636544a9b2ae1e87f74d0cdb989f8a41b008 doesn't cause this failure.

The failure is caused by this commit. https://github.com/openstack/nova/commit/f99641f09965b8f5036a976e9a5f5f28a542d800

[Soren Hansen (soren)]

I know why this happens, but I can't explain why it doesn't happen for everyone.

The problem is that we're maintaining two sets of stubs. One inside of mox and one outside of mock (self.mox + self.stubs in nova.test.TestCase).

The stub cleanup process is smart enough to unwind the stubs in the opposite order of how they were put in place, so if you stub out the same method twice, you get will end up with the correct method after the cleanup. However, this doesn't work when there are two separate sets of stubs, because the order in which each of the sets of stubs are cleaned up, might not be opposite of how they were put in place.

I have a fix in the works that unites the two sets of stubs so this won't happen anymore.

[Soren Hansen (soren)]

This problem happens consistently for me, occasionally in my Jenkins instance, and never on the OpenStack infrastructure, afaics. This means it's dependent on environmental factors. As such, if these factors were to change on the OpenStack infrastructure, it could get in the way of getting important security fixes out in a timely fashion. As such, I'm setting it to "High" importance.

[Soren Hansen (soren)]

Proposed fix here (goes into oslo-incubator):

    https://review.openstack.org/#/c/52037/

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/52037
Committed: http://github.com/openstack/oslo-incubator/commit/f4a485530ebd123cdb80b8b8a378ff9847b2a5d7
Submitter: Jenkins
Branch: master

commit f4a485530ebd123cdb80b8b8a378ff9847b2a5d7
Author: Soren Hansen <email address hidden>
Date: Wed Oct 16 08:35:03 2013 +0000

    Consolidate the use of stubs

    We have two separate StubOutForTesting objects when running tests. One
    that is instantiated directly in the moxstubout fixture and one that
    mox has for itself.

    When a method is stubbed, the overridden method is kept in a cache in
    the StubOutForTesting instance. When calling UnsetAll() on this
    instance, the order of the cache is reversed and the original methods
    are put back in place. This means if you have SomeObject with a method
    called actual_method and you stub that out with

        stubs.Set(SomeObject, "actual_method", fake_method)

    you end up with a this tuple in the cache:

        (SomeObject, "actual_method", SomeObject.actual_method)

    If you stub it out again

        stubs.Set(SomeObject, "actual_method", fake_method2)

    this tuple is appended to the cache:

        (SomeObject, "actual_method", fake_method)

    When calling UnsetAll(), the cache is reversed and becomes:

        [(SomeObject, "actual_method", fake_method),
         (SomeObject, "actual_method", SomeObject.actual_method)]

    So first, SomeObject.actual_method (which currently is fake_method2) is
    set to fake_method, and then set to the original
    SomeObject.actual_method medthod.

    If, however, you stub out the same method using both mox and our own
    StubOutForTesting object, one of the caches will have

        (SomeObject, "actual_method", SomeObject.actual_method)

    and the other will have:

        (SomeObject, "actual_method", fake_method)

    At this point, restoring everything back to the original state depends
    on these StubOutForTesting objects getting cleaned up in the correct
    order. If it's done in the wrong order, SomeObject.actual_method
    (currently set to fake_method2) will get reset to the original
    SomeObject.actual_method and subsequently get "reset" to fake_method
    which makes life miserable for subsequent tests that might rely on the
    real implementation.

    This change stops us from having two separate StubOutForTesting objects
    by simply using mox's all the time.

    Fixes bug #1239898

    Change-Id: I3a768eca3432e6df09c87bd86bffa9763aabfbed

[OpenStack Infra (hudson-openstack)]

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

[Rick Harris (rconradharris)]

This fix isn't quite right because it causes other tests to fail in nova/tests/network/test_manager.py.

The original code in Nova was carefully order to avoid these issues, but the Oslo code that added this fixture swapped the order of the cleanup calls, causing this issue to recur.

The test that a fix works in Nova is:

nosetests nova/tests/network/test_manager.py nova/tests/virt/xenapi/test_xenapi.py

I'm going to reintroduce the original (working) Nova code as the fix for Oslo.

[Rick Harris (rconradharris)]

For reference, the original nova commit to fix this is https://github.com/openstack/nova/commit/4e560d49d4a8d08341dae6df5e123e1be1b3c779

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/52094
Committed: http://github.com/openstack/nova/commit/0b513a7ea4518977f1b1ee9e30e0289f77db4130
Submitter: Jenkins
Branch: master

commit 0b513a7ea4518977f1b1ee9e30e0289f77db4130
Author: Soren Hansen <email address hidden>
Date: Wed Oct 16 12:36:28 2013 +0000

    Sync fixture module from oslo

    Changes pulled:

      [f4a4855] Consolidate the use of stubs
      [6111131] Make openstack.common.fixture.config Py3 compliant

    Due to the changes to the stub use, a couple of tests (the ones in
    test_shelve) needed to have some cleanups removed that depended on some
    stubs still being in place and not others. The normal DB cleanup
    procedure handles this correctly, so the cleanups were superfluous
    anyway.

    The test in test_manager was split in two to avoid it resetting its
    stubs halfway through. It was testing two separate scenarios anyway, so
    it's the correct thing to do regardless.

    I'll submit a patch later to get rid of all the superfluous VerifyAll
    and UnsetStubs calls across the entire test suite, but for now, let's
    just get the gate working again, shall we?

    Fixes bug #1239898

    Change-Id: I3aa4dfc0261a861e5eaa570849329292d64236ed