Andal.LND/edx-platform
6
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Merge pull request #21217 from edx/iahmad/ENT-1954-Reformat-Logs-For-Enterprise-SSO-Workflows

Browse Source 
ENT-1954: Reformatted logging for third party auth
This commit is contained in:
irfanuddinahmad
2019-07-25 17:31:40 +05:00
committed by GitHub
parent 877168f72b df1c7f553a
commit a6045f9d13
3 changed files with 38 additions and 23 deletions
Download Patch File Download Diff File Expand all files Collapse all files

32
common/djangoapps/third_party_auth/pipeline.py
View File

@@ -554,6 +554,7 @@ def ensure_user_information(strategy, auth_entry, backend=None, user=None, socia
(current_provider.skip_email_verification or current_provider.send_to_registration_first))
def is_provider_saml():
""" Verify that the third party provider uses SAML """
current_provider = provider.Registry.get_from_pipeline({'backend': current_partial.backend, 'kwargs': kwargs})
saml_providers_list = list(provider.Registry.get_enabled_by_backend_name('tpa-saml'))
return (current_provider and
@@ -614,8 +615,8 @@ def ensure_user_information(strategy, auth_entry, backend=None, user=None, socia
# register anew via SSO. See SOL-1324 in JIRA.
# However, we will log a warning for this case:
logger.warning(
u'User "%s" is using third_party_auth to login but has not yet activated their account. ',
user.username
u'[THIRD_PARTY_AUTH] User is using third_party_auth to login but has not yet activated their account. '
u'Username: {username}'.format(username=user.username)
)
@@ -751,17 +752,25 @@ def user_details_force_sync(auth_entry, strategy, details, user=None, *args, **k
current_value = getattr(model, field)
if provider_value is not None and current_value != provider_value:
if field in integrity_conflict_fields and User.objects.filter(**{field: provider_value}).exists():
logger.warning(u'User with ID [%s] tried to synchronize profile data through [%s] '
u'but there was a conflict with an existing [%s]: [%s].',
user.id, current_provider.name, field, provider_value)
logger.warning(u'[THIRD_PARTY_AUTH] Profile data synchronization conflict. '
u'UserId: {user_id}, Provider: {provider}, ConflictField: {conflict_field}, '
u'ConflictValue: {conflict_value}'.format(
user_id=user.id,
provider=current_provider.name,
conflict_field=field,
conflict_value=provider_value))
continue
changed[provider_field] = current_value
setattr(model, field, provider_value)
if changed:
logger.info(
u"User [%s] performed SSO through [%s] who synchronizes profile data, and the "
u"following fields were changed: %s", user.username, current_provider.name, list(changed.keys()),
u'[THIRD_PARTY_AUTH] User performed SSO and data was synchronized. '
u'Username: {username}, Provider: {provider}, UpdatedKeys: {updated_keys}'.format(
username=user.username,
provider=current_provider.name,
updated_keys=list(changed.keys())
)
)
# Save changes to user and user.profile models.
@@ -786,8 +795,8 @@ def user_details_force_sync(auth_entry, strategy, details, user=None, *args, **k
try:
email.send()
except SMTPException:
logger.exception('Error sending IdP learner data sync-initiated email change '
u'notification email for user [%s].', user.username)
logger.exception('[THIRD_PARTY_AUTH] Error sending IdP learner data sync-initiated email change '
u'notification email. Username {username}'.format(username=user.username))
def set_id_verification_status(auth_entry, strategy, details, user=None, *args, **kwargs):
@@ -867,11 +876,10 @@ def get_username(strategy, details, backend, user=None, *args, **kwargs):
# The final_username may be empty and will skip the loop.
# We are using our own version of user_exists to avoid possible case sensitivity issues.
while not final_username or user_exists({'username': final_username}):
# These log statements are here for debugging purposes and should be removed when ENT-1500 is resolved.
logger.info(u'Username %s is either empty or already in use, generating a new username!', final_username)
username = short_username + uuid4().hex[:uuid_length]
final_username = slug_func(clean_func(username[:max_length]))
logger.info(u'Generated username %s.', final_username)
logger.info(u'[THIRD_PARTY_AUTH] New username generated. Username {username}'.format(
username=final_username))
else:
final_username = storage.user.get_username(user)
return {'username': final_username}

25
common/djangoapps/third_party_auth/saml.py
View File

@@ -94,7 +94,8 @@ class SAMLAuthBackend(SAMLAuth): # pylint: disable=abstract-method
return super(SAMLAuthBackend, self).get_user_id(details, response)
except KeyError as ex:
log.warning(
u"Error in SAML authentication flow of IdP '{idp_name}': {message}".format(
u'[THIRD_PARTY_AUTH] Error in SAML authentication flow. '
u'Provider: {idp_name}, Message: {message}'.format(
message=ex.message,
idp_name=response.get('idp_name')
)
@@ -124,7 +125,7 @@ class SAMLAuthBackend(SAMLAuth): # pylint: disable=abstract-method
raise Http404 if SAML authentication is disabled.
"""
if not self._config.enabled:
log.error('SAML authentication is not enabled')
log.error('[THIRD_PARTY_AUTH] SAML authentication is not enabled')
raise Http404
return super(SAMLAuthBackend, self).auth_url()
@@ -169,7 +170,11 @@ class SAMLAuthBackend(SAMLAuth): # pylint: disable=abstract-method
for expected in idp.conf['requiredEntitlements']:
if expected not in entitlements:
log.warning(
u"SAML user from IdP %s rejected due to missing eduPersonEntitlement %s", idp.name, expected)
u'[THIRD_PARTY_AUTH] SAML user rejected due to missing eduPersonEntitlement. '
u'Provider: {provider}, Entitlement: {entitlement}'.format(
provider=idp.name,
entitlement=expected)
)
raise AuthForbidden(self)
def _create_saml_auth(self, idp):
@@ -237,7 +242,8 @@ class EdXSAMLIdentityProvider(SAMLIdentityProvider):
try:
return attributes[key][0]
except IndexError:
log.warning(u'SAML attribute "%s" value not found.', key)
log.warning(u'[THIRD_PARTY_AUTH] SAML attribute value not found. '
u'SamlAttribute: {attribute}'.format(attribute=key))
return self.conf['attr_defaults'].get(conf_key) or None
@property
@@ -381,9 +387,10 @@ class SapSuccessFactorsIdentityProvider(EdXSAMLIdentityProvider):
if not all(var in self.conf for var in self.required_variables):
missing = [var for var in self.required_variables if var not in self.conf]
log.warning(
u"To retrieve rich user data for an SAP SuccessFactors identity provider, the following keys in "
u"'other_settings' are required, but were missing: %s",
missing
u'[THIRD_PARTY_AUTH] To retrieve rich user data for a SAP SuccessFactors identity provider, '
u'the following keys in other_settings are required, but were missing. MissingKeys: {keys}'.format(
keys=missing
)
)
return missing
@@ -562,7 +569,7 @@ def get_saml_idp_class(idp_identifier_string):
}
if idp_identifier_string not in choices:
log.error(
u'%s is not a valid EdXSAMLIdentityProvider subclass; using EdXSAMLIdentityProvider base class.',
idp_identifier_string
u'[THIRD_PARTY_AUTH] Invalid EdXSAMLIdentityProvider subclass--'
u'using EdXSAMLIdentityProvider base class. Provider: {provider}'.format(provider=idp_identifier_string)
)
return choices.get(idp_identifier_string, EdXSAMLIdentityProvider)

4
common/djangoapps/third_party_auth/tests/test_saml.py
View File

@@ -24,8 +24,8 @@ class TestEdXSAMLIdentityProvider(SAMLTestCase):
error_mock = log_mock.error
idp_class = get_saml_idp_class('fake_idp_class_option')
error_mock.assert_called_once_with(
u'%s is not a valid EdXSAMLIdentityProvider subclass; using EdXSAMLIdentityProvider base class.',
'fake_idp_class_option'
u'[THIRD_PARTY_AUTH] Invalid EdXSAMLIdentityProvider subclass--'
u'using EdXSAMLIdentityProvider base class. Provider: {provider}'.format(provider='fake_idp_class_option')
)
self.assertIs(idp_class, EdXSAMLIdentityProvider)