From d4d101f57e3b2c4ad021948f3f7a897de10ca338 Mon Sep 17 00:00:00 2001 From: Betsy McPhail Date: Fri, 6 Aug 2021 15:51:37 -0400 Subject: Allow 'spack external find' to find executables on the system path (#22091) Co-authored-by: Lou Lawrence --- lib/spack/llnl/util/tty/log.py | 165 +++++++++++++++++++++++++++++++++++++ lib/spack/spack/detection/path.py | 4 + lib/spack/spack/installer.py | 113 ++++++++++++++----------- lib/spack/spack/main.py | 14 +++- lib/spack/spack/util/executable.py | 2 + 5 files changed, 247 insertions(+), 51 deletions(-) (limited to 'lib') diff --git a/lib/spack/llnl/util/tty/log.py b/lib/spack/llnl/util/tty/log.py index 566d180645..e86724942a 100644 --- a/lib/spack/llnl/util/tty/log.py +++ b/lib/spack/llnl/util/tty/log.py @@ -12,10 +12,15 @@ import errno import multiprocessing import os import re +import io import select import signal import sys +import ctypes import traceback +import tempfile +import threading +from threading import Thread from contextlib import contextmanager from types import ModuleType # novm from typing import Optional # novm @@ -671,6 +676,166 @@ class log_output(object): sys.stdout.flush() +class StreamWrapper: + """ Wrapper class to handle redirection of io streams """ + def __init__(self, sys_attr): + self.sys_attr = sys_attr + self.saved_stream = None + if sys.platform.startswith('win32'): + if sys.version_info < (3, 5): + libc = ctypes.CDLL(ctypes.util.find_library('c')) + else: + if hasattr(sys, 'gettotalrefcount'): # debug build + libc = ctypes.CDLL('ucrtbased') + else: + libc = ctypes.CDLL('api-ms-win-crt-stdio-l1-1-0') + + kernel32 = ctypes.WinDLL('kernel32') + + # https://docs.microsoft.com/en-us/windows/console/getstdhandle + if self.sys_attr == 'stdout': + STD_HANDLE = -11 + elif self.sys_attr == 'stderr': + STD_HANDLE = -12 + else: + raise KeyError(self.sys_attr) + + c_stdout = kernel32.GetStdHandle(STD_HANDLE) + self.libc = libc + self.c_stream = c_stdout + else: + # The original fd stdout points to. Usually 1 on POSIX systems for stdout. + self.libc = ctypes.CDLL(None) + self.c_stream = ctypes.c_void_p.in_dll(self.libc, self.sys_attr) + self.sys_stream = getattr(sys, self.sys_attr) + self.orig_stream_fd = self.sys_stream.fileno() + # Save a copy of the original stdout fd in saved_stream + self.saved_stream = os.dup(self.orig_stream_fd) + + def redirect_stream(self, to_fd): + """Redirect stdout to the given file descriptor.""" + # Flush the C-level buffer stream + if sys.platform.startswith('win32'): + self.libc.fflush(None) + else: + self.libc.fflush(self.c_stream) + # Flush and close sys_stream - also closes the file descriptor (fd) + sys_stream = getattr(sys, self.sys_attr) + sys_stream.flush() + sys_stream.close() + # Make orig_stream_fd point to the same file as to_fd + os.dup2(to_fd, self.orig_stream_fd) + # Set sys_stream to a new stream that points to the redirected fd + new_buffer = open(self.orig_stream_fd, 'wb') + new_stream = io.TextIOWrapper(new_buffer) + setattr(sys, self.sys_attr, new_stream) + self.sys_stream = getattr(sys, self.sys_attr) + + def flush(self): + if sys.platform.startswith('win32'): + self.libc.fflush(None) + else: + self.libc.fflush(self.c_stream) + self.sys_stream.flush() + + def close(self): + """Redirect back to the original system stream, and close stream""" + try: + if self.saved_stream is not None: + self.redirect_stream(self.saved_stream) + finally: + if self.saved_stream is not None: + os.close(self.saved_stream) + + +class winlog: + def __init__(self, logfile, echo=False, debug=0, env=None): + self.env = env + self.debug = debug + self.echo = echo + self.logfile = logfile + self.stdout = StreamWrapper('stdout') + self.stderr = StreamWrapper('stderr') + self._active = False + + def __enter__(self): + if self._active: + raise RuntimeError("Can't re-enter the same log_output!") + + if self.logfile is None: + raise RuntimeError( + "file argument must be set by __init__ ") + + # Open both write and reading on logfile + if type(self.logfile) == StringIO: + # cannot have two streams on tempfile, so we must make our own + self.writer = open('temp.txt', mode='wb+') + self.reader = open('temp.txt', mode='rb+') + else: + self.writer = open(self.logfile, mode='wb+') + self.reader = open(self.logfile, mode='rb+') + # Dup stdout so we can still write to it after redirection + self.echo_writer = open(os.dup(sys.stdout.fileno()), "w") + # Redirect stdout and stderr to write to logfile + self.stderr.redirect_stream(self.writer.fileno()) + self.stdout.redirect_stream(self.writer.fileno()) + self._kill = threading.Event() + + def background_reader(reader, echo_writer, _kill): + # for each line printed to logfile, read it + # if echo: write line to user + while True: + is_killed = _kill.wait(.1) + self.stderr.flush() + self.stdout.flush() + line = reader.readline() + while line: + if self.echo: + self.echo_writer.write('{0}'.format(line.decode())) + self.echo_writer.flush() + line = reader.readline() + + if is_killed: + break + + self._active = True + with replace_environment(self.env): + self._thread = Thread(target=background_reader, args=(self.reader, self.echo_writer, self._kill)) + self._thread.start() + + def __exit__(self, exc_type, exc_val, exc_tb): + self.echo_writer.flush() + self.stdout.flush() + self.stderr.flush() + self._kill.set() + self._thread.join() + self.stdout.close() + self.stderr.close() + if os.path.exists("temp.txt"): + os.remove("temp.txt") + self._active = False + + @contextmanager + def force_echo(self): + """Context manager to force local echo, even if echo is off.""" + if not self._active: + raise RuntimeError( + "Can't call force_echo() outside log_output region!") + + # This uses the xon/xoff to highlight regions to be echoed in the + # output. We use these control characters rather than, say, a + # separate pipe, because they're in-band and assured to appear + # exactly before and after the text we want to echo. + sys.stdout.write(xon) + sys.stdout.flush() + try: + yield + finally: + sys.stdout.write(xoff) + sys.stdout.flush() + + + def _writer_daemon(stdin_multiprocess_fd, read_multiprocess_fd, write_fd, echo, log_file_wrapper, control_pipe, filter_fn): """Daemon used by ``log_output`` to write to a log file and to ``stdout``. diff --git a/lib/spack/spack/detection/path.py b/lib/spack/spack/detection/path.py index e0b0b136ec..6f6e7c32a7 100644 --- a/lib/spack/spack/detection/path.py +++ b/lib/spack/spack/detection/path.py @@ -9,8 +9,10 @@ import collections import os import os.path import re +import sys import warnings + import llnl.util.filesystem import llnl.util.tty @@ -73,6 +75,8 @@ def by_executable(packages_to_check, path_hints=None): for pkg in packages_to_check: if hasattr(pkg, 'executables'): for exe in pkg.executables: + if sys.platform == 'win32': + exe = exe.replace('$', r'\.exe$') exe_pattern_to_pkgs[exe].append(pkg) pkg_to_found_exes = collections.defaultdict(set) diff --git a/lib/spack/spack/installer.py b/lib/spack/spack/installer.py index 41de608fff..35403a6cc1 100644 --- a/lib/spack/spack/installer.py +++ b/lib/spack/spack/installer.py @@ -43,7 +43,7 @@ import llnl.util.filesystem as fs import llnl.util.lock as lk import llnl.util.tty as tty from llnl.util.tty.color import colorize -from llnl.util.tty.log import log_output +from llnl.util.tty.log import log_output, winlog import spack.binary_distribution as binary_distribution import spack.compilers @@ -1936,61 +1936,80 @@ class BuildProcessInstaller(object): # Spawn a daemon that reads from a pipe and redirects # everything to log_path, and provide the phase for logging - for i, (phase_name, phase_attr) in enumerate(zip( - pkg.phases, pkg._InstallPhase_phases)): + if sys.platform != 'win32': + for i, (phase_name, phase_attr) in enumerate(zip( + pkg.phases, pkg._InstallPhase_phases)): + + # Keep a log file for each phase + log_dir = os.path.dirname(pkg.log_path) + log_file = "spack-build-%02d-%s-out.txt" % ( + i + 1, phase_name.lower() + ) + log_file = os.path.join(log_dir, log_file) + + try: + # DEBUGGING TIP - to debug this section, insert an IPython + # embed here, and run the sections below without log capture + log_contextmanager = log_output( + log_file, + self.echo, + True, + env=self.unmodified_env, + filter_fn=self.filter_fn + ) + + with log_contextmanager as logger: + with logger.force_echo(): + inner_debug_level = tty.debug_level() + tty.set_debug(debug_level) + tty.msg( + "{0} Executing phase: '{1}'" .format( + self.pre, + phase_name + ) + ) + tty.set_debug(inner_debug_level) - # Keep a log file for each phase - log_dir = os.path.dirname(pkg.log_path) - log_file = "spack-build-%02d-%s-out.txt" % ( - i + 1, phase_name.lower() - ) - log_file = os.path.join(log_dir, log_file) + # Redirect stdout and stderr to daemon pipe + phase = getattr(pkg, phase_attr) + self.timer.phase(phase_name) - try: - # DEBUGGING TIP - to debug this section, insert an IPython - # embed here, and run the sections below without log capture - log_contextmanager = log_output( - log_file, - self.echo, - True, - env=self.unmodified_env, - filter_fn=self.filter_fn - ) + # Catch any errors to report to logging + phase(pkg.spec, pkg.prefix) + spack.hooks.on_phase_success(pkg, phase_name, log_file) - with log_contextmanager as logger: - with logger.force_echo(): - inner_debug_level = tty.debug_level() - tty.set_debug(debug_level) - tty.msg( - "{0} Executing phase: '{1}'" .format( - self.pre, - phase_name - ) - ) - tty.set_debug(inner_debug_level) + except BaseException: + combine_phase_logs(pkg.phase_log_files, pkg.log_path) + spack.hooks.on_phase_error(pkg, phase_name, log_file) - # Redirect stdout and stderr to daemon pipe - phase = getattr(pkg, phase_attr) - self.timer.phase(phase_name) + # phase error indicates install error + spack.hooks.on_install_failure(pkg.spec) + raise - # Catch any errors to report to logging - phase(pkg.spec, pkg.prefix) - spack.hooks.on_phase_success(pkg, phase_name, log_file) + # We assume loggers share echo True/False + self.echo = logger.echo + else: + with winlog(pkg.log_path, True, True, + env=self.unmodified_env) as logger: - except BaseException: - combine_phase_logs(pkg.phase_log_files, pkg.log_path) - spack.hooks.on_phase_error(pkg, phase_name, log_file) + for phase_name, phase_attr in zip( + pkg.phases, pkg._InstallPhase_phases): - # phase error indicates install error - spack.hooks.on_install_failure(pkg.spec) - raise + # with logger.force_echo(): + # inner_debug_level = tty.debug_level() + # tty.set_debug(debug_level) + # tty.msg("{0} Executing phase: '{1}'" + # .format(pre, phase_name)) + # tty.set_debug(inner_debug_level) - # We assume loggers share echo True/False - self.echo = logger.echo + # Redirect stdout and stderr to daemon pipe + phase = getattr(pkg, phase_attr) + phase(pkg.spec, pkg.prefix) - # After log, we can get all output/error files from the package stage - combine_phase_logs(pkg.phase_log_files, pkg.log_path) - log(pkg) + if sys.platform != 'win32': + # After log, we can get all output/error files from the package stage + combine_phase_logs(pkg.phase_log_files, pkg.log_path) + log(pkg) def build_process(pkg, install_args): diff --git a/lib/spack/spack/main.py b/lib/spack/spack/main.py index 78c986e0d9..1f3cf5e723 100644 --- a/lib/spack/spack/main.py +++ b/lib/spack/spack/main.py @@ -31,7 +31,7 @@ import llnl.util.lang import llnl.util.tty as tty import llnl.util.tty.colify import llnl.util.tty.color as color -from llnl.util.tty.log import log_output +from llnl.util.tty.log import log_output, winlog import spack import spack.cmd @@ -494,6 +494,7 @@ def setup_main_options(args): # debug must be set first so that it can even affect behavior of # errors raised by spack.config. + tty.debug(spack.config.config) if args.debug: spack.error.debug = True spack.util.debug.register_interrupt_handler() @@ -611,9 +612,14 @@ class SpackCommand(object): out = StringIO() try: - with log_output(out): - self.returncode = _invoke_command( - self.command, self.parser, args, unknown) + if sys.platform == 'win32': + with winlog(out): + self.returncode = _invoke_command( + self.command, self.parser, args, unknown) + else: + with log_output(out): + self.returncode = _invoke_command( + self.command, self.parser, args, unknown) except SystemExit as e: self.returncode = e.code diff --git a/lib/spack/spack/util/executable.py b/lib/spack/spack/util/executable.py index 200ddc0d2d..f1e37a8672 100644 --- a/lib/spack/spack/util/executable.py +++ b/lib/spack/spack/util/executable.py @@ -22,6 +22,8 @@ class Executable(object): """Class representing a program that can be run on the command line.""" def __init__(self, name): + if sys.platform == 'win32': + name = name.replace('\\', '/') self.exe = shlex.split(str(name)) self.default_env = {} from spack.util.environment import EnvironmentModifications # no cycle -- cgit v1.2.3-60-g2f50