mattdrayer/ENT-686: Enhanced logging for SuccessFactors exceptions

common/djangoapps/third_party_auth/saml.py

@@ -231,10 +231,10 @@ class SapSuccessFactorsIdentityProvider(EdXSAMLIdentityProvider):
     def odata_client_id(self):
         return self.conf['odata_client_id']
 
-    def missing_variables(self):
+    def invalid_configuration(self):
         """
         Check that we have all the details we need to properly retrieve rich data from the
-        SAP SuccessFactors OData API. If we don't, then we should log a warning indicating
+        SAP SuccessFactors BizX OData API. If we don't, then we should log a warning indicating
         the specific variables that are missing.
         """
         if not all(var in self.conf for var in self.required_variables):
@@ -246,85 +246,136 @@ class SapSuccessFactorsIdentityProvider(EdXSAMLIdentityProvider):
             )
             return missing
 
-    def get_odata_api_client(self, user_id):
+    def log_bizx_api_exception(self, transaction_data, err):
+        sys_msg = err.response.json() if err.response else 'Not available'
+        headers = err.response.headers if err.response else 'Not available'
+        token_data = transaction_data.get('token_data')
+        token_data = token_data if token_data else 'Not available'
+        log_msg_template = (
+            'SAPSuccessFactors exception received for {operation_name} request.  ' +
+            'URL: {url}  ' +
+            'Company ID: {company_id}.  ' +
+            'User ID: {user_id}.  ' +
+            'Error message: {err_msg}.  ' +
+            'System message: {sys_msg}.  ' +
+            'Headers: {headers}.  ' +
+            'Token Data: {token_data}.'
+        )
+        log_msg = log_msg_template.format(
+            operation_name=transaction_data['operation_name'],
+            url=transaction_data['endpoint_url'],
+            company_id=transaction_data['company_id'],
+            user_id=transaction_data['user_id'],
+            err_msg=err.message,
+            sys_msg=sys_msg,
+            headers=headers,
+            token_data=token_data,
+        )
+        log.warning(log_msg, exc_info=True)
+
+    def generate_bizx_oauth_api_saml_assertion(self, user_id):
         """
-        Get a Requests session with the headers needed to properly authenticate it with
-        the SAP SuccessFactors OData API.
+        Obtain a SAML assertion from the SAP SuccessFactors BizX OAuth2 identity provider service using
+        information specified in the third party authentication configuration "Advanced Settings" section.
         """
         session = requests.Session()
