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

* Handle Logger.exception() outside "except" block

Fixes: hynek#634

* Continue fixing

* Try a more radical approach to fix _figure_out_exc_info()

The main problem of the function is that *v* can really be anything
(depending on what the users) do and the annotated return type did not
properly match it (e.g., if *v* was "0", the return value would be "0").

The function now rigorously checks the user input and either returns
the desired result (an exc info tuple) or None.  This makes it easier
and safer to use this function.

* Revert hynek#657

The changes introduced in hynek#657 are no longer needed since
_format_exception() is now only called if _figure_out_exc_info() detects
an actual exception

* Simplify branch condition

* Apply suggestions from code review

Co-authored-by: Hynek Schlawack <hs@ox.cx>

* Add changelog entry

Also remove the entry for the now obsolete hynek#657

---------

Co-authored-by: Hynek Schlawack <hs@ox.cx>

Author: sscherfke

CHANGELOG.md

@@ -30,9 +30,14 @@ You can find our backwards-compatibility policy [here](https://github.com/hynek/
 
 ## Fixed
 
-- `structlog.traceback.ExceptionDictTransformer` now correctly handles missing exceptions.
-
-  [#657](https://github.com/hynek/structlog/pull/657)
+- Fix handling calls to `{logger}.exception()` outside of exception blocks.
+  Depending on the structlog configuration,
+  this either resulted in an event dict key `exception: "MISSING"` or lead to an error.
+  Now, an invalid or missing `exc_info` will just be ignored.
+  This means, that calling `{logger}.exception()` outside of an exception block is basically the same as calling `{logger}.error()`.
+
+  [#634](https://github.com/hynek/structlog/issues/634)
+  [#680](https://github.com/hynek/structlog/pull/680)
 
 - Instantiating `structlog.dev.ConsoleRenderer` does not mutate the passed *styles* dict anymore.
 

src/structlog/_frames.py

@@ -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)

src/structlog/dev.py

@@ -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(

src/structlog/processors.py

@@ -19,7 +19,7 @@
 import threading
 import time
 
-from types import FrameType
+from types import FrameType, TracebackType
 from typing import (
     Any,
     Callable,
@@ -28,6 +28,7 @@
     NamedTuple,
     Sequence,
     TextIO,
+    cast,
 )
 
 from ._frames import (
@@ -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__ = [
@@ -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
 
@@ -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:

src/structlog/tracebacks.py

@@ -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
@@ -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,

tests/processors/test_renderers.py

@@ -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):
         """
@@ -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})

tests/test_dev.py

@@ -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):

tests/test_tracebacks.py

@@ -15,6 +15,8 @@
 
 import pytest
 
+import structlog
+
 from structlog import tracebacks
 
 
@@ -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:
+        """
+        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