fix: resubmit IDV attempts for early march 2023 (#31999)

* fix: resubmit IDV attempts for early march 2023

- initial commit w/ direct copy of retry_failed_photo_verifications.py

* fix: resubmit IDV attempts for early march 2023

- corrected filter and comments

* feat: re-submit in date range

* feat: reworked other command instead

* temp: building tests

* test: unit test complete

* fix: quality

* fix: remove old file

* temp: building tests

* temp: tests w/ debug

* test: reverted old files + removed debug

* chore: quality

* chore: NITs
This commit is contained in:
Isaac Lee
2023-04-04 15:38:34 -04:00
committed by GitHub
parent 8a5ecd68b8
commit b0da68aa3a
2 changed files with 195 additions and 19 deletions

View File

@@ -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 = "<SoftwareSecurePhotoVerification id, SoftwareSecurePhotoVerification id, ...>"
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 <batch_size>
if count == batch_size:
time.sleep(sleep_time)
count = 0
log.info("Done resubmitting failed photo verifications")

View File

@@ -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)