-        assertion = session.post(
-            self.sapsf_idp_url,
-            data={
+        transaction_data = {
+            'operation_name': 'generate_bizx_oauth_api_saml_assertion',
+            'endpoint_url': self.sapsf_idp_url,
+            'token_url': self.sapsf_token_url,
+            'company_id': self.odata_company_id,
             'client_id': self.odata_client_id,
             'user_id': user_id,
-                'token_url': self.sapsf_token_url,
             'private_key': self.sapsf_private_key,
-            },
+        }
+        try:
+            assertion = session.post(
+                transaction_data['endpoint_url'],
+                data=transaction_data,
                 timeout=self.timeout,
             )
             assertion.raise_for_status()
-        assertion = assertion.text
-        token = session.post(
-            self.sapsf_token_url,
-            data={
+        except requests.RequestException as err:
+            self.log_bizx_api_exception(transaction_data, err)
+            return None
+        return assertion.text
+
+    def generate_bizx_oauth_api_access_token(self, user_id):
+        """
+        Request a new access token from the SuccessFactors BizX OAuth2 identity provider service
+        using a valid SAML assertion (see generate_bizx_api_saml_assertion) and the infomration specified
+        in the third party authentication configuration "Advanced Settings" section.
+        """
+        session = requests.Session()
+        transaction_data = {
+            'operation_name': 'generate_bizx_oauth_api_access_token',
+            'endpoint_url': self.sapsf_token_url,
             'client_id': self.odata_client_id,
             'company_id': self.odata_company_id,
             'grant_type': 'urn:ietf:params:oauth:grant-type:saml2-bearer',
-                'assertion': assertion,
-            },
+        }
+        assertion = self.generate_bizx_oauth_api_saml_assertion(user_id)
+        if not assertion:
+            return None
+        try:
+            transaction_data['assertion'] = assertion
+            token_response = session.post(
+                transaction_data['endpoint_url'],
+                data=transaction_data,
                 timeout=self.timeout,
             )
-        token.raise_for_status()
-        token = token.json()['access_token']
-        session.headers.update({'Authorization': 'Bearer {}'.format(token), 'Accept': 'application/json'})
+            token_response.raise_for_status()
+        except requests.RequestException as err:
+            self.log_bizx_api_exception(transaction_data, err)
+            return None
+        return token_response.json()
+
+    def get_bizx_odata_api_client(self, user_id):
+        session = requests.Session()
+        access_token_data = self.generate_bizx_oauth_api_access_token(user_id)
+        if not access_token_data:
+            return None
+        token_string = access_token_data['access_token']
+        session.headers.update({'Authorization': 'Bearer {}'.format(token_string), 'Accept': 'application/json'})
+        session.token_data = access_token_data
         return session
 
     def get_user_details(self, attributes):
         """
         Attempt to get rich user details from the SAP SuccessFactors OData API. If we're missing any
-        of the details we need to do that, fail nicely by returning the details we're able to extract
-        from just the SAML response and log a warning.
+        of the info we need to do that, or if the request triggers an exception, then fail nicely by
+        returning the basic user details we're able to extract from just the SAML response.
         """
-        details = super(SapSuccessFactorsIdentityProvider, self).get_user_details(attributes)
-        if self.missing_variables():
-            # If there aren't enough details to make the request, log a warning and return the details
-            # from the SAML assertion.
-            return details
-        username = details['username']
+        basic_details = super(SapSuccessFactorsIdentityProvider, self).get_user_details(attributes)
+        if self.invalid_configuration():
+            return basic_details
+        user_id = basic_details['username']
         fields = ','.join(self.field_mappings)
-        odata_api_url = '{root_url}User(userId=\'{user_id}\')?$select={fields}'.format(
+        transaction_data = {
+            'operation_name': 'get_user_details',
+            'user_id': user_id,
+            'company_id': self.odata_company_id,
+            'fields': fields,
+            'endpoint_url': '{root_url}User(userId=\'{user_id}\')?$select={fields}'.format(
                 root_url=self.odata_api_root_url,
-            user_id=username,
+                user_id=user_id,
                 fields=fields,
-        )
+            ),
+        }
+        client = self.get_bizx_odata_api_client(user_id=transaction_data['user_id'])
+        if not client:
+            return basic_details
         try:
-            client = self.get_odata_api_client(user_id=username)
+            transaction_data['token_data'] = client.token_data
             response = client.get(
-                odata_api_url,
+                transaction_data['endpoint_url'],
                 timeout=self.timeout,
             )
             response.raise_for_status()
             response = response.json()
         except requests.RequestException as err:
-            # If there was an HTTP level error, log the error and return the details from the SAML assertion.
-            sys_msg = err.response.json() if err.response else "Not available"
-            headers = err.response.headers if err.response else "Not available"
-            log_msg_template = (
-                'Unable to retrieve user details with username {username} from SAPSuccessFactors for company ' +
-                'ID {company} with url "{url}".  Error message: {err_msg}.  System message: {sys_msg}.  ' +
-                'Headers: {headers}'
-            )
-            log_msg = log_msg_template.format(
-                username=username,
-                company=self.odata_company_id,
-                url=odata_api_url,
-                err_msg=err.message,
-                sys_msg=sys_msg,
-                headers=headers
-            )
-            log.warning(log_msg, exc_info=True)
-            return details
-
+            self.log_bizx_api_exception(transaction_data, err)
+            return basic_details
         return self.get_registration_fields(response)
 
 

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

@@ -504,7 +504,7 @@ class SuccessFactorsIntegrationTest(SamlIntegrationTestUtilities, IntegrationTes
 
         odata_company_id = 'NCC1701D'
         odata_api_root_url = 'http://api.successfactors.com/odata/v2/'
-        mocked_odata_ai_url = self._mock_odata_api_for_error(odata_api_root_url, self.USER_USERNAME)
+        mocked_odata_api_url = self._mock_odata_api_for_error(odata_api_root_url, self.USER_USERNAME)
         self._configure_testshib_provider(
             identity_provider_type='sap_success_factors',
             metadata_source=TESTSHIB_METADATA_URL,
@@ -520,7 +520,7 @@ class SuccessFactorsIntegrationTest(SamlIntegrationTestUtilities, IntegrationTes
             super(SuccessFactorsIntegrationTest, self).test_register()
             logging_messages = str([log_msg.getMessage() for log_msg in log_capture.records]).replace('\\', '')
             self.assertIn(odata_company_id, logging_messages)
-            self.assertIn(mocked_odata_ai_url, logging_messages)
+            self.assertIn(mocked_odata_api_url, logging_messages)
             self.assertIn(self.USER_USERNAME, logging_messages)
             self.assertIn("SAPSuccessFactors", logging_messages)
             self.assertIn("Error message", logging_messages)