Add optional "debug mode" w/ detailed logging for SAML IdPs

common/djangoapps/third_party_auth/admin.py

@@ -53,8 +53,7 @@ class SAMLProviderConfigAdmin(KeyedConfigurationModelAdmin):
         """ Don't show every single field in the admin change list """
         return (
             'name', 'enabled', 'backend_name', 'entity_id', 'metadata_source',
-            'has_data', 'icon_class', 'icon_image', 'change_date',
-            'changed_by', 'edit_link'
+            'has_data', 'mode', 'change_date', 'changed_by', 'edit_link',
         )
 
     def has_data(self, inst):
@@ -66,6 +65,13 @@ class SAMLProviderConfigAdmin(KeyedConfigurationModelAdmin):
     has_data.short_description = u'Metadata Ready'
     has_data.boolean = True
 
+    def mode(self, inst):
+        """ Indicate if debug_mode is enabled or not"""
+        if inst.debug_mode:
+            return '<span style="color: red;">Debug</span>'
+        return "Normal"
+    mode.allow_tags = True
+
     def save_model(self, request, obj, form, change):
         """
         Post save: Queue an asynchronous metadata fetch to update SAMLProviderData.

common/djangoapps/third_party_auth/migrations/0003_samlproviderconfig_debug_mode.py

+# -*- coding: utf-8 -*-
+from __future__ import unicode_literals
+
+from django.db import migrations, models
+
+
+class Migration(migrations.Migration):
+
+    dependencies = [
+        ('third_party_auth', '0002_schema__provider_icon_image'),
+    ]
+
+    operations = [
+        migrations.AddField(
+            model_name='samlproviderconfig',
+            name='debug_mode',
+            field=models.BooleanField(default=False, help_text=b'In debug mode, all SAML XML requests and responses will be logged. This is helpful for testing/setup but should always be disabled before users start using this provider.', verbose_name=b'Debug Mode'),
+        ),
+    ]

common/djangoapps/third_party_auth/models.py

@@ -40,6 +40,14 @@ _PSA_OAUTH2_BACKENDS = [backend_class.name for backend_class in _load_backend_cl
 _PSA_SAML_BACKENDS = [backend_class.name for backend_class in _load_backend_classes(SAMLAuth)]
 _LTI_BACKENDS = [backend_class.name for backend_class in _load_backend_classes(LTIAuthBackend)]
 
+DEFAULT_SAML_CONTACT = {
+    # Default contact information to put into the SAML metadata that gets generated by python-saml.
+    "givenName": "{} Support".format(
+        configuration_helpers.get_value('PLATFORM_NAME', settings.PLATFORM_NAME),
+    ),
+    "emailAddress": configuration_helpers.get_value('TECH_SUPPORT_EMAIL', settings.TECH_SUPPORT_EMAIL),
+}
+
 
 def clean_json(value, of_type):
     """ Simple helper method to parse and clean JSON """
@@ -300,6 +308,13 @@ class SAMLProviderConfig(ProviderConfig):
     attr_email = models.CharField(
         max_length=128, blank=True, verbose_name="Email Attribute",
         help_text="URN of SAML attribute containing the user's email address[es]. Leave blank for default.")
+    debug_mode = models.BooleanField(
+        default=False, verbose_name="Debug Mode",
+        help_text=(
+            "In debug mode, all SAML XML requests and responses will be logged. "
+            "This is helpful for testing/setup but should always be disabled before users start using this provider."
+        ),
+    )
     other_settings = models.TextField(
         verbose_name="Advanced settings", blank=True,
         help_text=(
@@ -451,16 +466,13 @@ class SAMLConfiguration(ConfigurationModel):
                 return self.private_key
             # To allow instances to avoid storing keys in the DB, the private key can also be set via Django:
             return getattr(settings, 'SOCIAL_AUTH_SAML_SP_PRIVATE_KEY', '')
-        other_config = json.loads(self.other_config_str)
-        if name in ("TECHNICAL_CONTACT", "SUPPORT_CONTACT"):
-            contact = {
-                "givenName": "{} Support".format(
-                    configuration_helpers.get_value('PLATFORM_NAME', settings.PLATFORM_NAME),
-                ),
-                "emailAddress": settings.TECH_SUPPORT_EMAIL
-            }
-            contact.update(other_config.get(name, {}))
-            return contact
+        other_config = {
+            # These defaults can be overriden by self.other_config_str
+            "EXTRA_DATA": ["attributes"],  # Save all attribute values the IdP sends into the UserSocialAuth table
+            "TECHNICAL_CONTACT": DEFAULT_SAML_CONTACT,
+            "SUPPORT_CONTACT": DEFAULT_SAML_CONTACT,
+        }
+        other_config.update(json.loads(self.other_config_str))
         return other_config[name]  # SECURITY_CONFIG, SP_EXTRA, or similar extra settings
 
 

common/djangoapps/third_party_auth/saml.py

@@ -62,6 +62,34 @@ class SAMLAuthBackend(SAMLAuth):  # pylint: disable=abstract-method
                         "SAML user from IdP %s rejected due to missing eduPersonEntitlement %s", idp.name, expected)
                     raise AuthForbidden(self)
 
+    def _create_saml_auth(self, idp):
+        """
+        Get an instance of OneLogin_Saml2_Auth
+
+        idp: The Identity Provider - a social.backends.saml.SAMLIdentityProvider instance
+        """
+        # We only override this method so that we can add extra debugging when debug_mode is True
+        # Note that auth_inst is instantiated just for the current HTTP request, then is destroyed
+        auth_inst = super(SAMLAuthBackend, self)._create_saml_auth(idp)
+        from .models import SAMLProviderConfig
+        if SAMLProviderConfig.current(idp.name).debug_mode:
+
+            def wrap_with_logging(method_name, action_description, xml_getter):
+                """ Wrap the request and response handlers to add debug mode logging """
+                method = getattr(auth_inst, method_name)
+
+                def wrapped_method(*args, **kwargs):
+                    """ Wrapped login or process_response method """
+                    result = method(*args, **kwargs)
+                    log.info("SAML login %s for IdP %s. XML is:\n%s", action_description, idp.name, xml_getter())
+                    return result
+                setattr(auth_inst, method_name, wrapped_method)
+
+            wrap_with_logging("login", "request", auth_inst.get_last_request_xml)
+            wrap_with_logging("process_response", "response", auth_inst.get_last_response_xml)
+
+        return auth_inst
+
     @cached_property
     def _config(self):
         from .models import SAMLConfiguration

common/djangoapps/third_party_auth/tests/specs/base.py

@@ -102,7 +102,7 @@ class IntegrationTestMixin(object):
         self._test_return_login(user_is_activated=True)
 
     def test_login(self):
-        user = UserFactory.create()
+        self.user = UserFactory.create()  # pylint: disable=attribute-defined-outside-init
         # The user goes to the login page, and sees a button to login with this provider:
         provider_login_url = self._check_login_page()
         # The user clicks on the provider's button:
@@ -122,7 +122,7 @@ class IntegrationTestMixin(object):
         # The AJAX on the page will log them in:
         ajax_login_response = self.client.post(
             reverse('user_api_login_session'),
-            {'email': user.email, 'password': 'test'}
+            {'email': self.user.email, 'password': 'test'}
         )
         self.assertEqual(ajax_login_response.status_code, 200)
         # Then the AJAX will finish the third party auth:

common/djangoapps/third_party_auth/tests/specs/test_testshib.py

 """
 Third_party_auth integration tests using a mock version of the TestShib provider
 """
+import ddt
 import unittest
 import httpretty
 from mock import patch
+from social.apps.django_app.default.models import UserSocialAuth
 
+from third_party_auth.saml import log as saml_log
 from third_party_auth.tasks import fetch_saml_metadata
 from third_party_auth.tests import testutil
 
@@ -16,6 +19,7 @@ TESTSHIB_METADATA_URL = 'https://mock.testshib.org/metadata/testshib-providers.x
 TESTSHIB_SSO_URL = 'https://idp.testshib.org/idp/profile/SAML2/Redirect/SSO'
 
 
+@ddt.ddt
 @unittest.skipUnless(testutil.AUTH_FEATURE_ENABLED, 'third_party_auth not enabled')
 class TestShibIntegrationTest(IntegrationTestMixin, testutil.SAMLTestCase):
     """
