Reduce installation noise: filter path padding and make some details debug level 2 (#31998)

lib/spack/spack/binary_distribution.py

@@ -1670,7 +1670,7 @@ def extract_tarball(spec, download_result, allow_root=False, unsigned=False, for
     old_relative_prefix = buildinfo.get("relative_prefix", new_relative_prefix)
     rel = buildinfo.get("relative_rpaths")
     info = "old relative prefix %s\nnew relative prefix %s\nrelative rpaths %s"
-    tty.debug(info % (old_relative_prefix, new_relative_prefix, rel))
+    tty.debug(info % (old_relative_prefix, new_relative_prefix, rel), level=2)
 
     # Extract the tarball into the store root, presumably on the same filesystem.
     # The directory created is the base directory name of the old prefix.
@@ -1756,6 +1756,8 @@ def install_root_node(spec, allow_root, unsigned=False, force=False, sha256=None
             raise spack.binary_distribution.NoChecksumException(msg)
         tty.debug("Verified SHA256 checksum of the build cache")
 
+    # don't print long padded paths while extracting/relocating binaries
+    with spack.util.path.filter_padding():
         tty.msg('Installing "{0}" from a buildcache'.format(spec.format()))
         extract_tarball(spec, download_result, allow_root, unsigned, force)
         spack.hooks.post_install(spec)
@@ -1814,14 +1816,17 @@ def try_direct_fetch(spec, mirrors=None):
                             specfile_name, buildcache_fetch_url_signed_json
                         ),
                         url_err,
+                        level=2,
                     )
                     tty.debug(
                         "Did not find {0} on {1}".format(specfile_name, buildcache_fetch_url_json),
                         url_err_x,
+                        level=2,
                     )
                     tty.debug(
                         "Did not find {0} on {1}".format(specfile_name, buildcache_fetch_url_yaml),
                         url_err_y,
+                        level=2,
                     )
                     continue
         specfile_contents = codecs.getreader("utf-8")(fs).read()

lib/spack/spack/installer.py

@@ -54,6 +54,7 @@
 import spack.repo
 import spack.store
 import spack.util.executable
+import spack.util.path
 from spack.util.environment import EnvironmentModifications, dump_environment
 from spack.util.executable import which
 from spack.util.timer import Timer
@@ -295,7 +296,7 @@ def _print_installed_pkg(message):
     Args:
         message (str): message to be output
     """
-    print(colorize("@*g{[+]} ") + message)
+    print(colorize("@*g{[+]} ") + spack.util.path.debug_padded_filter(message))
 
 
 def _process_external_package(pkg, explicit):
@@ -1357,7 +1358,8 @@ def _setup_install_dir(self, pkg):
             pkg (spack.package_base.Package): the package to be built and installed
         """
         if not os.path.exists(pkg.spec.prefix):
-            tty.debug("Creating the installation directory {0}".format(pkg.spec.prefix))
+            path = spack.util.path.debug_padded_filter(pkg.spec.prefix)
+            tty.debug("Creating the installation directory {0}".format(path))
             spack.store.layout.create_install_directory(pkg.spec)
         else:
             # Set the proper group for the prefix
@@ -1637,7 +1639,8 @@ def install(self):
                 ltype, lock = self._ensure_locked("read", pkg)
                 if lock is not None:
                     self._update_installed(task)
-                    _print_installed_pkg(pkg.prefix)
+                    path = spack.util.path.debug_padded_filter(pkg.prefix)
+                    _print_installed_pkg(path)
 
                     # It's an already installed compiler, add it to the config
                     if task.compiler:
@@ -1805,8 +1808,8 @@ def __init__(self, pkg, install_args):
 
         # If we are using a padded path, filter the output to compress padded paths
         # The real log still has full-length paths.
-        filter_padding = spack.config.get("config:install_tree:padded_length", None)
+        padding = spack.config.get("config:install_tree:padded_length", None)
-        self.filter_fn = spack.util.path.padding_filter if filter_padding else None
+        self.filter_fn = spack.util.path.padding_filter if padding else None
 
         # info/debug information
         pid = "{0}: ".format(os.getpid()) if tty.show_pid() else ""
@@ -2181,7 +2184,8 @@ def flag_installed(self, installed):
             tty.debug(
                 "{0}: Removed {1} from uninstalled deps list: {2}".format(
                     self.pkg_id, pkg_id, self.uninstalled_deps
-                )
+                ),
+                level=2,
             )
 
     @property

