Merge pull request #600 from edx/iahmad/ENT-2372-edX-system-sending-a…

…udit-track-completion-events-to-SuccessFactors-tenant

ENT-2372: Re-enabled the API calls to update completed_date and is_passing

CHANGELOG.rst

@@ -13,6 +13,11 @@ Change Log
 
 Unreleased
 ----------
+[2.0.7] - 2019-10-21
+---------------------
+
+* Added certificate and grades api calls for transmitting learner export to integrated channels
+
 [2.0.6] - 2019-10-18
 ---------------------
 

enterprise/__init__.py

@@ -4,6 +4,6 @@
 
 from __future__ import absolute_import, unicode_literals
 
-__version__ = "2.0.6"
+__version__ = "2.0.7"
 
 default_app_config = "enterprise.apps.EnterpriseConfig"  # pylint: disable=invalid-name

integrated_channels/integrated_channel/exporters/learner_data.py

@@ -87,6 +87,7 @@ def export(self, **kwargs):
           for self-paced courses, when the course end date is passed, or when the learner achieves a passing grade.
         * ``grade``: string grade recorded for the learner in the course.
         """
+        exporting_single_learner = False
         learner_to_transmit = kwargs.get('learner_to_transmit', None)
         course_run_id = kwargs.get('course_run_id', None)
         completed_date = kwargs.get('completed_date', None)
@@ -96,6 +97,14 @@ def export(self, **kwargs):
         TransmissionAudit = kwargs.get('TransmissionAudit', None)  # pylint: disable=invalid-name
         # Fetch the consenting enrollment data, including the enterprise_customer_user.
         # Order by the course_id, to avoid fetching course API data more than we have to.
+        LOGGER.info('[Integrated Channel] Starting Export.'
+                    ' CompletedDate: {completed_date}, Course: {course_run}, Grade: {grade}, IsPassing: {is_passing},'
+                    ' User: {user_id}'.format(
+                        completed_date=completed_date,
+                        course_run=course_run_id,
+                        grade=grade,
+                        is_passing=is_passing,
+                        user_id=learner_to_transmit.id if learner_to_transmit else None))
         enrollment_queryset = EnterpriseCourseEnrollment.objects.select_related(
             'enterprise_customer_user'
         ).filter(
@@ -107,6 +116,12 @@ def export(self, **kwargs):
                 course_id=course_run_id,
                 enterprise_customer_user__user_id=learner_to_transmit.id,
             )
+            exporting_single_learner = True
+            LOGGER.info('[Integrated Channel] Exporting single learner.'
+                        ' Course: {course_run}, Enterprise: {enterprise_slug}, User: {user_id}'.format(
+                            course_run=course_run_id,
+                            enterprise_slug=self.enterprise_customer.slug,
+                            user_id=learner_to_transmit.id))
         enrollment_queryset = enrollment_queryset.order_by('course_id')
 
         # Fetch course details from the Course API, and cache between calls.
@@ -120,7 +135,9 @@ def export(self, **kwargs):
                 )
                 if already_transmitted.exists():
                     # We've already sent a completion status call for this enrollment
-                    LOGGER.info("Skipping previously sent enterprise enrollment [%s]", enterprise_enrollment.id)
+                    LOGGER.info('[Integrated Channel] Skipping export of previously sent enterprise enrollment.'
+                                '  EnterpriseEnrollment: {enterprise_enrollment_id}'.format(
+                                    enterprise_enrollment_id=enterprise_enrollment.id))
                     continue
 
             course_id = enterprise_enrollment.course_id
@@ -134,8 +151,10 @@ def export(self, **kwargs):
 
             if course_details is None:
                 # Course not found, so we have nothing to report.
-                LOGGER.error("No course run details found for enrollment [%d]: [%s]",
-                             enterprise_enrollment.pk, course_id)
+                LOGGER.error('[Integrated Channel] Course run details not found.'
+                             ' EnterpriseEnrollment: {enterprise_enrollment_pk}, Course: {course_id}'.format(
+                                 enterprise_enrollment_pk=enterprise_enrollment.pk,
+                                 course_id=course_id))
                 continue
 
             consent = DataSharingConsent.objects.proxied_get(
@@ -147,15 +166,55 @@ def export(self, **kwargs):
             if not consent.granted or enterprise_enrollment.audit_reporting_disabled:
                 continue
 
-            if not is_passing and not completed_date:
-                # For instructor-paced courses, let the certificate determine course completion
-                if course_details.get('pacing') == 'instructor':
-                    completed_date, grade, is_passing = self._collect_certificate_data(enterprise_enrollment)
-
-                # For self-paced courses, check the Grades API
-                else:
-                    completed_date, grade, is_passing = self._collect_grades_data(enterprise_enrollment, course_details)
-
+            # For instructor-paced courses, let the certificate determine course completion
+            if course_details.get('pacing') == 'instructor':
+                completed_date_from_api, grade_from_api, is_passing_from_api = \
+                    self._collect_certificate_data(enterprise_enrollment)
+                LOGGER.info('[Integrated Channel] Received data from certificate api.'
+                            '  CompletedDate: {completed_date}, Course: {course_id}, Enterprise: {enterprise},'
+                            ' Grade: {grade}, IsPassing: {is_passing}, User: {user_id}'.format(
+                                completed_date=completed_date_from_api,
+                                grade=grade_from_api,
+                                is_passing=is_passing_from_api,
+                                course_id=course_id,
+                                user_id=enterprise_enrollment.enterprise_customer_user.user_id,
+                                enterprise=enterprise_enrollment.enterprise_customer_user.enterprise_customer.slug))
+            # For self-paced courses, check the Grades API
+            else:
+                completed_date_from_api, grade_from_api, is_passing_from_api = \
+                    self._collect_grades_data(enterprise_enrollment, course_details)
+                LOGGER.info('[Integrated Channel] Received data from grades api.'
+                            '  CompletedDate: {completed_date}, Course: {course_id}, Enterprise: {enterprise},'
+                            ' Grade: {grade}, IsPassing: {is_passing}, User: {user_id}'.format(
+                                completed_date=completed_date_from_api,
+                                grade=grade_from_api,
+                                is_passing=is_passing_from_api,
+                                course_id=course_id,
+                                user_id=enterprise_enrollment.enterprise_customer_user.user_id,
+                                enterprise=enterprise_enrollment.enterprise_customer_user.enterprise_customer.slug))
+            if exporting_single_learner and (grade != grade_from_api or is_passing != is_passing_from_api or
+                                             completed_date != completed_date_from_api):
+                enterprise_user = enterprise_enrollment.enterprise_customer_user
+                LOGGER.error('[Integrated Channel] Attempt to transmit conflicting data. '
+                             ' CompletedDate: {completed_date}, CompletedDateAPI: {completed_date_api},'
+                             ' Course: {course_id}, Enterprise: {enterprise},'
+                             ' EnrollmentId: {enrollment_id},'
+                             ' Grade: {grade}, GradeAPI: {grade_api}, IsPassing: {is_passing},'
+                             ' IsPassingAPI: {is_passing_api}, User: {user_id}'.format(
+                                 completed_date=completed_date,
+                                 grade=grade,
+                                 is_passing=is_passing,
+                                 completed_date_api=completed_date_from_api,
+                                 grade_api=grade_from_api,
+                                 is_passing_api=is_passing_from_api,
+                                 course_id=course_id,
+                                 enrollment_id=enterprise_enrollment.id,
+                                 user_id=enterprise_user.user_id,
+                                 enterprise=enterprise_user.enterprise_customer.slug))
+            # Apply the Single Source of Truth for Grades
+            grade = grade_from_api
+            completed_date = completed_date_from_api
+            is_passing = is_passing_from_api
             records = self.get_learner_data_records(
                 enterprise_enrollment=enterprise_enrollment,
                 completed_date=completed_date,
@@ -233,6 +292,12 @@ def _collect_certificate_data(self, enterprise_enrollment):
             grade = self.grade_passing if is_passing else self.grade_failing
 
         except HttpNotFoundError:
+            LOGGER.error('[Integrated Channel] Certificate data not found.'
+                         ' Course: {course_id}, EnterpriseEnrollment: {enterprise_enrollment},'
+                         ' Username: {username}'.format(
+                             course_id=course_id,
+                             username=username,
+                             enterprise_enrollment=enterprise_enrollment.pk))
             completed_date = None
             grade = self.grade_incomplete
             is_passing = False
@@ -271,14 +336,20 @@ def _collect_grades_data(self, enterprise_enrollment, course_details):
                 if response_content.get('error_code', '') == 'user_not_enrolled':
                     # This means the user has an enterprise enrollment record but is not enrolled in the course yet
                     LOGGER.info(
-                        "User [%s] not enrolled in course [%s], enterprise enrollment [%d]",
-                        username,
-                        course_id,
-                        enterprise_enrollment.pk
-                    )
+                        '[Integrated Channel] User is not enrolled in the course.'
+                        ' Course: {course_id}, EnterpriseEnrollment: {enterprise_enrollment},'
+                        ' Username: {username}'.format(
+                            course_id=course_id,
+                            username=username,
+                            enterprise_enrollment=enterprise_enrollment.pk))
                     return None, None, None
 
-            LOGGER.error("No grades data found for [%d]: [%s], [%s]", enterprise_enrollment.pk, course_id, username)
+            LOGGER.error('[Integrated Channel] Grades data not found.'
+                         ' Course: {course_id}, EnterpriseEnrollment: {enterprise_enrollment},'
+                         ' Username: {username}'.format(
+                             course_id=course_id,
+                             username=username,
+                             enterprise_enrollment=enterprise_enrollment.pk))
             return None, None, None
 
         # Prepare to process the course end date and pass/fail grade

integrated_channels/integrated_channel/tasks.py

@@ -34,20 +34,25 @@ def transmit_content_metadata(username, channel_code, channel_pk):
     start = time.time()
     api_user = User.objects.get(username=username)
     integrated_channel = INTEGRATED_CHANNEL_CHOICES[channel_code].objects.get(pk=channel_pk)
-    LOGGER.info('Transmitting content metadata to integrated channel using configuration: [%s]', integrated_channel)
+    LOGGER.info('[Integrated Channel] Content metadata transmission started.'
+                ' Configuration: {configuration}'.format(configuration=integrated_channel))
     try:
         integrated_channel.transmit_content_metadata(api_user)
     except Exception:  # pylint: disable=broad-except
         LOGGER.exception(
-            'Transmission of content metadata failed for user [%s] and for integrated '
-            'channel with code [%s] and id [%s].', username, channel_code, channel_pk
-        )
+            '[Integrated Channel] Transmission of content metadata failed.'
+            ' ChannelCode: {channel_code}, ChannelId: {channel_id}, Username: {user}'.format(
+                user=username,
+                channel_code=channel_code,
+                channel_id=channel_pk
+            ))
     duration = time.time() - start
     LOGGER.info(
-        'Content metadata transmission task for integrated channel configuration [%s] took [%s] seconds',
-        integrated_channel,
-        duration
-    )
+        '[Integrated Channel] Content metadata transmission task finished. Configuration: {configuration},'
+        'Duration: {duration}'.format(
+            configuration=integrated_channel,
+            duration=duration
+        ))
 
 
 @shared_task
@@ -64,18 +69,20 @@ def transmit_learner_data(username, channel_code, channel_pk):
     start = time.time()
     api_user = User.objects.get(username=username)
     integrated_channel = INTEGRATED_CHANNEL_CHOICES[channel_code].objects.get(pk=channel_pk)
-    LOGGER.info('Processing learners for integrated channel using configuration: [%s]', integrated_channel)
+    LOGGER.info('[Integrated Channel] Batch processing learners for integrated channel.'
+                ' Configuration: {configuration}'.format(configuration=integrated_channel))
 
     # Note: learner data transmission code paths don't raise any uncaught exception, so we don't need a broad
     # try-except block here.
     integrated_channel.transmit_learner_data(api_user)
 
     duration = time.time() - start
     LOGGER.info(
-        'Learner data transmission task for integrated channel configuration [%s] took [%s] seconds',
-        integrated_channel,
-        duration
-    )
+        '[Integrated Channel] Batch learner data transmission task finished. Configuration: {configuration},'
+        ' Duration: {duration}'.format(
+            configuration=integrated_channel,
+            duration=duration
+        ))
 
 
 @shared_task
@@ -89,14 +96,19 @@ def transmit_single_learner_data(username, course_run_id):
     """
     start = time.time()
     user = User.objects.get(username=username)