@@ -24,6 +28,7 @@ class TestShibIntegrationTest(IntegrationTestMixin, testutil.SAMLTestCase):
     PROVIDER_ID = "saml-testshib"
     PROVIDER_NAME = "TestShib"
     PROVIDER_BACKEND = "tpa-saml"
+    PROVIDER_IDP_SLUG = "testshib"
 
     USER_EMAIL = "myself@testshib.org"
     USER_NAME = "Me Myself And I"
@@ -77,6 +82,47 @@ class TestShibIntegrationTest(IntegrationTestMixin, testutil.SAMLTestCase):
         self._configure_testshib_provider()
         super(TestShibIntegrationTest, self).test_register()
 
+    def test_login_records_attributes(self):
+        """
+        Test that attributes sent by a SAML provider are stored in the UserSocialAuth table.
+        """
+        self.test_login()
+        record = UserSocialAuth.objects.get(
+            user=self.user, provider=self.PROVIDER_BACKEND, uid__startswith=self.PROVIDER_IDP_SLUG
+        )
+        attributes = record.extra_data["attributes"]
+        self.assertEqual(
+            attributes.get("urn:oid:1.3.6.1.4.1.5923.1.1.1.9"), ["Member@testshib.org", "Staff@testshib.org"]
+        )
+        self.assertEqual(attributes.get("urn:oid:2.5.4.3"), ["Me Myself And I"])
+        self.assertEqual(attributes.get("urn:oid:0.9.2342.19200300.100.1.1"), ["myself"])
+        self.assertEqual(attributes.get("urn:oid:2.5.4.20"), ["555-5555"])  # Phone number
+
+    @ddt.data(True, False)
+    def test_debug_mode_login(self, debug_mode_enabled):
+        """ Test SAML login logs with debug mode enabled or not """
+        self._configure_testshib_provider(debug_mode=debug_mode_enabled)
+        with patch.object(saml_log, 'info') as mock_log:
+            super(TestShibIntegrationTest, self).test_login()
+        if debug_mode_enabled:
+            # We expect that test_login() does two full logins, and each attempt generates two
+            # logs - one for the request and one for the response
+            self.assertEqual(mock_log.call_count, 4)
+
+            (msg, action_type, idp_name, xml), _kwargs = mock_log.call_args_list[0]
+            self.assertTrue(msg.startswith("SAML login %s"))
+            self.assertEqual(action_type, "request")
+            self.assertEqual(idp_name, self.PROVIDER_IDP_SLUG)
+            self.assertIn('<samlp:AuthnRequest', xml)
+
+            (msg, action_type, idp_name, xml), _kwargs = mock_log.call_args_list[1]
+            self.assertTrue(msg.startswith("SAML login %s"))
+            self.assertEqual(action_type, "response")
+            self.assertEqual(idp_name, self.PROVIDER_IDP_SLUG)
+            self.assertIn('<saml2p:Response', xml)
+        else:
+            self.assertFalse(mock_log.called)
+
     def _freeze_time(self, timestamp):
         """ Mock the current time for SAML, so we can replay canned requests/responses """
         now_patch = patch('onelogin.saml2.utils.OneLogin_Saml2_Utils.now', return_value=timestamp)
