Python: log uncaught exceptions with sys.excepthook

Posted on by

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
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
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:: 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.

6 thoughts on “Python: log uncaught exceptions with sys.excepthook”

  2. 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 'import sys; print repr(sys.excepthook)'
    <function 0xb71ee87c="" apport_excepthook="" at="">
    $ cat /etc/python2.7/sitecustomize.py 
    # install the apport exception handler if available
    try:
        import apport_python_hook
    except ImportError:
        pass
    else:
        apport_python_hook.install()
    </function>

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

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

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

Comments are closed.