CODEWITHSUNDEEP
pythonexceptionpython-logging
karlicoss
karlicoss

Reputation: 2549

Why doesn't python logging.exception method log traceback by default?

When writing defensive code in python (e.g. you're handling some user input or whatever), I find it useful to return Exception objects alongside regular computation results, so they can be discarded/logged or processed in some other way. Consider the following snippet:

import logging
from traceback import TracebackException
from typing import Union

logging.basicConfig(level=logging.INFO)


def _compute(x) -> int:
    return len(x)


def compute(x) -> Union[int, Exception]:
    try:
        return _compute(x)
    except Exception as e:
        return e


inputs = [
    'whatever',
    1,
    'ooo',
    None,
]


outputs = []
for i in inputs:
    r = compute(i)
    outputs.append(r)


for i, r in zip(inputs, outputs):
    logging.info('compute(%s)', i)
    if isinstance(r, Exception):
        logging.exception(r)
    else:
        logging.info(r)

This results in the following output

INFO:root:compute(whatever)
INFO:root:8
INFO:root:compute(1)
ERROR:root:object of type 'int' has no len()
NoneType: None
INFO:root:compute(ooo)
INFO:root:3
INFO:root:compute(None)
ERROR:root:object of type 'NoneType' has no len()
NoneType: None

So you can see that useful exception information like stacktrace is lost, which makes it a bit hard to debug the cause of exception.

This can be fixed by logging exception as logging.exception(r, exc_info=r):

INFO:root:compute(whatever)
INFO:root:8
INFO:root:compute(1)
ERROR:root:object of type 'int' has no len()
Traceback (most recent call last):
  File "/tmp/test.py", line 15, in compute
    return _compute(x)
  File "/tmp/test.py", line 10, in _compute
    return len(x)
TypeError: object of type 'int' has no len()
INFO:root:compute(ooo)
INFO:root:3
INFO:root:compute(None)
ERROR:root:object of type 'NoneType' has no len()
Traceback (most recent call last):
  File "/tmp/test.py", line 15, in compute
    return _compute(x)
  File "/tmp/test.py", line 10, in _compute
    return len(x)
TypeError: object of type 'NoneType' has no len()

My question is -- why doesn't logging.exception method do this by default, if the argument passed to it happens to be an Exception? I tried searching in PEPs/etc but wasn't really fruitful.

My only guess is that logging.exception is essentially just a special case of logging.error, so in principle logging.exception method doesn't know whether is' passed an Exception object or something else. So supporting this would require some code, e.g. checking whether isinstance(msg, Exception), and perhaps the authors of logging library decided it's a bit too specific. But IMO it makes sense considering in practice in most cases logging.exception is passed an Exception object.

Upvotes: 1

Views: 756

Answers (2)

karlicoss
karlicoss

Reputation: 2549

While it still doesn't answer the question why, I came up with a workaround:

You can define a Filter object that automatically adds exc_info to any exceptions, regardless whether they are called from the exception handler or not.

class AddExceptionTraceback(logging.Filter):
    def filter(self, record):
        s = super().filter(record)
        if s is False:
            return False
        if record.levelname == 'ERROR':
            exc = record.msg
            if isinstance(exc, BaseException):
                if record.exc_info is None or record.exc_info == (None, None, None):
                    exc_info = (type(exc), exc, exc.__traceback__)
                    record.exc_info = exc_info
        return s

logger.addFilter(AddExceptionTraceback())

I used it for a while now without any issues whatsoever, so maybe it'd help someone else.

Upvotes: 0

user2357112
user2357112

Reputation: 281604

logging.exception does log the traceback by default. However, you're using it wrong. As the docs say,

This function should only be called from an exception handler.

logging.exception does not expect to be passed an exception instance, or any sort of exception information whatsoever. It uses sys.exc_info to gather info about the exception currently being handled, which only works if an exception is currently being handled. If you call it outside of an exception handler, it breaks.

Upvotes: 2

Related Questions