feat(projectHistoryLogs): log deleted submissions (#5423)

### 📣 Summary
Create logs when submissions are deleted.


### 📖 Description
Each deletion is logged individually even if it was done in bulk. Unlike
other actions, even failed deletions will be logged as long as the
process of deletion was started, since some of the submissions may have
been deleted before the failure. In this case, we prefer false positives
to missing logs.


### 💭 Notes
The more robust way to handle this would probably be to redo the
bulk-deletion process entirely such that each deletion is done as a
single transaction with deletion from mongo, deleting docs from storage,
creating a log. This would obviously take a lot more time and probably
would work better as a celery task than an API endpoint.. At this moment
we did not think it was worth it to rethink the whole process, and
instead settled on just logging every *attempt* to delete, even if that
attempt failed. This is in-keeping with our logging strategy so far,
which has focused on intent more than effect.

For single deletes, this just adds a listener on the post_delete signal
for Instances which attaches the necessary information to the request,
similar to how individual updates were handled.


### 👀 Preview steps
Feature/no-change template:
1. ℹ️ have 2 accounts and a project
2. Give user2 permission to add submissions to the project
3. Add at least 2 submissions as user1 and 2 as user 2
4. Enable anonymous submissions
5. Add at least 2 anonymous submissions 
6. Go to Project > Data and get the _ids of 1 submission each for user1,
user2, and anonymous
7. For each submission, in the terminal, run `curl -X DELETE -H
'Authorization: Token <your token>'
localhost/api/v2/assets/<asset_uid>/data/<submission _id>/ `
8. Go to `api/v2/assets/<asset_uid>/history`
9. 🟢 There should be a project history log with
`action="delete-submission"` and the usual metadata, along with
`"submission":{"submitted_by": <user1/user2/AnonymousUser>}`
10. Go back to Project > Data
11. Select one submission each for user1, user2, and anonymous
12. Hit the Delete button and confirm
13. 🟢 Go back to `api/v2/assets/<asset_uid>/history`. There should be
three new project history logs (the same ones as were created with a
single delete)
14. To test that we still get logs in case of a database timeout, use
[mockobo](https://github.com/kobotoolbox/mockobo) to submit a 4000
submissions to your project (may want to do this in groups).
15. Go to Project > Data and select all submissions
16. Hit Delete and confirm
17. Before the request finishes (it should take a few seconds), kill
your mongo server locally (`docker compose stop mongo` if you're using
kobo-compose)
18. 🟢 Go back to `api/v2/assets/<asset_uid>/history`. The log count
should have gone up by 4000. You can spot check a few to make sure they
are deletion logs.
* sometimes it takes a minute for the logs to show up because the front
end times out before the backend does. you may need to reload a few
times.

kobo/apps/audit_log/middleware.py

@@ -9,11 +9,22 @@ def create_audit_logs(request):
         if request.method in ['GET', 'HEAD']:
             return response
         log_type = getattr(request, 'log_type', None)
+        url_name = request.resolver_match.url_name
+
         if (
             status.is_success(response.status_code) and
             log_type == AuditType.PROJECT_HISTORY
         ):
             ProjectHistoryLog.create_from_request(request)
+        # special case: log bulk delete requests even if there is an
+        # error. Things may have been deleted in mongo before the request timed out,
+        # and we'd rather have false positives than missing records
+        elif (
+            log_type == AuditType.PROJECT_HISTORY
+            and url_name == 'submission-bulk'
+            and request.method == 'DELETE'
+        ):
+            ProjectHistoryLog.create_from_request(request)
         return response
 
     return create_audit_logs

kobo/apps/audit_log/models.py

@@ -399,6 +399,7 @@ def create_from_request(cls, request: WSGIRequest):
             'assetsnapshot-submission-alias': cls._create_from_submission_request,
             'submissions': cls._create_from_submission_request,
             'submissions-list': cls._create_from_submission_request,
+            'submission-detail': cls._create_from_submission_request,
         }
         url_name = request.resolver_match.url_name
         method = url_name_to_action.get(url_name, None)
@@ -615,6 +616,8 @@ def _create_from_submission_request(cls, request):
         for instance in instances.values():
             if instance.action == 'add':
                 action = AuditAction.ADD_SUBMISSION
+            elif instance.action == 'delete':
+                action = AuditAction.DELETE_SUBMISSION
             else:
                 action = AuditAction.MODIFY_SUBMISSION
             metadata = {

kobo/apps/audit_log/signals.py

@@ -2,7 +2,7 @@
 
 from celery.signals import task_success
 from django.contrib.auth.signals import user_logged_in
-from django.db.models.signals import post_save
+from django.db.models.signals import post_delete, post_save
 from django.dispatch import receiver
 from django_userforeignkey.request import get_current_request
 
@@ -72,8 +72,7 @@ def add_assigned_partial_perms(sender, instance, user, perms, **kwargs):
     request.partial_permissions_added[user.username] = perms_as_list_of_dicts
 
 
-@receiver(post_save, sender=Instance)
-def add_instance_to_request(instance, created, **kwargs):
+def add_instance_to_request(instance, action):
     request = get_current_request()
     if request is None:
         return
@@ -90,13 +89,24 @@ def add_instance_to_request(instance, created, **kwargs):
             instance.id: SubmissionUpdate(
                 username=username,
                 status=instance.get_validation_status().get('label', 'None'),
-                action='add' if created else 'modify',
+                action=action,
                 id=instance.id,
             )
         }
     )
 
 
