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/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) 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..e8d106885b6 100644 --- a/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py +++ b/packages/service-library/src/servicelib/aiohttp/rest_middlewares.py @@ -12,11 +12,10 @@ from aiohttp import web from aiohttp.web_request import Request from aiohttp.web_response import StreamResponse -from models_library.errors_classes import OsparcErrorMixin +from models_library.error_codes import create_error_code 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 ..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,31 +58,23 @@ 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( + user_error_msg = _FMSG_INTERNAL_ERROR_USER_FRIENDLY_WITH_OEC.format( error_code=error_code ) - log_msg = create_troubleshotting_log_message( - message_to_user=frontend_msg, - error=err, - error_code=error_code, - error_context=error_context, - ) - http_error = create_http_error( err, - frontend_msg, + user_error_msg, web.HTTPInternalServerError, skip_internal_error_details=_is_prod, ) _logger.exception( - log_msg, - extra=get_log_record_extra( + **create_troubleshotting_log_kwargs( + user_error_msg, + error=err, + error_context=error_context, error_code=error_code, - user_id=error_context.get("user_id"), - ), + ) ) raise http_error 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..926581a3f2c --- /dev/null +++ b/packages/service-library/src/servicelib/logging_errors.py @@ -0,0 +1,94 @@ +import logging +from pprint import pformat +from typing import Any, TypedDict + +from models_library.error_codes import ErrorCodeStr +from models_library.errors_classes import OsparcErrorMixin + +from .logging_utils import LogExtra, get_log_record_extra + +_logger = logging.getLogger(__name__) + + +def create_troubleshotting_log_message( + user_error_msg: str, + *, + error: BaseException, + error_code: ErrorCodeStr | None = None, + error_context: dict[str, Any] | None = None, + tip: str | None = None, +) -> str: + """Create a formatted message for _logger.exception(...) + + Arguments: + 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) + tip -- Helpful suggestions or possible solutions explaining why the error may have occurred and how it could potentially be resolved + """ + debug_data = pformat( + { + "exception_type": f"{type(error)}", + "exception_details": f"{error}", + "error_code": error_code, + "context": pformat(error_context, indent=1), + "tip": tip, + }, + indent=1, + ) + + return f"{user_error_msg}.\n{debug_data}" + + +class LogKwargs(TypedDict): + msg: str + extra: LogExtra | None + + +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: + """ + 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( + user_error_msg=frontend_msg, + exception=exc, + tip="Check row in `groups_extra_properties` for this product. It might be missing.", + ) + ) + + """ + # error-context + context = error_context or {} + if isinstance(error, OsparcErrorMixin): + context.update(error.error_context()) + + # compose as log message + log_msg = create_troubleshotting_log_message( + user_error_msg, + error=error, + 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 24b9ebcad29..86bb38a08ca 100644 --- a/packages/service-library/src/servicelib/logging_utils.py +++ b/packages/service-library/src/servicelib/logging_utils.py @@ -14,10 +14,8 @@ 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 .error_codes import ErrorCodeStr from .utils_secrets import mask_sensitive_data _logger = logging.getLogger(__name__) @@ -320,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 @@ -345,35 +343,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/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_errors.py b/packages/service-library/tests/test_logging_errors.py new file mode 100644 index 00000000000..432d2421d17 --- /dev/null +++ b/packages/service-library/tests/test_logging_errors.py @@ -0,0 +1,68 @@ +# 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_kwargs, + create_troubleshotting_log_message, +) + + +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) + + assert exc.error_code() == error_code + + msg = f"Nice message to user [{error_code}]" + + log_msg = create_troubleshotting_log_message( + msg, + error=exc, + error_code=error_code, + error_context=exc.error_context(), + tip="This is a test error", + ) + + log_kwargs = create_troubleshotting_log_kwargs( + msg, + error=exc, + error_code=error_code, + tip="This is a test error", + ) + + assert log_kwargs["msg"] == log_msg + assert log_kwargs["extra"] is not None + assert ( + # pylint: disable=unsubscriptable-object + 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_kwargs) + + # 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 90ed5367d2f..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.errors_classes import OsparcErrorMixin -from servicelib.error_codes import create_error_code 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/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..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 @@ -2,7 +2,8 @@ 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 servicelib.logging_errors import create_troubleshotting_log_kwargs from ._utils import ExceptionHandler, create_error_json_response @@ -30,19 +31,22 @@ 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}" + error_code = create_error_code(exception) 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}, + user_error_msg += f" [{error_code}]" + + _logger.exception( + **create_troubleshotting_log_kwargs( + user_error_msg, + error=exception, + error_code=error_code, + 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 faefc5c905b..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 @@ -4,10 +4,11 @@ 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_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,26 @@ 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) + user_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( + user_error_msg, + error=exc, + error_code=error_code, + ) ) - yield ErrorGet( - errors=[ - MSG_INTERNAL_ERROR_USER_FRIENDLY_TEMPLATE + f" (OEC: {error_code})" - ] - ).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/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..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 @@ -6,7 +6,8 @@ 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 servicelib.logging_errors import create_troubleshotting_log_kwargs from .....core.dynamic_services_settings.scheduler import ( DynamicServicesSchedulerSettings, @@ -139,27 +140,38 @@ 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 # so that we can trace the logs and debug the issue. + 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." + ) + error_code = create_error_code(exc) - 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( + user_error_msg, + 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", + ) ) scheduler_data.dynamic_sidecar.status.update_failing_status( # This message must be human-friendly - f"Upss! This service ({service_name}) unexpectedly failed", + user_error_msg, error_code, ) finally: 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 eee821145c1..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 @@ -7,7 +7,8 @@ from typing import NamedTuple import psutil -from servicelib.error_codes import create_error_code +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,22 @@ async def async_command( ) except Exception as err: # pylint: disable=broad-except + error_code = create_error_code(err) + user_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( + user_error_msg, + error=err, + error_context={"command": command, "proc.returncode": proc.returncode}, + error_code=error_code, + tip="Process with command failed unexpectily", + ) ) return CommandResult( success=False, - message=f"Unexpected error [{error_code}]", + 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 53e9920990d..29a423837df 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. Email sent w/o attached pdf invoice", + error=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 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..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,7 +2,7 @@ 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, @@ -11,7 +11,6 @@ from models_library.emails import LowerCaseEmailStr 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 @@ -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/_2fa_api.py b/services/web/server/src/simcore_service_webserver/login/_2fa_api.py index 06a96f00e6d..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 @@ -13,8 +13,7 @@ from aiohttp import web 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.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/_registration.py b/services/web/server/src/simcore_service_webserver/login/_registration.py index 322dbb026c4..282256d1b16 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,38 @@ 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) + user_error_msg = ( + f"Invalid invitation. {MSG_INVITATIONS_CONTACT_SUFFIX} [{error_code}]" + ) + + _logger.exception( + **create_troubleshotting_log_kwargs( + user_error_msg, + error=err, + error_code=error_code, + tip="Something went wrong with the invitation", + ) + ) raise web.HTTPForbidden( - reason=f"{msg}. {MSG_INVITATIONS_CONTACT_SUFFIX}", + reason=user_error_msg, content_type=MIMETYPE_APPLICATION_JSON, ) from err except InvitationsServiceUnavailableError as err: + error_code = create_error_code(err) + user_error_msg = f"Unable to process your invitation since the invitations service is currently unavailable [{error_code}]" + + _logger.exception( + **create_troubleshotting_log_kwargs( + user_error_msg, + error=err, + error_code=error_code, + tip="Something went wrong communicating the `invitations` service", + ) + ) raise web.HTTPServiceUnavailable( - reason=f"{err}", + 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 e0b34c7787a..56588b87df6 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,18 @@ async def wrapper(request: web.Request) -> web.StreamResponse: return await handler(request) except (SendingVerificationSmsError, SendingVerificationEmailError) as exc: + 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, + error_code=error_code, + ) + ) raise web.HTTPServiceUnavailable( - reason=MSG_2FA_UNAVAILABLE_OEC.format(error_code=exc.code), + reason=front_end_msg, content_type=MIMETYPE_APPLICATION_JSON, ) from exc 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..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 @@ -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,7 @@ parse_request_body_as, parse_request_path_parameters_as, ) -from servicelib.error_codes import create_error_code +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,25 @@ async def validate_confirmation_and_redirect(request: web.Request): except Exception as err: # pylint: disable=broad-except error_code = create_error_code(err) + 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})" + ) + _logger.exception( - "Failed during email_confirmation [%s]", - f"{error_code}", - extra={"error_code": error_code}, + **create_troubleshotting_log_kwargs( + user_error_msg, + error=err, + error_code=error_code, + 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=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 d3f553db71c..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 @@ -5,10 +5,11 @@ 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.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,19 +267,27 @@ async def register(request: web.Request): ) except Exception as err: # pylint: disable=broad-except error_code = create_error_code(err) - log.exception( - "Failed while sending confirmation email to %s, %s [%s]", - f"{user=}", - f"{_confirmation=}", - f"{error_code}", - extra={"error_code": error_code}, + user_error_msg = f"{MSG_CANT_SEND_MAIL} [{error_code}]" + + _logger.exception( + **create_troubleshotting_log_kwargs( + user_error_msg, + error=err, + error_code=error_code, + 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, " @@ -400,13 +409,19 @@ 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_error_msg = f"Currently we cannot register phone numbers [{error_code}]" + + _logger.exception( + **create_troubleshotting_log_kwargs( + user_error_msg, + error=err, + error_code=error_code, + 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_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 1b60fd5f7e0..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 @@ -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,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.error_codes import create_error_code +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,22 @@ async def wrapper(request: web.Request) -> web.StreamResponse: except (ValidationError, web.HTTPServerError, Exception) as err: error_code = create_error_code(err) + + user_error_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( + user_error_msg, + error=err, + error_code=error_code, + 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=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 9545675d7ec..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 @@ -20,10 +20,11 @@ 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 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,22 @@ async def wrapper(request: web.Request) -> web.StreamResponse: except Exception as err: error_code = create_error_code(err) + user_error_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( + user_error_msg, + error=err, + error_code=error_code, + 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=user_error_msg, status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, ) from err @@ -327,13 +333,19 @@ async def get_redirection_to_study_page(request: web.Request) -> web.Response: # we cannot accept any more users. # error_code = create_error_code(exc) + + user_error_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( + user_error_msg, + error=exc, + error_code=error_code, + tip="Failed to create guest user. Responded with 429 Too Many Requests", + ) ) + raise RedirectToFrontEndPageError( - MSG_TOO_MANY_GUESTS, + user_error_msg, error_code=error_code, status_code=status.HTTP_429_TOO_MANY_REQUESTS, ) from exc @@ -353,15 +365,26 @@ 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) + + user_error_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( + user_error_msg, + error=exc, + error_code=error_code, + 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"), + 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 a8516095e57..3e2018c7d9b 100644 --- a/services/web/server/src/simcore_service_webserver/users/_handlers.py +++ b/services/web/server/src/simcore_service_webserver/users/_handlers.py @@ -9,11 +9,7 @@ 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, -) +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 @@ -53,24 +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: - 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.", - ) - + error_code = exc.error_code() + user_error_msg = FMSG_MISSING_CONFIG_WITH_OEC.format(error_code=error_code) _logger.exception( - log_msg, - extra=get_log_record_extra( + **create_troubleshotting_log_kwargs( + user_error_msg, + error=exc, error_code=error_code, - user_id=exc.error_context().get("user_id", None), - ), + 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 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..dc6855f2c01 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,8 +19,7 @@ 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.logging_errors import create_troubleshotting_log_kwargs from servicelib.request_keys import RQT_USERID_KEY from .._constants import RQ_PRODUCT_KEY @@ -89,18 +89,19 @@ 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_error_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_error_msg, + error=exc, + error_code=error_code, + ) ) - user_msg = f"{MSG_BILLING_DETAILS_NOT_DEFINED_ERROR} ({error_code})" - raise web.HTTPServiceUnavailable(reason=user_msg) from exc + + raise web.HTTPServiceUnavailable(reason=user_error_msg) from exc return wrapper