Merge branch staging

tests/adapters/incoming_messages_consumer/test_incoming_message_returns_fallback_message.py

@@ -1,5 +1,11 @@
+import logging
+from typing import Type
+
 import callee
 import pytest
+from pika.adapters.blocking_connection import BlockingChannel
+from pytest import LogCaptureFixture
+from pytest_mock import MockFixture
 
 from tests.adapters.incoming_messages_consumer import helpers
 from use_case_executor import constants
@@ -12,49 +18,28 @@
 from use_case_executor.domain.errors import InvalidFlowConfiguration
 from use_case_executor.domain.errors import InvalidFlowFormat
 from use_case_executor.domain.errors import InvalidUseCaseConfiguration
+from use_case_executor.domain.errors import Misconfiguration
 from use_case_executor.domain.errors import NLPExtractionError
+from use_case_executor.domain.errors import TechnicalException
 from use_case_executor.domain.errors import UserEventSendError
 from use_case_executor.domain.message_processing.answer_sender import AnswerSender
 from use_case_executor.domain.monitoring.monitoring_timer import MonitoringTimer
 
 
-@pytest.mark.parametrize(
-    "exception_class, fallback_text",
-    [
-        (ForbiddenUseCase, "Sorry, something looks misconfigured: test exception."),
-        (
-            InvalidUseCaseConfiguration,
-            "Sorry, something looks misconfigured: test exception.",
-        ),
-        (
-            InvalidFlowConfiguration,
-            "Sorry, something looks misconfigured: test exception.",
-        ),
-        (InvalidFlowFormat, InvalidFlowFormat().end_user_message),
-        (InvalidClientMessageFormat, InvalidClientMessageFormat().end_user_message),
-        (NLPExtractionError, NLPExtractionError().end_user_message),
-        (UserEventSendError, UserEventSendError().end_user_message),
-        (
-            ImpossibleHandoverAvailabilityCheck,
-            ImpossibleHandoverAvailabilityCheck().end_user_message,
-        ),
-        (ImpossibleTicketCreation, ImpossibleTicketCreation().end_user_message),
-        (Exception, constants.FALLBACK_MESSAGE),
-    ],
-)
-def test_process_incoming_message_raising_exception_sends_a_fallback_message(
-    mocker,
-    instance_id,
-    nlp_language,
-    content_language,
-    uce_incoming_messages_channel,
-    exception_class,
-    fallback_text,
-):
+def set_mocks_publish_message_and_check_mock_calls(
+    mocker: MockFixture,
+    exception: Exception,
+    instance_id: int,
+    nlp_language: str,
+    content_language: str,
+    use_latest: bool,
+    uce_incoming_messages_channel: BlockingChannel,
+    fallback_text: str,
+) -> None:
     process_incoming_message_mock = mocker.patch.object(
         facade,
         "process_incoming_message",
-        side_effect=exception_class("test exception"),
+        side_effect=exception,
         autospec=True,
     )
     send_message_acknowledgement_and_fallback_answer_mock = mocker.patch.object(
@@ -63,12 +48,11 @@ def test_process_incoming_message_raising_exception_sends_a_fallback_message(
         side_effect=None,
         autospec=True,
     )
-
     incoming_message = helpers.make_incoming_message(
         instance_id=instance_id,
         nlp_language=nlp_language,
         content_language=content_language,
-        use_latest=False,
+        use_latest=use_latest,
     )
     (
         message_properties,
@@ -77,7 +61,6 @@ def test_process_incoming_message_raising_exception_sends_a_fallback_message(
         message_to_send=incoming_message,
         uce_incoming_messages_channel=uce_incoming_messages_channel,
     )
-
     process_incoming_message_mock.assert_called_once_with(
         message_forward_data=BotMessageForwardData(
             message_properties=message_properties, message_body=message_body
@@ -88,6 +71,134 @@ def test_process_incoming_message_raising_exception_sends_a_fallback_message(
     )
     send_message_acknowledgement_and_fallback_answer_mock.assert_called_once_with(
         answer_sender=callee.InstanceOf(AnswerSender),
-        exception_raised=exception_class.__name__,
+        exception_raised=exception.__class__.__name__,
         fallback_text=fallback_text,
     )
+
+
+@pytest.mark.parametrize("use_latest", [True, False])
+def test_raising_exception_sends_default_fallback_message_and_log_exception_as_error(
+    mocker: MockFixture,
+    instance_id: int,
+    nlp_language: str,
+    content_language: str,
+    use_latest: bool,
+    uce_incoming_messages_channel: BlockingChannel,
+    caplog: LogCaptureFixture,
+) -> None:
+    exception = Exception("test exception")
+    set_mocks_publish_message_and_check_mock_calls(
+        mocker=mocker,
+        exception=exception,
+        instance_id=instance_id,
+        nlp_language=nlp_language,
+        content_language=content_language,
+        use_latest=use_latest,
+        uce_incoming_messages_channel=uce_incoming_messages_channel,
+        fallback_text=constants.FALLBACK_MESSAGE,
+    )
+
+    with caplog.at_level(logging.ERROR):
+        assert f"{exception.__class__.__name__}: test exception" in caplog.text
+
+
+@pytest.mark.parametrize("use_latest", [True, False])
+@pytest.mark.parametrize(
+    "exception_class",
+    [
+        InvalidFlowFormat,
+        InvalidClientMessageFormat,
+        NLPExtractionError,
+        UserEventSendError,
+        ImpossibleHandoverAvailabilityCheck,
+        ImpossibleTicketCreation,
+    ],
+)
+def test_raising_technical_exception_sends_custom_fallback_message_and_log_exception_as_error(
+    mocker: MockFixture,
+    instance_id: int,
+    nlp_language: str,
+    content_language: str,
+    use_latest: bool,
+    uce_incoming_messages_channel: BlockingChannel,
+    caplog: LogCaptureFixture,
+    exception_class: Type[TechnicalException],
+) -> None:
+    exception = exception_class("test exception")
+    set_mocks_publish_message_and_check_mock_calls(
+        mocker=mocker,
+        exception=exception,
+        instance_id=instance_id,
+        nlp_language=nlp_language,
+        content_language=content_language,
+        use_latest=use_latest,
+        uce_incoming_messages_channel=uce_incoming_messages_channel,
+        fallback_text=exception.end_user_message,
+    )
+
+    with caplog.at_level(logging.ERROR):
+        assert f"{exception.__class__.__name__}: test exception" in caplog.text
+
+
+@pytest.mark.parametrize(
+    "exception_class",
+    [ForbiddenUseCase, InvalidUseCaseConfiguration, InvalidFlowConfiguration],
+)
+def test_raising_misconfiguration_sends_custom_fallback_message_and_log_exception_as_error_if_not_use_latest(
+    mocker: MockFixture,
+    instance_id: int,
+    nlp_language: str,
+    content_language: str,
+    uce_incoming_messages_channel: BlockingChannel,
+    caplog: LogCaptureFixture,
+    exception_class: Type[Misconfiguration],
+) -> None:
+    exception = exception_class("test exception")
+    set_mocks_publish_message_and_check_mock_calls(
+        mocker=mocker,
+        exception=exception,
+        instance_id=instance_id,
+        nlp_language=nlp_language,
+        content_language=content_language,
+        use_latest=False,
+        uce_incoming_messages_channel=uce_incoming_messages_channel,
+        fallback_text="Sorry, something looks misconfigured: test exception.",
+    )
+
+    with caplog.at_level(logging.ERROR):
+        assert f"{exception.__class__.__name__}: test exception" in caplog.text
+
+
+@pytest.mark.parametrize(
+    "exception_class",
+    [ForbiddenUseCase, InvalidUseCaseConfiguration, InvalidFlowConfiguration],
+)
+def test_raising_misconfiguration_sends_custom_fallback_message_and_log_exception_as_info_if_use_latest(
+    mocker: MockFixture,
+    instance_id: int,
+    nlp_language: str,
+    content_language: str,
+    uce_incoming_messages_channel: BlockingChannel,
+    caplog: LogCaptureFixture,
+    exception_class: Type[Misconfiguration],
+) -> None:
+    exception = exception_class("test exception")
+    set_mocks_publish_message_and_check_mock_calls(
+        mocker=mocker,
+        exception=exception,
+        instance_id=instance_id,
+        nlp_language=nlp_language,
+        content_language=content_language,
+        use_latest=True,
+        uce_incoming_messages_channel=uce_incoming_messages_channel,
+        fallback_text="Sorry, something looks misconfigured: test exception.",
+    )
+
+    with caplog.at_level(logging.INFO):
+        assert (
+            f"Caught misconfiguration error, ignoring it: {repr(exception)}"
+            in caplog.text
+        )
+
+    with caplog.at_level(logging.ERROR):
+        assert f"{exception.__class__.__name__}: test exception" not in caplog.text

tests/domain/execute_use_case_and_send_answer/test_incoming_message_returns_a_fallback_message.py

@@ -19,7 +19,7 @@
     "use_latest, exception_message",
     [
         (True, "use case does not have any flow to execute"),
-        (False, "This use case is not published"),
+        (False, "this use case is not published"),
     ],
 )
 def test_incoming_message_with_matching_use_case_and_no_flow_returns_a_fallback_message(

tests/worker/message_handling/test_incoming_message_returns_a_fallback_message.py

@@ -76,7 +76,7 @@ def test_incoming_message_with_invalid_content_language_returns_a_fallback_messa
     "use_latest, exception_message",
     [
         (True, "use case does not have any flow to execute"),
-        (False, "This use case is not published"),
+        (False, "this use case is not published"),
     ],
 )
 def test_incoming_message_with_matching_use_case_and_no_flow_returns_a_fallback_message(

use_case_executor/adapters/incoming_messages_consumer.py

@@ -10,6 +10,7 @@
 from use_case_executor.adapters.bot_message_forwarder import BotMessageForwardData
 from use_case_executor.domain import facade
 from use_case_executor.domain.errors import DomainException
+from use_case_executor.domain.errors import Misconfiguration
 from use_case_executor.domain.message_processing.answer_sender import AnswerSender
 from use_case_executor.domain.monitoring.monitoring_timer import MonitoringTimer
 from use_case_executor.helpers import rmq_connection
@@ -151,4 +152,9 @@ def _process_uce_incoming_message(properties: BasicProperties, body: bytes) -> N
             fallback_text=fallback_text,
         )
 
+        # When use_latest is True, we do not send misconfiguration errors to Sentry
+        if message_json.get("use_latest") and isinstance(exc, Misconfiguration):
+            log.info("Caught misconfiguration error, ignoring it: %s", repr(exc))
+            return
+
         raise

use_case_executor/api/app_maker.py

@@ -1,13 +1,17 @@
 import logging
 import time
+from typing import Callable
 
 from content_size_limit_asgi import ContentSizeLimitMiddleware
 from fastapi import FastAPI
 from sentry_sdk.integrations.asgi import SentryAsgiMiddleware
 from starlette.requests import Request
+from starlette.responses import Response
 
 from use_case_executor import constants
+from use_case_executor.adapters.database_repository import database
 from use_case_executor.api import errors
+from use_case_executor.api.database_helpers import db_session
 from use_case_executor.api.namespaces import filters
 from use_case_executor.api.namespaces import image_upload
 from use_case_executor.api.namespaces import model_mappings
@@ -22,42 +26,6 @@
 log = logging.getLogger(__name__)
 
 
-def _setup_requests_monitoring_and_logging(fastapi_app: FastAPI) -> None:
-    @fastapi_app.middleware("http")
-    async def add_process_time_header(request: Request, call_next):
-        start_time = time.perf_counter()
-        response = await call_next(request)
-        elapsed_time = time.perf_counter() - start_time
-        try:
-            is_successful_health_check = (
-                request.scope["path"] == "/health_check" and response.status_code == 200
-            )
-            if not is_successful_health_check:
-                log.info(
-                    "%s %s %s %s %s %s (took %.3f s).",
-                    time.strftime("[%Y-%b-%d %H:%M:%s]"),
-                    request.client.host,
-                    request.method,
-                    request.scope["type"],
-                    request.scope["path"],
-                    response.status_code,
-                    elapsed_time,
-                )
-            tags = {
-                "endpoint": request.scope["endpoint"].__name__
-                if "endpoint" in request.scope
-                else "[unknown route]",
-                "method": request.method.lower(),
-                "status_code": response.status_code,
-            }
-            statsd_connector.STATSD_CLIENT.timing(
-                "http_response", elapsed_time, tags=tags
-            )
-        except Exception as exc:  # pylint: disable=broad-except
-            log.warning("Error processing after request callback: exc=%s", repr(exc))
-        return response
-
-
 def create_app() -> FastAPI:
     fastapi_app = FastAPI(
         title="use-case-executor", description="Service executing use cases."
@@ -68,7 +36,7 @@ def create_app() -> FastAPI:
         max_content_size=constants.MAX_CONTENT_SIZE,
     )
 
-    _setup_requests_monitoring_and_logging(fastapi_app=fastapi_app)
+    _setup_before_request_and_after_response_processing(fastapi_app=fastapi_app)
     errors.set_error_handlers(fastapi_app=fastapi_app)
 
     statsd_connector.STATSD_CLIENT.incr("boot_api")
@@ -84,3 +52,49 @@ def create_app() -> FastAPI:
     fastapi_app.include_router(variables.router)
 
     return fastapi_app
+
+
+def _setup_before_request_and_after_response_processing(fastapi_app: FastAPI) -> None:
+    @fastapi_app.middleware("http")
+    async def add_before_request_and_after_response_processing(
+        request: Request, call_next: Callable
+    ) -> Response:
+        start_time = time.perf_counter()
+        with database.session_maker() as session:
+            db_session.set(session)
+            response = await call_next(request)
+        try:
+            elapsed_time = time.perf_counter() - start_time
+            log_and_monitor_request(
+                elapsed_time=elapsed_time, request=request, response=response
+            )
+        except Exception as exc:  # pylint: disable=broad-except
+            log.warning("Error processing after request callback: exc=%s", repr(exc))
+        return response
+
+
+def log_and_monitor_request(
+    elapsed_time: float, request: Request, response: Response
+) -> None:
+    is_successful_health_check = (
+        request.scope["path"] == "/health_check" and response.status_code == 200
+    )
+    if not is_successful_health_check:
+        log.info(
+            "%s %s %s %s %s %s (took %.3f s).",
+            time.strftime("[%Y-%b-%d %H:%M:%s]"),
+            request.client.host,
+            request.method,
+            request.scope["type"],
+            request.scope["path"],
+            response.status_code,
+            elapsed_time,
+        )
+    tags = {
+        "endpoint": request.scope["endpoint"].__name__
+        if "endpoint" in request.scope
+        else "[unknown route]",
+        "method": request.method.lower(),
+        "status_code": response.status_code,
+    }
+    statsd_connector.STATSD_CLIENT.timing("http_response", elapsed_time, tags=tags)