Your Web News in One Place

Help Webnuz

Referal links:

Sign up for GreenGeeks web hosting
April 3, 2022 08:24 pm GMT

Logging in Python Command Line Applications

Introduction

Logging is a necessary part of any serious application. It allows you and your users to effectively debug issues. In this article, I will showcase a good way to configure logging for command-line python apps. You can see the finished product as a github gist here.

Goal

The goal of our logger will have multiple parts:

  1. Make the console output pretty and easy to read by a human
  2. Save additional output to a log file that can be parsed by a computer
  3. Save all traceback information for debugging later
  4. Allow users to change the verbosity of the console and log file output

We are going to make the console output look like this:

Image description

And the log file look like this:

DEBUG:2022-04-03 15:41:17,920:root:A debug messageINFO:2022-04-03 15:41:17,920:root:An info messageWARNING:2022-04-03 15:41:17,920:root:A warning messageERROR:2022-04-03 15:41:17,920:root:An error messageCRITICAL:2022-04-03 15:41:17,920:root:A critical message from an exception    Traceback (most recent call last):        /home/eb/projects/py-scratch/color-log.py  <module>  327: raise ValueError("A critical message from an exception")    ValueError: A critical message from an exception

We've got a few tricky things going on here.

  1. We are using different colors and formats based on the log level
  2. We are using different formats for the console and file output
  3. We are changing the traceback format

Formatter

The python logging formatter does not allow different format strings based on the log level, so we will need to implement our own formatter.

import typing as tclass MultiFormatter(PrettyExceptionFormatter):    """Format log messages differently for each log level"""    def __init__(self, formats: t.Dict[int, str] = None, **kwargs):        base_format = kwargs.pop("fmt", None)        super().__init__(base_format, **kwargs)        formats = formats or default_formats        self.formatters = {            level: PrettyExceptionFormatter(fmt, **kwargs)            for level, fmt in formats.items()        }    def format(self, record: logging.LogRecord):        formatter = self.formatters.get(record.levelno)        if formatter is None:            return super().format(record)        return formatter.format(record)

In our MultiFormatter class, we take a mapping of log level to a format string, then create different formatters for each level. In .format(), we dispatch to the formatter for the level logged.

Now, what is PrettyExceptionFormatter? We also need to implement that. It will format the traceback and exception information when it is included in the log record.

from textwrap import indentfrom pretty_traceback.formatting import exc_to_traceback_strclass PrettyExceptionFormatter(logging.Formatter):    """Uses pretty-traceback to format exceptions"""    def __init__(self, *args, color=True, **kwargs) -> None:        super().__init__(*args, **kwargs)        self.color = color    def formatException(self, ei):        _, exc_value, traceback = ei        return exc_to_traceback_str(exc_value, traceback, color=self.color)    def format(self, record: logging.LogRecord):        record.message = record.getMessage()        if self.usesTime():            record.asctime = self.formatTime(record, self.datefmt)        s = self.formatMessage(record)        if record.exc_info:            # Don't assign to exc_text here, since we don't want to inject color all the time            if s[-1:] != "
": s += "
" # Add indent to indicate the traceback is part of the previous message text = indent(self.formatException(record.exc_info), " " * 4) s += text return s

We're using the awesome pretty-traceback package here. Since the default behavior of logging.Formatter is to modify the record.exc_text with the output of .formatException(), we need to override that behavior. This is because we are adding ANSI color, and don't want to see that in log files.

In the standard logging.Formatter implementation, the record is modified when formatting exceptions (as of python 3.10.2):

def format(self, record):    ...    # exc_text is MODIFIED, which propagates to other formatters for other handlers    record.exc_text = self.formatException(record.exc_info)    ...    return s

The MultiFormatter class takes an argument to change the format string per-level, with the default strings as follows:

default_formats = {    logging.DEBUG: style("DEBUG", fg="cyan") + " | " + style("%(message)s", fg="cyan"),    logging.INFO: "%(message)s",    logging.WARNING: style("WARN ", fg="yellow") + " | " + style("%(message)s", fg="yellow"),    logging.ERROR: style("ERROR", fg="red") + " | " + style("%(message)s", fg="red"),    logging.CRITICAL: style("FATAL", fg="white", bg="red", bold=True) + " | " + style("%(message)s", fg="red", bold=True),}

