From 6edaf3b31d595a5c26b593c72f950ec7df6642ab Mon Sep 17 00:00:00 2001 From: Jonathan Reveille Date: Wed, 18 Sep 2024 16:27:55 +0200 Subject: [PATCH] =?UTF-8?q?fixup!=20=F0=9F=90=9B(backend)=20submit=20for?= =?UTF-8?q?=20signature=20handle=20timeout=20delete=20signing=20procedure?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- src/backend/joanie/core/models/products.py | 22 +++------ src/backend/joanie/core/utils/signature.py | 24 ---------- .../joanie/signature/backends/lex_persona.py | 10 ++++- .../joanie/tests/core/test_models_order.py | 29 +++++------- .../test_delete_signing_procedure.py | 45 ++++++++++++++++++- 5 files changed, 71 insertions(+), 59 deletions(-) diff --git a/src/backend/joanie/core/models/products.py b/src/backend/joanie/core/models/products.py index 4e79b25499..fceaaa09b2 100644 --- a/src/backend/joanie/core/models/products.py +++ b/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: diff --git a/src/backend/joanie/core/utils/signature.py b/src/backend/joanie/core/utils/signature.py index 7179ee3ddf..dba553fd47 100644 --- a/src/backend/joanie/core/utils/signature.py +++ b/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() diff --git a/src/backend/joanie/signature/backends/lex_persona.py b/src/backend/joanie/signature/backends/lex_persona.py index fd0f118ab2..143f6695c7 100644 --- a/src/backend/joanie/signature/backends/lex_persona.py +++ b/src/backend/joanie/signature/backends/lex_persona.py @@ -533,8 +533,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: diff --git a/src/backend/joanie/tests/core/test_models_order.py b/src/backend/joanie/tests/core/test_models_order.py index bd9ccc41b7..23827fcc1a 100644 --- a/src/backend/joanie/tests/core/test_models_order.py +++ b/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) diff --git a/src/backend/joanie/tests/signature/backends/lex_persona/test_delete_signing_procedure.py b/src/backend/joanie/tests/signature/backends/lex_persona/test_delete_signing_procedure.py index 651e334fca..c929f2db38 100644 --- a/src/backend/joanie/tests/signature/backends/lex_persona/test_delete_signing_procedure.py +++ b/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, + }, + ) + ], + )