installation: filter padding from all tty output

This is both a bugfix and a generalization of #25168. In #25168, we attempted to filter padding
*just* from the debug output of `spack.util.executable.Executable` objects. It turns out we got it
wrong -- filtering the command line string instead of the arg list resulted in output like this:

```
==> [2021-08-05-21:34:19.918576] ["'", '/', 'b', 'i', 'n', '/', 't', 'a', 'r', "'", ' ', "'", '-', 'o', 'x', 'f', "'", ' ', "'", '/', 't', 'm', 'p', '/', 'r', 'o', 'o', 't', '/', 's', 'p', 'a', 'c', 'k', '-', 's', 't', 'a', 'g', 'e', '/', 's', 'p', 'a', 'c', 'k', '-', 's', 't', 'a', 'g', 'e', '-', 'p', 'a', 't', 'c', 'h', 'e', 'l', 'f', '-', '0', '.', '1', '3', '-', 'w', 'p', 'h', 'p', 't', 'l', 'h', 'w', 'u', 's', 'e', 'i', 'a', '4', 'k', 'p', 'g', 'y', 'd', 'q', 'l', 'l', 'i', '2', '4', 'q', 'b', '5', '5', 'q', 'u', '4', '/', 'p', 'a', 't', 'c', 'h', 'e', 'l', 'f', '-', '0', '.', '1', '3', '.', 't', 'a', 'r', '.', 'b', 'z', '2', "'"]
```

Additionally, plenty of builds output padded paths in other plcaes -- e.g., not just command
arguments, but in other `tty` messages via `llnl.util.filesystem` and other places. `Executable`
isn't really the right place for this.

This PR reverts the changes to `Executable` and moves the filtering into `llnl.util.tty`. There is
now a context manager there that you can use to install a filter for all output.
`spack.installer.build_process()` now uses this context manager to make `tty` do path filtering
when padding is enabled.

- [x] revert filtering in `Executable`
- [x] add ability for `tty` to filter output
- [x] install output filter in `build_process()`
- [x] tests

lib/spack/llnl/util/tty/__init__.py

@@ -5,6 +5,7 @@
 
 from __future__ import unicode_literals
 
+import contextlib
 import fcntl
 import os
 import struct
@@ -28,6 +29,7 @@
 _msg_enabled = True
 _warn_enabled = True
 _error_enabled = True
+_output_filter = lambda s: s
 indent = "  "
 
 
@@ -90,6 +92,18 @@ def error_enabled():
     return _error_enabled
 
 
+@contextlib.contextmanager
+def output_filter(filter_fn):
+    """Context manager that applies a filter to all output."""
+    global _output_filter
+    saved_filter = _output_filter
+    try:
+        _output_filter = filter_fn
+        yield
+    finally:
+        _output_filter = saved_filter
+
+
 class SuppressOutput:
     """Class for disabling output in a scope using 'with' keyword"""
 
@@ -166,13 +180,23 @@ def msg(message, *args, **kwargs):
     if _stacktrace:
         st_text = process_stacktrace(2)
     if newline:
-        cprint("@*b{%s==>} %s%s" % (
+        cprint(
-            st_text, get_timestamp(), cescape(message)))
+            "@*b{%s==>} %s%s" % (
+                st_text,
+                get_timestamp(),
+                cescape(_output_filter(message))
+            )
+        )
     else:
-        cwrite("@*b{%s==>} %s%s" % (
+        cwrite(
-            st_text, get_timestamp(), cescape(message)))
+            "@*b{%s==>} %s%s" % (
+                st_text,
+                get_timestamp(),
+                cescape(_output_filter(message))
+            )
+        )
     for arg in args:
-        print(indent + six.text_type(arg))
+        print(indent + _output_filter(six.text_type(arg)))
 
 
 def info(message, *args, **kwargs):
@@ -188,18 +212,29 @@ def info(message, *args, **kwargs):
     st_text = ""
     if _stacktrace:
         st_text = process_stacktrace(st_countback)
-    cprint("@%s{%s==>} %s%s" % (
+    cprint(
-        format, st_text, get_timestamp(), cescape(six.text_type(message))
+        "@%s{%s==>} %s%s" % (
-    ), stream=stream)
+            format,
+            st_text,
+            get_timestamp(),
+            cescape(_output_filter(six.text_type(message)))
+        ),
+        stream=stream
+    )
     for arg in args:
         if wrap:
             lines = textwrap.wrap(
-                six.text_type(arg), initial_indent=indent,
+                _output_filter(six.text_type(arg)),
-                subsequent_indent=indent, break_long_words=break_long_words)
+                initial_indent=indent,
+                subsequent_indent=indent,
+                break_long_words=break_long_words
+            )
             for line in lines:
                 stream.write(line + '\n')
         else:
-            stream.write(indent + six.text_type(arg) + '\n')
+            stream.write(
+                indent + _output_filter(six.text_type(arg)) + '\n'
+            )
 
 
 def verbose(message, *args, **kwargs):

lib/spack/spack/installer.py

@@ -1886,7 +1886,7 @@ def build_process(pkg, install_args):
     installer = BuildProcessInstaller(pkg, install_args)
 
     # don't print long padded paths in executable debug output.
-    with spack.util.executable.filter_padding():
+    with spack.util.path.filter_padding():
         return installer.run()
 
 

lib/spack/spack/test/util/path.py

@@ -5,6 +5,9 @@
 
 import pytest
 
