From 73403b12c4b52f65021d326393ce86e261bbd209 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Thu, 13 Mar 2025 20:20:44 +0100 Subject: [PATCH 1/4] implements #7362 --- .../src/common_library/error_codes.py | 23 +++++++++-- .../common-library/tests/test_error_codes.py | 39 +++++++++++++++++-- 2 files changed, 56 insertions(+), 6 deletions(-) diff --git a/packages/common-library/src/common_library/error_codes.py b/packages/common-library/src/common_library/error_codes.py index 13b3b1566daa..55fac73b331b 100644 --- a/packages/common-library/src/common_library/error_codes.py +++ b/packages/common-library/src/common_library/error_codes.py @@ -1,4 +1,4 @@ -""" osparc ERROR CODES (OEC) +"""osparc ERROR CODES (OEC) Unique identifier of an exception instance Intended to report a user about unexpected errors. Unexpected exceptions can be traced by matching the @@ -7,13 +7,15 @@ SEE test_error_codes for some use cases """ +import hashlib import re +import traceback from typing import TYPE_CHECKING, Annotated from pydantic import StringConstraints, TypeAdapter _LABEL = "OEC:{}" -_PATTERN = r"OEC:\d+" +_PATTERN = r"OEC:[a-zA-Z0-9]+" if TYPE_CHECKING: ErrorCodeStr = str @@ -22,9 +24,24 @@ str, StringConstraints(strip_whitespace=True, pattern=_PATTERN) ] +_LEN = 12 # chars (~48 bits) + + +def _generate_error_fingerprint(exc: BaseException) -> str: + """ + Unique error fingerprint for deduplication purposes + """ + tb = traceback.extract_tb(exc.__traceback__) + frame_sigs = [f"{frame.name}:{frame.lineno}" for frame in tb] + fingerprint = f"{type(exc).__name__}|" + "|".join(frame_sigs) + # E.g. ZeroDivisionError|foo:23|main:10 + return hashlib.sha256(fingerprint.encode()).hexdigest()[:_LEN] + def create_error_code(exception: BaseException) -> ErrorCodeStr: - return TypeAdapter(ErrorCodeStr).validate_python(_LABEL.format(id(exception))) + return TypeAdapter(ErrorCodeStr).validate_python( + _LABEL.format(_generate_error_fingerprint(exception)) + ) def parse_error_code(obj) -> set[ErrorCodeStr]: diff --git a/packages/common-library/tests/test_error_codes.py b/packages/common-library/tests/test_error_codes.py index 5d4d78a5d2b8..c92af47a6855 100644 --- a/packages/common-library/tests/test_error_codes.py +++ b/packages/common-library/tests/test_error_codes.py @@ -11,10 +11,43 @@ logger = logging.getLogger(__name__) -def test_error_code_use_case(caplog: pytest.LogCaptureFixture): - """use case for error-codes""" +def _level_three(v): + msg = f"An error occurred in level three with {v}" + raise RuntimeError(msg) + + +def _level_two(v): + _level_three(v) + + +def _level_one(v=None): + _level_two(v) + + +def test_exception_fingerprint_consistency(): + error_codes = [] + + for v in range(2): + # emulates different runs of the same function (e.g. different sessions) + try: + _level_one(v) # same even if different value! + except Exception as err: + error_code = create_error_code(err) + error_codes.append(error_code) + + assert error_codes == [error_codes[0]] * len(error_codes) + + try: + # Same function but different location + _level_one(0) + except Exception as e2: + error_code_2 = create_error_code(e2) + assert error_code_2 != error_code[0] + + +def test_create_log_and_parse_error_code(caplog: pytest.LogCaptureFixture): with pytest.raises(RuntimeError) as exc_info: - raise RuntimeError("Something unexpected went wrong") + _level_one() # 1. Unexpected ERROR err = exc_info.value From c3dd18cc06196b5f6d03a1f56fa4a6366a71d761 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 18 Mar 2025 17:02:28 +0100 Subject: [PATCH 2/4] @GitHK review: composed 'OEC:{traceback}-{timestamp}' --- .../src/common_library/error_codes.py | 66 ++++++++++++++----- .../common-library/tests/test_error_codes.py | 34 +++++++--- .../tests/aiohttp/test_rest_middlewares.py | 7 +- 3 files changed, 80 insertions(+), 27 deletions(-) diff --git a/packages/common-library/src/common_library/error_codes.py b/packages/common-library/src/common_library/error_codes.py index 55fac73b331b..e4759a624af5 100644 --- a/packages/common-library/src/common_library/error_codes.py +++ b/packages/common-library/src/common_library/error_codes.py @@ -10,26 +10,30 @@ import hashlib import re import traceback -from typing import TYPE_CHECKING, Annotated +from datetime import datetime +from typing import Annotated, Final, TypeAlias +import arrow from pydantic import StringConstraints, TypeAdapter -_LABEL = "OEC:{}" -_PATTERN = r"OEC:[a-zA-Z0-9]+" - -if TYPE_CHECKING: - ErrorCodeStr = str -else: - ErrorCodeStr = Annotated[ - str, StringConstraints(strip_whitespace=True, pattern=_PATTERN) - ] +_LABEL = "OEC:{fingerprint}-{timestamp}" _LEN = 12 # chars (~48 bits) +_NAMED_PATTERN = re.compile( + r"OEC:(?P[a-fA-F0-9]{12})-(?P\d{13,14})" + # NOTE: timestamp limits: 13 digits (from 2001), 14 digits (good for ~500+ years) +) +_PATTERN = re.compile(r"OEC:[a-fA-F0-9]{12}-\d{13,14}") + +ErrorCodeStr: TypeAlias = Annotated[ + str, StringConstraints(strip_whitespace=True, pattern=_NAMED_PATTERN) +] -def _generate_error_fingerprint(exc: BaseException) -> str: + +def _create_fingerprint(exc: BaseException) -> str: """ - Unique error fingerprint for deduplication purposes + Unique error fingerprint of the **traceback** for deduplication purposes """ tb = traceback.extract_tb(exc.__traceback__) frame_sigs = [f"{frame.name}:{frame.lineno}" for frame in tb] @@ -38,11 +42,43 @@ def _generate_error_fingerprint(exc: BaseException) -> str: return hashlib.sha256(fingerprint.encode()).hexdigest()[:_LEN] +_MILISECONDS: Final[int] = 1000 + + +def _create_timestamp() -> int: + """Timestamp as milliseconds since epoch + NOTE: this reduces the precission to milliseconds but it is good enough for our purpose + """ + ts = arrow.utcnow().float_timestamp * _MILISECONDS + return int(ts) + + def create_error_code(exception: BaseException) -> ErrorCodeStr: + """ + Generates a unique error code for the given exception. + + The error code follows the format: `OEC:{traceback}-{timestamp}`. + This code is intended to be shared with the front-end as a `SupportID` + for debugging and support purposes. + """ return TypeAdapter(ErrorCodeStr).validate_python( - _LABEL.format(_generate_error_fingerprint(exception)) + _LABEL.format( + fingerprint=_create_fingerprint(exception), + timestamp=_create_timestamp(), + ) ) -def parse_error_code(obj) -> set[ErrorCodeStr]: - return set(re.findall(_PATTERN, f"{obj}")) +def parse_error_codes(obj) -> list[ErrorCodeStr]: + return TypeAdapter(list[ErrorCodeStr]).validate_python(_PATTERN.findall(f"{obj}")) + + +def parse_error_code_parts(oec: ErrorCodeStr) -> tuple[str, datetime]: + """Returns traceback-fingerprint and timestamp from `OEC:{traceback}-{timestamp}`""" + match = _NAMED_PATTERN.match(oec) + if not match: + msg = f"Invalid error code format: {oec}" + raise ValueError(msg) + fingerprint = match.group("fingerprint") + timestamp = arrow.get(int(match.group("timestamp")) / _MILISECONDS).datetime + return fingerprint, timestamp diff --git a/packages/common-library/tests/test_error_codes.py b/packages/common-library/tests/test_error_codes.py index c92af47a6855..31d4c4963916 100644 --- a/packages/common-library/tests/test_error_codes.py +++ b/packages/common-library/tests/test_error_codes.py @@ -4,9 +4,14 @@ # pylint: disable=unused-variable import logging +import time import pytest -from common_library.error_codes import create_error_code, parse_error_code +from common_library.error_codes import ( + create_error_code, + parse_error_code_parts, + parse_error_codes, +) logger = logging.getLogger(__name__) @@ -31,18 +36,31 @@ def test_exception_fingerprint_consistency(): # emulates different runs of the same function (e.g. different sessions) try: _level_one(v) # same even if different value! + time.sleep(0.1) except Exception as err: error_code = create_error_code(err) error_codes.append(error_code) - assert error_codes == [error_codes[0]] * len(error_codes) + fingerprints, timestamps = list( + zip( + *[parse_error_code_parts(error_code) for error_code in error_codes], + strict=True, + ) + ) + + assert fingerprints[0] == fingerprints[1] + assert timestamps[0] < timestamps[1] + time.sleep(0.1) try: # Same function but different location _level_one(0) except Exception as e2: error_code_2 = create_error_code(e2) - assert error_code_2 != error_code[0] + fingerprint_2, timestamp_2 = parse_error_code_parts(error_code_2) + + assert fingerprints[0] != fingerprint_2 + assert timestamps[1] < timestamp_2 def test_create_log_and_parse_error_code(caplog: pytest.LogCaptureFixture): @@ -66,11 +84,11 @@ def test_create_log_and_parse_error_code(caplog: pytest.LogCaptureFixture): logger.exception("Fake Unexpected error", extra={"error_code": error_code}) # logs something like E.g. 2022-07-06 14:31:13,432 OEC:140350117529856 : Fake Unexpected error - assert parse_error_code( + assert parse_error_codes( f"2022-07-06 14:31:13,432 {error_code} : Fake Unexpected error" - ) == { + ) == [ error_code, - } + ] assert caplog.records[0].error_code == error_code assert caplog.records[0] @@ -82,6 +100,6 @@ def test_create_log_and_parse_error_code(caplog: pytest.LogCaptureFixture): f"This is a user-friendly message to inform about an error. [{error_code}]" ) - assert parse_error_code(user_message) == { + assert parse_error_codes(user_message) == [ error_code, - } + ] diff --git a/packages/service-library/tests/aiohttp/test_rest_middlewares.py b/packages/service-library/tests/aiohttp/test_rest_middlewares.py index 81f5f3c628b0..0adfa6cf80dc 100644 --- a/packages/service-library/tests/aiohttp/test_rest_middlewares.py +++ b/packages/service-library/tests/aiohttp/test_rest_middlewares.py @@ -13,7 +13,7 @@ import pytest from aiohttp import web from aiohttp.test_utils import TestClient -from common_library.error_codes import parse_error_code +from common_library.error_codes import parse_error_codes from common_library.json_serialization import json_dumps from servicelib.aiohttp import status from servicelib.aiohttp.rest_middlewares import ( @@ -30,8 +30,7 @@ class Data: y: str = "foo" -class SomeUnexpectedError(Exception): - ... +class SomeUnexpectedError(Exception): ... class Handlers: @@ -237,7 +236,7 @@ async def test_raised_unhandled_exception( # user friendly message with OEC reference assert "OEC" in error["message"] - parsed_oec = parse_error_code(error["message"]).pop() + parsed_oec = parse_error_codes(error["message"]).pop() assert ( _FMSG_INTERNAL_ERROR_USER_FRIENDLY_WITH_OEC.format(error_code=parsed_oec) == error["message"] From 87f69e6845eb5f2b4bcd22451f2fe1fd517ef6c8 Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 18 Mar 2025 18:04:23 +0100 Subject: [PATCH 3/4] drop arrow dependency --- packages/common-library/src/common_library/error_codes.py | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/packages/common-library/src/common_library/error_codes.py b/packages/common-library/src/common_library/error_codes.py index e4759a624af5..342e85937ee2 100644 --- a/packages/common-library/src/common_library/error_codes.py +++ b/packages/common-library/src/common_library/error_codes.py @@ -10,10 +10,9 @@ import hashlib import re import traceback -from datetime import datetime +from datetime import UTC, datetime from typing import Annotated, Final, TypeAlias -import arrow from pydantic import StringConstraints, TypeAdapter _LABEL = "OEC:{fingerprint}-{timestamp}" @@ -49,7 +48,7 @@ def _create_timestamp() -> int: """Timestamp as milliseconds since epoch NOTE: this reduces the precission to milliseconds but it is good enough for our purpose """ - ts = arrow.utcnow().float_timestamp * _MILISECONDS + ts = datetime.now(UTC).timestamp() * _MILISECONDS return int(ts) From 2da9d9a2e7e2fada3498248e1e1f267a5301c09d Mon Sep 17 00:00:00 2001 From: Pedro Crespo-Valero <32402063+pcrespov@users.noreply.github.com> Date: Tue, 18 Mar 2025 18:12:50 +0100 Subject: [PATCH 4/4] rm dependency from arrow and fixed tests --- packages/common-library/src/common_library/error_codes.py | 8 +++++--- packages/common-library/tests/test_error_codes.py | 4 ++-- 2 files changed, 7 insertions(+), 5 deletions(-) diff --git a/packages/common-library/src/common_library/error_codes.py b/packages/common-library/src/common_library/error_codes.py index 342e85937ee2..70829a059ca3 100644 --- a/packages/common-library/src/common_library/error_codes.py +++ b/packages/common-library/src/common_library/error_codes.py @@ -41,14 +41,14 @@ def _create_fingerprint(exc: BaseException) -> str: return hashlib.sha256(fingerprint.encode()).hexdigest()[:_LEN] -_MILISECONDS: Final[int] = 1000 +_SECS_TO_MILISECS: Final[int] = 1000 # ms def _create_timestamp() -> int: """Timestamp as milliseconds since epoch NOTE: this reduces the precission to milliseconds but it is good enough for our purpose """ - ts = datetime.now(UTC).timestamp() * _MILISECONDS + ts = datetime.now(UTC).timestamp() * _SECS_TO_MILISECS return int(ts) @@ -79,5 +79,7 @@ def parse_error_code_parts(oec: ErrorCodeStr) -> tuple[str, datetime]: msg = f"Invalid error code format: {oec}" raise ValueError(msg) fingerprint = match.group("fingerprint") - timestamp = arrow.get(int(match.group("timestamp")) / _MILISECONDS).datetime + timestamp = datetime.fromtimestamp( + float(match.group("timestamp")) / _SECS_TO_MILISECS, tz=UTC + ) return fingerprint, timestamp diff --git a/packages/common-library/tests/test_error_codes.py b/packages/common-library/tests/test_error_codes.py index 31d4c4963916..80f7b8b0808a 100644 --- a/packages/common-library/tests/test_error_codes.py +++ b/packages/common-library/tests/test_error_codes.py @@ -36,8 +36,8 @@ def test_exception_fingerprint_consistency(): # emulates different runs of the same function (e.g. different sessions) try: _level_one(v) # same even if different value! - time.sleep(0.1) except Exception as err: + time.sleep(1) error_code = create_error_code(err) error_codes.append(error_code) @@ -51,11 +51,11 @@ def test_exception_fingerprint_consistency(): assert fingerprints[0] == fingerprints[1] assert timestamps[0] < timestamps[1] - time.sleep(0.1) try: # Same function but different location _level_one(0) except Exception as e2: + time.sleep(1) error_code_2 = create_error_code(e2) fingerprint_2, timestamp_2 = parse_error_code_parts(error_code_2)