Commit a8df217a by Will Daly Committed by Will Daly

Add info-level logging for the management commands used to generate certificates.

parent 3b6e76ce
"""Django management command to force certificate regeneration for one user""" """Django management command to force certificate regeneration for one user"""
import logging
import copy
from optparse import make_option from optparse import make_option
from django.contrib.auth.models import User from django.contrib.auth.models import User
from django.core.management.base import BaseCommand, CommandError from django.core.management.base import BaseCommand, CommandError
from opaque_keys import InvalidKeyError from opaque_keys import InvalidKeyError
from opaque_keys.edx.keys import CourseKey from opaque_keys.edx.keys import CourseKey
from opaque_keys.edx.locations import SlashSeparatedCourseKey from opaque_keys.edx.locations import SlashSeparatedCourseKey
from xmodule.course_module import CourseDescriptor
from xmodule.modulestore.django import modulestore from xmodule.modulestore.django import modulestore
from certificates.queue import XQueueCertInterface from certificates.queue import XQueueCertInterface
LOGGER = logging.getLogger(__name__)
class Command(BaseCommand): class Command(BaseCommand):
help = """Put a request on the queue to recreate the certificate for a particular user in a particular course.""" 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): ...@@ -49,12 +53,32 @@ class Command(BaseCommand):
) )
def handle(self, *args, **options): 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']: if options['course']:
# try to parse out the course from the serialized form # try to parse out the course from the serialized form
try: try:
course_id = CourseKey.from_string(options['course']) course_id = CourseKey.from_string(options['course'])
except InvalidKeyError: 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']) course_id = SlashSeparatedCourseKey.from_deprecated_string(options['course'])
else: else:
raise CommandError("You must specify a course") raise CommandError("You must specify a course")
...@@ -64,23 +88,61 @@ class Command(BaseCommand): ...@@ -64,23 +88,61 @@ class Command(BaseCommand):
raise CommandError('both course id and student username are required') raise CommandError('both course id and student username are required')
student = None student = None
print "Fetching enrollment for student {0} in {1}".format(user, course_id)
if '@' in user: if '@' in user:
student = User.objects.get(email=user, courseenrollment__course_id=course_id) student = User.objects.get(email=user, courseenrollment__course_id=course_id)
else: else:
student = User.objects.get(username=user, courseenrollment__course_id=course_id) 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) course = modulestore().get_course(course_id, depth=2)
if not options['noop']: 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 # Add the certificate request to the queue
xq = XQueueCertInterface() xqueue_interface = XQueueCertInterface()
if options['insecure']: if options['insecure']:
xq.use_https = False xqueue_interface.use_https = False
ret = xq.regen_cert(student, course_id, course=course,
forced_grade=options['grade_value'], ret = xqueue_interface.regen_cert(
template_file=options['template_file']) student, course_id, course=course,
print '{0} - {1}'.format(student, ret) 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: 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)
)
...@@ -2,20 +2,22 @@ ...@@ -2,20 +2,22 @@
Management command to find all students that need certificates for Management command to find all students that need certificates for
courses that have finished, and put their cert requests on the queue. 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 django.core.management.base import BaseCommand, CommandError
from certificates.models import certificate_status_for_student from certificates.models import certificate_status_for_student
from certificates.queue import XQueueCertInterface from certificates.queue import XQueueCertInterface
from django.contrib.auth.models import User from django.contrib.auth.models import User
from optparse import make_option from optparse import make_option
from django.conf import settings
from opaque_keys import InvalidKeyError from opaque_keys import InvalidKeyError
from opaque_keys.edx.keys import CourseKey from opaque_keys.edx.keys import CourseKey
from opaque_keys.edx.locations import SlashSeparatedCourseKey from opaque_keys.edx.locations import SlashSeparatedCourseKey
from xmodule.course_module import CourseDescriptor
from xmodule.modulestore.django import modulestore from xmodule.modulestore.django import modulestore
from certificates.models import CertificateStatuses from certificates.models import CertificateStatuses
import datetime
from pytz import UTC
LOGGER = logging.getLogger(__name__)
class Command(BaseCommand): class Command(BaseCommand):
...@@ -59,12 +61,21 @@ class Command(BaseCommand): ...@@ -59,12 +61,21 @@ class Command(BaseCommand):
def handle(self, *args, **options): 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 # Will only generate a certificate if the current
# status is in the unavailable state, can be set # status is in the unavailable state, can be set
# to something else with the force flag # to something else with the force flag
if options['force']: if options['force']:
valid_statuses = getattr(CertificateStatuses, options['force']) valid_statuses = [getattr(CertificateStatuses, options['force'])]
else: else:
valid_statuses = [CertificateStatuses.unavailable] valid_statuses = [CertificateStatuses.unavailable]
...@@ -77,7 +88,13 @@ class Command(BaseCommand): ...@@ -77,7 +88,13 @@ class Command(BaseCommand):
try: try:
course = CourseKey.from_string(options['course']) course = CourseKey.from_string(options['course'])
except InvalidKeyError: 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']) course = SlashSeparatedCourseKey.from_deprecated_string(options['course'])
ended_courses = [course] ended_courses = [course]
else: else:
...@@ -87,9 +104,9 @@ class Command(BaseCommand): ...@@ -87,9 +104,9 @@ class Command(BaseCommand):
# prefetch all chapters/sequentials by saying depth=2 # prefetch all chapters/sequentials by saying depth=2
course = modulestore().get_course(course_key, 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( enrolled_students = User.objects.filter(
courseenrollment__course_id=course_key) courseenrollment__course_id=course_key
)
xq = XQueueCertInterface() xq = XQueueCertInterface()
if options['insecure']: if options['insecure']:
...@@ -112,10 +129,61 @@ class Command(BaseCommand): ...@@ -112,10 +129,61 @@ class Command(BaseCommand):
count, total, hours, minutes) count, total, hours, minutes)
start = datetime.datetime.now(UTC) start = datetime.datetime.now(UTC)
if certificate_status_for_student( cert_status = certificate_status_for_student(student, course_key)['status']
student, course_key)['status'] in valid_statuses: 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']: if not options['noop']:
# Add the certificate request to the queue # Add the certificate request to the queue
ret = xq.add_cert(student, course_key, course=course) ret = xq.add_cert(student, course_key, course=course)
if ret == 'generating': 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)
)
...@@ -19,7 +19,7 @@ import lxml.html ...@@ -19,7 +19,7 @@ import lxml.html
from lxml.etree import XMLSyntaxError, ParserError from lxml.etree import XMLSyntaxError, ParserError
logger = logging.getLogger(__name__) LOGGER = logging.getLogger(__name__)
class XQueueCertInterface(object): class XQueueCertInterface(object):
...@@ -101,8 +101,31 @@ class XQueueCertInterface(object): ...@@ -101,8 +101,31 @@ class XQueueCertInterface(object):
# AWS. See note in the docstring too. # AWS. See note in the docstring too.
try: try:
certificate = GeneratedCertificate.objects.get(user=student, course_id=course_id) 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.status = status.unavailable
certificate.save() 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: except GeneratedCertificate.DoesNotExist:
pass pass
...@@ -153,17 +176,30 @@ class XQueueCertInterface(object): ...@@ -153,17 +176,30 @@ class XQueueCertInterface(object):
Returns the student's status Returns the student's status
""" """
VALID_STATUSES = [status.generating, valid_statuses = [
status.unavailable, status.generating,
status.deleted, status.unavailable,
status.error, status.deleted,
status.notpassing] status.error,
status.notpassing
]
cert_status = certificate_status_for_student(student, course_id)['status'] cert_status = certificate_status_for_student(student, course_id)['status']
new_status = cert_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 # grade the student
# re-use the course passed in optionally so we don't have to re-fetch everything # re-use the course passed in optionally so we don't have to re-fetch everything
...@@ -207,12 +243,33 @@ class XQueueCertInterface(object): ...@@ -207,12 +243,33 @@ class XQueueCertInterface(object):
grade_contents = grade.get('grade', None) grade_contents = grade.get('grade', None)
try: try:
grade_contents = lxml.html.fromstring(grade_contents).text_content() 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 # Despite blowing up the xml parser, bad values here are fine
grade_contents = None grade_contents = None
if is_whitelisted or grade_contents is not 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 # check to see whether the student is on the
# the embargoed country restricted list # the embargoed country restricted list
# otherwise, put a new certificate request # otherwise, put a new certificate request
...@@ -222,6 +279,18 @@ class XQueueCertInterface(object): ...@@ -222,6 +279,18 @@ class XQueueCertInterface(object):
new_status = status.restricted new_status = status.restricted
cert.status = new_status cert.status = new_status
cert.save() 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: else:
key = make_hashkey(random.random()) key = make_hashkey(random.random())
cert.key = key cert.key = key
...@@ -240,14 +309,36 @@ class XQueueCertInterface(object): ...@@ -240,14 +309,36 @@ class XQueueCertInterface(object):
cert.status = new_status cert.status = new_status
cert.save() cert.save()
self._send_to_xqueue(contents, key) 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: else:
cert_status = status.notpassing cert_status = status.notpassing
cert.status = cert_status cert.status = cert_status
cert.save() 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 return new_status
def _send_to_xqueue(self, contents, key): def _send_to_xqueue(self, contents, key):
"""Create a new task on the XQueue. """
if self.use_https: if self.use_https:
proto = "https" proto = "https"
...@@ -261,5 +352,5 @@ class XQueueCertInterface(object): ...@@ -261,5 +352,5 @@ class XQueueCertInterface(object):
(error, msg) = self.xqueue_interface.send_to_queue( (error, msg) = self.xqueue_interface.send_to_queue(
header=xheader, body=json.dumps(contents)) header=xheader, body=json.dumps(contents))
if error: 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') raise Exception('Unable to send queue message')
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment