logging.warn() add stacktrace

Question

There are several logging.warn('....') calls in the legacy code base I am working on today.

I want to understand the log output better. Up to now logging.warn() does emit one line. But this single line is not enough to understand the context.

I would like to see the stacktrace of the interpreter.

Since there are a lot of logging.warn('....') lines in my code, I would like to leave them like they are and only modify the configuration of the logging.

How can I add the interpreter stacktrace to every warn() or error() call automatically?

I know that logging.exception("message") shows the stacktrace, but I would like to leave the logging.warn() lines untouched.

Answer 1

The answer I was looking for was given by @Martijn Pieters♦ in the comments

In python 3.x

logger.warning(f'{error_message}', stack_info=True)

does exactly what you need.

Thanks @Martijn Pieters♦

Answer 2

it is trivial if you accept to add a log handler:

import logging
import traceback


class WarnWithStackHandler(logging.StreamHandler):
    def emit(self, record):
        if record.levelno == logging.WARNING:
            stack = traceback.extract_stack()
            # skip logging internal stacks
            stack = stack[:-7]
            for line in traceback.format_list(stack):
                print(line, end='')
        super().emit(record)

Answer 3

I don't believe a handler is your solution. Go for a filter:

import os.path
import traceback
import logging
_LOGGING_FILE = os.path.normcase(logging.addLevelName.__code__.co_filename)
_CURRENT_FILE = os.path.normcase(__file__)
_ELIMINATE_STACK = (_CURRENT_FILE, _LOGGING_FILE)


class AddStackFilter(logging.Filter):
    def __init__(self, levels=None):
        self.levels = levels or set()

    def get_stack(self):
        # Iterator over file names
        filenames = iter(_ELIMINATE_STACK)
        filename = next(filenames, "")
        frames = traceback.walk_stack(None)

        # Walk up the frames
        for frame, lineno in frames:

            # If frame is not from file, continue on to the next file
            while os.path.normcase(frame.f_code.co_filename) != filename:
                filename = next(filenames, None)
                if filename is None:
                    break
            else:
                # It's from the given file, go up a frame
                continue

            # Finished iterating over all files
            break

        # No frames left
        else:
            return None

        info = traceback.format_stack(frame)
        info.insert(0, 'Stack (most recent call last):\n')

        # Remove last newline
        info[-1] = info[-1].rstrip()

        return "".join(info)

    def filter(self, record):
        if record.levelno in self.levels:
            sinfo = self.get_stack()
            if sinfo is not None:
                record.stack_info = sinfo

        return True

This filter has numerous advantages:

1. Removes stack frames from the local file and logging's file.
2. Leaves stack frames in case we come back to the local file after passing through logging. Important if we wish to use the same module for other stuff.
3. You can attach it to any handler or logger, doesn't bind you to StreamHandler or any other handler.
4. You can affect multiple handlers using the same filter, or a single handler, your choice.
5. The levels are given as an __init__ variable, allowing you to add more levels as needed.
6. Allows you to add the stack trace to the log, and not just print.
7. Plays well with the logging module, putting the stack in the correct place, nothing unexpected.

Usage:

>>> import stackfilter
>>> import logging
>>> sfilter = stackfilter.AddStackFilter(levels={logging.WARNING})
>>> logging.basicConfig()
>>> logging.getLogger().addFilter(sfilter)
>>> def testy():
...     logging.warning("asdasd")
...
>>> testy()
WARNING:root:asdasd
Stack (most recent call last):
  File "<stdin>", line 1, in <module>
  File "<stdin>", line 2, in testy