From 2c802c12a594d64b72a589af9261f9ab7fecea2c Mon Sep 17 00:00:00 2001
From: Harmen Stoppels <harmenstoppels@gmail.com>
Date: Mon, 17 Oct 2022 15:54:40 +0200
Subject: installer.py: show timers for binary install (#33305)
Print a message of the form
```
Fetch mm:ss. Build: mm:ss. Total: mm:ss
```
when installing from buildcache.
Previously this only happened for source builds.
---
lib/spack/spack/installer.py | 80 +++++++++++++++++++++++++++++++-------------
1 file changed, 57 insertions(+), 23 deletions(-)
(limited to 'lib')
diff --git a/lib/spack/spack/installer.py b/lib/spack/spack/installer.py
index 4150302b28..7ec31f0267 100644
--- a/lib/spack/spack/installer.py
+++ b/lib/spack/spack/installer.py
@@ -262,6 +262,30 @@ def _hms(seconds):
return " ".join(parts)
+def _log_prefix(pkg_name):
+ """Prefix of the form "[pid]: [pkg name]: ..." when printing a status update during
+ the build."""
+ pid = "{0}: ".format(os.getpid()) if tty.show_pid() else ""
+ return "{0}{1}:".format(pid, pkg_name)
+
+
+def _print_installed_pkg(message):
+ """
+ Output a message with a package icon.
+
+ Args:
+ message (str): message to be output
+ """
+ print(colorize("@*g{[+]} ") + spack.util.path.debug_padded_filter(message))
+
+
+def _print_timer(pre, pkg_id, fetch, build, total):
+ tty.msg(
+ "{0} Successfully installed {1}".format(pre, pkg_id),
+ "Fetch: {0}. Build: {1}. Total: {2}.".format(_hms(fetch), _hms(build), _hms(total)),
+ )
+
+
def _install_from_cache(pkg, cache_only, explicit, unsigned=False):
"""
Extract the package from binary cache
@@ -278,7 +302,10 @@ def _install_from_cache(pkg, cache_only, explicit, unsigned=False):
bool: ``True`` if the package was extract from binary cache,
``False`` otherwise
"""
- installed_from_cache = _try_install_from_binary_cache(pkg, explicit, unsigned=unsigned)
+ timer = Timer()
+ installed_from_cache = _try_install_from_binary_cache(
+ pkg, explicit, unsigned=unsigned, timer=timer
+ )
pkg_id = package_id(pkg)
if not installed_from_cache:
pre = "No binary for {0} found".format(pkg_id)
@@ -287,23 +314,20 @@ def _install_from_cache(pkg, cache_only, explicit, unsigned=False):
tty.msg("{0}: installing from source".format(pre))
return False
-
+ timer.stop()
tty.debug("Successfully extracted {0} from binary cache".format(pkg_id))
+ _print_timer(
+ pre=_log_prefix(pkg.name),
+ pkg_id=pkg_id,
+ fetch=timer.phases.get("search", 0) + timer.phases.get("fetch", 0),
+ build=timer.phases.get("install", 0),
+ total=timer.total,
+ )
_print_installed_pkg(pkg.spec.prefix)
spack.hooks.post_install(pkg.spec)
return True
-def _print_installed_pkg(message):
- """
- Output a message with a package icon.
-
- Args:
- message (str): message to be output
- """
- print(colorize("@*g{[+]} ") + spack.util.path.debug_padded_filter(message))
-
-
def _process_external_package(pkg, explicit):
"""
Helper function to run post install hooks and register external packages.
@@ -345,7 +369,9 @@ def _process_external_package(pkg, explicit):
spack.store.db.add(spec, None, explicit=explicit)
-def _process_binary_cache_tarball(pkg, binary_spec, explicit, unsigned, mirrors_for_spec=None):
+def _process_binary_cache_tarball(
+ pkg, binary_spec, explicit, unsigned, mirrors_for_spec=None, timer=None
+):
"""
Process the binary cache tarball.
@@ -357,6 +383,7 @@ def _process_binary_cache_tarball(pkg, binary_spec, explicit, unsigned, mirrors_
otherwise, ``False``
mirrors_for_spec (list): Optional list of concrete specs and mirrors
obtained by calling binary_distribution.get_mirrors_for_spec().
+ timer (Timer): timer to keep track of binary install phases.
Return:
bool: ``True`` if the package was extracted from binary cache,
@@ -365,6 +392,8 @@ def _process_binary_cache_tarball(pkg, binary_spec, explicit, unsigned, mirrors_
download_result = binary_distribution.download_tarball(
binary_spec, unsigned, mirrors_for_spec=mirrors_for_spec
)
+ if timer:
+ timer.phase("fetch")
# see #10063 : install from source if tarball doesn't exist
if download_result is None:
tty.msg("{0} exists in binary cache but with different hash".format(pkg.name))
@@ -381,10 +410,12 @@ def _process_binary_cache_tarball(pkg, binary_spec, explicit, unsigned, mirrors_
pkg.installed_from_binary_cache = True
spack.store.db.add(pkg.spec, spack.store.layout, explicit=explicit)
+ if timer:
+ timer.phase("install")
return True
-def _try_install_from_binary_cache(pkg, explicit, unsigned=False):
+def _try_install_from_binary_cache(pkg, explicit, unsigned=False, timer=None):
"""
Try to extract the package from binary cache.
@@ -393,16 +424,20 @@ def _try_install_from_binary_cache(pkg, explicit, unsigned=False):
explicit (bool): the package was explicitly requested by the user
unsigned (bool): ``True`` if binary package signatures to be checked,
otherwise, ``False``
+ timer (Timer):
"""
pkg_id = package_id(pkg)
tty.debug("Searching for binary cache of {0}".format(pkg_id))
matches = binary_distribution.get_mirrors_for_spec(pkg.spec)
+ if timer:
+ timer.phase("search")
+
if not matches:
return False
return _process_binary_cache_tarball(
- pkg, pkg.spec, explicit, unsigned, mirrors_for_spec=matches
+ pkg, pkg.spec, explicit, unsigned, mirrors_for_spec=matches, timer=timer
)
@@ -1841,8 +1876,7 @@ class BuildProcessInstaller(object):
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 ""
- self.pre = "{0}{1}:".format(pid, pkg.name)
+ self.pre = _log_prefix(pkg.name)
self.pkg_id = package_id(pkg)
def run(self):
@@ -1885,12 +1919,12 @@ class BuildProcessInstaller(object):
# Run post install hooks before build stage is removed.
spack.hooks.post_install(self.pkg.spec)
- build_time = self.timer.total - self.pkg._fetch_time
- tty.msg(
- "{0} Successfully installed {1}".format(self.pre, self.pkg_id),
- "Fetch: {0}. Build: {1}. Total: {2}.".format(
- _hms(self.pkg._fetch_time), _hms(build_time), _hms(self.timer.total)
- ),
+ _print_timer(
+ pre=self.pre,
+ pkg_id=self.pkg_id,
+ fetch=self.pkg._fetch_time,
+ build=self.timer.total - self.pkg._fetch_time,
+ total=self.timer.total,
)
_print_installed_pkg(self.pkg.prefix)
--
cgit v1.2.3-70-g09d2