======================================================================
FAIL: keystone.tests.unit.test_v3_credential.TestCredentialAccessToken.test_access_token_ec2_credential
keystone.tests.unit.test_v3_credential.TestCredentialAccessToken.test_access_token_ec2_credential
----------------------------------------------------------------------
_StringException: pythonlogging:'': {{{
Adding standard routes to API credentials for `MethodViewType` (API Prefix: ) [/credentials, /credentials/<string:credential_id>]
Adding standard routes to API limits for `MethodViewType` (API Prefix: ) [/limits, /limits/<string:limit_id>]
Adding resource routes to API limits: ['/limits/model' {}]
Adding standard routes to API OS-OAUTH1 for `MethodViewType` (API Prefix: /OS-OAUTH1) [/consumers, /consumers/<string:consumer_id>]
Adding resource routes to API OS-OAUTH1: ['/request_token' {}]
Adding resource routes to API OS-OAUTH1: ['/access_token' {}]
Adding resource routes to API OS-OAUTH1: ['/authorize/<string:request_token_id>' {}]
Adding resource routes to API events: ['/events' {}]
Adding standard routes to API registered_limit for `MethodViewType` (API Prefix: ) [/registered_limits, /registered_limits/<string:registered_limit_id>]
Adding standard routes to API trusts for `MethodViewType` (API Prefix: /OS-TRUST) [/trusts, /trusts/<string:trust_id>]
Adding resource routes to API trusts: ['/trusts/<string:trust_id>/roles' {}]
Adding resource routes to API trusts: ['/trusts/<string:trust_id>/roles/<string:role_id>' {}]
Created a new temporary key: /tmp/tmpgj2rjeyh/tmp3x2i0zo7/0.tmp
Become a valid new key: /tmp/tmpgj2rjeyh/tmp3x2i0zo7/0
Starting key rotation with 1 key files: ['/tmp/tmpgj2rjeyh/tmp3x2i0zo7/0']
Created a new temporary key: /tmp/tmpgj2rjeyh/tmp3x2i0zo7/0.tmp
Current primary key is: 0
Next primary key will be: 1
Promoted key 0 to be the primary: 1
Become a valid new key: /tmp/tmpgj2rjeyh/tmp3x2i0zo7/0
Created a new temporary key: /tmp/tmpgj2rjeyh/tmp1343r7ur/0.tmp
Become a valid new key: /tmp/tmpgj2rjeyh/tmp1343r7ur/0
Starting key rotation with 1 key files: ['/tmp/tmpgj2rjeyh/tmp1343r7ur/0']
Created a new temporary key: /tmp/tmpgj2rjeyh/tmp1343r7ur/0.tmp
Current primary key is: 0
Next primary key will be: 1
Promoted key 0 to be the primary: 1
Become a valid new key: /tmp/tmpgj2rjeyh/tmp1343r7ur/0
Dispatching request to legacy mapper: /v3/auth
SCRIPT_NAME: `/v3`, PATH_INFO: `/auth/tokens`
POST http://localhost:80/v3/auth/tokens
MFA Rules not processed for user `f1e4d98104fd45ce88184cdb125b9f68`. Rule list: `[]` (Enabled: `True`).
Loaded 2 Fernet keys from /tmp/tmpgj2rjeyh/tmpxz02j3ma, but `[fernet_tokens] max_active_keys = 3`; perhaps there have not been enough key rotations to reach `max_active_keys` yet?
Authenticating user token
RBAC: auth_context: {'trust_id': None, 'trustor_id': None, 'trustee_id': None, 'domain_id': None, 'domain_name': None, 'group_ids': [], 'token': <TokenModel (audit_id=D7mMAt3-SW-5TOCVUiDraw, audit_chain_id=['D7mMAt3-SW-5TOCVUiDraw']) at 0x7f7fbe7dc5c0>, 'user_id': 'f1e4d98104fd45ce88184cdb125b9f68', 'user_domain_id': '0bbb35f29eda42309fe28fc589b8ed6c', 'system_scope': None, 'project_id': 'df4bece853e24d50af97fd9712786b91', 'project_domain_id': '0bbb35f29eda42309fe28fc589b8ed6c', 'roles': ['admin'], 'is_admin_project': True, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_id': None, 'service_project_domain_id': None, 'service_roles': []}
Dispatching back to Flask native app.
SCRIPT_NAME: ``, PATH_INFO: `/v3/OS-OAUTH1/consumers`
RBAC: Authorizing `identity:create_consumer()`
/usr/lib/python3/dist-packages/oslo_context/context.py:107: DeprecationWarning: Policy enforcement is depending on the value of trust_id. This key is deprecated. Please update your policy file to use the standard policy values.
  DeprecationWarning)

/usr/lib/python3/dist-packages/oslo_context/context.py:107: DeprecationWarning: Policy enforcement is depending on the value of trustor_id. This key is deprecated. Please update your policy file to use the standard policy values.
  DeprecationWarning)

/usr/lib/python3/dist-packages/oslo_context/context.py:107: DeprecationWarning: Policy enforcement is depending on the value of trustee_id. This key is deprecated. Please update your policy file to use the standard policy values.
  DeprecationWarning)

/usr/lib/python3/dist-packages/oslo_context/context.py:107: DeprecationWarning: Policy enforcement is depending on the value of domain_id. This key is deprecated. Please update your policy file to use the standard policy values.
  DeprecationWarning)

