Add exc_info support

Author: jteppinette

logfmter/formatter.py

@@ -1,6 +1,12 @@
+import io
 import logging
 import numbers
-from typing import Tuple
+import traceback
+from contextlib import closing
+from types import TracebackType
+from typing import Tuple, Type, cast
+
+ExcInfo = Tuple[Type[BaseException], BaseException, TracebackType]
 
 # Reserved log record attributes cannot be overwritten. They
 # will not included in the formatted log.
@@ -67,6 +73,31 @@ def format_value(cls, value) -> str:
 
         return cls.format_string(str(value))
 
+    @classmethod
+    def format_exc_info(cls, exc_info: ExcInfo) -> str:
+        """
+        Format the provided exc_info into a logfmt formatted string.
+
+        This function should only be used to format exceptions which are
+        currently being handled. Not with those exceptions which are
+        manually passed into the logger. For example:
+
+            try:
+                raise Exception()
+            except Exception:
+                logging.exception()
+        """
+        _type, exc, tb = exc_info
+
+        with closing(io.StringIO()) as sio:
+            traceback.print_exception(_type, exc, tb, None, sio)
+            value = sio.getvalue()
+
+        # Tracebacks have a single trailing newline that we don't need.
+        value = value.rstrip("\n")
+
+        return cls.format_string(value)
+
     @classmethod
     def format_params(cls, params: dict) -> str:
         """
@@ -95,9 +126,12 @@ def format(self, record: logging.LogRecord) -> str:
             extra = self.get_extra(record)
             params = {"msg": record.getMessage(), **extra}
 
-        return " ".join(
-            (
-                "at={}".format(record.levelname),
-                self.format_params(params),
-            )
-        )
+        tokens = ["at={}".format(record.levelname), self.format_params(params)]
+
+        if record.exc_info:
+            # Cast exc_info to its not null variant to make mypy happy.
+            exc_info = cast(ExcInfo, record.exc_info)
+
+            tokens.append("exc_info={}".format(self.format_exc_info(exc_info)))
+
+        return " ".join(tokens)

tests/test_formatter.py

@@ -1,4 +1,5 @@
 import logging
+import sys
 
 import pytest
 
@@ -49,6 +50,23 @@ def test_format_value(value, expected):
     assert Logfmter.format_value(value) == expected
 
 
+def test_format_exc_info():
+    try:
+        raise Exception("alpha")
+    except Exception:
+        exc_info = sys.exc_info()
+
+    value = Logfmter().format_exc_info(exc_info)
+
+    assert value.startswith('"') and value.endswith('"')
+
+    tokens = value.strip('"').split("\\n")
+
+    assert len(tokens) == 4
+    assert "Traceback (most recent call last):" in tokens
+    assert "Exception: alpha" in tokens
+
+
 @pytest.mark.parametrize(
     "value,expected",
     [({"a": 1}, "a=1"), ({"a": 1, "b": 2}, "a=1 b=2"), ({"a": " "}, 'a=" "')],
@@ -79,6 +97,20 @@ def test_get_extra(record, expected):
         ({"levelname": "INFO", "msg": "test", "a": 1}, "at=INFO msg=test a=1"),
         # All parameter values will be passed through the format pipeline.
         ({"levelname": "INFO", "msg": "="}, 'at=INFO msg="="'),
+        # Any existing exc_info will be appropriately formatted and
+        # added to the log output.
+        (
+            {
+                "levelname": "INFO",
+                "msg": "alpha",
+                "exc_info": (
+                    Exception,
+                    Exception("alpha"),
+                    None,
+                ),  # We don't pass a traceback, because they are difficult to fake.
+            },
+            'at=INFO msg=alpha exc_info="Exception: alpha"',
+        ),
     ],
 )
 def test_format(record, expected):