Python: log uncaught exceptions with sys.excepthook

You ever notice how when your script dies because of some uncaught error, you don’t get that error in your log files? This post walks through how to make sure that you log that uncaught exception.

This is a trivial script that will raise an uncaught exception (code available here):


    $ cat rgl/kaboom1.py
    # vim: set expandtab ts=4 sw=4 filetype=python:

    import logging

    def f():
        return g()

    def g():
        return h()

    def h():
        return i()

    def i():
        1/0

    if __name__ == '__main__':

        logging.basicConfig(
            level=logging.DEBUG,
            filename='/tmp/kaboom1.log',
            filemode='w')

        logging.debug('About to do f().')

        f()

Notice the helpful traceback:

    $ python rgl/kaboom1.py
    Traceback (most recent call last):
      File "rgl/kaboom1.py", line 28, in <module>
        f()
      File "rgl/kaboom1.py", line 9, in f
        return g()
      File "rgl/kaboom1.py", line 13, in g
        return h()
      File "rgl/kaboom1.py", line 17, in h
        return i()
      File "rgl/kaboom1.py", line 21, in i
        1/0
    ZeroDivisionError: integer division or
    modulo by zero

Unfortunately, that helpful traceback does not show up in the output logs!

    $ cat /tmp/kaboom1.log
    DEBUG:root:About to do f().

You could wrap your code with big try / except

This diaper pattern is a popular solution::


    try:
        f()

    except Exception as ex:
        logging.exception(ex)
        raise

Make sure you re-raise the exception, otherwise your program will end with a zero return code.

Sidenote: how to log an exception instance

If you do any of these, you probably won’t like what you get:


    logging.error(ex)
    logging.error(str(ex))

In both cases, you are just turning the exception to a string. You won’t see the traceback and you won’t see the exception type.

Instead of those, make sure you do one of these:


        logging.exception(ex)

        # this is exactly what logging.exception does inside
        logging.error(ex, exc_info=1) 

        # sets a higher log level than error
        logging.critical(ex, exc_info=1) 

For the last two, without that exc_info=1 parameter, you won’t see the traceback in your logs. You’ll just see the message from the exception.

Or you can use sys.excepthook

Instead of nesting your code inside a try-except clause, you can customize the built-in sys.excepthook function.

The kaboom2.py script has this extra code:


    def log_uncaught_exceptions(ex_cls, ex, tb):

        logging.critical(''.join(traceback.format_tb(tb)))
        logging.critical('{0}: {1}'.format(ex_cls, ex))

    sys.excepthook = log_uncaught_exceptions

And here’s the results:

    $ python rgl/kaboom2.py

    $ cat /tmp/kaboom2.log
    DEBUG:root:About to do f().
    CRITICAL:root:  File "rgl/kaboom2.py", line 39, in <module>
        f()
      File "rgl/kaboom2.py", line 9, in f
        return g()
      File "rgl/kaboom2.py", line 13, in g
        return h()
      File "rgl/kaboom2.py", line 17, in h
        return i()
      File "rgl/kaboom2.py", line 21, in i
        1/0

    CRITICAL:root:<type 'exceptions.ZeroDivisionError'>: integer division or modulo by zero

Incidentally, sys.excepthook preserves the non-zero return code.
Also incidentally, you can use sys.excepthook for all sorts of fun stuff. This shows how to make it fire off pdb when stuff blows up.

  • http://lucumr.pocoo.org/ Armin Ronacher

    Better then that would be logging as “logger.critical('Whatever', exc_info=(exc_type, exc_value, tb))“

  • https://launchpad.net/~flimm Flimm

    One thing to watch out for is that Apport, the crash reporting tool on Ubuntu, overrides sys.excepthook for you already. It does this by including an Apport hook in sitecustomize.py:

    $ python -c &#39;import sys; print repr(sys.excepthook)&#39;<br>&lt;function 0xb71ee87c="" apport_excepthook="" at=""&gt;<br>$ cat /etc/python2.7/<a href="http://sitecustomize.py" rel="nofollow">sitecustomize.py</a> <br># install the apport exception handler if available<br>try:<br>    import apport_python_hook<br>except ImportError:<br>    pass<br>else:<br>    apport_python_hook.install()<br>&lt;/function&gt;

  • Federico

    Full example:
    def log_uncaught_exceptions(*exc_info): 
        logging.critical('Unhandled exception:', exc_info=exc_info) 

  • http://blog.tplus1.com Matt Wilson

    Thanks for the feedback!

  • ??????? ???????

    What is the profit of logging.critical(”.join.traceback.format…. in hook? why not just use logging.exception(ex) oneliner there?

  • yazinsai

    Awesome! Thanks for sharing.. great for catching leaking exceptions without making the codebase all icky..