-    LOGGER.info('Started transmitting single learner data for user: [%s] and course [%s]', username, course_run_id)
+    LOGGER.info('[Integrated Channel] Single learner data transmission started.'
+                ' Course: {course_run}, Username: {username}'.format(
+                    course_run=course_run_id,
+                    username=username))
     channel_utils = IntegratedChannelCommandUtils()
     # Transmit the learner data to each integrated channel
     for channel in channel_utils.get_integrated_channels({'channel': None}):
         integrated_channel = INTEGRATED_CHANNEL_CHOICES[channel.channel_code()].objects.get(pk=channel.pk)
         LOGGER.info(
-            'Processing learner [%s] for integrated channel using configuration: [%s]', user.id, integrated_channel
-        )
+            '[Integrated Channel] Processing learner for transmission. Configuration: {configuration},'
+            ' User: {user_id}'.format(
+                configuration=integrated_channel,
+                user_id=user.id))
         integrated_channel.transmit_single_learner_data(
             learner_to_transmit=user,
             course_run_id=course_run_id,
@@ -107,11 +119,11 @@ def transmit_single_learner_data(username, course_run_id):
 
     duration = time.time() - start
     LOGGER.info(
-        'Learner data transmission task for user: [%s] and course [%s] took [%s] seconds',
-        username,
-        course_run_id,
-        duration
-    )
+        '[Integrated Channel] Single learner data transmission task finished.'
+        ' Course: {course_run}, Duration: {duration}, Username: {username}'.format(
+            username=username,
+            course_run=course_run_id,
+            duration=duration))
 
 
 @shared_task

