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

Handle Logger.exception() outside "except" block #680

Merged
merged 10 commits into from
Jan 5, 2025
10 changes: 0 additions & 10 deletions src/structlog/_frames.py
Original file line number Diff line number Diff line change
Expand Up @@ -16,22 +16,12 @@
from .typing import ExcInfo


def is_missing_exc_info(exc_info: ExcInfo) -> bool:
"""
Return True if exc_info is the missing value.
"""
return exc_info == (None, None, None) # type: ignore[comparison-overlap]


def _format_exception(exc_info: ExcInfo) -> str:
"""
Prettyprint an `exc_info` tuple.

Shamelessly stolen from stdlib's logging module.
"""
if is_missing_exc_info(exc_info):
return "MISSING"

sio = StringIO()

traceback.print_exception(exc_info[0], exc_info[1], exc_info[2], None, sio)
Expand Down
6 changes: 2 additions & 4 deletions src/structlog/dev.py
Original file line number Diff line number Diff line change
Expand Up @@ -733,11 +733,9 @@ def __call__(
if exc_info or exc is not None:
sio.write("\n\n" + "=" * 79 + "\n")

exc_info = _figure_out_exc_info(exc_info)
if exc_info:
exc_info = _figure_out_exc_info(exc_info)

if exc_info != (None, None, None):
self._exception_formatter(sio, exc_info)
self._exception_formatter(sio, exc_info)
elif exc is not None:
if self._exception_formatter is not plain_traceback:
warnings.warn(
Expand Down
39 changes: 26 additions & 13 deletions src/structlog/processors.py
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,7 @@
import threading
import time

from types import FrameType
from types import FrameType, TracebackType
from typing import (
Any,
Callable,
Expand All @@ -28,6 +28,7 @@
NamedTuple,
Sequence,
TextIO,
cast,
)

from ._frames import (
Expand All @@ -38,7 +39,12 @@
from ._log_levels import NAME_TO_LEVEL, add_log_level
from ._utils import get_processname
from .tracebacks import ExceptionDictTransformer
from .typing import EventDict, ExceptionTransformer, ExcInfo, WrappedLogger
from .typing import (
EventDict,
ExceptionTransformer,
ExcInfo,
WrappedLogger,
)


__all__ = [
Expand Down Expand Up @@ -407,11 +413,9 @@ def __init__(
def __call__(
self, logger: WrappedLogger, name: str, event_dict: EventDict
) -> EventDict:
exc_info = event_dict.pop("exc_info", None)
exc_info = _figure_out_exc_info(event_dict.pop("exc_info", None))
if exc_info:
event_dict["exception"] = self.format_exception(
_figure_out_exc_info(exc_info)
)
event_dict["exception"] = self.format_exception(exc_info)

return event_dict

Expand Down Expand Up @@ -586,21 +590,30 @@ def __call__(
return event_dict


def _figure_out_exc_info(v: Any) -> ExcInfo:
def _figure_out_exc_info(v: Any) -> ExcInfo | None:
"""
Depending on the Python version will try to do the smartest thing possible
to transform *v* into an ``exc_info`` tuple.
Try to convert *v* into an ``exc_info`` tuple.

Return ``None`` if *v* does not represent an exception or if there is no
current exception.
"""
if isinstance(v, BaseException):
return (v.__class__, v, v.__traceback__)

if isinstance(v, tuple):
return v
if isinstance(v, tuple) and len(v) == 3:
has_type = isinstance(v[0], type) and issubclass(v[0], BaseException)
has_exc = isinstance(v[1], BaseException)
has_tb = v[2] is None or isinstance(v[2], TracebackType)
if has_type and has_exc and has_tb:
return v

if v:
return sys.exc_info() # type: ignore[return-value]
result = sys.exc_info()
if result == (None, None, None):
return None
return cast(ExcInfo, result)

return v
return None


class ExceptionPrettyPrinter:
Expand Down
4 changes: 0 additions & 4 deletions src/structlog/tracebacks.py
Original file line number Diff line number Diff line change
Expand Up @@ -22,8 +22,6 @@
from types import ModuleType, TracebackType
from typing import Any, Iterable, Sequence, Tuple, Union

from ._frames import is_missing_exc_info


try:
import rich
Expand Down Expand Up @@ -418,8 +416,6 @@ def __init__(
self.use_rich = use_rich

def __call__(self, exc_info: ExcInfo) -> list[dict[str, Any]]:
if is_missing_exc_info(exc_info):
return []
trace = extract(
*exc_info,
show_locals=self.show_locals,
Expand Down
8 changes: 3 additions & 5 deletions tests/processors/test_renderers.py
Original file line number Diff line number Diff line change
Expand Up @@ -514,12 +514,12 @@ def test_nop_missing(self):

def test_formats_tuple(self):
"""
If exc_info is a tuple, it is used.
If exc_info is an arbitrary 3-tuple, it is not used.
"""
formatter = ExceptionRenderer(lambda exc_info: exc_info)
d = formatter(None, None, {"exc_info": (None, None, 42)})

assert {"exception": (None, None, 42)} == d
assert {} == d

def test_gets_exc_info_on_bool(self):
"""
Expand Down Expand Up @@ -580,6 +580,4 @@ def test_no_exception(self, ei):
"""
A missing exception does not blow up.
"""
assert {"exception": "MISSING"} == format_exc_info(
None, None, {"exc_info": ei}
)
assert {} == format_exc_info(None, None, {"exc_info": ei})
5 changes: 1 addition & 4 deletions tests/test_dev.py
Original file line number Diff line number Diff line change
Expand Up @@ -545,10 +545,7 @@ def test_no_exception(self):
r = dev.ConsoleRenderer(colors=False)

assert (
"hi"
== r(
None, None, {"event": "hi", "exc_info": (None, None, None)}
).rstrip()
"hi" == r(None, None, {"event": "hi", "exc_info": None}).rstrip()
)

def test_columns_warns_about_meaningless_arguments(self, recwarn):
Expand Down
75 changes: 70 additions & 5 deletions tests/test_tracebacks.py
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,8 @@

import pytest

import structlog

from structlog import tracebacks


Expand Down Expand Up @@ -772,12 +774,75 @@ def test_json_traceback_value_error(
tracebacks.ExceptionDictTransformer(**kwargs)


def test_exception_dict_transformer_missing_exc_info():
class TestLogException:
"""
ExceptionDictTransformer returns an empty list if exc_info is missing.
Higher level integration tests for `Logger.exception()`.
"""
transformer = tracebacks.ExceptionDictTransformer()

result = transformer(exc_info=(None, None, None))
@pytest.fixture
def cap_logs(self) -> structlog.testing.LogCapture:
sscherfke marked this conversation as resolved.
Show resolved Hide resolved
"""
Create a LogCapture to be used as processor and fixture for retrieving
logs in tests.
"""
return structlog.testing.LogCapture()

@pytest.fixture
def logger(
self, cap_logs: structlog.testing.LogCapture
) -> structlog.Logger:
"""
Create a logger with the dict_tracebacks and a LogCapture processor.
"""
old_processors = structlog.get_config()["processors"]
structlog.configure([structlog.processors.dict_tracebacks, cap_logs])
logger = structlog.get_logger("dict_tracebacks")
try:
yield logger
finally:
structlog.configure(processors=old_processors)

def test_log_explicit_exception(
self, logger: structlog.Logger, cap_logs: structlog.testing.LogCapture
) -> None:
"""
The log row contains a traceback when `Logger.exception()` is
explicitly called with an exception instance.
"""
try:
1 / 0
except ZeroDivisionError as e:
logger.exception("onoes", exception=e)

log_row = cap_logs.entries[0]

assert log_row["exception"][0]["exc_type"] == "ZeroDivisionError"

def test_log_implicit_exception(
self, logger: structlog.Logger, cap_logs: structlog.testing.LogCapture
) -> None:
"""
The log row contains a traceback when `Logger.exception()` is called
in an `except` block but without explicitly passing the exception.
"""
try:
1 / 0
except ZeroDivisionError:
logger.exception("onoes")

log_row = cap_logs.entries[0]

assert log_row["exception"][0]["exc_type"] == "ZeroDivisionError"

def test_no_exception(
self, logger: structlog.Logger, cap_logs: structlog.testing.LogCapture
) -> None:
"""
`Logger.exception()` should not be called outside an `except` block
but this cases is gracefully handled and does not lead to an exception.

See: https://github.com/hynek/structlog/issues/634
"""
logger.exception("onoes")

assert [] == result
assert [{"event": "onoes", "log_level": "error"}] == cap_logs.entries
Loading