test_revoke.RevokeTreeTests.test_cleanup fails

[Steve Martinelli]

As seen in http://logs.openstack.org/69/83169/3/check/gate-keystone-python27/160e2d4/console.html

Additional logs: http://logs.openstack.org/69/83169/3/check/gate-keystone-python27/160e2d4/

The following test fails:

2014-04-01 03:37:31.236 | ======================================================================
2014-04-01 03:37:31.236 | FAIL: keystone.tests.test_revoke.RevokeTreeTests.test_cleanup
2014-04-01 03:37:31.236 | tags: worker-3
2014-04-01 03:37:31.236 | ----------------------------------------------------------------------
2014-04-01 03:37:31.236 | Empty attachments:
2014-04-01 03:37:31.236 | pythonlogging:''-1
2014-04-01 03:37:31.236 | stderr
2014-04-01 03:37:31.236 | stdout
2014-04-01 03:37:31.236 |
2014-04-01 03:37:31.237 | pythonlogging:'': {{{Adding cache-proxy 'keystone.tests.test_cache.CacheIsolatingProxy' to backend.}}}
2014-04-01 03:37:31.237 |
2014-04-01 03:37:31.237 | Traceback (most recent call last):
2014-04-01 03:37:31.237 | File "keystone/tests/test_revoke.py", line 457, in test_cleanup
2014-04-01 03:37:31.237 | self._assertEventsMatchIteration(i + 1)
2014-04-01 03:37:31.237 | File "keystone/tests/test_revoke.py", line 418, in _assertEventsMatchIteration
2014-04-01 03:37:31.237 | ['access_token_id=*']))
2014-04-01 03:37:31.237 | File "/home/jenkins/workspace/gate-keystone-python27/.tox/py27/local/lib/python2.7/site-packages/testtools/testcase.py", line 321, in assertEqual
2014-04-01 03:37:31.237 | self.assertThat(observed, matcher, message)
2014-04-01 03:37:31.237 | File "/home/jenkins/workspace/gate-keystone-python27/.tox/py27/local/lib/python2.7/site-packages/testtools/testcase.py", line 406, in assertThat
2014-04-01 03:37:31.237 | raise mismatch_error
2014-04-01 03:37:31.237 | MismatchError: 3 != 2
2014-04-01 03:37:31.238 | ======================================================================
2014-04-01 03:37:31.238 | FAIL: process-returncode
2014-04-01 03:37:31.238 | tags: worker-3
2014-04-01 03:37:31.238 | ----------------------------------------------------------------------

[Dolph Mathews (dolph)]

Is this a result of https://review.openstack.org/#/c/83584/ ? Or is this an issue in milestone-proposed?

[Steve Martinelli (stevemar)]

Dolph, I'm not sure, by gut feeling was https://review.openstack.org/#/c/83584/

but https://review.openstack.org/#/c/82917/ also crossed my mind.

[Dolph Mathews (dolph)]

As long as it's not an issue in icehouse-rc1 / milestone-proposed :)

[Morgan Fainberg (mdrnstm)]

I would say this is a concurrency one. The in-memory SQLite is would generate (in most cases) significantly more issues if it wasn't being torn down as expected.

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/86472
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=455cc04611be675567927297265418bef8538165
Submitter: Jenkins
Branch: master

commit 455cc04611be675567927297265418bef8538165
Author: Brant Knudson <email address hidden>
Date: Wed Apr 9 18:53:33 2014 -0500

    More debug output for test

    This is to see if we can get some more info when this fails.

    Related-Bug: #1300581

    Change-Id: I9be3784095cfd8f04f3a49ae7e9d39520018b4da

[Openstack Gerrit (openstack-gerrit)]

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

[Openstack Gerrit (openstack-gerrit)]

Reviewed: https://review.openstack.org/90224
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=5fbb0a28bc40d3e30b416a284cbe63f233cca39e
Submitter: Jenkins
Branch: master

commit 5fbb0a28bc40d3e30b416a284cbe63f233cca39e
Author: Adam Young <email address hidden>
Date: Thu Apr 24 16:15:06 2014 -0400

    Make test_revoke expiry times distinct

    Calling _future_time had the possibility of returning the same value
    if it is called between clock ticks. It appears to be happening in
    gate, potentially due to being run in a VM.

    Instead, for the loop that revokes distinct events,
    Assign each a different expires_at time.

    Change-Id: Iab7ed92bb1e142651265a167ae73d6d1225b01a9
    Closes-Bug: #1300581

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/icehouse
Review: https://review.openstack.org/112102

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/112102
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=c900a6ef25f213807d964c86682b3d35b74c7d2d
Submitter: Jenkins
Branch: stable/icehouse

commit c900a6ef25f213807d964c86682b3d35b74c7d2d
Author: Adam Young <email address hidden>
Date: Thu Apr 24 16:15:06 2014 -0400

    Make test_revoke expiry times distinct

    Calling _future_time had the possibility of returning the same value
    if it is called between clock ticks. It appears to be happening in
    gate, potentially due to being run in a VM.

    Instead, for the loop that revokes distinct events,
    Assign each a different expires_at time.

    Conflicts:

     keystone/tests/test_revoke.py

    Change-Id: Iab7ed92bb1e142651265a167ae73d6d1225b01a9
    Closes-Bug: #1300581
    (cherry picked from commit 5fbb0a28bc40d3e30b416a284cbe63f233cca39e)

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Change abandoned by Ryan Hsu (<email address hidden>) on branch: master
Review: https://review.openstack.org/121711
Reason: Testing