How do I can format exception stacktraces in Python logging?

Question

The logs I am creating in Python are intended to be temporarily stored as files which will, in turn, be processed into a log database. They take a pipe-delineated format to dictate how the logs will be processed, but logging.exception() is breaking my standard by adding one too many fields and way too many newlines.

import logging
logging.basicConfig(filename='output.txt', 
                    format='%(asctime)s|%(levelname)s|%(message)s|', 
                    datefmt='%m/%d/%Y %I:%M:%S %p', 
                    level=logging.DEBUG)
logging.info('Sample message')

try:
    x = 1 / 0
except ZeroDivisionError as e:
    logging.exception('ZeroDivisionError: {0}'.format(e))

# output.txt
01/27/2015 02:09:01 PM|INFO|Sample message|
01/27/2015 02:09:01 PM|ERROR|ZeroDivisionError: integer division or modulo by zero|
Traceback (most recent call last):
  File "C:\Users\matr06586\Desktop\ETLstage\Python\blahblah.py", line 90, in <module>
    x = 1 / 0
ZeroDivisionError: integer division or modulo by zero

How can I best handle or format tracebacks with the whitespace and newlines? These messages are part and parcel in logging.exception(), but it feels odd to circumvent the function when I am attempting to document instances of exceptions. How do I record my tracebacks and format them too? Should the tracebacks be ignored?

Thank you for your time!

Sudd

Are you asking what you should do, or how to do it? How you want to format the error messages in your log file is up to you. What do you want them to look like? – Biffin

Thanks for clearing that up. Ideally, I could contain the tracebacks as another pipe-delimited attribute on the same line as the rest of the logged message. – Sudd

Answer 1

You can define your own Formatter whose methods you can override to format exception information exactly how you want it. Here is a simplistic (but working) example:

import logging

class OneLineExceptionFormatter(logging.Formatter):
    def formatException(self, exc_info):
        result = super(OneLineExceptionFormatter, self).formatException(exc_info)
        return repr(result) # or format into one line however you want to

    def format(self, record):
        s = super(OneLineExceptionFormatter, self).format(record)
        if record.exc_text:
            s = s.replace('\n', '') + '|'
        return s

fh = logging.FileHandler('output.txt', 'w')
f = OneLineExceptionFormatter('%(asctime)s|%(levelname)s|%(message)s|', '%m/%d/%Y %I:%M:%S %p')
fh.setFormatter(f)
root = logging.getLogger()
root.setLevel(logging.DEBUG)
root.addHandler(fh)
logging.info('Sample message')

try:
    x = 1 / 0
except ZeroDivisionError as e:
    logging.exception('ZeroDivisionError: {0}'.format(e))

This produces just two lines:

01/28/2015 07:28:27 AM|INFO|Sample message|
01/28/2015 07:28:27 AM|ERROR|ZeroDivisionError: integer division or modulo by zero|'Traceback (most recent call last):\n  File "logtest2.py", line 23, in <module>\n    x = 1 / 0\nZeroDivisionError: integer division or modulo by zero'|

Of course, you can build on this example to do precisely what you want, e.g. via the traceback module.

Glossal

Not sure why rewrite of formatException is needed here, it does nothing if doesn't need to wrap traceback with ' ', could you please explain why you rewrite formatException method? thanks – Smorgasbord

@SunKe Because the exception itself may contain newlines and need formatting into a single line. In the specific case it may not be required, but the comment "or format into one line however you want to" indicates where you might need to change things. – Glossal

@VinaySajip Can this be implemented without a file handler? I'm attempting to get a single log line to log to stdout. – Isosteric

@Isosteric Yes - just attach the formatter to a console handler (e.g. a StreamHandler instance). – Glossal

Answer 2

For my usecase Vinay Sajip's code did not work good enough (I worked with more complex message format), so I came up with this one (for me it's also cleaner):

class OneLineExceptionFormatter(logging.Formatter):
    def format(self, record):
        if record.exc_info:
            # Replace record.msg with the string representation of the message
            # use repr() to prevent printing it to multiple lines
            record.msg = repr(super().formatException(record.exc_info))
            record.exc_info = None
            record.exc_text = None
        result = super().format(record)
        return result

So this format() method can detect that an exception is going to be logged and can just convert it to its string representation and formatting of the log message happen simply for that plain message string. I tested it in python 3.

Bub

This method doesn't take into account any arguments from the original logging call. Ex: logging.exception("Unhandled exception when x=%s y=%s", "1", "2") will fail. Formatting is applied after the call to format, so a cheap way to get that in above would be to append the formatException results to record.msg, Ex: record.msg += repr(super().formatException(record.exc_info)) -- but in general I think the accepted answer based on the official docs is better: docs.python.org/3/howto/… – Gehlbach

Answer 3

You should define your own function that uses traceback.extract_tb to format the traceback to the syntax you want and then return it or write it to a file:

traceback.extract_tb(traceback[, limit])

Return a list of up to limit “pre-processed” stack trace entries extracted from the traceback object traceback. It is useful for alternate formatting of stack traces. If limit is omitted or None, all entries are extracted. A “pre-processed” stack trace entry is a 4-tuple (filename, line number, function name, text) representing the information that is usually printed for a stack trace. The text is a string with leading and trailing whitespace stripped; if the source is not available it is None.

https://docs.python.org/2/library/traceback.html

Pascal