/usr/lib/python3/dist-packages/oslo_context/context.py:107: DeprecationWarning: Policy enforcement is depending on the value of domain_name. This key is deprecated. Please update your policy file to use the standard policy values.
  DeprecationWarning)

/usr/lib/python3/dist-packages/oslo_context/context.py:107: DeprecationWarning: Policy enforcement is depending on the value of group_ids. This key is deprecated. Please update your policy file to use the standard policy values.
  DeprecationWarning)

/usr/lib/python3/dist-packages/oslo_context/context.py:107: DeprecationWarning: Policy enforcement is depending on the value of token. This key is deprecated. Please update your policy file to use the standard policy values.
  DeprecationWarning)

RBAC: Policy Enforcement Cred Data `identity:create_consumer creds(trust_id=None, trustor_id=None, trustee_id=None, domain_id=None, domain_name=None, group_ids=[], token=*** (audit_id=D7mMAt3-SW-5TOCVUiDraw, audit_chain_id=['D7mMAt3-SW-5TOCVUiDraw']) at 0x7f7fbe7dc5c0>, user_id=f1e4d98104fd45ce88184cdb125b9f68, user_domain_id=0bbb35f29eda42309fe28fc589b8ed6c, system_scope=None, project_id=df4bece853e24d50af97fd9712786b91, project_domain_id=0bbb35f29eda42309fe28fc589b8ed6c, roles=['admin'], is_admin_project=True, service_user_id=None, service_user_domain_id=None, service_project_id=None, service_project_domain_id=None, service_roles=[])`
RBAC: Policy Enforcement Target Data `identity:create_consumer => target(consumer.description=d59d82ecc6e9487fa816c9cb0cf188e6)`
The policy file /<<PKGBUILDDIR>>/etc/policy.json could not be found.
/usr/lib/python3/dist-packages/oslo_policy/policy.py:896: UserWarning: Policy identity:create_consumer failed scope check. The token used to make the request was project scoped but the policy requires ['system'] scope. This behavior may change in the future where using the intended scope is required
  warnings.warn(msg)