lib/spack/spack/relocate.py

@@ -889,7 +889,7 @@ def file_is_relocatable(filename, paths_to_relocate=None):
 
     m_type, m_subtype = mime_type(filename)
     if m_type == "application":
-        tty.debug("{0},{1}".format(m_type, m_subtype))
+        tty.debug("{0},{1}".format(m_type, m_subtype), level=2)
 
     if not is_macos:
         if m_subtype == "x-executable" or m_subtype == "x-sharedlib":
@@ -908,7 +908,7 @@ def file_is_relocatable(filename, paths_to_relocate=None):
             # One binary has the root folder not in the RPATH,
             # meaning that this spec is not relocatable
             msg = 'Found "{0}" in {1} strings'
-            tty.debug(msg.format(path_to_relocate, filename))
+            tty.debug(msg.format(path_to_relocate, filename), level=2)
             return False
 
     return True
@@ -953,7 +953,7 @@ def mime_type(filename):
         Tuple containing the MIME type and subtype
     """
     output = _get_mime_type()(filename, output=str, error=str).strip()
-    tty.debug("==> " + output)
+    tty.debug("==> " + output, level=2)
     type, _, subtype = output.partition("/")
     return type, subtype
 

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

@@ -111,3 +111,21 @@ def test_output_filtering(self, capfd, install_mockery, mutable_config):
         tty.msg("here is a long path: %s/with/a/suffix" % long_path)
         out, err = capfd.readouterr()
         assert padding_string not in out
+
+
+@pytest.mark.parametrize("debug", [1, 2])
+def test_path_debug_padded_filter(debug, monkeypatch):
+    """Ensure padded filter works as expected with different debug levels."""
+    fmt = "{0}{1}{2}{1}{3}"
+    prefix = "[+] {0}home{0}user{0}install".format(os.sep)
+    suffix = "mypackage"
+    string = fmt.format(prefix, os.sep, os.sep.join([sup.SPACK_PATH_PADDING_CHARS] * 2), suffix)
+    expected = (
+        fmt.format(prefix, os.sep, "[padded-to-{0}-chars]".format(72), suffix)
+        if debug <= 1 and not is_windows
+        else string
+    )
+
+    monkeypatch.setattr(tty, "_debug", debug)
+    with spack.config.override("config:install_tree", {"padded_length": 128}):
+        assert expected == sup.debug_padded_filter(string)

lib/spack/spack/util/path.py

@@ -371,6 +371,7 @@ def padding_filter(string):
     entirety at least one time. e.g., "/spack/" would not be filtered, but
     "/__spack_path_placeholder__/spack/" would be.
 
+    Note that only the first padded path in the string is filtered.
     """
     global _filter_re
 
@@ -408,3 +409,22 @@ def filter_padding():
             yield
     else:
         yield  # no-op: don't filter unless padding is actually enabled
+
+
+def debug_padded_filter(string, level=1):
+    """
+    Return string, path padding filtered if debug level and not windows
+
+    Args:
+        string (str): string containing path
+        level (int): maximum debug level value for filtering (e.g., 1
+            means filter path padding if the current debug level is 0 or 1
+            but return the original string if it is 2 or more)
+
+    Returns (str): filtered string if current debug level does not exceed
+        level and not windows; otherwise, unfiltered string
+    """
+    if is_windows:
+        return string
+
+    return padding_filter(string) if tty.debug_level() <= level else string