diff --git a/easybuild/tools/run.py b/easybuild/tools/run.py index 9ab9cce702..bef92ec2a2 100644 --- a/easybuild/tools/run.py +++ b/easybuild/tools/run.py @@ -77,6 +77,36 @@ RunResult = namedtuple('RunResult', ('output', 'exit_code', 'stderr')) +def run_cmd_cache(func): + """Function decorator to cache (and retrieve cached) results of running commands.""" + cache = {} + + @functools.wraps(func) + def cache_aware_func(cmd, *args, **kwargs): + """Retrieve cached result of selected commands, or run specified and collect & cache result.""" + # cache key is combination of command and input provided via stdin ('stdin' for run, 'inp' for run_cmd) + key = (cmd, kwargs.get('stdin', None) or kwargs.get('inp', None)) + # fetch from cache if available, cache it if it's not, but only on cmd strings + if isinstance(cmd, str) and key in cache: + _log.debug("Using cached value for command '%s': %s", cmd, cache[key]) + return cache[key] + else: + res = func(cmd, *args, **kwargs) + if cmd in CACHED_COMMANDS: + cache[key] = res + return res + + # expose clear/update methods of cache to wrapped function + cache_aware_func.clear_cache = cache.clear + cache_aware_func.update_cache = cache.update + + return cache_aware_func + + +run_cache = run_cmd_cache + + +@run_cache def run(cmd, fail_on_error=True, split_stderr=False, stdin=None, hidden=False, in_dry_run=False, work_dir=None, shell=True, output_file=False, stream_output=False, asynchronous=False, @@ -90,7 +120,7 @@ def run(cmd, fail_on_error=True, split_stderr=False, stdin=None, :param hidden: do not show command in terminal output (when using --trace, or with --extended-dry-run / -x) :param in_dry_run: also run command in dry run mode :param work_dir: working directory to run command in (current working directory if None) - :param shell: execute command through a shell (enabled by default) + :param shell: execute command through bash shell (enabled by default) :param output_file: collect command output in temporary output file :param stream_output: stream command output to stdout :param asynchronous: run command asynchronously @@ -104,7 +134,7 @@ def run(cmd, fail_on_error=True, split_stderr=False, stdin=None, """ # temporarily raise a NotImplementedError until all options are implemented - if any((not fail_on_error, split_stderr, in_dry_run, work_dir, output_file, stream_output, asynchronous)): + if any((split_stderr, work_dir, stream_output, asynchronous)): raise NotImplementedError if qa_patterns or qa_wait_patterns: @@ -117,19 +147,24 @@ def run(cmd, fail_on_error=True, split_stderr=False, stdin=None, else: raise EasyBuildError(f"Unknown command type ('{type(cmd)}'): {cmd}") - silent = build_option('silent') - if work_dir is None: work_dir = os.getcwd() - # output file for command output (only used if output_file is enabled) - cmd_out_fp = None + # temporary output file for command output, if requested + if output_file or not hidden: + # collect output of running command in temporary log file, if desired + fd, cmd_out_fp = tempfile.mkstemp(suffix='.log', prefix='easybuild-run-') + os.close(fd) + _log.info(f'run_cmd: Output of "{cmd}" will be logged to {cmd_out_fp}') + else: + cmd_out_fp = None # early exit in 'dry run' mode, after printing the command that would be run (unless 'hidden' is enabled) - if build_option('extended_dry_run'): + if not in_dry_run and build_option('extended_dry_run'): if not hidden: - msg = f" running command \"%{cmd_msg}s\"\n" - msg += f" (in %{work_dir})" + silent = build_option('silent') + msg = f" running command \"{cmd_msg}s\"\n" + msg += f" (in {work_dir})" dry_run_msg(msg, silent=silent) return RunResult(output='', exit_code=0, stderr=None) @@ -142,14 +177,23 @@ def run(cmd, fail_on_error=True, split_stderr=False, stdin=None, # 'input' value fed to subprocess.run must be a byte sequence stdin = stdin.encode() + # use bash as shell instead of the default /bin/sh used by subprocess.run + # (which could be dash instead of bash, like on Ubuntu, see https://wiki.ubuntu.com/DashAsBinSh) + if shell: + executable = '/bin/bash' + else: + # stick to None (default value) when not running command via a shell + executable = None + _log.info(f"Running command '{cmd_msg}' in {work_dir}") - proc = subprocess.run(cmd, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, input=stdin, shell=shell) + proc = subprocess.run(cmd, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, check=fail_on_error, + input=stdin, shell=shell, executable=executable) # return output as a regular string rather than a byte sequence (and non-UTF-8 characters get stripped out) output = proc.stdout.decode('utf-8', 'ignore') res = RunResult(output=output, exit_code=proc.returncode, stderr=None) - _log.info(f"Command '{cmd_msg}' exited with exit code {res.exit_code} and output:\n%{res.output}") + _log.info(f"Command '{cmd_msg}' exited with exit code {res.exit_code} and output:\n{res.output}") if not hidden: time_since_start = time_str_since(start_time) @@ -185,32 +229,6 @@ def cmd_trace_msg(cmd, start_time, work_dir, stdin, cmd_out_fp): trace_msg('\n'.join(lines)) -def run_cmd_cache(func): - """Function decorator to cache (and retrieve cached) results of running commands.""" - cache = {} - - @functools.wraps(func) - def cache_aware_func(cmd, *args, **kwargs): - """Retrieve cached result of selected commands, or run specified and collect & cache result.""" - # cache key is combination of command and input provided via stdin - key = (cmd, kwargs.get('inp', None)) - # fetch from cache if available, cache it if it's not, but only on cmd strings - if isinstance(cmd, str) and key in cache: - _log.debug("Using cached value for command '%s': %s", cmd, cache[key]) - return cache[key] - else: - res = func(cmd, *args, **kwargs) - if cmd in CACHED_COMMANDS: - cache[key] = res - return res - - # expose clear/update methods of cache to wrapped function - cache_aware_func.clear_cache = cache.clear - cache_aware_func.update_cache = cache.update - - return cache_aware_func - - def get_output_from_process(proc, read_size=None, asynchronous=False): """ Get output from running process (that was opened with subprocess.Popen). diff --git a/easybuild/tools/systemtools.py b/easybuild/tools/systemtools.py index 458b61fa0c..e6e3de7067 100644 --- a/easybuild/tools/systemtools.py +++ b/easybuild/tools/systemtools.py @@ -65,7 +65,7 @@ from easybuild.tools.build_log import EasyBuildError, print_warning from easybuild.tools.config import IGNORE from easybuild.tools.filetools import is_readable, read_file, which -from easybuild.tools.run import run_cmd +from easybuild.tools.run import run _log = fancylogger.getLogger('systemtools', fname=False) @@ -274,10 +274,10 @@ def get_avail_core_count(): core_cnt = int(sum(sched_getaffinity())) else: # BSD-type systems - out, _ = run_cmd('sysctl -n hw.ncpu', force_in_dry_run=True, trace=False, stream_output=False) + res = run('sysctl -n hw.ncpu', in_dry_run=True, hidden=True) try: - if int(out) > 0: - core_cnt = int(out) + if int(res.output) > 0: + core_cnt = int(res.output) except ValueError: pass @@ -311,9 +311,9 @@ def get_total_memory(): elif os_type == DARWIN: cmd = "sysctl -n hw.memsize" _log.debug("Trying to determine total memory size on Darwin via cmd '%s'", cmd) - out, ec = run_cmd(cmd, force_in_dry_run=True, trace=False, stream_output=False) - if ec == 0: - memtotal = int(out.strip()) // (1024**2) + res = run(cmd, in_dry_run=True, hidden=True) + if res.exit_code == 0: + memtotal = int(res.output.strip()) // (1024**2) if memtotal is None: memtotal = UNKNOWN @@ -393,16 +393,16 @@ def get_cpu_vendor(): elif os_type == DARWIN: cmd = "sysctl -n machdep.cpu.vendor" - out, ec = run_cmd(cmd, force_in_dry_run=True, trace=False, stream_output=False, log_ok=False) - out = out.strip() - if ec == 0 and out in VENDOR_IDS: + res = run(cmd, fail_on_error=False, in_dry_run=True, hidden=True) + out = res.output.strip() + if res.exit_code == 0 and out in VENDOR_IDS: vendor = VENDOR_IDS[out] _log.debug("Determined CPU vendor on DARWIN as being '%s' via cmd '%s" % (vendor, cmd)) else: cmd = "sysctl -n machdep.cpu.brand_string" - out, ec = run_cmd(cmd, force_in_dry_run=True, trace=False, stream_output=False, log_ok=False) - out = out.strip().split(' ')[0] - if ec == 0 and out in CPU_VENDORS: + res = run(cmd, fail_on_error=False, in_dry_run=True, hidden=True) + out = res.output.strip().split(' ')[0] + if res.exit_code == 0 and out in CPU_VENDORS: vendor = out _log.debug("Determined CPU vendor on DARWIN as being '%s' via cmd '%s" % (vendor, cmd)) @@ -503,9 +503,9 @@ def get_cpu_model(): elif os_type == DARWIN: cmd = "sysctl -n machdep.cpu.brand_string" - out, ec = run_cmd(cmd, force_in_dry_run=True, trace=False, stream_output=False) - if ec == 0: - model = out.strip() + res = run(cmd, in_dry_run=True, hidden=True) + if res.exit_code == 0: + model = res.output.strip() _log.debug("Determined CPU model on Darwin using cmd '%s': %s" % (cmd, model)) if model is None: @@ -548,10 +548,10 @@ def get_cpu_speed(): elif os_type == DARWIN: cmd = "sysctl -n hw.cpufrequency_max" _log.debug("Trying to determine CPU frequency on Darwin via cmd '%s'" % cmd) - out, ec = run_cmd(cmd, force_in_dry_run=True, trace=False, stream_output=False) - out = out.strip() + res = run(cmd, in_dry_run=True, hidden=True) + out = res.output.strip() cpu_freq = None - if ec == 0 and out: + if res.exit_code == 0 and out: # returns clock frequency in cycles/sec, but we want MHz cpu_freq = float(out) // (1000 ** 2) @@ -596,9 +596,9 @@ def get_cpu_features(): for feature_set in ['extfeatures', 'features', 'leaf7_features']: cmd = "sysctl -n machdep.cpu.%s" % feature_set _log.debug("Trying to determine CPU features on Darwin via cmd '%s'", cmd) - out, ec = run_cmd(cmd, force_in_dry_run=True, trace=False, stream_output=False, log_ok=False) - if ec == 0: - cpu_feat.extend(out.strip().lower().split()) + res = run(cmd, in_dry_run=True, hidden=True, fail_on_error=False) + if res.exit_code == 0: + cpu_feat.extend(res.output.strip().lower().split()) cpu_feat.sort() @@ -623,16 +623,15 @@ def get_gpu_info(): try: cmd = "nvidia-smi --query-gpu=gpu_name,driver_version --format=csv,noheader" _log.debug("Trying to determine NVIDIA GPU info on Linux via cmd '%s'", cmd) - out, ec = run_cmd(cmd, simple=False, log_ok=False, log_all=False, - force_in_dry_run=True, trace=False, stream_output=False) - if ec == 0: - for line in out.strip().split('\n'): + res = run(cmd, fail_on_error=False, in_dry_run=True, hidden=True) + if res.exit_code == 0: + for line in res.output.strip().split('\n'): nvidia_gpu_info = gpu_info.setdefault('NVIDIA', {}) nvidia_gpu_info.setdefault(line, 0) nvidia_gpu_info[line] += 1 else: - _log.debug("None zero exit (%s) from nvidia-smi: %s", ec, out) - except Exception as err: + _log.debug("None zero exit (%s) from nvidia-smi: %s", res.exit_code, res.output) + except EasyBuildError as err: _log.debug("Exception was raised when running nvidia-smi: %s", err) _log.info("No NVIDIA GPUs detected") @@ -642,17 +641,15 @@ def get_gpu_info(): try: cmd = "rocm-smi --showdriverversion --csv" _log.debug("Trying to determine AMD GPU driver on Linux via cmd '%s'", cmd) - out, ec = run_cmd(cmd, simple=False, log_ok=False, log_all=False, - force_in_dry_run=True, trace=False, stream_output=False) - if ec == 0: - amd_driver = out.strip().split('\n')[1].split(',')[1] + res = run(cmd, fail_on_error=False, in_dry_run=True, hidden=True) + if res.exit_code == 0: + amd_driver = res.output.strip().split('\n')[1].split(',')[1] cmd = "rocm-smi --showproductname --csv" _log.debug("Trying to determine AMD GPU info on Linux via cmd '%s'", cmd) - out, ec = run_cmd(cmd, simple=False, log_ok=False, log_all=False, - force_in_dry_run=True, trace=False, stream_output=False) - if ec == 0: - for line in out.strip().split('\n')[1:]: + res = run(cmd, fail_on_error=False, in_dry_run=True, hidden=True) + if res.exit_code == 0: + for line in res.output.strip().split('\n')[1:]: amd_card_series = line.split(',')[1] amd_card_model = line.split(',')[2] amd_gpu = "%s (model: %s, driver: %s)" % (amd_card_series, amd_card_model, amd_driver) @@ -660,8 +657,8 @@ def get_gpu_info(): amd_gpu_info.setdefault(amd_gpu, 0) amd_gpu_info[amd_gpu] += 1 else: - _log.debug("None zero exit (%s) from rocm-smi: %s", ec, out) - except Exception as err: + _log.debug("None zero exit (%s) from rocm-smi: %s", res.exit_code, res.output) + except EasyBuildError as err: _log.debug("Exception was raised when running rocm-smi: %s", err) _log.info("No AMD GPUs detected") @@ -861,16 +858,16 @@ def check_os_dependency(dep): for pkg_cmd in pkg_cmds: if which(pkg_cmd): - cmd = [ + cmd = ' '.join([ # unset $LD_LIBRARY_PATH to avoid broken rpm command due to loaded dependencies # see https://github.com/easybuilders/easybuild-easyconfigs/pull/4179 'unset LD_LIBRARY_PATH &&', pkg_cmd, pkg_cmd_flag.get(pkg_cmd), dep, - ] - found = run_cmd(' '.join(cmd), simple=True, log_all=False, log_ok=False, - force_in_dry_run=True, trace=False, stream_output=False) + ]) + res = run(cmd, fail_on_error=False, in_dry_run=True, hidden=True) + found = res.exit_code == 0 if found: break @@ -881,10 +878,9 @@ def check_os_dependency(dep): # try locate if it's available if not found and which('locate'): cmd = 'locate -c --regexp "/%s$"' % dep - out, ec = run_cmd(cmd, simple=False, log_all=False, log_ok=False, force_in_dry_run=True, trace=False, - stream_output=False) + res = run(cmd, fail_on_error=False, in_dry_run=True, hidden=True) try: - found = (ec == 0 and int(out.strip()) > 0) + found = (res.exit_code == 0 and int(res.output.strip()) > 0) except ValueError: # Returned something else than an int -> Error found = False @@ -897,41 +893,39 @@ def get_tool_version(tool, version_option='--version', ignore_ec=False): Get output of running version option for specific command line tool. Output is returned as a single-line string (newlines are replaced by '; '). """ - out, ec = run_cmd(' '.join([tool, version_option]), simple=False, log_ok=False, force_in_dry_run=True, - trace=False, stream_output=False) - if not ignore_ec and ec: - _log.warning("Failed to determine version of %s using '%s %s': %s" % (tool, tool, version_option, out)) + res = run(' '.join([tool, version_option]), fail_on_error=False, in_dry_run=True, hidden=True) + if not ignore_ec and res.exit_code: + _log.warning("Failed to determine version of %s using '%s %s': %s" % (tool, tool, version_option, res.output)) return UNKNOWN else: - return '; '.join(out.split('\n')) + return '; '.join(res.output.split('\n')) def get_gcc_version(): """ Process `gcc --version` and return the GCC version. """ - out, ec = run_cmd('gcc --version', simple=False, log_ok=False, force_in_dry_run=True, verbose=False, trace=False, - stream_output=False) - res = None - if ec: - _log.warning("Failed to determine the version of GCC: %s", out) - res = UNKNOWN + res = run('gcc --version', fail_on_error=False, in_dry_run=True, hidden=True) + gcc_ver = None + if res.exit_code: + _log.warning("Failed to determine the version of GCC: %s", res.output) + gcc_ver = UNKNOWN # Fedora: gcc (GCC) 5.1.1 20150618 (Red Hat 5.1.1-4) # Debian: gcc (Debian 4.9.2-10) 4.9.2 - find_version = re.search(r"^gcc\s+\([^)]+\)\s+(?P[^\s]+)\s+", out) + find_version = re.search(r"^gcc\s+\([^)]+\)\s+(?P[^\s]+)\s+", res.output) if find_version: - res = find_version.group('version') - _log.debug("Found GCC version: %s from %s", res, out) + gcc_ver = find_version.group('version') + _log.debug("Found GCC version: %s from %s", res, res.output) else: # Apple likes to install clang but call it gcc. if get_os_type() == DARWIN: _log.warning("On recent version of Mac OS, gcc is actually clang, returning None as GCC version") - res = None + gcc_ver = None else: - raise EasyBuildError("Failed to determine the GCC version from: %s", out) + raise EasyBuildError("Failed to determine the GCC version from: %s", res.output) - return res + return gcc_ver def get_glibc_version(): @@ -967,9 +961,9 @@ def get_linked_libs_raw(path): or None for other types of files. """ - file_cmd_out, ec = run_cmd("file %s" % path, simple=False, trace=False) - if ec: - fail_msg = "Failed to run 'file %s': %s" % (path, file_cmd_out) + res = run("file %s" % path, fail_on_error=False, hidden=True) + if res.exit_code: + fail_msg = "Failed to run 'file %s': %s" % (path, res.output) _log.warning(fail_msg) os_type = get_os_type() @@ -980,7 +974,7 @@ def get_linked_libs_raw(path): # /usr/bin/ls: ELF 64-bit LSB executable, x86-64, ..., dynamically linked (uses shared libs), ... # example output for shared libraries: # /lib64/libc-2.17.so: ELF 64-bit LSB shared object, x86-64, ..., dynamically linked (uses shared libs), ... - if "dynamically linked" in file_cmd_out: + if "dynamically linked" in res.output: # determine linked libraries via 'ldd' linked_libs_cmd = "ldd %s" % path else: @@ -992,7 +986,7 @@ def get_linked_libs_raw(path): # example output for shared libraries: # /usr/lib/libz.dylib: Mach-O 64-bit dynamically linked shared library x86_64 bin_lib_regex = re.compile('(Mach-O .* executable)|(dynamically linked)', re.M) - if bin_lib_regex.search(file_cmd_out): + if bin_lib_regex.search(res.output): linked_libs_cmd = "otool -L %s" % path else: return None @@ -1002,12 +996,12 @@ def get_linked_libs_raw(path): # take into account that 'ldd' may fail for strange reasons, # like printing 'not a dynamic executable' when not enough memory is available # (see also https://bugzilla.redhat.com/show_bug.cgi?id=1817111) - out, ec = run_cmd(linked_libs_cmd, simple=False, trace=False, log_ok=False, log_all=False) - if ec == 0: - linked_libs_out = out + res = run(linked_libs_cmd, fail_on_error=False, hidden=True) + if res.exit_code == 0: + linked_libs_out = res.output else: - fail_msg = "Determining linked libraries for %s via '%s' failed! Output: '%s'" % (path, linked_libs_cmd, out) - print_warning(fail_msg) + fail_msg = "Determining linked libraries for %s via '%s' failed! Output: '%s'" + print_warning(fail_msg % (path, linked_libs_cmd, res.output)) linked_libs_out = None return linked_libs_out @@ -1183,20 +1177,21 @@ def get_default_parallelism(): except AttributeError: # No cache -> Calculate value from current system values par = get_avail_core_count() - # check ulimit -u - out, ec = run_cmd('ulimit -u', force_in_dry_run=True, trace=False, stream_output=False) + # determine max user processes via ulimit -u + res = run("ulimit -u", in_dry_run=True, hidden=True) try: - if out.startswith("unlimited"): + if res.output.startswith("unlimited"): maxuserproc = 2 ** 32 - 1 else: - maxuserproc = int(out) + maxuserproc = int(res.output) except ValueError as err: - raise EasyBuildError("Failed to determine max user processes (%s, %s): %s", ec, out, err) + raise EasyBuildError("Failed to determine max user processes (%s, %s): %s", + res.exit_code, res.output, err) # assume 6 processes per build thread + 15 overhead par_guess = (maxuserproc - 15) // 6 if par_guess < par: par = par_guess - _log.info("Limit parallel builds to %s because max user processes is %s", par, out) + _log.info("Limit parallel builds to %s because max user processes is %s", par, res.output) # Cache value det_parallelism._default_parallelism = par return par diff --git a/test/framework/run.py b/test/framework/run.py index 9a9e589224..5ee8f59f0a 100644 --- a/test/framework/run.py +++ b/test/framework/run.py @@ -49,7 +49,7 @@ from easybuild.tools.build_log import EasyBuildError, init_logging, stop_logging from easybuild.tools.filetools import adjust_permissions, mkdir, read_file, write_file from easybuild.tools.run import check_async_cmd, check_log_for_errors, complete_cmd, get_output_from_process -from easybuild.tools.run import parse_log_for_error, run, run_cmd, run_cmd_qa, subprocess_terminate +from easybuild.tools.run import RunResult, parse_log_for_error, run, run_cmd, run_cmd_qa, subprocess_terminate from easybuild.tools.config import ERROR, IGNORE, WARN @@ -297,6 +297,28 @@ def handler(signum, _): signal.signal(signal.SIGALRM, orig_sigalrm_handler) signal.alarm(0) + def test_run_fail_cmd(self): + """Test run function with command that has negative exit code.""" + # define signal handler to call in case run takes too long + def handler(signum, _): + raise RuntimeError("Signal handler called with signal %s" % signum) + + orig_sigalrm_handler = signal.getsignal(signal.SIGALRM) + + try: + # set the signal handler and a 3-second alarm + signal.signal(signal.SIGALRM, handler) + signal.alarm(3) + + with self.mocked_stdout_stderr(): + res = run("kill -9 $$", fail_on_error=False) + self.assertEqual(res.exit_code, -9) + + finally: + # cleanup: disable the alarm + reset signal handler for SIGALRM + signal.signal(signal.SIGALRM, orig_sigalrm_handler) + signal.alarm(0) + def test_run_cmd_bis(self): """More 'complex' test for run_cmd function.""" # a more 'complex' command to run, make sure all required output is there @@ -306,6 +328,15 @@ def test_run_cmd_bis(self): self.assertEqual(len(out), len("hello\n" * 300)) self.assertEqual(ec, 0) + def test_run_bis(self): + """More 'complex' test for run function.""" + # a more 'complex' command to run, make sure all required output is there + with self.mocked_stdout_stderr(): + res = run("for j in `seq 1 3`; do for i in `seq 1 100`; do echo hello; done; sleep 1.4; done") + self.assertTrue(res.output.startswith('hello\nhello\n')) + self.assertEqual(len(res.output), len("hello\n" * 300)) + self.assertEqual(res.exit_code, 0) + def test_run_cmd_log_output(self): """Test run_cmd with log_output enabled""" with self.mocked_stdout_stderr(): @@ -339,9 +370,7 @@ def test_run_cmd_log_output(self): self.assertEqual(type(out), str) def test_run_cmd_trace(self): - """Test run_cmd under --trace""" - - init_config(build_options={'trace': True}) + """Test run_cmd in trace mode, and with tracing disabled.""" pattern = [ r"^ >> running command:", @@ -352,6 +381,7 @@ def test_run_cmd_trace(self): r" >> command completed: exit 0, ran in .*", ] + # trace output is enabled by default (since EasyBuild v5.0) self.mock_stdout(True) self.mock_stderr(True) (out, ec) = run_cmd("echo hello") @@ -365,6 +395,22 @@ def test_run_cmd_trace(self): regex = re.compile('\n'.join(pattern)) self.assertTrue(regex.search(stdout), "Pattern '%s' found in: %s" % (regex.pattern, stdout)) + init_config(build_options={'trace': False}) + + self.mock_stdout(True) + self.mock_stderr(True) + (out, ec) = run_cmd("echo hello") + stdout = self.get_stdout() + stderr = self.get_stderr() + self.mock_stdout(False) + self.mock_stderr(False) + self.assertEqual(out, 'hello\n') + self.assertEqual(ec, 0) + self.assertEqual(stderr, '') + self.assertEqual(stdout, '') + + init_config(build_options={'trace': True}) + # also test with command that is fed input via stdin self.mock_stdout(True) self.mock_stderr(True) @@ -381,18 +427,93 @@ def test_run_cmd_trace(self): regex = re.compile('\n'.join(pattern)) self.assertTrue(regex.search(stdout), "Pattern '%s' found in: %s" % (regex.pattern, stdout)) - # trace output can be disabled on a per-command basis + init_config(build_options={'trace': False}) + self.mock_stdout(True) self.mock_stderr(True) - (out, ec) = run_cmd("echo hello", trace=False) + (out, ec) = run_cmd('cat', inp='hello') stdout = self.get_stdout() stderr = self.get_stderr() self.mock_stdout(False) self.mock_stderr(False) - self.assertEqual(out, 'hello\n') + self.assertEqual(out, 'hello') self.assertEqual(ec, 0) + self.assertEqual(stderr, '') self.assertEqual(stdout, '') + + # trace output can be disabled on a per-command basis + for trace in (True, False): + init_config(build_options={'trace': trace}) + + self.mock_stdout(True) + self.mock_stderr(True) + (out, ec) = run_cmd("echo hello", trace=False) + stdout = self.get_stdout() + stderr = self.get_stderr() + self.mock_stdout(False) + self.mock_stderr(False) + self.assertEqual(out, 'hello\n') + self.assertEqual(ec, 0) + self.assertEqual(stdout, '') + self.assertEqual(stderr, '') + + def test_run_trace(self): + """Test run in trace mode, and with tracing disabled.""" + + pattern = [ + r"^ >> running command:", + r"\t\[started at: .*\]", + r"\t\[working dir: .*\]", + r"\t\[output logged in .*\]", + r"\techo hello", + r" >> command completed: exit 0, ran in .*", + ] + + # trace output is enabled by default (since EasyBuild v5.0) + self.mock_stdout(True) + self.mock_stderr(True) + res = run("echo hello") + stdout = self.get_stdout() + stderr = self.get_stderr() + self.mock_stdout(False) + self.mock_stderr(False) + self.assertEqual(res.output, 'hello\n') + self.assertEqual(res.exit_code, 0) self.assertEqual(stderr, '') + regex = re.compile('\n'.join(pattern)) + self.assertTrue(regex.search(stdout), "Pattern '%s' found in: %s" % (regex.pattern, stdout)) + + init_config(build_options={'trace': False}) + + self.mock_stdout(True) + self.mock_stderr(True) + res = run("echo hello") + stdout = self.get_stdout() + stderr = self.get_stderr() + self.mock_stdout(False) + self.mock_stderr(False) + self.assertEqual(res.output, 'hello\n') + self.assertEqual(res.exit_code, 0) + self.assertEqual(stderr, '') + self.assertEqual(stdout, '') + + init_config(build_options={'trace': True}) + + # trace output can be disabled on a per-command basis via 'hidden' option + for trace in (True, False): + init_config(build_options={'trace': trace}) + + self.mock_stdout(True) + self.mock_stderr(True) + res = run("echo hello", hidden=True) + stdout = self.get_stdout() + stderr = self.get_stderr() + self.mock_stdout(False) + self.mock_stderr(False) + self.assertEqual(res.output, 'hello\n') + self.assertEqual(res.exit_code, 0) + self.assertEqual(stdout, '') + self.assertEqual(stderr, '') def test_run_trace_stdin(self): """Test run under --trace + passing stdin input.""" @@ -403,6 +524,7 @@ def test_run_trace_stdin(self): r"^ >> running command:", r"\t\[started at: [0-9][0-9][0-9][0-9]-[0-9][0-9]-[0-9][0-9] [0-9][0-9]:[0-9][0-9]:[0-9][0-9]\]", r"\t\[working dir: .*\]", + r"\t\[output logged in .*\]", r"\techo hello", r" >> command completed: exit 0, ran in .*", ] @@ -615,6 +737,42 @@ def test_run_cmd_cache(self): run_cmd.clear_cache() + def test_run_cache(self): + """Test caching for run""" + with self.mocked_stdout_stderr(): + res = run("ulimit -u") + first_out = res.output + self.assertEqual(res.exit_code, 0) + with self.mocked_stdout_stderr(): + res = run("ulimit -u") + cached_out = res.output + self.assertEqual(res.exit_code, 0) + self.assertEqual(first_out, cached_out) + + # inject value into cache to check whether executing command again really returns cached value + with self.mocked_stdout_stderr(): + cached_res = RunResult(output="123456", exit_code=123, stderr=None) + run.update_cache({("ulimit -u", None): cached_res}) + res = run("ulimit -u") + self.assertEqual(res.exit_code, 123) + self.assertEqual(res.output, "123456") + + # also test with command that uses stdin + with self.mocked_stdout_stderr(): + res = run("cat", stdin='foo') + self.assertEqual(res.exit_code, 0) + self.assertEqual(res.output, 'foo') + + # inject different output for cat with 'foo' as stdin to check whether cached value is used + with self.mocked_stdout_stderr(): + cached_res = RunResult(output="bar", exit_code=123, stderr=None) + run.update_cache({('cat', 'foo'): cached_res}) + res = run("cat", stdin='foo') + self.assertEqual(res.exit_code, 123) + self.assertEqual(res.output, 'bar') + + run.clear_cache() + def test_parse_log_error(self): """Test basic parse_log_for_error functionality.""" errors = parse_log_for_error("error failed", True) @@ -641,7 +799,7 @@ def test_dry_run(self): run_cmd("somecommand foo 123 bar", verbose=False) self.mock_stdout(False) - # check forced run + # check forced run_cmd outfile = os.path.join(self.test_prefix, 'cmd.out') self.assertNotExists(outfile) self.mock_stdout(True) @@ -651,6 +809,16 @@ def test_dry_run(self): self.assertExists(outfile) self.assertEqual(read_file(outfile), "This is always echoed\n") + write_file(outfile, '', forced=True) + + # check forced run + self.mock_stdout(True) + run("echo 'This is always echoed' > %s" % outfile, in_dry_run=True) + txt = self.get_stdout() + self.mock_stdout(False) + self.assertExists(outfile) + self.assertEqual(read_file(outfile), "This is always echoed\n") + # Q&A commands self.mock_stdout(True) run_cmd_qa("some_qa_cmd", {'question1': 'answer1'}) diff --git a/test/framework/systemtools.py b/test/framework/systemtools.py index 1a8137ef98..cb8c5a740d 100644 --- a/test/framework/systemtools.py +++ b/test/framework/systemtools.py @@ -40,7 +40,7 @@ import easybuild.tools.systemtools as st from easybuild.tools.build_log import EasyBuildError from easybuild.tools.filetools import adjust_permissions, read_file, symlink, which, write_file -from easybuild.tools.run import run_cmd +from easybuild.tools.run import RunResult, run from easybuild.tools.systemtools import CPU_ARCHITECTURES, AARCH32, AARCH64, POWER, X86_64 from easybuild.tools.systemtools import CPU_FAMILIES, POWER_LE, DARWIN, LINUX, UNKNOWN from easybuild.tools.systemtools import CPU_VENDORS, AMD, APM, ARM, CAVIUM, IBM, INTEL @@ -320,8 +320,8 @@ def mocked_is_readable(mocked_fp, fp): return fp == mocked_fp -def mocked_run_cmd(cmd, **kwargs): - """Mocked version of run_cmd, with specified output for known commands.""" +def mocked_run(cmd, **kwargs): + """Mocked version of run, with specified output for known commands.""" known_cmds = { "gcc --version": "gcc (GCC) 5.1.1 20150618 (Red Hat 5.1.1-4)", "ldd --version": "ldd (GNU libc) 2.12; ", @@ -340,12 +340,9 @@ def mocked_run_cmd(cmd, **kwargs): "ulimit -u": '40', } if cmd in known_cmds: - if 'simple' in kwargs and kwargs['simple']: - return True - else: - return (known_cmds[cmd], 0) + return RunResult(output=known_cmds[cmd], exit_code=0, stderr=None) else: - return run_cmd(cmd, **kwargs) + return run(cmd, **kwargs) def mocked_uname(): @@ -364,7 +361,7 @@ def setUp(self): self.orig_get_os_type = st.get_os_type self.orig_is_readable = st.is_readable self.orig_read_file = st.read_file - self.orig_run_cmd = st.run_cmd + self.orig_run = st.run self.orig_platform_dist = st.platform.dist if hasattr(st.platform, 'dist') else None self.orig_platform_uname = st.platform.uname self.orig_get_tool_version = st.get_tool_version @@ -384,7 +381,7 @@ def tearDown(self): st.get_cpu_architecture = self.orig_get_cpu_architecture st.get_os_name = self.orig_get_os_name st.get_os_type = self.orig_get_os_type - st.run_cmd = self.orig_run_cmd + st.run = self.orig_run if self.orig_platform_dist is not None: st.platform.dist = self.orig_platform_dist st.platform.uname = self.orig_platform_uname @@ -415,7 +412,7 @@ def test_avail_core_count_linux(self): def test_avail_core_count_darwin(self): """Test getting core count (mocked for Darwin).""" st.get_os_type = lambda: st.DARWIN - st.run_cmd = mocked_run_cmd + st.run = mocked_run self.assertEqual(get_avail_core_count(), 10) def test_cpu_model_native(self): @@ -453,7 +450,7 @@ def test_cpu_model_linux(self): def test_cpu_model_darwin(self): """Test getting CPU model (mocked for Darwin).""" st.get_os_type = lambda: st.DARWIN - st.run_cmd = mocked_run_cmd + st.run = mocked_run self.assertEqual(get_cpu_model(), "Intel(R) Core(TM) i5-4258U CPU @ 2.40GHz") def test_cpu_speed_native(self): @@ -488,7 +485,7 @@ def test_cpu_speed_linux(self): def test_cpu_speed_darwin(self): """Test getting CPU speed (mocked for Darwin).""" st.get_os_type = lambda: st.DARWIN - st.run_cmd = mocked_run_cmd + st.run = mocked_run self.assertEqual(get_cpu_speed(), 2400.0) def test_cpu_features_native(self): @@ -543,7 +540,7 @@ def test_cpu_features_linux(self): def test_cpu_features_darwin(self): """Test getting CPU features (mocked for Darwin).""" st.get_os_type = lambda: st.DARWIN - st.run_cmd = mocked_run_cmd + st.run = mocked_run expected = ['1gbpage', 'acpi', 'aes', 'apic', 'avx1.0', 'avx2', 'bmi1', 'bmi2', 'clfsh', 'cmov', 'cx16', 'cx8', 'de', 'ds', 'dscpl', 'dtes64', 'em64t', 'erms', 'est', 'f16c', 'fma', 'fpu', 'fpu_csds', 'fxsr', 'htt', 'invpcid', 'lahf', 'lzcnt', 'mca', 'mce', 'mmx', 'mon', 'movbe', 'msr', 'mtrr', @@ -637,12 +634,12 @@ def test_cpu_vendor_linux(self): def test_cpu_vendor_darwin(self): """Test getting CPU vendor (mocked for Darwin).""" st.get_os_type = lambda: st.DARWIN - st.run_cmd = mocked_run_cmd + st.run = mocked_run self.assertEqual(get_cpu_vendor(), INTEL) def test_cpu_family_native(self): """Test get_cpu_family function.""" - run_cmd.clear_cache() + run.clear_cache() cpu_family = get_cpu_family() self.assertTrue(cpu_family in CPU_FAMILIES or cpu_family == UNKNOWN) @@ -687,8 +684,8 @@ def test_cpu_family_linux(self): def test_cpu_family_darwin(self): """Test get_cpu_family function (mocked for Darwin).""" st.get_os_type = lambda: st.DARWIN - st.run_cmd = mocked_run_cmd - run_cmd.clear_cache() + st.run = mocked_run + run.clear_cache() self.assertEqual(get_cpu_family(), INTEL) def test_os_type(self): @@ -770,13 +767,14 @@ def test_gcc_version_native(self): def test_gcc_version_linux(self): """Test getting gcc version (mocked for Linux).""" st.get_os_type = lambda: st.LINUX - st.run_cmd = mocked_run_cmd + st.run = mocked_run self.assertEqual(get_gcc_version(), '5.1.1') def test_gcc_version_darwin(self): """Test getting gcc version (mocked for Darwin).""" st.get_os_type = lambda: st.DARWIN - st.run_cmd = lambda *args, **kwargs: ("Apple LLVM version 7.0.0 (clang-700.1.76)", 0) + out = "Apple LLVM version 7.0.0 (clang-700.1.76)" + st.run = lambda *args, **kwargs: RunResult(output=out, exit_code=0, stderr=None) self.assertEqual(get_gcc_version(), None) def test_glibc_version_native(self): @@ -787,7 +785,7 @@ def test_glibc_version_native(self): def test_glibc_version_linux(self): """Test getting glibc version (mocked for Linux).""" st.get_os_type = lambda: st.LINUX - st.run_cmd = mocked_run_cmd + st.run = mocked_run self.assertEqual(get_glibc_version(), '2.12') def test_glibc_version_linux_gentoo(self): @@ -818,7 +816,7 @@ def test_get_total_memory_linux(self): def test_get_total_memory_darwin(self): """Test the function that gets the total memory.""" st.get_os_type = lambda: st.DARWIN - st.run_cmd = mocked_run_cmd + st.run = mocked_run self.assertEqual(get_total_memory(), 8192) def test_get_total_memory_native(self): @@ -850,7 +848,7 @@ def test_det_parallelism_mocked(self): st.get_avail_core_count = lambda: 8 self.assertTrue(det_parallelism(), 8) # make 'ulimit -u' return '40', which should result in default (max) parallelism of 4 ((40-15)/6) - st.run_cmd = mocked_run_cmd + st.run = mocked_run self.assertTrue(det_parallelism(), 4) self.assertTrue(det_parallelism(par=6), 4) self.assertTrue(det_parallelism(maxpar=2), 2) @@ -1039,15 +1037,16 @@ def test_check_linked_shared_libs(self): os_type = get_os_type() if os_type == LINUX: with self.mocked_stdout_stderr(): - out, _ = run_cmd("ldd %s" % bin_ls_path) + res = run("ldd %s" % bin_ls_path) elif os_type == DARWIN: - out, _ = run_cmd("otool -L %s" % bin_ls_path) + with self.mocked_stdout_stderr(): + res = run("otool -L %s" % bin_ls_path) else: raise EasyBuildError("Unknown OS type: %s" % os_type) shlib_ext = get_shared_lib_ext() lib_path_regex = re.compile(r'(?P[^\s]*/lib[^ ]+\.%s[^ ]*)' % shlib_ext, re.M) - lib_path = lib_path_regex.search(out).group(1) + lib_path = lib_path_regex.search(res.output).group(1) test_pattern_named_args = [ # if no patterns are specified, result is always True