Logging uncaught exceptions in Python

Question

How do you cause uncaught exceptions to output via the logging module rather than to stderr?

I realize the best way to do this would be:

try:
    raise Exception, 'Throwing a boring exception'
except Exception, e:
    logging.exception(e)

But my situation is such that it would be really nice if logging.exception(...) were invoked automatically whenever an exception isn't caught.

Vola

See also: Can structured logging be done with Pythons standard library? – Mauro

See also: Can I make Python output exceptions in one line / via logging? – Mauro

Great question! You say it's not the best way, but isn't this a common use case when you're prototyping? Eg. want your log file to show which exceptions you forgot to handle (I mean, chose to implement later). I wouldn't put a giant try/except around my main method... – Sternmost

Answer 1

As Ned pointed out, sys.excepthook is invoked every time an exception is raised and uncaught. The practical implication of this is that in your code you can override the default behavior of sys.excepthook to do whatever you want (including using logging.exception).

As a straw man example:

import sys
def foo(exctype, value, tb):
    print('My Error Information')
    print('Type:', exctype)
    print('Value:', value)
    print('Traceback:', tb)

Override sys.excepthook:

>>> sys.excepthook = foo

Commit obvious syntax error (leave out the colon) and get back custom error information:

>>> def bar(a, b)
My Error Information
Type: <type 'exceptions.SyntaxError'>
Value: invalid syntax (<stdin>, line 1)
Traceback: None

For more information about sys.excepthook, read the docs.

Oleary

I assume the function argument type would not work, since it's a reserved keyword..? – Unstrap

@Codemonkey It's not a reserved keyword, it's a preexisting type name. You can use type as a function argument, although IDEs will complain about hiding the global type (much like using var self = this in Javascript). It doesn't really matter unless you need to access the type object inside your function, in which case you can use type_ as the argument instead. – Edifice

The phrase "every time" here is misleading:: "sys.excepthook is invoked every time an exception is raised and uncaught"... because in a program, there can be exactly one "uncaught" exception. Also, sys.excepthook is NOT called when an exception is "raised". It is called when the program is going to terminate due to an uncaught exception, which cannot happen more than once. – Guttering

@Nawaz: it can happen more than once in a REPL – Highboy

@Nawaz It can also happen multiple times if the program is using threads. I've also seem GUI event loops (like Qt) keep running, even though the exception has made it to sys.excepthook – Terti

@Mr.Zeus: Workaround for exactly what problem? – Guttering

@Nawaz That we can't log multiple(all?) errors that are raised. – Pufahl

But if there are errors before the uncaught error how do you log them too? @Nawaz – Pufahl

I tried something like sys.stderr = io.StringIO("") but it didn't work. – Pufahl

Anyone trying to test the above code, make sure that you generate a traceback error while testing your function. SyntaxError are not being handled by sys.excepthook. You can use print(1/0) and this shall invoke the function you have defined to override sys.excepthook – Aulea

What is the type of the parameters of sys.excepthook? – Mauro

Doesn't work in IPython or Spyder python console... but I think this is "normal". Works fine in Python 3.8 console. Also with SyntaxError @ParthKaria – Stefanstefanac

Answer 2

Here's a complete small example that also includes a few other tricks:

import sys
import logging
logger = logging.getLogger(__name__)
handler = logging.StreamHandler(stream=sys.stdout)
logger.addHandler(handler)

def handle_exception(exc_type, exc_value, exc_traceback):
    if issubclass(exc_type, KeyboardInterrupt):
        sys.__excepthook__(exc_type, exc_value, exc_traceback)
        return

    logger.error("Uncaught exception", exc_info=(exc_type, exc_value, exc_traceback))

sys.excepthook = handle_exception

if __name__ == "__main__":
    raise RuntimeError("Test unhandled")

• Ignore KeyboardInterrupt so a console python program can exit with Ctrl + C.

• Rely entirely on python's logging module for formatting the exception.

• Use a custom logger with an example handler. This one changes the unhandled exception to go to stdout rather than stderr, but you could add all sorts of handlers in this same style to the logger object.

Weiman

I would use logger.critical() inside the excepthook handler, since an uncaught exception is pretty critical I would say. – Erwinery

This is the most practical answer IMO. – Micahmicawber

@Weiman thanks for the snippet. In which file would you put this? – Plume

@chefarov The main file where you initialize all other logging – Weiman

Hi, How can we write down to file like debug.log this info. i try it to add line logging.basicConfig(level=logging.DEBUG, filename="debug.log", format='%(asctime)s - %(name)s - %(levelname)s - %(message)s') But didn't help. – Suffix

@Suffix You might want to check out #6387198 – Weiman

