local tests failing fernet tests

[Brant Knudson]

When running local tests with tox -e py27, several fernet tests are failing:

keystone.tests.unit.test_v3_auth.TestFernetTokenProvider.test_project_scoped_token_invalid_after_disabling_project
keystone.tests.unit.test_v3_auth.TestFernetTokenProvider.test_revoke_project_scoped_token
keystone.tests.unit.test_v3_auth.TestFernetTokenProvider.test_unscoped_token_is_invalid_after_changing_user_password
keystone.tests.unit.test_v3_auth.TestFernetTokenProvider.test_trust_scoped_token_is_invalid_after_disabling_trustor
keystone.tests.unit.test_v3_auth.TestFernetTokenProvider.test_unscoped_token_is_invalid_after_disabling_user
keystone.tests.unit.test_v3_auth.TestFernetTokenProvider.test_unscoped_token_is_invalid_after_disabling_user_domain
keystone.tests.unit.test_v3_auth.TestFernetTokenProvider.test_domain_scoped_token_is_invalid_after_deleting_grant
keystone.tests.unit.test_v3_auth.TestFernetTokenProvider.test_domain_scoped_token_invalid_after_disabling_domain
keystone.tests.unit.test_v3_auth.TestFernetTokenProvider.test_domain_scoped_token_is_invalid_after_disabling_user
keystone.tests.unit.test_v3_auth.TestFernetTokenProvider.test_trust_scoped_token_invalid_after_disabled_trustor_domain
keystone.tests.unit.test_v3_auth.TestFernetTokenProvider.test_project_scoped_token_invalid_after_changing_user_password
keystone.tests.unit.test_v3_auth.TestFernetTokenProvider.test_trust_scoped_token_invalid_after_changing_trustee_password
keystone.tests.unit.test_v3_auth.TestFernetTokenProvider.test_revoke_unscoped_token
keystone.tests.unit.test_v3_auth.TestFernetTokenProvider.test_trust_scoped_token_invalid_after_changing_trustor_password
keystone.tests.unit.test_v3_auth.TestFernetTokenProvider.test_trust_scoped_token_is_invalid_after_disabling_trustee
keystone.tests.unit.test_v3_auth.TestFernetTokenProvider.test_unscoped_token_is_invalid_after_enabling_disabled_user

Here's an example:

keystone.tests.unit.token.test_fernet_provider.TestBaseTokenFormatter.test_time_string_to_int_conversions
---------------------------------------------------------------------------------------------------------

Captured traceback:
~~~~~~~~~~~~~~~~~~~
    Traceback (most recent call last):
    _StringException: Empty attachments:
      pythonlogging:''-1
      stderr
      stdout

    pythonlogging:'': {{{
    Adding cache-proxy 'keystone.tests.unit.test_cache.CacheIsolatingProxy' to backend.
    Created a new key: /tmp/tmpDxjwUU/tmpUgUvin/0
    Starting key rotation with 1 key files: ['/tmp/tmpDxjwUU/tmpUgUvin/0']
    Current primary key is: 0
    Next primary key will be: 1
    Promoted key 0 to be the primary: 1
    Created a new key: /tmp/tmpDxjwUU/tmpUgUvin/0
    Excess keys to purge: []
    }}}

    Traceback (most recent call last):
      File "keystone/tests/unit/token/test_fernet_provider.py", line 105, in test_time_string_to_int_conversions
        self.assertEqual(expected_time_str, actual_time_str)
      File "/opt/stack/keystone/.tox/py27/local/lib/python2.7/site-packages/testtools/testcase.py", line 348, in assertEqual
        self.assertThat(observed, matcher, message)
      File "/opt/stack/keystone/.tox/py27/local/lib/python2.7/site-packages/testtools/testcase.py", line 433, in assertThat
        raise mismatch_error
    MismatchError: '2015-03-08T22:13:49Z' != '2015-03-08T23:13:49Z'

    Traceback (most recent call last):
    _StringException: Empty attachments:
      pythonlogging:''-1
      stderr
      stdout

    pythonlogging:'': {{{
    Adding cache-proxy 'keystone.tests.unit.test_cache.CacheIsolatingProxy' to backend.
    Created a new key: /tmp/tmpDxjwUU/tmpUgUvin/0
    Starting key rotation with 1 key files: ['/tmp/tmpDxjwUU/tmpUgUvin/0']
    Current primary key is: 0
    Next primary key will be: 1
    Promoted key 0 to be the primary: 1
    Created a new key: /tmp/tmpDxjwUU/tmpUgUvin/0
    Excess keys to purge: []
    }}}

    Traceback (most recent call last):
      File "keystone/tests/unit/token/test_fernet_provider.py", line 105, in test_time_string_to_int_conversions
        self.assertEqual(expected_time_str, actual_time_str)
      File "/opt/stack/keystone/.tox/py27/local/lib/python2.7/site-packages/testtools/testcase.py", line 348, in assertEqual
        self.assertThat(observed, matcher, message)
      File "/opt/stack/keystone/.tox/py27/local/lib/python2.7/site-packages/testtools/testcase.py", line 433, in assertThat
        raise mismatch_error
    MismatchError: '2015-03-08T22:13:49Z' != '2015-03-08T23:13:49Z'

It's off by an hour for some reason.

[Dolph Mathews (dolph)]

Marking this as High because it doesn't look like the issue is isolated to tests - we're actually reading/writing the time wrong in the payload.

[Dolph Mathews (dolph)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/162489
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=7ef4119981408e79404057052a0377ee35310527
Submitter: Jenkins
Branch: master

commit 7ef4119981408e79404057052a0377ee35310527
Author: Brant Knudson <email address hidden>
Date: Sun Mar 8 16:51:14 2015 -0500

    Fix seconds since epoch use in fernet tokens

    The fernet code wasn't using seconds since the epoch correctly.
    The seconds since epoch doesn't depend on the timezone, but the
    time int calculated by the fernet functions was based on the local
    time of the system.

    This was causing local unit tests to fail.

    Closes-Bug: 1429663
    Change-Id: I56757e9636e7baf46eeb1657dab209616e310672