Add duration to task status. Add tests for reset-attempts.

lms/djangoapps/courseware/task_queue.py

@@ -224,6 +224,7 @@ def _get_course_task_log_status(task_id):
           'updated': number of attempts that "succeeded"
           'total': number of possible subtasks to attempt
           'action_name': user-visible verb to use in status messages.  Should be past-tense.
+          'duration_ms': how long the task has (or had) been running.
       'task_traceback': optional, returned if task failed and produced a traceback.
       'succeeded': on complete tasks, indicates if the task outcome was successful:
           did it achieve what it set out to do.

lms/djangoapps/courseware/tasks.py

 
 import json
-from time import sleep
+from time import sleep, time
+
 
 from django.contrib.auth.models import User
 from django.db import transaction
 
 from celery import task, current_task
-# from celery.signals import worker_ready
 from celery.utils.log import get_task_logger
 
 import mitxmako.middleware as middleware
 
 from courseware.models import StudentModule
 from courseware.model_data import ModelDataCache
-# from courseware.module_render import get_module
 from courseware.module_render import get_module_for_descriptor_internal
 
 from xmodule.modulestore.django import modulestore
@@ -40,14 +39,18 @@ def _update_problem_module_state(course_id, module_state_key, student, update_fc
     fmt = 'Starting to update problem modules as task "{task_id}": course "{course_id}" problem "{state_key}": nothing {action} yet'
     task_log.info(fmt.format(task_id=task_id, course_id=course_id, state_key=module_state_key, action=action_name))
 
+    # get start time for task:
+    start_time = time()
+
     # add task_id to xmodule_instance_args, so that it can be output with tracking info:
     xmodule_instance_args['task_id'] = task_id
-    
-    # add hack so that mako templates will work on celery worker server:
-    # The initialization of Make templating is usually done when Django is
+
+    # Hack to get mako templates to work on celery worker server's worker thread.
+    # The initialization of Mako templating is usually done when Django is
     # initializing middleware packages as part of processing a server request.
     # When this is run on a celery worker server, no such initialization is
-    # called.  So we look for the result: the defining of the lookup paths
+    # called. Using @worker_ready.connect doesn't run in the right container.
+    #  So we look for the result: the defining of the lookup paths
     # for templates.
     if 'main' not in middleware.lookup:
         task_log.info("Initializing Mako middleware explicitly")
@@ -74,14 +77,16 @@ def _update_problem_module_state(course_id, module_state_key, student, update_fc
     num_total = len(modules_to_update)  # TODO: make this more efficient.  Count()?
 
     def get_task_progress():
+        current_time = time()
         progress = {'action_name': action_name,
                     'attempted': num_attempted,
                     'updated': num_updated,
                     'total': num_total,
+                    'start_ms': int(start_time * 1000),
+                    'duration_ms': int((current_time - start_time) * 1000),
                     }
         return progress
 
-
     for module_to_update in modules_to_update:
         num_attempted += 1
         # There is no try here:  if there's an error, we let it throw, and the task will
@@ -102,7 +107,8 @@ def _update_problem_module_state(course_id, module_state_key, student, update_fc
     task_progress = get_task_progress()
     current_task.update_state(state='PROGRESS', meta=task_progress)
 
-    task_log.info("Finished processing task")
+    fmt = 'Finishing task "{task_id}": course "{course_id}" problem "{state_key}": final: {progress}'
+    task_log.info(fmt.format(task_id=task_id, course_id=course_id, state_key=module_state_key, progress=task_progress))
     return task_progress
 
 
@@ -288,11 +294,15 @@ def delete_problem_state_for_all_students(course_id, problem_url, xmodule_instan
                                                          xmodule_instance_args=xmodule_instance_args)
 
 
+# Using @worker_ready.connect was an effort to call middleware initialization
+# only once, when the worker was coming up.  However, the actual worker task
+# was not getting initialized, so it was likely running in a separate process
+# from the worker server.
 #@worker_ready.connect
 #def initialize_middleware(**kwargs):
-#    # The initialize Django middleware - some middleware components
+#    # Initialize Django middleware - some middleware components
 #    # are initialized lazily when the first request is served. Since
-#    # the celery workers do not serve request, the components never
+#    # the celery workers do not serve requests, the components never
 #    # get initialized, causing errors in some dependencies.
 #    # In particular, the Mako template middleware is used by some xmodules
 #    task_log.info("Initializing all middleware from worker_ready.connect hook")

lms/djangoapps/courseware/tests/test_tasks.py

@@ -19,7 +19,8 @@ from student.tests.factories import CourseEnrollmentFactory, UserFactory, AdminF
 from courseware.model_data import StudentModule
 from courseware.task_queue import (submit_regrade_problem_for_all_students, 
                                    submit_regrade_problem_for_student,
-                                   course_task_log_status)
+                                   course_task_log_status,
+    submit_reset_problem_attempts_for_all_students)
 from courseware.tests.tests import LoginEnrollmentTestCase, TEST_DATA_MONGO_MODULESTORE
 
 
@@ -228,7 +229,7 @@ class TestRegrading(TestRegradingBase):
         self.create_student('u4')
         self.logout()
 
-    def testRegradingOptionProblem(self):
+    def test_regrading_option_problem(self):
         '''Run regrade scenario on option problem'''
         # get descriptor:
         problem_url_name = 'H1P1'
@@ -280,7 +281,7 @@ class TestRegrading(TestRegradingBase):
                            display_name=str(problem_url_name),
                            data=problem_xml)
 
-    def testRegradingFailure(self):
+    def test_regrading_failure(self):
         """Simulate a failure in regrading a problem"""
         problem_url_name = 'H1P1'
         self.define_option_problem(problem_url_name)
@@ -307,19 +308,19 @@ class TestRegrading(TestRegradingBase):
         status = json.loads(response.content)
         self.assertEqual(status['message'], expected_message)
 
-    def testRegradingNonProblem(self):
+    def test_regrading_non_problem(self):
         """confirm that a non-problem will not submit"""
         problem_url_name = self.problem_section.location.url()
         with self.assertRaises(NotImplementedError):
             self.regrade_all_student_answers('instructor', problem_url_name)
 
-    def testRegradingNonexistentProblem(self):
+    def test_regrading_nonexistent_problem(self):
         """confirm that a non-existent problem will not submit"""
         problem_url_name = 'NonexistentProblem'
         with self.assertRaises(ItemNotFoundError):
             self.regrade_all_student_answers('instructor', problem_url_name)
 
-    def testRegradingCodeProblem(self):
+    def test_regrading_code_problem(self):
         '''Run regrade scenario on problem with code submission'''
         problem_url_name = 'H1P2'
         self.define_code_response_problem(problem_url_name)
@@ -338,3 +339,84 @@ class TestRegrading(TestRegradingBase):
         response = course_task_log_status(mock_request, task_id=course_task_log.task_id)
         status = json.loads(response.content)
         self.assertEqual(status['message'], "Problem's definition does not support regrading")
+
+
+class TestResetAttempts(TestRegradingBase):
+    userlist = ['u1', 'u2', 'u3', 'u4']
+
+    def setUp(self):
+        self.initialize_course()
+        self.create_instructor('instructor')
+        for username in self.userlist:
+            self.create_student(username)
+        self.logout()
+
+    def get_num_attempts(self, username, descriptor):
+        module = self.get_student_module(username, descriptor)
+        state = json.loads(module.state)
+        return state['attempts']
+
+    def reset_problem_attempts(self, instructor, problem_url_name):
+        """Submits the current problem for resetting"""
+        return submit_reset_problem_attempts_for_all_students(self._create_task_request(instructor), self.course.id,
+                                                              TestRegradingBase.problem_location(problem_url_name))
+
+    def test_reset_attempts_on_problem(self):
+        '''Run reset-attempts scenario on option problem'''
+        # get descriptor:
+        problem_url_name = 'H1P1'
+        self.define_option_problem(problem_url_name)
+        location = TestRegradingBase.problem_location(problem_url_name)
+        descriptor = self.module_store.get_instance(self.course.id, location)
+        num_attempts = 3
+        # first store answers for each of the separate users:
+        for _ in range(num_attempts):
+            for username in self.userlist:
+                self.submit_student_answer(username, problem_url_name, ['Option 1', 'Option 1'])
+
+        for username in self.userlist:
+            self.assertEquals(self.get_num_attempts(username, descriptor), num_attempts)
+
+        self.reset_problem_attempts('instructor', problem_url_name)
+
+        for username in self.userlist:
+            self.assertEquals(self.get_num_attempts(username, descriptor), 0)
+
+    def test_reset_failure(self):
+        """Simulate a failure in resetting attempts on a problem"""
+        problem_url_name = 'H1P1'
+        self.define_option_problem(problem_url_name)
+        self.submit_student_answer('u1', problem_url_name, ['Option 1', 'Option 1'])
+
+        expected_message = "bad things happened"
+        with patch('courseware.models.StudentModule.save') as mock_save:
+            mock_save.side_effect = ZeroDivisionError(expected_message)
+            course_task_log = self.reset_problem_attempts('instructor', problem_url_name)
+
+        # check task_log returned
+        self.assertEqual(course_task_log.task_state, 'FAILURE')
+        self.assertEqual(course_task_log.student, None)
+        self.assertEqual(course_task_log.requester.username, 'instructor')
+        self.assertEqual(course_task_log.task_name, 'reset_problem_attempts')
+        self.assertEqual(course_task_log.task_args, TestRegrading.problem_location(problem_url_name))
+        status = json.loads(course_task_log.task_progress)
+        self.assertEqual(status['exception'], 'ZeroDivisionError')
+        self.assertEqual(status['message'], expected_message)
+
+        # check status returned:
+        mock_request = Mock()
+        response = course_task_log_status(mock_request, task_id=course_task_log.task_id)
+        status = json.loads(response.content)
+        self.assertEqual(status['message'], expected_message)
+
+    def test_reset_non_problem(self):
+        """confirm that a non-problem can still be successfully reset"""
+        problem_url_name = self.problem_section.location.url()
+        course_task_log = self.reset_problem_attempts('instructor', problem_url_name)
+        self.assertEqual(course_task_log.task_state, 'SUCCESS')
+
+    def test_reset_nonexistent_problem(self):
+        """confirm that a non-existent problem will not submit"""
+        problem_url_name = 'NonexistentProblem'
+        with self.assertRaises(ItemNotFoundError):
+            self.reset_problem_attempts('instructor', problem_url_name)

lms/djangoapps/instructor/views.py

@@ -1308,25 +1308,34 @@ def get_background_task_table(course_id, problem_url, student=None):
             "Task Id",
             "Requester",
             "Submitted",
-            "Updated",
+            "Duration",
             "Task State",
             "Task Status",
             "Message"]
 
         datatable['data'] = []
         for i, course_task in enumerate(history_entries):
+            # get duration info, if known:
+            duration_ms = 'unknown'
+            if hasattr(course_task, 'task_progress'):
+                task_progress = json.loads(course_task.task_progress)
+                if 'duration_ms' in task_progress:
+                    duration_ms = task_progress['duration_ms']
+            # get progress status message:
             success, message = task_queue.get_task_completion_message(course_task)
             if success:
                 status = "Complete"
             else:
                 status = "Incomplete"
+            # generate row for this task:
             row = ["#{0}".format(len(history_entries) - i),
                 str(course_task.task_name),
                 str(course_task.student),
                 str(course_task.task_id),
                 str(course_task.requester),
                 course_task.created.strftime("%Y/%m/%d %H:%M:%S"),
-                course_task.updated.strftime("%Y/%m/%d %H:%M:%S"),
+                duration_ms,
+                #course_task.updated.strftime("%Y/%m/%d %H:%M:%S"),
                 str(course_task.task_state),
                 status,
                 message]