Add log-auto-indent option to control multiline formatting

This commit is contained in:
Michael Krebs 2019-10-07 17:56:28 -04:00
parent afabbb6346
commit 1f5b454355
5 changed files with 188 additions and 14 deletions

View File

@ -177,6 +177,7 @@ Michael Aquilina
Michael Birtwell Michael Birtwell
Michael Droettboom Michael Droettboom
Michael Goerz Michael Goerz
Michael Krebs
Michael Seifert Michael Seifert
Michal Wajszczuk Michal Wajszczuk
Mihai Capotă Mihai Capotă

View File

@ -0,0 +1,11 @@
Allow selective auto-indentation of multiline log messages.
Adds command line option ``--log-auto-indent``, config option
``log_auto_indent`` and support for per-entry configuration of
indentation behavior on calls to ``logging.log()``.
Alters the default for auto-indention from ``on`` to ``off``. This
restores the older behavior that existed prior to v4.6.0. This
reversion to earlier behavior was done because it is better to
activate new features that may lead to broken tests explicitly
rather than implicitly.

View File

@ -1192,6 +1192,29 @@ passed multiple times. The expected format is ``name=value``. For example::
[pytest] [pytest]
junit_suite_name = my_suite junit_suite_name = my_suite
.. confval:: log_auto_indent
Allow selective auto-indentation of multiline log messages.
Supports command line option ``--log-auto-indent [value]``
and config option ``log_auto_indent = [value]`` to set the
auto-indentation behavior for all logging.
``[value]`` can be:
* True or "On" - Dynamically auto-indent multiline log messages
* False or "Off" or 0 - Do not auto-indent multiline log messages (the default behavior)
* [positive integer] - auto-indent multiline log messages by [value] spaces
.. code-block:: ini
[pytest]
log_auto_indent = False
Supports passing kwarg ``extra={"auto_indent": [value]}`` to
calls to ``logging.log()`` to specify auto-indentation behavior for
a specific entry in the log. ``extra`` kwarg overrides the value specified
on the command line or in the config.
.. confval:: log_cli_date_format .. confval:: log_cli_date_format

View File

