Merge pull request #323 from ScatterHQ/stdlib-tracebacks

Stdlib bridge logs tracebacks

Author: itamarst

docs/source/generating/errors.rst

@@ -22,6 +22,16 @@ If you get a completely unexpected exception you may wish to log a traceback to
                  write_traceback()
 
 
+You can also pass in the output of ``sys.exc_info()``:
+
+.. code-block:: python
+
+    import sys
+    from eliot import write_traceback
+
+    write_traceback(exc_info=sys.exc_info())
+
+
 .. _extract errors:
 
 Custom Exception Logging

docs/source/news.rst

@@ -1,6 +1,21 @@
 What's New
 ==========
 
+1.5.0
+^^^^^
+
+Bug fixes:
+
+* The standard library ``logging`` bridge now logs tracebacks, not just messages.
+
+Features:
+
+* You can now pass in an explicit traceback tuple to ``write_traceback``.
+
+Changes:
+
+* The deprecated ``system`` argument to ``write_traceback`` and ``writeFailure`` has been removed.
+
 1.4.0
 ^^^^^
 

docs/source/quickstart.rst

@@ -119,5 +119,6 @@ You can learn more by reading the rest of the documentation, including:
 
 * The :doc:`motivation behind Eliot <introduction>`.
 * How to generate :doc:`actions <generating/actions>`, :doc:`standalone messages <generating/messages>`, and :doc:`handle errors <generating/errors>`.
-* How to integrate with :doc:`asyncio coroutines <generating/asyncio>`, :doc:`threads and processes <generating/threads>`, or :doc:`Twisted <generating/twisted>`.
+* How to integrate or migrate your :doc:`existing stdlib logging messages <generating/migrating>`.
 * How to output logs :doc:`to a file or elsewhere <outputting/output>`.
+* Using :doc:`asyncio coroutines <generating/asyncio>`, :doc:`threads and processes <generating/threads>`, or :doc:`Twisted <generating/twisted>`.

eliot/__init__.py

@@ -17,7 +17,7 @@
     FileDestination,
 )
 from ._validation import Field, fields, MessageType, ActionType
-from ._traceback import writeTraceback, writeFailure
+from ._traceback import write_traceback, writeFailure
 from ._errors import register_exception_extractor
 from ._version import get_versions
 
@@ -37,11 +37,11 @@ def add_destination(destination):
 addDestination = add_destination
 removeDestination = Logger._destinations.remove
 addGlobalFields = Logger._destinations.addGlobalFields
+writeTraceback = write_traceback
 
 # PEP 8 variants:
 start_action = startAction
 start_task = startTask
-write_traceback = writeTraceback
 write_failure = writeFailure
 add_destinations = Logger._destinations.add
 remove_destination = removeDestination

eliot/_errors.py

@@ -45,8 +45,8 @@ def get_fields_for_exception(self, logger, exception):
                 try:
                     return extractor(exception)
                 except:
-                    from ._traceback import writeTraceback
-                    writeTraceback(logger)
+                    from ._traceback import write_traceback
+                    write_traceback(logger)
                     return {}
         return {}
 

eliot/_output.py

@@ -14,7 +14,7 @@
 from . import _bytesjson as bytesjson
 from zope.interface import Interface, implementer
 
