Problem with Custom Subclass of logging.Formatter

[Olllom]

Hey,

I had problems with a custom logging.Formatter that allows to include styles into the log message via record.args, like

mylogger.info("Red bold text", red, bold)

Sure, this is a slight abuse of record.args, but anyway...

With

log_cli=false
log_level=10

pytest tries to redirect message and arguments to the standard formatter and fails with a lengthy error message (not all arguments converted during string formatting in logging.LogRecord.getMessage()).

>       assert err == expected
E       assert '\x1b[31mtest...yle: Red>,)\n' == '\x1b[31mtest\x1b[39m\n'
E           test
E         - --- Logging error ---
E         - Traceback (most recent call last):
E         -   File "/Users/akraemer/Software/anaconda3/anaconda/lib/python3.6/logging/__init__.py", line 992, in emit
E         -     msg = self.format(record)
E         -   File "/Users/akraemer/Software/anaconda3/anaconda/lib/python3.6/logging/__init__.py", line 838, in format
E         -     return fmt.format(record)
E         -   File "/Users/akraemer/Software/anaconda3/anaconda/lib/python3.6/logging/__init__.py", line 575, in format
E         -     record.message = record.getMessage()
E         -   File "/Users/akraemer/Software/anaconda3/anaconda/lib/python3.6/logging/__init__.py", line 338, in getMessage
E         -     msg = msg % self.args
E         - TypeError: not all arguments converted during string formatting
E         - Call stack:
E        ...

E         -   File "/Users/akraemer/Software/anaconda3/anaconda/lib/python3.6/site-packages/_pytest/logging.py", line 177, in emit
E         -     logging.StreamHandler.emit(self, record)
E         - Message: 'test'
E         - Arguments: (<ANSIStyle: Red>,)


E         -   File "/Users/akraemer/Software/anaconda3/anaconda/lib/python3.6/logging/__init__.py", line 338, in getMessage
E         -     msg = msg % self.args

• [platform darwin -- Python 3.6.4, pytest-3.4.2, py-1.5.2, pluggy-0.6.0]
• Minimal example below (plumbum was version 1.6.6, but I don't think it matters)

With

log_cli=false
log_level=100

in the config file, everything works, so it does not bother me too much at the moment. I just wanted to let you know.

Minimal Example:

minex.py

import logging
import copy
from plumbum import colors
from plumbum.colorlib.styles import ANSIStyle

def apply_styles(msg, *styleargs, **kwargs):
    """Format message with styles.
    """
    if styleargs:
        for a in styleargs:
            msg = msg | a
    return msg

class ColorFormatter(logging.Formatter):
    def __init__(self, *args, **kwargs):
        super(ColorFormatter, self).__init__(*args, **kwargs)

    def format(self, record):
        r = copy.copy(record)
        styleargs = [a for a in r.args if isinstance(a, ANSIStyle)]
        otherargs = [a for a in r.args if not isinstance(a, ANSIStyle)]
        r.msg = apply_styles(str(r.msg), *styleargs)
        r.args = otherargs
        return super(ColorFormatter, self).format(r)

def setup_logger():
    logger = logging.getLogger("SomeLogger")
    console_handler = logging.StreamHandler()
    console_formatter = ColorFormatter('%(message)s')
    console_handler.setFormatter(console_formatter)
    logger.setLevel(logging.DEBUG)
    logger.addHandler(console_handler)
    return logger

test_minex.py

import minex
import plumbum
from plumbum.colors import red, bold

def test_color(capsys):
    #print(plumbum.__version__)
    logger = minex.setup_logger()
    logger.warning("test", red, bold)
    out, err = capsys.readouterr()
    expected = ("test" | red | bold) + "\n"
    assert err == expected

[pytestbot]

GitMate.io thinks possibly related issues are #2987 (Feature request: use caplog with custom formatter), #531 (Problems with fixture parametrization), #2534 (Fixture inheritance problem), #2079 (Capturing, with and without stdlib logging), and #2435 (f).

[RonnyPfannschmidt]

this is incorrect messing up of the logging api, its your own fault the standard components break, nothing pytest can do over you missusing things