@ -7,6 +7,7 @@ import py
import pytest import pytest
from _pytest.compat import nullcontext from _pytest.compat import nullcontext
from _pytest.config import _strtobool
from _pytest.config import create_terminal_writer from _pytest.config import create_terminal_writer
from _pytest.pathlib import Path from _pytest.pathlib import Path
@ -72,24 +73,87 @@ class PercentStyleMultiline(logging.PercentStyle):
formats the message as if each line were logged separately. formats the message as if each line were logged separately.
""" """
def __init__(self, fmt, auto_indent):
super().__init__(fmt)
self._auto_indent = self._get_auto_indent(auto_indent)
@staticmethod @staticmethod
def _update_message(record_dict, message): def _update_message(record_dict, message):
tmp = record_dict.copy() tmp = record_dict.copy()
tmp["message"] = message tmp["message"] = message
return tmp return tmp
@staticmethod
def _get_auto_indent(auto_indent_option) -> int:
"""Determines the current auto indentation setting
Specify auto indent behavior (on/off/fixed) by passing in
extra={"auto_indent": [value]} to the call to logging.log() or
using a --log-auto-indent [value] command line or the
log_auto_indent [value] config option.
Default behavior is auto-indent off.
Using the string "True" or "on" or the boolean True as the value
turns auto indent on, using the string "False" or "off" or the
boolean False or the int 0 turns it off, and specifying a
positive integer fixes the indentation position to the value
specified.
Any other values for the option are invalid, and will silently be
converted to the default.
:param any auto_indent_option: User specified option for indentation
from command line, config or extra kwarg. Accepts int, bool or str.
str option accepts the same range of values as boolean config options,
as well as positive integers represented in str form.
:returns: indentation value, which can be
-1 (automatically determine indentation) or
0 (auto-indent turned off) or
>0 (explicitly set indentation position).
"""
if type(auto_indent_option) is int:
return int(auto_indent_option)
elif type(auto_indent_option) is str:
try:
return int(auto_indent_option)
except ValueError:
pass
try:
if _strtobool(auto_indent_option):
return -1
except ValueError:
return 0
elif type(auto_indent_option) is bool:
if auto_indent_option:
return -1
return 0
def format(self, record): def format(self, record):
if "\n" in record.message: if "\n" in record.message:
lines = record.message.splitlines() if hasattr(record, "auto_indent"):
formatted = self._fmt % self._update_message(record.__dict__, lines[0]) # passed in from the "extra={}" kwarg on the call to logging.log()
# TODO optimize this by introducing an option that tells the auto_indent = self._get_auto_indent(record.auto_indent)
# logging framework that the indentation doesn't else:
# change. This allows to compute the indentation only once. auto_indent = self._auto_indent
indentation = _remove_ansi_escape_sequences(formatted).find(lines[0])
lines[0] = formatted if auto_indent:
return ("\n" + " " * indentation).join(lines) lines = record.message.splitlines()
else: formatted = self._fmt % self._update_message(record.__dict__, lines[0])
return self._fmt % record.__dict__
if auto_indent < 0:
indentation = _remove_ansi_escape_sequences(formatted).find(
lines[0]
)
else:
# optimizes logging by allowing a fixed indentation
indentation = auto_indent
lines[0] = formatted
return ("\n" + " " * indentation).join(lines)
return self._fmt % record.__dict__
def get_option_ini(config, *names): def get_option_ini(config, *names):
@ -183,6 +247,12 @@ def pytest_addoption(parser):
default=DEFAULT_LOG_DATE_FORMAT, default=DEFAULT_LOG_DATE_FORMAT,
help="log date format as used by the logging module.", help="log date format as used by the logging module.",
) )
add_option_ini(
"--log-auto-indent",
dest="log_auto_indent",
default=None,
help="Auto-indent multiline messages passed to the logging module. Accepts true|on, false|off or an integer.",
)
@contextmanager @contextmanager
@ -413,6 +483,7 @@ class LoggingPlugin:
self.formatter = self._create_formatter( self.formatter = self._create_formatter(
get_option_ini(config, "log_format"), get_option_ini(config, "log_format"),
get_option_ini(config, "log_date_format"), get_option_ini(config, "log_date_format"),
get_option_ini(config, "log_auto_indent"),
) )
self.log_level = get_actual_log_level(config, "log_level") self.log_level = get_actual_log_level(config, "log_level")
@ -444,7 +515,7 @@ class LoggingPlugin:
if self._log_cli_enabled(): if self._log_cli_enabled():
self._setup_cli_logging() self._setup_cli_logging()
def _create_formatter(self, log_format, log_date_format): def _create_formatter(self, log_format, log_date_format, auto_indent):
# color option doesn't exist if terminal plugin is disabled # color option doesn't exist if terminal plugin is disabled
color = getattr(self._config.option, "color", "no") color = getattr(self._config.option, "color", "no")
if color != "no" and ColoredLevelFormatter.LEVELNAME_FMT_REGEX.search( if color != "no" and ColoredLevelFormatter.LEVELNAME_FMT_REGEX.search(
@ -456,7 +527,10 @@ class LoggingPlugin:
else: else:
formatter = logging.Formatter(log_format, log_date_format) formatter = logging.Formatter(log_format, log_date_format)
formatter._style = PercentStyleMultiline(formatter._style._fmt) formatter._style = PercentStyleMultiline(
formatter._style._fmt, auto_indent=auto_indent
)
return formatter return formatter
def _setup_cli_logging(self): def _setup_cli_logging(self):
@ -473,6 +547,7 @@ class LoggingPlugin:
log_cli_formatter = self._create_formatter( log_cli_formatter = self._create_formatter(
get_option_ini(config, "log_cli_format", "log_format"), get_option_ini(config, "log_cli_format", "log_format"),
get_option_ini(config, "log_cli_date_format", "log_date_format"), get_option_ini(config, "log_cli_date_format", "log_date_format"),
get_option_ini(config, "log_auto_indent"),
) )
log_cli_level = get_actual_log_level(config, "log_cli_level", "log_level") log_cli_level = get_actual_log_level(config, "log_cli_level", "log_level")

View File

@ -53,13 +53,77 @@ def test_multiline_message():
# this is called by logging.Formatter.format # this is called by logging.Formatter.format
record.message = record.getMessage() record.message = record.getMessage()
style = PercentStyleMultiline(logfmt) ai_on_style = PercentStyleMultiline(logfmt, True)
output = style.format(record) output = ai_on_style.format(record)
assert output == ( assert output == (
"dummypath 10 INFO Test Message line1\n" "dummypath 10 INFO Test Message line1\n"
" line2" " line2"
) )
ai_off_style = PercentStyleMultiline(logfmt, False)
output = ai_off_style.format(record)
assert output == (
"dummypath 10 INFO Test Message line1\nline2"
)
ai_none_style = PercentStyleMultiline(logfmt, None)
output = ai_none_style.format(record)
assert output == (
"dummypath 10 INFO Test Message line1\nline2"
)
record.auto_indent = False
output = ai_on_style.format(record)
assert output == (
"dummypath 10 INFO Test Message line1\nline2"
)
record.auto_indent = True
output = ai_off_style.format(record)
assert output == (
"dummypath 10 INFO Test Message line1\n"
" line2"
)
record.auto_indent = "False"
output = ai_on_style.format(record)
assert output == (
"dummypath 10 INFO Test Message line1\nline2"
)
record.auto_indent = "True"
output = ai_off_style.format(record)
assert output == (
"dummypath 10 INFO Test Message line1\n"
" line2"
)
# bad string values default to False
record.auto_indent = "junk"
output = ai_off_style.format(record)
assert output == (
"dummypath 10 INFO Test Message line1\nline2"
)
# anything other than string or int will default to False
record.auto_indent = dict()
output = ai_off_style.format(record)
assert output == (
"dummypath 10 INFO Test Message line1\nline2"
)
record.auto_indent = "5"
output = ai_off_style.format(record)
assert output == (
"dummypath 10 INFO Test Message line1\n line2"
)
record.auto_indent = 5
output = ai_off_style.format(record)
assert output == (
"dummypath 10 INFO Test Message line1\n line2"
)
def test_colored_short_level(): def test_colored_short_level():
logfmt = "%(levelname).1s %(message)s" logfmt = "%(levelname).1s %(message)s"