summaryrefslogtreecommitdiff
path: root/lib
diff options
context:
space:
mode:
Diffstat (limited to 'lib')
-rw-r--r--lib/spack/spack/installer.py18
-rw-r--r--lib/spack/spack/package.py9
-rw-r--r--lib/spack/spack/solver/asp.py28
-rw-r--r--lib/spack/spack/test/cmd/install.py25
-rw-r--r--lib/spack/spack/test/install.py27
-rw-r--r--lib/spack/spack/util/timer.py60
6 files changed, 123 insertions, 44 deletions
diff --git a/lib/spack/spack/installer.py b/lib/spack/spack/installer.py
index 4ee56db26d..fd6bc31d4b 100644
--- a/lib/spack/spack/installer.py
+++ b/lib/spack/spack/installer.py
@@ -56,7 +56,7 @@ from llnl.util.tty.color import colorize
from llnl.util.tty.log import log_output
from spack.util.environment import dump_environment
from spack.util.executable import which
-
+from spack.util.timer import Timer
#: Counter to support unique spec sequencing that is used to ensure packages
#: with the same priority are (initially) processed in the order in which they
@@ -1685,7 +1685,7 @@ def build_process(pkg, kwargs):
unmodified_env = kwargs.get('unmodified_env', {})
verbose = kwargs.get('verbose', False)
- start_time = time.time()
+ timer = Timer()
if not fake:
if not skip_patch:
pkg.do_patch()
@@ -1770,9 +1770,9 @@ def build_process(pkg, kwargs):
# Redirect stdout and stderr to daemon pipe
phase = getattr(pkg, phase_attr)
+ timer.phase(phase_name)
# Catch any errors to report to logging
-
phase(pkg.spec, pkg.prefix)
spack.hooks.on_phase_success(pkg, phase_name, log_file)
@@ -1788,17 +1788,19 @@ def build_process(pkg, kwargs):
combine_phase_logs(pkg.phase_log_files, pkg.log_path)
log(pkg)
+ # Stop the timer and save results
+ timer.stop()
+ with open(pkg.times_log_path, 'w') as timelog:
+ timer.write_json(timelog)
+
# Run post install hooks before build stage is removed.
spack.hooks.post_install(pkg.spec)
- # Stop the timer
- pkg._total_time = time.time() - start_time
- build_time = pkg._total_time - pkg._fetch_time
-
+ build_time = timer.total - pkg._fetch_time
tty.msg('{0} Successfully installed {1}'.format(pre, pkg_id),
'Fetch: {0}. Build: {1}. Total: {2}.'
.format(_hms(pkg._fetch_time), _hms(build_time),
- _hms(pkg._total_time)))
+ _hms(timer.total)))
_print_installed_pkg(pkg.prefix)
# Send final status that install is successful
diff --git a/lib/spack/spack/package.py b/lib/spack/spack/package.py
index 051f135667..7db7f76589 100644
--- a/lib/spack/spack/package.py
+++ b/lib/spack/spack/package.py
@@ -71,6 +71,9 @@ _spack_build_logfile = 'spack-build-out.txt'
# Filename for the Spack build/install environment file.
_spack_build_envfile = 'spack-build-env.txt'
+# Filename of json with total build and phase times (seconds)
+_spack_times_log = 'install_times.json'
+
# Filename for the Spack configure args file.
_spack_configure_argsfile = 'spack-configure-args.txt'
@@ -699,7 +702,6 @@ class PackageBase(six.with_metaclass(PackageMeta, PackageViewMixin, object)):
# Set up timing variables
self._fetch_time = 0.0
- self._total_time = 0.0
if self.is_extension:
spack.repo.get(self.extendee_spec)._check_extendable()
@@ -1093,6 +1095,11 @@ class PackageBase(six.with_metaclass(PackageMeta, PackageViewMixin, object)):
return os.path.join(self.stage.path, _spack_configure_argsfile)
@property
+ def times_log_path(self):
+ """Return the times log json file."""
+ return os.path.join(self.metadata_dir, _spack_times_log)
+
+ @property
def install_configure_args_path(self):
"""Return the configure args file path on successful installation."""
return os.path.join(self.metadata_dir, _spack_configure_argsfile)
diff --git a/lib/spack/spack/solver/asp.py b/lib/spack/spack/solver/asp.py
index 5bfbf1a6a0..94cc35d8de 100644
--- a/lib/spack/spack/solver/asp.py
+++ b/lib/spack/spack/solver/asp.py
@@ -10,7 +10,6 @@ import itertools
import os
import pprint
import sys
-import time
import types
import warnings
from six import string_types
@@ -43,7 +42,7 @@ import spack.repo
import spack.bootstrap
import spack.variant
import spack.version
-
+import spack.util.timer
if sys.version_info >= (3, 3):
from collections.abc import Sequence # novm
@@ -51,27 +50,6 @@ else:
from collections import Sequence
-class Timer(object):
- """Simple timer for timing phases of a solve"""
- def __init__(self):
- self.start = time.time()
- self.last = self.start
- self.phases = {}
-
- def phase(self, name):
- last = self.last
- now = time.time()
- self.phases[name] = now - last
- self.last = now
-
- def write(self, out=sys.stdout):
- now = time.time()
- out.write("Time:\n")
- for phase, t in self.phases.items():
- out.write(" %-15s%.4f\n" % (phase + ":", t))
- out.write("Total: %.4f\n" % (now - self.start))
-
-
def issequence(obj):
if isinstance(obj, string_types):
return False
@@ -331,7 +309,7 @@ class PyclingoDriver(object):
self, solver_setup, specs, dump=None, nmodels=0,
timers=False, stats=False, tests=False
):
- timer = Timer()
+ timer = spack.util.timer.Timer()
# Initialize the control object for the solver
self.control = clingo.Control()
@@ -428,7 +406,7 @@ class PyclingoDriver(object):
result.cores.append(core_symbols)
if timers:
- timer.write()
+ timer.write_tty()
print()
if stats:
print("Statistics:")
diff --git a/lib/spack/spack/test/cmd/install.py b/lib/spack/spack/test/cmd/install.py
index 4808ea2b9d..328323b1af 100644
--- a/lib/spack/spack/test/cmd/install.py
+++ b/lib/spack/spack/test/cmd/install.py
@@ -201,26 +201,28 @@ def test_install_overwrite(
install('libdwarf')
+ # Ignore manifest and install times
manifest = os.path.join(spec.prefix, spack.store.layout.metadata_dir,
spack.store.layout.manifest_file_name)
+ ignores = [manifest, spec.package.times_log_path]
assert os.path.exists(spec.prefix)
- expected_md5 = fs.hash_directory(spec.prefix, ignore=[manifest])
+ expected_md5 = fs.hash_directory(spec.prefix, ignore=ignores)
# Modify the first installation to be sure the content is not the same
# as the one after we reinstalled
with open(os.path.join(spec.prefix, 'only_in_old'), 'w') as f:
f.write('This content is here to differentiate installations.')
- bad_md5 = fs.hash_directory(spec.prefix, ignore=[manifest])
+ bad_md5 = fs.hash_directory(spec.prefix, ignore=ignores)
assert bad_md5 != expected_md5
install('--overwrite', '-y', 'libdwarf')
assert os.path.exists(spec.prefix)
- assert fs.hash_directory(spec.prefix, ignore=[manifest]) == expected_md5
- assert fs.hash_directory(spec.prefix, ignore=[manifest]) != bad_md5
+ assert fs.hash_directory(spec.prefix, ignore=ignores) == expected_md5
+ assert fs.hash_directory(spec.prefix, ignore=ignores) != bad_md5
def test_install_overwrite_not_installed(
@@ -254,16 +256,19 @@ def test_install_overwrite_multiple(
spack.store.layout.metadata_dir,
spack.store.layout.manifest_file_name)
+ ld_ignores = [ld_manifest, libdwarf.package.times_log_path]
+
assert os.path.exists(libdwarf.prefix)
expected_libdwarf_md5 = fs.hash_directory(libdwarf.prefix,
- ignore=[ld_manifest])
+ ignore=ld_ignores)
cm_manifest = os.path.join(cmake.prefix,
spack.store.layout.metadata_dir,
spack.store.layout.manifest_file_name)
+ cm_ignores = [cm_manifest, cmake.package.times_log_path]
assert os.path.exists(cmake.prefix)
- expected_cmake_md5 = fs.hash_directory(cmake.prefix, ignore=[cm_manifest])
+ expected_cmake_md5 = fs.hash_directory(cmake.prefix, ignore=cm_ignores)
# Modify the first installation to be sure the content is not the same
# as the one after we reinstalled
@@ -272,8 +277,8 @@ def test_install_overwrite_multiple(
with open(os.path.join(cmake.prefix, 'only_in_old'), 'w') as f:
f.write('This content is here to differentiate installations.')
- bad_libdwarf_md5 = fs.hash_directory(libdwarf.prefix, ignore=[ld_manifest])
- bad_cmake_md5 = fs.hash_directory(cmake.prefix, ignore=[cm_manifest])
+ bad_libdwarf_md5 = fs.hash_directory(libdwarf.prefix, ignore=ld_ignores)
+ bad_cmake_md5 = fs.hash_directory(cmake.prefix, ignore=cm_ignores)
assert bad_libdwarf_md5 != expected_libdwarf_md5
assert bad_cmake_md5 != expected_cmake_md5
@@ -282,8 +287,8 @@ def test_install_overwrite_multiple(
assert os.path.exists(libdwarf.prefix)
assert os.path.exists(cmake.prefix)
- ld_hash = fs.hash_directory(libdwarf.prefix, ignore=[ld_manifest])
- cm_hash = fs.hash_directory(cmake.prefix, ignore=[cm_manifest])
+ ld_hash = fs.hash_directory(libdwarf.prefix, ignore=ld_ignores)
+ cm_hash = fs.hash_directory(cmake.prefix, ignore=cm_ignores)
assert ld_hash == expected_libdwarf_md5
assert cm_hash == expected_cmake_md5
assert ld_hash != bad_libdwarf_md5
diff --git a/lib/spack/spack/test/install.py b/lib/spack/spack/test/install.py
index 77810ff0e3..6a533bb8b1 100644
--- a/lib/spack/spack/test/install.py
+++ b/lib/spack/spack/test/install.py
@@ -15,6 +15,7 @@ import spack.patch
import spack.repo
import spack.store
from spack.spec import Spec
+import spack.util.spack_json as sjson
from spack.package import (_spack_build_envfile, _spack_build_logfile,
_spack_configure_argsfile)
@@ -161,6 +162,32 @@ def test_install_dependency_symlinks_pkg(
assert os.path.isdir(dependency_dir)
+def test_install_times(
+ install_mockery, mock_fetch, mutable_mock_repo):
+ """Test install times added."""
+ spec = Spec('dev-build-test-install-phases')
+ spec.concretize()
+ pkg = spec.package
+ pkg.do_install()
+
+ # Ensure dependency directory exists after the installation.
+ install_times = os.path.join(pkg.prefix, ".spack", 'install_times.json')
+ assert os.path.isfile(install_times)
+
+ # Ensure the phases are included
+ with open(install_times, 'r') as timefile:
+ times = sjson.load(timefile.read())
+
+ # The order should be maintained
+ phases = [x['name'] for x in times['phases']]
+ total = sum([x['seconds'] for x in times['phases']])
+ for name in ['one', 'two', 'three', 'install']:
+ assert name in phases
+
+ # Give a generous difference threshold
+ assert abs(total - times['total']['seconds']) < 5
+
+
def test_flatten_deps(
install_mockery, mock_fetch, mutable_mock_repo):
"""Explicitly test the flattening code for coverage purposes."""
diff --git a/lib/spack/spack/util/timer.py b/lib/spack/spack/util/timer.py
new file mode 100644
index 0000000000..077b81222f
--- /dev/null
+++ b/lib/spack/spack/util/timer.py
@@ -0,0 +1,60 @@
+# Copyright 2013-2021 Lawrence Livermore National Security, LLC and other
+# Spack Project Developers. See the top-level COPYRIGHT file for details.
+#
+# SPDX-License-Identifier: (Apache-2.0 OR MIT)
+
+"""Debug signal handler: prints a stack trace and enters interpreter.
+
+``register_interrupt_handler()`` enables a ctrl-C handler that prints
+a stack trace and drops the user into an interpreter.
+
+"""
+import spack.util.spack_json as sjson
+import time
+import sys
+
+
+class Timer(object):
+ """
+ Simple timer for timing phases of a solve or install
+ """
+ def __init__(self):
+ self.start = time.time()
+ self.last = self.start
+ self.phases = {}
+ self.end = None
+
+ def phase(self, name):
+ last = self.last
+ now = time.time()
+ self.phases[name] = now - last
+ self.last = now
+
+ @property
+ def total(self):
+ """Return the total time
+ """
+ if self.end:
+ return self.end - self.start
+ return time.time() - self.start
+
+ def stop(self):
+ """
+ Stop the timer to record a total time, if desired.
+ """
+ self.end = time.time()
+
+ def write_json(self, out=sys.stdout):
+ """
+ Write a json object with times to file
+ """
+ phases = [{"name": p, "seconds": s} for p, s in self.phases.items()]
+ times = {"phases": phases, "total": {"seconds": self.total}}
+ out.write(sjson.dump(times))
+
+ def write_tty(self, out=sys.stdout):
+ now = time.time()
+ out.write("Time:\n")
+ for phase, t in self.phases.items():
+ out.write(" %-15s%.4f\n" % (phase + ":", t))
+ out.write("Total: %.4f\n" % (now - self.start))
generated by cgit v1.2.3-70-g09d2 (git 2.46.0) at 2024-11-18 18:17:07 +0000