Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

🎨 Enhanced error handling and troubleshooting logs helpers #6531

Merged
merged 27 commits into from
Oct 16, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
@@ -1,5 +1,7 @@
from pydantic.errors import PydanticErrorMixin

from .error_codes import create_error_code


class _DefaultDict(dict):
def __missing__(self, key):
Expand Down Expand Up @@ -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)
Original file line number Diff line number Diff line change
Expand Up @@ -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__)

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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

Expand Down
94 changes: 94 additions & 0 deletions packages/service-library/src/servicelib/logging_errors.py
Original file line number Diff line number Diff line change
@@ -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),
),
}
39 changes: 4 additions & 35 deletions packages/service-library/src/servicelib/logging_utils.py
Original file line number Diff line number Diff line change
Expand Up @@ -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__)
Expand Down Expand Up @@ -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
Expand All @@ -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 ""

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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 (
Expand All @@ -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
Expand Down
68 changes: 68 additions & 0 deletions packages/service-library/tests/test_logging_errors.py
Original file line number Diff line number Diff line change
@@ -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
43 changes: 0 additions & 43 deletions packages/service-library/tests/test_logging_utils.py
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down Expand Up @@ -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
Loading
Loading