Improved package.py error handling. (#2187)
- Detailed debug information is now handed back to the parent process from builds, for *any* type of exception. - previously this only worked for Spack ProcessErrors, but now it works for any type of error raised in a child. - Spack will print an error message and source code context for build errors by default. - It will print a stack trace when using `spack -d`, even when the error occurred in the child process.
This commit is contained in:
Todd Gamblin
GitHub
parent
1b7f9e24f4
commit
edfe2297fd
@ -51,10 +51,12 @@
|
||||
Skimming this module is a nice way to get acquainted with the types of
|
||||
calls you can make from within the install() function.
|
||||
"""
|
||||
import multiprocessing
|
||||
import os
|
||||
import shutil
|
||||
import sys
|
||||
import multiprocessing
|
||||
import traceback
|
||||
import inspect
|
||||
import shutil
|
||||
|
||||
import llnl.util.tty as tty
|
||||
import spack
|
||||
@ -530,9 +532,29 @@ def child_execution(child_connection):
|
||||
try:
|
||||
setup_package(pkg, dirty=dirty)
|
||||
function()
|
||||
child_connection.send([None, None, None])
|
||||
except Exception as e:
|
||||
child_connection.send([type(e), e, None])
|
||||
child_connection.send(None)
|
||||
except:
|
||||
# catch ANYTHING that goes wrong in the child process
|
||||
exc_type, exc, tb = sys.exc_info()
|
||||
|
||||
# Need to unwind the traceback in the child because traceback
|
||||
# objects can't be sent to the parent.
|
||||
tb_string = traceback.format_exc()
|
||||
|
||||
# build up some context from the offending package so we can
|
||||
# show that, too.
|
||||
package_context = get_package_context(tb)
|
||||
|
||||
build_log = None
|
||||
if hasattr(pkg, 'log_path'):
|
||||
build_log = pkg.log_path
|
||||
|
||||
# make a pickleable exception to send to parent.
|
||||
msg = "%s: %s" % (str(exc_type.__name__), str(exc))
|
||||
|
||||
ce = ChildError(msg, tb_string, build_log, package_context)
|
||||
child_connection.send(ce)
|
||||
|
||||
finally:
|
||||
child_connection.close()
|
||||
|
||||
@ -542,11 +564,126 @@ def child_execution(child_connection):
|
||||
args=(child_connection,)
|
||||
)
|
||||
p.start()
|
||||
exc_type, exception, traceback = parent_connection.recv()
|
||||
child_exc = parent_connection.recv()
|
||||
p.join()
|
||||
if exception is not None:
|
||||
raise exception
|
||||
|
||||
if child_exc is not None:
|
||||
raise child_exc
|
||||
|
||||
|
||||
def get_package_context(traceback):
|
||||
"""Return some context for an error message when the build fails.
|
||||
|
||||
Args:
|
||||
traceback -- A traceback from some exception raised during install.
|
||||
|
||||
This function inspects the stack to find where we failed in the
|
||||
package file, and it adds detailed context to the long_message
|
||||
from there.
|
||||
|
||||
"""
|
||||
def make_stack(tb, stack=None):
|
||||
"""Tracebacks come out of the system in caller -> callee order. Return
|
||||
an array in callee -> caller order so we can traverse it."""
|
||||
if stack is None:
|
||||
stack = []
|
||||
if tb is not None:
|
||||
make_stack(tb.tb_next, stack)
|
||||
stack.append(tb)
|
||||
return stack
|
||||
|
||||
stack = make_stack(traceback)
|
||||
|
||||
for tb in stack:
|
||||
frame = tb.tb_frame
|
||||
if 'self' in frame.f_locals:
|
||||
# Find the first proper subclass of spack.PackageBase.
|
||||
obj = frame.f_locals['self']
|
||||
if isinstance(obj, spack.PackageBase):
|
||||
break
|
||||
|
||||
# we found obj, the Package implementation we care about.
|
||||
# point out the location in the install method where we failed.
|
||||
lines = []
|
||||
lines.append("%s:%d, in %s:" % (
|
||||
inspect.getfile(frame.f_code), frame.f_lineno, frame.f_code.co_name
|
||||
))
|
||||
|
||||
# Build a message showing context in the install method.
|
||||
sourcelines, start = inspect.getsourcelines(frame)
|
||||
for i, line in enumerate(sourcelines):
|
||||
mark = ">> " if start + i == frame.f_lineno else " "
|
||||
lines.append(" %s%-5d%s" % (mark, start + i, line.rstrip()))
|
||||
|
||||
return lines
|
||||
|
||||
|
||||
class InstallError(spack.error.SpackError):
|
||||
"""Raised when a package fails to install"""
|
||||
"""Raised by packages when a package fails to install"""
|
||||
|
||||
|
||||
class ChildError(spack.error.SpackError):
|
||||
"""Special exception class for wrapping exceptions from child processes
|
||||
in Spack's build environment.
|
||||
|
||||
The main features of a ChildError are:
|
||||
|
||||
1. They're serializable, so when a child build fails, we can send one
|
||||
of these to the parent and let the parent report what happened.
|
||||
|
||||
2. They have a ``traceback`` field containing a traceback generated
|
||||
on the child immediately after failure. Spack will print this on
|
||||
failure in lieu of trying to run sys.excepthook on the parent
|
||||
process, so users will see the correct stack trace from a child.
|
||||
|
||||
3. They also contain package_context, which shows source code context
|
||||
in the Package implementation where the error happened. To get
|
||||
this, Spack searches the stack trace for the deepest frame where
|
||||
``self`` is in scope and is an instance of PackageBase. This will
|
||||
generally find a useful spot in the ``package.py`` file.
|
||||
|
||||
The long_message of a ChildError displays all this stuff to the user,
|
||||
and SpackError handles displaying the special traceback if we're in
|
||||
debug mode with spack -d.
|
||||
|
||||
"""
|
||||
def __init__(self, msg, traceback_string, build_log, package_context):
|
||||
super(ChildError, self).__init__(msg)
|
||||
self.traceback = traceback_string
|
||||
self.build_log = build_log
|
||||
self.package_context = package_context
|
||||
|
||||
@property
|
||||
def long_message(self):
|
||||
msg = self._long_message if self._long_message else ''
|
||||
|
||||
if self.package_context:
|
||||
if msg:
|
||||
msg += "\n\n"
|
||||
msg += '\n'.join(self.package_context)
|
||||
|
||||
if msg:
|
||||
msg += "\n\n"
|
||||
|
||||
if self.build_log:
|
||||
msg += "See build log for details:\n"
|
||||
msg += " %s" % self.build_log
|
||||
|
||||
return msg
|
||||
|
||||
def __reduce__(self):
|
||||
"""__reduce__ is used to serialize (pickle) ChildErrors.
|
||||
|
||||
Return a function to reconstruct a ChildError, along with the
|
||||
salient properties we'll need.
|
||||
"""
|
||||
return _make_child_error, (
|
||||
self.message,
|
||||
self.traceback,
|
||||
self.build_log,
|
||||
self.package_context)
|
||||
|
||||
|
||||
def _make_child_error(msg, traceback, build_log, package_context):
|
||||
"""Used by __reduce__ in ChildError to reconstruct pickled errors."""
|
||||
return ChildError(msg, traceback, build_log, package_context)
|
||||
|
||||
@ -39,19 +39,31 @@ def __init__(self, message, long_message=None):
|
||||
self.message = message
|
||||
self._long_message = long_message
|
||||
|
||||
# for exceptions raised from child build processes, we save the
|
||||
# traceback as a string and print it in the parent.
|
||||
self.traceback = None
|
||||
|
||||
@property
|
||||
def long_message(self):
|
||||
return self._long_message
|
||||
|
||||
def die(self):
|
||||
# basic debug message
|
||||
tty.error(self.message)
|
||||
if self.long_message:
|
||||
print(self.long_message)
|
||||
|
||||
# stack trace, etc. in debug mode.
|
||||
if spack.debug:
|
||||
sys.excepthook(*sys.exc_info())
|
||||
os._exit(1)
|
||||
else:
|
||||
tty.error(self.message)
|
||||
if self.long_message:
|
||||
print(self.long_message)
|
||||
os._exit(1)
|
||||
if self.traceback:
|
||||
# exception came from a build child, already got
|
||||
# traceback in child, so print it.
|
||||
sys.stderr.write(self.traceback)
|
||||
else:
|
||||
# run parent exception hook.
|
||||
sys.excepthook(*sys.exc_info())
|
||||
|
||||
os._exit(1)
|
||||
|
||||
def __str__(self):
|
||||
msg = self.message
|
||||
|
||||
@ -65,7 +65,6 @@
|
||||
from spack.stage import Stage, ResourceStage, StageComposite
|
||||
from spack.util.crypto import bit_length
|
||||
from spack.util.environment import dump_environment
|
||||
from spack.util.executable import ProcessError
|
||||
from spack.version import *
|
||||
|
||||
"""Allowed URL schemes for spack packages."""
|
||||
@ -96,6 +95,8 @@ def __get__(self, instance, owner):
|
||||
# install phase, thus return a properly set wrapper
|
||||
phase = getattr(instance, self.name)
|
||||
|
||||
print phase
|
||||
|
||||
@functools.wraps(phase)
|
||||
def phase_wrapper(spec, prefix):
|
||||
# Check instance attributes at the beginning of a phase
|
||||
@ -1213,60 +1214,57 @@ def build_process():
|
||||
|
||||
self.stage.keep = keep_stage
|
||||
|
||||
try:
|
||||
with contextlib.nested(self.stage, self._prefix_write_lock()):
|
||||
# Run the pre-install hook in the child process after
|
||||
# the directory is created.
|
||||
spack.hooks.pre_install(self)
|
||||
if fake:
|
||||
self.do_fake_install()
|
||||
else:
|
||||
# Do the real install in the source directory.
|
||||
self.stage.chdir_to_source()
|
||||
# Save the build environment in a file before building.
|
||||
env_path = join_path(os.getcwd(), 'spack-build.env')
|
||||
# Redirect I/O to a build log (and optionally to
|
||||
# the terminal)
|
||||
log_path = join_path(os.getcwd(), 'spack-build.out')
|
||||
# FIXME : refactor this assignment
|
||||
self.log_path = log_path
|
||||
self.env_path = env_path
|
||||
dump_environment(env_path)
|
||||
# Spawn a daemon that reads from a pipe and redirects
|
||||
# everything to log_path
|
||||
redirection_context = log_output(
|
||||
log_path, verbose,
|
||||
sys.stdout.isatty(),
|
||||
True
|
||||
)
|
||||
with redirection_context as log_redirection:
|
||||
for phase_name, phase in zip(self.phases, self._InstallPhase_phases): # NOQA: ignore=E501
|
||||
tty.msg(
|
||||
'Executing phase : \'{0}\''.format(phase_name) # NOQA: ignore=E501
|
||||
)
|
||||
# Redirect stdout and stderr to daemon pipe
|
||||
with log_redirection:
|
||||
getattr(self, phase)(
|
||||
self.spec, self.prefix)
|
||||
self.log()
|
||||
# Run post install hooks before build stage is removed.
|
||||
spack.hooks.post_install(self)
|
||||
with contextlib.nested(self.stage, self._prefix_write_lock()):
|
||||
# Run the pre-install hook in the child process after
|
||||
# the directory is created.
|
||||
spack.hooks.pre_install(self)
|
||||
if fake:
|
||||
self.do_fake_install()
|
||||
else:
|
||||
# Do the real install in the source directory.
|
||||
self.stage.chdir_to_source()
|
||||
|
||||
# Stop timer.
|
||||
self._total_time = time.time() - start_time
|
||||
build_time = self._total_time - self._fetch_time
|
||||
# Save the build environment in a file before building.
|
||||
env_path = join_path(os.getcwd(), 'spack-build.env')
|
||||
|
||||
tty.msg("Successfully installed %s" % self.name,
|
||||
"Fetch: %s. Build: %s. Total: %s." %
|
||||
(_hms(self._fetch_time), _hms(build_time),
|
||||
_hms(self._total_time)))
|
||||
print_pkg(self.prefix)
|
||||
# Redirect I/O to a build log (and optionally to
|
||||
# the terminal)
|
||||
log_path = join_path(os.getcwd(), 'spack-build.out')
|
||||
|
||||
except ProcessError as e:
|
||||
# Annotate ProcessErrors with the location of
|
||||
# the build log
|
||||
e.build_log = log_path
|
||||
raise e
|
||||
# FIXME : refactor this assignment
|
||||
self.log_path = log_path
|
||||
self.env_path = env_path
|
||||
dump_environment(env_path)
|
||||
|
||||
# Spawn a daemon that reads from a pipe and redirects
|
||||
# everything to log_path
|
||||
redirection_context = log_output(
|
||||
log_path, verbose,
|
||||
sys.stdout.isatty(),
|
||||
True
|
||||
)
|
||||
with redirection_context as log_redirection:
|
||||
for phase_name, phase in zip(self.phases, self._InstallPhase_phases): # NOQA: ignore=E501
|
||||
tty.msg(
|
||||
'Executing phase : \'{0}\''.format(phase_name) # NOQA: ignore=E501
|
||||
)
|
||||
# Redirect stdout and stderr to daemon pipe
|
||||
with log_redirection:
|
||||
getattr(self, phase)(
|
||||
self.spec, self.prefix)
|
||||
self.log()
|
||||
# Run post install hooks before build stage is removed.
|
||||
spack.hooks.post_install(self)
|
||||
|
||||
# Stop timer.
|
||||
self._total_time = time.time() - start_time
|
||||
build_time = self._total_time - self._fetch_time
|
||||
|
||||
tty.msg("Successfully installed %s" % self.name,
|
||||
"Fetch: %s. Build: %s. Total: %s." %
|
||||
(_hms(self._fetch_time), _hms(build_time),
|
||||
_hms(self._total_time)))
|
||||
print_pkg(self.prefix)
|
||||
|
||||
try:
|
||||
# Create the install prefix and fork the build process.
|
||||
|
||||
@ -26,7 +26,6 @@
|
||||
import os
|
||||
import re
|
||||
import subprocess
|
||||
import inspect
|
||||
|
||||
import llnl.util.tty as tty
|
||||
import spack
|
||||
@ -237,94 +236,4 @@ def which(name, **kwargs):
|
||||
|
||||
|
||||
class ProcessError(spack.error.SpackError):
|
||||
|
||||
def __init__(self, msg, long_message=None):
|
||||
# These are used for detailed debugging information for
|
||||
# package builds. They're built up gradually as the exception
|
||||
# propagates.
|
||||
self.package_context = _get_package_context()
|
||||
self.build_log = None
|
||||
|
||||
super(ProcessError, self).__init__(msg, long_message)
|
||||
|
||||
@property
|
||||
def long_message(self):
|
||||
|
||||
msg = self._long_message if self._long_message else ''
|
||||
|
||||
if self.package_context:
|
||||
if msg:
|
||||
msg += "\n\n"
|
||||
msg += '\n'.join(self.package_context)
|
||||
|
||||
if msg:
|
||||
msg += "\n\n"
|
||||
|
||||
if self.build_log:
|
||||
msg += "See build log for details:\n"
|
||||
msg += " %s" % self.build_log
|
||||
|
||||
return msg
|
||||
|
||||
def __reduce__(self):
|
||||
# We need this constructor because we are trying to move a ProcessError
|
||||
# across processes. This means that we have to preserve the original
|
||||
# package context and build log
|
||||
return _make_process_error, (
|
||||
self.message,
|
||||
self._long_message,
|
||||
self.package_context,
|
||||
self.build_log
|
||||
)
|
||||
|
||||
|
||||
def _make_process_error(msg, long_message, pkg_context, build_log):
|
||||
a = ProcessError(msg, long_message)
|
||||
a.package_context = pkg_context
|
||||
a.build_log = build_log
|
||||
return a
|
||||
|
||||
|
||||
def _get_package_context():
|
||||
"""Return some context for an error message when the build fails.
|
||||
|
||||
This should be called within a ProcessError when the exception is
|
||||
thrown.
|
||||
|
||||
Args:
|
||||
process_error -- A ProcessError raised during install()
|
||||
|
||||
This function inspects the stack to find where we failed in the
|
||||
package file, and it adds detailed context to the long_message
|
||||
from there.
|
||||
|
||||
"""
|
||||
lines = []
|
||||
|
||||
# Walk up the stack
|
||||
for f in inspect.stack():
|
||||
frame = f[0]
|
||||
|
||||
# Find a frame with 'self' in the local variables.
|
||||
if 'self' not in frame.f_locals:
|
||||
continue
|
||||
|
||||
# Look only at a frame in a subclass of spack.Package
|
||||
obj = frame.f_locals['self']
|
||||
if type(obj) != spack.PackageBase and isinstance(obj, spack.PackageBase): # NOQA: ignore=E501
|
||||
break
|
||||
else:
|
||||
# Didn't find anything
|
||||
return lines
|
||||
|
||||
# Build a message showing where in install we failed.
|
||||
lines.append("%s:%d, in %s:" % (
|
||||
inspect.getfile(frame.f_code), frame.f_lineno, frame.f_code.co_name
|
||||
))
|
||||
|
||||
sourcelines, start = inspect.getsourcelines(frame)
|
||||
for i, line in enumerate(sourcelines):
|
||||
mark = ">> " if start + i == frame.f_lineno else " "
|
||||
lines.append(" %s%-5d%s" % (mark, start + i, line.rstrip()))
|
||||
|
||||
return lines
|
||||
"""ProcessErrors are raised when Executables exit with an error code."""
|
||||
|
||||
Loading…
Reference in New Issue
Block a user