Logging the exception calls again the function in which it happened

[pawamoy]

Might be related to #88.

I noticed this issue because my tests (ran with pytest) were breaking when I added a fixture to enable the logger.

Here is some minimal example. I added comments to explain what seems to happen.

class Whatever:
    @property
    def following(self):
        if not self._following:  # self._following initialized to None in __init__
            following_id = "some id"
            try:
                self._following = do_something_with(following_id)
            except SomeException as error:  # triggered
                logger.warning(f"blah blah {following_id}, blah blah blah ({id(self)}")  # this works fine
                logger.opt(exception=True).trace(error)  # this re-enter this very property
                self._following = None  # this code is never reached
        return self._following  # this code is never reached

In the generated log file, I then have 91 lines with the same warning. I tried adding depth=-1 in the opt() parameters, but it changes nothing. The instance of SomeException does not contain any reference to the Whatever instance.

• If I remove the .opt(exception=True) it works fine again (but I get no traceback)
• If I pass the exception directly with logger.opt(exception=error).trace(error) it works as well, but it does not print the traceback.
• If I pass the exception info, with logger.opt(exception=sys.exc_info()).trace(error), it does not work.
• If I only retrieve the exception info with exc_info = sys.exc_info(), without logging it, it works fine (so the issue must come from what loguru does with the exception).

I guess the following property is triggered when inspecting sys.exc_info or something? Is there anything loguru can do about this? If not, I can still pass the exception directly so it's not so bad. It would be interesting to replicate this in a test though.

[pawamoy]

Here is a draft for a test:

def test_exception_in_property(writer):
    logger.add(writer, format="{message}")

    class A:
        @property
        def value(self):
            try:
                1 / 0
            except:
                logger.opt(exception=True).debug("test")
                return None
            else:
                return "never"

    a = A()
    value = a.value

    lines = writer.read().strip().splitlines()

    assert lines[0] == "test"
    assert lines[-1] == "ZeroDivisionError: division by zero"

But I'm not sure it makes sense because if it does not work, it will break the test runner.

[pawamoy]

Issue was coming from better_exceptions_fork 😉 It's actually already solved (well, installing latest version of loguru fixed it, I was still on version 0.2.5).

[Delgan]

Well, I'm glad it has been fixed in more recent release, but I don't really know why... 😄

There was indeed a refactoring of everything related to the exceptions formated. It seems related to the backtracing process fetching previous stack frames.

So, I gonna take the test_exception_in_property() you created and directly copy/paste it to the loguru tests suit. Thanks for that! 😄

[pawamoy]

No problem! I didn't try the test code though ⚠️ ! You might need to update it!

[Delgan]

I tested it and it failed just as expected, while it worked fine with the latest Loguru version. I will update it adequately if needed, thanks again. 👍