31

I asked this question for python 2 here, but bumped into the issue again when the the answer no longer worked for Python 3.2.3.

Here's code that works on Python 2.7.3:

import logging

# Attempt to set up a Python3 logger than will print custom messages
# based on each message's logging level.
# The technique recommended for Python2 does not appear to work for
# Python3

class CustomConsoleFormatter(logging.Formatter):
    """
    Modify the way DEBUG messages are displayed.

    """
    def __init__(self, fmt="%(levelno)d: %(msg)s"):
        logging.Formatter.__init__(self, fmt=fmt)

    def format(self, record):

        # Remember the original format
        format_orig = self._fmt

        if record.levelno == logging.DEBUG:
            self._fmt = "DEBUG: %(msg)s"

        # Call the original formatter to do the grunt work
        result = logging.Formatter.format(self, record)

        # Restore the original format
        self._fmt = format_orig

        return result


# Set up a logger
my_logger = logging.getLogger("my_custom_logger")
my_logger.setLevel(logging.DEBUG)

my_formatter = CustomConsoleFormatter()

console_handler = logging.StreamHandler()
console_handler.setFormatter(my_formatter)

my_logger.addHandler(console_handler)

my_logger.debug("This is a DEBUG-level message")
my_logger.info("This is an INFO-level message")

A run using Python 2.7.3:

tcsh-16: python demo_python_2.7.3.py 
DEBUG: This is a DEBUG-level message
20: This is an INFO-level message


As far as I can tell, conversion to Python3 requires only a slight mod to CustomConsoleFormatter.init():

def __init__(self):
    super().__init__(fmt="%(levelno)d: %(msg)s", datefmt=None, style='%')

On Python 3.2.3:

tcsh-26: python3 demo_python_3.2.3.py
10: This is a DEBUG-level message
20: This is an INFO-level message


As you can see, my desire to replace '10' with 'DEBUG' is being thwarted.

I've tried digging around in Python3 source and it looks like the PercentStyle instantiation is clobbering self._fmt after I, well, clobber it myself.

My logging chops stop just short of being able to work around this wrinkle.

Can anyone recommend another way or perhaps point out what I'm overlooking?

Community
  • 1
  • 1
JS.
  • 14,781
  • 13
  • 63
  • 75

8 Answers8

29

With a bit of digging, I was able to modify the Python 2 solution to work with Python 3. In Python2, it was necessary to temporarily overwrite Formatter._fmt. In Python3, support for multiple format string types requires us to temporarily overwrite Formatter._style._fmt instead.

# Custom formatter
class MyFormatter(logging.Formatter):

    err_fmt  = "ERROR: %(msg)s"
    dbg_fmt  = "DBG: %(module)s: %(lineno)d: %(msg)s"
    info_fmt = "%(msg)s"

    def __init__(self):
        super().__init__(fmt="%(levelno)d: %(msg)s", datefmt=None, style='%')  
    
    def format(self, record):

        # Save the original format configured by the user
        # when the logger formatter was instantiated
        format_orig = self._style._fmt

        # Replace the original format with one customized by logging level
        if record.levelno == logging.DEBUG:
            self._style._fmt = MyFormatter.dbg_fmt

        elif record.levelno == logging.INFO:
            self._style._fmt = MyFormatter.info_fmt

        elif record.levelno == logging.ERROR:
            self._style._fmt = MyFormatter.err_fmt

        # Call the original formatter class to do the grunt work
        result = logging.Formatter.format(self, record)

        # Restore the original format configured by the user
        self._style._fmt = format_orig

        return result

And here is Halloleo's example of how to use the above in your script (from the Python2 version of this question):

fmt = MyFormatter()
hdlr = logging.StreamHandler(sys.stdout)

hdlr.setFormatter(fmt)
logging.root.addHandler(hdlr)
logging.root.setLevel(logging.DEBUG)
JS.
  • 14,781
  • 13
  • 63
  • 75
  • `logging.info('test %i', 3)` doesn't print `test 3` with this (see https://stackoverflow.com/a/62488520/4417769). Also note, that `DEBUG` should be `logging.DEBUG`. – sezanzeb Aug 26 '20 at 18:57
  • 1
    @sezanzeb s/DEBUG/logging.DEBUG/ fixed. Thanks for pointing that one out. – JS. Aug 26 '20 at 20:25
  • Crucially, this fails to respect the integral nature of levels. It should be able to choose a reasonable formatter for a level between DEBUG and INFO but does not. Also, it does non-thread-safe instance mutation with no lock and no `finally`. – Reinderien Jun 27 '21 at 18:46
