Merge pull request #5926 from AtakamaLLC/optional-multiline

Add log-auto-indent option to control multiline formatting

AUTHORS

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

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.

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
 

src/_pytest/logging.py

@@ -10,6 +10,7 @@
 
 import pytest
 from _pytest.compat import nullcontext
+from _pytest.config import _strtobool
 from _pytest.config import create_terminal_writer
 from _pytest.pathlib import Path
 
@@ -76,24 +77,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):
@@ -187,6 +251,12 @@ def add_option_ini(option, dest, default=None, type=None, **kwargs):
         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
@@ -418,6 +488,7 @@ def __init__(self, config):
         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")
 
@@ -449,7 +520,7 @@ def __init__(self, config):
         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(
@@ -461,7 +532,10 @@ def _create_formatter(self, log_format, log_date_format):
         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):
@@ -478,6 +552,7 @@ def _setup_cli_logging(self):
         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")

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"