This adds a vertical line between the level name and message, except for info messages, which are passed through as plain messages. The style function here is a direct copy of the click.style utility.

Context Managers

The end goal here is to simply call with cli_log_config():, and get beautiful output. We will need some context managers. Starting with a logging context, straight from the python docs:

class LoggingContext:    def __init__(        self,        logger: logging.Logger = None,        level: int = None,        handler: logging.Handler = None,        close: bool = True,    ):        self.logger = logger or logging.root        self.level = level        self.handler = handler        self.close = close    def __enter__(self):        if self.level is not None:            self.old_level = self.logger.level            self.logger.setLevel(self.level)        if self.handler:            self.logger.addHandler(self.handler)    def __exit__(self, *exc_info):        if self.level is not None:            self.logger.setLevel(self.old_level)        if self.handler:            self.logger.removeHandler(self.handler)        if self.handler and self.close:            self.handler.close()

Next, we create a special context manager to combine multiple context managers dynamically:

class MultiContext:    """Can be used to dynamically combine context managers"""    def __init__(self, *contexts) -> None:        self.contexts = contexts    def __enter__(self):        return tuple(ctx.__enter__() for ctx in self.contexts)    def __exit__(self, *exc_info):        for ctx in self.contexts:            ctx.__exit__(*exc_info)

Finally, we can combine everything we've done so far into a single context manager:

def cli_log_config(    logger: logging.Logger = None,    verbose: int = 2,    filename: str = None,    file_verbose: int = None,):    """    Use a logging configuration for a CLI application.    This will prettify log messages for the console, and show more info in a log file.    Parameters    ----------    logger : logging.Logger, default None        The logger to configure. If None, configures the root logger    verbose : int from 0 to 3, default 2        Sets the output verbosity.        Verbosity 0 shows critical errors        Verbosity 1 shows warnings and above        Verbosity 2 shows info and above        Verbosity 3 and above shows debug and above    filename : str, default None        The file name of the log file to log to. If None, no log file is generated.    file_verbose : int from 0 to 3, default None        Set a different verbosity for the log file. If None, is set to `verbose`.        This has no effect if `filename` is None.    Returns    -------    A context manager that will configure the logger, and reset to the previous configuration afterwards.    """    if file_verbose is None:        file_verbose = verbose    verbosities = {        0: logging.CRITICAL,        1: logging.WARNING,        2: logging.INFO,        3: logging.DEBUG,    }    console_level = verbosities.get(verbose, logging.DEBUG)    file_level = verbosities.get(file_verbose, logging.DEBUG)    # This configuration will print pretty tracebacks with color to the console,    # and log pretty tracebacks without color to the log file.    console_handler = logging.StreamHandler()    console_handler.setFormatter(MultiFormatter())    console_handler.setLevel(console_level)    contexts = [        LoggingContext(logger=logger, level=min(console_level, file_level)),        LoggingContext(logger=logger, handler=console_handler, close=False),    ]    if filename:        file_handler = logging.FileHandler(filename)        file_handler.setFormatter(            PrettyExceptionFormatter(                "%(levelname)s:%(asctime)s:%(name)s:%(message)s", color=False            )        )        file_handler.setLevel(file_level)        contexts.append(LoggingContext(logger=logger, handler=file_handler))    return MultiContext(*contexts)

We now have the option to specify a verbosity level, a log file, and a different verbosity for the file. Try out the example:

with cli_log_config(verbose=3, filename="test.log"):    try:        logging.debug("A debug message")        logging.info("An info message")        logging.warning("A warning message")        logging.error("An error message")        raise ValueError("A critical message from an exception")    except Exception as exc:        logging.critical(str(exc), exc_info=True)

Conculsion

In this article, we:

  1. Implemented a custom logging formatter to dynamically format messages based on log level
  2. Added color to console log output
  3. Prettified exceptions in log messages
  4. Wrapped everything into a reusable context manager

I hope you enjoyed, and drew some inspiration for making your CLI apps more user-friendly and robust!


Original Link: https://dev.to/eblocha/logging-in-python-command-line-applications-2gmi

Share this article:    Share on Facebook
View Full Article

Dev To

An online community for sharing and discovering great ideas, having debates, and making friends

More About this Source Visit Dev To