10

I prefer this because it's shorter, simpler and does not require strings like 'ERROR' to be hard coded. No need to reset ._fmt, because else: can handle that just fine.

Also, using "%(msg)s" doesn't work with lazy logging!

class Formatter(logging.Formatter):
    def format(self, record):
        if record.levelno == logging.INFO:
            self._style._fmt = "%(message)s"
        else:
            self._style._fmt = "%(levelname)s: %(message)s"
        return super().format(record)

Usage example:

import logging

logger = logging.getLogger()
handler = logging.StreamHandler()
handler.setFormatter(Formatter())
logger.setLevel(logging.DEBUG)
logger.addHandler(handler)

logger.debug('foo')
logger.info('bar %d', 4)
DEBUG: foo
bar 4

In case you want to have the levelname colored:

class Formatter(logging.Formatter):
    def format(self, record):
        if record.levelno == logging.INFO:
            self._style._fmt = "%(message)s"
        else:
            color = {
                logging.WARNING: 33,
                logging.ERROR: 31,
                logging.FATAL: 31,
                logging.DEBUG: 36
            }.get(record.levelno, 0)
            self._style._fmt = f"\033[{color}m%(levelname)s\033[0m: %(message)s"
        return super().format(record)

see https://en.wikipedia.org/wiki/ANSI_escape_code#3/4_bit for color numbers

sezanzeb
  • 816
  • 8
  • 20
2

Cross-posting of another answer. It doesn't work because of the new (3.2+, 3.4 as of now) implementation of logging.Formatter which now relies on formatting styles. This relies on the '{' style format, but it can be adapted. Could be refined to be more general and allow selection of formatting style and custom messages as arguments to __init__, too.

class SpecialFormatter(logging.Formatter):
    FORMATS = {logging.DEBUG : logging._STYLES['{']("{module} DEBUG: {lineno}: {message}"),
           logging.ERROR : logging._STYLES['{']("{module} ERROR: {message}"),
           logging.INFO : logging._STYLES['{']("{module}: {message}"),
           'DEFAULT' : logging._STYLES['{']("{module}: {message}")}

    def format(self, record):
        # Ugly. Should be better
        self._style = self.FORMATS.get(record.levelno, self.FORMATS['DEFAULT'])
        return logging.Formatter.format(self, record)

hdlr = logging.StreamHandler(sys.stderr)
hdlr.setFormatter(SpecialFormatter())
logging.root.addHandler(hdlr)
logging.root.setLevel(logging.INFO)
Community
  • 1
  • 1
Evpok
  • 4,273
  • 3
  • 34
  • 46
2

For some weird reasons, the solutions of @JS and @Evpok were raising some errors (I am using Python 3.7 and that might be why).

This solution worked for me:

class CustomFormatter(logging.Formatter):
    """Logging Formatter to add colors and count warning / errors"""

    FORMATS = {
        logging.ERROR: "ERROR: %(msg)s",
        logging.WARNING: "WARNING: %(msg)s",
        logging.DEBUG: "DBG: %(module)s: %(lineno)d: %(msg)s",
        "DEFAULT": "%(msg)s",
    }

    def format(self, record):
        log_fmt = self.FORMATS.get(record.levelno, self.FORMATS['DEFAULT'])
        formatter = logging.Formatter(log_fmt)
        return formatter.format(record)

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)
logger_ch = logging.StreamHandler()
logger_ch.setLevel(logging.INFO)
logger_ch.setFormatter(CustomFormatter())
logger.addHandler(logger_ch)
Jean-Francois T.
  • 11,549
  • 7
  • 68
  • 107
1

I am quiet late for this question but here is my solution. It follows the original python 2 syntax style. In general there are three new classes that you should be using due to the addition of styles support. Those are: PercentStyle, StrFormatStyle, and StringTemplateStyle.

