diff --git a/openedx/core/djangoapps/credentials/tasks/v1/tasks.py b/openedx/core/djangoapps/credentials/tasks/v1/tasks.py index ee24289dad..31d2db8cfa 100644 --- a/openedx/core/djangoapps/credentials/tasks/v1/tasks.py +++ b/openedx/core/djangoapps/credentials/tasks/v1/tasks.py @@ -23,7 +23,7 @@ from lms.djangoapps.grades.api import CourseGradeFactory, get_recently_modified_ from openedx.core.djangoapps.catalog.utils import get_programs from openedx.core.djangoapps.content.course_overviews.models import CourseOverview from openedx.core.djangoapps.credentials.helpers import is_learner_records_enabled_for_org -from openedx.core.djangoapps.credentials.models import CredentialsApiConfig +from openedx.core.djangoapps.credentials.api import is_credentials_enabled from openedx.core.djangoapps.credentials.utils import get_credentials_api_base_url, get_credentials_api_client from openedx.core.djangoapps.programs.signals import ( handle_course_cert_awarded, @@ -329,71 +329,60 @@ def send_grade_if_interesting( LMS. verbose (bool): A value determining the logging level desired for this grade update """ - if verbose: - msg = ( - f"Starting send_grade_if_interesting with_params: user [{getattr(user, 'username', None)}], " - f"course_run_key [{course_run_key}], mode [{mode}], status [{status}], letter_grade [{letter_grade}], " - f"percent_grade [{percent_grade}], grade_last_updated [{grade_last_updated}], verbose [{verbose}]" - ) - logger.info(msg) + warning_base = f"Skipping send grade for user {user} in course run {course_run_key}:" - # Avoid scheduling new tasks if certification is disabled. (Grades are a part of the records/cert story) - if not CredentialsApiConfig.current().is_learner_issuance_enabled: + if verbose: + logger.info( + f"Starting send_grade_if_interesting with params: user [{user}], course_run_key [{course_run_key}], mode " + f"[{mode}], status [{status}], letter_grade [{letter_grade}], percent_grade [{percent_grade}], " + f"grade_last_updated [{grade_last_updated}, verbose [{verbose}]" + ) + + if not is_credentials_enabled(): if verbose: - logger.info("Skipping send grade: is_learner_issuance_enabled False") + logger.warning(f"{warning_base} use of the Credentials IDA is disabled by config") return - # Avoid scheduling new tasks if learner records are disabled for this site. + # avoid scheduling tasks if the learner records feature has been disabled for this org if not is_learner_records_enabled_for_org(course_run_key.org): if verbose: - logger.info( - "Skipping send grade: ENABLE_LEARNER_RECORDS False for org [{org}]".format( - org=course_run_key.org - ) - ) + logger.warning(f"{warning_base} the learner records feature is disabled for the org {course_run_key.org}") return - # Grab mode/status if we don't have them in hand + # If we don't have mode and/or status, retrieve them from the learner's certificate record if mode is None or status is None: try: cert = GeneratedCertificate.objects.get(user=user, course_id=course_run_key) # pylint: disable=no-member mode = cert.mode status = cert.status except GeneratedCertificate.DoesNotExist: - # We only care about grades for which there is a certificate. + # we only care about grades for which there is a certificate record if verbose: - logger.info( - f"Skipping send grade: no cert for user [{getattr(user, 'username', None)}] & course_id " - f"[{course_run_key}]" - ) + logger.warning(f"{warning_base} no certificate record in the specified course run") return - # Don't worry about whether it's available as well as awarded. Just awarded is good enough to record a verified - # attempt at a course. We want even the grades that didn't pass the class because Credentials wants to know about - # those too. + # Don't worry about the certificate record being in a passing or awarded status. Having a certificate record in any + # status is good enough to record a verified attempt at a course. The Credentials IDA keeps track of how many times + # a learner has made an attempt at a course run of a course, so it wants to know about all the learner's efforts. + # This check is attempt to prevent updates being sent to Credentials that it does not care about (e.g. updates + # related to a legacy Audit course) if mode not in INTERESTING_MODES or status not in INTERESTING_STATUSES: if verbose: - logger.info(f"Skipping send grade: mode/status uninteresting for mode [{mode}] & status [{status}]") + logger.warning(f"{warning_base} mode ({mode}) or status ({status}) is not interesting to Credentials") return - # If the course isn't in any program, don't bother telling Credentials about it. When Credentials grows support - # for course records as well as program records, we'll need to open this up. + # don't bother sending an update if the course run is not associated with any programs if not is_course_run_in_a_program(course_run_key): if verbose: - logger.info( - f"Skipping send grade: course run not in a program. [{course_run_key}]" - ) + logger.warning(f"{warning_base} course run is not associated with any programs") return - # Grab grade data if we don't have them in hand + # grab additional grade data if we don't have it in hand if letter_grade is None or percent_grade is None or grade_last_updated is None: grade = CourseGradeFactory().read(user, course_key=course_run_key, create_if_needed=False) if grade is None: if verbose: - logger.info( - f"Skipping send grade: No grade found for user [{getattr(user, 'username', None)}] & course_id " - f"[{course_run_key}]" - ) + logger.warning(f"{warning_base} no grade found for user in the specified course run") return letter_grade = grade.letter_grade percent_grade = grade.percent diff --git a/openedx/core/djangoapps/programs/tasks.py b/openedx/core/djangoapps/programs/tasks.py index 96237ff26e..9d77f427d6 100644 --- a/openedx/core/djangoapps/programs/tasks.py +++ b/openedx/core/djangoapps/programs/tasks.py @@ -1,5 +1,6 @@ """ -This file contains celery tasks for programs-related functionality. +This file contains celery tasks and utility functions responsible for syncing course and program certificate metadata +between the monolith and the Credentials IDA. """ from typing import Dict, List from urllib.parse import urljoin @@ -19,9 +20,7 @@ from common.djangoapps.course_modes.models import CourseMode from lms.djangoapps.certificates.api import available_date_for_certificate from lms.djangoapps.certificates.models import GeneratedCertificate from openedx.core.djangoapps.content.course_overviews.api import get_course_overview_or_none -from openedx.core.djangoapps.content.course_overviews.models import CourseOverview from openedx.core.djangoapps.credentials.api import is_credentials_enabled -from openedx.core.djangoapps.credentials.models import CredentialsApiConfig from openedx.core.djangoapps.credentials.utils import ( get_credentials, get_credentials_api_base_url, @@ -34,12 +33,10 @@ from xmodule.data import CertificatesDisplayBehaviors User = get_user_model() LOGGER = get_task_logger(__name__) -# Maximum number of retries before giving up on awarding credentials. -# For reference, 11 retries with exponential backoff yields a maximum waiting -# time of 2047 seconds (about 30 minutes). Setting this to None could yield -# unwanted behavior: infinite retries. +# Maximum number of retries before giving up on awarding credentials. For reference, 11 retries with exponential backoff +# yields a maximum waiting time of 2047 seconds (about 30 minutes). Setting this to None could yield unwanted behavior: +# infinite retries. MAX_RETRIES = 11 - PROGRAM_CERTIFICATE = "program" COURSE_CERTIFICATE = "course-run" DATE_FORMAT = "%Y-%m-%dT%H:%M:%SZ" @@ -105,6 +102,35 @@ def get_certified_programs(student: User, raise_on_error: bool = False) -> List[ return certified_programs +def get_revokable_program_uuids(course_specific_programs: List[Dict], student: User) -> List[str]: + """ + Get program uuids for which certificate to be revoked. + + Checks for existing learner certificates and filter out the program UUIDS + for which a certificate needs to be revoked. + + Args: + course_specific_programs (dict[]): list of programs specific to a course + student (User): Representing the student whose programs to check for. + + Returns: + list of program UUIDs for which certificates to be revoked + + Raises: + HttpError, if the API call generated by get_certified_programs fails + """ + program_uuids_to_revoke = [] + # Get any programs where the user has already been rewarded a certificate + # Failed API calls with get_certified_programs should raise exceptions, + # because an empty response would dangerously imply a false negative. + existing_program_uuids = get_certified_programs(student, raise_on_error=True) + for program in course_specific_programs: + if program["uuid"] in existing_program_uuids: + program_uuids_to_revoke.append(program["uuid"]) + + return program_uuids_to_revoke + + def award_program_certificate(client, user, program_uuid, visible_date): """ Issue a new certificate of completion to the given student for the given program. @@ -136,156 +162,54 @@ def award_program_certificate(client, user, program_uuid, visible_date): response.raise_for_status() -@shared_task(bind=True, ignore_result=True) -@set_code_owner_attribute -def award_program_certificates(self, username): # lint-amnesty, pylint: disable=too-many-statements +def revoke_program_certificate(client, username, program_uuid): """ - This task is designed to be called whenever a student's completion status - changes with respect to one or more courses (primarily, when a course - certificate is awarded). - - It will consult with a variety of APIs to determine whether or not the - specified user should be awarded a certificate in one or more programs, and - use the credentials service to create said certificates if so. - - This task may also be invoked independently of any course completion status - change - for example, to backpopulate missing program credentials for a - student. - - If this function is moved, make sure to update it's entry in - EXPLICIT_QUEUES in the settings files so it runs in the correct queue. + Make a request to the Credentials IDA, requesting the system to revoke a program certificate from the given user in + a given program. Args: - username (str): The username of the student + client: credentials API client (requests.Session) + username: The username of the student + program_uuid: uuid of the program Returns: None - """ + credentials_api_base_url = get_credentials_api_base_url() + api_url = urljoin(f"{credentials_api_base_url}/", "credentials/") + response = client.post( + api_url, + json={ + "username": username, + "status": "revoked", + "credential": {"type": PROGRAM_CERTIFICATE, "program_uuid": program_uuid}, + }, + ) + response.raise_for_status() - def _retry_with_custom_exception(username, reason, countdown): - exception = MaxRetriesExceededError( - f"Failed to award program certificate for user {username}. Reason: {reason}" - ) - return self.retry(exc=exception, countdown=countdown, max_retries=MAX_RETRIES) - LOGGER.info(f"Running task award_program_certificates for username {username}") - programs_without_certificates = configuration_helpers.get_value("programs_without_certificates", []) - if programs_without_certificates: - if str(programs_without_certificates[0]).lower() == "all": - # this check will prevent unnecessary logging for partners without program certificates - return +def post_course_certificate(client, username, certificate, visible_date, date_override=None, org=None): + """ + POST a certificate that has been updated to Credentials + """ + credentials_api_base_url = get_credentials_api_base_url(org) + api_url = urljoin(f"{credentials_api_base_url}/", "credentials/") - countdown = 2**self.request.retries - # If the credentials config model is disabled for this - # feature, it may indicate a condition where processing of such tasks - # has been temporarily disabled. Since this is a recoverable situation, - # mark this task for retry instead of failing it altogether. - - if not CredentialsApiConfig.current().is_learner_issuance_enabled: - error_msg = ( - "Task award_program_certificates cannot be executed when credentials issuance is disabled in API config" - ) - LOGGER.warning(error_msg) - raise _retry_with_custom_exception(username=username, reason=error_msg, countdown=countdown) - - try: - try: - student = User.objects.get(username=username) - except User.DoesNotExist: - LOGGER.exception(f"Task award_program_certificates was called with invalid username {username}") - # Don't retry for this case - just conclude the task. - return - completed_programs = {} - for site in Site.objects.all(): - completed_programs.update(get_completed_programs(site, student)) - if not completed_programs: - # No reason to continue beyond this point unless/until this - # task gets updated to support revocation of program certs. - LOGGER.info(f"Task award_program_certificates was called for user {username} with no completed programs") - return - - # Determine which program certificates the user has already been awarded, if any. - existing_program_uuids = get_certified_programs(student) - - # we will skip all the programs which have already been awarded and we want to skip the programs - # which are exit in site configuration in 'programs_without_certificates' list. - awarded_and_skipped_program_uuids = list(set(existing_program_uuids + list(programs_without_certificates))) - - except Exception as exc: - error_msg = f"Failed to determine program certificates to be awarded for user {username}. {exc}" - LOGGER.exception(error_msg) - raise _retry_with_custom_exception(username=username, reason=error_msg, countdown=countdown) from exc - - # For each completed program for which the student doesn't already have a - # certificate, award one now. - # - # This logic is important, because we will retry the whole task if awarding any particular program cert fails. - # - # N.B. the list is sorted to facilitate deterministic ordering, e.g. for tests. - new_program_uuids = sorted(list(set(completed_programs.keys()) - set(awarded_and_skipped_program_uuids))) - if new_program_uuids: - try: - credentials_client = get_credentials_api_client( - User.objects.get(username=settings.CREDENTIALS_SERVICE_USERNAME), - ) - except Exception as exc: - error_msg = "Failed to create a credentials API client to award program certificates" - LOGGER.exception(error_msg) - # Retry because a misconfiguration could be fixed - raise _retry_with_custom_exception(username=username, reason=error_msg, countdown=countdown) from exc - - failed_program_certificate_award_attempts = [] - for program_uuid in new_program_uuids: - visible_date = completed_programs[program_uuid] - try: - LOGGER.info(f"Visible date for user {username} : program {program_uuid} is {visible_date}") - award_program_certificate(credentials_client, student, program_uuid, visible_date) - LOGGER.info(f"Awarded certificate for program {program_uuid} to user {username}") - except HTTPError as exc: - if exc.response.status_code == 404: - LOGGER.exception( - f"Certificate for program {program_uuid} could not be found. " - f"Unable to award certificate to user {username}. The program might not be configured." - ) - elif exc.response.status_code == 429: - rate_limit_countdown = 60 - error_msg = ( - f"Rate limited. " - f"Retrying task to award certificates to user {username} in {rate_limit_countdown} seconds" - ) - LOGGER.info(error_msg) - # Retry after 60 seconds, when we should be in a new throttling window - raise _retry_with_custom_exception( - username=username, - reason=error_msg, - countdown=rate_limit_countdown, - ) from exc - else: - LOGGER.exception( - f"Unable to award certificate to user {username} for program {program_uuid}. " - "The program might not be configured." - ) - except Exception: # pylint: disable=broad-except - # keep trying to award other certs, but retry the whole task to fix any missing entries - LOGGER.exception(f"Failed to award certificate for program {program_uuid} to user {username}.") - failed_program_certificate_award_attempts.append(program_uuid) - - if failed_program_certificate_award_attempts: - # N.B. This logic assumes that this task is idempotent - LOGGER.info(f"Retrying task to award failed certificates to user {username}") - # The error message may change on each reattempt but will never be raised until - # the max number of retries have been exceeded. It is unlikely that this list - # will change by the time it reaches its maximimum number of attempts. - error_msg = ( - f"Failed to award certificate for user {username} " - f"for programs {failed_program_certificate_award_attempts}" - ) - raise _retry_with_custom_exception(username=username, reason=error_msg, countdown=countdown) - else: - LOGGER.info(f"User {username} is not eligible for any new program certificates") - - LOGGER.info(f"Successfully completed the task award_program_certificates for username {username}") + response = client.post( + api_url, + json={ + "username": username, + "status": "awarded" if certificate.is_valid() else "revoked", # Only need the two options at this time + "credential": { + "course_run_key": str(certificate.course_id), + "mode": certificate.mode, + "type": COURSE_CERTIFICATE, + }, + "date_override": {"date": date_override.strftime(DATE_FORMAT)} if date_override else None, + "attributes": [{"name": "visible_date", "value": visible_date.strftime(DATE_FORMAT)}], + }, + ) + response.raise_for_status() def post_course_certificate_configuration(client, cert_config, certificate_available_date=None): @@ -326,28 +250,155 @@ def post_course_certificate_configuration(client, cert_config, certificate_avail response.raise_for_status() -def post_course_certificate(client, username, certificate, visible_date, date_override=None, org=None): +@shared_task(bind=True, ignore_result=True) +@set_code_owner_attribute +def award_program_certificates(self, username): # lint-amnesty, pylint: disable=too-many-statements """ - POST a certificate that has been updated to Credentials - """ - credentials_api_base_url = get_credentials_api_base_url(org) - api_url = urljoin(f"{credentials_api_base_url}/", "credentials/") + This task is designed to be called whenever a student's completion status changes with respect to one or more + courses (primarily, when a course certificate is awarded). - response = client.post( - api_url, - json={ - "username": username, - "status": "awarded" if certificate.is_valid() else "revoked", # Only need the two options at this time - "credential": { - "course_run_key": str(certificate.course_id), - "mode": certificate.mode, - "type": COURSE_CERTIFICATE, - }, - "date_override": {"date": date_override.strftime(DATE_FORMAT)} if date_override else None, - "attributes": [{"name": "visible_date", "value": visible_date.strftime(DATE_FORMAT)}], - }, - ) - response.raise_for_status() + It will consult with a variety of APIs to determine whether or not the specified user should be awarded a program + certificate in one or more programs, and use the credentials service to create said certificates if so. + + This task may also be invoked independently of any course completion status change - for example, to backpopulate + missing program credentials for a student. + + If this function is moved, make sure to update it's entry in EXPLICIT_QUEUES in the settings files so it runs in the + correct queue. + + Args: + username (str): The username of the student + + Returns: + None + """ + def _retry_with_custom_exception(username, reason, countdown): + exception = MaxRetriesExceededError( + f"Failed to award a program certificate to user {username}. Reason: {reason}" + ) + return self.retry(exc=exception, countdown=countdown, max_retries=MAX_RETRIES) + + countdown = 2**self.request.retries + + # If the credentials config model is disabled for this feature, it may indicate a condition where processing of such + # tasks has been temporarily disabled. Since this is a recoverable situation, mark this task for retry instead of + # failing it altogether. + if not is_credentials_enabled(): + error_msg = ( + "Task award_program_certificates cannot be executed, use of the Credentials service is disabled by config" + ) + LOGGER.warning(error_msg) + raise _retry_with_custom_exception(username=username, reason=error_msg, countdown=countdown) + + try: + student = User.objects.get(username=username) + except User.DoesNotExist: + LOGGER.warning( + "Task award_program_certificates was called with an invalid username. Could not retrieve a User instance " + f"with username {username}" + ) + return + + # this check will prevent unnecessary logging for partners without program certificates + programs_without_certificates = configuration_helpers.get_value("programs_without_certificates", []) + if programs_without_certificates: + if str(programs_without_certificates[0]).lower() == "all": + return + + LOGGER.info(f"Running task award_program_certificates for user {student}") + try: + completed_programs = {} + for site in Site.objects.all(): + completed_programs.update(get_completed_programs(site, student)) + + if not completed_programs: + LOGGER.warning(f"Task award_program_certificates was called for user {student} with no completed programs") + return + + # determine which program certificates have been awarded to the user + existing_program_uuids = get_certified_programs(student) + # construct a list of program UUIDs where the learner has already been awarded a program certificate or if the + # program is part of the "programs without certificates" list in our site configuration + awarded_and_skipped_program_uuids = list(set(existing_program_uuids + list(programs_without_certificates))) + except Exception as exc: + error_msg = f"Failed to determine program certificates to be awarded for user {student}: {exc}" + LOGGER.exception(error_msg) + raise _retry_with_custom_exception(username=username, reason=error_msg, countdown=countdown) from exc + + # For each completed program for which the student doesn't already have a certificate, award one now. + # + # This logic is important, because we will retry the whole task if awarding any particular program cert fails. + # + # N.B. the list is sorted to facilitate deterministic ordering, e.g. for tests. + new_program_uuids = sorted(list(set(completed_programs.keys()) - set(awarded_and_skipped_program_uuids))) + if new_program_uuids: + try: + credentials_client = get_credentials_api_client( + User.objects.get(username=settings.CREDENTIALS_SERVICE_USERNAME), + ) + except Exception as exc: + error_msg = "Failed to create a credentials API client to award program certificates" + LOGGER.exception(error_msg) + # Retry because a misconfiguration could be fixed + raise _retry_with_custom_exception(username=username, reason=error_msg, countdown=countdown) from exc + + failed_program_certificate_award_attempts = [] + for program_uuid in new_program_uuids: + visible_date = completed_programs[program_uuid] + try: + LOGGER.info( + f"Visible date for program certificate awarded to user {student} in program {program_uuid} is " + f"{visible_date}" + ) + award_program_certificate(credentials_client, student, program_uuid, visible_date) + LOGGER.info(f"Awarded program certificate to user {student} in program {program_uuid}") + except HTTPError as exc: + if exc.response.status_code == 404: + LOGGER.warning( + f"Unable to award a program certificate to user {student} in program {program_uuid}. A " + f"certificate configuration for program {program_uuid} could not be found, the program might " + "not be configured correctly in Credentials" + ) + elif exc.response.status_code == 429: + rate_limit_countdown = 60 + error_msg = ( + f"Rate limited. Retrying task to award certificate to user {student} in program " + f"{program_uuid} in {rate_limit_countdown} seconds" + ) + LOGGER.warning(error_msg) + # Retry after 60 seconds, when we should be in a new throttling window + raise _retry_with_custom_exception( + username=username, + reason=error_msg, + countdown=rate_limit_countdown, + ) from exc + else: + LOGGER.warning( + f"Unable to award program certificate to user {student} in program {program_uuid}. The program " + "might not be configured correctly in Credentials" + ) + except Exception as exc: # pylint: disable=broad-except + # keep trying to award other certs, but retry the whole task to fix any missing entries + LOGGER.exception( + f"Failed to award program certificate to user {student} in program {program_uuid}: {exc}" + ) + failed_program_certificate_award_attempts.append(program_uuid) + + if failed_program_certificate_award_attempts: + # N.B. This logic assumes that this task is idempotent + LOGGER.info(f"Retrying failed tasks to award program certificate(s) to user {student}") + # The error message may change on each reattempt but will never be raised until the max number of retries + # have been exceeded. It is unlikely that this list will change by the time it reaches its maximimum number + # of attempts. + error_msg = ( + f"Failed to award program certificate(s) for user {student} in programs " + f"{failed_program_certificate_award_attempts}" + ) + raise _retry_with_custom_exception(username=username, reason=error_msg, countdown=countdown) + else: + LOGGER.warning(f"User {student} is not eligible for any new program certificates") + + LOGGER.info(f"Successfully completed the task award_program_certificates for user {student}") # pylint: disable=W0613 @@ -410,22 +461,18 @@ def award_course_certificate(self, username, course_run_key): username (str): The user to award the Credentials course cert to course_run_key (str): The course run key to award the certificate for """ - def _retry_with_custom_exception(username, course_run_key, reason, countdown): exception = MaxRetriesExceededError( f"Failed to award course certificate for user {username} for course {course_run_key}. Reason: {reason}" ) return self.retry(exc=exception, countdown=countdown, max_retries=MAX_RETRIES) - LOGGER.info(f"Running task award_course_certificate for username {username}") - countdown = 2**self.request.retries - # If the credentials config model is disabled for this - # feature, it may indicate a condition where processing of such tasks - # has been temporarily disabled. Since this is a recoverable situation, + # If the credentials config model is disabled for this feature, it may indicate a condition where processing of such + # tasks has been temporarily disabled. Since this is a recoverable situation, # mark this task for retry instead of failing it altogether. - if not CredentialsApiConfig.current().is_learner_issuance_enabled: + if not is_credentials_enabled(): error_msg = ( "Task award_course_certificate cannot be executed when credentials issuance is disabled in API config" ) @@ -436,14 +483,19 @@ def award_course_certificate(self, username, course_run_key): reason=error_msg, countdown=countdown, ) + + try: + user = User.objects.get(username=username) + except User.DoesNotExist: + LOGGER.warning( + "Task award_course_certificate was called with an invalid username. Could not retrieve a User instance " + f"with username {username}" + ) + return + + LOGGER.info(f"Running task award_course_certificate for user {user}") try: course_key = CourseKey.from_string(course_run_key) - try: - user = User.objects.get(username=username) - except User.DoesNotExist: - LOGGER.exception(f"Task award_course_certificate was called with invalid username {username}") - # Don't retry for this case - just conclude the task. - return # Get the cert for the course key and username if it's both passing and available in professional/verified try: certificate = GeneratedCertificate.eligible_certificates.get( @@ -451,31 +503,24 @@ def award_course_certificate(self, username, course_run_key): course_id=course_key, ) except GeneratedCertificate.DoesNotExist: - LOGGER.exception( - "Task award_course_certificate was called without Certificate found " - f"for {course_key} to user {username}" + LOGGER.warning( + f"Task award_course_certificate was called for user {user} in course run {course_key} but this learner " + "has not earned a course certificate in this course run" ) return + if certificate.mode in CourseMode.CERTIFICATE_RELEVANT_MODES: - try: - course_overview = CourseOverview.get_from_id(course_key) - except (CourseOverview.DoesNotExist, OSError): - LOGGER.exception( - f"Task award_course_certificate was called without course overview data for course {course_key}" + course_overview = get_course_overview_or_none(course_key) + if not course_overview: + LOGGER.warning( + f"Task award_course_certificate was called for user {user} in course {course_key} but no course " + "overview could be retrieved for the course run" ) return - credentials_client = get_credentials_api_client( - User.objects.get(username=settings.CREDENTIALS_SERVICE_USERNAME), - ) - - visible_date = available_date_for_certificate( - course_overview, - certificate, - ) - + visible_date = available_date_for_certificate(course_overview, certificate) LOGGER.info( - "Task award_course_certificate will award certificate for course " + f"Task award_course_certificate will award a course certificate to user {user} in course run " f"{course_key} with a visible date of {visible_date}" ) @@ -483,12 +528,15 @@ def award_course_certificate(self, username, course_run_key): try: date_override = certificate.date_override.date LOGGER.info( - "Task award_course_certificate will award certificate for course {course_key} with a date override " - f"of {date_override}" + f"Task award_course_certificate will award a course certificate to user {user} in course run " + f"{course_key} with an override date of {date_override}" ) except ObjectDoesNotExist: date_override = None + credentials_client = get_credentials_api_client( + User.objects.get(username=settings.CREDENTIALS_SERVICE_USERNAME), + ) post_course_certificate( credentials_client, username, @@ -497,10 +545,9 @@ def award_course_certificate(self, username, course_run_key): date_override, org=course_key.org, ) - - LOGGER.info(f"Awarded certificate for course {course_key} to user {username}") + LOGGER.info(f"Awarded a course certificate to user {user} in course run {course_key}") except Exception as exc: - error_msg = f"Failed to determine course certificates to be awarded for user {username}." + error_msg = f"Failed to determine course certificates to be awarded for user {user}." LOGGER.exception(error_msg) raise _retry_with_custom_exception( username=username, @@ -510,73 +557,17 @@ def award_course_certificate(self, username, course_run_key): ) from exc -def get_revokable_program_uuids(course_specific_programs: List[Dict], student: User) -> List[str]: - """ - Get program uuids for which certificate to be revoked. - - Checks for existing learner certificates and filter out the program UUIDS - for which a certificate needs to be revoked. - - Args: - course_specific_programs (dict[]): list of programs specific to a course - student (User): Representing the student whose programs to check for. - - Returns: - list of program UUIDs for which certificates to be revoked - - Raises: - HttpError, if the API call generated by get_certified_programs fails - """ - program_uuids_to_revoke = [] - # Get any programs where the user has already been rewarded a certificate - # Failed API calls with get_certified_programs should raise exceptions, - # because an empty response would dangerously imply a false negative. - existing_program_uuids = get_certified_programs(student, raise_on_error=True) - for program in course_specific_programs: - if program["uuid"] in existing_program_uuids: - program_uuids_to_revoke.append(program["uuid"]) - - return program_uuids_to_revoke - - -def revoke_program_certificate(client, username, program_uuid): - """ - Revoke a certificate of the given student for the given program. - - Args: - client: credentials API client (requests.Session) - username: The username of the student - program_uuid: uuid of the program - - Returns: - None - """ - credentials_api_base_url = get_credentials_api_base_url() - api_url = urljoin(f"{credentials_api_base_url}/", "credentials/") - response = client.post( - api_url, - json={ - "username": username, - "status": "revoked", - "credential": {"type": PROGRAM_CERTIFICATE, "program_uuid": program_uuid}, - }, - ) - response.raise_for_status() - - @shared_task(bind=True, ignore_result=True) @set_code_owner_attribute def revoke_program_certificates(self, username, course_key): # lint-amnesty, pylint: disable=too-many-statements """ - This task is designed to be called whenever a student's course certificate is - revoked. + This task is designed to be called whenever a student's course certificate is revoked. - It will consult with a variety of APIs to determine whether or not the - specified user's certificate should be revoked in one or more programs, and - use the credentials service to revoke the said certificates if so. + It will consult with a variety of APIs to determine whether or not the specified user's certificate should be + revoked in one or more programs, and use the credentials service to revoke the said certificates if so. - If this function is moved, make sure to update it's entry in - EXPLICIT_QUEUES in the settings files so it runs in the correct queue. + If this function is moved, make sure to update it's entry in EXPLICIT_QUEUES in the settings files so it runs in the + correct queue. Args: username (str): The username of the student @@ -584,9 +575,7 @@ def revoke_program_certificates(self, username, course_key): # lint-amnesty, py Returns: None - """ - def _retry_with_custom_exception(username, course_key, reason, countdown): exception = MaxRetriesExceededError( f"Failed to revoke program certificate for user {username} for course {course_key}. Reason: {reason}" @@ -594,14 +583,13 @@ def revoke_program_certificates(self, username, course_key): # lint-amnesty, py return self.retry(exc=exception, countdown=countdown, max_retries=MAX_RETRIES) countdown = 2**self.request.retries - # If the credentials config model is disabled for this - # feature, it may indicate a condition where processing of such tasks - # has been temporarily disabled. Since this is a recoverable situation, - # mark this task for retry instead of failing it altogether. - if not CredentialsApiConfig.current().is_learner_issuance_enabled: + # If the credentials config model is disabled for this feature, it may indicate a condition where processing of such + # tasks has been temporarily disabled. Since this is a recoverable situation, mark this task for retry instead of + # failing it altogether. + if not is_credentials_enabled(): error_msg = ( - "Task revoke_program_certificates cannot be executed when credentials issuance is disabled in API config" + "Task revoke_program_certificates cannot be executed, use of the Credentials service is disabled by config" ) LOGGER.warning(error_msg) raise _retry_with_custom_exception( @@ -614,21 +602,20 @@ def revoke_program_certificates(self, username, course_key): # lint-amnesty, py try: student = User.objects.get(username=username) except User.DoesNotExist: - LOGGER.exception( - f"Task revoke_program_certificates was called with invalid username {username}", - username, + LOGGER.warning( + "Task revoke_program_certificates was called with an invalid username. Could not retrieve a User instance " + f"with username {username}" ) - # Don't retry for this case - just conclude the task. return + LOGGER.info(f"Running task revoke_program_certificates for user {student}") try: inverted_programs = get_inverted_programs(student) course_specific_programs = inverted_programs.get(course_key) if not course_specific_programs: - # No reason to continue beyond this point - LOGGER.info( - f"Task revoke_program_certificates was called for user {username} " - f"and course {course_key} with no engaged programs" + LOGGER.warning( + f"Task revoke_program_certificates was called for user {student} and course run {course_key} with no " + "engaged programs" ) return @@ -636,7 +623,8 @@ def revoke_program_certificates(self, username, course_key): # lint-amnesty, py program_uuids_to_revoke = get_revokable_program_uuids(course_specific_programs, student) except Exception as exc: error_msg = ( - f"Failed to determine program certificates to be revoked for user {username} " f"with course {course_key}" + f"Failed to determine if any program certificates associated with course run {course_key} should be " + f"revoked from user {student}" ) LOGGER.exception(error_msg) raise _retry_with_custom_exception( @@ -661,20 +649,20 @@ def revoke_program_certificates(self, username, course_key): # lint-amnesty, py for program_uuid in program_uuids_to_revoke: try: revoke_program_certificate(credentials_client, username, program_uuid) - LOGGER.info(f"Revoked certificate for program {program_uuid} for user {username}") + LOGGER.info(f"Revoked program certificate from user {student} in program {program_uuid}") except HTTPError as exc: if exc.response.status_code == 404: - LOGGER.exception( - f"Certificate for program {program_uuid} could not be found. " - f"Unable to revoke certificate for user {username}" + LOGGER.warning( + f"Unable to revoke program certificate from user {student} in program {program_uuid}, a " + "program certificate could not be found" ) elif exc.response.status_code == 429: rate_limit_countdown = 60 error_msg = ( - "Rate limited. Retrying task to revoke certificates " - f"for user {username} in {rate_limit_countdown} seconds" + f"Rate limited. Retrying task to revoke a program certificate from user {student} in program " + f"{program_uuid} in {rate_limit_countdown} seconds" ) - LOGGER.info(error_msg) + LOGGER.warning(error_msg) # Retry after 60 seconds, when we should be in a new throttling window raise _retry_with_custom_exception( username, @@ -683,27 +671,31 @@ def revoke_program_certificates(self, username, course_key): # lint-amnesty, py countdown=rate_limit_countdown, ) from exc else: - LOGGER.exception(f"Unable to revoke certificate for user {username} for program {program_uuid}.") - except Exception: # pylint: disable=broad-except + LOGGER.warning( + f"Unable to revoke program certificate from user {student} in program {program_uuid}" + ) + except Exception as exc: # pylint: disable=broad-except # keep trying to revoke other certs, but retry the whole task to fix any missing entries - LOGGER.warning(f"Failed to revoke certificate for program {program_uuid} of user {username}.") + LOGGER.exception( + f"Failed to revoke program certificate from user {student} in program {program_uuid}: {exc}" + ) failed_program_certificate_revoke_attempts.append(program_uuid) if failed_program_certificate_revoke_attempts: # N.B. This logic assumes that this task is idempotent - LOGGER.info(f"Retrying task to revoke failed certificates to user {username}") - # The error message may change on each reattempt but will never be raised until - # the max number of retries have been exceeded. It is unlikely that this list - # will change by the time it reaches its maximimum number of attempts. + LOGGER.info(f"Retrying failed task to revoke program certificate(s) from user {student}") + # The error message may change on each reattempt but will never be raised until the max number of retries + # have been exceeded. It is unlikely that this list will change by the time it reaches its maximimum number + # of attempts. error_msg = ( - f"Failed to revoke certificate for user {username} " - f"for programs {failed_program_certificate_revoke_attempts}" + f"Failed to revoke program certificate(s) from user {student} for programs " + f"{failed_program_certificate_revoke_attempts}" ) raise _retry_with_custom_exception(username, course_key, reason=error_msg, countdown=countdown) - else: - LOGGER.info(f"There is no program certificates for user {username} to revoke") - LOGGER.info(f"Successfully completed the task revoke_program_certificates for username {username}") + LOGGER.info(f"No program certificates to revoke from user {student}") + + LOGGER.info(f"Successfully completed the task revoke_program_certificates for user {student}") @shared_task(bind=True, ignore_result=True) @@ -727,7 +719,7 @@ def update_certificate_visible_date_on_course_update(self, course_key): # If the CredentialsApiConfig configuration model is disabled for this feature, it may indicate a condition where # processing of such tasks has been temporarily disabled. Since this is a recoverable situation, mark this task for # retry instead of failing it. - if not CredentialsApiConfig.current().is_learner_issuance_enabled: + if not is_credentials_enabled(): error_msg = ( "Cannot execute the `update_certificate_visible_date_on_course_update` task. Issuing user credentials " "through the Credentials IDA is disabled." diff --git a/openedx/core/djangoapps/programs/tests/test_tasks.py b/openedx/core/djangoapps/programs/tests/test_tasks.py index 83fa66a256..4b3a143fc9 100644 --- a/openedx/core/djangoapps/programs/tests/test_tasks.py +++ b/openedx/core/djangoapps/programs/tests/test_tasks.py @@ -250,7 +250,7 @@ class AwardProgramCertificatesTestCase(CatalogIntegrationMixin, CredentialsApiCo Checks that the task will be aborted and not retried if the username passed was not found, and that an exception is logged. """ - with mock.patch(TASKS_MODULE + ".LOGGER.exception") as mock_exception: + with mock.patch(TASKS_MODULE + ".LOGGER.warning") as mock_exception: tasks.award_program_certificates.delay("nonexistent-username").get() assert mock_exception.called for mock_helper in mock_helpers: @@ -355,15 +355,12 @@ class AwardProgramCertificatesTestCase(CatalogIntegrationMixin, CredentialsApiCo TASKS_MODULE + ".LOGGER.exception" ) as mock_warning: tasks.award_program_certificates.delay(self.student.username).get() - assert mock_award_program_certificate.call_count == 3 mock_warning.assert_called_once_with( - "Failed to award certificate for program {uuid} to user {username}.".format( - uuid=1, username=self.student.username - ) + f"Failed to award program certificate to user {self.student} in program 1: boom" ) - mock_info.assert_any_call(f"Awarded certificate for program {1} to user {self.student.username}") - mock_info.assert_any_call(f"Awarded certificate for program {2} to user {self.student.username}") + mock_info.assert_any_call(f"Awarded program certificate to user {self.student} in program 1") + mock_info.assert_any_call(f"Awarded program certificate to user {self.student} in program 2") def test_retry_on_programs_api_errors(self, mock_get_completed_programs, *_mock_helpers): """ @@ -608,7 +605,7 @@ class AwardCourseCertificatesTestCase(CredentialsApiConfigMixin, TestCase): """ Test that the post method is never called if the user isn't found by username """ - with mock.patch(TASKS_MODULE + ".LOGGER.exception") as mock_exception: + with mock.patch(TASKS_MODULE + ".LOGGER.warning") as mock_exception: # Use a random username here since this user won't be found in the DB tasks.award_course_certificate.delay("random_username", str(self.course.id)).get() assert mock_exception.called @@ -619,7 +616,7 @@ class AwardCourseCertificatesTestCase(CredentialsApiConfigMixin, TestCase): Test that the post method is never called if the certificate doesn't exist for the user and course """ self.certificate.delete() - with mock.patch(TASKS_MODULE + ".LOGGER.exception") as mock_exception: + with mock.patch(TASKS_MODULE + ".LOGGER.warning") as mock_exception: tasks.award_course_certificate.delay(self.student.username, str(self.course.id)).get() assert mock_exception.called assert not mock_post_course_certificate.called @@ -629,7 +626,7 @@ class AwardCourseCertificatesTestCase(CredentialsApiConfigMixin, TestCase): Test that the post method is never called if the CourseOverview isn't found """ self.course.delete() - with mock.patch(TASKS_MODULE + ".LOGGER.exception") as mock_exception: + with mock.patch(TASKS_MODULE + ".LOGGER.warning") as mock_exception: # Use the certificate course id here since the course will be deleted tasks.award_course_certificate.delay(self.student.username, str(self.certificate.course_id)).get() assert mock_exception.called @@ -780,7 +777,7 @@ class RevokeProgramCertificatesTestCase(CatalogIntegrationMixin, CredentialsApiC Checks that the task will be aborted and not retried if the username passed was not found, and that an exception is logged. """ - with mock.patch(TASKS_MODULE + ".LOGGER.exception") as mock_exception: + with mock.patch(TASKS_MODULE + ".LOGGER.warning") as mock_exception: tasks.revoke_program_certificates.delay("nonexistent-username", self.course_key).get() assert mock_exception.called for mock_helper in mock_helpers: @@ -819,18 +816,16 @@ class RevokeProgramCertificatesTestCase(CatalogIntegrationMixin, CredentialsApiC mock_revoke_program_certificate.side_effect = self._make_side_effect([Exception("boom"), None]) with mock.patch(TASKS_MODULE + ".LOGGER.info") as mock_info, mock.patch( - TASKS_MODULE + ".LOGGER.warning" + TASKS_MODULE + ".LOGGER.exception" ) as mock_warning: tasks.revoke_program_certificates.delay(self.student.username, self.course_key).get() assert mock_revoke_program_certificate.call_count == 3 mock_warning.assert_called_once_with( - "Failed to revoke certificate for program {uuid} of user {username}.".format( - uuid=1, username=self.student.username - ) + f"Failed to revoke program certificate from user {self.student} in program 1: boom" ) - mock_info.assert_any_call(f"Revoked certificate for program {1} for user {self.student.username}") - mock_info.assert_any_call(f"Revoked certificate for program {2} for user {self.student.username}") + mock_info.assert_any_call(f"Revoked program certificate from user {self.student} in program 1") + mock_info.assert_any_call(f"Revoked program certificate from user {self.student} in program 2") def test_retry_on_credentials_api_errors( self,