@@ -86,9 +132,9 @@ class TestShibIntegrationTest(IntegrationTestMixin, testutil.SAMLTestCase):
     def _configure_testshib_provider(self, **kwargs):
         """ Enable and configure the TestShib SAML IdP as a third_party_auth provider """
         fetch_metadata = kwargs.pop('fetch_metadata', True)
-        kwargs.setdefault('name', 'TestShib')
+        kwargs.setdefault('name', self.PROVIDER_NAME)
         kwargs.setdefault('enabled', True)
-        kwargs.setdefault('idp_slug', 'testshib')
+        kwargs.setdefault('idp_slug', self.PROVIDER_IDP_SLUG)
         kwargs.setdefault('entity_id', TESTSHIB_ENTITY_ID)
         kwargs.setdefault('metadata_source', TESTSHIB_METADATA_URL)
         kwargs.setdefault('icon_class', 'fa-university')

requirements/edx/post.txt

@@ -4,9 +4,14 @@
 #   * @edx/ospr - to check licensing
 #   * @edx/devops - to check system requirements
 
-# This needs to be installed *after* lxml, which is in base.txt.
-# python-saml pulls in lxml as a dependency, and due to a bug in setuptools,
-# trying to compile lxml as a dependency causes setuptools to go into an
-# infinite loop and run out of memory. Because why would you trust a
-# dependency management tool to manage dependencies for you?
-python-saml==2.1.6
+# python-saml depends on lxml, which is referenced in base.txt. A bug exists
+# in setuptools 18.0.1 which results in an infinite loop during
+# resolution of this dependency during compilation. So we need to install
+# python-saml only after lxml has been successfully installed. 
+
+# In addition, we are currently utilizing a forked version of python-saml,
+# managed by OpenCraft, which features enhanced logging. We will return to
+# the official version of python-saml on PyPI when
+# https://github.com/onelogin/python-saml/pull/159 (or its derivative) has
+# been incorporated into the main project.
+git+https://github.com/open-craft/python-saml.git@87d4c18865e4997061ec62fd0e8d1e070b92e4e7#egg=python-saml==2.1.9