From 1f5b454355d27bccda2ce1b3b145cfbde020fb76 Mon Sep 17 00:00:00 2001 From: Michael Krebs Date: Mon, 7 Oct 2019 17:56:28 -0400 Subject: [PATCH] Add log-auto-indent option to control multiline formatting --- AUTHORS | 1 + changelog/5515.feature.rst | 11 ++++ doc/en/reference.rst | 23 +++++++ src/_pytest/logging.py | 99 +++++++++++++++++++++++++++---- testing/logging/test_formatter.py | 68 ++++++++++++++++++++- 5 files changed, 188 insertions(+), 14 deletions(-) create mode 100644 changelog/5515.feature.rst diff --git a/AUTHORS b/AUTHORS index 9f6ee048d..d96e6e713 100644 --- a/AUTHORS +++ b/AUTHORS @@ -177,6 +177,7 @@ Michael Aquilina Michael Birtwell Michael Droettboom Michael Goerz +Michael Krebs Michael Seifert Michal Wajszczuk Mihai Capotă diff --git a/changelog/5515.feature.rst b/changelog/5515.feature.rst new file mode 100644 index 000000000..b53097c43 --- /dev/null +++ b/changelog/5515.feature.rst @@ -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. diff --git a/doc/en/reference.rst b/doc/en/reference.rst index 9c3a4c731..f90efc3a5 100644 --- a/doc/en/reference.rst +++ b/doc/en/reference.rst @@ -1192,6 +1192,29 @@ passed multiple times. The expected format is ``name=value``. For example:: [pytest] 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 diff --git a/src/_pytest/logging.py b/src/_pytest/logging.py index 2861baefd..f12ac13d8 100644 --- a/src/_pytest/logging.py +++ b/src/_pytest/logging.py @@ -7,6 +7,7 @@ import py import pytest from _pytest.compat import nullcontext +from _pytest.config import _strtobool from _pytest.config import create_terminal_writer from _pytest.pathlib import Path @@ -72,24 +73,87 @@ class PercentStyleMultiline(logging.PercentStyle): 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 def _update_message(record_dict, message): tmp = record_dict.copy() tmp["message"] = message 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): if "\n" in record.message: - lines = record.message.splitlines() - formatted = self._fmt % self._update_message(record.__dict__, lines[0]) - # TODO optimize this by introducing an option that tells the - # logging framework that the indentation doesn't - # change. This allows to compute the indentation only once. - indentation = _remove_ansi_escape_sequences(formatted).find(lines[0]) - lines[0] = formatted - return ("\n" + " " * indentation).join(lines) - else: - return self._fmt % record.__dict__ + if hasattr(record, "auto_indent"): + # passed in from the "extra={}" kwarg on the call to logging.log() + auto_indent = self._get_auto_indent(record.auto_indent) + else: + auto_indent = self._auto_indent + + if auto_indent: + lines = record.message.splitlines() + formatted = self._fmt % self._update_message(record.__dict__, lines[0]) + + 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): @@ -183,6 +247,12 @@ def pytest_addoption(parser): default=DEFAULT_LOG_DATE_FORMAT, 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 @@ -413,6 +483,7 @@ class LoggingPlugin: self.formatter = self._create_formatter( get_option_ini(config, "log_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") @@ -444,7 +515,7 @@ class LoggingPlugin: if self._log_cli_enabled(): 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 = getattr(self._config.option, "color", "no") if color != "no" and ColoredLevelFormatter.LEVELNAME_FMT_REGEX.search( @@ -456,7 +527,10 @@ class LoggingPlugin: else: 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 def _setup_cli_logging(self): @@ -473,6 +547,7 @@ class LoggingPlugin: log_cli_formatter = self._create_formatter( 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_auto_indent"), ) log_cli_level = get_actual_log_level(config, "log_cli_level", "log_level") diff --git a/testing/logging/test_formatter.py b/testing/logging/test_formatter.py index 6850a83cd..b363e8b03 100644 --- a/testing/logging/test_formatter.py +++ b/testing/logging/test_formatter.py @@ -53,13 +53,77 @@ def test_multiline_message(): # this is called by logging.Formatter.format record.message = record.getMessage() - style = PercentStyleMultiline(logfmt) - output = style.format(record) + ai_on_style = PercentStyleMultiline(logfmt, True) + output = ai_on_style.format(record) assert output == ( "dummypath 10 INFO Test Message line1\n" " 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(): logfmt = "%(levelname).1s %(message)s"