from logging import Formatter, PercentStyle, ERROR, WARNING, INFO, DEBUG
class SrvLogFormat(Formatter):
    def __init__(self):
        super().__init__(fmt=env.fmt_log, datefmt=env.fmt_log_date)

    def format(self, record):
        original_style = self._style

        if record.levelno == DEBUG:
            self._style = PercentStyle(env.fmt_dflt)
        if record.levelno == INFO:
            self._style = PercentStyle(env.fmt_dflt)
        if record.levelno == WARNING:
            self._style = PercentStyle(env.fmt_dflt)
        if record.levelno == ERROR:
            self._style = PercentStyle(env.fmt_err)

        result = Formatter.format(self, record)
        self._style = original_style
        return result
1

Both this Python3 question and its Python2 question have answers with major flaws:

  • Levels are selected either by equality comparison or dictionary lookup, when levels are not intended to be discrete; they exist on the integer number line and should be orderable.
  • When the formatter instance is mutated, there is no lock to protect the _fmt member and so this is thread-unsafe.
  • Modification of that member should at least be surrounded by a try/finally.

Really, that member should not be modified at all. A trivial way around this is to instantiate one or more immutable surrogate formatters and defer to them as needed. Also, select them via bisection instead of equality, to support arbitrary levels:

import logging
from bisect import bisect
from logging import getLogger, Formatter, LogRecord, StreamHandler
from typing import Dict


class LevelFormatter(Formatter):
    def __init__(self, formats: Dict[int, str], **kwargs):
        super().__init__()

        if 'fmt' in kwargs:
            raise ValueError(
                'Format string must be passed to level-surrogate formatters, '
                'not this one'
            )

        self.formats = sorted(
            (level, Formatter(fmt, **kwargs)) for level, fmt in formats.items()
        )

    def format(self, record: LogRecord) -> str:
        idx = bisect(self.formats, (record.levelno,), hi=len(self.formats)-1)
        level, formatter = self.formats[idx]
        return formatter.format(record)


def test():
    handler = StreamHandler()
    handler.setFormatter(
        LevelFormatter(
            {
                logging.INFO: '%(levelname)s (info): %(message)s',
                logging.WARNING: '%(levelname)s: (warning): %(message)s',
            }
        )
    )
    handler.setLevel(logging.DEBUG)

    logger = getLogger('test_logger')
    logger.setLevel(logging.DEBUG)
    logger.addHandler(handler)

    logger.debug('mdebug')
    logger.info('minfo')
    logger.log(logging.INFO + 1, 'higher minfo')
    logger.warning('mwarning')
    logger.error('merror')
    logger.critical('mcritical')


test()

outputs

DEBUG (info): mdebug
INFO (info): minfo
Level 21: (warning): higher minfo
WARNING: (warning): mwarning
ERROR: (warning): merror
CRITICAL: (warning): mcritical
Reinderien
  • 11,755
  • 5
  • 49
  • 77
0
import logging
from logging import DEBUG, INFO, WARN, ERROR

class LogFormatter(logging.Formatter):

    formats = {
        DEBUG: "DEBUG: %(msg)s",
        INFO:  "%(msg)s",
        WARN:  "WARNING: %(msg)s",
        ERROR: "ERROR: %(msg)s"
    }
    
    def format(self, record):
        return LogFormatter.formats.get(
            record.levelno, self._fmt) % record.__dict__

In the source code of logging/__init__.py, the method _format of PercentStyle is simply

    def _format(self, record):
        return self._fmt % record.__dict__

Therefore using the % operator works as well.

JamesTZ
  • 25
  • 4
0

An alternative a custom Formatter class is a custom Logger class. The logging module provides a method setLoggerClass to support this approach. This has some limitations, but is really simple to implement.

import logging

class CustomLogger(logging.getLoggerClass()):
    def __init__(self, name: str) -> None:
        logging.Logger.__init__(self, name=name)

    def debug(self, msg: str, *args, **kwargs):
        return super().debug(f'[DEBUG] {msg}', *args, **kwargs)

logging.setLoggerClass(CustomLogger)
logging.basicConfig(level=logging.DEBUG, format='%(message)s')
log = logging.getLogger('hello_world')

log.info("An info message.")
log.debug("A debug message.")

Result:

An info message.
[DEBUG] A debug message.
Bryan Roach
  • 743
  • 9
  • 12