Skip to content

E
edx-platform
Commit 6cdaad58 by Sarina Canelake
Options

Merge pull request #6730 from OmarIthawi/edraak/unicode-fixes-log-username 

(WIP) Unicode fixes for log messages with username and other unicode input
parents f579482e 01064fcc
Showing with 280 additions and 135 deletions
common/djangoapps/student/management/commands/assigngroups.py
...@@ -82,9 +82,11 @@ class Command(BaseCommand): ...@@ -82,9 +82,11 @@ class Command(BaseCommand):
v = random.uniform(0, 1) v = random.uniform(0, 1)
group = group_from_value(groups, v) group = group_from_value(groups, v)
group_objects[group].users.add(user) group_objects[group].users.add(user)
f.write("Assigned user {name} ({id}) to {group}\n".format(name=user.username, f.write(u"Assigned user {name} ({id}) to {group}\n".format(
name=user.username,
id=user.id, id=user.id,
group=group)) group=group
).encode('utf-8'))
## Save groups ## Save groups
for group in group_objects: for group in group_objects:
......
common/djangoapps/student/models.py
...@@ -122,13 +122,12 @@ def anonymous_id_for_user(user, course_id, save=True): ...@@ -122,13 +122,12 @@ def anonymous_id_for_user(user, course_id, save=True):
) )
if anonymous_user_id.anonymous_user_id != digest: if anonymous_user_id.anonymous_user_id != digest:
log.error( log.error(
"Stored anonymous user id {stored!r} for user {user!r} " u"Stored anonymous user id %r for user %r "
"in course {course!r} doesn't match computed id {digest!r}".format( u"in course %r doesn't match computed id %r",
user=user, user,
course=course_id, course_id,
stored=anonymous_user_id.anonymous_user_id, anonymous_user_id.anonymous_user_id,
digest=digest digest
)
) )
except IntegrityError: except IntegrityError:
# Another thread has already created this entry, so # Another thread has already created this entry, so
...@@ -889,7 +888,12 @@ class CourseEnrollment(models.Model): ...@@ -889,7 +888,12 @@ class CourseEnrollment(models.Model):
except: # pylint: disable=bare-except except: # pylint: disable=bare-except
if event_name and self.course_id: if event_name and self.course_id:
log.exception('Unable to emit event %s for user %s and course %s', event_name, self.user.username, self.course_id) log.exception(
u'Unable to emit event %s for user %s and course %s',
event_name,
self.user.username, # pylint: disable=no-member
self.course_id,
)
@classmethod @classmethod
def enroll(cls, user, course_key, mode="honor", check_access=False): def enroll(cls, user, course_key, mode="honor", check_access=False):
...@@ -930,10 +934,9 @@ class CourseEnrollment(models.Model): ...@@ -930,10 +934,9 @@ class CourseEnrollment(models.Model):
course = modulestore().get_course(course_key) course = modulestore().get_course(course_key)
except ItemNotFoundError: except ItemNotFoundError:
log.warning( log.warning(
"User {0} failed to enroll in non-existent course {1}".format( u"User %s failed to enroll in non-existent course %s",
user.username, user.username,
course_key.to_deprecated_string() course_key.to_deprecated_string(),
)
) )
raise NonExistentCourseError raise NonExistentCourseError
...@@ -942,28 +945,25 @@ class CourseEnrollment(models.Model): ...@@ -942,28 +945,25 @@ class CourseEnrollment(models.Model):
raise NonExistentCourseError raise NonExistentCourseError
if CourseEnrollment.is_enrollment_closed(user, course): if CourseEnrollment.is_enrollment_closed(user, course):
log.warning( log.warning(
"User {0} failed to enroll in course {1} because enrollment is closed".format( u"User %s failed to enroll in course %s because enrollment is closed",
user.username, user.username,
course_key.to_deprecated_string() course_key.to_deprecated_string()
) )
)
raise EnrollmentClosedError raise EnrollmentClosedError
if CourseEnrollment.is_course_full(course): if CourseEnrollment.is_course_full(course):
log.warning( log.warning(
"User {0} failed to enroll in full course {1}".format( u"User %s failed to enroll in full course %s",
user.username, user.username,
course_key.to_deprecated_string() course_key.to_deprecated_string(),
)
) )
raise CourseFullError raise CourseFullError
if CourseEnrollment.is_enrolled(user, course_key): if CourseEnrollment.is_enrolled(user, course_key):
log.warning( log.warning(
"User {0} attempted to enroll in {1}, but they were already enrolled".format( u"User %s attempted to enroll in %s, but they were already enrolled",
user.username, user.username,
course_key.to_deprecated_string() course_key.to_deprecated_string()
) )
)
if check_access: if check_access:
raise AlreadyEnrolledError raise AlreadyEnrolledError
...@@ -1029,8 +1029,11 @@ class CourseEnrollment(models.Model): ...@@ -1029,8 +1029,11 @@ class CourseEnrollment(models.Model):
record.update_enrollment(is_active=False, skip_refund=skip_refund) record.update_enrollment(is_active=False, skip_refund=skip_refund)
except cls.DoesNotExist: except cls.DoesNotExist:
err_msg = u"Tried to unenroll student {} from {} but they were not enrolled" log.error(
log.error(err_msg.format(user, course_id)) u"Tried to unenroll student %s from %s but they were not enrolled",
user,
course_id
)
@classmethod @classmethod
def unenroll_by_email(cls, email, course_id): def unenroll_by_email(cls, email, course_id):
...@@ -1046,8 +1049,11 @@ class CourseEnrollment(models.Model): ...@@ -1046,8 +1049,11 @@ class CourseEnrollment(models.Model):
user = User.objects.get(email=email) user = User.objects.get(email=email)
return cls.unenroll(user, course_id) return cls.unenroll(user, course_id)
except User.DoesNotExist: except User.DoesNotExist:
err_msg = u"Tried to unenroll email {} from course {}, but user not found" log.error(
log.error(err_msg.format(email, course_id)) u"Tried to unenroll email %s from course %s, but user not found",
email,
course_id
)
@classmethod @classmethod
def is_enrolled(cls, user, course_key): def is_enrolled(cls, user, course_key):
......
common/djangoapps/student/views.py
...@@ -285,9 +285,12 @@ def get_course_enrollment_pairs(user, course_org_filter, org_filter_out_set): ...@@ -285,9 +285,12 @@ def get_course_enrollment_pairs(user, course_org_filter, org_filter_out_set):
yield (course, enrollment) yield (course, enrollment)
else: else:
log.error("User {0} enrolled in {2} course {1}".format( log.error(
user.username, enrollment.course_id, "broken" if course else "non-existent" u"User %s enrolled in %s course %s",
)) user.username,
"broken" if course else "non-existent",
enrollment.course_id
)
def _cert_info(user, course, cert_status): def _cert_info(user, course, cert_status):
...@@ -338,8 +341,11 @@ def _cert_info(user, course, cert_status): ...@@ -338,8 +341,11 @@ def _cert_info(user, course, cert_status):
if status == 'ready': if status == 'ready':
if 'download_url' not in cert_status: if 'download_url' not in cert_status:
log.warning("User %s has a downloadable cert for %s, but no download url", log.warning(
user.username, course.id) u"User %s has a downloadable cert for %s, but no download url",
user.username,
course.id
)
return default_info return default_info
else: else:
status_dict['download_url'] = cert_status['download_url'] status_dict['download_url'] = cert_status['download_url']
...@@ -470,7 +476,12 @@ def is_course_blocked(request, redeemed_registration_codes, course_key): ...@@ -470,7 +476,12 @@ def is_course_blocked(request, redeemed_registration_codes, course_key):
blocked = True blocked = True
# disabling email notifications for unpaid registration courses # disabling email notifications for unpaid registration courses
Optout.objects.get_or_create(user=request.user, course_id=course_key) Optout.objects.get_or_create(user=request.user, course_id=course_key)
log.info(u"User {0} ({1}) opted out of receiving emails from course {2}".format(request.user.username, request.user.email, course_key)) log.info(
u"User %s (%s) opted out of receiving emails from course %s",
request.user.username,
request.user.email,
course_key
)
track.views.server_track(request, "change-email1-settings", {"receive_emails": "no", "course": course_key.to_deprecated_string()}, page='dashboard') track.views.server_track(request, "change-email1-settings", {"receive_emails": "no", "course": course_key.to_deprecated_string()}, page='dashboard')
break break
...@@ -771,18 +782,17 @@ def try_change_enrollment(request): ...@@ -771,18 +782,17 @@ def try_change_enrollment(request):
# There isn't really a way to display the results to the user, so we just log it # There isn't really a way to display the results to the user, so we just log it
# We expect the enrollment to be a success, and will show up on the dashboard anyway # We expect the enrollment to be a success, and will show up on the dashboard anyway
log.info( log.info(
"Attempted to automatically enroll after login. Response code: {0}; response body: {1}".format( u"Attempted to automatically enroll after login. Response code: %s; response body: %s",
enrollment_response.status_code, enrollment_response.status_code,
enrollment_response.content enrollment_response.content
) )
)
# Hack: since change_enrollment delivers its redirect_url in the content # Hack: since change_enrollment delivers its redirect_url in the content
# of its response, we check here that only the 200 codes with content # of its response, we check here that only the 200 codes with content
# will return redirect_urls. # will return redirect_urls.
if enrollment_response.status_code == 200 and enrollment_response.content != '': if enrollment_response.status_code == 200 and enrollment_response.content != '':
return enrollment_response.content return enrollment_response.content
except Exception as exc: # pylint: disable=broad-except except Exception as exc: # pylint: disable=broad-except
log.exception("Exception automatically enrolling after login: %s", exc) log.exception(u"Exception automatically enrolling after login: %s", exc)
def _update_email_opt_in(request, username, org): def _update_email_opt_in(request, username, org):
...@@ -842,11 +852,10 @@ def change_enrollment(request, check_access=True): ...@@ -842,11 +852,10 @@ def change_enrollment(request, check_access=True):
course_id = SlashSeparatedCourseKey.from_deprecated_string(request.POST.get("course_id")) course_id = SlashSeparatedCourseKey.from_deprecated_string(request.POST.get("course_id"))
except InvalidKeyError: except InvalidKeyError:
log.warning( log.warning(
"User {username} tried to {action} with invalid course id: {course_id}".format( u"User %s tried to %s with invalid course id: %s",
username=user.username, user.username,
action=action, action,
course_id=request.POST.get("course_id") request.POST.get("course_id"),
)
) )
return HttpResponseBadRequest(_("Invalid course id")) return HttpResponseBadRequest(_("Invalid course id"))
...@@ -854,8 +863,11 @@ def change_enrollment(request, check_access=True): ...@@ -854,8 +863,11 @@ def change_enrollment(request, check_access=True):
# Make sure the course exists # Make sure the course exists
# We don't do this check on unenroll, or a bad course id can't be unenrolled from # We don't do this check on unenroll, or a bad course id can't be unenrolled from
if not modulestore().has_course(course_id): if not modulestore().has_course(course_id):
log.warning("User {0} tried to enroll in non-existent course {1}" log.warning(
.format(user.username, course_id)) u"User %s tried to enroll in non-existent course %s",
user.username,
course_id
)
return HttpResponseBadRequest(_("Course id is invalid")) return HttpResponseBadRequest(_("Course id is invalid"))
# Record the user's email opt-in preference # Record the user's email opt-in preference
...@@ -1010,7 +1022,7 @@ def login_user(request, error=""): # pylint: disable-msg=too-many-statements,un ...@@ -1010,7 +1022,7 @@ def login_user(request, error=""): # pylint: disable-msg=too-many-statements,un
}) # TODO: this should be status code 301 # pylint: disable=fixme }) # TODO: this should be status code 301 # pylint: disable=fixme
except ExternalAuthMap.DoesNotExist: except ExternalAuthMap.DoesNotExist:
# This is actually the common case, logging in user without external linked login # This is actually the common case, logging in user without external linked login
AUDIT_LOG.info("User %s w/o external auth attempting login", user) AUDIT_LOG.info(u"User %s w/o external auth attempting login", user)
# see if account has been locked out due to excessive login failures # see if account has been locked out due to excessive login failures
user_found_by_email_lookup = user user_found_by_email_lookup = user
...@@ -1248,11 +1260,11 @@ def disable_account_ajax(request): ...@@ -1248,11 +1260,11 @@ def disable_account_ajax(request):
if account_action == 'disable': if account_action == 'disable':
user_account.account_status = UserStanding.ACCOUNT_DISABLED user_account.account_status = UserStanding.ACCOUNT_DISABLED
context['message'] = _("Successfully disabled {}'s account").format(username) context['message'] = _("Successfully disabled {}'s account").format(username)
log.info("{} disabled {}'s account".format(request.user, username)) log.info(u"%s disabled %s's account", request.user, username)
elif account_action == 'reenable': elif account_action == 'reenable':
user_account.account_status = UserStanding.ACCOUNT_ENABLED user_account.account_status = UserStanding.ACCOUNT_ENABLED
context['message'] = _("Successfully reenabled {}'s account").format(username) context['message'] = _("Successfully reenabled {}'s account").format(username)
log.info("{} reenabled {}'s account".format(request.user, username)) log.info(u"%s reenabled %s's account", request.user, username)
else: else:
context['message'] = _("Unexpected account status") context['message'] = _("Unexpected account status")
return JsonResponse(context, status=400) return JsonResponse(context, status=400)
...@@ -1619,7 +1631,7 @@ def create_account(request, post_override=None): # pylint: disable-msg=too-many ...@@ -1619,7 +1631,7 @@ def create_account(request, post_override=None): # pylint: disable-msg=too-many
else: else:
user.email_user(subject, message, from_address) user.email_user(subject, message, from_address)
except Exception: # pylint: disable=broad-except except Exception: # pylint: disable=broad-except
log.error('Unable to send activation email to user from "{from_address}"'.format(from_address=from_address), exc_info=True) log.error(u'Unable to send activation email to user from "%s"', from_address, exc_info=True)
js['value'] = _('Could not send activation e-mail.') js['value'] = _('Could not send activation e-mail.')
# What is the correct status code to use here? I think it's 500, because # What is the correct status code to use here? I think it's 500, because
# the problem is on the server's end -- but also, the account was created. # the problem is on the server's end -- but also, the account was created.
...@@ -1642,8 +1654,8 @@ def create_account(request, post_override=None): # pylint: disable-msg=too-many ...@@ -1642,8 +1654,8 @@ def create_account(request, post_override=None): # pylint: disable-msg=too-many
eamap.user = new_user eamap.user = new_user
eamap.dtsignup = datetime.datetime.now(UTC) eamap.dtsignup = datetime.datetime.now(UTC)
eamap.save() eamap.save()
AUDIT_LOG.info("User registered with external_auth %s", post_vars['username']) AUDIT_LOG.info(u"User registered with external_auth %s", post_vars['username'])
AUDIT_LOG.info('Updated ExternalAuthMap for %s to be %s', post_vars['username'], eamap) AUDIT_LOG.info(u'Updated ExternalAuthMap for %s to be %s', post_vars['username'], eamap)
if settings.FEATURES.get('BYPASS_ACTIVATION_EMAIL_FOR_EXTAUTH'): if settings.FEATURES.get('BYPASS_ACTIVATION_EMAIL_FOR_EXTAUTH'):
log.info('bypassing activation email') log.info('bypassing activation email')
...@@ -1951,7 +1963,7 @@ def reactivation_email_for_user(user): ...@@ -1951,7 +1963,7 @@ def reactivation_email_for_user(user):
try: try:
user.email_user(subject, message, settings.DEFAULT_FROM_EMAIL) user.email_user(subject, message, settings.DEFAULT_FROM_EMAIL)
except Exception: # pylint: disable=broad-except except Exception: # pylint: disable=broad-except
log.error('Unable to send reactivation email from "{from_address}"'.format(from_address=settings.DEFAULT_FROM_EMAIL), exc_info=True) log.error(u'Unable to send reactivation email from "%s"', settings.DEFAULT_FROM_EMAIL, exc_info=True)
return JsonResponse({ return JsonResponse({
"success": False, "success": False,
"error": _('Unable to send reactivation email') "error": _('Unable to send reactivation email')
...@@ -2028,7 +2040,7 @@ def change_email_request(request): ...@@ -2028,7 +2040,7 @@ def change_email_request(request):
try: try:
send_mail(subject, message, from_address, [pec.new_email]) send_mail(subject, message, from_address, [pec.new_email])
except Exception: # pylint: disable=broad-except except Exception: # pylint: disable=broad-except
log.error('Unable to send email activation link to user from "{from_address}"'.format(from_address=from_address), exc_info=True) log.error(u'Unable to send email activation link to user from "%s"', from_address, exc_info=True)
return JsonResponse({ return JsonResponse({
"success": False, "success": False,
"error": _('Unable to send email activation link. Please try again later.') "error": _('Unable to send email activation link. Please try again later.')
...@@ -2228,11 +2240,21 @@ def change_email_settings(request): ...@@ -2228,11 +2240,21 @@ def change_email_settings(request):
optout_object = Optout.objects.filter(user=user, course_id=course_key) optout_object = Optout.objects.filter(user=user, course_id=course_key)
if optout_object: if optout_object:
optout_object.delete() optout_object.delete()
log.info(u"User {0} ({1}) opted in to receive emails from course {2}".format(user.username, user.email, course_id)) log.info(
u"User %s (%s) opted in to receive emails from course %s",
user.username,
user.email,
course_id
)
track.views.server_track(request, "change-email-settings", {"receive_emails": "yes", "course": course_id}, page='dashboard') track.views.server_track(request, "change-email-settings", {"receive_emails": "yes", "course": course_id}, page='dashboard')
else: else:
Optout.objects.get_or_create(user=user, course_id=course_key) Optout.objects.get_or_create(user=user, course_id=course_key)
log.info(u"User {0} ({1}) opted out of receiving emails from course {2}".format(user.username, user.email, course_id)) log.info(
u"User %s (%s) opted out of receiving emails from course %s",
user.username,
user.email,
course_id
)
track.views.server_track(request, "change-email-settings", {"receive_emails": "no", "course": course_id}, page='dashboard') track.views.server_track(request, "change-email-settings", {"receive_emails": "no", "course": course_id}, page='dashboard')
return JsonResponse({"success": True}) return JsonResponse({"success": True})
lms/djangoapps/certificates/views.py
...@@ -36,7 +36,8 @@ def request_certificate(request): ...@@ -36,7 +36,8 @@ def request_certificate(request):
status = certificate_status_for_student(student, course_key)['status'] status = certificate_status_for_student(student, course_key)['status']
if status in [CertificateStatuses.unavailable, CertificateStatuses.notpassing, CertificateStatuses.error]: if status in [CertificateStatuses.unavailable, CertificateStatuses.notpassing, CertificateStatuses.error]:
logger.info('Grading and certification requested for user {} in course {} via /request_certificate call'.format(username, course_key)) log_msg = u'Grading and certification requested for user %s in course %s via /request_certificate call'
logger.info(log_msg, username, course_key)
status = xqci.add_cert(student, course_key, course=course) status = xqci.add_cert(student, course_key, course=course)
return HttpResponse(json.dumps({'add_status': status}), mimetype='application/json') return HttpResponse(json.dumps({'add_status': status}), mimetype='application/json')
return HttpResponse(json.dumps({'add_status': 'ERRORANONYMOUSUSER'}), mimetype='application/json') return HttpResponse(json.dumps({'add_status': 'ERRORANONYMOUSUSER'}), mimetype='application/json')
......
lms/djangoapps/courseware/grades.py
...@@ -89,8 +89,9 @@ def answer_distributions(course_key): ...@@ -89,8 +89,9 @@ def answer_distributions(course_key):
raw_answers = state_dict.get("student_answers", {}) raw_answers = state_dict.get("student_answers", {})
except ValueError: except ValueError:
log.error( log.error(
"Answer Distribution: Could not parse module state for " + u"Answer Distribution: Could not parse module state for StudentModule id=%s, course=%s",
"StudentModule id={}, course={}".format(module.id, course_key) module.id,
course_key,
) )
continue continue
......
lms/djangoapps/courseware/management/commands/regrade_partial.py
...@@ -52,9 +52,13 @@ class Command(BaseCommand): ...@@ -52,9 +52,13 @@ class Command(BaseCommand):
module_state = module.state module_state = module.state
if module_state is None: if module_state is None:
# not likely, since we filter on it. But in general... # not likely, since we filter on it. But in general...
LOG.info("No state found for {type} module {id} for student {student} in course {course_id}" LOG.info(
.format(type=module.module_type, id=module.module_state_key, u"No state found for %s module %s for student %s in course %s",
student=module.student.username, course_id=module.course_id)) module.module_type,
module.module_state_key,
module.student.username,
module.course_id,
)
return return
state_dict = json.loads(module_state) state_dict = json.loads(module_state)
...@@ -66,15 +70,31 @@ class Command(BaseCommand): ...@@ -66,15 +70,31 @@ class Command(BaseCommand):
if (not student_answers) or len(student_answers) == 0: if (not student_answers) or len(student_answers) == 0:
# we should not have a grade here: # we should not have a grade here:
if module.grade != 0: if module.grade != 0:
LOG.error("No answer found but grade {grade} exists for {type} module {id} for student {student} " log_msg = (
"in course {course_id}".format(grade=module.grade, u"No answer found but grade %(grade)s exists for %(type)s module %(id)s for student %(student)s " +
type=module.module_type, id=module.module_state_key, u"in course %(course_id)s"
student=module.student.username, course_id=module.course_id)) )
LOG.error(log_msg, {
"grade": module.grade,
"type": module.module_type,
"id": module.module_state_key,
"student": module.student.username,
"course_id": module.course_id,
})
else: else:
LOG.debug("No answer and no grade found for {type} module {id} for student {student} " log_msg = (
"in course {course_id}".format(grade=module.grade, u"No answer and no grade found for %(type)s module %(id)s for student %(student)s " +
type=module.module_type, id=module.module_state_key, u"in course %(course_id)s"
student=module.student.username, course_id=module.course_id)) )
LOG.debug(log_msg, {
"grade": module.grade,
"type": module.module_type,
"id": module.module_state_key,
"student": module.student.username,
"course_id": module.course_id,
})
return return
# load into a CorrectMap, as done in LoncapaProblem.__init__(): # load into a CorrectMap, as done in LoncapaProblem.__init__():
...@@ -90,24 +110,48 @@ class Command(BaseCommand): ...@@ -90,24 +110,48 @@ class Command(BaseCommand):
if module.grade == correct: if module.grade == correct:
# nothing to change # nothing to change
LOG.debug("Grade matches for {type} module {id} for student {student} in course {course_id}" log_msg = u"Grade matches for %(type)s module %(id)s for student %(student)s in course %(course_id)s"
.format(type=module.module_type, id=module.module_state_key, LOG.debug(log_msg, {
student=module.student.username, course_id=module.course_id)) "type": module.module_type,
"id": module.module_state_key,
"student": module.student.username,
"course_id": module.course_id,
})
elif save_changes: elif save_changes:
# make the change # make the change
LOG.info("Grade changing from {0} to {1} for {type} module {id} for student {student} " log_msg = (
"in course {course_id}".format(module.grade, correct, u"Grade changing from %(grade)s to %(correct)s for %(type)s module " +
type=module.module_type, id=module.module_state_key, u"%(id)s for student %(student)s in course %(course_id)s"
student=module.student.username, course_id=module.course_id)) )
LOG.debug(log_msg, {
"grade": module.grade,
"correct": correct,
"type": module.module_type,
"id": module.module_state_key,
"student": module.student.username,
"course_id": module.course_id,
})
module.grade = correct module.grade = correct
module.save() module.save()
self.num_changed += 1 self.num_changed += 1
else: else:
# don't make the change, but log that the change would be made # don't make the change, but log that the change would be made
LOG.info("Grade would change from {0} to {1} for {type} module {id} for student {student} " log_msg = (
"in course {course_id}".format(module.grade, correct, u"Grade would change from %(grade)s to %(correct)s for %(type)s module %(id)s for student " +
type=module.module_type, id=module.module_state_key, u"%(student)s in course %(course_id)s"
student=module.student.username, course_id=module.course_id)) )
LOG.debug(log_msg, {
"grade": module.grade,
"correct": correct,
"type": module.module_type,
"id": module.module_state_key,
"student": module.student.username,
"course_id": module.course_id,
})
self.num_changed += 1 self.num_changed += 1
def handle(self, **options): def handle(self, **options):
......
lms/djangoapps/courseware/management/commands/remove_input_state.py
...@@ -68,7 +68,7 @@ class Command(BaseCommand): ...@@ -68,7 +68,7 @@ class Command(BaseCommand):
try: try:
module = StudentModule.objects.get(id=student_module_id) module = StudentModule.objects.get(id=student_module_id)
except StudentModule.DoesNotExist: except StudentModule.DoesNotExist:
LOG.error("Unable to find student module with id = {0}: skipping... ".format(student_module_id)) LOG.error(u"Unable to find student module with id = %s: skipping... ", student_module_id)
continue continue
self.remove_studentmodule_input_state(module, save_changes) self.remove_studentmodule_input_state(module, save_changes)
......
lms/djangoapps/instructor/tests/test_api.py
...@@ -334,7 +334,7 @@ class TestInstructorAPIBulkAccountCreationAndEnrollment(ModuleStoreTestCase, Log ...@@ -334,7 +334,7 @@ class TestInstructorAPIBulkAccountCreationAndEnrollment(ModuleStoreTestCase, Log
self.assertEquals(len(data['general_errors']), 0) self.assertEquals(len(data['general_errors']), 0)
# test the log for email that's send to new created user. # test the log for email that's send to new created user.
info_log.assert_called_with('email sent to new created user at test_student@example.com') info_log.assert_called_with('email sent to new created user at %s', 'test_student@example.com')
@patch('instructor.views.api.log.info') @patch('instructor.views.api.log.info')
def test_account_creation_and_enrollment_with_csv_with_blank_lines(self, info_log): def test_account_creation_and_enrollment_with_csv_with_blank_lines(self, info_log):
...@@ -351,7 +351,7 @@ class TestInstructorAPIBulkAccountCreationAndEnrollment(ModuleStoreTestCase, Log ...@@ -351,7 +351,7 @@ class TestInstructorAPIBulkAccountCreationAndEnrollment(ModuleStoreTestCase, Log
self.assertEquals(len(data['general_errors']), 0) self.assertEquals(len(data['general_errors']), 0)
# test the log for email that's send to new created user. # test the log for email that's send to new created user.
info_log.assert_called_with('email sent to new created user at test_student@example.com') info_log.assert_called_with('email sent to new created user at %s', 'test_student@example.com')
@patch('instructor.views.api.log.info') @patch('instructor.views.api.log.info')
def test_email_and_username_already_exist(self, info_log): def test_email_and_username_already_exist(self, info_log):
...@@ -370,7 +370,11 @@ class TestInstructorAPIBulkAccountCreationAndEnrollment(ModuleStoreTestCase, Log ...@@ -370,7 +370,11 @@ class TestInstructorAPIBulkAccountCreationAndEnrollment(ModuleStoreTestCase, Log
self.assertEquals(len(data['general_errors']), 0) self.assertEquals(len(data['general_errors']), 0)
# test the log for email that's send to new created user. # test the log for email that's send to new created user.
info_log.assert_called_with("user already exists with username '{username}' and email '{email}'".format(username='test_student_1', email='test_student@example.com')) info_log.assert_called_with(
u"user already exists with username '%s' and email '%s'",
'test_student_1',
'test_student@example.com'
)
def test_file_upload_type_not_csv(self): def test_file_upload_type_not_csv(self):
""" """
...@@ -434,7 +438,11 @@ class TestInstructorAPIBulkAccountCreationAndEnrollment(ModuleStoreTestCase, Log ...@@ -434,7 +438,11 @@ class TestInstructorAPIBulkAccountCreationAndEnrollment(ModuleStoreTestCase, Log
uploaded_file = SimpleUploadedFile("temp.csv", csv_content) uploaded_file = SimpleUploadedFile("temp.csv", csv_content)
response = self.client.post(self.url, {'students_list': uploaded_file}) response = self.client.post(self.url, {'students_list': uploaded_file})
self.assertEqual(response.status_code, 200) self.assertEqual(response.status_code, 200)
info_log.assert_called_with('user {username} enrolled in the course {course}'.format(username='NotEnrolledStudent', course=self.course.id)) info_log.assert_called_with(
u'user %s enrolled in the course %s',
u'NotEnrolledStudent',
self.course.id
)
def test_user_with_already_existing_email_in_csv(self): def test_user_with_already_existing_email_in_csv(self):
""" """
......
lms/djangoapps/instructor/views/api.py
...@@ -358,15 +358,24 @@ def register_and_enroll_students(request, course_id): # pylint: disable=too-man ...@@ -358,15 +358,24 @@ def register_and_enroll_students(request, course_id): # pylint: disable=too-man
).format(email=email, username=username) ).format(email=email, username=username)
warnings.append({ warnings.append({
'username': username, 'email': email, 'response': warning_message}) 'username': username, 'email': email, 'response': warning_message
log.warning('email {email} already exist'.format(email=email)) })
log.warning(u'email %s already exist', email)
else: else:
log.info("user already exists with username '{username}' and email '{email}'".format(email=email, username=username)) log.info(
u"user already exists with username '%s' and email '%s'",
username,
email
)
# make sure user is enrolled in course # make sure user is enrolled in course
if not CourseEnrollment.is_enrolled(user, course_id): if not CourseEnrollment.is_enrolled(user, course_id):
CourseEnrollment.enroll(user, course_id) CourseEnrollment.enroll(user, course_id)
log.info('user {username} enrolled in the course {course}'.format(username=username, course=course.id)) log.info(
u'user %s enrolled in the course %s',
username,
course.id,
)
enroll_email(course_id=course_id, student_email=email, auto_enroll=True, email_students=True, email_params=email_params) enroll_email(course_id=course_id, student_email=email, auto_enroll=True, email_students=True, email_params=email_params)
else: else:
# This email does not yet exist, so we need to create a new account # This email does not yet exist, so we need to create a new account
...@@ -390,7 +399,7 @@ def register_and_enroll_students(request, course_id): # pylint: disable=too-man ...@@ -390,7 +399,7 @@ def register_and_enroll_students(request, course_id): # pylint: disable=too-man
email_params['password'] = password email_params['password'] = password
email_params['platform_name'] = microsite.get_value('platform_name', settings.PLATFORM_NAME) email_params['platform_name'] = microsite.get_value('platform_name', settings.PLATFORM_NAME)
send_mail_to_student(email, email_params) send_mail_to_student(email, email_params)
log.info('email sent to new created user at {email}'.format(email=email)) log.info(u'email sent to new created user at %s', email)
else: else:
general_errors.append({ general_errors.append({
...@@ -544,7 +553,7 @@ def students_update_enrollment(request, course_id): ...@@ -544,7 +553,7 @@ def students_update_enrollment(request, course_id):
except Exception as exc: # pylint: disable=broad-except except Exception as exc: # pylint: disable=broad-except
# catch and log any exceptions # catch and log any exceptions
# so that one error doesn't cause a 500. # so that one error doesn't cause a 500.
log.exception("Error while #{}ing student") log.exception(u"Error while #{}ing student")
log.exception(exc) log.exception(exc)
results.append({ results.append({
'identifier': identifier, 'identifier': identifier,
...@@ -618,7 +627,7 @@ def bulk_beta_modify_access(request, course_id): ...@@ -618,7 +627,7 @@ def bulk_beta_modify_access(request, course_id):
# catch and log any unexpected exceptions # catch and log any unexpected exceptions
# so that one error doesn't cause a 500. # so that one error doesn't cause a 500.
except Exception as exc: # pylint: disable=broad-except except Exception as exc: # pylint: disable=broad-except
log.exception("Error while #{}ing student") log.exception(u"Error while #{}ing student")
log.exception(exc) log.exception(exc)
error = True error = True
else: else:
...@@ -1980,7 +1989,7 @@ def proxy_legacy_analytics(request, course_id): ...@@ -1980,7 +1989,7 @@ def proxy_legacy_analytics(request, course_id):
try: try:
res = requests.get(url) res = requests.get(url)
except Exception: # pylint: disable=broad-except except Exception: # pylint: disable=broad-except
log.exception("Error requesting from analytics server at %s", url) log.exception(u"Error requesting from analytics server at %s", url)
return HttpResponse("Error requesting from analytics server.", status=500) return HttpResponse("Error requesting from analytics server.", status=500)
if res.status_code is 200: if res.status_code is 200:
...@@ -1995,10 +2004,9 @@ def proxy_legacy_analytics(request, course_id): ...@@ -1995,10 +2004,9 @@ def proxy_legacy_analytics(request, course_id):
else: else:
# 500 on all other unexpected status codes. # 500 on all other unexpected status codes.
log.error( log.error(
"Error fetching {}, code: {}, msg: {}".format( u"Error fetching %s, code: %s, msg: %s",
url, res.status_code, res.content url, res.status_code, res.content
) )
)
return HttpResponse( return HttpResponse(
"Error from analytics server ({}).".format(res.status_code), "Error from analytics server ({}).".format(res.status_code),
status=500 status=500
......
lms/djangoapps/instructor/views/legacy.py
...@@ -252,9 +252,11 @@ def instructor_dashboard(request, course_id): ...@@ -252,9 +252,11 @@ def instructor_dashboard(request, course_id):
try: try:
ddata.append([student.email, student.grades[aidx]]) ddata.append([student.email, student.grades[aidx]])
except IndexError: except IndexError:
log.debug('No grade for assignment {idx} ({name}) for student {email}'.format( log.debug(u'No grade for assignment %(idx)s (%(name)s) for student %(email)s', {
idx=aidx, name=aname, email=student.email) "idx": aidx,
) "name": aname,
"email": student.email,
})
datatable['data'] = ddata datatable['data'] = ddata
datatable['title'] = _('Grades for assignment "{name}"').format(name=aname) datatable['title'] = _('Grades for assignment "{name}"').format(name=aname)
...@@ -749,7 +751,7 @@ def get_student_grade_summary_data(request, course, get_grades=True, get_raw_sco ...@@ -749,7 +751,7 @@ def get_student_grade_summary_data(request, course, get_grades=True, get_raw_sco
if get_grades: if get_grades:
gradeset = student_grades(student, request, course, keep_raw_scores=get_raw_scores, use_offline=use_offline) gradeset = student_grades(student, request, course, keep_raw_scores=get_raw_scores, use_offline=use_offline)
log.debug('student={0}, gradeset={1}'.format(student, gradeset)) log.debug(u'student=%s, gradeset=%s', student, gradeset)
with gtab.add_row(student.id) as add_grade: with gtab.add_row(student.id) as add_grade:
if get_raw_scores: if get_raw_scores:
# TODO (ichuang) encode Score as dict instead of as list, so score[0] -> score['earned'] # TODO (ichuang) encode Score as dict instead of as list, so score[0] -> score['earned']
......
lms/djangoapps/lms_migration/migrate.py
...@@ -69,11 +69,11 @@ def manage_modulestores(request, reload_dir=None, commit_id=None): ...@@ -69,11 +69,11 @@ def manage_modulestores(request, reload_dir=None, commit_id=None):
html += '<h3>IP address: %s <h3>' % ip html += '<h3>IP address: %s <h3>' % ip
html += '<h3>User: %s </h3>' % request.user html += '<h3>User: %s </h3>' % request.user
html += '<h3>My pid: %s</h3>' % os.getpid() html += '<h3>My pid: %s</h3>' % os.getpid()
log.debug('request from ip=%s, user=%s' % (ip, request.user)) log.debug(u'request from ip=%s, user=%s', ip, request.user)
if not (ip in ALLOWED_IPS or 'any' in ALLOWED_IPS): if not (ip in ALLOWED_IPS or 'any' in ALLOWED_IPS):
if request.user and request.user.is_staff: if request.user and request.user.is_staff:
log.debug('request allowed because user=%s is staff' % request.user) log.debug(u'request allowed because user=%s is staff', request.user)
else: else:
html += 'Permission denied' html += 'Permission denied'
html += "</body></html>" html += "</body></html>"
...@@ -185,7 +185,7 @@ def gitreload(request, reload_dir=None): ...@@ -185,7 +185,7 @@ def gitreload(request, reload_dir=None):
if not (ip in ALLOWED_IPS or 'any' in ALLOWED_IPS): if not (ip in ALLOWED_IPS or 'any' in ALLOWED_IPS):
if request.user and request.user.is_staff: if request.user and request.user.is_staff:
log.debug('request allowed because user=%s is staff' % request.user) log.debug(u'request allowed because user=%s is staff', request.user)
else: else:
html += 'Permission denied' html += 'Permission denied'
html += "</body></html>" html += "</body></html>"
......
lms/djangoapps/shoppingcart/models.py
...@@ -1074,7 +1074,7 @@ class CouponRedemption(models.Model): ...@@ -1074,7 +1074,7 @@ class CouponRedemption(models.Model):
coupon_redemption = cls.objects.filter(user=user, order=cart) coupon_redemption = cls.objects.filter(user=user, order=cart)
if coupon_redemption: if coupon_redemption:
coupon_redemption.delete() coupon_redemption.delete()
log.info('Coupon redemption entry removed for user {0} for order {1}'.format(user, cart.id)) log.info(u'Coupon redemption entry removed for user %s for order %s', user, cart.id)
@classmethod @classmethod
def get_discount_price(cls, percentage_discount, value): def get_discount_price(cls, percentage_discount, value):
...@@ -1093,8 +1093,11 @@ class CouponRedemption(models.Model): ...@@ -1093,8 +1093,11 @@ class CouponRedemption(models.Model):
coupon_redemptions = cls.objects.filter(order=order, user=order.user) coupon_redemptions = cls.objects.filter(order=order, user=order.user)
for coupon_redemption in coupon_redemptions: for coupon_redemption in coupon_redemptions:
if coupon_redemption.coupon.code != coupon.code or coupon_redemption.coupon.id == coupon.id: if coupon_redemption.coupon.code != coupon.code or coupon_redemption.coupon.id == coupon.id:
log.exception("Coupon redemption already exist for user '{0}' against order id '{1}'" log.exception(
.format(order.user.username, order.id)) u"Coupon redemption already exist for user '%s' against order id '%s'",
order.user.username,
order.id,
)
raise MultipleCouponsNotAllowedException raise MultipleCouponsNotAllowedException
for item in cart_items: for item in cart_items:
...@@ -1106,8 +1109,11 @@ class CouponRedemption(models.Model): ...@@ -1106,8 +1109,11 @@ class CouponRedemption(models.Model):
item.list_price = item.unit_cost item.list_price = item.unit_cost
item.unit_cost = discount_price item.unit_cost = discount_price
item.save() item.save()
log.info("Discount generated for user {0} against order id '{1}' " log.info(
.format(order.user.username, order.id)) u"Discount generated for user %s against order id '%s'",
order.user.username,
order.id,
)
is_redemption_applied = True is_redemption_applied = True
return is_redemption_applied return is_redemption_applied
...@@ -1165,8 +1171,12 @@ class PaidCourseRegistration(OrderItem): ...@@ -1165,8 +1171,12 @@ class PaidCourseRegistration(OrderItem):
raise CourseDoesNotExistException raise CourseDoesNotExistException
if cls.contained_in_order(order, course_id): if cls.contained_in_order(order, course_id):
log.warning("User {} tried to add PaidCourseRegistration for course {}, already in cart id {}" log.warning(
.format(order.user.email, course_id, order.id)) u"User %s tried to add PaidCourseRegistration for course %s, already in cart id %s",
order.user.email,
course_id,
order.id,
)
raise ItemAlreadyInCartException raise ItemAlreadyInCartException
if CourseEnrollment.is_enrolled(user=order.user, course_key=course_id): if CourseEnrollment.is_enrolled(user=order.user, course_key=course_id):
...@@ -1466,7 +1476,11 @@ class CertificateItem(OrderItem): ...@@ -1466,7 +1476,11 @@ class CertificateItem(OrderItem):
try: try:
target_cert = target_certs[0] target_cert = target_certs[0]
except IndexError: except IndexError:
log.error("Matching CertificateItem not found while trying to refund. User %s, Course %s", course_enrollment.user, course_enrollment.course_id) log.error(
u"Matching CertificateItem not found while trying to refund. User %s, Course %s",
course_enrollment.user,
course_enrollment.course_id,
)
return return
target_cert.status = 'refunded' target_cert.status = 'refunded'
target_cert.refund_requested_time = datetime.now(pytz.utc) target_cert.refund_requested_time = datetime.now(pytz.utc)
......
lms/djangoapps/shoppingcart/tests/test_views.py
...@@ -584,7 +584,9 @@ class ShoppingCartViewsTests(ModuleStoreTestCase): ...@@ -584,7 +584,9 @@ class ShoppingCartViewsTests(ModuleStoreTestCase):
resp = self.client.post(reverse('shoppingcart.views.remove_item', args=[]), resp = self.client.post(reverse('shoppingcart.views.remove_item', args=[]),
{'id': reg_item.id}) {'id': reg_item.id})
debug_log.assert_called_with( debug_log.assert_called_with(
'Code redemption does not exist for order item id={0}.'.format(reg_item.id)) 'Code redemption does not exist for order item id=%s.',
str(reg_item.id)
)
self.assertEqual(resp.status_code, 200) self.assertEqual(resp.status_code, 200)
self.assertEquals(self.cart.orderitem_set.count(), 0) self.assertEquals(self.cart.orderitem_set.count(), 0)
...@@ -604,7 +606,11 @@ class ShoppingCartViewsTests(ModuleStoreTestCase): ...@@ -604,7 +606,11 @@ class ShoppingCartViewsTests(ModuleStoreTestCase):
self.assertEqual(resp.status_code, 200) self.assertEqual(resp.status_code, 200)
self.assertEquals(self.cart.orderitem_set.count(), 0) self.assertEquals(self.cart.orderitem_set.count(), 0)
info_log.assert_called_with( info_log.assert_called_with(
'Coupon "{0}" redemption entry removed for user "{1}" for order item "{2}"'.format(self.coupon_code, self.user, reg_item.id)) 'Coupon "%s" redemption entry removed for user "%s" for order item "%s"',
self.coupon_code,
self.user,
str(reg_item.id)
)
@patch('shoppingcart.views.log.info') @patch('shoppingcart.views.log.info')
def test_reset_redemption_for_coupon(self, info_log): def test_reset_redemption_for_coupon(self, info_log):
...@@ -619,7 +625,10 @@ class ShoppingCartViewsTests(ModuleStoreTestCase): ...@@ -619,7 +625,10 @@ class ShoppingCartViewsTests(ModuleStoreTestCase):
self.assertEqual(resp.status_code, 200) self.assertEqual(resp.status_code, 200)
info_log.assert_called_with( info_log.assert_called_with(
'Coupon redemption entry removed for user {0} for order {1}'.format(self.user, reg_item.id)) 'Coupon redemption entry removed for user %s for order %s',
self.user,
reg_item.id
)
@patch('shoppingcart.views.log.info') @patch('shoppingcart.views.log.info')
def test_coupon_discount_for_multiple_courses_in_cart(self, info_log): def test_coupon_discount_for_multiple_courses_in_cart(self, info_log):
...@@ -648,7 +657,11 @@ class ShoppingCartViewsTests(ModuleStoreTestCase): ...@@ -648,7 +657,11 @@ class ShoppingCartViewsTests(ModuleStoreTestCase):
self.assertEqual(resp.status_code, 200) self.assertEqual(resp.status_code, 200)
self.assertEquals(self.cart.orderitem_set.count(), 1) self.assertEquals(self.cart.orderitem_set.count(), 1)
info_log.assert_called_with( info_log.assert_called_with(
'Coupon "{0}" redemption entry removed for user "{1}" for order item "{2}"'.format(self.coupon_code, self.user, reg_item.id)) 'Coupon "%s" redemption entry removed for user "%s" for order item "%s"',
self.coupon_code,
self.user,
str(reg_item.id)
)
@patch('shoppingcart.views.log.info') @patch('shoppingcart.views.log.info')
def test_delete_certificate_item(self, info_log): def test_delete_certificate_item(self, info_log):
...@@ -664,7 +677,10 @@ class ShoppingCartViewsTests(ModuleStoreTestCase): ...@@ -664,7 +677,10 @@ class ShoppingCartViewsTests(ModuleStoreTestCase):
self.assertEqual(resp.status_code, 200) self.assertEqual(resp.status_code, 200)
self.assertEquals(self.cart.orderitem_set.count(), 1) self.assertEquals(self.cart.orderitem_set.count(), 1)
info_log.assert_called_with( info_log.assert_called_with(
'order item {0} removed for user {1}'.format(cert_item.id, self.user)) 'order item %s removed for user %s',
str(cert_item.id),
self.user
)
@patch('shoppingcart.views.log.info') @patch('shoppingcart.views.log.info')
def test_remove_coupon_redemption_on_clear_cart(self, info_log): def test_remove_coupon_redemption_on_clear_cart(self, info_log):
...@@ -682,7 +698,10 @@ class ShoppingCartViewsTests(ModuleStoreTestCase): ...@@ -682,7 +698,10 @@ class ShoppingCartViewsTests(ModuleStoreTestCase):
self.assertEquals(self.cart.orderitem_set.count(), 0) self.assertEquals(self.cart.orderitem_set.count(), 0)
info_log.assert_called_with( info_log.assert_called_with(
'Coupon redemption entry removed for user {0} for order {1}'.format(self.user, reg_item.id)) 'Coupon redemption entry removed for user %s for order %s',
self.user,
reg_item.id
)
def test_add_course_to_cart_already_registered(self): def test_add_course_to_cart_already_registered(self):
CourseEnrollment.enroll(self.user, self.course_key) CourseEnrollment.enroll(self.user, self.course_key)
...@@ -773,13 +792,18 @@ class ShoppingCartViewsTests(ModuleStoreTestCase): ...@@ -773,13 +792,18 @@ class ShoppingCartViewsTests(ModuleStoreTestCase):
{'id': cert_item.id}) {'id': cert_item.id})
self.assertEqual(resp2.status_code, 200) self.assertEqual(resp2.status_code, 200)
exception_log.assert_called_with( exception_log.assert_called_with(
'Cannot remove cart OrderItem id={0}. DoesNotExist or item is already purchased'.format(cert_item.id)) 'Cannot remove cart OrderItem id=%s. DoesNotExist or item is already purchased', str(cert_item.id)
)
resp3 = self.client.post(reverse('shoppingcart.views.remove_item', args=[]), resp3 = self.client.post(
{'id': -1}) reverse('shoppingcart.views.remove_item', args=[]),
{'id': -1}
)
self.assertEqual(resp3.status_code, 200) self.assertEqual(resp3.status_code, 200)
exception_log.assert_called_with( exception_log.assert_called_with(
'Cannot remove cart OrderItem id={0}. DoesNotExist or item is already purchased'.format(-1)) 'Cannot remove cart OrderItem id=%s. DoesNotExist or item is already purchased',
'-1'
)
@patch('shoppingcart.views.process_postpay_callback', postpay_mock) @patch('shoppingcart.views.process_postpay_callback', postpay_mock)
def test_postpay_callback_success(self): def test_postpay_callback_success(self):
......
lms/djangoapps/shoppingcart/views.py
...@@ -81,7 +81,7 @@ def add_course_to_cart(request, course_id): ...@@ -81,7 +81,7 @@ def add_course_to_cart(request, course_id):
assert isinstance(course_id, basestring) assert isinstance(course_id, basestring)
if not request.user.is_authenticated(): if not request.user.is_authenticated():
log.info("Anon user trying to add course {} to cart".format(course_id)) log.info(u"Anon user trying to add course %s to cart", course_id)
return HttpResponseForbidden(_('You must be logged-in to add to a shopping cart')) return HttpResponseForbidden(_('You must be logged-in to add to a shopping cart'))
cart = Order.get_cart_for_user(request.user) cart = Order.get_cart_for_user(request.user)
course_key = SlashSeparatedCourseKey.from_deprecated_string(course_id) course_key = SlashSeparatedCourseKey.from_deprecated_string(course_id)
...@@ -131,7 +131,7 @@ def update_user_cart(request): ...@@ -131,7 +131,7 @@ def update_user_cart(request):
try: try:
item = OrderItem.objects.get(id=item_id, status='cart') item = OrderItem.objects.get(id=item_id, status='cart')
except OrderItem.DoesNotExist: except OrderItem.DoesNotExist:
log.exception('Cart OrderItem id={item_id} DoesNotExist'.format(item_id=item_id)) log.exception(u'Cart OrderItem id=%s DoesNotExist', item_id)
return HttpResponseNotFound('Order item does not exist.') return HttpResponseNotFound('Order item does not exist.')
item.qty = qty item.qty = qty
...@@ -200,8 +200,11 @@ def clear_cart(request): ...@@ -200,8 +200,11 @@ def clear_cart(request):
coupon_redemption = CouponRedemption.objects.filter(user=request.user, order=cart.id) coupon_redemption = CouponRedemption.objects.filter(user=request.user, order=cart.id)
if coupon_redemption: if coupon_redemption:
coupon_redemption.delete() coupon_redemption.delete()
log.info('Coupon redemption entry removed for user {user} for order {order_id}'.format(user=request.user, log.info(
order_id=cart.id)) u'Coupon redemption entry removed for user %s for order %s',
request.user,
cart.id,
)
return HttpResponse('Cleared') return HttpResponse('Cleared')
...@@ -217,14 +220,20 @@ def remove_item(request): ...@@ -217,14 +220,20 @@ def remove_item(request):
items = OrderItem.objects.filter(id=item_id, status='cart').select_subclasses() items = OrderItem.objects.filter(id=item_id, status='cart').select_subclasses()
if not len(items): if not len(items):
log.exception('Cannot remove cart OrderItem id={item_id}. DoesNotExist or item is already purchased'.format( log.exception(
item_id=item_id)) u'Cannot remove cart OrderItem id=%s. DoesNotExist or item is already purchased',
item_id
)
else: else:
item = items[0] item = items[0]
if item.user == request.user: if item.user == request.user:
order_item_course_id = getattr(item, 'course_id') order_item_course_id = getattr(item, 'course_id')
item.delete() item.delete()
log.info('order item {item_id} removed for user {user}'.format(item_id=item_id, user=request.user)) log.info(
u'order item %s removed for user %s',
item_id,
request.user,
)
remove_code_redemption(order_item_course_id, item_id, item, request.user) remove_code_redemption(order_item_course_id, item_id, item, request.user)
item.order.update_order_type() item.order.update_order_type()
...@@ -244,10 +253,14 @@ def remove_code_redemption(order_item_course_id, item_id, item, user): ...@@ -244,10 +253,14 @@ def remove_code_redemption(order_item_course_id, item_id, item, user):
order=item.order_id order=item.order_id
) )
coupon_redemption.delete() coupon_redemption.delete()
log.info('Coupon "{code}" redemption entry removed for user "{user}" for order item "{item_id}"' log.info(
.format(code=coupon_redemption.coupon.code, user=user, item_id=item_id)) u'Coupon "%s" redemption entry removed for user "%s" for order item "%s"',
coupon_redemption.coupon.code,
user,
item_id,
)
except CouponRedemption.DoesNotExist: except CouponRedemption.DoesNotExist:
log.debug('Code redemption does not exist for order item id={item_id}.'.format(item_id=item_id)) log.debug(u'Code redemption does not exist for order item id=%s.', item_id)
@login_required @login_required
...@@ -310,7 +323,7 @@ def get_reg_code_validity(registration_code, request, limiter): ...@@ -310,7 +323,7 @@ def get_reg_code_validity(registration_code, request, limiter):
reg_code_already_redeemed = True reg_code_already_redeemed = True
if not reg_code_is_valid: if not reg_code_is_valid:
#tick the rate limiter counter # tick the rate limiter counter
AUDIT_LOG.info("Redemption of a non existing RegistrationCode {code}".format(code=registration_code)) AUDIT_LOG.info("Redemption of a non existing RegistrationCode {code}".format(code=registration_code))
limiter.tick_bad_request_counter(request) limiter.tick_bad_request_counter(request)
raise Http404() raise Http404()
...@@ -431,7 +444,7 @@ def use_registration_code(course_reg, user): ...@@ -431,7 +444,7 @@ def use_registration_code(course_reg, user):
and redirects the user to the Registration code redemption page. and redirects the user to the Registration code redemption page.
""" """
if RegistrationCodeRedemption.is_registration_code_redeemed(course_reg): if RegistrationCodeRedemption.is_registration_code_redeemed(course_reg):
log.warning("Registration code '{registration_code}' already used".format(registration_code=course_reg.code)) log.warning(u"Registration code '%s' already used", course_reg.code)
return HttpResponseBadRequest( return HttpResponseBadRequest(
_("Oops! The code '{registration_code}' you entered is either invalid or expired").format( _("Oops! The code '{registration_code}' you entered is either invalid or expired").format(
registration_code=course_reg.code registration_code=course_reg.code
...@@ -441,8 +454,7 @@ def use_registration_code(course_reg, user): ...@@ -441,8 +454,7 @@ def use_registration_code(course_reg, user):
cart = Order.get_cart_for_user(user) cart = Order.get_cart_for_user(user)
cart_items = cart.find_item_by_course_id(course_reg.course_id) cart_items = cart.find_item_by_course_id(course_reg.course_id)
except ItemNotFoundInCartException: except ItemNotFoundInCartException:
log.warning("Course item does not exist against registration code '{registration_code}'".format( log.warning(u"Course item does not exist against registration code '%s'", course_reg.code)
registration_code=course_reg.code))
return HttpResponseNotFound( return HttpResponseNotFound(
_("Code '{registration_code}' is not valid for any course in the shopping cart.").format( _("Code '{registration_code}' is not valid for any course in the shopping cart.").format(
registration_code=course_reg.code registration_code=course_reg.code
...@@ -481,7 +493,7 @@ def use_coupon_code(coupons, user): ...@@ -481,7 +493,7 @@ def use_coupon_code(coupons, user):
return HttpResponseBadRequest(_("Only one coupon redemption is allowed against an order")) return HttpResponseBadRequest(_("Only one coupon redemption is allowed against an order"))
if not is_redemption_applied: if not is_redemption_applied:
log.warning("Discount does not exist against code '{code}'.".format(code=coupons[0].code)) log.warning(u"Discount does not exist against code '%s'.", coupons[0].code)
return HttpResponseNotFound(_("Discount does not exist against code '{code}'.").format(code=coupons[0].code)) return HttpResponseNotFound(_("Discount does not exist against code '{code}'.").format(code=coupons[0].code))
return HttpResponse( return HttpResponse(
...@@ -560,10 +572,11 @@ def donate(request): ...@@ -560,10 +572,11 @@ def donate(request):
# Course ID may be None if this is a donation to the entire organization # Course ID may be None if this is a donation to the entire organization
Donation.add_to_order(cart, amount, course_id=course_id) Donation.add_to_order(cart, amount, course_id=course_id)
except InvalidCartItem as ex: except InvalidCartItem as ex:
log.exception(( log.exception(
u"Could not create donation item for " u"Could not create donation item for amount '%s' and course ID '%s'",
u"amount '{amount}' and course ID '{course_id}'" amount,
).format(amount=amount, course_id=course_id)) course_id
)
return HttpResponseBadRequest(unicode(ex)) return HttpResponseBadRequest(unicode(ex))
# Start the purchase. # Start the purchase.
......
lms/djangoapps/verify_student/views.py
...@@ -929,7 +929,7 @@ def midcourse_reverify_dash(request): ...@@ -929,7 +929,7 @@ def midcourse_reverify_dash(request):
try: try:
course_enrollment_pairs.append((modulestore().get_course(enrollment.course_id), enrollment)) course_enrollment_pairs.append((modulestore().get_course(enrollment.course_id), enrollment))
except ItemNotFoundError: except ItemNotFoundError:
log.error("User {0} enrolled in non-existent course {1}".format(user.username, enrollment.course_id)) log.error(u"User %s enrolled in non-existent course %s", user.username, enrollment.course_id)
statuses = ["approved", "pending", "must_reverify", "denied"] statuses = ["approved", "pending", "must_reverify", "denied"]
......
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