fixup! 🐛(backend) submit for signature handle timeout delete signing …

…procedure

src/backend/joanie/core/models/products.py

@@ -37,7 +37,6 @@
 from joanie.core.utils import contract_definition as contract_definition_utility
 from joanie.core.utils import issuers, webhooks
 from joanie.core.utils.payment_schedule import generate as generate_payment_schedule
-from joanie.core.utils.signature import handle_signature_deletion_error
 from joanie.signature.backends import get_signature_backend
 from joanie.signature.exceptions import DeleteSignatureProcedureFailed
 
@@ -967,24 +966,17 @@ def submit_for_signature(self, user: User):
         )
 
         if should_be_resubmitted:
-            # The signature provider may take some time to respond with the confirmation of the
-            # deletion. If we reach the timeout limit, we should reset the contract submission
-            # values because the signature provider will delete them.
-            # We won't be able to use the `contract.signature_backend_reference` again.
-            # There can be edge case where the signature backend reference was already deleted,
-            # causing an error that the reference was not found at the signature provider side.
+            # The signature provider may delay confirming deletion. If timeout occurs, reset
+            # submission values, as the signature provider will delete them. In an edge case, the
+            # reference `contract.signature_backend_reference` cannot be used and may already
+            # be deleted causing a 'not found' error from the signature provider.
             try:
                 backend_signature.delete_signing_procedure(
                     contract.signature_backend_reference
                 )
-            except BackendTimeout as exception:  # pylint: disable=unused-variable
-                handle_signature_deletion_error(
-                    order=self, error_message="Timeout on signature reference deletion"
-                )
-            except DeleteSignatureProcedureFailed as exception:  # pylint: disable=unused-variable
-                handle_signature_deletion_error(
-                    order=self, error_message="Failed to delete signature procedure"
-                )
+            except (BackendTimeout, DeleteSignatureProcedureFailed):
+                pass
+            contract.reset_submission_for_signature()
             was_already_submitted = False
 
         # We want to submit or re-submit the contract for signature in three cases:

src/backend/joanie/core/utils/signature.py

@@ -4,14 +4,11 @@
 
 import hashlib
 import hmac
-import logging
 
 from django.conf import settings
 
 from rest_framework import exceptions
 
-logger = logging.getLogger(__name__)
-
 
 def check_signature(request, settings_name):
     """Check the signature of a request."""
@@ -36,24 +33,3 @@ def check_signature(request, settings_name):
     )
     if not signature_is_valid:
         raise exceptions.AuthenticationFailed("Invalid authentication.")
-
-
-def handle_signature_deletion_error(order, error_message):
-    """
-    Handles the exception raised on the deletion of a signing procedure.
-    It's responsible for resetting the submission values from the outdated
-    contract of the order.
-    """
-    logger.error(
-        error_message,
-        extra={
-            "context": {
-                "order": order.to_dict(),
-                "product": order.product.to_dict(),
-                "signature_backend_reference": (
-                    order.contract.signature_backend_reference
-                ),
-            }
-        },
-    )
-    order.contract.reset_submission_for_signature()

src/backend/joanie/signature/backends/lex_persona.py

@@ -527,8 +527,16 @@ def delete_signing_procedure(self, reference_id: str):
         try:
             response = requests.delete(url, headers=headers, timeout=timeout)
         except ReadTimeout as exception:
+            logger.error(
+                exception,
+                extra={
+                    "context": {
+                        "signature_backend_reference": reference_id,
+                    }
+                },
+            )
             raise BackendTimeout(
-                "Deletion request is taking longer than expected."
+                f"Deletion request is taking longer than expected for reference: {reference_id}"
             ) from exception
 
         if not response.ok:

src/backend/joanie/tests/core/test_models_order.py

@@ -18,9 +18,9 @@
 from django.utils import timezone as django_timezone
 
 import responses
+from requests.exceptions import ReadTimeout
 
 from joanie.core import enums, factories
-from joanie.core.exceptions import BackendTimeout
 from joanie.core.models import Contract, CourseState
 from joanie.core.utils import contract_definition
 from joanie.payment.factories import BillingAddressDictFactory, InvoiceFactory
@@ -1338,11 +1338,14 @@ def test_models_order_submit_for_signature_step_delete_signing_procedure_timeout
         # Change the contract definition title to trigger the `should_be_resubmitted` condition
         order.product.contract_definition.title = "You know nothing John Snow."
         order.product.contract_definition.save()
-        # Prepare the ReadTimeout on the `delete_signing_procedure` method
+        # Prepare the `ReadTimeout` on the `delete_signing_procedure` method
+        # when the second call of `submit_for_signature` occurs
         responses.add(
             responses.DELETE,
             f"https://lex_persona.test01.com/api/workflows/{workflow_id}",
-            body=BackendTimeout(),
+            body=ReadTimeout(
+                f"Deletion request is taking longer than expected for reference: {workflow_id}",
+            ),
         )
         # Prepare the data for the new document to sign on the contract
         new_workflow_id = "wfl_id_fake_2"
