From 2718257fe1a393184e0e6e9222d93efa2193a95e Mon Sep 17 00:00:00 2001 From: Delgan Date: Thu, 31 Aug 2023 20:22:18 +0200 Subject: [PATCH] Revert "Fix errors due to non-unpicklable Exception when "enqueue=True"" This reverts commit 4c8ebe267b82c4e97e2a2e7821b571199218e44d. --- CHANGELOG.rst | 3 +- loguru/_recattrs.py | 29 ++++++----------- tests/test_add_option_enqueue.py | 53 +++++++++++++++++++++++--------- 3 files changed, 49 insertions(+), 36 deletions(-) diff --git a/CHANGELOG.rst b/CHANGELOG.rst index e1e209764..4fdbfc60e 100644 --- a/CHANGELOG.rst +++ b/CHANGELOG.rst @@ -5,8 +5,7 @@ - Add support for true colors on Windows using ANSI/VT console when available (`#934 `_, thanks `@tunaflsh `_). - Fix file possibly rotating too early or too late when re-starting an application around midnight (`#894 `_). - Fix inverted ``""`` and ``""`` color tags (`#943 `_, thanks `@tunaflsh `_). -- Fix possible untraceable errors raised when logging non-unpicklable ``Exception`` instances while using ``enqueue=True`` (`#329 `_). -- Fix possible errors raised when logging non-picklable ``Exception`` instances while using ``enqueue=True`` (`#342 `_, thanks `@ncoudene `_). +- Fix possible errors raised by logging non-picklable ``Exception`` instances while using ``enqueue=True`` (`#342 `_, thanks `@ncoudene `_). - Fix missing seconds and microseconds when formatting timezone offset that requires such accuracy (`#961 `_). - Raise ``ValueError`` if an attempt to use nanosecond precision for time formatting is detected (`#855 `_). diff --git a/loguru/_recattrs.py b/loguru/_recattrs.py index b09426efb..2e9cab719 100644 --- a/loguru/_recattrs.py +++ b/loguru/_recattrs.py @@ -64,27 +64,16 @@ def __repr__(self): return "(type=%r, value=%r, traceback=%r)" % (self.type, self.value, self.traceback) def __reduce__(self): - # The traceback is not picklable, therefore it needs to be removed. Additionally, there's a - # possibility that the exception value is not picklable either. In such cases, we also need - # to remove it. This is done for user convenience, aiming to prevent error logging caused by - # custom exceptions from third-party libraries. If the serialization succeeds, we can reuse - # the pickled value later for optimization (so that it's not pickled twice). It's important - # to note that custom exceptions might not necessarily raise a PickleError, hence the - # generic Exception catch. + # The traceback is not picklable so we need to remove it. Also, some custom exception + # values aren't picklable either. For user convenience, we try first to serialize it and + # we remove the value in case or error. As an optimization, we could have re-used the + # dumped value during unpickling, but this requires using "pickle.loads()" which is + # flagged as insecure by some security tools. + # __reduce__ function does not alway raise PickleError. Multidict, for example, raise + # TypeError. To manage all the cases, we catch Exception. try: - pickled_value = pickle.dumps(self.value) + pickle.dumps(self.value) except Exception: return (RecordException, (self.type, None, None)) else: - return (RecordException._from_pickled_value, (self.type, pickled_value, None)) - - @classmethod - def _from_pickled_value(cls, type_, pickled_value, traceback_): - try: - # It's safe to use "pickle.loads()" in this case because the pickled value is generated - # by the same code and is not coming from an untrusted source. - value = pickle.loads(pickled_value) - except Exception: - return cls(type_, None, traceback_) - else: - return cls(type_, value, traceback_) + return (RecordException, (self.type, self.value, None)) diff --git a/tests/test_add_option_enqueue.py b/tests/test_add_option_enqueue.py index c59d6facf..9810d34ca 100644 --- a/tests/test_add_option_enqueue.py +++ b/tests/test_add_option_enqueue.py @@ -34,14 +34,6 @@ def __setstate__(self, state): raise pickle.UnpicklingError("You shall not de-serialize me!") -class NotUnpicklableTypeError: - def __getstate__(self): - return "..." - - def __setstate__(self, state): - raise TypeError("You shall not de-serialize me!") - - class NotWritable: def write(self, message): if "fail" in message.record["extra"]: @@ -105,6 +97,24 @@ def test_caught_exception_queue_put(writer, capsys): assert lines[-1] == "--- End of logging error ---" +def test_caught_exception_queue_put_typerror(writer, capsys): + logger.add(writer, enqueue=True, catch=True, format="{message}") + + logger.info("It's fine") + logger.bind(broken=NotPicklableTypeError()).info("Bye bye...") + logger.info("It's fine again") + logger.remove() + + out, err = capsys.readouterr() + lines = err.strip().splitlines() + assert writer.read() == "It's fine\nIt's fine again\n" + assert out == "" + assert lines[0] == "--- Logging error in Loguru Handler #0 ---" + assert re.match(r"Record was: \{.*Bye bye.*\}", lines[1]) + assert lines[-2].endswith("TypeError: You shall not serialize me!") + assert lines[-1] == "--- End of logging error ---" + + def test_caught_exception_queue_get(writer, capsys): logger.add(writer, enqueue=True, catch=True, format="{message}") @@ -156,6 +166,22 @@ def test_not_caught_exception_queue_put(writer, capsys): assert err == "" +def test_not_caught_exception_queue_put_typeerror(writer, capsys): + logger.add(writer, enqueue=True, catch=False, format="{message}") + + logger.info("It's fine") + + with pytest.raises(TypeError, match=r"You shall not serialize me!"): + logger.bind(broken=NotPicklableTypeError()).info("Bye bye...") + + logger.remove() + + out, err = capsys.readouterr() + assert writer.read() == "It's fine\n" + assert out == "" + assert err == "" + + def test_not_caught_exception_queue_get(writer, capsys): logger.add(writer, enqueue=True, catch=False, format="{message}") @@ -248,8 +274,7 @@ def slow_sink(message): assert err == "".join("%d\n" % i for i in range(10)) -@pytest.mark.parametrize("exception_value", [NotPicklable(), NotPicklableTypeError()]) -def test_logging_not_picklable_exception(exception_value): +def test_logging_not_picklable_exception(): exception = None def sink(message): @@ -259,7 +284,7 @@ def sink(message): logger.add(sink, enqueue=True, catch=False) try: - raise ValueError(exception_value) + raise ValueError(NotPicklable()) except Exception: logger.exception("Oups") @@ -271,8 +296,8 @@ def sink(message): assert traceback_ is None -@pytest.mark.parametrize("exception_value", [NotUnpicklable(), NotUnpicklableTypeError()]) -def test_logging_not_unpicklable_exception(exception_value): +@pytest.mark.skip(reason="No way to safely deserialize exception yet") +def test_logging_not_unpicklable_exception(): exception = None def sink(message): @@ -282,7 +307,7 @@ def sink(message): logger.add(sink, enqueue=True, catch=False) try: - raise ValueError(exception_value) + raise ValueError(NotUnpicklable()) except Exception: logger.exception("Oups")