def test_task_input_valid_length(self): """ Test allowed length of task_input field """ task_input = 's' * TASK_INPUT_LENGTH with pytest.raises(AttributeError): InstructorTask.create( course_id='dummy_course_id', task_type='dummy type', task_key='dummy key', task_input=task_input, requester='dummy requester', )
def on_failure(self, exc, task_id, args, kwargs, einfo): """ Update InstructorTask object corresponding to this task with info about failure. Fetches and updates exception and traceback information on failure. If an exception is raised internal to the task, it is caught by celery and provided here. The information is recorded in the InstructorTask object as a JSON-serialized dict stored in the task_output column. It contains the following keys: 'exception': type of exception object 'message': error message from exception object 'traceback': traceback information (truncated if necessary) Note that there is no way to record progress made within the task (e.g. attempted, succeeded, etc.) when such failures occur. """ TASK_LOG.debug(u'Task %s: failure returned', task_id) entry_id = args[0] try: entry = InstructorTask.objects.get(pk=entry_id) except InstructorTask.DoesNotExist: # if the InstructorTask object does not exist, then there's no point # trying to update it. TASK_LOG.error(u"Task (%s) has no InstructorTask object for id %s", task_id, entry_id) else: TASK_LOG.warning(u"Task (%s) failed", task_id, exc_info=True) entry.task_output = InstructorTask.create_output_for_failure(einfo.exception, einfo.traceback) entry.task_state = FAILURE entry.save_now()
def _reserve_task(course_id, task_type, task_key, task_input, requester): """ Creates a database entry to indicate that a task is in progress. Throws AlreadyRunningError if the task is already in progress. Includes the creation of an arbitrary value for task_id, to be submitted with the task call to celery. Note that there is a chance of a race condition here, when two users try to run the same task at almost exactly the same time. One user could be after the check and before the create when the second user gets to the check. At that point, both users are able to run their tasks simultaneously. This is deemed a small enough risk to not put in further safeguards. """ if _task_is_running(course_id, task_type, task_key): log.warning("Duplicate task found for task_type %s and task_key %s", task_type, task_key) error_message = generate_already_running_error_message(task_type) raise AlreadyRunningError(error_message) try: most_recent_id = InstructorTask.objects.latest('id').id except InstructorTask.DoesNotExist: most_recent_id = "None found" finally: log.warning( "No duplicate tasks found: task_type %s, task_key %s, and most recent task_id = %s", task_type, task_key, most_recent_id ) # Create log entry now, so that future requests will know it's running. return InstructorTask.create(course_id, task_type, task_key, task_input, requester)
def test_send_email_retried_subtask(self): # test at a lower level, to ensure that the course gets checked down below too. entry = InstructorTask.create(self.course.id, "task_type", "task_key", "task_input", self.instructor) entry_id = entry.id subtask_id = "subtask-id-value" initialize_subtask_info(entry, "emailed", 100, [subtask_id]) subtask_status = SubtaskStatus.create(subtask_id, state=RETRY, retried_nomax=2) update_subtask_status(entry_id, subtask_id, subtask_status) bogus_email_id = 1001 to_list = ['*****@*****.**'] global_email_context = {'course_title': 'dummy course'} # try running with a clean subtask: new_subtask_status = SubtaskStatus.create(subtask_id) with self.assertRaisesRegex(DuplicateTaskException, 'already retried'): send_course_email(entry_id, bogus_email_id, to_list, global_email_context, new_subtask_status.to_dict()) # try again, with a retried subtask with lower count: new_subtask_status = SubtaskStatus.create(subtask_id, state=RETRY, retried_nomax=1) with self.assertRaisesRegex(DuplicateTaskException, 'already retried'): send_course_email(entry_id, bogus_email_id, to_list, global_email_context, new_subtask_status.to_dict())
def _reserve_task(course_id, task_type, task_key, task_input, requester): """ Creates a database entry to indicate that a task is in progress. Throws AlreadyRunningError if the task is already in progress. Includes the creation of an arbitrary value for task_id, to be submitted with the task call to celery. Note that there is a chance of a race condition here, when two users try to run the same task at almost exactly the same time. One user could be after the check and before the create when the second user gets to the check. At that point, both users are able to run their tasks simultaneously. This is deemed a small enough risk to not put in further safeguards. """ if _task_is_running(course_id, task_type, task_key): log.warning("Duplicate task found for task_type %s and task_key %s", task_type, task_key) error_message = generate_already_running_error_message(task_type) raise AlreadyRunningError(error_message) try: most_recent_id = InstructorTask.objects.latest('id').id except InstructorTask.DoesNotExist: most_recent_id = "None found" finally: log.warning( "No duplicate tasks found: task_type %s, task_key %s, and most recent task_id = %s", task_type, task_key, most_recent_id) # Create log entry now, so that future requests will know it's running. return InstructorTask.create(course_id, task_type, task_key, task_input, requester)
def on_failure(self, exc, task_id, args, kwargs, einfo): """ Update InstructorTask object corresponding to this task with info about failure. Fetches and updates exception and traceback information on failure. If an exception is raised internal to the task, it is caught by celery and provided here. The information is recorded in the InstructorTask object as a JSON-serialized dict stored in the task_output column. It contains the following keys: 'exception': type of exception object 'message': error message from exception object 'traceback': traceback information (truncated if necessary) Note that there is no way to record progress made within the task (e.g. attempted, succeeded, etc.) when such failures occur. """ TASK_LOG.debug('Task %s: failure returned', task_id) entry_id = args[0] try: entry = InstructorTask.objects.get(pk=entry_id) except InstructorTask.DoesNotExist: # if the InstructorTask object does not exist, then there's no point # trying to update it. TASK_LOG.error("Task (%s) has no InstructorTask object for id %s", task_id, entry_id) else: TASK_LOG.warning("Task (%s) failed", task_id, exc_info=True) entry.task_output = InstructorTask.create_output_for_failure( einfo.exception, einfo.traceback) entry.task_state = FAILURE entry.save_now()
def initialize_subtask_info(entry, action_name, total_num, subtask_id_list): """ Store initial subtask information to InstructorTask object. The InstructorTask's "task_output" field is initialized. This is a JSON-serialized dict. Counters for 'attempted', 'succeeded', 'failed', 'skipped' keys are initialized to zero, as is the 'duration_ms' value. A 'start_time' is stored for later duration calculations, and the total number of "things to do" is set, so the user can be told how much needs to be done overall. The `action_name` is also stored, to help with constructing more readable task_progress messages. The InstructorTask's "subtasks" field is also initialized. This is also a JSON-serialized dict. Keys include 'total', 'succeeded', 'retried', 'failed', which are counters for the number of subtasks. 'Total' is set here to the total number, while the other three are initialized to zero. Once the counters for 'succeeded' and 'failed' match the 'total', the subtasks are done and the InstructorTask's "status" will be changed to SUCCESS. The "subtasks" field also contains a 'status' key, that contains a dict that stores status information for each subtask. The value for each subtask (keyed by its task_id) is its subtask status, as defined by SubtaskStatus.to_dict(). This information needs to be set up in the InstructorTask before any of the subtasks start running. If not, there is a chance that the subtasks could complete before the parent task is done creating subtasks. Doing so also simplifies the save() here, as it avoids the need for locking. Monitoring code should assume that if an InstructorTask has subtask information, that it should rely on the status stored in the InstructorTask object, rather than status stored in the corresponding AsyncResult. """ task_progress = { 'action_name': action_name, 'attempted': 0, 'failed': 0, 'skipped': 0, 'succeeded': 0, 'total': total_num, 'duration_ms': int(0), 'start_time': time() } entry.task_output = InstructorTask.create_output_for_success(task_progress) entry.task_state = PROGRESS # Write out the subtasks information. num_subtasks = len(subtask_id_list) # Note that may not be necessary to store initial value with all those zeroes! # Write out as a dict, so it will go more smoothly into json. subtask_status = {subtask_id: (SubtaskStatus.create(subtask_id)).to_dict() for subtask_id in subtask_id_list} subtask_dict = { 'total': num_subtasks, 'succeeded': 0, 'failed': 0, 'status': subtask_status } entry.subtasks = json.dumps(subtask_dict) # and save the entry immediately, before any subtasks actually start work: entry.save_now() return task_progress
def test_send_email_undefined_subtask(self): # test at a lower level, to ensure that the course gets checked down below too. entry = InstructorTask.create(self.course.id, "task_type", "task_key", "task_input", self.instructor) entry_id = entry.id to_list = ['*****@*****.**'] global_email_context = {'course_title': 'dummy course'} subtask_id = "subtask-id-value" subtask_status = SubtaskStatus.create(subtask_id) email_id = 1001 with self.assertRaisesRegexp(DuplicateTaskException, 'unable to find subtasks of instructor task'): send_course_email(entry_id, email_id, to_list, global_email_context, subtask_status.to_dict())
def test_nonexistent_course(self): """ Tests exception when the course in the email doesn't exist """ course_id = CourseLocator("I", "DONT", "EXIST") email = CourseEmail(course_id=course_id) email.save() entry = InstructorTask.create(course_id, "task_type", "task_key", "task_input", self.instructor) task_input = {"email_id": email.id} # (?i) is a regex for ignore case with self.assertRaisesRegexp(ValueError, r"(?i)course not found"): perform_delegate_email_batches(entry.id, course_id, task_input, "action_name")
def test_nonexistent_course(self): """ Tests exception when the course in the email doesn't exist """ course_id = SlashSeparatedCourseKey("I", "DONT", "EXIST") email = CourseEmail(course_id=course_id) email.save() entry = InstructorTask.create(course_id, "task_type", "task_key", "task_input", self.instructor) task_input = {"email_id": email.id} # (?i) is a regex for ignore case with self.assertRaisesRegexp(ValueError, r"(?i)course not found"): perform_delegate_email_batches(entry.id, course_id, task_input, "action_name")
def test_wrong_course_id_in_email(self): """ Tests exception when the course_id in CourseEmail is not the same as one explicitly passed in. """ email = CourseEmail.create(CourseLocator("bogus", "course", "id"), self.instructor, [SEND_TO_MYSELF], "re: subject", "dummy body goes here") entry = InstructorTask.create(self.course.id, "task_type", "task_key", "task_input", self.instructor) task_input = {"email_id": email.id} with self.assertRaisesRegex(ValueError, 'does not match email value'): perform_delegate_email_batches(entry.id, self.course.id, task_input, "action_name")
def test_nonexistent_course(self): """ Tests exception when the course in the email doesn't exist """ course_id = CourseLocator("I", "DONT", "EXIST") email = CourseEmail(course_id=course_id) email.save() entry = InstructorTask.create(course_id, "task_type", "task_key", "task_input", self.instructor) task_input = {"email_id": email.id} with pytest.raises(CourseRunNotFound): perform_delegate_email_batches(entry.id, course_id, task_input, "action_name")
def test_send_email_missing_subtask(self): # test at a lower level, to ensure that the course gets checked down below too. entry = InstructorTask.create(self.course.id, "task_type", "task_key", "task_input", self.instructor) entry_id = entry.id to_list = ['*****@*****.**'] global_email_context = {'course_title': 'dummy course'} subtask_id = "subtask-id-value" initialize_subtask_info(entry, "emailed", 100, [subtask_id]) different_subtask_id = "bogus-subtask-id-value" subtask_status = SubtaskStatus.create(different_subtask_id) bogus_email_id = 1001 with self.assertRaisesRegexp(DuplicateTaskException, 'unable to find status for subtask of instructor task'): send_course_email(entry_id, bogus_email_id, to_list, global_email_context, subtask_status.to_dict())
def test_send_email_running_subtask(self): # test at a lower level, to ensure that the course gets checked down below too. entry = InstructorTask.create(self.course.id, "task_type", "task_key", "task_input", self.instructor) entry_id = entry.id subtask_id = "subtask-id-value" initialize_subtask_info(entry, "emailed", 100, [subtask_id]) subtask_status = SubtaskStatus.create(subtask_id) update_subtask_status(entry_id, subtask_id, subtask_status) check_subtask_is_valid(entry_id, subtask_id, subtask_status) bogus_email_id = 1001 to_list = ['*****@*****.**'] global_email_context = {'course_title': 'dummy course'} with self.assertRaisesRegexp(DuplicateTaskException, 'already being executed'): send_course_email(entry_id, bogus_email_id, to_list, global_email_context, subtask_status.to_dict())
def test_wrong_course_id_in_email(self): """ Tests exception when the course_id in CourseEmail is not the same as one explicitly passed in. """ email = CourseEmail.create( CourseLocator("bogus", "course", "id"), self.instructor, [SEND_TO_MYSELF], "re: subject", "dummy body goes here" ) entry = InstructorTask.create(self.course.id, "task_type", "task_key", "task_input", self.instructor) task_input = {"email_id": email.id} with self.assertRaisesRegexp(ValueError, 'does not match email value'): perform_delegate_email_batches(entry.id, self.course.id, task_input, "action_name")
def test_nonexistent_email(self, mock_log, result): """ Tests retries when the email doesn't exist """ # create an InstructorTask object to pass through course_id = self.course.id entry = InstructorTask.create(course_id, "task_type", "task_key", "task_input", self.instructor) task_input = {"email_id": -1} with self.assertRaises(CourseEmail.DoesNotExist): perform_delegate_email_batches(entry.id, course_id, task_input, "action_name") ((log_str, __, email_id), __) = mock_log.warning.call_args self.assertTrue(mock_log.warning.called) self.assertIn('Failed to get CourseEmail with id', log_str) self.assertEqual(email_id, -1) self.assertFalse(result.called)
def test_send_email_with_locked_instructor_task(self): # test at a lower level, to ensure that the course gets checked down below too. entry = InstructorTask.create(self.course.id, "task_type", "task_key", "task_input", self.instructor) entry_id = entry.id subtask_id = "subtask-id-locked-model" initialize_subtask_info(entry, "emailed", 100, [subtask_id]) subtask_status = SubtaskStatus.create(subtask_id) bogus_email_id = 1001 to_list = ['*****@*****.**'] global_email_context = {'course_title': 'dummy course'} with patch('lms.djangoapps.instructor_task.subtasks.InstructorTask.save') as mock_task_save: mock_task_save.side_effect = DatabaseError with self.assertRaises(DatabaseError): send_course_email(entry_id, bogus_email_id, to_list, global_email_context, subtask_status.to_dict()) self.assertEquals(mock_task_save.call_count, MAX_DATABASE_LOCK_RETRIES)
def test_send_email_undefined_email(self): # test at a lower level, to ensure that the course gets checked down below too. entry = InstructorTask.create(self.course.id, "task_type", "task_key", "task_input", self.instructor) entry_id = entry.id to_list = ['*****@*****.**'] global_email_context = {'course_title': 'dummy course'} subtask_id = "subtask-id-undefined-email" initialize_subtask_info(entry, "emailed", 100, [subtask_id]) subtask_status = SubtaskStatus.create(subtask_id) bogus_email_id = 1001 with self.assertRaises(CourseEmail.DoesNotExist): # we skip the call that updates subtask status, since we've not set up the InstructorTask # for the subtask, and it's not important to the test. with patch('bulk_email.tasks.update_subtask_status'): send_course_email(entry_id, bogus_email_id, to_list, global_email_context, subtask_status.to_dict())
def schedule_task(request, task_type, course_key, task_input, task_key, schedule): """ Helper function to schedule a background task. Reserves the requested task and stores it until the task is ready for execution. We also create an instance of a InstructorTaskSchedule object responsible for maintaining the details of _when_ a task should be executed. Extracts arguments important to the task from the originating server request and stores them as part of the schedule object. Sets the `task_status` to SCHEDULED to indicate this task will be executed in the future. Args: request (WSGIRequest): The originating web request associated with this task request. task_type (String): Text describing the type of task (e.g. 'bulk_course_email' or 'grade_course') course_key (CourseKey): The CourseKey of the course-run the task belongs to. task_input (dict): Task input arguments stores as JSON-serialized dictionary. task_key (String): Encoded input arguments used during task execution. schedule (DateTime): DateTime (in UTC) describing when the task should be executed. """ instructor_task = None try: log.info( f"Creating a scheduled instructor task of type '{task_type}' for course '{course_key}' requested by " f"user with id '{request.user.id}'") instructor_task = InstructorTask.create(course_key, task_type, task_key, task_input, request.user) task_id = instructor_task.task_id task_args = _get_xmodule_instance_args(request, task_id) log.info( f"Creating a task schedule associated with instructor task '{instructor_task.id}' and due after " f"'{schedule}'") InstructorTaskSchedule.objects.create( task=instructor_task, task_args=json.dumps(task_args), task_due=schedule, ) log.info( f"Updating task state of instructor task '{instructor_task.id}' to '{SCHEDULED}'" ) instructor_task.task_state = SCHEDULED instructor_task.save() except Exception as error: # pylint: disable=broad-except log.error(f"Error occurred during task or schedule creation: {error}") # Set any orphaned instructor tasks to the FAILURE state. if instructor_task: _handle_instructor_task_failure(instructor_task, error)
def test_send_email_retried_subtask(self): # test at a lower level, to ensure that the course gets checked down below too. entry = InstructorTask.create(self.course.id, "task_type", "task_key", "task_input", self.instructor) entry_id = entry.id subtask_id = "subtask-id-value" initialize_subtask_info(entry, "emailed", 100, [subtask_id]) subtask_status = SubtaskStatus.create(subtask_id, state=RETRY, retried_nomax=2) update_subtask_status(entry_id, subtask_id, subtask_status) bogus_email_id = 1001 to_list = ['*****@*****.**'] global_email_context = {'course_title': 'dummy course'} # try running with a clean subtask: new_subtask_status = SubtaskStatus.create(subtask_id) with self.assertRaisesRegexp(DuplicateTaskException, 'already retried'): send_course_email(entry_id, bogus_email_id, to_list, global_email_context, new_subtask_status.to_dict()) # try again, with a retried subtask with lower count: new_subtask_status = SubtaskStatus.create(subtask_id, state=RETRY, retried_nomax=1) with self.assertRaisesRegexp(DuplicateTaskException, 'already retried'): send_course_email(entry_id, bogus_email_id, to_list, global_email_context, new_subtask_status.to_dict())
def on_success(self, task_progress, task_id, args, kwargs): # lint-amnesty, pylint: disable=arguments-differ """ Update InstructorTask object corresponding to this task with info about success. Updates task_output and task_state. But it shouldn't actually do anything if the task is only creating subtasks to actually do the work. Assumes `task_progress` is a dict containing the task's result, with the following keys: 'attempted': number of attempts made 'succeeded': number of attempts that "succeeded" 'skipped': number of attempts that "skipped" 'failed': number of attempts that "failed" 'total': number of possible subtasks to attempt 'action_name': user-visible verb to use in status messages. Should be past-tense. Pass-through of input `action_name`. 'duration_ms': how long the task has (or had) been running. This is JSON-serialized and stored in the task_output column of the InstructorTask entry. """ TASK_LOG.debug('Task %s: success returned with progress: %s', task_id, task_progress) # We should be able to find the InstructorTask object to update # based on the task_id here, without having to dig into the # original args to the task. On the other hand, the entry_id # is the first value passed to all such args, so we'll use that. # And we assume that it exists, else we would already have had a failure. entry_id = args[0] entry = InstructorTask.objects.get(pk=entry_id) # Check to see if any subtasks had been defined as part of this task. # If not, then we know that we're done. (If so, let the subtasks # handle updating task_state themselves.) if len(entry.subtasks) == 0: entry.task_output = InstructorTask.create_output_for_success( task_progress) entry.task_state = SUCCESS entry.save_now()
def on_success(self, task_progress, task_id, args, kwargs): """ Update InstructorTask object corresponding to this task with info about success. Updates task_output and task_state. But it shouldn't actually do anything if the task is only creating subtasks to actually do the work. Assumes `task_progress` is a dict containing the task's result, with the following keys: 'attempted': number of attempts made 'succeeded': number of attempts that "succeeded" 'skipped': number of attempts that "skipped" 'failed': number of attempts that "failed" 'total': number of possible subtasks to attempt 'action_name': user-visible verb to use in status messages. Should be past-tense. Pass-through of input `action_name`. 'duration_ms': how long the task has (or had) been running. This is JSON-serialized and stored in the task_output column of the InstructorTask entry. """ TASK_LOG.debug(u'Task %s: success returned with progress: %s', task_id, task_progress) # We should be able to find the InstructorTask object to update # based on the task_id here, without having to dig into the # original args to the task. On the other hand, the entry_id # is the first value passed to all such args, so we'll use that. # And we assume that it exists, else we would already have had a failure. entry_id = args[0] entry = InstructorTask.objects.get(pk=entry_id) # Check to see if any subtasks had been defined as part of this task. # If not, then we know that we're done. (If so, let the subtasks # handle updating task_state themselves.) if len(entry.subtasks) == 0: entry.task_output = InstructorTask.create_output_for_success(task_progress) entry.task_state = SUCCESS entry.save_now()
def initialize_subtask_info(entry, action_name, total_num, subtask_id_list): """ Store initial subtask information to InstructorTask object. The InstructorTask's "task_output" field is initialized. This is a JSON-serialized dict. Counters for 'attempted', 'succeeded', 'failed', 'skipped' keys are initialized to zero, as is the 'duration_ms' value. A 'start_time' is stored for later duration calculations, and the total number of "things to do" is set, so the user can be told how much needs to be done overall. The `action_name` is also stored, to help with constructing more readable task_progress messages. The InstructorTask's "subtasks" field is also initialized. This is also a JSON-serialized dict. Keys include 'total', 'succeeded', 'retried', 'failed', which are counters for the number of subtasks. 'Total' is set here to the total number, while the other three are initialized to zero. Once the counters for 'succeeded' and 'failed' match the 'total', the subtasks are done and the InstructorTask's "status" will be changed to SUCCESS. The "subtasks" field also contains a 'status' key, that contains a dict that stores status information for each subtask. The value for each subtask (keyed by its task_id) is its subtask status, as defined by SubtaskStatus.to_dict(). This information needs to be set up in the InstructorTask before any of the subtasks start running. If not, there is a chance that the subtasks could complete before the parent task is done creating subtasks. Doing so also simplifies the save() here, as it avoids the need for locking. Monitoring code should assume that if an InstructorTask has subtask information, that it should rely on the status stored in the InstructorTask object, rather than status stored in the corresponding AsyncResult. """ task_progress = { 'action_name': action_name, 'attempted': 0, 'failed': 0, 'skipped': 0, 'succeeded': 0, 'total': total_num, 'duration_ms': int(0), 'start_time': time() } entry.task_output = InstructorTask.create_output_for_success(task_progress) entry.task_state = PROGRESS # Write out the subtasks information. num_subtasks = len(subtask_id_list) # Note that may not be necessary to store initial value with all those zeroes! # Write out as a dict, so it will go more smoothly into json. subtask_status = { subtask_id: (SubtaskStatus.create(subtask_id)).to_dict() for subtask_id in subtask_id_list } subtask_dict = { 'total': num_subtasks, 'succeeded': 0, 'failed': 0, 'status': subtask_status } entry.subtasks = json.dumps(subtask_dict) # and save the entry immediately, before any subtasks actually start work: entry.save_now() return task_progress
def _update_subtask_status(entry_id, current_task_id, new_subtask_status): """ Update the status of the subtask in the parent InstructorTask object tracking its progress. Uses select_for_update to lock the InstructorTask object while it is being updated. The operation is surrounded by a try/except/else that permit the manual transaction to be committed on completion, or rolled back on error. The InstructorTask's "task_output" field is updated. This is a JSON-serialized dict. Accumulates values for 'attempted', 'succeeded', 'failed', 'skipped' from `new_subtask_status` into the corresponding values in the InstructorTask's task_output. Also updates the 'duration_ms' value with the current interval since the original InstructorTask started. Note that this value is only approximate, since the subtask may be running on a different server than the original task, so is subject to clock skew. The InstructorTask's "subtasks" field is also updated. This is also a JSON-serialized dict. Keys include 'total', 'succeeded', 'retried', 'failed', which are counters for the number of subtasks. 'Total' is expected to have been set at the time the subtasks were created. The other three counters are incremented depending on the value of `status`. Once the counters for 'succeeded' and 'failed' match the 'total', the subtasks are done and the InstructorTask's "status" is changed to SUCCESS. The "subtasks" field also contains a 'status' key, that contains a dict that stores status information for each subtask. At the moment, the value for each subtask (keyed by its task_id) is the value of the SubtaskStatus.to_dict(), but could be expanded in future to store information about failure messages, progress made, etc. """ TASK_LOG.info("Preparing to update status for subtask %s for instructor task %d with status %s", current_task_id, entry_id, new_subtask_status) try: entry = InstructorTask.objects.select_for_update().get(pk=entry_id) subtask_dict = json.loads(entry.subtasks) subtask_status_info = subtask_dict['status'] if current_task_id not in subtask_status_info: # unexpected error -- raise an exception format_str = "Unexpected task_id '{}': unable to update status for subtask of instructor task '{}'" msg = format_str.format(current_task_id, entry_id) TASK_LOG.warning(msg) raise ValueError(msg) # Update status: subtask_status_info[current_task_id] = new_subtask_status.to_dict() # Update the parent task progress. # Set the estimate of duration, but only if it # increases. Clock skew between time() returned by different machines # may result in non-monotonic values for duration. task_progress = json.loads(entry.task_output) start_time = task_progress['start_time'] prev_duration = task_progress['duration_ms'] new_duration = int((time() - start_time) * 1000) task_progress['duration_ms'] = max(prev_duration, new_duration) # Update counts only when subtask is done. # In future, we can make this more responsive by updating status # between retries, by comparing counts that change from previous # retry. new_state = new_subtask_status.state if new_subtask_status is not None and new_state in READY_STATES: for statname in ['attempted', 'succeeded', 'failed', 'skipped']: task_progress[statname] += getattr(new_subtask_status, statname) # Figure out if we're actually done (i.e. this is the last task to complete). # This is easier if we just maintain a counter, rather than scanning the # entire new_subtask_status dict. if new_state == SUCCESS: subtask_dict['succeeded'] += 1 elif new_state in READY_STATES: subtask_dict['failed'] += 1 num_remaining = subtask_dict['total'] - subtask_dict['succeeded'] - subtask_dict['failed'] # If we're done with the last task, update the parent status to indicate that. # At present, we mark the task as having succeeded. In future, we should see # if there was a catastrophic failure that occurred, and figure out how to # report that here. if num_remaining <= 0: entry.task_state = SUCCESS entry.subtasks = json.dumps(subtask_dict) entry.task_output = InstructorTask.create_output_for_success(task_progress) TASK_LOG.debug("about to save....") entry.save() TASK_LOG.info("Task output updated to %s for subtask %s of instructor task %d", entry.task_output, current_task_id, entry_id) except Exception: TASK_LOG.exception("Unexpected error while updating InstructorTask.") dog_stats_api.increment('instructor_task.subtask.update_exception') raise
def _update_instructor_task(instructor_task, task_result): """ Updates and possibly saves a InstructorTask entry based on a task Result. Used when updated status is requested. The `instructor_task` that is passed in is updated in-place, but is usually not saved. In general, tasks that have finished (either with success or failure) should have their entries updated by the task itself, so are not updated here. Tasks that are still running are not updated and saved while they run. The one exception to the no-save rule are tasks that are in a "revoked" state. This may mean that the task never had the opportunity to update the InstructorTask entry. Tasks that are in progress and have subtasks doing the processing do not look to the task's AsyncResult object. When subtasks are running, the InstructorTask object itself is updated with the subtasks' progress, not any AsyncResult object. In this case, the InstructorTask is not updated at all. Calculates json to store in "task_output" field of the `instructor_task`, as well as updating the task_state. For a successful task, the json contains the output of the task result. For a failed task, the json contains "exception", "message", and "traceback" keys. A revoked task just has a "message" stating it was revoked. """ # Pull values out of the result object as close to each other as possible. # If we wait and check the values later, the values for the state and result # are more likely to have changed. Pull the state out first, and # then code assuming that the result may not exactly match the state. task_id = task_result.task_id result_state = task_result.state returned_result = task_result.result result_traceback = task_result.traceback # Assume we don't always save the InstructorTask entry if we don't have to, # but that in most cases we will update the InstructorTask in-place with its # current progress. entry_needs_updating = True entry_needs_saving = False task_output = None if instructor_task.task_state == PROGRESS and len( instructor_task.subtasks) > 0: # This happens when running subtasks: the result object is marked with SUCCESS, # meaning that the subtasks have successfully been defined. However, the InstructorTask # will be marked as in PROGRESS, until the last subtask completes and marks it as SUCCESS. # We want to ignore the parent SUCCESS if subtasks are still running, and just trust the # contents of the InstructorTask. entry_needs_updating = False elif result_state in [PROGRESS, SUCCESS]: # construct a status message directly from the task result's result: # it needs to go back with the entry passed in. log.info("background task (%s), state %s: result: %s", task_id, result_state, returned_result) task_output = InstructorTask.create_output_for_success(returned_result) elif result_state == FAILURE: # on failure, the result's result contains the exception that caused the failure exception = returned_result traceback = result_traceback if result_traceback is not None else '' log.warning("background task (%s) failed: %s %s", task_id, returned_result, traceback) task_output = InstructorTask.create_output_for_failure( exception, result_traceback) elif result_state == REVOKED: # on revocation, the result's result doesn't contain anything # but we cannot rely on the worker thread to set this status, # so we set it here. entry_needs_saving = True log.warning("background task (%s) revoked.", task_id) task_output = InstructorTask.create_output_for_revoked() # save progress and state into the entry, even if it's not being saved: # when celery is run in "ALWAYS_EAGER" mode, progress needs to go back # with the entry passed in. if entry_needs_updating: instructor_task.task_state = result_state if task_output is not None: instructor_task.task_output = task_output if entry_needs_saving: instructor_task.save()
def _update_subtask_status(entry_id, current_task_id, new_subtask_status): """ Update the status of the subtask in the parent InstructorTask object tracking its progress. Uses select_for_update to lock the InstructorTask object while it is being updated. The operation is surrounded by a try/except/else that permit the manual transaction to be committed on completion, or rolled back on error. The InstructorTask's "task_output" field is updated. This is a JSON-serialized dict. Accumulates values for 'attempted', 'succeeded', 'failed', 'skipped' from `new_subtask_status` into the corresponding values in the InstructorTask's task_output. Also updates the 'duration_ms' value with the current interval since the original InstructorTask started. Note that this value is only approximate, since the subtask may be running on a different server than the original task, so is subject to clock skew. The InstructorTask's "subtasks" field is also updated. This is also a JSON-serialized dict. Keys include 'total', 'succeeded', 'retried', 'failed', which are counters for the number of subtasks. 'Total' is expected to have been set at the time the subtasks were created. The other three counters are incremented depending on the value of `status`. Once the counters for 'succeeded' and 'failed' match the 'total', the subtasks are done and the InstructorTask's "status" is changed to SUCCESS. The "subtasks" field also contains a 'status' key, that contains a dict that stores status information for each subtask. At the moment, the value for each subtask (keyed by its task_id) is the value of the SubtaskStatus.to_dict(), but could be expanded in future to store information about failure messages, progress made, etc. """ TASK_LOG.info( "Preparing to update status for subtask %s for instructor task %d with status %s", current_task_id, entry_id, new_subtask_status) try: entry = InstructorTask.objects.select_for_update().get(pk=entry_id) subtask_dict = json.loads(entry.subtasks) subtask_status_info = subtask_dict['status'] if current_task_id not in subtask_status_info: # unexpected error -- raise an exception format_str = "Unexpected task_id '{}': unable to update status for subtask of instructor task '{}'" msg = format_str.format(current_task_id, entry_id) TASK_LOG.warning(msg) raise ValueError(msg) # Update status: subtask_status_info[current_task_id] = new_subtask_status.to_dict() # Update the parent task progress. # Set the estimate of duration, but only if it # increases. Clock skew between time() returned by different machines # may result in non-monotonic values for duration. task_progress = json.loads(entry.task_output) start_time = task_progress['start_time'] prev_duration = task_progress['duration_ms'] new_duration = int((time() - start_time) * 1000) task_progress['duration_ms'] = max(prev_duration, new_duration) # Update counts only when subtask is done. # In future, we can make this more responsive by updating status # between retries, by comparing counts that change from previous # retry. new_state = new_subtask_status.state if new_subtask_status is not None and new_state in READY_STATES: for statname in ['attempted', 'succeeded', 'failed', 'skipped']: task_progress[statname] += getattr(new_subtask_status, statname) # Figure out if we're actually done (i.e. this is the last task to complete). # This is easier if we just maintain a counter, rather than scanning the # entire new_subtask_status dict. if new_state == SUCCESS: subtask_dict['succeeded'] += 1 elif new_state in READY_STATES: subtask_dict['failed'] += 1 num_remaining = subtask_dict['total'] - subtask_dict[ 'succeeded'] - subtask_dict['failed'] # If we're done with the last task, update the parent status to indicate that. # At present, we mark the task as having succeeded. In future, we should see # if there was a catastrophic failure that occurred, and figure out how to # report that here. if num_remaining <= 0: entry.task_state = SUCCESS entry.subtasks = json.dumps(subtask_dict) entry.task_output = InstructorTask.create_output_for_success( task_progress) TASK_LOG.debug("about to save....") entry.save() TASK_LOG.info( "Task output updated to %s for subtask %s of instructor task %d", entry.task_output, current_task_id, entry_id) except Exception: TASK_LOG.exception("Unexpected error while updating InstructorTask.") dog_stats_api.increment('instructor_task.subtask.update_exception') raise
def _update_instructor_task(instructor_task, task_result): """ Updates and possibly saves a InstructorTask entry based on a task Result. Used when updated status is requested. The `instructor_task` that is passed in is updated in-place, but is usually not saved. In general, tasks that have finished (either with success or failure) should have their entries updated by the task itself, so are not updated here. Tasks that are still running are not updated and saved while they run. The one exception to the no-save rule are tasks that are in a "revoked" state. This may mean that the task never had the opportunity to update the InstructorTask entry. Tasks that are in progress and have subtasks doing the processing do not look to the task's AsyncResult object. When subtasks are running, the InstructorTask object itself is updated with the subtasks' progress, not any AsyncResult object. In this case, the InstructorTask is not updated at all. Calculates json to store in "task_output" field of the `instructor_task`, as well as updating the task_state. For a successful task, the json contains the output of the task result. For a failed task, the json contains "exception", "message", and "traceback" keys. A revoked task just has a "message" stating it was revoked. """ # Pull values out of the result object as close to each other as possible. # If we wait and check the values later, the values for the state and result # are more likely to have changed. Pull the state out first, and # then code assuming that the result may not exactly match the state. task_id = task_result.task_id result_state = task_result.state returned_result = task_result.result result_traceback = task_result.traceback # Assume we don't always save the InstructorTask entry if we don't have to, # but that in most cases we will update the InstructorTask in-place with its # current progress. entry_needs_updating = True entry_needs_saving = False task_output = None if instructor_task.task_state == PROGRESS and len(instructor_task.subtasks) > 0: # This happens when running subtasks: the result object is marked with SUCCESS, # meaning that the subtasks have successfully been defined. However, the InstructorTask # will be marked as in PROGRESS, until the last subtask completes and marks it as SUCCESS. # We want to ignore the parent SUCCESS if subtasks are still running, and just trust the # contents of the InstructorTask. entry_needs_updating = False elif result_state in [PROGRESS, SUCCESS]: # construct a status message directly from the task result's result: # it needs to go back with the entry passed in. log.info("background task (%s), state %s: result: %s", task_id, result_state, returned_result) task_output = InstructorTask.create_output_for_success(returned_result) elif result_state == FAILURE: # on failure, the result's result contains the exception that caused the failure exception = returned_result traceback = result_traceback if result_traceback is not None else '' log.warning("background task (%s) failed: %s %s", task_id, returned_result, traceback) task_output = InstructorTask.create_output_for_failure(exception, result_traceback) elif result_state == REVOKED: # on revocation, the result's result doesn't contain anything # but we cannot rely on the worker thread to set this status, # so we set it here. entry_needs_saving = True log.warning("background task (%s) revoked.", task_id) task_output = InstructorTask.create_output_for_revoked() # save progress and state into the entry, even if it's not being saved: # when celery is run in "ALWAYS_EAGER" mode, progress needs to go back # with the entry passed in. if entry_needs_updating: instructor_task.task_state = result_state if task_output is not None: instructor_task.task_output = task_output if entry_needs_saving: instructor_task.save()