Merge pull request #19238 from edx/ri/EDUCATOR-3668-add-logs

EDUCATOR-3668 add temporary logs to track to track the invocation of compute_all_grades_for_course task

cms/djangoapps/contentstore/signals/handlers.py

@@ -114,6 +114,7 @@ def handle_grading_policy_changed(sender, **kwargs):
     """
     kwargs = {
         'course_key': unicode(kwargs.get('course_key')),
+        'grading_policy_hash': unicode(kwargs.get('grading_policy_hash')),
         'event_transaction_id': unicode(get_event_transaction_id()),
         'event_transaction_type': unicode(get_event_transaction_type()),
     }

cms/djangoapps/contentstore/tests/test_course_settings.py

@@ -496,11 +496,13 @@ class CourseGradingTest(CourseTestCase):
 
         # one for each of the calls to update_from_json()
         send_signal.assert_has_calls([
-            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id),
-            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id),
-            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id),
-            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id),
-            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id),
+            # pylint: disable=line-too-long
+            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id, grading_policy_hash=grading_policy_1),
+            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id, grading_policy_hash=grading_policy_2),
+            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id, grading_policy_hash=grading_policy_3),
+            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id, grading_policy_hash=grading_policy_4),
+            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id, grading_policy_hash=grading_policy_4),
+            # pylint: enable=line-too-long
         ])
 
         # one for each of the calls to update_from_json(); the last update doesn't actually change the parts of the
@@ -546,9 +548,11 @@ class CourseGradingTest(CourseTestCase):
 
         # one for each of the calls to update_grader_from_json()
         send_signal.assert_has_calls([
-            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id),
-            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id),
-            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id),
+            # pylint: disable=line-too-long
+            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id, grading_policy_hash=grading_policy_1),
+            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id, grading_policy_hash=grading_policy_2),
+            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id, grading_policy_hash=grading_policy_3),
+            # pylint: enable=line-too-long
         ])
 
         # one for each of the calls to update_grader_from_json()
@@ -661,8 +665,10 @@ class CourseGradingTest(CourseTestCase):
 
         # one for each call to update_section_grader_type()
         send_signal.assert_has_calls([
-            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id),
-            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id),
+            # pylint: disable=line-too-long
+            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id, grading_policy_hash=grading_policy_1),
+            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id, grading_policy_hash=grading_policy_2),
+            # pylint: enable=line-too-long
         ])
 
         tracker.emit.assert_has_calls([
@@ -723,7 +729,7 @@ class CourseGradingTest(CourseTestCase):
             '{}/{}'.format(grader_type_url_base, len(original_model['graders'])),
             new_grader
         )
-
+        grading_policy_hash1 = self._grading_policy_hash_for_course()
         self.assertEqual(200, response.status_code)
         grader_sample = json.loads(response.content)
         new_grader['id'] = len(original_model['graders'])
@@ -731,7 +737,7 @@ class CourseGradingTest(CourseTestCase):
 
         # test deleting the original grader
         response = self.client.delete(grader_type_url_base + '/1', HTTP_ACCEPT="application/json")
-
+        grading_policy_hash2 = self._grading_policy_hash_for_course()
         self.assertEqual(204, response.status_code)
         updated_model = self._model_from_url(grader_type_url_base)
         new_grader['id'] -= 1  # one fewer and the id mutates
@@ -739,9 +745,11 @@ class CourseGradingTest(CourseTestCase):
         self.assertNotIn(original_model['graders'][1], updated_model['graders'])
         send_signal.assert_has_calls([
             # once for the POST
-            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id),
+            # pylint: disable=line-too-long
+            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id, grading_policy_hash=grading_policy_hash1),
             # once for the DELETE
-            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id),
+            mock.call(sender=CourseGradingModel, user_id=self.user.id, course_key=self.course.id, grading_policy_hash=grading_policy_hash2),
+            # pylint: enable=line-too-long
         ])
 
     def setup_test_set_get_section_grader_ajax(self):
@@ -1018,7 +1026,7 @@ class CourseMetadataEditingTest(CourseTestCase):
         fresh = modulestore().get_course(self.course.id)
         test_model = CourseMetadata.fetch(fresh)
 
-        self.assertNotEqual(test_model['advertised_start']['value'], 1, 'advertised_start should not be updated to a wrong value')
+        self.assertNotEqual(test_model['advertised_start']['value'], 1, 'advertised_start should not be updated to a wrong value')  # pylint: disable=line-too-long
         self.assertNotEqual(test_model['days_early_for_beta']['value'], "supposed to be an integer",
                             'days_early_for beta should not be updated to a wrong value')
 

cms/djangoapps/models/settings/course_grading.py

@@ -256,16 +256,21 @@ class CourseGradingModel(object):
 def _grading_event_and_signal(course_key, user_id):
     name = GRADING_POLICY_CHANGED_EVENT_TYPE
     course = modulestore().get_course(course_key)
-
+    grading_policy_hash = unicode(hash_grading_policy(course.grading_policy))
     data = {
         "course_id": unicode(course_key),
         "user_id": unicode(user_id),
-        "grading_policy_hash": unicode(hash_grading_policy(course.grading_policy)),
+        "grading_policy_hash": grading_policy_hash,
         "event_transaction_id": unicode(create_new_event_transaction_id()),
         "event_transaction_type": GRADING_POLICY_CHANGED_EVENT_TYPE,
     }
     tracker.emit(name, data)
-    GRADING_POLICY_CHANGED.send(sender=CourseGradingModel, user_id=user_id, course_key=course_key)
+    GRADING_POLICY_CHANGED.send(
+        sender=CourseGradingModel,
+        user_id=user_id,
+        course_key=course_key,
+        grading_policy_hash=grading_policy_hash
+    )
 
 
 def hash_grading_policy(grading_policy):

lms/djangoapps/grades/course_grade_factory.py

@@ -101,6 +101,14 @@ class CourseGradeFactory(object):
         course_data = CourseData(
             user=None, course=course, collected_block_structure=collected_block_structure, course_key=course_key,
         )
+        # adding temporary log to investigate EDUCATOR-3668
+        log.info(
+            "EDUCATOR-3668-lms.grades.CourseGradeFactory.iter: using course_version: {course_version} "
+            "and course_key: {course_key}".format(
+                course_version=course_data.version,
+                course_key=course_data.course_key
+            )
+        )
         stats_tags = [u'action:{}'.format(course_data.course_key)]
         for user in users:
             with dog_stats_api.timer('lms.grades.CourseGradeFactory.iter', tags=stats_tags):

lms/djangoapps/grades/tasks.py

@@ -63,6 +63,10 @@ def compute_all_grades_for_course(**kwargs):
         if are_grades_frozen(course_key):
             log.info("Attempted compute_all_grades_for_course for course '%s', but grades are frozen.", course_key)
             return
+        # adding temporary log to investigate EDUCATOR-3668
+        log.info("EDUCATOR-3668-Computing grades for all students in course: {course_key}".format(
+            course_key=course_key
+        ))
         for course_key_string, offset, batch_size in _course_task_args(course_key=course_key, **kwargs):
             kwargs.update({
                 'course_key': course_key_string,