diff --git a/lms/djangoapps/certificates/management/commands/regenerate_user.py b/lms/djangoapps/certificates/management/commands/regenerate_user.py index 150d050..b3cd1dd 100644 --- a/lms/djangoapps/certificates/management/commands/regenerate_user.py +++ b/lms/djangoapps/certificates/management/commands/regenerate_user.py @@ -1,16 +1,20 @@ """Django management command to force certificate regeneration for one user""" +import logging +import copy from optparse import make_option from django.contrib.auth.models import User from django.core.management.base import BaseCommand, CommandError from opaque_keys import InvalidKeyError from opaque_keys.edx.keys import CourseKey from opaque_keys.edx.locations import SlashSeparatedCourseKey -from xmodule.course_module import CourseDescriptor from xmodule.modulestore.django import modulestore from certificates.queue import XQueueCertInterface +LOGGER = logging.getLogger(__name__) + + class Command(BaseCommand): help = """Put a request on the queue to recreate the certificate for a particular user in a particular course.""" @@ -49,12 +53,32 @@ class Command(BaseCommand): ) def handle(self, *args, **options): + + # Scrub the username from the log message + cleaned_options = copy.copy(options) + if 'username' in cleaned_options: + cleaned_options['username'] = '<USERNAME>' + LOGGER.info( + ( + u"Starting to create tasks to regenerate certificates " + u"with arguments %s and options %s" + ), + unicode(args), + unicode(cleaned_options) + ) + if options['course']: # try to parse out the course from the serialized form try: course_id = CourseKey.from_string(options['course']) except InvalidKeyError: - print("Course id {} could not be parsed as a CourseKey; falling back to SSCK.from_dep_str".format(options['course'])) + LOGGER.warning( + ( + u"Course id %s could not be parsed as a CourseKey; " + u"falling back to SlashSeparatedCourseKey.from_deprecated_string()" + ), + options['course'] + ) course_id = SlashSeparatedCourseKey.from_deprecated_string(options['course']) else: raise CommandError("You must specify a course") @@ -64,23 +88,61 @@ class Command(BaseCommand): raise CommandError('both course id and student username are required') student = None - print "Fetching enrollment for student {0} in {1}".format(user, course_id) if '@' in user: student = User.objects.get(email=user, courseenrollment__course_id=course_id) else: student = User.objects.get(username=user, courseenrollment__course_id=course_id) - print "Fetching course data for {0}".format(course_id) course = modulestore().get_course(course_id, depth=2) if not options['noop']: + LOGGER.info( + ( + u"Adding task to the XQueue to generate a certificate " + u"for student %s in course '%s'." + ), + student.id, + course_id + ) + # Add the certificate request to the queue - xq = XQueueCertInterface() + xqueue_interface = XQueueCertInterface() if options['insecure']: - xq.use_https = False - ret = xq.regen_cert(student, course_id, course=course, - forced_grade=options['grade_value'], - template_file=options['template_file']) - print '{0} - {1}'.format(student, ret) + xqueue_interface.use_https = False + + ret = xqueue_interface.regen_cert( + student, course_id, course=course, + forced_grade=options['grade_value'], + template_file=options['template_file'] + ) + + LOGGER.info( + ( + u"Added a certificate regeneration task to the XQueue " + u"for student %s in course '%s'. " + u"The new certificate status is '%s'." + ), + student.id, + unicode(course_id), + ret + ) + else: - print "noop option given, skipping work queueing..." + LOGGER.info( + ( + u"Skipping certificate generation for " + u"student %s in course '%s' " + u"because the noop flag is set." + ), + student.id, + unicode(course_id) + ) + + LOGGER.info( + ( + u"Finished regenerating certificates command for " + u"user %s and course '%s'." + ), + student.id, + unicode(course_id) + ) diff --git a/lms/djangoapps/certificates/management/commands/ungenerated_certs.py b/lms/djangoapps/certificates/management/commands/ungenerated_certs.py index 7718dc9..838e422 100644 --- a/lms/djangoapps/certificates/management/commands/ungenerated_certs.py +++ b/lms/djangoapps/certificates/management/commands/ungenerated_certs.py @@ -2,20 +2,22 @@ Management command to find all students that need certificates for courses that have finished, and put their cert requests on the queue. """ +import logging +import datetime +from pytz import UTC from django.core.management.base import BaseCommand, CommandError from certificates.models import certificate_status_for_student from certificates.queue import XQueueCertInterface from django.contrib.auth.models import User from optparse import make_option -from django.conf import settings from opaque_keys import InvalidKeyError from opaque_keys.edx.keys import CourseKey from opaque_keys.edx.locations import SlashSeparatedCourseKey -from xmodule.course_module import CourseDescriptor from xmodule.modulestore.django import modulestore from certificates.models import CertificateStatuses -import datetime -from pytz import UTC + + +LOGGER = logging.getLogger(__name__) class Command(BaseCommand): @@ -59,12 +61,21 @@ class Command(BaseCommand): def handle(self, *args, **options): + LOGGER.info( + ( + u"Starting to create tasks for ungenerated certificates " + u"with arguments %s and options %s" + ), + unicode(args), + unicode(options) + ) + # Will only generate a certificate if the current # status is in the unavailable state, can be set # to something else with the force flag if options['force']: - valid_statuses = getattr(CertificateStatuses, options['force']) + valid_statuses = [getattr(CertificateStatuses, options['force'])] else: valid_statuses = [CertificateStatuses.unavailable] @@ -77,7 +88,13 @@ class Command(BaseCommand): try: course = CourseKey.from_string(options['course']) except InvalidKeyError: - print("Course id {} could not be parsed as a CourseKey; falling back to SSCK.from_dep_str".format(options['course'])) + LOGGER.warning( + ( + u"Course id %s could not be parsed as a CourseKey; " + u"falling back to SlashSeparatedCourseKey.from_deprecated_string()" + ), + options['course'] + ) course = SlashSeparatedCourseKey.from_deprecated_string(options['course']) ended_courses = [course] else: @@ -87,9 +104,9 @@ class Command(BaseCommand): # prefetch all chapters/sequentials by saying depth=2 course = modulestore().get_course(course_key, depth=2) - print "Fetching enrolled students for {0}".format(course_key.to_deprecated_string()) enrolled_students = User.objects.filter( - courseenrollment__course_id=course_key) + courseenrollment__course_id=course_key + ) xq = XQueueCertInterface() if options['insecure']: @@ -112,10 +129,61 @@ class Command(BaseCommand): count, total, hours, minutes) start = datetime.datetime.now(UTC) - if certificate_status_for_student( - student, course_key)['status'] in valid_statuses: + cert_status = certificate_status_for_student(student, course_key)['status'] + LOGGER.info( + ( + u"Student %s has certificate status '%s' " + u"in course '%s'" + ), + student.id, + cert_status, + unicode(course_key) + ) + + if cert_status in valid_statuses: + if not options['noop']: # Add the certificate request to the queue ret = xq.add_cert(student, course_key, course=course) + if ret == 'generating': - print '{0} - {1}'.format(student, ret) + LOGGER.info( + ( + u"Added a certificate generation task to the XQueue " + u"for student %s in course '%s'. " + u"The new certificate status is '%s'." + ), + student.id, + unicode(course_key), + ret + ) + + else: + LOGGER.info( + ( + u"Skipping certificate generation for " + u"student %s in course '%s' " + u"because the noop flag is set." + ), + student.id, + unicode(course_key) + ) + + else: + LOGGER.info( + ( + u"Skipped student %s because " + u"certificate status '%s' is not in %s" + ), + student.id, + cert_status, + unicode(valid_statuses) + ) + + LOGGER.info( + ( + u"Completed ungenerated certificates command " + u"for course '%s'" + ), + unicode(course_key) + ) diff --git a/lms/djangoapps/certificates/queue.py b/lms/djangoapps/certificates/queue.py index 790163b..782cb3a 100644 --- a/lms/djangoapps/certificates/queue.py +++ b/lms/djangoapps/certificates/queue.py @@ -19,7 +19,7 @@ import lxml.html from lxml.etree import XMLSyntaxError, ParserError -logger = logging.getLogger(__name__) +LOGGER = logging.getLogger(__name__) class XQueueCertInterface(object): @@ -101,8 +101,31 @@ class XQueueCertInterface(object): # AWS. See note in the docstring too. try: certificate = GeneratedCertificate.objects.get(user=student, course_id=course_id) + + LOGGER.info( + ( + u"Found an existing certificate entry for student %s " + u"in course '%s' " + u"with status '%s' while regenerating certificates. " + ), + student.id, + unicode(course_id), + certificate.status + ) + certificate.status = status.unavailable certificate.save() + + LOGGER.info( + ( + u"The certificate status for student %s " + u"in course '%s' has been changed to '%s'." + ), + student.id, + unicode(course_id), + certificate.status + ) + except GeneratedCertificate.DoesNotExist: pass @@ -153,17 +176,30 @@ class XQueueCertInterface(object): Returns the student's status """ - VALID_STATUSES = [status.generating, - status.unavailable, - status.deleted, - status.error, - status.notpassing] + valid_statuses = [ + status.generating, + status.unavailable, + status.deleted, + status.error, + status.notpassing + ] cert_status = certificate_status_for_student(student, course_id)['status'] - new_status = cert_status - if cert_status in VALID_STATUSES: + if cert_status not in valid_statuses: + LOGGER.warning( + ( + u"Cannot create certificate generation task for user %s " + u"in the course '%s'; " + u"the certificate status '%s' is not one of %s." + ), + student.id, + unicode(course_id), + cert_status, + unicode(valid_statuses) + ) + else: # grade the student # re-use the course passed in optionally so we don't have to re-fetch everything @@ -207,12 +243,33 @@ class XQueueCertInterface(object): grade_contents = grade.get('grade', None) try: grade_contents = lxml.html.fromstring(grade_contents).text_content() - except (TypeError, XMLSyntaxError, ParserError) as e: + except (TypeError, XMLSyntaxError, ParserError) as exc: + LOGGER.info( + ( + u"Could not retrieve grade for student %s " + u"in the course '%s' " + u"because an exception occurred while parsing the " + u"grade contents '%s' as HTML. " + u"The exception was: '%s'" + ), + student.id, + unicode(course_id), + grade_contents, + unicode(exc) + ) + # Despite blowing up the xml parser, bad values here are fine grade_contents = None if is_whitelisted or grade_contents is not None: + if is_whitelisted: + LOGGER.info( + u"Student %s is whitelisted in '%s'", + student.id, + unicode(course_id) + ) + # check to see whether the student is on the # the embargoed country restricted list # otherwise, put a new certificate request @@ -222,6 +279,18 @@ class XQueueCertInterface(object): new_status = status.restricted cert.status = new_status cert.save() + + LOGGER.info( + ( + u"Student %s is in the embargoed country restricted " + u"list, so their certificate status has been set to '%s' " + u"for the course '%s'. " + u"No certificate generation task was sent to the XQueue." + ), + student.id, + new_status, + unicode(course_id) + ) else: key = make_hashkey(random.random()) cert.key = key @@ -240,14 +309,36 @@ class XQueueCertInterface(object): cert.status = new_status cert.save() self._send_to_xqueue(contents, key) + + LOGGER.info( + ( + u"The certificate status has been set to '%s'. " + u"Sent a certificate grading task to the XQueue " + u"with the key '%s'. " + ), + key, + new_status + ) else: cert_status = status.notpassing cert.status = cert_status cert.save() + LOGGER.info( + ( + u"Student %s does not have a grade for '%s', " + u"so their certificate status has been set to '%s'. " + u"No certificate generation task was sent to the XQueue." + ), + student.id, + unicode(course_id), + cert_status + ) + return new_status def _send_to_xqueue(self, contents, key): + """Create a new task on the XQueue. """ if self.use_https: proto = "https" @@ -261,5 +352,5 @@ class XQueueCertInterface(object): (error, msg) = self.xqueue_interface.send_to_queue( header=xheader, body=json.dumps(contents)) if error: - logger.critical('Unable to add a request to the queue: {} {}'.format(error, msg)) + LOGGER.critical(u'Unable to add a request to the queue: %s %s', unicode(error), msg) raise Exception('Unable to send queue message')