🎨 Enhanced error handling and troubleshooting logs helpers (#6531)

Author: pcrespov

packages/service-library/src/servicelib/error_codes.py renamed to packages/models-library/src/models_library/error_codes.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)

packages/models-library/src/models_library/errors_classes.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__)
 

packages/service-library/tests/test_error_codes.py renamed to packages/models-library/tests/test_error_codes.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
 

packages/service-library/src/servicelib/aiohttp/rest_middlewares.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),
+        ),
+    }

packages/service-library/src/servicelib/logging_errors.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 ""
 

packages/service-library/src/servicelib/logging_utils.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

packages/service-library/tests/aiohttp/test_rest_middlewares.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

packages/service-library/tests/test_logging_errors.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