Allow 'spack external find' to find executables on the system path (#22091)

Co-authored-by: Lou Lawrence <lou.lawrence@kitware.com>

5 files changed, 247 insertions, 51 deletions

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