@@ -1533,16 +1536,14 @@ def test_models_order_submit_for_signature_step_delete_signing_procedure_timeout
         with self.assertLogs("joanie") as logger:
             order.submit_for_signature(user=user)
 
-        # We should find the in the logger message the reference wfl_id_fake_1 being deleted
+        # We should find in the logger message the reference wfl_id_fake_1 being deleted
         self.assertLogsEquals(
             logger.records,
             [
                 (
                     "ERROR",
-                    "Timeout on signature reference deletion",
+                    f"Deletion request is taking longer than expected for reference: {workflow_id}",
                     {
-                        "order": dict,
-                        "product": dict,
                         "signature_backend_reference": str,
                     },
                 )
@@ -1824,7 +1825,8 @@ def test_models_order_submit_for_signature_step_delete_signing_procedure_referen
         with self.assertLogs("joanie") as logger:
             order.submit_for_signature(user=user)
 
-        # We should find the in the logger message the reference wfl_id_fake_1 being deleted
+        # We should find in the logger message the reference wfl_id_fake_1 trying to deleted
+        # but fails
         self.assertLogsEquals(
             logger.records,
             [
@@ -1833,19 +1835,10 @@ def test_models_order_submit_for_signature_step_delete_signing_procedure_referen
                     "Lex Persona: Unable to delete the signature procedure"
                     f" the reference does not exist {workflow_id}, reason: {error_response}",
                 ),
-                (
-                    "ERROR",
-                    "Failed to delete signature procedure",
-                    {
-                        "order": dict,
-                        "product": dict,
-                        "signature_backend_reference": str,
-                    },
-                ),
             ],
         )
 
-        # Check we have the latest data from db for the contract
+        # Our contract must have the new values of the document to sign
         contract.refresh_from_db()
         self.assertIsNotNone(contract.submitted_for_signature_on)
         self.assertEqual(contract.signature_backend_reference, new_workflow_id)

src/backend/joanie/tests/signature/backends/lex_persona/test_delete_signing_procedure.py

@@ -6,9 +6,12 @@
 from django.test.utils import override_settings
 
 import responses
+from requests.exceptions import ReadTimeout
 
+from joanie.core.exceptions import BackendTimeout
 from joanie.signature import exceptions
 from joanie.signature.backends import get_signature_backend
+from joanie.tests.base import BaseLogMixinTestCase
 
 from . import get_expected_workflow_payload
 
@@ -23,7 +26,7 @@
     JOANIE_SIGNATURE_VALIDITY_PERIOD_IN_SECONDS=60 * 60 * 24 * 15,
     JOANIE_SIGNATURE_TIMEOUT=3,
 )
-class LexPersonaBackendTestCase(TestCase):
+class LexPersonaBackendTestCase(TestCase, BaseLogMixinTestCase):
     """Test suite for Lex Persona Signature provider Backend delete_signing_procedure."""
 
     @responses.activate
@@ -92,3 +95,43 @@ def test_backend_lex_persona_delete_signing_procedure_failed(self):
             responses.calls[0].request.headers["Authorization"], "Bearer token_id_fake"
         )
         self.assertEqual(responses.calls[0].request.method, "DELETE")
+
+    @responses.activate
+    def test_backend_lex_persona_delete_signing_procedure_reaches_timeout(self):
+        """
+        When deleting a signature procedure requests reaches a `ReadTimeout`, it should raise
+        a `BackendTimeOut` with the error message mentioning that it takes a while for the
+        signature provider to delete the reference on their side. We should also see log messages
+        that mentions the reference being deleted.
+        """
+        backend = get_signature_backend()
+
+        responses.add(
+            responses.DELETE,
+            "https://lex_persona.test01.com/api/workflows/wfl_id_fake",
+            body=ReadTimeout(
+                "Deletion request is taking longer than expected for reference: wfl_id_fake"
+            ),
+        )
+
+        with self.assertRaises(BackendTimeout) as context:
+            with self.assertLogs("joanie") as logger:
+                backend.delete_signing_procedure(reference_id="wfl_id_fake")
+
+        self.assertEqual(
+            str(context.exception),
+            "Deletion request is taking longer than expected for reference: wfl_id_fake",
+        )
+
+        self.assertLogsEquals(
+            logger.records,
+            [
+                (
+                    "ERROR",
+                    "Deletion request is taking longer than expected for reference: wfl_id_fake",
+                    {
+                        "signature_backend_reference": str,
+                    },
+                )
+            ],
+        )