+import llnl.util.tty as tty
+
+import spack.config
 import spack.util.path as sup
 
 #: Some lines with lots of placeholders
@@ -57,3 +60,40 @@ def test_longest_prefix_re():
     assert "(?:s(?:t(?:r(?:i(?:ng?)?)?)?)?)" == sup.longest_prefix_re(
         "string", capture=False
     )
+
+
+def test_output_filtering(capfd, install_mockery, mutable_config):
+    """Test filtering padding out of tty messages."""
+    long_path = "/" + "/".join([sup.SPACK_PATH_PADDING_CHARS] * 200)
+    padding_string = "[padded-to-%d-chars]" % len(long_path)
+
+    # test filtering when padding is enabled
+    with spack.config.override('config:install_tree', {"padded_length": 256}):
+        # tty.msg with filtering on the first argument
+        with sup.filter_padding():
+            tty.msg("here is a long path: %s/with/a/suffix" % long_path)
+        out, err = capfd.readouterr()
+        assert padding_string in out
+
+        # tty.msg with filtering on a laterargument
+        with sup.filter_padding():
+            tty.msg("here is a long path:", "%s/with/a/suffix" % long_path)
+        out, err = capfd.readouterr()
+        assert padding_string in out
+
+        # tty.error with filtering on the first argument
+        with sup.filter_padding():
+            tty.error("here is a long path: %s/with/a/suffix" % long_path)
+        out, err = capfd.readouterr()
+        assert padding_string in err
+
+        # tty.error with filtering on a later argument
+        with sup.filter_padding():
+            tty.error("here is a long path:", "%s/with/a/suffix" % long_path)
+        out, err = capfd.readouterr()
+        assert padding_string in err
+
+    # test no filtering
+    tty.msg("here is a long path: %s/with/a/suffix" % long_path)
+    out, err = capfd.readouterr()
+    assert padding_string not in out

lib/spack/spack/util/executable.py

@@ -2,7 +2,7 @@
 # Spack Project Developers. See the top-level COPYRIGHT file for details.
 #
 # SPDX-License-Identifier: (Apache-2.0 OR MIT)
-import contextlib
+
 import os
 import re
 import shlex
@@ -17,27 +17,6 @@
 
 __all__ = ['Executable', 'which', 'ProcessError']
 
-#: optionally filter padding on debug output in spack.util.executable
-_filter_padding = False
-
-
-@contextlib.contextmanager
-def filter_padding():
-    """Context manager to safely disable path padding in debug output.
-
-    This is needed because Spack's debug output gets extremely long when we use a
-    long padded installation path.
-    """
-    global _filter_padding
-    try:
-        # don't bother filtering if padding isn't actually enabled
-        padding = spack.config.get("config:install_tree:padded_length", None)
-        if padding:
-            _filter_padding = True
-        yield
-    finally:
-        _filter_padding = False
-
 
 class Executable(object):
     """Class representing a program that can be run on the command line."""
@@ -206,13 +185,9 @@ def streamify(arg, mode):
 
         cmd = self.exe + list(args)
 
-        cmd_line = "'%s'" % "' '".join(
+        escaped_cmd = ["'%s'" % arg.replace("'", "'\"'\"'") for arg in cmd]
-            map(lambda arg: arg.replace("'", "'\"'\"'"), cmd))
+        cmd_line_string = " ".join(escaped_cmd)
-
+        tty.debug(cmd_line_string)
-        debug_cmd_line = cmd_line
-        if _filter_padding:
-            debug_cmd_line = [spack.util.path.padding_filter(elt) for elt in cmd_line]
-        tty.debug(debug_cmd_line)
 
         try:
             proc = subprocess.Popen(
@@ -239,7 +214,7 @@ def streamify(arg, mode):
 
             rc = self.returncode = proc.returncode
             if fail_on_error and rc != 0 and (rc not in ignore_errors):
-                long_msg = cmd_line
+                long_msg = cmd_line_string
                 if result:
                     # If the output is not captured in the result, it will have
                     # been stored either in the specified files (e.g. if
@@ -254,13 +229,13 @@ def streamify(arg, mode):
 
         except OSError as e:
             raise ProcessError(
-                '%s: %s' % (self.exe[0], e.strerror), 'Command: ' + cmd_line)
+                '%s: %s' % (self.exe[0], e.strerror), 'Command: ' + cmd_line_string)
 
         except subprocess.CalledProcessError as e:
             if fail_on_error:
                 raise ProcessError(
                     str(e), '\nExit status %d when invoking command: %s' %
-                    (proc.returncode, cmd_line))
+                    (proc.returncode, cmd_line_string))
 
         finally:
             if close_ostream:

lib/spack/spack/util/path.py

@@ -7,6 +7,7 @@
 
 TODO: this is really part of spack.config. Consolidate it.
 """
+import contextlib
 import getpass
 import os
 import re
@@ -232,3 +233,19 @@ def replacer(match):
             len(match.group(0))
         )
     return _filter_re.sub(replacer, string)
+
+
+@contextlib.contextmanager
+def filter_padding():
+    """Context manager to safely disable path padding in all Spack output.
+
+    This is needed because Spack's debug output gets extremely long when we use a
+    long padded installation path.
+    """
+    padding = spack.config.get("config:install_tree:padded_length", None)
+    if padding:
+        # filter out all padding from the intsall command output
+        with tty.output_filter(padding_filter):
+            yield
+    else:
+        yield  # no-op: don't filter unless padding is actually enabled