I'm not sure how much keystone can do to fix this. Keystone seems to be doing what is expected, but request latency could be causing skew to account for this case. One thing we might be able to do is bump up the user_lockout_duration from 5 to something greater. While that specific test will run slower, it will be isolated to that specific test.
[0] https://github.com/openstack/tempest/blob/b9b03484e50024112bd325182165945656be9f55/tempest/config.py#L182-L185 ** Changed in: keystone Status: New => Invalid -- You received this bug notification because you are a member of Yahoo! Engineering Team, which is subscribed to OpenStack Identity (keystone). https://bugs.launchpad.net/bugs/1693917 Title: test_user_account_lockout failed in gate because authN attempts took longer than usual Status in OpenStack Identity (keystone): Invalid Bug description: http://logs.openstack.org/99/460399/2/check/gate-tempest-dsvm-neutron- full-ubuntu-xenial/f7eb334/logs/testr_results.html.gz ft1.2: tempest.api.identity.v3.test_users.IdentityV3UsersTest.test_user_account_lockout[id-a7ad8bbf-2cff-4520-8c1d-96332e151658]_StringException: pythonlogging:'': {{{ 2017-05-24 21:05:50,147 32293 INFO [tempest.lib.common.rest_client] Request (IdentityV3UsersTest:test_user_account_lockout): 201 POST https://15.184.66.148/identity/v3/auth/tokens 2017-05-24 21:05:50,147 32293 DEBUG [tempest.lib.common.rest_client] Request - Headers: {'Accept': 'application/json', 'Content-Type': 'application/json'} Body: <omitted> Response - Headers: {u'vary': 'X-Auth-Token', 'content-location': 'https://15.184.66.148/identity/v3/auth/tokens', u'connection': 'close', u'content-length': '344', u'x-openstack-request-id': 'req-11e47cfa-6b25-47d4-977a-94f3e6d95665', 'status': '201', u'server': 'Apache/2.4.18 (Ubuntu)', u'date': 'Wed, 24 May 2017 21:05:50 GMT', u'x-subject-token': '<omitted>', u'content-type': 'application/json'} Body: {"token": {"issued_at": "2017-05-24T21:05:50.000000Z", "audit_ids": ["GQR0RZcDSWC_bslZSUzpGg"], "methods": ["password"], "expires_at": "2017-05-24T22:05:50.000000Z", "user": {"password_expires_at": null, "domain": {"id": "default", "name": "Default"}, "id": "415e3f0e215f44a586bdf62e7ea6e02d", "name": "tempest-IdentityV3UsersTest-343470382"}}} 2017-05-24 21:05:50,237 32293 INFO [tempest.lib.common.rest_client] Request (IdentityV3UsersTest:test_user_account_lockout): 401 POST https://15.184.66.148/identity/v3/auth/tokens 2017-05-24 21:05:50,238 32293 DEBUG [tempest.lib.common.rest_client] Request - Headers: {'Accept': 'application/json', 'Content-Type': 'application/json'} Body: <omitted> Response - Headers: {u'vary': 'X-Auth-Token', 'content-location': 'https://15.184.66.148/identity/v3/auth/tokens', u'connection': 'close', u'content-length': '114', u'x-openstack-request-id': 'req-0a45b9b8-4c7c-409c-9c8d-f6b2661c234f', 'status': '401', u'server': 'Apache/2.4.18 (Ubuntu)', u'date': 'Wed, 24 May 2017 21:05:50 GMT', u'content-type': 'application/json', u'www-authenticate': 'Keystone uri="https://15.184.66.148/identity";'} Body: {"error": {"message": "The request you have made requires authentication.", "code": 401, "title": "Unauthorized"}} 2017-05-24 21:05:54,909 32293 INFO [tempest.lib.common.rest_client] Request (IdentityV3UsersTest:test_user_account_lockout): 401 POST https://15.184.66.148/identity/v3/auth/tokens 2017-05-24 21:05:54,910 32293 DEBUG [tempest.lib.common.rest_client] Request - Headers: {'Accept': 'application/json', 'Content-Type': 'application/json'} Body: <omitted> Response - Headers: {u'vary': 'X-Auth-Token', 'content-location': 'https://15.184.66.148/identity/v3/auth/tokens', u'connection': 'close', u'content-length': '114', u'x-openstack-request-id': 'req-3dbd065f-826b-497d-86bc-2bc78a0de997', 'status': '401', u'server': 'Apache/2.4.18 (Ubuntu)', u'date': 'Wed, 24 May 2017 21:05:50 GMT', u'content-type': 'application/json', u'www-authenticate': 'Keystone uri="https://15.184.66.148/identity";'} Body: {"error": {"message": "The request you have made requires authentication.", "code": 401, "title": "Unauthorized"}} 2017-05-24 21:05:55,106 32293 INFO [tempest.lib.common.rest_client] Request (IdentityV3UsersTest:test_user_account_lockout): 201 POST https://15.184.66.148/identity/v3/auth/tokens 2017-05-24 21:05:55,106 32293 DEBUG [tempest.lib.common.rest_client] Request - Headers: {'Accept': 'application/json', 'Content-Type': 'application/json'} Body: <omitted> Response - Headers: {u'vary': 'X-Auth-Token', 'content-location': 'https://15.184.66.148/identity/v3/auth/tokens', u'connection': 'close', u'content-length': '344', u'x-openstack-request-id': 'req-1d367c81-2ffa-4812-904a-16be33d12fc0', 'status': '201', u'server': 'Apache/2.4.18 (Ubuntu)', u'date': 'Wed, 24 May 2017 21:05:54 GMT', u'x-subject-token': '<omitted>', u'content-type': 'application/json'} Body: {"token": {"issued_at": "2017-05-24T21:05:55.000000Z", "audit_ids": ["qlWnVS-MShm4hcBujHTL1g"], "methods": ["password"], "expires_at": "2017-05-24T22:05:55.000000Z", "user": {"password_expires_at": null, "domain": {"id": "default", "name": "Default"}, "id": "415e3f0e215f44a586bdf62e7ea6e02d", "name": "tempest-IdentityV3UsersTest-343470382"}}} }}} Traceback (most recent call last): File "tempest/api/identity/v3/test_users.py", line 154, in test_user_account_lockout password=password) File "/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/testtools/testcase.py", line 485, in assertRaises self.assertThat(our_callable, matcher) File "/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/testtools/testcase.py", line 498, in assertThat raise mismatch_error testtools.matchers._impl.MismatchError: <bound method V3TokenClient.auth of <tempest.lib.services.identity.v3.token_client.V3TokenClient object at 0x7f0083561c90>> returned {u'token': {u'expires_at': u'2017-05-24T22:05:55.000000Z', u'audit_ids': [u'qlWnVS-MShm4hcBujHTL1g'], u'issued_at': u'2017-05-24T21:05:55.000000Z', u'methods': [u'password'], u'user': {u'domain': {u'id': u'default', u'name': u'Default'}, u'id': u'415e3f0e215f44a586bdf62e7ea6e02d', u'password_expires_at': None, u'name': u'tempest-IdentityV3UsersTest-343470382'}}} The last authN attempt succeeded because it happened after lockout timeout (5 seconds). Looks like req-3dbd065f-826b-497d-86bc-2bc78a0de997 took longer than usual (~4seconds). To manage notifications about this bug go to: https://bugs.launchpad.net/keystone/+bug/1693917/+subscriptions -- Mailing list: https://launchpad.net/~yahoo-eng-team Post to : [email protected] Unsubscribe : https://launchpad.net/~yahoo-eng-team More help : https://help.launchpad.net/ListHelp
