[ENG-10737] Registrations are failing to auto-approve [privacy] (CenterForOpenScience#11718)

* fix check manual restart approval
* minor fixes

Author: antkryt

osf/management/commands/process_manual_restart_approvals.py

@@ -4,7 +4,6 @@
 from django.utils import timezone
 from osf.models import Registration
 from osf.models.admin_log_entry import AdminLogEntry, MANUAL_ARCHIVE_RESTART
-from website import settings
 from scripts.approve_registrations import approve_past_pendings
 
 logger = logging.getLogger(__name__)
@@ -134,9 +133,9 @@ def should_auto_approve(self, registration):
         if approval.is_rejected:
             return 'approval was rejected'
 
-        time_since_initiation = timezone.now() - approval.initiation_date
-        if time_since_initiation < settings.REGISTRATION_APPROVAL_TIME:
-            remaining = settings.REGISTRATION_APPROVAL_TIME - time_since_initiation
+        auto_approval_time = approval.auto_approval_time
+        if timezone.now() < auto_approval_time:
+            remaining = auto_approval_time - timezone.now()
             return f'not ready yet ({remaining} remaining)'
 
         if registration.is_stuck_registration:

osf/models/registrations.py

@@ -237,7 +237,7 @@ def is_collection(self):
 
     @property
     def archive_job(self):
-        return self.archive_jobs.first() if self.archive_jobs.count() else None
+        return self.archive_jobs.first()
 
     @property
     def sanction(self):

osf/models/sanctions.py

@@ -878,6 +878,10 @@ class RegistrationApproval(SanctionCallbackMixin, EmailApprovableSanction):
 
     initiated_by = models.ForeignKey(settings.AUTH_USER_MODEL, null=True, blank=True, on_delete=models.CASCADE)
 
+    @property
+    def auto_approval_time(self):
+        return self.initiation_date + osf_settings.REGISTRATION_APPROVAL_TIME
+
     @staticmethod
     def find_approval_backlog():
         """

osf_tests/test_archiver.py

@@ -451,6 +451,22 @@ def test_archive(self, mock_chain, mock_enqueue):
             ]
         )
 
+    @mock.patch('website.archiver.tasks.delayed_manual_restart_approval.delay')
+    @mock.patch('osf.management.commands.force_archive.archive')
+    @mock.patch('osf.management.commands.force_archive.verify')
+    def test_force_archive_schedules_manual_restart_approval_check(
+        self, mock_verify, mock_archive, mock_delayed_check
+    ):
+        result = force_archive(
+            registration_id=self.dst._id,
+            permissible_addons=['osfstorage'],
+        )
+
+        assert result == f'Registration {self.dst._id} archive completed'
+        mock_verify.assert_called_once()
+        mock_archive.assert_called_once()
+        mock_delayed_check.assert_called_once_with(self.dst._id, delay_minutes=5)
+
     def test_stat_addon(self):
         with mock.patch.object(BaseStorageAddon, '_get_file_tree') as mock_file_tree:
             mock_file_tree.return_value = FILE_TREE

scripts/check_manual_restart_approval.py

@@ -1,45 +1,56 @@
 import logging
+from framework import sentry
 from framework.celery_tasks import app as celery_app
 from django.core.management import call_command
+from django.utils import timezone
 from osf.models import Registration
+from scripts.approve_registrations import approve_past_pendings
 
 logger = logging.getLogger(__name__)
 
 
 @celery_app.task(name='scripts.check_manual_restart_approval')
 def check_manual_restart_approval(registration_id):
     try:
-        try:
-            registration = Registration.objects.get(_id=registration_id)
-        except Registration.DoesNotExist:
+        registration = Registration.load(registration_id)
+        if not registration:
             logger.error(f"Registration {registration_id} not found")
             return f"Registration {registration_id} not found"
 
         if registration.is_public or registration.is_registration_approved:
             return f"Registration {registration_id} already approved/public"
 
+        approval = registration.registration_approval
+        if not approval:
+            logger.error(f"Registration {registration_id} has no registration approval object")
+            return f"Registration {registration_id} has no registration approval object"
+
+        if approval.is_rejected:
+            logger.info(f"Registration {registration_id} approval was rejected")
+            return f"Registration {registration_id} approval was rejected"
+
         if registration.archiving:
-            logger.info(f"Registration {registration_id} still archiving, retrying in 10 minutes")
+            logger.debug(f"Registration {registration_id} still archiving, retrying in 10 minutes")
             check_manual_restart_approval.apply_async(
                 args=[registration_id],
                 countdown=600
             )
             return f"Registration {registration_id} still archiving, scheduled retry"
 
-        logger.info(f"Processing manual restart approval for registration {registration_id}")
+        if timezone.now() < approval.auto_approval_time:
+            logger.info(f"Registration {registration_id} not ready for auto-approval yet")
+            return f"Registration {registration_id} not ready for auto-approval yet"
 
-        call_command(
-            'process_manual_restart_approvals',
-            registration_id=registration_id,
-            dry_run=False,
-            hours_back=24,
-            verbosity=1
-        )
+        logger.debug(f"Processing manual restart approval for registration {registration_id}")
+        approve_past_pendings([approval], dry_run=False)
 
         return f"Processed manual restart approval check for registration {registration_id}"
 
     except Exception as e:
-        logger.error(f"Error processing manual restart approval for {registration_id}: {e}")
+        msg = f"Error processing manual restart approval for {registration_id}: {str(e)}"
+        logger.error(msg)
+        sentry.log_message(msg)
+        sentry.log_exception(e)
         raise
 
 

scripts/tests/test_check_manual_restart_approval.py

@@ -0,0 +1,47 @@
+from datetime import timedelta
+from unittest import mock
+
+from django.utils import timezone
+
+from osf_tests.factories import RegistrationFactory, UserFactory
+from scripts.check_manual_restart_approval import check_manual_restart_approval
+from tests.base import OsfTestCase
+from website import settings
+
+
+class TestCheckManualRestartApproval(OsfTestCase):
+
+    def setUp(self):
+        super().setUp()
+        self.user = UserFactory()
+        self.registration = RegistrationFactory(creator=self.user, archive=False)
+        self.registration.require_approval(self.user)
+
+    @mock.patch('scripts.check_manual_restart_approval.approve_past_pendings')
+    def test_skips_if_approval_window_not_elapsed(self, mock_approve):
+        self.registration.registration_approval.initiation_date = timezone.now() - timedelta(hours=47)
+        self.registration.registration_approval.save()
+
+        result = check_manual_restart_approval(self.registration._id)
+
+        assert 'not ready for auto-approval' in result
+        mock_approve.assert_not_called()
+
+    @mock.patch('scripts.check_manual_restart_approval.approve_past_pendings')
+    def test_approves_when_approval_window_elapsed(self, mock_approve):
+        self.registration.registration_approval.initiation_date = (
+            timezone.now() - settings.REGISTRATION_APPROVAL_TIME - timedelta(minutes=1)
+        )
+        self.registration.registration_approval.save()
+
+        result = check_manual_restart_approval(self.registration._id)
+
+        assert 'Processed manual restart approval check' in result
+        mock_approve.assert_called_once_with([self.registration.registration_approval], dry_run=False)
+
+    @mock.patch('scripts.check_manual_restart_approval.Registration.load', return_value=None)
+    def test_returns_not_found_when_registration_missing(self, mock_load):
+        result = check_manual_restart_approval('abc12')
+
+        assert result == 'Registration abc12 not found'
+        mock_load.assert_called_once_with('abc12')

website/archiver/tasks.py

@@ -7,9 +7,6 @@
 import celery
 from celery.utils.log import get_task_logger
 
-from django.utils import timezone
-from datetime import timedelta
-
 from framework.celery_tasks import app as celery_app
 from framework.celery_tasks.utils import logged
 from framework.exceptions import HTTPError
@@ -38,7 +35,6 @@
 from website import settings
 from website.app import init_addons
 
-from osf.models.admin_log_entry import AdminLogEntry, MANUAL_ARCHIVE_RESTART
 from osf.models import (
     ArchiveJob,
     AbstractNode,
@@ -445,23 +441,9 @@ def archive_success(self, dst_pk, job_pk):
         job.save()
         dst.sanction.ask(dst.get_active_contributors_recursive(unique_users=True))
 
-    if was_manually_restarted(dst):
-        logger.info(f'Registration {dst._id} was manually restarted, scheduling approval check')
-        delayed_manual_restart_approval.delay(dst._id, delay_minutes=5)
-
     dst.update_search()
 
 
-def was_manually_restarted(registration):
-    recent_logs = AdminLogEntry.objects.filter(
-        object_id=registration.pk,
-        action_flag=MANUAL_ARCHIVE_RESTART,
-        action_time__gte=timezone.now() - timedelta(hours=48)
-    )
-
-    return recent_logs.exists()
-
-
 @celery_app.task(bind=True)
 def force_archive(self, registration_id, permissible_addons, allow_unconfigured=False, skip_collisions=False, delete_collisions=False):
     from osf.management.commands.force_archive import archive, verify
@@ -482,6 +464,10 @@ def force_archive(self, registration_id, permissible_addons, allow_unconfigured=
             skip_collisions=skip_collisions,
             delete_collisions=delete_collisions,
         )
+
+        logger.info(f'Registration {registration._id} was manually restarted, scheduling approval check')
+        delayed_manual_restart_approval.delay(registration._id, delay_minutes=5)
+
         return f'Registration {registration_id} archive completed'
 
     except Exception as exc: