From cfd6a3ed5f612dd468f0bc4a37b6ce6c5cf37f9d Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Mon, 14 Oct 2024 20:58:35 +0200 Subject: [PATCH 01/24] moves error_codes to models_library --- .../src/models_library}/error_codes.py | 0 .../tests/test_error_codes.py | 2 +- .../service-library/src/servicelib/aiohttp/rest_middlewares.py | 2 +- packages/service-library/src/servicelib/logging_utils.py | 3 ++- .../service-library/tests/aiohttp/test_rest_middlewares.py | 2 +- packages/service-library/tests/test_logging_utils.py | 2 +- .../exceptions/handlers/_handlers_factory.py | 2 +- .../src/simcore_service_api_server/services/log_streaming.py | 2 +- .../models/dynamic_services_scheduler.py | 2 +- .../modules/dynamic_sidecar/scheduler/_core/_observer.py | 2 +- .../src/simcore_service_dynamic_sidecar/core/utils.py | 2 +- .../server/src/simcore_service_webserver/invitations/_core.py | 2 +- .../web/server/src/simcore_service_webserver/login/_2fa_api.py | 2 +- .../simcore_service_webserver/login/handlers_confirmation.py | 2 +- .../simcore_service_webserver/login/handlers_registration.py | 2 +- .../studies_dispatcher/_redirects_handlers.py | 2 +- .../studies_dispatcher/_studies_access.py | 2 +- .../server/src/simcore_service_webserver/users/_handlers.py | 2 +- services/web/server/src/simcore_service_webserver/utils.py | 2 +- .../server/src/simcore_service_webserver/wallets/_handlers.py | 2 +- 20 files changed, 20 insertions(+), 19 deletions(-) rename packages/{service-library/src/servicelib => models-library/src/models_library}/error_codes.py (100%) rename packages/{service-library => models-library}/tests/test_error_codes.py (95%) diff --git a/packages/service-library/src/servicelib/error_codes.py b/packages/models-library/src/models_library/error_codes.py similarity index 100% rename from packages/service-library/src/servicelib/error_codes.py rename to packages/models-library/src/models_library/error_codes.py diff --git a/packages/service-library/tests/test_error_codes.py b/packages/models-library/tests/test_error_codes.py similarity index 95% rename from packages/service-library/tests/test_error_codes.py rename to packages/models-library/tests/test_error_codes.py index f738ebe1e96..17f252a2539 100644 --- a/packages/service-library/tests/test_error_codes.py +++ b/packages/models-library/tests/test_error_codes.py @@ -6,7 +6,7 @@ import logging import pytest -from servicelib.error_codes import create_error_code, parse_error_code +from models_library.error_codes import create_error_code, parse_error_code logger = logging.getLogger(__name__) diff --git a/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py b/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py index 0b6af4a5428..f34f8990fa8 100644 --- a/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py +++ b/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py @@ -12,9 +12,9 @@ from aiohttp import web from aiohttp.web_request import Request from aiohttp.web_response import StreamResponse +from models_library.error_codes import create_error_code from models_library.errors_classes import OsparcErrorMixin from models_library.utils.json_serialization import json_dumps -from servicelib.error_codes import create_error_code from ..logging_utils import create_troubleshotting_log_message, get_log_record_extra from ..mimetype_constants import MIMETYPE_APPLICATION_JSON diff --git a/packages/service-library/src/servicelib/logging_utils.py b/packages/service-library/src/servicelib/logging_utils.py index 24b9ebcad29..909e8bc29e3 100644 --- a/packages/service-library/src/servicelib/logging_utils.py +++ b/packages/service-library/src/servicelib/logging_utils.py @@ -17,7 +17,8 @@ from pprint import pformat from typing import Any, TypeAlias, TypedDict, TypeVar -from .error_codes import ErrorCodeStr +from models_library.error_codes import ErrorCodeStr + from .utils_secrets import mask_sensitive_data _logger = logging.getLogger(__name__) diff --git a/packages/service-library/tests/aiohttp/test_rest_middlewares.py b/packages/service-library/tests/aiohttp/test_rest_middlewares.py index e70b6963b43..76fb8dc7c2b 100644 --- a/packages/service-library/tests/aiohttp/test_rest_middlewares.py +++ b/packages/service-library/tests/aiohttp/test_rest_middlewares.py @@ -13,6 +13,7 @@ import pytest from aiohttp import web from aiohttp.test_utils import TestClient +from models_library.error_codes import parse_error_code from models_library.utils.json_serialization import json_dumps from servicelib.aiohttp import status from servicelib.aiohttp.rest_middlewares import ( @@ -21,7 +22,6 @@ error_middleware_factory, ) from servicelib.aiohttp.rest_responses import is_enveloped, unwrap_envelope -from servicelib.error_codes import parse_error_code @dataclass diff --git a/packages/service-library/tests/test_logging_utils.py b/packages/service-library/tests/test_logging_utils.py index 90ed5367d2f..119611a32b1 100644 --- a/packages/service-library/tests/test_logging_utils.py +++ b/packages/service-library/tests/test_logging_utils.py @@ -6,8 +6,8 @@ import pytest from faker import Faker +from models_library.error_codes import create_error_code from models_library.errors_classes import OsparcErrorMixin -from servicelib.error_codes import create_error_code from servicelib.logging_utils import ( LogExtra, LogLevelInt, diff --git a/services/api-server/src/simcore_service_api_server/exceptions/handlers/_handlers_factory.py b/services/api-server/src/simcore_service_api_server/exceptions/handlers/_handlers_factory.py index fb9ae8ddc10..5a9e5a6e59a 100644 --- a/services/api-server/src/simcore_service_api_server/exceptions/handlers/_handlers_factory.py +++ b/services/api-server/src/simcore_service_api_server/exceptions/handlers/_handlers_factory.py @@ -2,7 +2,7 @@ from fastapi.requests import Request from fastapi.responses import JSONResponse -from servicelib.error_codes import create_error_code +from models_library.error_codes import create_error_code from ._utils import ExceptionHandler, create_error_json_response diff --git a/services/api-server/src/simcore_service_api_server/services/log_streaming.py b/services/api-server/src/simcore_service_api_server/services/log_streaming.py index faefc5c905b..2222ea488f7 100644 --- a/services/api-server/src/simcore_service_api_server/services/log_streaming.py +++ b/services/api-server/src/simcore_service_api_server/services/log_streaming.py @@ -4,10 +4,10 @@ from collections.abc import AsyncIterable from typing import Final +from models_library.error_codes import create_error_code from models_library.rabbitmq_messages import LoggerRabbitMessage from models_library.users import UserID from pydantic import NonNegativeInt -from servicelib.error_codes import create_error_code from servicelib.logging_utils import log_catch from servicelib.rabbitmq import RabbitMQClient from simcore_service_api_server.exceptions.backend_errors import BaseBackEndError diff --git a/services/director-v2/src/simcore_service_director_v2/models/dynamic_services_scheduler.py b/services/director-v2/src/simcore_service_director_v2/models/dynamic_services_scheduler.py index 3427a2bc525..3f112860fb4 100644 --- a/services/director-v2/src/simcore_service_director_v2/models/dynamic_services_scheduler.py +++ b/services/director-v2/src/simcore_service_director_v2/models/dynamic_services_scheduler.py @@ -16,6 +16,7 @@ ) from models_library.basic_types import PortInt from models_library.callbacks_mapping import CallbacksMapping +from models_library.error_codes import ErrorCodeStr from models_library.generated_models.docker_rest_api import ContainerState, Status2 from models_library.projects_nodes_io import NodeID from models_library.resource_tracker import HardwareInfo, PricingInfo @@ -36,7 +37,6 @@ parse_obj_as, validator, ) -from servicelib.error_codes import ErrorCodeStr from servicelib.exception_utils import DelayedExceptionHandler from ..constants import ( diff --git a/services/director-v2/src/simcore_service_director_v2/modules/dynamic_sidecar/scheduler/_core/_observer.py b/services/director-v2/src/simcore_service_director_v2/modules/dynamic_sidecar/scheduler/_core/_observer.py index 7cd402784d3..afc5663f880 100644 --- a/services/director-v2/src/simcore_service_director_v2/modules/dynamic_sidecar/scheduler/_core/_observer.py +++ b/services/director-v2/src/simcore_service_director_v2/modules/dynamic_sidecar/scheduler/_core/_observer.py @@ -6,7 +6,7 @@ from math import floor from fastapi import FastAPI -from servicelib.error_codes import create_error_code +from models_library.error_codes import create_error_code from .....core.dynamic_services_settings.scheduler import ( DynamicServicesSchedulerSettings, diff --git a/services/dynamic-sidecar/src/simcore_service_dynamic_sidecar/core/utils.py b/services/dynamic-sidecar/src/simcore_service_dynamic_sidecar/core/utils.py index eee821145c1..b776eea90fe 100644 --- a/services/dynamic-sidecar/src/simcore_service_dynamic_sidecar/core/utils.py +++ b/services/dynamic-sidecar/src/simcore_service_dynamic_sidecar/core/utils.py @@ -7,7 +7,7 @@ from typing import NamedTuple import psutil -from servicelib.error_codes import create_error_code +from models_library.error_codes import create_error_code from ..modules.mounted_fs import MountedVolumes diff --git a/services/web/server/src/simcore_service_webserver/invitations/_core.py b/services/web/server/src/simcore_service_webserver/invitations/_core.py index b834ac55b26..522785551a1 100644 --- a/services/web/server/src/simcore_service_webserver/invitations/_core.py +++ b/services/web/server/src/simcore_service_webserver/invitations/_core.py @@ -9,9 +9,9 @@ ApiInvitationInputs, ) from models_library.emails import LowerCaseEmailStr +from models_library.error_codes import create_error_code from pydantic import AnyHttpUrl, ValidationError, parse_obj_as from servicelib.aiohttp import status -from servicelib.error_codes import create_error_code from ..groups.api import is_user_by_email_in_group from ..products.api import Product diff --git a/services/web/server/src/simcore_service_webserver/login/_2fa_api.py b/services/web/server/src/simcore_service_webserver/login/_2fa_api.py index 06a96f00e6d..015239c8e38 100644 --- a/services/web/server/src/simcore_service_webserver/login/_2fa_api.py +++ b/services/web/server/src/simcore_service_webserver/login/_2fa_api.py @@ -11,9 +11,9 @@ import logging from aiohttp import web +from models_library.error_codes import create_error_code from models_library.users import UserID from pydantic import BaseModel, Field -from servicelib.error_codes import create_error_code from servicelib.logging_utils import LogExtra, get_log_record_extra, log_decorator from servicelib.utils_secrets import generate_passcode from settings_library.twilio import TwilioSettings diff --git a/services/web/server/src/simcore_service_webserver/login/handlers_confirmation.py b/services/web/server/src/simcore_service_webserver/login/handlers_confirmation.py index ecb99ce84e7..3f5f6de3eef 100644 --- a/services/web/server/src/simcore_service_webserver/login/handlers_confirmation.py +++ b/services/web/server/src/simcore_service_webserver/login/handlers_confirmation.py @@ -5,6 +5,7 @@ from aiohttp import web from aiohttp.web import RouteTableDef from models_library.emails import LowerCaseEmailStr +from models_library.error_codes import create_error_code from models_library.products import ProductName from pydantic import ( BaseModel, @@ -20,7 +21,6 @@ parse_request_body_as, parse_request_path_parameters_as, ) -from servicelib.error_codes import create_error_code from servicelib.mimetype_constants import MIMETYPE_APPLICATION_JSON from simcore_postgres_database.errors import UniqueViolation from yarl import URL diff --git a/services/web/server/src/simcore_service_webserver/login/handlers_registration.py b/services/web/server/src/simcore_service_webserver/login/handlers_registration.py index d3f553db71c..196081b073f 100644 --- a/services/web/server/src/simcore_service_webserver/login/handlers_registration.py +++ b/services/web/server/src/simcore_service_webserver/login/handlers_registration.py @@ -5,10 +5,10 @@ from aiohttp import web from aiohttp.web import RouteTableDef from models_library.emails import LowerCaseEmailStr +from models_library.error_codes import create_error_code from pydantic import BaseModel, Field, PositiveInt, SecretStr, validator from servicelib.aiohttp import status from servicelib.aiohttp.requests_validation import parse_request_body_as -from servicelib.error_codes import create_error_code from servicelib.mimetype_constants import MIMETYPE_APPLICATION_JSON from simcore_postgres_database.models.users import UserStatus diff --git a/services/web/server/src/simcore_service_webserver/studies_dispatcher/_redirects_handlers.py b/services/web/server/src/simcore_service_webserver/studies_dispatcher/_redirects_handlers.py index 1b60fd5f7e0..3ed129bb96b 100644 --- a/services/web/server/src/simcore_service_webserver/studies_dispatcher/_redirects_handlers.py +++ b/services/web/server/src/simcore_service_webserver/studies_dispatcher/_redirects_handlers.py @@ -8,6 +8,7 @@ from typing import TypeAlias from aiohttp import web +from models_library.error_codes import create_error_code from models_library.projects import ProjectID from models_library.projects_nodes_io import NodeID from models_library.services import ServiceKey, ServiceVersion @@ -15,7 +16,6 @@ from servicelib.aiohttp import status from servicelib.aiohttp.requests_validation import parse_request_query_parameters_as from servicelib.aiohttp.typing_extension import Handler -from servicelib.error_codes import create_error_code from ..director_v2.api import update_dynamic_service_networks_in_project from ..products.api import get_product_name diff --git a/services/web/server/src/simcore_service_webserver/studies_dispatcher/_studies_access.py b/services/web/server/src/simcore_service_webserver/studies_dispatcher/_studies_access.py index 9545675d7ec..202bc6ee50a 100644 --- a/services/web/server/src/simcore_service_webserver/studies_dispatcher/_studies_access.py +++ b/services/web/server/src/simcore_service_webserver/studies_dispatcher/_studies_access.py @@ -20,10 +20,10 @@ from aiohttp import web from aiohttp_session import get_session +from models_library.error_codes import create_error_code from models_library.projects import ProjectID from servicelib.aiohttp import status from servicelib.aiohttp.typing_extension import Handler -from servicelib.error_codes import create_error_code from .._constants import INDEX_RESOURCE_NAME from ..director_v2._core_computations import create_or_update_pipeline diff --git a/services/web/server/src/simcore_service_webserver/users/_handlers.py b/services/web/server/src/simcore_service_webserver/users/_handlers.py index a8516095e57..6798c144f38 100644 --- a/services/web/server/src/simcore_service_webserver/users/_handlers.py +++ b/services/web/server/src/simcore_service_webserver/users/_handlers.py @@ -2,6 +2,7 @@ import logging from aiohttp import web +from models_library.error_codes import create_error_code from models_library.users import UserID from pydantic import BaseModel, Field from servicelib.aiohttp.requests_validation import ( @@ -9,7 +10,6 @@ parse_request_query_parameters_as, ) from servicelib.aiohttp.typing_extension import Handler -from servicelib.error_codes import create_error_code from servicelib.logging_utils import ( create_troubleshotting_log_message, get_log_record_extra, diff --git a/services/web/server/src/simcore_service_webserver/utils.py b/services/web/server/src/simcore_service_webserver/utils.py index d9ff8b9fcda..6e7e7fced67 100644 --- a/services/web/server/src/simcore_service_webserver/utils.py +++ b/services/web/server/src/simcore_service_webserver/utils.py @@ -14,7 +14,7 @@ import orjson from models_library.basic_types import SHA1Str -from servicelib.error_codes import ErrorCodeStr +from models_library.error_codes import ErrorCodeStr _CURRENT_DIR = ( Path(sys.argv[0] if __name__ == "__main__" else __file__).resolve().parent diff --git a/services/web/server/src/simcore_service_webserver/wallets/_handlers.py b/services/web/server/src/simcore_service_webserver/wallets/_handlers.py index e7c67919f10..8e9215aa7af 100644 --- a/services/web/server/src/simcore_service_webserver/wallets/_handlers.py +++ b/services/web/server/src/simcore_service_webserver/wallets/_handlers.py @@ -8,6 +8,7 @@ WalletGet, WalletGetWithAvailableCredits, ) +from models_library.error_codes import create_error_code from models_library.users import UserID from models_library.wallets import WalletID from pydantic import Field @@ -18,7 +19,6 @@ parse_request_path_parameters_as, ) from servicelib.aiohttp.typing_extension import Handler -from servicelib.error_codes import create_error_code from servicelib.logging_utils import LogExtra, get_log_record_extra from servicelib.request_keys import RQT_USERID_KEY From 25972ca1067a90a2532d264090574111cedd2ee2 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Mon, 14 Oct 2024 21:15:14 +0200 Subject: [PATCH 02/24] errors in erro classes --- .../models-library/src/models_library/errors_classes.py | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/packages/models-library/src/models_library/errors_classes.py b/packages/models-library/src/models_library/errors_classes.py index 259c165bd50..921db49df3c 100644 --- a/packages/models-library/src/models_library/errors_classes.py +++ b/packages/models-library/src/models_library/errors_classes.py @@ -1,5 +1,7 @@ from pydantic.errors import PydanticErrorMixin +from .error_codes import create_error_code + class _DefaultDict(dict): def __missing__(self, key): @@ -34,3 +36,7 @@ def _get_full_class_name(cls) -> str: def error_context(self): """Returns context in which error occurred and stored within the exception""" return dict(**self.__dict__) + + def error_code(self) -> str: + assert isinstance(self, Exception), "subclass must be exception" # nosec + return create_error_code(self) From d05251af8e1f60443d122d160546c063d4ba882c Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Mon, 14 Oct 2024 21:15:37 +0200 Subject: [PATCH 03/24] tests --- .../servicelib/aiohttp/rest_middlewares.py | 2 +- .../src/servicelib/logging_errors.py | 68 +++++++++++++++++++ .../src/servicelib/logging_utils.py | 31 --------- .../tests/test_logging_errors.py | 48 +++++++++++++ .../tests/test_logging_utils.py | 43 ------------ .../users/_handlers.py | 6 +- 6 files changed, 119 insertions(+), 79 deletions(-) create mode 100644 packages/service-library/src/servicelib/logging_errors.py create mode 100644 packages/service-library/tests/test_logging_errors.py diff --git a/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py b/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py index f34f8990fa8..5026acf8b18 100644 --- a/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py +++ b/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py @@ -16,7 +16,7 @@ from models_library.errors_classes import OsparcErrorMixin from models_library.utils.json_serialization import json_dumps -from ..logging_utils import create_troubleshotting_log_message, get_log_record_extra +from ..logging_errors import create_troubleshotting_log_message, get_log_record_extra from ..mimetype_constants import MIMETYPE_APPLICATION_JSON from ..utils import is_production_environ from .rest_models import ErrorItemType, ErrorType, LogMessageType diff --git a/packages/service-library/src/servicelib/logging_errors.py b/packages/service-library/src/servicelib/logging_errors.py new file mode 100644 index 00000000000..68cded53f51 --- /dev/null +++ b/packages/service-library/src/servicelib/logging_errors.py @@ -0,0 +1,68 @@ +import logging +from pprint import pformat +from typing import Any + +from models_library.error_codes import ErrorCodeStr, create_error_code +from models_library.errors_classes import OsparcErrorMixin + +from .logging_errors import get_log_record_extra + +_logger = logging.getLogger(__name__) + + +def create_troubleshotting_log_message( + message_to_user: str, + error: BaseException, + error_code: ErrorCodeStr, + error_context: dict[str, Any] | None = None, + tip: str | None = None, +) -> str: + """Create a formatted message for _logger.exception(...) + + Arguments: + message_to_user -- A user-friendly message to be displayed on the front-end explaining the issue in simple terms. + error -- the instance of the handled exception + error_code -- A unique error code (e.g., OEC or osparc-specific) to identify the type or source of the error for easier tracking. + error_context -- Additional context surrounding the exception, such as environment variables or function-specific data. This can be derived from exc.error_context() (relevant when using the OsparcErrorMixin) + tip -- Helpful suggestions or possible solutions explaining why the error may have occurred and how it could potentially be resolved + """ + debug_data = pformat( + { + "exception_details": f"{error}", + "error_code": error_code, + "context": pformat(error_context, indent=1), + "tip": tip, + }, + indent=1, + ) + + return f"{message_to_user}.\n{debug_data}" + + +def create_troubleshotting_log_kwargs( + message_to_user: str, + exception: BaseException, + error_context: dict[str, Any] | None = None, + tip: str | None = None, +): + error_code = create_error_code(exception) + + context = error_context or {} + if isinstance(exception, OsparcErrorMixin): + context.update(exception.error_context()) + + log_msg = create_troubleshotting_log_message( + message_to_user=message_to_user, + error=exception, + error_code=error_code, + error_context=context, + tip=tip, + ) + + return { + "msg": log_msg, + "extra": get_log_record_extra( + error_code=error_code, + user_id=context.get("user_id", None), + ), + } diff --git a/packages/service-library/src/servicelib/logging_utils.py b/packages/service-library/src/servicelib/logging_utils.py index 909e8bc29e3..fbaba59fd30 100644 --- a/packages/service-library/src/servicelib/logging_utils.py +++ b/packages/service-library/src/servicelib/logging_utils.py @@ -17,8 +17,6 @@ from pprint import pformat from typing import Any, TypeAlias, TypedDict, TypeVar -from models_library.error_codes import ErrorCodeStr - from .utils_secrets import mask_sensitive_data _logger = logging.getLogger(__name__) @@ -346,35 +344,6 @@ def get_log_record_extra( return extra or None -def create_troubleshotting_log_message( - message_to_user: str, - error: BaseException | None, - error_code: ErrorCodeStr, - error_context: dict[str, Any] | None = None, - tip: str | None = None, -) -> str: - """Create a formatted message for _logger.exception(...) - - Arguments: - message_to_user -- A user-friendly message to be displayed on the front-end explaining the issue in simple terms. - error -- the instance of the handled exception - error_code -- A unique error code (e.g., OEC or osparc-specific) to identify the type or source of the error for easier tracking. - error_context -- Additional context surrounding the exception, such as environment variables or function-specific data. This can be derived from exc.error_context() (relevant when using the OsparcErrorMixin) - tip -- Helpful suggestions or possible solutions explaining why the error may have occurred and how it could potentially be resolved - """ - debug_data = pformat( - { - "exception_details": f"{error}", - "error_code": error_code, - "context": pformat(error_context, indent=1), - "tip": tip, - }, - indent=1, - ) - - return f"{message_to_user}.\n{debug_data}" - - def _un_capitalize(s: str) -> str: return s[:1].lower() + s[1:] if s else "" diff --git a/packages/service-library/tests/test_logging_errors.py b/packages/service-library/tests/test_logging_errors.py new file mode 100644 index 00000000000..eab66a3326a --- /dev/null +++ b/packages/service-library/tests/test_logging_errors.py @@ -0,0 +1,48 @@ +# pylint:disable=redefined-outer-name + +import logging + +import pytest +from models_library.error_codes import create_error_code +from models_library.errors_classes import OsparcErrorMixin +from servicelib.logging_errors import create_troubleshotting_log_message +from servicelib.logging_utils import get_log_record_extra + + +def test_create_troubleshotting_log_message(caplog: pytest.LogCaptureFixture): + class MyError(OsparcErrorMixin, RuntimeError): + msg_template = "My error {user_id}" + + with pytest.raises(MyError) as exc_info: + raise MyError(user_id=123, product_name="foo") + + exc = exc_info.value + error_code = create_error_code(exc) + log_msg = create_troubleshotting_log_message( + f"Nice message to user [{error_code}]", + exc, + error_code=error_code, + error_context=exc.error_context(), + tip="This is a test error", + ) + + with caplog.at_level(logging.WARNING): + root_logger = logging.getLogger() + root_logger.exception( + log_msg, extra=get_log_record_extra(error_code=error_code) + ) + + # ERROR root:test_logging_utils.py:417 Nice message to user [OEC:126055703573984]. + # { + # "exception_details": "My error 123", + # "error_code": "OEC:126055703573984", + # "context": { + # "user_id": 123, + # "product_name": "foo" + # }, + # "tip": "This is a test error" + # } + + assert error_code in caplog.text + assert "user_id" in caplog.text + assert "product_name" in caplog.text diff --git a/packages/service-library/tests/test_logging_utils.py b/packages/service-library/tests/test_logging_utils.py index 119611a32b1..abdfcd5411e 100644 --- a/packages/service-library/tests/test_logging_utils.py +++ b/packages/service-library/tests/test_logging_utils.py @@ -6,14 +6,10 @@ import pytest from faker import Faker -from models_library.error_codes import create_error_code -from models_library.errors_classes import OsparcErrorMixin from servicelib.logging_utils import ( LogExtra, LogLevelInt, LogMessageStr, - create_troubleshotting_log_message, - get_log_record_extra, guess_message_log_level, log_context, log_decorator, @@ -381,42 +377,3 @@ def test_set_parent_module_log_level_(caplog: pytest.LogCaptureFixture): assert "parent warning" in caplog.text assert "child warning" in caplog.text - - -def test_create_troubleshotting_log_message(caplog: pytest.LogCaptureFixture): - class MyError(OsparcErrorMixin, RuntimeError): - msg_template = "My error {user_id}" - - with pytest.raises(MyError) as exc_info: - raise MyError(user_id=123, product_name="foo") - - exc = exc_info.value - error_code = create_error_code(exc) - log_msg = create_troubleshotting_log_message( - f"Nice message to user [{error_code}]", - exc, - error_code=error_code, - error_context=exc.error_context(), - tip="This is a test error", - ) - - with caplog.at_level(logging.WARNING): - root_logger = logging.getLogger() - root_logger.exception( - log_msg, extra=get_log_record_extra(error_code=error_code) - ) - - # ERROR root:test_logging_utils.py:417 Nice message to user [OEC:126055703573984]. - # { - # "exception_details": "My error 123", - # "error_code": "OEC:126055703573984", - # "context": { - # "user_id": 123, - # "product_name": "foo" - # }, - # "tip": "This is a test error" - # } - - assert error_code in caplog.text - assert "user_id" in caplog.text - assert "product_name" in caplog.text diff --git a/services/web/server/src/simcore_service_webserver/users/_handlers.py b/services/web/server/src/simcore_service_webserver/users/_handlers.py index 6798c144f38..e8fe44c7920 100644 --- a/services/web/server/src/simcore_service_webserver/users/_handlers.py +++ b/services/web/server/src/simcore_service_webserver/users/_handlers.py @@ -10,10 +10,8 @@ parse_request_query_parameters_as, ) from servicelib.aiohttp.typing_extension import Handler -from servicelib.logging_utils import ( - create_troubleshotting_log_message, - get_log_record_extra, -) +from servicelib.logging_errors import create_troubleshotting_log_message +from servicelib.logging_utils import get_log_record_extra from servicelib.mimetype_constants import MIMETYPE_APPLICATION_JSON from servicelib.request_keys import RQT_USERID_KEY from servicelib.rest_constants import RESPONSE_MODEL_POLICY From f0c948116315f69fa626c96ab6fa1e7d1c373ef0 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 11:23:20 +0200 Subject: [PATCH 04/24] updates trobleshotting functions --- .../servicelib/aiohttp/rest_middlewares.py | 2 +- .../src/servicelib/logging_errors.py | 37 ++++++++++++++++--- .../tests/test_logging_errors.py | 20 +++++++++- .../users/_handlers.py | 25 ++++--------- 4 files changed, 58 insertions(+), 26 deletions(-) diff --git a/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py b/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py index 5026acf8b18..e776f0423ec 100644 --- a/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py +++ b/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py @@ -67,7 +67,7 @@ def _process_and_raise_unexpected_error(request: web.BaseRequest, err: Exception ) log_msg = create_troubleshotting_log_message( message_to_user=frontend_msg, - error=err, + exception=err, error_code=error_code, error_context=error_context, ) diff --git a/packages/service-library/src/servicelib/logging_errors.py b/packages/service-library/src/servicelib/logging_errors.py index 68cded53f51..dec31ee34ad 100644 --- a/packages/service-library/src/servicelib/logging_errors.py +++ b/packages/service-library/src/servicelib/logging_errors.py @@ -1,18 +1,18 @@ import logging from pprint import pformat -from typing import Any +from typing import Any, NotRequired, TypedDict from models_library.error_codes import ErrorCodeStr, create_error_code from models_library.errors_classes import OsparcErrorMixin -from .logging_errors import get_log_record_extra +from .logging_utils import LogExtra, get_log_record_extra _logger = logging.getLogger(__name__) def create_troubleshotting_log_message( message_to_user: str, - error: BaseException, + exception: BaseException, error_code: ErrorCodeStr, error_context: dict[str, Any] | None = None, tip: str | None = None, @@ -28,7 +28,7 @@ def create_troubleshotting_log_message( """ debug_data = pformat( { - "exception_details": f"{error}", + "exception_details": f"{exception}", "error_code": error_code, "context": pformat(error_context, indent=1), "tip": tip, @@ -39,21 +39,46 @@ def create_troubleshotting_log_message( return f"{message_to_user}.\n{debug_data}" +class LogKwargs(TypedDict): + msg: str + extra: NotRequired[LogExtra | None] + + def create_troubleshotting_log_kwargs( message_to_user: str, exception: BaseException, error_context: dict[str, Any] | None = None, tip: str | None = None, -): +) -> LogKwargs: + """ + Creates a dictionary of logging arguments to be used with _log.exception for troubleshooting purposes. + + Usage: + + try: + ... + except MyException as exc + _logger.exception( + **create_troubleshotting_log_kwargs( + message_to_user=frontend_msg, + exception=exc, + tip="Check row in `groups_extra_properties` for this product. It might be missing.", + ) + ) + + """ + # error-code error_code = create_error_code(exception) + # error-context context = error_context or {} if isinstance(exception, OsparcErrorMixin): context.update(exception.error_context()) + # aggregate log_msg = create_troubleshotting_log_message( message_to_user=message_to_user, - error=exception, + exception=exception, error_code=error_code, error_context=context, tip=tip, diff --git a/packages/service-library/tests/test_logging_errors.py b/packages/service-library/tests/test_logging_errors.py index eab66a3326a..89443c3f783 100644 --- a/packages/service-library/tests/test_logging_errors.py +++ b/packages/service-library/tests/test_logging_errors.py @@ -5,7 +5,10 @@ import pytest from models_library.error_codes import create_error_code from models_library.errors_classes import OsparcErrorMixin -from servicelib.logging_errors import create_troubleshotting_log_message +from servicelib.logging_errors import ( + create_troubleshotting_log_kwargs, + create_troubleshotting_log_message, +) from servicelib.logging_utils import get_log_record_extra @@ -18,14 +21,27 @@ class MyError(OsparcErrorMixin, RuntimeError): exc = exc_info.value error_code = create_error_code(exc) + + assert exc.error_code() == error_code + + msg = f"Nice message to user [{error_code}]" + log_msg = create_troubleshotting_log_message( - f"Nice message to user [{error_code}]", + msg, exc, error_code=error_code, error_context=exc.error_context(), tip="This is a test error", ) + log_kwargs = create_troubleshotting_log_kwargs( + msg, + exc, + tip="This is a test error", + ) + + assert log_kwargs["msg"] == log_msg + with caplog.at_level(logging.WARNING): root_logger = logging.getLogger() root_logger.exception( diff --git a/services/web/server/src/simcore_service_webserver/users/_handlers.py b/services/web/server/src/simcore_service_webserver/users/_handlers.py index e8fe44c7920..5aeb92fa260 100644 --- a/services/web/server/src/simcore_service_webserver/users/_handlers.py +++ b/services/web/server/src/simcore_service_webserver/users/_handlers.py @@ -2,7 +2,6 @@ import logging from aiohttp import web -from models_library.error_codes import create_error_code from models_library.users import UserID from pydantic import BaseModel, Field from servicelib.aiohttp.requests_validation import ( @@ -10,8 +9,7 @@ parse_request_query_parameters_as, ) from servicelib.aiohttp.typing_extension import Handler -from servicelib.logging_errors import create_troubleshotting_log_message -from servicelib.logging_utils import get_log_record_extra +from servicelib.logging_errors import create_troubleshotting_log_kwargs from servicelib.mimetype_constants import MIMETYPE_APPLICATION_JSON from servicelib.request_keys import RQT_USERID_KEY from servicelib.rest_constants import RESPONSE_MODEL_POLICY @@ -51,22 +49,15 @@ async def wrapper(request: web.Request) -> web.StreamResponse: except UserNotFoundError as exc: raise web.HTTPNotFound(reason=f"{exc}") from exc except MissingGroupExtraPropertiesForProductError as exc: - error_code = create_error_code(exc) - frontend_msg = FMSG_MISSING_CONFIG_WITH_OEC.format(error_code=error_code) - log_msg = create_troubleshotting_log_message( - message_to_user=frontend_msg, - error=exc, - error_code=error_code, - error_context=exc.error_context(), - tip="Row in `groups_extra_properties` for this product is missing.", + frontend_msg = FMSG_MISSING_CONFIG_WITH_OEC.format( + error_code=exc.error_code() ) - _logger.exception( - log_msg, - extra=get_log_record_extra( - error_code=error_code, - user_id=exc.error_context().get("user_id", None), - ), + **create_troubleshotting_log_kwargs( + message_to_user=frontend_msg, + exception=exc, + tip="Row in `groups_extra_properties` for this product is missing.", + ) ) raise web.HTTPServiceUnavailable(reason=frontend_msg) from exc From 9c5458296a9a7cbe7035a64539652b3693013ffa Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 11:28:52 +0200 Subject: [PATCH 05/24] simplified log kwargs --- .../servicelib/aiohttp/rest_middlewares.py | 22 +++++-------------- .../tests/test_logging_errors.py | 8 +++---- 2 files changed, 10 insertions(+), 20 deletions(-) diff --git a/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py b/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py index e776f0423ec..68dba13f3f9 100644 --- a/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py +++ b/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py @@ -13,10 +13,9 @@ from aiohttp.web_request import Request from aiohttp.web_response import StreamResponse from models_library.error_codes import create_error_code -from models_library.errors_classes import OsparcErrorMixin from models_library.utils.json_serialization import json_dumps -from ..logging_errors import create_troubleshotting_log_message, get_log_record_extra +from ..logging_errors import create_troubleshotting_log_kwargs from ..mimetype_constants import MIMETYPE_APPLICATION_JSON from ..utils import is_production_environ from .rest_models import ErrorItemType, ErrorType, LogMessageType @@ -59,19 +58,10 @@ def _process_and_raise_unexpected_error(request: web.BaseRequest, err: Exception "request.method": f"{request.method}", "request.path": f"{request.path}", } - if isinstance(err, OsparcErrorMixin): - error_context.update(err.error_context()) frontend_msg = _FMSG_INTERNAL_ERROR_USER_FRIENDLY_WITH_OEC.format( error_code=error_code ) - log_msg = create_troubleshotting_log_message( - message_to_user=frontend_msg, - exception=err, - error_code=error_code, - error_context=error_context, - ) - http_error = create_http_error( err, frontend_msg, @@ -79,11 +69,11 @@ def _process_and_raise_unexpected_error(request: web.BaseRequest, err: Exception skip_internal_error_details=_is_prod, ) _logger.exception( - log_msg, - extra=get_log_record_extra( - error_code=error_code, - user_id=error_context.get("user_id"), - ), + **create_troubleshotting_log_kwargs( + message_to_user=frontend_msg, + exception=err, + error_context=error_context, + ) ) raise http_error diff --git a/packages/service-library/tests/test_logging_errors.py b/packages/service-library/tests/test_logging_errors.py index 89443c3f783..0fbc23ae294 100644 --- a/packages/service-library/tests/test_logging_errors.py +++ b/packages/service-library/tests/test_logging_errors.py @@ -9,7 +9,6 @@ create_troubleshotting_log_kwargs, create_troubleshotting_log_message, ) -from servicelib.logging_utils import get_log_record_extra def test_create_troubleshotting_log_message(caplog: pytest.LogCaptureFixture): @@ -41,12 +40,13 @@ class MyError(OsparcErrorMixin, RuntimeError): ) assert log_kwargs["msg"] == log_msg + assert ( + log_kwargs["extra"]["log_uid"] == "123" + ), "user_id is injected as extra from context" with caplog.at_level(logging.WARNING): root_logger = logging.getLogger() - root_logger.exception( - log_msg, extra=get_log_record_extra(error_code=error_code) - ) + root_logger.exception(**log_kwargs) # ERROR root:test_logging_utils.py:417 Nice message to user [OEC:126055703573984]. # { From 61dc08047dad79af7b9004378ec537872149f87b Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 11:33:28 +0200 Subject: [PATCH 06/24] updates payments log --- .../services/notifier_email.py | 28 +++++++++---------- 1 file changed, 13 insertions(+), 15 deletions(-) diff --git a/services/payments/src/simcore_service_payments/services/notifier_email.py b/services/payments/src/simcore_service_payments/services/notifier_email.py index 53e9920990d..8c648000fcd 100644 --- a/services/payments/src/simcore_service_payments/services/notifier_email.py +++ b/services/payments/src/simcore_service_payments/services/notifier_email.py @@ -15,8 +15,7 @@ from models_library.products import ProductName from models_library.users import UserID from pydantic import EmailStr -from servicelib.error_codes import create_error_code -from servicelib.logging_utils import create_troubleshotting_log_message +from servicelib.logging_errors import create_troubleshotting_log_kwargs from settings_library.email import EmailProtocol, SMTPSettings from tenacity import ( retry, @@ -238,20 +237,19 @@ async def _create_user_email( subtype=sub_type, ) - except Exception as err: # pylint: disable=broad-exception-caught - error_code = create_error_code(err) - error_msg = create_troubleshotting_log_message( - "Cannot attach invoice to payment", - error=err, - error_code=error_code, - error_context={ - "user": user, - "payment": payment, - "product": product, - }, - tip=f"Check downloading: `wget -v {payment.invoice_pdf_url}`", + except Exception as exc: # pylint: disable=broad-exception-caught + _logger.exception( + **create_troubleshotting_log_kwargs( + "Cannot attach invoice to payment", + exception=exc, + error_context={ + "user": user, + "payment": payment, + "product": product, + }, + tip=f"Check downloading: `wget -v {payment.invoice_pdf_url}`", + ) ) - _logger.exception("%s", error_msg) return email_msg From 0c470e3801281c5a2df5aaf36f8899086c54ac83 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 11:39:44 +0200 Subject: [PATCH 07/24] adds type --- packages/service-library/src/servicelib/logging_errors.py | 1 + 1 file changed, 1 insertion(+) diff --git a/packages/service-library/src/servicelib/logging_errors.py b/packages/service-library/src/servicelib/logging_errors.py index dec31ee34ad..839a7352428 100644 --- a/packages/service-library/src/servicelib/logging_errors.py +++ b/packages/service-library/src/servicelib/logging_errors.py @@ -28,6 +28,7 @@ def create_troubleshotting_log_message( """ debug_data = pformat( { + "exception_type": f"{type(exception)}", "exception_details": f"{exception}", "error_code": error_code, "context": pformat(error_context, indent=1), From e43c5b8b017d1a03ed6118d8bc09f115c7f0efe7 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 11:40:02 +0200 Subject: [PATCH 08/24] adapts hander in api-server --- .../exceptions/handlers/_handlers_factory.py | 12 +++++++----- 1 file changed, 7 insertions(+), 5 deletions(-) diff --git a/services/api-server/src/simcore_service_api_server/exceptions/handlers/_handlers_factory.py b/services/api-server/src/simcore_service_api_server/exceptions/handlers/_handlers_factory.py index 5a9e5a6e59a..5240a2f9ee9 100644 --- a/services/api-server/src/simcore_service_api_server/exceptions/handlers/_handlers_factory.py +++ b/services/api-server/src/simcore_service_api_server/exceptions/handlers/_handlers_factory.py @@ -3,6 +3,7 @@ from fastapi.requests import Request from fastapi.responses import JSONResponse from models_library.error_codes import create_error_code +from servicelib.logging_errors import create_troubleshotting_log_kwargs from ._utils import ExceptionHandler, create_error_json_response @@ -37,12 +38,13 @@ async def _http_error_handler( if add_oec_to_message: error_code = create_error_code(exception) msg += f" [{error_code}]" - _logger.exception( - "Unexpected %s: %s", - exception.__class__.__name__, - msg, - extra={"error_code": error_code}, + + _logger.exception( + **create_troubleshotting_log_kwargs( + f"Unexpected {exception.__class__.__name__}: {msg}", + exception=exception, ) + ) return create_error_json_response(msg, status_code=status_code) return _http_error_handler From 04eba2fc19130987efb1f981563e9dc6e69df8ca Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 11:48:03 +0200 Subject: [PATCH 09/24] adapts hander in api-server --- .../services/log_streaming.py | 21 +++++++++++-------- .../login/handlers_confirmation.py | 20 ++++++++++++------ 2 files changed, 26 insertions(+), 15 deletions(-) diff --git a/services/api-server/src/simcore_service_api_server/services/log_streaming.py b/services/api-server/src/simcore_service_api_server/services/log_streaming.py index 2222ea488f7..a9693459234 100644 --- a/services/api-server/src/simcore_service_api_server/services/log_streaming.py +++ b/services/api-server/src/simcore_service_api_server/services/log_streaming.py @@ -8,6 +8,7 @@ from models_library.rabbitmq_messages import LoggerRabbitMessage from models_library.users import UserID from pydantic import NonNegativeInt +from servicelib.logging_errors import create_troubleshotting_log_kwargs from servicelib.logging_utils import log_catch from servicelib.rabbitmq import RabbitMQClient from simcore_service_api_server.exceptions.backend_errors import BaseBackEndError @@ -124,21 +125,23 @@ async def log_generator(self) -> AsyncIterable[str]: yield log.json() + _NEW_LINE except asyncio.TimeoutError: done = await self._project_done() + except BaseBackEndError as exc: _logger.info("%s", f"{exc}") + yield ErrorGet(errors=[f"{exc}"]).json() + _NEW_LINE + except Exception as exc: # pylint: disable=W0718 error_code = create_error_code(exc) + error_msg = MSG_INTERNAL_ERROR_USER_FRIENDLY_TEMPLATE + f" [{error_code}]" + _logger.exception( - "Unexpected %s: %s", - exc.__class__.__name__, - f"{exc}", - extra={"error_code": error_code}, + **create_troubleshotting_log_kwargs( + error_msg, + exception=exc, + ) ) - yield ErrorGet( - errors=[ - MSG_INTERNAL_ERROR_USER_FRIENDLY_TEMPLATE + f" (OEC: {error_code})" - ] - ).json() + _NEW_LINE + yield ErrorGet(errors=[error_msg]).json() + _NEW_LINE + finally: await self._log_distributor.deregister(self._job_id) diff --git a/services/web/server/src/simcore_service_webserver/login/handlers_confirmation.py b/services/web/server/src/simcore_service_webserver/login/handlers_confirmation.py index 3f5f6de3eef..985c5314ec8 100644 --- a/services/web/server/src/simcore_service_webserver/login/handlers_confirmation.py +++ b/services/web/server/src/simcore_service_webserver/login/handlers_confirmation.py @@ -21,6 +21,7 @@ parse_request_body_as, parse_request_path_parameters_as, ) +from servicelib.logging_errors import create_troubleshotting_log_kwargs from servicelib.mimetype_constants import MIMETYPE_APPLICATION_JSON from simcore_postgres_database.errors import UniqueViolation from yarl import URL @@ -179,17 +180,24 @@ async def validate_confirmation_and_redirect(request: web.Request): except Exception as err: # pylint: disable=broad-except error_code = create_error_code(err) + front_end_msg = ( + f"Sorry, we cannot confirm your {action}." + "Please try again in a few moments. " + f"If the problem persist please contact support attaching this code ({error_code})" + ) + _logger.exception( - "Failed during email_confirmation [%s]", - f"{error_code}", - extra={"error_code": error_code}, + **create_troubleshotting_log_kwargs( + front_end_msg, + exception=err, + tip="Failed during email_confirmation", + ) ) + raise create_redirect_to_page_response( request.app, page="error", - message=f"Sorry, we cannot confirm your {action}." - "Please try again in a few moments. " - "If the problem persist please contact support attaching this code ({error_code})", + message=front_end_msg, status_code=status.HTTP_503_SERVICE_UNAVAILABLE, ) from err From 9a723d73f85ae91d8b5c99c4e2103972fbe01c74 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 15:49:21 +0200 Subject: [PATCH 10/24] raises verification errors and logs them in handler --- .../login/_2fa_api.py | 34 +++++++------------ .../simcore_service_webserver/login/errors.py | 12 ++++++- 2 files changed, 24 insertions(+), 22 deletions(-) diff --git a/services/web/server/src/simcore_service_webserver/login/_2fa_api.py b/services/web/server/src/simcore_service_webserver/login/_2fa_api.py index 015239c8e38..fc844dd79f6 100644 --- a/services/web/server/src/simcore_service_webserver/login/_2fa_api.py +++ b/services/web/server/src/simcore_service_webserver/login/_2fa_api.py @@ -11,10 +11,9 @@ import logging from aiohttp import web -from models_library.error_codes import create_error_code from models_library.users import UserID from pydantic import BaseModel, Field -from servicelib.logging_utils import LogExtra, get_log_record_extra, log_decorator +from servicelib.logging_utils import log_decorator from servicelib.utils_secrets import generate_passcode from settings_library.twilio import TwilioSettings from twilio.base.exceptions import TwilioException # type: ignore[import-untyped] @@ -132,15 +131,11 @@ def _sender(): await asyncio.get_event_loop().run_in_executor(executor=None, func=_sender) except TwilioException as exc: - error_code = create_error_code(exc) - log_extra: LogExtra = get_log_record_extra(user_id=user_id) or {} - log.exception( - "Failed while setting up 2FA code and sending SMS to %s [%s]", - mask_phone_number(phone_number), - f"{error_code}", - extra={"error_code": error_code, **log_extra}, - ) - raise SendingVerificationSmsError(reason=exc) from exc + raise SendingVerificationSmsError( + reason=f"Could not send SMS to {mask_phone_number(phone_number)}", + user_id=user_id, + twilio_error=exc, + ) from exc # @@ -177,16 +172,13 @@ async def send_email_code( "product": product, }, ) - except TwilioException as exc: - error_code = create_error_code(exc) - log_extra: LogExtra = get_log_record_extra(user_id=user_id) or {} - log.exception( - "Failed while setting up 2FA code and sending Email to %s [%s]", - user_email, - f"{error_code}", - extra={"error_code": error_code, **log_extra}, - ) - raise SendingVerificationEmailError(reason=exc) from exc + except Exception as exc: + raise SendingVerificationEmailError( + reason=f"Could not send email to {user_email}", + user_id=user_id, + user_email=user_email, + email_error=exc, + ) from exc # diff --git a/services/web/server/src/simcore_service_webserver/login/errors.py b/services/web/server/src/simcore_service_webserver/login/errors.py index e0b34c7787a..0c0060d99ed 100644 --- a/services/web/server/src/simcore_service_webserver/login/errors.py +++ b/services/web/server/src/simcore_service_webserver/login/errors.py @@ -1,12 +1,16 @@ import functools +import logging from aiohttp import web from servicelib.aiohttp.typing_extension import Handler +from servicelib.logging_errors import create_troubleshotting_log_kwargs from servicelib.mimetype_constants import MIMETYPE_APPLICATION_JSON from ..errors import WebServerBaseError from ._constants import MSG_2FA_UNAVAILABLE_OEC +_logger = logging.getLogger(__name__) + class LoginError(WebServerBaseError, ValueError): ... @@ -27,8 +31,14 @@ async def wrapper(request: web.Request) -> web.StreamResponse: return await handler(request) except (SendingVerificationSmsError, SendingVerificationEmailError) as exc: + + front_end_msg = MSG_2FA_UNAVAILABLE_OEC.format(error_code=exc.error_code()) + # in these cases I want to log the cause + _logger.exception( + **create_troubleshotting_log_kwargs(front_end_msg, exception=exc) + ) raise web.HTTPServiceUnavailable( - reason=MSG_2FA_UNAVAILABLE_OEC.format(error_code=exc.code), + reason=front_end_msg, content_type=MIMETYPE_APPLICATION_JSON, ) from exc From c7ada73eded95e74897132d22c28ebfa602ec81c Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 16:01:00 +0200 Subject: [PATCH 11/24] error in directorv2 --- .../scheduler/_core/_observer.py | 23 ++++++++++++++----- 1 file changed, 17 insertions(+), 6 deletions(-) diff --git a/services/director-v2/src/simcore_service_director_v2/modules/dynamic_sidecar/scheduler/_core/_observer.py b/services/director-v2/src/simcore_service_director_v2/modules/dynamic_sidecar/scheduler/_core/_observer.py index afc5663f880..913ecb71bf4 100644 --- a/services/director-v2/src/simcore_service_director_v2/modules/dynamic_sidecar/scheduler/_core/_observer.py +++ b/services/director-v2/src/simcore_service_director_v2/modules/dynamic_sidecar/scheduler/_core/_observer.py @@ -7,6 +7,7 @@ from fastapi import FastAPI from models_library.error_codes import create_error_code +from servicelib.logging_errors import create_troubleshotting_log_kwargs from .....core.dynamic_services_settings.scheduler import ( DynamicServicesSchedulerSettings, @@ -144,17 +145,27 @@ async def observing_single_service( # With unhandled errors, let's generate and ID and send it to the end-user # so that we can trace the logs and debug the issue. + front_end_msg = ( + f"This service ({service_name}) unexpectedly failed." + " Our team has recorded the issue and is working to resolve it as quickly as possible." + " Thank you for your patience." + ) - error_code = create_error_code(e) logger.exception( - "Observation of %s unexpectedly failed [%s]", - f"{service_name=} ", - f"{error_code}", - extra={"error_code": error_code}, + **create_troubleshotting_log_kwargs( + front_end_msg, + exception=e, + error_context={ + "service_name": service_name, + "user_id": scheduler_data.user_id, + }, + tip=f"Observation of {service_name=} unexpectedly failed", + ) ) + error_code = create_error_code(e) scheduler_data.dynamic_sidecar.status.update_failing_status( # This message must be human-friendly - f"Upss! This service ({service_name}) unexpectedly failed", + front_end_msg, error_code, ) finally: From 3d868b7fc115856cb4ab9c6ff2345f74c15743e4 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 16:05:12 +0200 Subject: [PATCH 12/24] error in dy-sidecar --- .../simcore_service_dynamic_sidecar/core/utils.py | 15 ++++++++++----- 1 file changed, 10 insertions(+), 5 deletions(-) diff --git a/services/dynamic-sidecar/src/simcore_service_dynamic_sidecar/core/utils.py b/services/dynamic-sidecar/src/simcore_service_dynamic_sidecar/core/utils.py index b776eea90fe..5fa0dce1a19 100644 --- a/services/dynamic-sidecar/src/simcore_service_dynamic_sidecar/core/utils.py +++ b/services/dynamic-sidecar/src/simcore_service_dynamic_sidecar/core/utils.py @@ -8,6 +8,7 @@ import psutil from models_library.error_codes import create_error_code +from servicelib.logging_errors import create_troubleshotting_log_kwargs from ..modules.mounted_fs import MountedVolumes @@ -105,17 +106,21 @@ async def async_command( ) except Exception as err: # pylint: disable=broad-except + error_code = create_error_code(err) + error_msg = f"Unexpected error [{error_code}]" _logger.exception( - "Process with %s failed unexpectedly [%s]", - f"{command=!r}", - f"{error_code}", - extra={"error_code": error_code}, + **create_troubleshotting_log_kwargs( + error_msg, + exception=err, + error_context={"command": command, "proc.returncode": proc.returncode}, + tip="Process with command failed unexpectily", + ) ) return CommandResult( success=False, - message=f"Unexpected error [{error_code}]", + message=error_msg, command=f"{command}", elapsed=time.time() - start, ) From fafb72e80964695920e56eaa994eb83e972dba24 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 16:35:52 +0200 Subject: [PATCH 13/24] updates invitations logs --- .../invitations/_core.py | 30 +++++++++--------- .../invitations/errors.py | 7 ++--- .../login/_registration.py | 31 ++++++++++++++++--- 3 files changed, 42 insertions(+), 26 deletions(-) diff --git a/services/web/server/src/simcore_service_webserver/invitations/_core.py b/services/web/server/src/simcore_service_webserver/invitations/_core.py index 522785551a1..2bf18487638 100644 --- a/services/web/server/src/simcore_service_webserver/invitations/_core.py +++ b/services/web/server/src/simcore_service_webserver/invitations/_core.py @@ -2,14 +2,13 @@ from contextlib import contextmanager from typing import Final -from aiohttp import ClientError, ClientResponseError, web +from aiohttp import ClientResponseError, web from models_library.api_schemas_invitations.invitations import ( ApiInvitationContent, ApiInvitationContentAndLink, ApiInvitationInputs, ) from models_library.emails import LowerCaseEmailStr -from models_library.error_codes import create_error_code from pydantic import AnyHttpUrl, ValidationError, parse_obj_as from servicelib.aiohttp import status @@ -35,31 +34,30 @@ def _handle_exceptions_as_invitations_errors(): except ClientResponseError as err: # check possible errors if err.status == status.HTTP_422_UNPROCESSABLE_ENTITY: - error_code = create_error_code(err) - _logger.exception( - "Invitation request unexpectedly failed [%s]", - f"{error_code}", - extra={"error_code": error_code}, - ) raise InvalidInvitationError( - reason=f"Unexpected error [{error_code}]" + invitations_api_response={ + "err": err, + "status": err.status, + "message": err.message, + "url": err.request_info.real_url, + }, ) from err assert err.status >= status.HTTP_400_BAD_REQUEST # nosec - # any other error status code - raise InvitationsServiceUnavailableError from err - except (ValidationError, ClientError) as err: - _logger.debug("Invitations error %s", f"{err}") - raise InvitationsServiceUnavailableError from err + # any other error status code + raise InvitationsServiceUnavailableError( + client_response_error=err, + ) from err except InvitationsError: # bypass: prevents that the Exceptions handler catches this exception raise except Exception as err: - _logger.exception("Unexpected error in invitations plugin") - raise InvitationsServiceUnavailableError from err + raise InvitationsServiceUnavailableError( + unexpected_error=err, + ) from err # diff --git a/services/web/server/src/simcore_service_webserver/invitations/errors.py b/services/web/server/src/simcore_service_webserver/invitations/errors.py index cde3e3ab5c7..881b62c6df9 100644 --- a/services/web/server/src/simcore_service_webserver/invitations/errors.py +++ b/services/web/server/src/simcore_service_webserver/invitations/errors.py @@ -14,11 +14,8 @@ class InvitationsError(WebServerBaseError, ValueError): class InvalidInvitationError(InvitationsError): - msg_template = "Invalid invitation. {reason}" + msg_template = "Invalid invitation" class InvitationsServiceUnavailableError(InvitationsError): - msg_template = ( - "Unable to process your invitation since the invitations service is currently unavailable. " - "Please try again later." - ) + msg_template = "Cannot process invitations" diff --git a/services/web/server/src/simcore_service_webserver/login/_registration.py b/services/web/server/src/simcore_service_webserver/login/_registration.py index 322dbb026c4..99ba498ad9c 100644 --- a/services/web/server/src/simcore_service_webserver/login/_registration.py +++ b/services/web/server/src/simcore_service_webserver/login/_registration.py @@ -12,6 +12,7 @@ from aiohttp import web from models_library.basic_types import IdInt from models_library.emails import LowerCaseEmailStr +from models_library.error_codes import create_error_code from models_library.products import ProductName from pydantic import ( BaseModel, @@ -22,6 +23,7 @@ parse_obj_as, validator, ) +from servicelib.logging_errors import create_troubleshotting_log_kwargs from servicelib.mimetype_constants import MIMETYPE_APPLICATION_JSON from simcore_postgres_database.models.confirmations import ConfirmationAction from simcore_postgres_database.models.users import UserStatus @@ -211,17 +213,36 @@ def _invitations_request_context(invitation_code: str) -> Iterator[URL]: yield url except (ValidationError, InvalidInvitationError) as err: - msg = f"{err}" - if isinstance(err, ValidationError): - msg = f"{InvalidInvitationError(reason='')}" + error_code = create_error_code(err) + front_end_msg = ( + f"Invalid invitation. {MSG_INVITATIONS_CONTACT_SUFFIX} [{error_code}]" + ) + + _logger.exception( + **create_troubleshotting_log_kwargs( + front_end_msg, + exception=err, + tip="Something went wrong with the invitation", + ) + ) raise web.HTTPForbidden( - reason=f"{msg}. {MSG_INVITATIONS_CONTACT_SUFFIX}", + reason=front_end_msg, content_type=MIMETYPE_APPLICATION_JSON, ) from err except InvitationsServiceUnavailableError as err: + error_code = create_error_code(err) + front_end_msg = f"Unable to process your invitation since the invitations service is currently unavailable [{error_code}]" + + _logger.exception( + **create_troubleshotting_log_kwargs( + front_end_msg, + exception=err, + tip="Something went wrong communicating the `invitations` service", + ) + ) raise web.HTTPServiceUnavailable( - reason=f"{err}", + reason=front_end_msg, content_type=MIMETYPE_APPLICATION_JSON, ) from err From 9ca32a49dd346c4f53194534547cd6fb4ef3521a Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 16:39:35 +0200 Subject: [PATCH 14/24] walets --- .../simcore_service_webserver/wallets/_handlers.py | 13 +++++-------- 1 file changed, 5 insertions(+), 8 deletions(-) diff --git a/services/web/server/src/simcore_service_webserver/wallets/_handlers.py b/services/web/server/src/simcore_service_webserver/wallets/_handlers.py index 8e9215aa7af..9835274cbb3 100644 --- a/services/web/server/src/simcore_service_webserver/wallets/_handlers.py +++ b/services/web/server/src/simcore_service_webserver/wallets/_handlers.py @@ -19,7 +19,7 @@ parse_request_path_parameters_as, ) from servicelib.aiohttp.typing_extension import Handler -from servicelib.logging_utils import LogExtra, get_log_record_extra +from servicelib.logging_errors import create_troubleshotting_log_kwargs from servicelib.request_keys import RQT_USERID_KEY from .._constants import RQ_PRODUCT_KEY @@ -89,17 +89,14 @@ async def wrapper(request: web.Request) -> web.StreamResponse: raise web.HTTPConflict(reason=MSG_PRICE_NOT_DEFINED_ERROR) from exc except BillingDetailsNotFoundError as exc: + error_code = create_error_code(exc) - log_extra: LogExtra = {} - if user_id := getattr(exc, "user_id", None): - log_extra = get_log_record_extra(user_id=user_id) or {} + user_msg = f"{MSG_BILLING_DETAILS_NOT_DEFINED_ERROR} [{error_code}]" - log_msg = f"{exc} [{error_code}]" _logger.exception( - log_msg, - extra={"error_code": error_code, **log_extra}, + **create_troubleshotting_log_kwargs(user_msg, exception=exc) ) - user_msg = f"{MSG_BILLING_DETAILS_NOT_DEFINED_ERROR} ({error_code})" + raise web.HTTPServiceUnavailable(reason=user_msg) from exc return wrapper From e3d77adbe433faf6658054603af5507d3a370b87 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 16:55:26 +0200 Subject: [PATCH 15/24] studies-access oec --- .../studies_dispatcher/_redirects_handlers.py | 18 ++++--- .../studies_dispatcher/_studies_access.py | 52 +++++++++++++------ 2 files changed, 48 insertions(+), 22 deletions(-) diff --git a/services/web/server/src/simcore_service_webserver/studies_dispatcher/_redirects_handlers.py b/services/web/server/src/simcore_service_webserver/studies_dispatcher/_redirects_handlers.py index 3ed129bb96b..6a2117e732d 100644 --- a/services/web/server/src/simcore_service_webserver/studies_dispatcher/_redirects_handlers.py +++ b/services/web/server/src/simcore_service_webserver/studies_dispatcher/_redirects_handlers.py @@ -16,6 +16,7 @@ from servicelib.aiohttp import status from servicelib.aiohttp.requests_validation import parse_request_query_parameters_as from servicelib.aiohttp.typing_extension import Handler +from servicelib.logging_errors import create_troubleshotting_log_kwargs from ..director_v2.api import update_dynamic_service_networks_in_project from ..products.api import get_product_name @@ -124,16 +125,21 @@ async def wrapper(request: web.Request) -> web.StreamResponse: except (ValidationError, web.HTTPServerError, Exception) as err: error_code = create_error_code(err) + + front_end_msg = compose_support_error_msg( + msg=MSG_UNEXPECTED_ERROR.format(hint=""), error_code=error_code + ) _logger.exception( - "Unexpected failure while dispatching study [%s]", - f"{error_code}", - extra={"error_code": error_code}, + **create_troubleshotting_log_kwargs( + front_end_msg, + exception=err, + error_context={"request": request}, + tip="Unexpected failure while dispatching study", + ) ) raise _create_redirect_response_to_error_page( request.app, - message=compose_support_error_msg( - msg=MSG_UNEXPECTED_ERROR.format(hint=""), error_code=error_code - ), + message=front_end_msg, status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, ) from err diff --git a/services/web/server/src/simcore_service_webserver/studies_dispatcher/_studies_access.py b/services/web/server/src/simcore_service_webserver/studies_dispatcher/_studies_access.py index 202bc6ee50a..fffe07d4adb 100644 --- a/services/web/server/src/simcore_service_webserver/studies_dispatcher/_studies_access.py +++ b/services/web/server/src/simcore_service_webserver/studies_dispatcher/_studies_access.py @@ -24,6 +24,7 @@ from models_library.projects import ProjectID from servicelib.aiohttp import status from servicelib.aiohttp.typing_extension import Handler +from servicelib.logging_errors import create_troubleshotting_log_kwargs from .._constants import INDEX_RESOURCE_NAME from ..director_v2._core_computations import create_or_update_pipeline @@ -258,17 +259,21 @@ async def wrapper(request: web.Request) -> web.StreamResponse: except Exception as err: error_code = create_error_code(err) + front_end_msg = compose_support_error_msg( + msg=MSG_UNEXPECTED_ERROR.format(hint=""), error_code=error_code + ) _logger.exception( - "Unexpected failure while dispatching study [%s]", - f"{error_code}", - extra={"error_code": error_code}, + **create_troubleshotting_log_kwargs( + front_end_msg, + exception=err, + tip="Unexpected failure while dispatching study", + ) ) + raise create_redirect_to_page_response( request.app, page="error", - message=compose_support_error_msg( - msg=MSG_UNEXPECTED_ERROR.format(hint=""), error_code=error_code - ), + message=front_end_msg, status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, ) from err @@ -327,13 +332,18 @@ async def get_redirection_to_study_page(request: web.Request) -> web.Response: # we cannot accept any more users. # error_code = create_error_code(exc) + + front_end_msg = MSG_TOO_MANY_GUESTS _logger.exception( - "Failed to create guest user. Responded with 429 Too Many Requests [%s]", - f"{error_code}", - extra={"error_code": error_code}, + **create_troubleshotting_log_kwargs( + front_end_msg, + exception=exc, + tip="Failed to create guest user. Responded with 429 Too Many Requests", + ) ) + raise RedirectToFrontEndPageError( - MSG_TOO_MANY_GUESTS, + front_end_msg, error_code=error_code, status_code=status.HTTP_429_TOO_MANY_REQUESTS, ) from exc @@ -353,15 +363,25 @@ async def get_redirection_to_study_page(request: web.Request) -> web.Response: except Exception as exc: # pylint: disable=broad-except error_code = create_error_code(exc) + + front_end_msg = MSG_UNEXPECTED_ERROR.format(hint="while copying your study") _logger.exception( - "Failed while copying project '%s' to '%s' [%s]", - template_project.get("name"), - user.get("email"), - f"{error_code}", - extra={"error_code": error_code}, + **create_troubleshotting_log_kwargs( + front_end_msg, + exception=exc, + error_context={ + "user_id": user.get("id"), + "user": dict(user), + "template_project": { + k: template_project.get(k) for k in ["name", "uuid"] + }, + }, + tip=f"Failed while copying project '{template_project.get('name')}' to '{user.get('email')}'", + ) ) + raise RedirectToFrontEndPageError( - MSG_UNEXPECTED_ERROR.format(hint="while copying your study"), + front_end_msg, error_code=error_code, status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, ) from exc From fb47d6309434a7f80839aa1f6b5e1060b5d2ea03 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 17:00:27 +0200 Subject: [PATCH 16/24] registration --- .../login/handlers_registration.py | 20 ++++++++++++------- 1 file changed, 13 insertions(+), 7 deletions(-) diff --git a/services/web/server/src/simcore_service_webserver/login/handlers_registration.py b/services/web/server/src/simcore_service_webserver/login/handlers_registration.py index 196081b073f..1fcf2a603d4 100644 --- a/services/web/server/src/simcore_service_webserver/login/handlers_registration.py +++ b/services/web/server/src/simcore_service_webserver/login/handlers_registration.py @@ -9,6 +9,7 @@ from pydantic import BaseModel, Field, PositiveInt, SecretStr, validator from servicelib.aiohttp import status from servicelib.aiohttp.requests_validation import parse_request_body_as +from servicelib.logging_errors import create_troubleshotting_log_kwargs from servicelib.mimetype_constants import MIMETYPE_APPLICATION_JSON from simcore_postgres_database.models.users import UserStatus @@ -58,7 +59,7 @@ ) from .utils_email import get_template_path, send_email_from_template -log = logging.getLogger(__name__) +_logger = logging.getLogger(__name__) routes = RouteTableDef() @@ -266,7 +267,7 @@ async def register(request: web.Request): ) except Exception as err: # pylint: disable=broad-except error_code = create_error_code(err) - log.exception( + _logger.exception( "Failed while sending confirmation email to %s, %s [%s]", f"{user=}", f"{_confirmation=}", @@ -400,13 +401,18 @@ async def register_phone(request: web.Request): except Exception as err: # pylint: disable=broad-except # Unhandled errors -> 503 error_code = create_error_code(err) - log.exception( - "Phone registration failed [%s]", - f"{error_code}", - extra={"error_code": error_code}, + user_msg = f"Currently we cannot register phone numbers [{error_code}]" + + _logger.exception( + **create_troubleshotting_log_kwargs( + user_msg, + exception=err, + error_context={"request": request, "registration": registration}, + tip="Phone registration failed", + ) ) raise web.HTTPServiceUnavailable( - reason=f"Currently we cannot register phone numbers ({error_code})", + reason=user_msg, content_type=MIMETYPE_APPLICATION_JSON, ) from err From 573c17b94e13ba2c5de354830fc8ebeb1bc24242 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 17:08:46 +0200 Subject: [PATCH 17/24] renaming --- .../servicelib/aiohttp/rest_middlewares.py | 4 +-- .../src/servicelib/logging_errors.py | 26 ++++++++-------- .../exceptions/handlers/_handlers_factory.py | 11 +++---- .../services/log_streaming.py | 10 +++--- .../scheduler/_core/_observer.py | 8 ++--- .../core/utils.py | 8 ++--- .../services/notifier_email.py | 2 +- .../login/_registration.py | 16 +++++----- .../simcore_service_webserver/login/errors.py | 2 +- .../login/handlers_confirmation.py | 8 ++--- .../login/handlers_registration.py | 31 ++++++++++++------- .../studies_dispatcher/_redirects_handlers.py | 8 ++--- .../studies_dispatcher/_studies_access.py | 24 +++++++------- .../users/_handlers.py | 4 +-- .../wallets/_handlers.py | 6 ++-- 15 files changed, 88 insertions(+), 80 deletions(-) diff --git a/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py b/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py index 68dba13f3f9..9352fde88cd 100644 --- a/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py +++ b/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py @@ -70,8 +70,8 @@ def _process_and_raise_unexpected_error(request: web.BaseRequest, err: Exception ) _logger.exception( **create_troubleshotting_log_kwargs( - message_to_user=frontend_msg, - exception=err, + error_user_msg=frontend_msg, + error=err, error_context=error_context, ) ) diff --git a/packages/service-library/src/servicelib/logging_errors.py b/packages/service-library/src/servicelib/logging_errors.py index 839a7352428..58e3ffd11b0 100644 --- a/packages/service-library/src/servicelib/logging_errors.py +++ b/packages/service-library/src/servicelib/logging_errors.py @@ -11,8 +11,8 @@ def create_troubleshotting_log_message( - message_to_user: str, - exception: BaseException, + error_user_msg: str, + error: BaseException, error_code: ErrorCodeStr, error_context: dict[str, Any] | None = None, tip: str | None = None, @@ -28,8 +28,8 @@ def create_troubleshotting_log_message( """ debug_data = pformat( { - "exception_type": f"{type(exception)}", - "exception_details": f"{exception}", + "exception_type": f"{type(error)}", + "exception_details": f"{error}", "error_code": error_code, "context": pformat(error_context, indent=1), "tip": tip, @@ -37,7 +37,7 @@ def create_troubleshotting_log_message( indent=1, ) - return f"{message_to_user}.\n{debug_data}" + return f"{error_user_msg}.\n{debug_data}" class LogKwargs(TypedDict): @@ -46,8 +46,8 @@ class LogKwargs(TypedDict): def create_troubleshotting_log_kwargs( - message_to_user: str, - exception: BaseException, + error_user_msg: str, + error: BaseException, error_context: dict[str, Any] | None = None, tip: str | None = None, ) -> LogKwargs: @@ -61,7 +61,7 @@ def create_troubleshotting_log_kwargs( except MyException as exc _logger.exception( **create_troubleshotting_log_kwargs( - message_to_user=frontend_msg, + error_user_msg=frontend_msg, exception=exc, tip="Check row in `groups_extra_properties` for this product. It might be missing.", ) @@ -69,17 +69,17 @@ def create_troubleshotting_log_kwargs( """ # error-code - error_code = create_error_code(exception) + error_code = create_error_code(error) # error-context context = error_context or {} - if isinstance(exception, OsparcErrorMixin): - context.update(exception.error_context()) + if isinstance(error, OsparcErrorMixin): + context.update(error.error_context()) # aggregate log_msg = create_troubleshotting_log_message( - message_to_user=message_to_user, - exception=exception, + error_user_msg=error_user_msg, + error=error, error_code=error_code, error_context=context, tip=tip, diff --git a/services/api-server/src/simcore_service_api_server/exceptions/handlers/_handlers_factory.py b/services/api-server/src/simcore_service_api_server/exceptions/handlers/_handlers_factory.py index 5240a2f9ee9..b6894672cb5 100644 --- a/services/api-server/src/simcore_service_api_server/exceptions/handlers/_handlers_factory.py +++ b/services/api-server/src/simcore_service_api_server/exceptions/handlers/_handlers_factory.py @@ -31,20 +31,19 @@ async def _http_error_handler( assert request # nosec assert isinstance(exception, exception_cls) # nosec - msg = error_message + user_error_msg = error_message if add_exception_to_message: - msg += f" {exception}" + user_error_msg += f" {exception}" if add_oec_to_message: error_code = create_error_code(exception) - msg += f" [{error_code}]" + user_error_msg += f" [{error_code}]" _logger.exception( **create_troubleshotting_log_kwargs( - f"Unexpected {exception.__class__.__name__}: {msg}", - exception=exception, + user_error_msg, error=exception, tip="Unexpected error" ) ) - return create_error_json_response(msg, status_code=status_code) + return create_error_json_response(user_error_msg, status_code=status_code) return _http_error_handler diff --git a/services/api-server/src/simcore_service_api_server/services/log_streaming.py b/services/api-server/src/simcore_service_api_server/services/log_streaming.py index a9693459234..895cb883766 100644 --- a/services/api-server/src/simcore_service_api_server/services/log_streaming.py +++ b/services/api-server/src/simcore_service_api_server/services/log_streaming.py @@ -133,15 +133,17 @@ async def log_generator(self) -> AsyncIterable[str]: except Exception as exc: # pylint: disable=W0718 error_code = create_error_code(exc) - error_msg = MSG_INTERNAL_ERROR_USER_FRIENDLY_TEMPLATE + f" [{error_code}]" + user_error_msg = ( + MSG_INTERNAL_ERROR_USER_FRIENDLY_TEMPLATE + f" [{error_code}]" + ) _logger.exception( **create_troubleshotting_log_kwargs( - error_msg, - exception=exc, + user_error_msg, + error=exc, ) ) - yield ErrorGet(errors=[error_msg]).json() + _NEW_LINE + yield ErrorGet(errors=[user_error_msg]).json() + _NEW_LINE finally: await self._log_distributor.deregister(self._job_id) diff --git a/services/director-v2/src/simcore_service_director_v2/modules/dynamic_sidecar/scheduler/_core/_observer.py b/services/director-v2/src/simcore_service_director_v2/modules/dynamic_sidecar/scheduler/_core/_observer.py index 913ecb71bf4..19af0f38869 100644 --- a/services/director-v2/src/simcore_service_director_v2/modules/dynamic_sidecar/scheduler/_core/_observer.py +++ b/services/director-v2/src/simcore_service_director_v2/modules/dynamic_sidecar/scheduler/_core/_observer.py @@ -145,7 +145,7 @@ async def observing_single_service( # With unhandled errors, let's generate and ID and send it to the end-user # so that we can trace the logs and debug the issue. - front_end_msg = ( + user_error_msg = ( f"This service ({service_name}) unexpectedly failed." " Our team has recorded the issue and is working to resolve it as quickly as possible." " Thank you for your patience." @@ -153,8 +153,8 @@ async def observing_single_service( logger.exception( **create_troubleshotting_log_kwargs( - front_end_msg, - exception=e, + user_error_msg, + error=e, error_context={ "service_name": service_name, "user_id": scheduler_data.user_id, @@ -165,7 +165,7 @@ async def observing_single_service( error_code = create_error_code(e) scheduler_data.dynamic_sidecar.status.update_failing_status( # This message must be human-friendly - front_end_msg, + user_error_msg, error_code, ) finally: diff --git a/services/dynamic-sidecar/src/simcore_service_dynamic_sidecar/core/utils.py b/services/dynamic-sidecar/src/simcore_service_dynamic_sidecar/core/utils.py index 5fa0dce1a19..660f0eec63b 100644 --- a/services/dynamic-sidecar/src/simcore_service_dynamic_sidecar/core/utils.py +++ b/services/dynamic-sidecar/src/simcore_service_dynamic_sidecar/core/utils.py @@ -108,11 +108,11 @@ async def async_command( except Exception as err: # pylint: disable=broad-except error_code = create_error_code(err) - error_msg = f"Unexpected error [{error_code}]" + user_error_msg = f"Unexpected error [{error_code}]" _logger.exception( **create_troubleshotting_log_kwargs( - error_msg, - exception=err, + user_error_msg, + error=err, error_context={"command": command, "proc.returncode": proc.returncode}, tip="Process with command failed unexpectily", ) @@ -120,7 +120,7 @@ async def async_command( return CommandResult( success=False, - message=error_msg, + message=user_error_msg, command=f"{command}", elapsed=time.time() - start, ) diff --git a/services/payments/src/simcore_service_payments/services/notifier_email.py b/services/payments/src/simcore_service_payments/services/notifier_email.py index 8c648000fcd..d0ea8bb413d 100644 --- a/services/payments/src/simcore_service_payments/services/notifier_email.py +++ b/services/payments/src/simcore_service_payments/services/notifier_email.py @@ -241,7 +241,7 @@ async def _create_user_email( _logger.exception( **create_troubleshotting_log_kwargs( "Cannot attach invoice to payment", - exception=exc, + error=exc, error_context={ "user": user, "payment": payment, diff --git a/services/web/server/src/simcore_service_webserver/login/_registration.py b/services/web/server/src/simcore_service_webserver/login/_registration.py index 99ba498ad9c..4cf2cbc7864 100644 --- a/services/web/server/src/simcore_service_webserver/login/_registration.py +++ b/services/web/server/src/simcore_service_webserver/login/_registration.py @@ -214,35 +214,35 @@ def _invitations_request_context(invitation_code: str) -> Iterator[URL]: except (ValidationError, InvalidInvitationError) as err: error_code = create_error_code(err) - front_end_msg = ( + user_error_msg = ( f"Invalid invitation. {MSG_INVITATIONS_CONTACT_SUFFIX} [{error_code}]" ) _logger.exception( **create_troubleshotting_log_kwargs( - front_end_msg, - exception=err, + user_error_msg, + error=err, tip="Something went wrong with the invitation", ) ) raise web.HTTPForbidden( - reason=front_end_msg, + reason=user_error_msg, content_type=MIMETYPE_APPLICATION_JSON, ) from err except InvitationsServiceUnavailableError as err: error_code = create_error_code(err) - front_end_msg = f"Unable to process your invitation since the invitations service is currently unavailable [{error_code}]" + user_error_msg = f"Unable to process your invitation since the invitations service is currently unavailable [{error_code}]" _logger.exception( **create_troubleshotting_log_kwargs( - front_end_msg, - exception=err, + user_error_msg, + error=err, tip="Something went wrong communicating the `invitations` service", ) ) raise web.HTTPServiceUnavailable( - reason=front_end_msg, + reason=user_error_msg, content_type=MIMETYPE_APPLICATION_JSON, ) from err diff --git a/services/web/server/src/simcore_service_webserver/login/errors.py b/services/web/server/src/simcore_service_webserver/login/errors.py index 0c0060d99ed..1a8b857ba08 100644 --- a/services/web/server/src/simcore_service_webserver/login/errors.py +++ b/services/web/server/src/simcore_service_webserver/login/errors.py @@ -35,7 +35,7 @@ async def wrapper(request: web.Request) -> web.StreamResponse: front_end_msg = MSG_2FA_UNAVAILABLE_OEC.format(error_code=exc.error_code()) # in these cases I want to log the cause _logger.exception( - **create_troubleshotting_log_kwargs(front_end_msg, exception=exc) + **create_troubleshotting_log_kwargs(front_end_msg, error=exc) ) raise web.HTTPServiceUnavailable( reason=front_end_msg, diff --git a/services/web/server/src/simcore_service_webserver/login/handlers_confirmation.py b/services/web/server/src/simcore_service_webserver/login/handlers_confirmation.py index 985c5314ec8..ec0caef3194 100644 --- a/services/web/server/src/simcore_service_webserver/login/handlers_confirmation.py +++ b/services/web/server/src/simcore_service_webserver/login/handlers_confirmation.py @@ -180,7 +180,7 @@ async def validate_confirmation_and_redirect(request: web.Request): except Exception as err: # pylint: disable=broad-except error_code = create_error_code(err) - front_end_msg = ( + user_error_msg = ( f"Sorry, we cannot confirm your {action}." "Please try again in a few moments. " f"If the problem persist please contact support attaching this code ({error_code})" @@ -188,8 +188,8 @@ async def validate_confirmation_and_redirect(request: web.Request): _logger.exception( **create_troubleshotting_log_kwargs( - front_end_msg, - exception=err, + user_error_msg, + error=err, tip="Failed during email_confirmation", ) ) @@ -197,7 +197,7 @@ async def validate_confirmation_and_redirect(request: web.Request): raise create_redirect_to_page_response( request.app, page="error", - message=front_end_msg, + message=user_error_msg, status_code=status.HTTP_503_SERVICE_UNAVAILABLE, ) from err diff --git a/services/web/server/src/simcore_service_webserver/login/handlers_registration.py b/services/web/server/src/simcore_service_webserver/login/handlers_registration.py index 1fcf2a603d4..83cad69dc24 100644 --- a/services/web/server/src/simcore_service_webserver/login/handlers_registration.py +++ b/services/web/server/src/simcore_service_webserver/login/handlers_registration.py @@ -267,19 +267,26 @@ async def register(request: web.Request): ) except Exception as err: # pylint: disable=broad-except error_code = create_error_code(err) + user_error_msg = f"{MSG_CANT_SEND_MAIL} [{error_code}]" + _logger.exception( - "Failed while sending confirmation email to %s, %s [%s]", - f"{user=}", - f"{_confirmation=}", - f"{error_code}", - extra={"error_code": error_code}, + **create_troubleshotting_log_kwargs( + user_error_msg, + error=err, + error_context={ + "request": request, + "registration": registration, + "user_id": user.get("id"), + "user": user, + "confirmation": _confirmation, + }, + tip="Failed while sending confirmation email", + ) ) await db.delete_confirmation_and_user(user, _confirmation) - raise web.HTTPServiceUnavailable( - reason=f"{MSG_CANT_SEND_MAIL} [{error_code}]" - ) from err + raise web.HTTPServiceUnavailable(reason=user_error_msg) from err return flash_response( "You are registered successfully! To activate your account, please, " @@ -401,18 +408,18 @@ async def register_phone(request: web.Request): except Exception as err: # pylint: disable=broad-except # Unhandled errors -> 503 error_code = create_error_code(err) - user_msg = f"Currently we cannot register phone numbers [{error_code}]" + user_error_msg = f"Currently we cannot register phone numbers [{error_code}]" _logger.exception( **create_troubleshotting_log_kwargs( - user_msg, - exception=err, + user_error_msg, + error=err, error_context={"request": request, "registration": registration}, tip="Phone registration failed", ) ) raise web.HTTPServiceUnavailable( - reason=user_msg, + reason=user_error_msg, content_type=MIMETYPE_APPLICATION_JSON, ) from err diff --git a/services/web/server/src/simcore_service_webserver/studies_dispatcher/_redirects_handlers.py b/services/web/server/src/simcore_service_webserver/studies_dispatcher/_redirects_handlers.py index 6a2117e732d..922601e4352 100644 --- a/services/web/server/src/simcore_service_webserver/studies_dispatcher/_redirects_handlers.py +++ b/services/web/server/src/simcore_service_webserver/studies_dispatcher/_redirects_handlers.py @@ -126,20 +126,20 @@ async def wrapper(request: web.Request) -> web.StreamResponse: except (ValidationError, web.HTTPServerError, Exception) as err: error_code = create_error_code(err) - front_end_msg = compose_support_error_msg( + user_error_msg = compose_support_error_msg( msg=MSG_UNEXPECTED_ERROR.format(hint=""), error_code=error_code ) _logger.exception( **create_troubleshotting_log_kwargs( - front_end_msg, - exception=err, + user_error_msg, + error=err, error_context={"request": request}, tip="Unexpected failure while dispatching study", ) ) raise _create_redirect_response_to_error_page( request.app, - message=front_end_msg, + message=user_error_msg, status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, ) from err diff --git a/services/web/server/src/simcore_service_webserver/studies_dispatcher/_studies_access.py b/services/web/server/src/simcore_service_webserver/studies_dispatcher/_studies_access.py index fffe07d4adb..6cf65fa6ce4 100644 --- a/services/web/server/src/simcore_service_webserver/studies_dispatcher/_studies_access.py +++ b/services/web/server/src/simcore_service_webserver/studies_dispatcher/_studies_access.py @@ -259,13 +259,13 @@ async def wrapper(request: web.Request) -> web.StreamResponse: except Exception as err: error_code = create_error_code(err) - front_end_msg = compose_support_error_msg( + user_error_msg = compose_support_error_msg( msg=MSG_UNEXPECTED_ERROR.format(hint=""), error_code=error_code ) _logger.exception( **create_troubleshotting_log_kwargs( - front_end_msg, - exception=err, + user_error_msg, + error=err, tip="Unexpected failure while dispatching study", ) ) @@ -273,7 +273,7 @@ async def wrapper(request: web.Request) -> web.StreamResponse: raise create_redirect_to_page_response( request.app, page="error", - message=front_end_msg, + message=user_error_msg, status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, ) from err @@ -333,17 +333,17 @@ async def get_redirection_to_study_page(request: web.Request) -> web.Response: # error_code = create_error_code(exc) - front_end_msg = MSG_TOO_MANY_GUESTS + user_error_msg = MSG_TOO_MANY_GUESTS _logger.exception( **create_troubleshotting_log_kwargs( - front_end_msg, - exception=exc, + user_error_msg, + error=exc, tip="Failed to create guest user. Responded with 429 Too Many Requests", ) ) raise RedirectToFrontEndPageError( - front_end_msg, + user_error_msg, error_code=error_code, status_code=status.HTTP_429_TOO_MANY_REQUESTS, ) from exc @@ -364,11 +364,11 @@ async def get_redirection_to_study_page(request: web.Request) -> web.Response: except Exception as exc: # pylint: disable=broad-except error_code = create_error_code(exc) - front_end_msg = MSG_UNEXPECTED_ERROR.format(hint="while copying your study") + user_error_msg = MSG_UNEXPECTED_ERROR.format(hint="while copying your study") _logger.exception( **create_troubleshotting_log_kwargs( - front_end_msg, - exception=exc, + user_error_msg, + error=exc, error_context={ "user_id": user.get("id"), "user": dict(user), @@ -381,7 +381,7 @@ async def get_redirection_to_study_page(request: web.Request) -> web.Response: ) raise RedirectToFrontEndPageError( - front_end_msg, + user_error_msg, error_code=error_code, status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, ) from exc diff --git a/services/web/server/src/simcore_service_webserver/users/_handlers.py b/services/web/server/src/simcore_service_webserver/users/_handlers.py index 5aeb92fa260..5322b21534d 100644 --- a/services/web/server/src/simcore_service_webserver/users/_handlers.py +++ b/services/web/server/src/simcore_service_webserver/users/_handlers.py @@ -54,8 +54,8 @@ async def wrapper(request: web.Request) -> web.StreamResponse: ) _logger.exception( **create_troubleshotting_log_kwargs( - message_to_user=frontend_msg, - exception=exc, + error_user_msg=frontend_msg, + error=exc, tip="Row in `groups_extra_properties` for this product is missing.", ) ) diff --git a/services/web/server/src/simcore_service_webserver/wallets/_handlers.py b/services/web/server/src/simcore_service_webserver/wallets/_handlers.py index 9835274cbb3..84608b591c5 100644 --- a/services/web/server/src/simcore_service_webserver/wallets/_handlers.py +++ b/services/web/server/src/simcore_service_webserver/wallets/_handlers.py @@ -91,13 +91,13 @@ async def wrapper(request: web.Request) -> web.StreamResponse: except BillingDetailsNotFoundError as exc: error_code = create_error_code(exc) - user_msg = f"{MSG_BILLING_DETAILS_NOT_DEFINED_ERROR} [{error_code}]" + user_error_msg = f"{MSG_BILLING_DETAILS_NOT_DEFINED_ERROR} [{error_code}]" _logger.exception( - **create_troubleshotting_log_kwargs(user_msg, exception=exc) + **create_troubleshotting_log_kwargs(user_error_msg, error=exc) ) - raise web.HTTPServiceUnavailable(reason=user_msg) from exc + raise web.HTTPServiceUnavailable(reason=user_error_msg) from exc return wrapper From cf4b04b9b107990993ff1a83498c2aa16394ce2e Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 17:09:32 +0200 Subject: [PATCH 18/24] key args --- packages/service-library/src/servicelib/logging_errors.py | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/packages/service-library/src/servicelib/logging_errors.py b/packages/service-library/src/servicelib/logging_errors.py index 58e3ffd11b0..42ff46e75ec 100644 --- a/packages/service-library/src/servicelib/logging_errors.py +++ b/packages/service-library/src/servicelib/logging_errors.py @@ -12,6 +12,7 @@ def create_troubleshotting_log_message( error_user_msg: str, + *, error: BaseException, error_code: ErrorCodeStr, error_context: dict[str, Any] | None = None, @@ -20,7 +21,7 @@ def create_troubleshotting_log_message( """Create a formatted message for _logger.exception(...) Arguments: - message_to_user -- A user-friendly message to be displayed on the front-end explaining the issue in simple terms. + error_user_msg -- A user-friendly message to be displayed on the front-end explaining the issue in simple terms. error -- the instance of the handled exception error_code -- A unique error code (e.g., OEC or osparc-specific) to identify the type or source of the error for easier tracking. error_context -- Additional context surrounding the exception, such as environment variables or function-specific data. This can be derived from exc.error_context() (relevant when using the OsparcErrorMixin) @@ -47,6 +48,7 @@ class LogKwargs(TypedDict): def create_troubleshotting_log_kwargs( error_user_msg: str, + *, error: BaseException, error_context: dict[str, Any] | None = None, tip: str | None = None, From 4e4eb473712c25c1834714e0692749e5b85c1d84 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 17:18:51 +0200 Subject: [PATCH 19/24] cleanup --- .../src/servicelib/aiohttp/rest_middlewares.py | 2 +- .../src/servicelib/logging_errors.py | 15 +++++++-------- .../simcore_service_webserver/users/_handlers.py | 6 +++--- 3 files changed, 11 insertions(+), 12 deletions(-) diff --git a/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py b/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py index 9352fde88cd..0a8892c3408 100644 --- a/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py +++ b/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py @@ -70,7 +70,7 @@ def _process_and_raise_unexpected_error(request: web.BaseRequest, err: Exception ) _logger.exception( **create_troubleshotting_log_kwargs( - error_user_msg=frontend_msg, + user_error_msg=frontend_msg, error=err, error_context=error_context, ) diff --git a/packages/service-library/src/servicelib/logging_errors.py b/packages/service-library/src/servicelib/logging_errors.py index 42ff46e75ec..7af51f349b6 100644 --- a/packages/service-library/src/servicelib/logging_errors.py +++ b/packages/service-library/src/servicelib/logging_errors.py @@ -11,7 +11,7 @@ def create_troubleshotting_log_message( - error_user_msg: str, + user_error_msg: str, *, error: BaseException, error_code: ErrorCodeStr, @@ -21,7 +21,7 @@ def create_troubleshotting_log_message( """Create a formatted message for _logger.exception(...) Arguments: - error_user_msg -- A user-friendly message to be displayed on the front-end explaining the issue in simple terms. + user_error_msg -- A user-friendly message to be displayed on the front-end explaining the issue in simple terms. error -- the instance of the handled exception error_code -- A unique error code (e.g., OEC or osparc-specific) to identify the type or source of the error for easier tracking. error_context -- Additional context surrounding the exception, such as environment variables or function-specific data. This can be derived from exc.error_context() (relevant when using the OsparcErrorMixin) @@ -38,7 +38,7 @@ def create_troubleshotting_log_message( indent=1, ) - return f"{error_user_msg}.\n{debug_data}" + return f"{user_error_msg}.\n{debug_data}" class LogKwargs(TypedDict): @@ -47,8 +47,7 @@ class LogKwargs(TypedDict): def create_troubleshotting_log_kwargs( - error_user_msg: str, - *, + user_error_msg: str, error: BaseException, error_context: dict[str, Any] | None = None, tip: str | None = None, @@ -63,7 +62,7 @@ def create_troubleshotting_log_kwargs( except MyException as exc _logger.exception( **create_troubleshotting_log_kwargs( - error_user_msg=frontend_msg, + user_error_msg=frontend_msg, exception=exc, tip="Check row in `groups_extra_properties` for this product. It might be missing.", ) @@ -78,9 +77,9 @@ def create_troubleshotting_log_kwargs( if isinstance(error, OsparcErrorMixin): context.update(error.error_context()) - # aggregate + # compose as log message log_msg = create_troubleshotting_log_message( - error_user_msg=error_user_msg, + user_error_msg, error=error, error_code=error_code, error_context=context, diff --git a/services/web/server/src/simcore_service_webserver/users/_handlers.py b/services/web/server/src/simcore_service_webserver/users/_handlers.py index 5322b21534d..afe0034a28d 100644 --- a/services/web/server/src/simcore_service_webserver/users/_handlers.py +++ b/services/web/server/src/simcore_service_webserver/users/_handlers.py @@ -49,17 +49,17 @@ async def wrapper(request: web.Request) -> web.StreamResponse: except UserNotFoundError as exc: raise web.HTTPNotFound(reason=f"{exc}") from exc except MissingGroupExtraPropertiesForProductError as exc: - frontend_msg = FMSG_MISSING_CONFIG_WITH_OEC.format( + user_error_msg = FMSG_MISSING_CONFIG_WITH_OEC.format( error_code=exc.error_code() ) _logger.exception( **create_troubleshotting_log_kwargs( - error_user_msg=frontend_msg, + user_error_msg, error=exc, tip="Row in `groups_extra_properties` for this product is missing.", ) ) - raise web.HTTPServiceUnavailable(reason=frontend_msg) from exc + raise web.HTTPServiceUnavailable(reason=user_error_msg) from exc return wrapper From 1d18522f43d82b583241e8d6f7b018e7628a4d37 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 17:30:18 +0200 Subject: [PATCH 20/24] error_code optional --- packages/service-library/src/servicelib/logging_errors.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/service-library/src/servicelib/logging_errors.py b/packages/service-library/src/servicelib/logging_errors.py index 7af51f349b6..396eaca0fce 100644 --- a/packages/service-library/src/servicelib/logging_errors.py +++ b/packages/service-library/src/servicelib/logging_errors.py @@ -14,7 +14,7 @@ def create_troubleshotting_log_message( user_error_msg: str, *, error: BaseException, - error_code: ErrorCodeStr, + error_code: ErrorCodeStr | None = None, error_context: dict[str, Any] | None = None, tip: str | None = None, ) -> str: From 07c8690b4e0574daaad6b85ca24950f094122594 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 17:32:38 +0200 Subject: [PATCH 21/24] error-code --- packages/service-library/src/servicelib/logging_errors.py | 7 +++---- .../exceptions/handlers/_handlers_factory.py | 7 +++++-- 2 files changed, 8 insertions(+), 6 deletions(-) diff --git a/packages/service-library/src/servicelib/logging_errors.py b/packages/service-library/src/servicelib/logging_errors.py index 396eaca0fce..273cee901fe 100644 --- a/packages/service-library/src/servicelib/logging_errors.py +++ b/packages/service-library/src/servicelib/logging_errors.py @@ -2,7 +2,7 @@ from pprint import pformat from typing import Any, NotRequired, TypedDict -from models_library.error_codes import ErrorCodeStr, create_error_code +from models_library.error_codes import ErrorCodeStr from models_library.errors_classes import OsparcErrorMixin from .logging_utils import LogExtra, get_log_record_extra @@ -48,7 +48,9 @@ class LogKwargs(TypedDict): def create_troubleshotting_log_kwargs( user_error_msg: str, + *, error: BaseException, + error_code: ErrorCodeStr | None = None, error_context: dict[str, Any] | None = None, tip: str | None = None, ) -> LogKwargs: @@ -69,9 +71,6 @@ def create_troubleshotting_log_kwargs( ) """ - # error-code - error_code = create_error_code(error) - # error-context context = error_context or {} if isinstance(error, OsparcErrorMixin): diff --git a/services/api-server/src/simcore_service_api_server/exceptions/handlers/_handlers_factory.py b/services/api-server/src/simcore_service_api_server/exceptions/handlers/_handlers_factory.py index b6894672cb5..4b7eea72a40 100644 --- a/services/api-server/src/simcore_service_api_server/exceptions/handlers/_handlers_factory.py +++ b/services/api-server/src/simcore_service_api_server/exceptions/handlers/_handlers_factory.py @@ -35,13 +35,16 @@ async def _http_error_handler( if add_exception_to_message: user_error_msg += f" {exception}" + error_code = create_error_code(exception) if add_oec_to_message: - error_code = create_error_code(exception) user_error_msg += f" [{error_code}]" _logger.exception( **create_troubleshotting_log_kwargs( - user_error_msg, error=exception, tip="Unexpected error" + user_error_msg, + error=exception, + error_code=error_code, + tip="Unexpected error", ) ) return create_error_json_response(user_error_msg, status_code=status_code) From 3e375730ba98a0cd0ba5a8c1a1d80c5acb3d1de1 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 17:39:57 +0200 Subject: [PATCH 22/24] cleanup --- .../src/servicelib/aiohttp/rest_middlewares.py | 7 ++++--- packages/service-library/tests/test_logging_errors.py | 5 +++-- .../services/log_streaming.py | 1 + .../dynamic_sidecar/scheduler/_core/_observer.py | 11 ++++++----- .../src/simcore_service_dynamic_sidecar/core/utils.py | 1 + .../services/notifier_email.py | 2 +- .../simcore_service_webserver/login/_registration.py | 2 ++ .../src/simcore_service_webserver/login/errors.py | 10 +++++++--- .../login/handlers_confirmation.py | 1 + .../login/handlers_registration.py | 2 ++ .../studies_dispatcher/_redirects_handlers.py | 1 + .../studies_dispatcher/_studies_access.py | 3 +++ .../src/simcore_service_webserver/users/_handlers.py | 6 +++--- .../simcore_service_webserver/wallets/_handlers.py | 6 +++++- 14 files changed, 40 insertions(+), 18 deletions(-) diff --git a/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py b/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py index 0a8892c3408..e8d106885b6 100644 --- a/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py +++ b/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py @@ -59,20 +59,21 @@ def _process_and_raise_unexpected_error(request: web.BaseRequest, err: Exception "request.path": f"{request.path}", } - frontend_msg = _FMSG_INTERNAL_ERROR_USER_FRIENDLY_WITH_OEC.format( + user_error_msg = _FMSG_INTERNAL_ERROR_USER_FRIENDLY_WITH_OEC.format( error_code=error_code ) http_error = create_http_error( err, - frontend_msg, + user_error_msg, web.HTTPInternalServerError, skip_internal_error_details=_is_prod, ) _logger.exception( **create_troubleshotting_log_kwargs( - user_error_msg=frontend_msg, + user_error_msg, error=err, error_context=error_context, + error_code=error_code, ) ) raise http_error diff --git a/packages/service-library/tests/test_logging_errors.py b/packages/service-library/tests/test_logging_errors.py index 0fbc23ae294..219f2f19de0 100644 --- a/packages/service-library/tests/test_logging_errors.py +++ b/packages/service-library/tests/test_logging_errors.py @@ -27,7 +27,7 @@ class MyError(OsparcErrorMixin, RuntimeError): log_msg = create_troubleshotting_log_message( msg, - exc, + error=exc, error_code=error_code, error_context=exc.error_context(), tip="This is a test error", @@ -35,7 +35,8 @@ class MyError(OsparcErrorMixin, RuntimeError): log_kwargs = create_troubleshotting_log_kwargs( msg, - exc, + error=exc, + error_code=error_code, tip="This is a test error", ) diff --git a/services/api-server/src/simcore_service_api_server/services/log_streaming.py b/services/api-server/src/simcore_service_api_server/services/log_streaming.py index 895cb883766..5bb8cbd362e 100644 --- a/services/api-server/src/simcore_service_api_server/services/log_streaming.py +++ b/services/api-server/src/simcore_service_api_server/services/log_streaming.py @@ -141,6 +141,7 @@ async def log_generator(self) -> AsyncIterable[str]: **create_troubleshotting_log_kwargs( user_error_msg, error=exc, + error_code=error_code, ) ) yield ErrorGet(errors=[user_error_msg]).json() + _NEW_LINE diff --git a/services/director-v2/src/simcore_service_director_v2/modules/dynamic_sidecar/scheduler/_core/_observer.py b/services/director-v2/src/simcore_service_director_v2/modules/dynamic_sidecar/scheduler/_core/_observer.py index 19af0f38869..5ced0f1a591 100644 --- a/services/director-v2/src/simcore_service_director_v2/modules/dynamic_sidecar/scheduler/_core/_observer.py +++ b/services/director-v2/src/simcore_service_director_v2/modules/dynamic_sidecar/scheduler/_core/_observer.py @@ -140,7 +140,7 @@ async def observing_single_service( logger.debug("completed observation cycle of %s", f"{service_name=}") except asyncio.CancelledError: # pylint: disable=try-except-raise raise # pragma: no cover - except Exception as e: # pylint: disable=broad-except + except Exception as exc: # pylint: disable=broad-except service_name = scheduler_data.service_name # With unhandled errors, let's generate and ID and send it to the end-user @@ -150,19 +150,20 @@ async def observing_single_service( " Our team has recorded the issue and is working to resolve it as quickly as possible." " Thank you for your patience." ) + error_code = create_error_code(exc) logger.exception( **create_troubleshotting_log_kwargs( user_error_msg, - error=e, + error=exc, error_context={ "service_name": service_name, "user_id": scheduler_data.user_id, }, + error_code=error_code, tip=f"Observation of {service_name=} unexpectedly failed", ) ) - error_code = create_error_code(e) scheduler_data.dynamic_sidecar.status.update_failing_status( # This message must be human-friendly user_error_msg, @@ -172,5 +173,5 @@ async def observing_single_service( if scheduler_data_copy != scheduler_data: try: await update_scheduler_data_label(scheduler_data) - except GenericDockerError as e: - logger.warning("Skipped labels update, please check:\n %s", f"{e}") + except GenericDockerError as exc: + logger.warning("Skipped labels update, please check:\n %s", f"{exc}") diff --git a/services/dynamic-sidecar/src/simcore_service_dynamic_sidecar/core/utils.py b/services/dynamic-sidecar/src/simcore_service_dynamic_sidecar/core/utils.py index 660f0eec63b..697dc673b8e 100644 --- a/services/dynamic-sidecar/src/simcore_service_dynamic_sidecar/core/utils.py +++ b/services/dynamic-sidecar/src/simcore_service_dynamic_sidecar/core/utils.py @@ -114,6 +114,7 @@ async def async_command( user_error_msg, error=err, error_context={"command": command, "proc.returncode": proc.returncode}, + error_code=error_code, tip="Process with command failed unexpectily", ) ) diff --git a/services/payments/src/simcore_service_payments/services/notifier_email.py b/services/payments/src/simcore_service_payments/services/notifier_email.py index d0ea8bb413d..29a423837df 100644 --- a/services/payments/src/simcore_service_payments/services/notifier_email.py +++ b/services/payments/src/simcore_service_payments/services/notifier_email.py @@ -240,7 +240,7 @@ async def _create_user_email( except Exception as exc: # pylint: disable=broad-exception-caught _logger.exception( **create_troubleshotting_log_kwargs( - "Cannot attach invoice to payment", + "Cannot attach invoice to payment. Email sent w/o attached pdf invoice", error=exc, error_context={ "user": user, diff --git a/services/web/server/src/simcore_service_webserver/login/_registration.py b/services/web/server/src/simcore_service_webserver/login/_registration.py index 4cf2cbc7864..282256d1b16 100644 --- a/services/web/server/src/simcore_service_webserver/login/_registration.py +++ b/services/web/server/src/simcore_service_webserver/login/_registration.py @@ -222,6 +222,7 @@ def _invitations_request_context(invitation_code: str) -> Iterator[URL]: **create_troubleshotting_log_kwargs( user_error_msg, error=err, + error_code=error_code, tip="Something went wrong with the invitation", ) ) @@ -238,6 +239,7 @@ def _invitations_request_context(invitation_code: str) -> Iterator[URL]: **create_troubleshotting_log_kwargs( user_error_msg, error=err, + error_code=error_code, tip="Something went wrong communicating the `invitations` service", ) ) diff --git a/services/web/server/src/simcore_service_webserver/login/errors.py b/services/web/server/src/simcore_service_webserver/login/errors.py index 1a8b857ba08..56588b87df6 100644 --- a/services/web/server/src/simcore_service_webserver/login/errors.py +++ b/services/web/server/src/simcore_service_webserver/login/errors.py @@ -31,11 +31,15 @@ async def wrapper(request: web.Request) -> web.StreamResponse: return await handler(request) except (SendingVerificationSmsError, SendingVerificationEmailError) as exc: - - front_end_msg = MSG_2FA_UNAVAILABLE_OEC.format(error_code=exc.error_code()) + error_code = exc.error_code() + front_end_msg = MSG_2FA_UNAVAILABLE_OEC.format(error_code=error_code) # in these cases I want to log the cause _logger.exception( - **create_troubleshotting_log_kwargs(front_end_msg, error=exc) + **create_troubleshotting_log_kwargs( + front_end_msg, + error=exc, + error_code=error_code, + ) ) raise web.HTTPServiceUnavailable( reason=front_end_msg, diff --git a/services/web/server/src/simcore_service_webserver/login/handlers_confirmation.py b/services/web/server/src/simcore_service_webserver/login/handlers_confirmation.py index ec0caef3194..c627fb58358 100644 --- a/services/web/server/src/simcore_service_webserver/login/handlers_confirmation.py +++ b/services/web/server/src/simcore_service_webserver/login/handlers_confirmation.py @@ -190,6 +190,7 @@ async def validate_confirmation_and_redirect(request: web.Request): **create_troubleshotting_log_kwargs( user_error_msg, error=err, + error_code=error_code, tip="Failed during email_confirmation", ) ) diff --git a/services/web/server/src/simcore_service_webserver/login/handlers_registration.py b/services/web/server/src/simcore_service_webserver/login/handlers_registration.py index 83cad69dc24..9ae8b1af582 100644 --- a/services/web/server/src/simcore_service_webserver/login/handlers_registration.py +++ b/services/web/server/src/simcore_service_webserver/login/handlers_registration.py @@ -273,6 +273,7 @@ async def register(request: web.Request): **create_troubleshotting_log_kwargs( user_error_msg, error=err, + error_code=error_code, error_context={ "request": request, "registration": registration, @@ -414,6 +415,7 @@ async def register_phone(request: web.Request): **create_troubleshotting_log_kwargs( user_error_msg, error=err, + error_code=error_code, error_context={"request": request, "registration": registration}, tip="Phone registration failed", ) diff --git a/services/web/server/src/simcore_service_webserver/studies_dispatcher/_redirects_handlers.py b/services/web/server/src/simcore_service_webserver/studies_dispatcher/_redirects_handlers.py index 922601e4352..05757c80468 100644 --- a/services/web/server/src/simcore_service_webserver/studies_dispatcher/_redirects_handlers.py +++ b/services/web/server/src/simcore_service_webserver/studies_dispatcher/_redirects_handlers.py @@ -133,6 +133,7 @@ async def wrapper(request: web.Request) -> web.StreamResponse: **create_troubleshotting_log_kwargs( user_error_msg, error=err, + error_code=error_code, error_context={"request": request}, tip="Unexpected failure while dispatching study", ) diff --git a/services/web/server/src/simcore_service_webserver/studies_dispatcher/_studies_access.py b/services/web/server/src/simcore_service_webserver/studies_dispatcher/_studies_access.py index 6cf65fa6ce4..1e218e94c10 100644 --- a/services/web/server/src/simcore_service_webserver/studies_dispatcher/_studies_access.py +++ b/services/web/server/src/simcore_service_webserver/studies_dispatcher/_studies_access.py @@ -266,6 +266,7 @@ async def wrapper(request: web.Request) -> web.StreamResponse: **create_troubleshotting_log_kwargs( user_error_msg, error=err, + error_code=error_code, tip="Unexpected failure while dispatching study", ) ) @@ -338,6 +339,7 @@ async def get_redirection_to_study_page(request: web.Request) -> web.Response: **create_troubleshotting_log_kwargs( user_error_msg, error=exc, + error_code=error_code, tip="Failed to create guest user. Responded with 429 Too Many Requests", ) ) @@ -369,6 +371,7 @@ async def get_redirection_to_study_page(request: web.Request) -> web.Response: **create_troubleshotting_log_kwargs( user_error_msg, error=exc, + error_code=error_code, error_context={ "user_id": user.get("id"), "user": dict(user), diff --git a/services/web/server/src/simcore_service_webserver/users/_handlers.py b/services/web/server/src/simcore_service_webserver/users/_handlers.py index afe0034a28d..3e2018c7d9b 100644 --- a/services/web/server/src/simcore_service_webserver/users/_handlers.py +++ b/services/web/server/src/simcore_service_webserver/users/_handlers.py @@ -49,13 +49,13 @@ async def wrapper(request: web.Request) -> web.StreamResponse: except UserNotFoundError as exc: raise web.HTTPNotFound(reason=f"{exc}") from exc except MissingGroupExtraPropertiesForProductError as exc: - user_error_msg = FMSG_MISSING_CONFIG_WITH_OEC.format( - error_code=exc.error_code() - ) + error_code = exc.error_code() + user_error_msg = FMSG_MISSING_CONFIG_WITH_OEC.format(error_code=error_code) _logger.exception( **create_troubleshotting_log_kwargs( user_error_msg, error=exc, + error_code=error_code, tip="Row in `groups_extra_properties` for this product is missing.", ) ) diff --git a/services/web/server/src/simcore_service_webserver/wallets/_handlers.py b/services/web/server/src/simcore_service_webserver/wallets/_handlers.py index 84608b591c5..dc6855f2c01 100644 --- a/services/web/server/src/simcore_service_webserver/wallets/_handlers.py +++ b/services/web/server/src/simcore_service_webserver/wallets/_handlers.py @@ -94,7 +94,11 @@ async def wrapper(request: web.Request) -> web.StreamResponse: user_error_msg = f"{MSG_BILLING_DETAILS_NOT_DEFINED_ERROR} [{error_code}]" _logger.exception( - **create_troubleshotting_log_kwargs(user_error_msg, error=exc) + **create_troubleshotting_log_kwargs( + user_error_msg, + error=exc, + error_code=error_code, + ) ) raise web.HTTPServiceUnavailable(reason=user_error_msg) from exc From 0e1fcfe13b4d7880e2f6594bc71c14efe8464400 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 18:00:21 +0200 Subject: [PATCH 23/24] pylint and not required --- .../service-library/src/servicelib/logging_errors.py | 4 ++-- packages/service-library/src/servicelib/logging_utils.py | 9 ++++----- packages/service-library/tests/test_logging_errors.py | 5 ++++- 3 files changed, 10 insertions(+), 8 deletions(-) diff --git a/packages/service-library/src/servicelib/logging_errors.py b/packages/service-library/src/servicelib/logging_errors.py index 273cee901fe..5182262ddb5 100644 --- a/packages/service-library/src/servicelib/logging_errors.py +++ b/packages/service-library/src/servicelib/logging_errors.py @@ -1,6 +1,6 @@ import logging from pprint import pformat -from typing import Any, NotRequired, TypedDict +from typing import Any, TypedDict from models_library.error_codes import ErrorCodeStr from models_library.errors_classes import OsparcErrorMixin @@ -43,7 +43,7 @@ def create_troubleshotting_log_message( class LogKwargs(TypedDict): msg: str - extra: NotRequired[LogExtra | None] + extra: LogExtra def create_troubleshotting_log_kwargs( diff --git a/packages/service-library/src/servicelib/logging_utils.py b/packages/service-library/src/servicelib/logging_utils.py index fbaba59fd30..86bb38a08ca 100644 --- a/packages/service-library/src/servicelib/logging_utils.py +++ b/packages/service-library/src/servicelib/logging_utils.py @@ -14,8 +14,7 @@ from datetime import datetime from inspect import getframeinfo, stack from pathlib import Path -from pprint import pformat -from typing import Any, TypeAlias, TypedDict, TypeVar +from typing import Any, NotRequired, TypeAlias, TypedDict, TypeVar from .utils_secrets import mask_sensitive_data @@ -319,9 +318,9 @@ def log_catch(logger: logging.Logger, *, reraise: bool = True) -> Iterator[None] raise exc from exc -class LogExtra(TypedDict, total=False): - log_uid: str - log_oec: str +class LogExtra(TypedDict): + log_uid: NotRequired[str] + log_oec: NotRequired[str] LogLevelInt: TypeAlias = int diff --git a/packages/service-library/tests/test_logging_errors.py b/packages/service-library/tests/test_logging_errors.py index 219f2f19de0..432d2421d17 100644 --- a/packages/service-library/tests/test_logging_errors.py +++ b/packages/service-library/tests/test_logging_errors.py @@ -41,8 +41,11 @@ class MyError(OsparcErrorMixin, RuntimeError): ) assert log_kwargs["msg"] == log_msg + assert log_kwargs["extra"] is not None assert ( - log_kwargs["extra"]["log_uid"] == "123" + # pylint: disable=unsubscriptable-object + log_kwargs["extra"]["log_uid"] + == "123" ), "user_id is injected as extra from context" with caplog.at_level(logging.WARNING): From 6f173e66fc5dca85c261fc64eb94bdfed9441d24 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 15 Oct 2024 19:03:45 +0200 Subject: [PATCH 24/24] fixes mypy --- packages/service-library/src/servicelib/logging_errors.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/service-library/src/servicelib/logging_errors.py b/packages/service-library/src/servicelib/logging_errors.py index 5182262ddb5..926581a3f2c 100644 --- a/packages/service-library/src/servicelib/logging_errors.py +++ b/packages/service-library/src/servicelib/logging_errors.py @@ -43,7 +43,7 @@ def create_troubleshotting_log_message( class LogKwargs(TypedDict): msg: str - extra: LogExtra + extra: LogExtra | None def create_troubleshotting_log_kwargs(