+@receiver(post_save, sender=Instance)
+def add_instance_to_request_post_save(instance, created, **kwargs):
+    action = 'add' if created else 'modify'
+    add_instance_to_request(instance, action)
+
+
+@receiver(post_delete, sender=Instance)
+def add_instance_to_request_post_delete(instance, *args, **kwargs):
+    add_instance_to_request(instance, 'delete')
+
+
 @receiver(post_remove_perm, sender=Asset)
 def add_removed_perms(sender, instance, user, codename, **kwargs):
     request = _initialize_request()

kobo/apps/audit_log/tests/test_project_history_logs.py

@@ -13,6 +13,7 @@
 from django.core.files.uploadedfile import SimpleUploadedFile
 from django.test import override_settings
 from django.urls import reverse
+from pymongo.errors import PyMongoError
 from rest_framework.response import Response
 from rest_framework.reverse import reverse as drf_reverse
 
@@ -1657,12 +1658,12 @@ def test_multiple_submision_validation_statuses(self):
         self.assertEqual(log2.action, AuditAction.MODIFY_SUBMISSION)
         self.assertEqual(log2.metadata['submission']['status'], 'On Hold')
 
-        log2 = ProjectHistoryLog.objects.filter(
+        log3 = ProjectHistoryLog.objects.filter(
             metadata__submission__submitted_by='AnonymousUser'
         ).first()
-        self._check_common_metadata(log2.metadata, PROJECT_HISTORY_LOG_PROJECT_SUBTYPE)
-        self.assertEqual(log2.action, AuditAction.MODIFY_SUBMISSION)
-        self.assertEqual(log2.metadata['submission']['status'], 'On Hold')
+        self._check_common_metadata(log3.metadata, PROJECT_HISTORY_LOG_PROJECT_SUBTYPE)
+        self.assertEqual(log3.action, AuditAction.MODIFY_SUBMISSION)
+        self.assertEqual(log3.metadata['submission']['status'], 'On Hold')
 
     @data(
         # submit as anonymous?, use v1 endpoint?
@@ -1720,3 +1721,77 @@ def test_add_submission(self, anonymous, v1):
         self._check_common_metadata(log.metadata, PROJECT_HISTORY_LOG_PROJECT_SUBTYPE)
         username = 'AnonymousUser' if anonymous else self.user.username
         self.assertEqual(log.metadata['submission']['submitted_by'], username)
+
+    def test_delete_single_submission(self):
+        self._add_submission('adminuser')
+        submissions_json = self.asset.deployment.get_submissions(
+            self.asset.owner, fields=['_id']
+        )
+        log_metadata = self._base_project_history_log_test(
+            method=self.client.delete,
+            url=reverse(
+                'api_v2:submission-detail',
+                kwargs={
+                    'parent_lookup_asset': self.asset.uid,
+                    'pk': submissions_json[0]['_id'],
+                },
+            ),
+            request_data={},
+            expected_action=AuditAction.DELETE_SUBMISSION,
+            expected_subtype=PROJECT_HISTORY_LOG_PROJECT_SUBTYPE,
+        )
+        self.assertEqual(log_metadata['submission']['submitted_by'], 'adminuser')
+
+    @data(True, False)
+    def test_delete_multiple_submissions(self, simulate_error):
+        self._add_submission('adminuser')
+        self._add_submission('someuser')
+        self._add_submission(None)
+        submissions_json = self.asset.deployment.get_submissions(
+            self.asset.owner, fields=['_id']
+        )
+        payload = json.dumps(
+            {
+                'submission_ids': [sub['_id'] for sub in submissions_json],
+            }
+        )
+        if simulate_error:
+            # tell the client to return a 500 like a normal request would
+            # instead of raising errors directly
+            self.client.raise_request_exception = False
+
+            # simulate a DB error
+            mongo_patcher = patch(
+                'kobo.apps.openrosa.apps.viewer.models.parsed_instance.xform_instances.delete_many',  # noqa
+                side_effect=PyMongoError(),
+            )
+            mongo_patcher.start()
+        self.client.delete(
+            path=reverse(
+                'api_v2:submission-bulk',
+                kwargs={'parent_lookup_asset': self.asset.uid},
+            ),
+            data={'payload': payload},
+            format='json',
+        )
+        if simulate_error:
+            mongo_patcher.stop()
+
+        self.assertEqual(ProjectHistoryLog.objects.count(), 3)
+        log1 = ProjectHistoryLog.objects.filter(
+            metadata__submission__submitted_by='adminuser'
+        ).first()
+        self._check_common_metadata(log1.metadata, PROJECT_HISTORY_LOG_PROJECT_SUBTYPE)
+        self.assertEqual(log1.action, AuditAction.DELETE_SUBMISSION)
+
+        log2 = ProjectHistoryLog.objects.filter(
+            metadata__submission__submitted_by='someuser'
+        ).first()
+        self._check_common_metadata(log2.metadata, PROJECT_HISTORY_LOG_PROJECT_SUBTYPE)
+        self.assertEqual(log2.action, AuditAction.DELETE_SUBMISSION)
+
+        log3 = ProjectHistoryLog.objects.filter(
+            metadata__submission__submitted_by='AnonymousUser'
+        ).first()
+        self._check_common_metadata(log2.metadata, PROJECT_HISTORY_LOG_PROJECT_SUBTYPE)
+        self.assertEqual(log3.action, AuditAction.DELETE_SUBMISSION)

kobo/apps/audit_log/utils.py

@@ -3,10 +3,10 @@
 
 @dataclass
 class SubmissionUpdate:
-    status: str
-    action: str
     id: int
+    action: str
     username: str = 'AnonymousUser'
+    status: str | None = None
 
     def __post_init__(self):
         self.username = 'AnonymousUser' if self.username is None else self.username

kobo/apps/audit_log/views.py

@@ -430,6 +430,7 @@ class AllProjectHistoryLogViewSet(AuditLogViewSet):
     >        connect-project
     >        delete-media
     >        delete-service
+    >        delete-submission
     >        deploy
     >        disable-sharing
     >        disallow-anonymous-submissions
@@ -510,6 +511,10 @@ class AllProjectHistoryLogViewSet(AuditLogViewSet):
 
         c. metadata__hook__active
 
+    * delete-submission
+
+        a. metadata__submission__submitted_by
+
     * deploy
 
         a. metadata__latest_version_uid
@@ -692,6 +697,7 @@ class ProjectHistoryLogViewSet(
     >        connect-project
     >        delete-media
     >        delete-service
+    >        delete-submission
     >        deploy
     >        disable-sharing
     >        disallow-anonymous-submissions
@@ -772,6 +778,10 @@ class ProjectHistoryLogViewSet(
 
         c. metadata__hook__active
 
+    * delete-submission
+
+        a. metadata__submission__submitted_by
+
     * deploy
 
         a. metadata__latest_version_uid

kpi/tests/api/v2/test_api_submissions.py

@@ -17,12 +17,11 @@
 from django_digest.test import Client as DigestClient
 from rest_framework import status
 
-from kobo.apps.audit_log.models import AuditLog, AuditType
 from kobo.apps.kobo_auth.shortcuts import User
+from kobo.apps.openrosa.apps.logger.exceptions import InstanceIdMissingError
 from kobo.apps.openrosa.apps.logger.models.instance import Instance
 from kobo.apps.openrosa.apps.main.models.user_profile import UserProfile
 from kobo.apps.openrosa.libs.utils.logger_tools import dict2xform
-from kobo.apps.openrosa.apps.logger.exceptions import InstanceIdMissingError
 from kpi.constants import (
     ASSET_TYPE_SURVEY,
     PERM_ADD_SUBMISSIONS,
@@ -163,32 +162,6 @@ def test_delete_submissions_as_owner(self):
         """
         self._delete_submissions()
 
-    def test_audit_log_on_bulk_delete(self):
-        """
-        Validate that all submission ids are logged in AuditLog table on
-        bulk deletion.
-        """
-        expected_submission_ids = [
-            s['_id']
-            for s in self.asset.deployment.get_submissions(
-                self.asset.owner, fields=['_id']
-            )
-        ]
-        audit_log_count = AuditLog.objects.filter(
-            user=self.someuser, app_label='logger', model_name='instance'
-        ).count()
-        # No submissions have been deleted yet
-        assert audit_log_count == 0
-        # Delete all submissions
-        self._delete_submissions()
-
-        # All submissions have been deleted and should be logged
-        deleted_submission_ids = AuditLog.objects.values_list('pk', flat=True).filter(
-            user=self.someuser, app_label='logger', model_name='instance'
-        )
-        assert len(expected_submission_ids) > 0
-        assert sorted(expected_submission_ids), sorted(deleted_submission_ids)
-
     def test_delete_submissions_as_anonymous(self):
         """
         someuser is the project owner.
@@ -791,35 +764,6 @@ def test_delete_submission_as_owner(self):
         submission = self.submissions_submitted_by_someuser[0]
         self._delete_submission(submission)
 
-    def test_audit_log_on_delete(self):
-        """
-        Validate that the submission id is logged in AuditLog table when it is
-        deleted.
-        """
-        submission = self.submissions_submitted_by_someuser[0]
-        audit_log_count = AuditLog.objects.filter(
-            user=self.someuser,
-            app_label='logger',
-            model_name='instance',
-            log_type=AuditType.SUBMISSION_MANAGEMENT,
-        ).count()
-        # No submissions have been deleted yet
-        assert audit_log_count == 0
-        # Delete one submission
-        self.test_delete_submission_as_owner()
-
-        # All submissions have been deleted and should be logged
-        deleted_submission_ids = AuditLog.objects.values_list(
-            'pk', flat=True
-        ).filter(
-            user=self.someuser,
-            app_label='logger',
-            model_name='instance',
-            log_type=AuditType.SUBMISSION_MANAGEMENT,
-        )
-        assert len(deleted_submission_ids) > 0
-        assert [submission['_id']], deleted_submission_ids
-
     def test_delete_not_existing_submission_as_owner(self):
         """
         someuser is the owner of the project.