RBAC: Authorization granted
Collected params: [('oauth_nonce', '50365890243650514161588676429'), ('oauth_timestamp', '1588676429'), ('oauth_version', '1.0'), ('oauth_signature_method', 'HMAC-SHA1'), ('oauth_consumer_key', 'ef73a40a001943cd99df5f8a6ced5e41'), ('oauth_callback', 'oob')]
Normalized params: oauth_callback=oob&oauth_consumer_key=ef73a40a001943cd99df5f8a6ced5e41&oauth_nonce=50365890243650514161588676429&oauth_signature_method=HMAC-SHA1&oauth_timestamp=1588676429&oauth_version=1.0
Normalized URI: http://localhost/v3/OS-OAUTH1/request_token
Signing: signature base string: POST&http%3A%2F%2Flocalhost%2Fv3%2FOS-OAUTH1%2Frequest_token&oauth_callback%3Doob%26oauth_consumer_key%3Def73a40a001943cd99df5f8a6ced5e41%26oauth_nonce%3D50365890243650514161588676429%26oauth_signature_method%3DHMAC-SHA1%26oauth_timestamp%3D1588676429%26oauth_version%3D1.0
Signature: rSwFQgLZwiFO0FDx2dCreOy2nFo=
Dispatching request to legacy mapper: /v3/auth
SCRIPT_NAME: `/v3`, PATH_INFO: `/auth/tokens`
POST http://localhost:80/v3/auth/tokens
MFA Rules not processed for user `f1e4d98104fd45ce88184cdb125b9f68`. Rule list: `[]` (Enabled: `True`).
Loaded 2 Fernet keys from /tmp/tmpgj2rjeyh/tmpxz02j3ma, but `[fernet_tokens] max_active_keys = 3`; perhaps there have not been enough key rotations to reach `max_active_keys` yet?
Authenticating user token
RBAC: auth_context: {'trust_id': None, 'trustor_id': None, 'trustee_id': None, 'domain_id': None, 'domain_name': None, 'group_ids': [], 'token': <TokenModel (audit_id=S9MraI4YSPu0dS9V0myekQ, audit_chain_id=['S9MraI4YSPu0dS9V0myekQ']) at 0x7f7fbda83128>, 'user_id': 'f1e4d98104fd45ce88184cdb125b9f68', 'user_domain_id': '0bbb35f29eda42309fe28fc589b8ed6c', 'system_scope': None, 'project_id': 'df4bece853e24d50af97fd9712786b91', 'project_domain_id': '0bbb35f29eda42309fe28fc589b8ed6c', 'roles': ['admin'], 'is_admin_project': True, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_id': None, 'service_project_domain_id': None, 'service_roles': []}
Dispatching back to Flask native app.
SCRIPT_NAME: ``, PATH_INFO: `/v3/OS-OAUTH1/request_token`
Dispatching request to legacy mapper: /v3/auth
SCRIPT_NAME: `/v3`, PATH_INFO: `/auth/tokens`
POST http://localhost:80/v3/auth/tokens
MFA Rules not processed for user `f1e4d98104fd45ce88184cdb125b9f68`. Rule list: `[]` (Enabled: `True`).
Loaded 2 Fernet keys from /tmp/tmpgj2rjeyh/tmpxz02j3ma, but `[fernet_tokens] max_active_keys = 3`; perhaps there have not been enough key rotations to reach `max_active_keys` yet?
Authenticating user token
RBAC: auth_context: {'trust_id': None, 'trustor_id': None, 'trustee_id': None, 'domain_id': None, 'domain_name': None, 'group_ids': [], 'token': <TokenModel (audit_id=q3vzfcECROagZib5j_yL1w, audit_chain_id=['q3vzfcECROagZib5j_yL1w']) at 0x7f7fbd84c390>, 'user_id': 'f1e4d98104fd45ce88184cdb125b9f68', 'user_domain_id': '0bbb35f29eda42309fe28fc589b8ed6c', 'system_scope': None, 'project_id': 'df4bece853e24d50af97fd9712786b91', 'project_domain_id': '0bbb35f29eda42309fe28fc589b8ed6c', 'roles': ['admin'], 'is_admin_project': True, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_id': None, 'service_project_domain_id': None, 'service_roles': []}
Dispatching back to Flask native app.
SCRIPT_NAME: ``, PATH_INFO: `/v3/OS-OAUTH1/authorize/1225c3da46984ff98dd5c246118b023a`
RBAC: Authorizing `identity:authorize_request_token(request_token_id=1225c3da46984ff98dd5c246118b023a)`
RBAC: Policy Enforcement Cred Data `identity:authorize_request_token creds(trust_id=None, trustor_id=None, trustee_id=None, domain_id=None, domain_name=None, group_ids=[], token=*** (audit_id=q3vzfcECROagZib5j_yL1w, audit_chain_id=['q3vzfcECROagZib5j_yL1w']) at 0x7f7fbd84c390>, user_id=f1e4d98104fd45ce88184cdb125b9f68, user_domain_id=0bbb35f29eda42309fe28fc589b8ed6c, system_scope=None, project_id=df4bece853e24d50af97fd9712786b91, project_domain_id=0bbb35f29eda42309fe28fc589b8ed6c, roles=['admin'], is_admin_project=True, service_user_id=None, service_user_domain_id=None, service_project_id=None, service_project_domain_id=None, service_roles=[])`
RBAC: Policy Enforcement Target Data `identity:authorize_request_token => target(request_token_id=1225c3da46984ff98dd5c246118b023a, roles=[{'id': '163653c3911b442181b07dc0e77649f4'}])`
RBAC: Authorization granted
Collected params: [('oauth_nonce', '1681792203298865891588676429'), ('oauth_timestamp', '1588676429'), ('oauth_version', '1.0'), ('oauth_signature_method', 'HMAC-SHA1'), ('oauth_consumer_key', 'ef73a40a001943cd99df5f8a6ced5e41'), ('oauth_token', '1225c3da46984ff98dd5c246118b023a'), ('oauth_verifier', 'qK935sES')]
Normalized params: oauth_consumer_key=ef73a40a001943cd99df5f8a6ced5e41&oauth_nonce=1681792203298865891588676429&oauth_signature_method=HMAC-SHA1&oauth_timestamp=1588676429&oauth_token=1225c3da46984ff98dd5c246118b023a&oauth_verifier=qK935sES&oauth_version=1.0
Normalized URI: http://localhost/v3/OS-OAUTH1/access_token
Signing: signature base string: POST&http%3A%2F%2Flocalhost%2Fv3%2FOS-OAUTH1%2Faccess_token&oauth_consumer_key%3Def73a40a001943cd99df5f8a6ced5e41%26oauth_nonce%3D1681792203298865891588676429%26oauth_signature_method%3DHMAC-SHA1%26oauth_timestamp%3D1588676429%26oauth_token%3D1225c3da46984ff98dd5c246118b023a%26oauth_verifier%3DqK935sES%26oauth_version%3D1.0
Signature: M5fHYSkp5kFNHMg4gDljD9fFXmw=
Dispatching request to legacy mapper: /v3/auth
SCRIPT_NAME: `/v3`, PATH_INFO: `/auth/tokens`
POST http://localhost:80/v3/auth/tokens
MFA Rules not processed for user `f1e4d98104fd45ce88184cdb125b9f68`. Rule list: `[]` (Enabled: `True`).
Loaded 2 Fernet keys from /tmp/tmpgj2rjeyh/tmpxz02j3ma, but `[fernet_tokens] max_active_keys = 3`; perhaps there have not been enough key rotations to reach `max_active_keys` yet?
Authenticating user token
RBAC: auth_context: {'trust_id': None, 'trustor_id': None, 'trustee_id': None, 'domain_id': None, 'domain_name': None, 'group_ids': [], 'token': <TokenModel (audit_id=UB_uwh5kSuSNPYVw0m1pNw, audit_chain_id=['UB_uwh5kSuSNPYVw0m1pNw']) at 0x7f7fbe2a9fd0>, 'user_id': 'f1e4d98104fd45ce88184cdb125b9f68', 'user_domain_id': '0bbb35f29eda42309fe28fc589b8ed6c', 'system_scope': None, 'project_id': 'df4bece853e24d50af97fd9712786b91', 'project_domain_id': '0bbb35f29eda42309fe28fc589b8ed6c', 'roles': ['admin'], 'is_admin_project': True, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_id': None, 'service_project_domain_id': None, 'service_roles': []}
Dispatching back to Flask native app.
SCRIPT_NAME: ``, PATH_INFO: `/v3/OS-OAUTH1/access_token`
Collected params: [('oauth_nonce', '149152655113413813721588676429'), ('oauth_timestamp', '1588676429'), ('oauth_version', '1.0'), ('oauth_signature_method', 'HMAC-SHA1'), ('oauth_consumer_key', 'ef73a40a001943cd99df5f8a6ced5e41'), ('oauth_token', 'b80760190cc94237ba0bf6de71fd4c81')]
Normalized params: oauth_consumer_key=ef73a40a001943cd99df5f8a6ced5e41&oauth_nonce=149152655113413813721588676429&oauth_signature_method=HMAC-SHA1&oauth_timestamp=1588676429&oauth_token=b80760190cc94237ba0bf6de71fd4c81&oauth_version=1.0
Normalized URI: http://localhost/v3/auth/tokens
Signing: signature base string: POST&http%3A%2F%2Flocalhost%2Fv3%2Fauth%2Ftokens&oauth_consumer_key%3Def73a40a001943cd99df5f8a6ced5e41%26oauth_nonce%3D149152655113413813721588676429%26oauth_signature_method%3DHMAC-SHA1%26oauth_timestamp%3D1588676429%26oauth_token%3Db80760190cc94237ba0bf6de71fd4c81%26oauth_version%3D1.0
Signature: VfvdV3E7ZXsC9z8aTi26xUUi+wo=
Dispatching request to legacy mapper: /v3/auth
SCRIPT_NAME: `/v3`, PATH_INFO: `/auth/tokens`
POST http://localhost:80/v3/auth/tokens
MFA Rules not processed for user `f1e4d98104fd45ce88184cdb125b9f68`. Rule list: `[]` (Enabled: `True`).
Loaded 2 Fernet keys from /tmp/tmpgj2rjeyh/tmpxz02j3ma, but `[fernet_tokens] max_active_keys = 3`; perhaps there have not been enough key rotations to reach `max_active_keys` yet?
Authenticating user token
RBAC: auth_context: {'trust_id': None, 'trustor_id': None, 'trustee_id': None, 'domain_id': None, 'domain_name': None, 'group_ids': [], 'token': <TokenModel (audit_id=WnOwPApIQkKGvadO-AdxAA, audit_chain_id=['WnOwPApIQkKGvadO-AdxAA']) at 0x7f7fbead81d0>, 'user_id': 'f1e4d98104fd45ce88184cdb125b9f68', 'user_domain_id': '0bbb35f29eda42309fe28fc589b8ed6c', 'system_scope': None, 'project_id': 'df4bece853e24d50af97fd9712786b91', 'project_domain_id': '0bbb35f29eda42309fe28fc589b8ed6c', 'roles': ['admin'], 'is_admin_project': True, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_id': None, 'service_project_domain_id': None, 'service_roles': []}
Dispatching request to legacy mapper: /v3/auth
SCRIPT_NAME: `/v3`, PATH_INFO: `/auth/tokens`
POST http://localhost:80/v3/auth/tokens
MFA Rules not processed for user `f1e4d98104fd45ce88184cdb125b9f68`. Rule list: `[]` (Enabled: `True`).
Loaded 2 Fernet keys from /tmp/tmpgj2rjeyh/tmpxz02j3ma, but `[fernet_tokens] max_active_keys = 3`; perhaps there have not been enough key rotations to reach `max_active_keys` yet?
Authenticating user token
RBAC: auth_context: {'trust_id': None, 'trustor_id': None, 'trustee_id': None, 'domain_id': None, 'domain_name': None, 'group_ids': [], 'token': <TokenModel (audit_id=heCpFSyfTV-MNMKMiFWs1A, audit_chain_id=['heCpFSyfTV-MNMKMiFWs1A']) at 0x7f7fbd84c6a0>, 'user_id': 'f1e4d98104fd45ce88184cdb125b9f68', 'user_domain_id': '0bbb35f29eda42309fe28fc589b8ed6c', 'system_scope': None, 'project_id': 'df4bece853e24d50af97fd9712786b91', 'project_domain_id': '0bbb35f29eda42309fe28fc589b8ed6c', 'roles': ['admin'], 'is_admin_project': True, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_id': None, 'service_project_domain_id': None, 'service_roles': []}
Dispatching back to Flask native app.
SCRIPT_NAME: ``, PATH_INFO: `/v3/credentials`
RBAC: Authorizing `identity:create_credential()`
RBAC: Policy Enforcement Cred Data `identity:create_credential creds(trust_id=None, trustor_id=None, trustee_id=None, domain_id=None, domain_name=None, group_ids=[], token=*** (audit_id=heCpFSyfTV-MNMKMiFWs1A, audit_chain_id=['heCpFSyfTV-MNMKMiFWs1A']) at 0x7f7fbd84c6a0>, user_id=f1e4d98104fd45ce88184cdb125b9f68, user_domain_id=0bbb35f29eda42309fe28fc589b8ed6c, system_scope=None, project_id=df4bece853e24d50af97fd9712786b91, project_domain_id=0bbb35f29eda42309fe28fc589b8ed6c, roles=['admin'], is_admin_project=True, service_user_id=None, service_user_domain_id=None, service_project_id=None, service_project_domain_id=None, service_roles=[])`
RBAC: Policy Enforcement Target Data `identity:create_credential => target(credential.id=d863617c3c059810bb227b680393cdc762575c3d9acb5f89f300537feea2bae2, credential.user_id=f1e4d98104fd45ce88184cdb125b9f68, credential.type=ec2, credential.project_id=df4bece853e24d50af97fd9712786b91, credential.blob={"access": "1c90a04605c743fe9d432276f69e7685", "secret": "***", "trust_id": null})`
RBAC: Authorization granted
Dispatching request to legacy mapper: /v3/auth
SCRIPT_NAME: `/v3`, PATH_INFO: `/auth/tokens`
POST http://localhost:80/v3/auth/tokens
MFA Rules not processed for user `f1e4d98104fd45ce88184cdb125b9f68`. Rule list: `[]` (Enabled: `True`).
Loaded 2 Fernet keys from /tmp/tmpgj2rjeyh/tmpxz02j3ma, but `[fernet_tokens] max_active_keys = 3`; perhaps there have not been enough key rotations to reach `max_active_keys` yet?
Authenticating user token
RBAC: auth_context: {'trust_id': None, 'trustor_id': None, 'trustee_id': None, 'domain_id': None, 'domain_name': None, 'group_ids': [], 'token': <TokenModel (audit_id=4fpz_CP_Rqm0m3f_qrseiQ, audit_chain_id=['4fpz_CP_Rqm0m3f_qrseiQ']) at 0x7f7fbd800630>, 'user_id': 'f1e4d98104fd45ce88184cdb125b9f68', 'user_domain_id': '0bbb35f29eda42309fe28fc589b8ed6c', 'system_scope': None, 'project_id': 'df4bece853e24d50af97fd9712786b91', 'project_domain_id': '0bbb35f29eda42309fe28fc589b8ed6c', 'roles': ['admin', 'reader'], 'is_admin_project': True, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_id': None, 'service_project_domain_id': None, 'service_roles': []}
Dispatching request to legacy mapper: /v3/ec2tokens
SCRIPT_NAME: `/v3`, PATH_INFO: `/ec2tokens`
POST http://localhost:80/v3/ec2tokens
Loaded 2 Fernet keys from /tmp/tmpgj2rjeyh/tmpxz02j3ma, but `[fernet_tokens] max_active_keys = 3`; perhaps there have not been enough key rotations to reach `max_active_keys` yet?
}}}

Traceback (most recent call last):
  File "/<<PKGBUILDDIR>>/keystone/tests/unit/test_v3_credential.py", line 937, in test_access_token_ec2_credential
    self.assertNotIn(role_id, ec2_roles)
  File "/usr/lib/python3/dist-packages/testtools/testcase.py", line 455, in assertNotIn
    self.assertThat(haystack, matcher, message)
  File "/usr/lib/python3/dist-packages/testtools/testcase.py", line 498, in assertThat
    raise mismatch_error
testtools.matchers._impl.MismatchError: ['163653c3911b442181b07dc0e77649f4', '7f559f981e024c8fa6ce2a5be99e62d2'] matches Contains('7f559f981e024c8fa6ce2a5be99e62d2')