diff --git a/lms/djangoapps/bulk_email/tasks.py b/lms/djangoapps/bulk_email/tasks.py index c4810b15cd..8a8a03acad 100644 --- a/lms/djangoapps/bulk_email/tasks.py +++ b/lms/djangoapps/bulk_email/tasks.py @@ -7,7 +7,9 @@ import json import logging import random import re +import time from collections import Counter +from datetime import datetime from smtplib import SMTPConnectError, SMTPDataError, SMTPException, SMTPServerDisconnected from time import sleep @@ -207,6 +209,10 @@ def perform_delegate_email_batches(entry_id, course_id, task_input, action_name) def _create_send_email_subtask(to_list, initial_subtask_status): """Creates a subtask to send email to a given recipient list.""" subtask_id = initial_subtask_status.task_id + log.info( + u"BulkEmail Task: %s Subtask: %s starting at %s in Queue: %s", + task_id, subtask_id, datetime.now(), routing_key + ) new_subtask = send_course_email.subtask( ( entry_id, @@ -295,6 +301,7 @@ def send_course_email(entry_id, email_id, to_list, global_email_context, subtask new_subtask_status = None try: course_title = global_email_context['course_title'] + start_time = time.time() new_subtask_status, send_exception = _send_course_email( entry_id, email_id, @@ -302,6 +309,12 @@ def send_course_email(entry_id, email_id, to_list, global_email_context, subtask global_email_context, subtask_status, ) + log.info( + u"BulkEmail ==> _send_course_email completed in : %s for task : %s with recipient count: %s", + time.time() - start_time, + subtask_status.task_id, + len(to_list) + ) except Exception: # Unexpected exception. Try to write out the failure to the entry before failing. log.exception(u"Send-email task %s for email %s: failed unexpectedly!", current_task_id, email_id) @@ -504,6 +517,7 @@ def _send_course_email(entry_id, email_id, to_list, global_email_context, subtas email_context = {'name': '', 'email': ''} email_context.update(global_email_context) + start_time = time.time() while to_list: # Update context with user-specific values from the user at the end of the list. # At the end of processing this user, they will be popped off of the to_list. @@ -640,14 +654,15 @@ def _send_course_email(entry_id, email_id, to_list, global_email_context, subtas log.info( u"BulkEmail ==> Task: %s, SubTask: %s, EmailId: %s, Total Successful Recipients: %s/%s, \ - Failed Recipients: %s/%s", + Failed Recipients: %s/%s, Time Taken: %s", parent_task_id, task_id, email_id, total_recipients_successful, total_recipients, total_recipients_failed, - total_recipients + total_recipients, + time.time() - start_time ) duplicate_recipients = [u"{0} ({1})".format(email, repetition) for email, repetition in recipients_info.most_common() if repetition > 1] diff --git a/lms/djangoapps/instructor_task/subtasks.py b/lms/djangoapps/instructor_task/subtasks.py index 206ea6ecd7..c5e5bd202f 100644 --- a/lms/djangoapps/instructor_task/subtasks.py +++ b/lms/djangoapps/instructor_task/subtasks.py @@ -4,6 +4,7 @@ This module contains celery task functions for handling the management of subtas import json import logging from contextlib import contextmanager +from datetime import datetime from time import time from uuid import uuid4 @@ -336,6 +337,10 @@ def queue_subtasks_for_query( num_subtasks += 1 subtask_status = SubtaskStatus.create(subtask_id) new_subtask = create_subtask_fcn(item_list, subtask_status) + TASK_LOG.info( + u"Queueing BulkEmail Task: %s Subtask: %s at timestamp: %s", + task_id, subtask_id, datetime.now() + ) new_subtask.apply_async() # Subtasks have been queued so no exceptions should be raised after this point.