nova.tests.unit.test_context.ContextTestCase.test_store_when_no_overwrite intermittently fails with MismatchError

[Matt Riedemann]

http://logs.openstack.org/53/155853/16/check/gate-nova-python27/1f928bf/console.html#_2015-03-05_15_33_13_116

2015-03-05 15:33:13.116 | Captured traceback:
2015-03-05 15:33:13.116 | ~~~~~~~~~~~~~~~~~~~
2015-03-05 15:33:13.116 | Traceback (most recent call last):
2015-03-05 15:33:13.116 | File "nova/tests/unit/test_context.py", line 147, in test_store_when_no_overwrite
2015-03-05 15:33:13.117 | self.assertIs(o_context.get_current(), ctx)
2015-03-05 15:33:13.117 | File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/testtools/testcase.py", line 382, in assertIs
2015-03-05 15:33:13.117 | self.assertThat(observed, matcher, message)
2015-03-05 15:33:13.117 | File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/testtools/testcase.py", line 433, in assertThat
2015-03-05 15:33:13.117 | raise mismatch_error
2015-03-05 15:33:13.117 | MismatchError: is not:
2015-03-05 15:33:13.117 | reference = <nova.context.RequestContext object at 0x7f610d4b8650>
2015-03-05 15:33:13.117 | actual = <nova.context.RequestContext object at 0x7f610d4b1410>
2015-03-05 15:33:13.117 |
2015-03-05 15:33:13.117 | Traceback (most recent call last):
2015-03-05 15:33:13.117 | _StringException: Empty attachments:
2015-03-05 15:33:13.118 | pythonlogging:''
2015-03-05 15:33:13.118 | stderr
2015-03-05 15:33:13.118 | stdout

Looks like it's just this test:

http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOlwiRmlsZSBcXFwibm92YS90ZXN0cy91bml0L3Rlc3RfY29udGV4dC5weVxcXCIsIGxpbmVcIiBBTkQgYnVpbGRfcXVldWU6XCJnYXRlXCIgQU5EIHRhZ3M6XCJjb25zb2xlXCIgQU5EIGJ1aWxkX25hbWU6XCJnYXRlLW5vdmEtcHl0aG9uMjdcIiIsImZpZWxkcyI6W10sIm9mZnNldCI6MCwidGltZWZyYW1lIjoiNjA0ODAwIiwiZ3JhcGhtb2RlIjoiY291bnQiLCJ0aW1lIjp7InVzZXJfaW50ZXJ2YWwiOjB9LCJzdGFtcCI6MTQyNTU3MzEzNzE0NSwibW9kZSI6IiIsImFuYWx5emVfZmllbGQiOiIifQ==

18 hits in the last 7 days, 2 different changes in the gate hit on this.

Note that RequestContext doesn't implement __eq__ or __ne__.

[Matt Riedemann (mriedem)]

Started with this change:

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

So what does oslo_context do differently with it's store from what nova's old request context code did?

[Johannes Erdfelt (johannes.erdfelt)]

This has been failing on my review the last couple of times Jenkins has run unit tests against it:

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

If I run the full test suite on my development machine, then I can't reproduce it (the opposite behavior to infra Jenkins which seems to reliably trigger it when running the full test suite).

If I run just the nova.tests.unit.test_context.ContextTestCase.test_store_when_no_overwrite test, then it fails reliably for me.

I'm guessing either a race condition or something isn't cleaning up state in between tests correctly.

[Johannes Erdfelt (johannes.erdfelt)]

The test fails because it assumes that there is not already a context set, so overwrite=False would set it.

However, there is already a context set, so it doesn't get overwritten and the assertion fails.

Not immediately sure why there is a context set already even when this is the only test being run.

I'm guessing that some other test clears the context and that's why this test passes most of the time.

[Johannes Erdfelt (johannes.erdfelt)]

This is due to nova/tests/unit/api/openstack/compute/contrib/test_services.py:FakeRequest

It calls context.get_admin_context() as part of the construction of the class, which implicitly creates a context, which then gets registered.

The fix here is to either clear any contexts out before tests run, or to make FakeRequest (and there are some others) call get_admin_context() during __init__() instead.

[Johannes Erdfelt (johannes.erdfelt)]

There are also places like nova/tests/unit/db/test_db_api.py:_create_aggregate which calls get_admin_context() as a default value for an argument to a function.

Tackling all of the places that call get_admin_context() at import time would likely fix the problem at the expense of a lot of work, but it also won't prevent new uses from sneaking in.

I guess clearing out the context is the best short term solution.

We should really rethink how contexts work because side-effects like this are bad.

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Change abandoned by Johannes Erdfelt (<email address hidden>) on branch: master
Review: https://review.openstack.org/161800
Reason: Similar fix released in oslo.context instead

[Matt Riedemann (mriedem)]

Fixed here: https://review.openstack.org/#/c/161784/

[Matt Riedemann (mriedem)]

Released in 0.2.0:

https://pypi.python.org/pypi/oslo.context/0.2.0

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/oslo.context 0.2.0 release.