What is the type of the parameters of sys.excepthook? Could you add a type annotation to handle_exception? – Mauro

Excellent methodology. For those looking for a method to unit test this, see https://mcmap.net/q/56976/-how-to-write-a-unit-test-for-uncaught-exception-handler – Dichroic

exc_info=(exc_type, exc_value, exc_traceback) this works perfectly when I am logging it to a log file. But if I try to print all the three or save them to variable, they show None. I am trying to send any un-handled exceptions over email instead of dumping to a log file. Any help is appreciated. – Aulea

@Weiman It would be beneficial to note that, if an imported module raises an exception, it may not use your new sys.excepthook (tkinter is one notable example of this behavior). This happens when the module defines its own excepthook. In those cases, you would need to override this excepthook (for tkinter, see https://mcmap.net/q/56977/-python-tkinter-and-imported-classes-logging-uncaught-exceptions) – Dichroic

@ChrisCollett "good" python modules meant to be used as libraries are designed/implemented/tested to not have unpredictable/un-intuitive behavior (changing the global excepthook is something a "good library" python module should IMO avoid). – Selmaselman

This is a great solution and I was wondering if anyone in this thread would be able to apply this to py-shiny's framework? I posted the question here but I thought that this would be a really nice solution for me if someone was able to get this working with py-shiny: #73339522 – Lateshalatest

Answer 3

Why not:

import sys
import logging
import traceback

def log_except_hook(*exc_info):
    text = "".join(traceback.format_exception(*exc_info()))
    logging.error("Unhandled exception: %s", text)

sys.excepthook = log_except_hook

None()

Here is the output with sys.excepthook as seen above:

$ python tb.py
ERROR:root:Unhandled exception: Traceback (most recent call last):
  File "tb.py", line 11, in <module>
    None()
TypeError: 'NoneType' object is not callable

Here is the output with the sys.excepthook commented out:

$ python tb.py
Traceback (most recent call last):
  File "tb.py", line 11, in <module>
    None()
TypeError: 'NoneType' object is not callable

The only difference is that the former has ERROR:root:Unhandled exception: at the beginning of the first line.

Elroy

Another difference is that the former writes the trace to the logging system, so any handlers and formatters you have installed are applied. The latter writes directly to sys.stderr. – Hillel

Error in sys.excepthook: Traceback (most recent call last): File "e:/Programing/pump/core2/SiteManager.py", line 16515, in log_except_hook text = "".join(traceback.format_exception(*exc_info())) TypeError: 'tuple' object is not callable – Erlineerlinna

Answer 4

The method sys.excepthook will be invoked if an exception is uncaught: http://docs.python.org/library/sys.html#sys.excepthook

When an exception is raised and uncaught, the interpreter calls sys.excepthook with three arguments, the exception class, exception instance, and a traceback object. In an interactive session this happens just before control is returned to the prompt; in a Python program this happens just before the program exits. The handling of such top-level exceptions can be customized by assigning another three-argument function to sys.excepthook.

Abampere

Why does it send the exception class? Can't you always get that by calling type on the instance? – Mousetail

What is the type of the parameters of sys.excepthook? – Mauro

Answer 5

In my case (using python 3) when using @Jacinda 's answer the content of the traceback was not printed. Instead, it just prints the object itself: <traceback object at 0x7f90299b7b90>.

Instead I do:

import sys
import logging
import traceback

def custom_excepthook(exc_type, exc_value, exc_traceback):
    # Do not print exception when user cancels the program
    if issubclass(exc_type, KeyboardInterrupt):
        sys.__excepthook__(exc_type, exc_value, exc_traceback)
        return

    logging.error("An uncaught exception occurred:")
    logging.error("Type: %s", exc_type)
    logging.error("Value: %s", exc_value)

    if exc_traceback:
        format_exception = traceback.format_tb(exc_traceback)
        for line in format_exception:
            logging.error(repr(line))

sys.excepthook = custom_excepthook

Marjoram

your answer, specifically traceback,format(tb(exc_traceback) helped me resolve my missing understanding of the difference between traceback the handler and exc_traceback the object. I was trying to use the handler's methods on the object like exc_traceback.format_tb which was obviously not working. Once I knew how to work with the handler and object, it opens up the universe of working with tracebacks! Thanks! – Castara

Thanks - been after something like this for a while! – Giorgione

One oddity .. I found that only the first line got logged ("An uncaught exception occurred:"). I just put all messages/comments I wanted into that single line and I was ok. – Giorgione

Answer 6

To build on Jacinda's answer, but using a logger object:

def catchException(logger, typ, value, traceback):
    logger.critical("My Error Information")
    logger.critical("Type: %s" % typ)
    logger.critical("Value: %s" % value)
    logger.critical("Traceback: %s" % traceback)

# Use a partially applied function
func = lambda typ, value, traceback: catchException(logger, typ, value, traceback)
sys.excepthook = func

Hinojosa

It would be better to use functools.partial() instead of lambda. See: docs.python.org/2/library/functools.html#functools.partial – Nilson

@MariuszJamro why? – Fleabitten

Answer 7

Although @gnu_lorien's answer gave me good starting point, my program crashes on first exception.

I came with a customised (and/or) improved solution, which silently logs Exceptions of functions that are decorated with @handle_error.

import logging

__author__ = 'ahmed'
logging.basicConfig(filename='error.log', level=logging.DEBUG)


def handle_exception(exc_type, exc_value, exc_traceback):
    import sys
    if issubclass(exc_type, KeyboardInterrupt):
        sys.__excepthook__(exc_type, exc_value, exc_traceback)
        return
    logging.critical(exc_value.message, exc_info=(exc_type, exc_value, exc_traceback))


def handle_error(func):
    import sys

    def __inner(*args, **kwargs):
        try:
            return func(*args, **kwargs)
        except Exception, e:
            exc_type, exc_value, exc_tb = sys.exc_info()
            handle_exception(exc_type, exc_value, exc_tb)
        finally:
            print(e.message)
    return __inner


@handle_error
def main():
    raise RuntimeError("RuntimeError")


if __name__ == "__main__":
    for _ in xrange(1, 20):
        main()

Overcautious

Answer 8

Wrap your app entry call in a try...except block so you'll be able to catch and log (and perhaps re-raise) all uncaught exceptions. E.g. instead of:

if __name__ == '__main__':
    main()

Do this:

if __name__ == '__main__':
    try:
        main()
    except Exception as e:
        logger.exception(e)
        raise

Mallett

This is not what question is asking. Intention of the question is to ask what to do when exception is NOT handled by code. – Marquismarquisate

Well, Python is a programming language, and this implies that it don't do things "automatically" (as the OP wants), except if and when you ask it to do it. In other words, there is no way to "automatically" log all exceptions, unless you code for it -- and that's what is in my answer. – Mallett

Well, if you look at Ned Batchelder's answer, there is something called as exception hook. You have to define at one place in your code and all your uncaught exceptions are handled. – Marquismarquisate

The exception hook doesn't change the fact that it is not "automatic" (in the sense the OP wants) -- in other words, you still have to code it. Ned's answer (which use the exception hook) really address the original question -- it's just that, in my opinion, the way it does that is much less pythonic than mine. – Mallett

wrapping your entire code in a try-except block is not a good idea, and if only because it will throw your IDE out of it's debugging routines ... – Wellintentioned

It pretty much depends on your own objectives. If you program to please the IDE, then yes catching all exceptions might not be an option. But if you want to handle errors gracefully, and display nice feedback to the user, then I am afraid that you will need to catch all exceptions. Ok, enough sarcasm :-) -- if you look carefully you will see that the code intercept the exception, but re-raise then, so unless your IDE is doing something "magical" it shouldn't be doing, it will still get the exception. – Mallett

Answer 9

To answer the question from Mr.Zeus discussed in the comment section of the accepted answer, I use this to log uncaught exceptions in an interactive console (tested with PyCharm 2018-2019). I found out sys.excepthook does not work in a python shell so I looked deeper and found that I could use sys.exc_info instead. However, sys.exc_info takes no arguments unlike sys.excepthook that takes 3 arguments.

Here, I use both sys.excepthook and sys.exc_info to log both exceptions in an interactive console and a script with a wrapper function. To attach a hook function to both functions, I have two different interfaces depending if arguments are given or not.

Here's the code:

def log_exception(exctype, value, traceback):
    logger.error("Uncaught exception occurred!",
                 exc_info=(exctype, value, traceback))


def attach_hook(hook_func, run_func):
    def inner(*args, **kwargs):
        if not (args or kwargs):
            # This condition is for sys.exc_info
            local_args = run_func()
            hook_func(*local_args)
        else:
            # This condition is for sys.excepthook
            hook_func(*args, **kwargs)
        return run_func(*args, **kwargs)
    return inner


sys.exc_info = attach_hook(log_exception, sys.exc_info)
sys.excepthook = attach_hook(log_exception, sys.excepthook)

The logging setup can be found in gnu_lorien's answer.

Chintz

Answer 10

Maybe you could do something at the top of a module that redirects stderr to a file, and then logg that file at the bottom

sock = open('error.log', 'w')               
sys.stderr = sock

doSomething() #makes errors and they will log to error.log

logging.exception(open('error.log', 'r').read() )

Derman