diff --git a/lms/djangoapps/verify_student/management/commands/retry_failed_photo_verifications.py b/lms/djangoapps/verify_student/management/commands/retry_failed_photo_verifications.py index d7311a5b45..c8e589a1af 100644 --- a/lms/djangoapps/verify_student/management/commands/retry_failed_photo_verifications.py +++ b/lms/djangoapps/verify_student/management/commands/retry_failed_photo_verifications.py @@ -2,8 +2,10 @@ Django admin commands related to verify_student """ - +from datetime import datetime import logging +import time + from django.core.management.base import BaseCommand from lms.djangoapps.verify_student.models import SoftwareSecurePhotoVerification, SSPVerificationRetryConfig @@ -13,14 +15,23 @@ log = logging.getLogger('retry_photo_verification') class Command(BaseCommand): """ - This method finds those PhotoVerifications with a status of - MUST_RETRY and attempts to verify them. + This method finds those SoftwareSecurePhotoVerifications with a selected status + from a start_datetime to an end_datetime and attempts to verify them. + + Use case: Multiple IDVs need to be resubmitted. + + Example: + ./manage.py lms retry_failed_photo_verifications --status="submitted" \ + --start_datetime="2023-03-01 00:00:00" --end_datetime="2023-03-28 23:59:59" + (This resubmits all 'submitted' SoftwareSecurePhotoVerifications from 2023-03-01 to 2023-03-28) """ + args = "" help = ( "Retries SoftwareSecurePhotoVerifications passed as " "arguments, or if no arguments are supplied, all that " - "are in a state of 'must_retry'" + "have a specified status, from a start datetime to an " + "end datetime" ) def add_arguments(self, parser): @@ -40,12 +51,63 @@ class Command(BaseCommand): help='Use arguments from the SSPVerificationRetryConfig model instead of the command line.', ) + parser.add_argument( + '--status', + action='store', + dest='status', + default='must_retry', + type=str, + help='SoftwareSecurePhotoVerifications status to filter for' + ) + + parser.add_argument( + '--start_datetime', + action='store', + dest='start_datetime', + default=None, + type=str, + help='Start date for a date range of SoftwareSecurePhotoVerifications; ' + 'Should be formatted as YYYY-mm-dd HH:MM:SS; ' + 'Requires the end_datetime arg.', + ) + + parser.add_argument( + '--end_datetime', + action='store', + dest='end_datetime', + # "YYYY-mm-dd HH:MM:SS" + default=None, + type=str, + help='End date for a date range of SoftwareSecurePhotoVerifications; ' + 'Should be formatted as YYYY-mm-dd HH:MM:SS; ' + 'Requires the start_datetime arg.', + ) + + parser.add_argument( + '--batch_size', + action='store', + dest='batch_size', + type=int, + default=300, + help='Maximum number of SoftwareSecurePhotoVerifications to process. ' + 'This helps avoid overloading the database while updating large amount of data.' + ) + + parser.add_argument( + '--sleep_time', + action='store', + dest='sleep_time', + type=int, + default=10, + help='Sleep time in seconds between update of batches' + ) + def get_args_from_database(self): """ Returns an options dictionary from the current SSPVerificationRetryConfig model. """ sspv_retry_config = SSPVerificationRetryConfig.current() if not sspv_retry_config.enabled: - log.warning('SSPVerificationRetryConfig is disabled or empty, but --args-from-database was requested.') + log.error('SSPVerificationRetryConfig is disabled or empty, but --args-from-database was requested.') return {} # We don't need fancy shell-style whitespace/quote handling - none of our arguments are complicated @@ -57,26 +119,66 @@ class Command(BaseCommand): def handle(self, *args, **options): options = self.get_args_from_database() if options['args_from_database'] else options + if options == {}: + return + args = options.get('verification_ids', None) + force_must_retry = False if args: + force_must_retry = True attempts_to_retry = SoftwareSecurePhotoVerification.objects.filter( receipt_id__in=options['verification_ids'] ) - log.info("Fetching retry verification ids from config model") - force_must_retry = True + log.info( + f"Attempting to re-submit {len(attempts_to_retry)} failed SoftwareSecurePhotoVerification submissions; " + f"with retry verification ids from config model" + ) else: - attempts_to_retry = SoftwareSecurePhotoVerification.objects.filter(status='must_retry') - force_must_retry = False + # Filter by status + status = options['status'] + if status != 'must_retry': + force_must_retry = True + attempts_to_retry = SoftwareSecurePhotoVerification.objects.filter( + status=status + ) + + log.info( + f"Attempting to re-submit {len(attempts_to_retry)} failed SoftwareSecurePhotoVerification submissions; " + f"\nwith status: {status}" + ) + + # Make sure we have both a start date and end date + if options['start_datetime'] is not None and options['end_datetime'] is not None: + start_datetime = datetime.strptime(options['start_datetime'], '%Y-%m-%d %H:%M:%S') + end_datetime = datetime.strptime(options['end_datetime'], '%Y-%m-%d %H:%M:%S') + + # Filter by date range + attempts_to_retry = attempts_to_retry.filter(submitted_at__range=(start_datetime, end_datetime)) + + log.info( + f"In date range: `{start_datetime}` to `{end_datetime}`" + ) + + # Re-submit attempts_to_retry + batch_size = options['batch_size'] + sleep_time = options['sleep_time'] + count = 0 - log.info(f"Attempting to retry {len(attempts_to_retry)} failed PhotoVerification submissions") for index, attempt in enumerate(attempts_to_retry): - log.info(f"Retrying submission #{index} (ID: {attempt.id}, User: {attempt.user})") + log.info(f"Re-submitting submission #{index} (ID: {attempt.id}, User: {attempt.user})") - # Set the attempts status to 'must_retry' so that we can re-submit it + # Set the attempt's status to 'must_retry' so that we can re-submit it if force_must_retry: attempt.status = 'must_retry' attempt.submit(copy_id_photo_from=attempt.copy_id_photo_from) log.info(f"Retry result: {attempt.status}") + count += 1 + + # Sleep between batches of + if count == batch_size: + time.sleep(sleep_time) + count = 0 + log.info("Done resubmitting failed photo verifications") diff --git a/lms/djangoapps/verify_student/management/commands/tests/test_verify_student.py b/lms/djangoapps/verify_student/management/commands/tests/test_retry_failed_photo_verifications.py similarity index 50% rename from lms/djangoapps/verify_student/management/commands/tests/test_verify_student.py rename to lms/djangoapps/verify_student/management/commands/tests/test_retry_failed_photo_verifications.py index 2294230d91..1c3f22aa30 100644 --- a/lms/djangoapps/verify_student/management/commands/tests/test_verify_student.py +++ b/lms/djangoapps/verify_student/management/commands/tests/test_retry_failed_photo_verifications.py @@ -4,12 +4,14 @@ Tests for django admin commands in the verify_student module Lots of imports from verify_student's model tests, since they cover similar ground """ -from unittest.mock import patch +from freezegun import freeze_time +from unittest.mock import call, patch, ANY from django.conf import settings from django.core.management import call_command from testfixtures import LogCapture +from django.test.utils import override_settings from common.test.utils import MockS3Boto3Mixin from lms.djangoapps.verify_student.models import SoftwareSecurePhotoVerification, SSPVerificationRetryConfig from lms.djangoapps.verify_student.tests import TestVerificationBase @@ -25,12 +27,12 @@ LOGGER_NAME = 'retry_photo_verification' # Lots of patching to stub in our own settings, and HTTP posting @patch.dict(settings.VERIFY_STUDENT, FAKE_SETTINGS) @patch('lms.djangoapps.verify_student.models.requests.post', new=mock_software_secure_post) -class TestVerifyStudentCommand(MockS3Boto3Mixin, TestVerificationBase): +class TestRetryFailedPhotoVerifications(MockS3Boto3Mixin, TestVerificationBase): """ Tests for django admin commands in the verify_student module """ - def test_retry_failed_photo_verifications(self): + def test_command(self): """ Tests that the task used to find "must_retry" SoftwareSecurePhotoVerifications and re-submit them executes successfully @@ -53,7 +55,7 @@ class TestVerifyStudentCommand(MockS3Boto3Mixin, TestVerificationBase): def add_test_config_for_retry_verification(self): """Setups verification retry configuration.""" config = SSPVerificationRetryConfig.current() - config.arguments = '--verification-ids 1 2 3' + config.arguments = ('--verification-ids 1 2 3') config.enabled = True config.save() @@ -64,7 +66,7 @@ class TestVerifyStudentCommand(MockS3Boto3Mixin, TestVerificationBase): call_command('retry_failed_photo_verifications', '--args-from-database') log.check_present( ( - LOGGER_NAME, 'WARNING', + LOGGER_NAME, 'ERROR', 'SSPVerificationRetryConfig is disabled or empty, but --args-from-database was requested.' ), ) @@ -77,7 +79,8 @@ class TestVerifyStudentCommand(MockS3Boto3Mixin, TestVerificationBase): log.check_present( ( LOGGER_NAME, 'INFO', - f'Attempting to retry {1} failed PhotoVerification submissions' + f'Attempting to re-submit {1} failed SoftwareSecurePhotoVerification submissions; ' + f'\nwith status: must_retry' ), ) @@ -88,6 +91,77 @@ class TestVerifyStudentCommand(MockS3Boto3Mixin, TestVerificationBase): log.check_present( ( LOGGER_NAME, 'INFO', - 'Fetching retry verification ids from config model' + f'Attempting to re-submit {0} failed SoftwareSecurePhotoVerification submissions; ' + f'with retry verification ids from config model' ), ) + + +@override_settings(VERIFY_STUDENT=FAKE_SETTINGS) +@patch.dict(settings.FEATURES, {'AUTOMATIC_VERIFY_STUDENT_IDENTITY_FOR_TESTING': True}) +class TestRetryFailedPhotoVerificationsBetweenDates(MockS3Boto3Mixin, TestVerificationBase): + """ + Tests that the command selects specific objects within a date range + """ + + def setUp(self): + super().setUp() + # Test that the correct attempts within a date range are called + with patch('lms.djangoapps.verify_student.models.requests.post'): + with freeze_time("2023-02-28 23:59:59"): + self._create_attempts(1) + with freeze_time("2023-03-01 00:00:00"): + self._create_attempts(4) + with freeze_time("2023-03-28 23:59:59"): + self._create_attempts(4) + with freeze_time("2023-03-29 00:00:00"): + self._create_attempts(1) + + def _create_attempts(self, num_attempts): + for _ in range(num_attempts): + self.create_upload_and_submit_attempt_for_user() + + @patch('lms.djangoapps.verify_student.signals.idv_update_signal.send') + def test_resubmit_in_date_range(self, send_idv_update_mock): + call_command('retry_failed_photo_verifications', + status="submitted", + start_datetime="2023-03-01 00:00:00", + end_datetime="2023-03-28 23:59:59" + ) + + expected_calls = [ + call( + sender='idv_update', attempt_id=2, user_id=2, status='submitted', + photo_id_name=ANY, full_name=ANY + ), + call( + sender='idv_update', attempt_id=3, user_id=3, status='submitted', + photo_id_name=ANY, full_name=ANY + ), + call( + sender='idv_update', attempt_id=4, user_id=4, status='submitted', + photo_id_name=ANY, full_name=ANY + ), + call( + sender='idv_update', attempt_id=5, user_id=5, status='submitted', + photo_id_name=ANY, full_name=ANY + ), + call( + sender='idv_update', attempt_id=6, user_id=6, status='submitted', + photo_id_name=ANY, full_name=ANY + ), + call( + sender='idv_update', attempt_id=7, user_id=7, status='submitted', + photo_id_name=ANY, full_name=ANY + ), + call( + sender='idv_update', attempt_id=8, user_id=8, status='submitted', + photo_id_name=ANY, full_name=ANY + ), + call( + sender='idv_update', attempt_id=9, user_id=9, status='submitted', + photo_id_name=ANY, full_name=ANY + ), + ] + self.assertEqual(send_idv_update_mock.call_count, 8) + send_idv_update_mock.assert_has_calls(expected_calls, any_order=True)