From a0182c069fb69f9df10a23ad929874505f9ec89e Mon Sep 17 00:00:00 2001
From: Harmen Stoppels <harmenstoppels@gmail.com>
Date: Tue, 15 Nov 2022 21:10:07 +0100
Subject: Show time per phase (#33874)
---
lib/spack/spack/installer.py | 25 ++++++++++---------------
lib/spack/spack/test/install.py | 2 +-
2 files changed, 11 insertions(+), 16 deletions(-)
(limited to 'lib')
diff --git a/lib/spack/spack/installer.py b/lib/spack/spack/installer.py
index 7a69d80abc..60891b75c4 100644
--- a/lib/spack/spack/installer.py
+++ b/lib/spack/spack/installer.py
@@ -279,11 +279,10 @@ def _print_installed_pkg(message):
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 _print_timer(pre, pkg_id, timer):
+ phases = ["{}: {}.".format(p.capitalize(), _hms(timer.duration(p))) for p in timer.phases]
+ phases.append("Total: {}".format(_hms(timer.duration())))
+ tty.msg("{0} Successfully installed {1}".format(pre, pkg_id), " ".join(phases))
def _install_from_cache(pkg, cache_only, explicit, unsigned=False):
@@ -316,13 +315,7 @@ def _install_from_cache(pkg, cache_only, explicit, unsigned=False):
return False
t.stop()
tty.debug("Successfully extracted {0} from binary cache".format(pkg_id))
- _print_timer(
- pre=_log_prefix(pkg.name),
- pkg_id=pkg_id,
- fetch=t.duration("search") + t.duration("fetch"),
- build=t.duration("install"),
- total=t.duration(),
- )
+ _print_timer(pre=_log_prefix(pkg.name), pkg_id=pkg_id, timer=t)
_print_installed_pkg(pkg.spec.prefix)
spack.hooks.post_install(pkg.spec)
return True
@@ -1918,12 +1911,16 @@ class BuildProcessInstaller(object):
def run(self):
"""Main entry point from ``build_process`` to kick off install in child."""
+ self.timer.start("stage")
+
if not self.fake:
if not self.skip_patch:
self.pkg.do_patch()
else:
self.pkg.do_stage()
+ self.timer.stop("stage")
+
tty.debug(
"{0} Building {1} [{2}]".format(self.pre, self.pkg_id, self.pkg.build_system_class)
)
@@ -1958,9 +1955,7 @@ class BuildProcessInstaller(object):
_print_timer(
pre=self.pre,
pkg_id=self.pkg_id,
- fetch=self.pkg._fetch_time,
- build=self.timer.duration() - self.pkg._fetch_time,
- total=self.timer.duration(),
+ timer=self.timer,
)
_print_installed_pkg(self.pkg.prefix)
diff --git a/lib/spack/spack/test/install.py b/lib/spack/spack/test/install.py
index 4f6ef31a41..6b67c4c7ce 100644
--- a/lib/spack/spack/test/install.py
+++ b/lib/spack/spack/test/install.py
@@ -252,7 +252,7 @@ def test_install_times(install_mockery, mock_fetch, mutable_mock_repo):
# The order should be maintained
phases = [x["name"] for x in times["phases"]]
- assert phases == ["one", "two", "three", "install"]
+ assert phases == ["stage", "one", "two", "three", "install"]
assert all(isinstance(x["seconds"], float) for x in times["phases"])
--
cgit v1.2.3-70-g09d2