integrated_channels/sap_success_factors/exporters/learner_data.py

@@ -72,7 +72,8 @@ def get_learner_data_records(self, enterprise_enrollment, completed_date=None, g
             ]
         else:
             LOGGER.debug(
-                'No learner data was sent for user [%s] because an SAP SuccessFactors user ID could not be found.',
+                '[Integrated Channel] No learner data was sent for user [%s] because an SAP SuccessFactors user ID'
+                ' could not be found.',
                 enterprise_enrollment.enterprise_customer_user.username
             )
 

tests/test_integrated_channels/test_cornerstone/test_exporters/test_learner_data.py

@@ -189,6 +189,7 @@ def test_api_client_called_with_appropriate_payload(self, mock_post_request):
         assert sorted(expected_headers.items()) == sorted(actual_headers.items())
 
     @responses.activate
+    @mock.patch('enterprise.api_client.lms.JwtBuilder', mock.Mock())
     def test_transmit_single_learner_data_performs_only_one_transmission(self):
         """
         Test sending single user's data sould only update one `CornerstoneLearnerDataTransmissionAudit` entry
@@ -211,6 +212,16 @@ def test_transmit_single_learner_data_performs_only_one_transmission(self):
             }
         )
 
+        # Certificates API user's grade response
+        responses.add(
+            responses.GET,
+            urljoin(
+                lms_api.CertificatesApiClient.API_BASE_URL,
+                "certificates/{user}/courses/{course}/".format(course=course_id, user=self.user.username)
+            ),
+            json={"is_passing": "true", "created_date": "2019-06-21T12:58:17.428373Z", "grade": "0.8"},
+        )
+
         transmissions = CornerstoneLearnerDataTransmissionAudit.objects.filter(user=self.user, course_completed=False)
         # assert we have two uncompleted data transmission
         self.assertEqual(transmissions.count(), 2)