-from ._traceback import writeTraceback, TRACEBACK_MESSAGE
+from ._traceback import write_traceback, TRACEBACK_MESSAGE
 from ._message import (
     Message,
     EXCEPTION_FIELD,
@@ -186,7 +186,7 @@ def write(self, dictionary, serializer=None):
             if serializer is not None:
                 serializer.serialize(dictionary)
         except:
-            writeTraceback(self)
+            write_traceback(self)
             msg = Message(
                 {
                     MESSAGE_TYPE_FIELD: "eliot:serialization_failure",
@@ -252,7 +252,7 @@ class MemoryLogger(object):
         L{MemoryLogger.messages}. Do not mutate this list.
 
     @ivar tracebackMessages: A C{list} of messages written to this logger for
-        tracebacks using L{eliot.writeTraceback} or L{eliot.writeFailure}. Do
+        tracebacks using L{eliot.write_traceback} or L{eliot.writeFailure}. Do
         not mutate this list.
     """
 

eliot/_traceback.py

@@ -7,7 +7,6 @@
 
 import traceback
 import sys
-from warnings import warn
 
 from ._message import EXCEPTION_FIELD, REASON_FIELD
 from ._util import safeunicode, load_module
@@ -74,7 +73,7 @@ def lazycache(self, *args, **kwargs):
 _traceback_no_io = _get_traceback_no_io()
 
 
-def writeTraceback(logger=None, system=None):
+def write_traceback(logger=None, exc_info=None):
     """
     Write the latest traceback to the log.
 
@@ -83,20 +82,19 @@ def writeTraceback(logger=None, system=None):
          try:
              dostuff()
          except:
-             writeTraceback(logger)
-    """
-    if system is not None:
-        warn(
-            "The `system` argument to writeTraceback is no longer used.",
-            DeprecationWarning,
-            stacklevel=2)
+             write_traceback(logger)
 
-    typ, exception, tb = sys.exc_info()
+    Or you can pass the result of C{sys.exc_info()} to the C{exc_info}
+    parameter.
+    """
+    if exc_info is None:
+        exc_info = sys.exc_info()
+    typ, exception, tb = exc_info
     traceback = "".join(_traceback_no_io.format_exception(typ, exception, tb))
     _writeTracebackMessage(logger, typ, exception, traceback)
 
 
-def writeFailure(failure, logger=None, system=None):
+def writeFailure(failure, logger=None):
     """
     Write a L{twisted.python.failure.Failure} to the log.
 
@@ -114,12 +112,6 @@ def writeFailure(failure, logger=None, system=None):
 
     @return: None
     """
-    if system is not None:
-        warn(
-            "The `system` argument to writeFailure is no longer used.",
-            DeprecationWarning,
-            stacklevel=2)
-
     # Failure.getBriefTraceback does not include source code, so does not do
     # I/O.
     _writeTracebackMessage(

eliot/stdlib.py

@@ -1,7 +1,9 @@
 """Integration with the standard library ``logging`` package."""
 
 from logging import Handler
+
 from ._message import Message
+from ._traceback import write_traceback
 
 
 class EliotHandler(Handler):
@@ -14,6 +16,8 @@ def emit(self, record):
             logger=record.name,
             message=record.getMessage()
         )
+        if record.exc_info:
+            write_traceback(exc_info=record.exc_info)
 
 
 __all__ = ["EliotHandler"]

eliot/tests/test_output.py

@@ -21,7 +21,7 @@
     MemoryLogger, ILogger, Destinations, Logger, bytesjson as json, to_file,
     FileDestination, _DestinationsSendError)
 from .._validation import ValidationError, Field, _MessageSerializer
-from .._traceback import writeTraceback
+from .._traceback import write_traceback
 from ..testing import assertContainsFields
 
 
@@ -155,14 +155,14 @@ def test_serializeCopies(self):
         logger.serialize()
         self.assertEqual(logger.messages[0]["length"], "abc")
 
-    def writeTraceback(self, logger, exception):
+    def write_traceback(self, logger, exception):
         """
         Write an exception as a traceback to the logger.
         """
         try:
             raise exception
         except:
-            writeTraceback(logger)
+            write_traceback(logger)
 
     def test_tracebacksCauseTestFailure(self):
         """
@@ -171,7 +171,7 @@ def test_tracebacksCauseTestFailure(self):
         """
         logger = MemoryLogger()
         exception = Exception()
-        self.writeTraceback(logger, exception)
+        self.write_traceback(logger, exception)
         self.assertEqual(logger.tracebackMessages[0]["reason"], exception)
 
     def test_flushTracebacksNoTestFailure(self):
@@ -182,7 +182,7 @@ def test_flushTracebacksNoTestFailure(self):
         """
         logger = MemoryLogger()
         exception = RuntimeError()
-        self.writeTraceback(logger, exception)
+        self.write_traceback(logger, exception)
         logger.flushTracebacks(RuntimeError)
         self.assertEqual(logger.tracebackMessages, [])
 
@@ -194,7 +194,7 @@ def test_flushTracebacksReturnsExceptions(self):
         logger = MemoryLogger()
         logger.write({"x": 1})
         for exc in exceptions:
-            self.writeTraceback(logger, exc)
+            self.write_traceback(logger, exc)
         logger.write({"x": 1})
         flushed = logger.flushTracebacks(ZeroDivisionError)
         self.assertEqual(flushed, logger.messages[1:3])
@@ -207,7 +207,7 @@ def test_flushTracebacksUnflushedTestFailure(self):
         """
         logger = MemoryLogger()
         exception = RuntimeError()
-        self.writeTraceback(logger, exception)
+        self.write_traceback(logger, exception)
         logger.flushTracebacks(KeyError)
         self.assertEqual(logger.tracebackMessages[0]["reason"], exception)
 
@@ -218,7 +218,7 @@ def test_flushTracebacksUnflushedUnreturned(self):
         """
         logger = MemoryLogger()
         exception = RuntimeError()
-        self.writeTraceback(logger, exception)
+        self.write_traceback(logger, exception)
         self.assertEqual(logger.flushTracebacks(KeyError), [])
 
     def test_reset(self):

eliot/tests/test_stdlib.py

@@ -2,9 +2,11 @@
 
 from unittest import TestCase
 import logging
+import traceback
 
 from ..testing import assertContainsFields, capture_logging
 from ..stdlib import EliotHandler
+from .test_traceback import assert_expected_traceback
 
 
 class StdlibTests(TestCase):
@@ -18,14 +20,48 @@ def test_handler(self, logger):
         handler = EliotHandler()
         stdlib_logger.addHandler(handler)
         stdlib_logger.info("hello")
-        stdlib_logger.warn("ono")
+        stdlib_logger.warning("ono")
         message = logger.messages[0]
-        assertContainsFields(self, message, {"message_type": "eliot:stdlib",
-                                             "log_level": "INFO",
-                                             "message": "hello",
-                                             "logger": "eliot-test"})
+        assertContainsFields(
+            self, message, {
+                "message_type": "eliot:stdlib",
+                "log_level": "INFO",
+                "message": "hello",
+                "logger": "eliot-test"
+            }
+        )
         message = logger.messages[1]
-        assertContainsFields(self, message, {"message_type": "eliot:stdlib",
-                                             "log_level": "WARNING",
-                                             "message": "ono",
-                                             "logger": "eliot-test"})
+        assertContainsFields(
+            self, message, {
+                "message_type": "eliot:stdlib",
+                "log_level": "WARNING",
+                "message": "ono",
+                "logger": "eliot-test"
+            }
+        )
+
+    @capture_logging(None)
+    def test_traceback(self, logger):
+        """The EliotHandler routes tracebacks to Eliot."""
+        stdlib_logger = logging.getLogger("eliot-test2")
+        stdlib_logger.setLevel(logging.DEBUG)
+        handler = EliotHandler()
+        stdlib_logger.addHandler(handler)
+        try:
+            raise RuntimeError()
+        except Exception as e:
+            exception = e
+            expected_traceback = traceback.format_exc()
+            stdlib_logger.exception("ono")
+        message = logger.messages[0]
+        assertContainsFields(
+            self, message, {
+                "message_type": "eliot:stdlib",
+                "log_level": "ERROR",
+                "message": "ono",
+                "logger": "eliot-test2"
+            }
+        )
+        assert_expected_traceback(
+            self, logger, logger.messages[1], exception, expected_traceback
+        )