Browse Source

Add debug logging to revocation event checking

Previously, the revocation matching engine was basically a black box
that seemed to mysteriously match some tokens and not others, and it was
difficult to understand why an event would match a given token at a
glance. Fixed.

Change-Id: I751d891dc1cec2bb22ad6a3948aafaa34fc835d1
changes/42/353742/5
Dolph Mathews 6 years ago committed by David Stanek
parent
commit
d2ee07b8e7
  1. 97
      keystone/models/revoke_model.py

97
keystone/models/revoke_model.py

@ -159,12 +159,11 @@ def is_revoked(events, token_data):
def matches(event, token_values):
"""See if the token matches the revocation event.
A brute force approach to checking.
Compare each attribute from the event with the corresponding
value from the token. If the event does not have a value for
the attribute, a match is still possible. If the event has a
value for the attribute, and it does not match the token, no match
is possible, so skip the remaining checks.
A brute force approach to checking. Compare each attribute from the event
with the corresponding value from the token. If the event does not have a
value for the attribute, a match is still possible. If the event has a
value for the attribute, and it does not match the token, no match is
possible, so skip the remaining checks.
:param event: a RevokeEvent instance
:param token_values: dictionary with set of values taken from the
@ -172,65 +171,143 @@ def matches(event, token_values):
:returns: True if the token matches the revocation event, indicating the
token has been revoked
"""
# If any one check does not match, the whole token does
# not match the event. The numerous return False indicate
# that the token is still valid and short-circuits the
# rest of the logic.
# If any one check does not match, the whole token does not match the
# event. The numerous return False indicate that the token is still valid
# and short-circuits the rest of the logic.
# The token has three attributes that can match the user_id.
if event.user_id is not None and event.user_id not in (
token_values['user_id'],
token_values['trustor_id'],
token_values['trustee_id'],):
LOG.debug(
'The user (id=%s) in the revocation event does not match any user '
'(user_id=%s, trustor_id=%s, trustee_id=%s) in the token.',
event.user_id,
token_values['user_id'],
token_values['trustor_id'],
token_values['trustee_id'])
return False
# The token has two attributes that can match the domain_id.
if event.domain_id is not None and event.domain_id not in(
token_values['identity_domain_id'],
token_values['assignment_domain_id'],):
LOG.debug(
'The domain (id=%s) in the revocation event does not match any '
'domain (identity_domain_id=%s, assignment_domain_id=%s) in the '
'token.',
event.domain_id,
token_values['identity_domain_id'],
token_values['assignment_domain_id'])
return False
if event.domain_scope_id is not None and event.domain_scope_id not in (
token_values['assignment_domain_id'],):
LOG.debug(
'The domain scope (id=%s) in the revocation event does not match '
'the domain scope (id=%s) in the token.',
event.domain_scope_id,
token_values['assignment_domain_id'])
return False
# If an event specifies an attribute name, but it does not match, the token
# is not revoked.
if event.project_id is not None and event.project_id not in (
token_values['project_id'],):
LOG.debug(
'The project ID (%s) in the revocation event does not match the '
'project ID (%s) in the token.',
event.project_id,
token_values['project_id'])
return False
if event.expires_at is not None and event.expires_at not in (
token_values['expires_at'],):
LOG.debug(
'The expiration (id=%s) in the revocation event does not match '
'the expiration (at=%s) of the token.',
event.expires_at,
token_values['expires_at'])
return False
if event.trust_id is not None and event.trust_id not in (
token_values['trust_id'],):
LOG.debug(
'The trust (id=%s) in the revocation event does not match the '
'trust (id=%s) in the token.',
event.trust_id,
token_values['trust_id'])
return False
if event.consumer_id is not None and event.consumer_id not in (
token_values['consumer_id'],):
LOG.debug(
'The OAuth consumer (id=%s) in the revocation event does not '
'match the OAuth consumer ID (id=%s) in the token.',
event.consumer_id,
token_values['consumer_id'])
return False
if event.access_token_id is not None and event.access_token_id not in (
token_values['access_token_id'],):
LOG.debug(
'The OAuth access token (id=%s) in the revocation event does not '
'match the OAuth access token (id=%s) in the token.',
event.access_token_id,
token_values['access_token_id'])
return False
if event.audit_id is not None and event.audit_id not in (
token_values['audit_id'],):
LOG.debug(
'The audit (id=%s) in the revocation event does not match the '
'audit (id=%s) in the token.',
event.audit_id,
token_values['audit_id'])
return False
if event.audit_chain_id is not None and event.audit_chain_id not in (
token_values['audit_chain_id'],):
LOG.debug(
'The audit chain (id=%s) in the revocation event does not match '
'the audit chain (id=%s) in the token.',
event.audit_chain_id,
token_values['audit_chain_id'])
return False
if event.role_id is not None and event.role_id not in (
token_values['roles']):
if LOG.logger.getEffectiveLevel() <= log.DEBUG:
# The string formatting here needs to be conditional, so that the
# extra work can be skipped if DEBUG logs are not actually being
# written anywhere.
role_ids = ', '.join('id=%s' % x for x in token_values['roles'])
LOG.debug(
'The role (id=%s) in the revocation event does not match any '
'of the roles (%s) in the token.',
event.role_id,
role_ids)
return False
if token_values['issued_at'] > event.issued_before:
LOG.debug(
'The token was created (%s) after the revocation event was issued '
'(%s).',
token_values['issued_at'],
event.issued_before)
return False
if LOG.logger.getEffectiveLevel() <= log.DEBUG:
# The string formatting here needs to be conditional, so that the
# extra work can be skipped if DEBUG logs are not actually being
# written anywhere.
event_dict = event.to_dict()
attrs = ', '.join('='.join(item) for item in event_dict.items())
LOG.debug(
'All attributes (%s) in the revocation event are in the token.',
attrs, )
return True

Loading…
Cancel
Save