diff --git a/easybuild/tools/modules.py b/easybuild/tools/modules.py index 9037be6ea8..2a32e7fdd4 100644 --- a/easybuild/tools/modules.py +++ b/easybuild/tools/modules.py @@ -50,7 +50,7 @@ from easybuild.tools.environment import ORIG_OS_ENVIRON, restore_env, setvar, unset_env_vars from easybuild.tools.filetools import convert_name, mkdir, normalize_path, path_matches, read_file, which, write_file from easybuild.tools.module_naming_scheme.mns import DEVEL_MODULE_SUFFIX -from easybuild.tools.run import run_cmd, subprocess_popen_text +from easybuild.tools.run import run from easybuild.tools.utilities import get_subclasses, nub # software root/version environment variable name prefixes @@ -307,31 +307,32 @@ def check_module_function(self, allow_mismatch=False, regex=None): if self.testing: # grab 'module' function definition from environment if it's there; only during testing if 'module' in os.environ: - out, ec = os.environ['module'], 0 + output, exit_code = os.environ['module'], 0 else: - out, ec = None, 1 + output, exit_code = None, 1 else: cmd = "type module" - out, ec = run_cmd(cmd, simple=False, log_ok=False, log_all=False, force_in_dry_run=True, trace=False) + res = run(cmd, fail_on_error=False, in_dry_run=False, hidden=True) + output, exit_code = res.output, res.exit_code if regex is None: regex = r".*%s" % os.path.basename(self.cmd) mod_cmd_re = re.compile(regex, re.M) mod_details = "pattern '%s' (%s)" % (mod_cmd_re.pattern, self.NAME) - if ec == 0: - if mod_cmd_re.search(out): + if exit_code == 0: + if mod_cmd_re.search(output): self.log.debug("Found pattern '%s' in defined 'module' function." % mod_cmd_re.pattern) else: msg = "%s not found in defined 'module' function.\n" % mod_details msg += "Specify the correct modules tool to avoid weird problems due to this mismatch, " msg += "see the --modules-tool and --avail-modules-tools command line options.\n" if allow_mismatch: - msg += "Obtained definition of 'module' function: %s" % out + msg += "Obtained definition of 'module' function: %s" % output self.log.warning(msg) else: msg += "Or alternatively, use --allow-modules-tool-mismatch to stop treating this as an error. " - msg += "Obtained definition of 'module' function: %s" % out + msg += "Obtained definition of 'module' function: %s" % output raise EasyBuildError(msg) else: # module function may not be defined (weird, but fine) @@ -821,24 +822,23 @@ def run_module(self, *args, **kwargs): key, old_value, new_value) cmd_list = self.compose_cmd_list(args) - full_cmd = ' '.join(cmd_list) - self.log.debug("Running module command '%s' from %s" % (full_cmd, os.getcwd())) - - proc = subprocess_popen_text(cmd_list, env=environ) + cmd = ' '.join(cmd_list) + # note: module commands are always run in dry mode, and are kept hidden in trace and dry run output + res = run(cmd_list, env=environ, fail_on_error=False, shell=False, split_stderr=True, + hidden=True, in_dry_run=True) # stdout will contain python code (to change environment etc) # stderr will contain text (just like the normal module command) - (stdout, stderr) = proc.communicate() - self.log.debug("Output of module command '%s': stdout: %s; stderr: %s" % (full_cmd, stdout, stderr)) + stdout, stderr = res.output, res.stderr + self.log.debug("Output of module command '%s': stdout: %s; stderr: %s", cmd, stdout, stderr) # also catch and check exit code - exit_code = proc.returncode - if kwargs.get('check_exit_code', True) and exit_code != 0: + if kwargs.get('check_exit_code', True) and res.exit_code != 0: raise EasyBuildError("Module command '%s' failed with exit code %s; stderr: %s; stdout: %s", - ' '.join(cmd_list), exit_code, stderr, stdout) + cmd, res.exit_code, stderr, stdout) if kwargs.get('check_output', True): - self.check_module_output(full_cmd, stdout, stderr) + self.check_module_output(cmd, stdout, stderr) if kwargs.get('return_stderr', False): return stderr @@ -1422,21 +1422,22 @@ def update(self): if build_option('update_modules_tool_cache'): spider_cmd = os.path.join(os.path.dirname(self.cmd), 'spider') - cmd = [spider_cmd, '-o', 'moduleT', os.environ['MODULEPATH']] - self.log.debug("Running command '%s'..." % ' '.join(cmd)) + cmd_list = [spider_cmd, '-o', 'moduleT', os.environ['MODULEPATH']] + cmd = ' '.join(cmd_list) + self.log.debug("Running command '%s'...", cmd) - proc = subprocess_popen_text(cmd, env=os.environ) - (stdout, stderr) = proc.communicate() + res = run(cmd_list, env=os.environ, fail_on_error=False, shell=False, split_stderr=True, hidden=True) + stdout, stderr = res.output, res.stderr if stderr: - raise EasyBuildError("An error occurred when running '%s': %s", ' '.join(cmd), stderr) + raise EasyBuildError("An error occurred when running '%s': %s", cmd, stderr) if self.testing: # don't actually update local cache when testing, just return the cache contents return stdout else: cache_fp = os.path.join(self.USER_CACHE_DIR, 'moduleT.lua') - self.log.debug("Updating Lmod spider cache %s with output from '%s'" % (cache_fp, ' '.join(cmd))) + self.log.debug("Updating Lmod spider cache %s with output from '%s'", cache_fp, cmd) cache_dir = os.path.dirname(cache_fp) if not os.path.exists(cache_dir): mkdir(cache_dir, parents=True) diff --git a/easybuild/tools/run.py b/easybuild/tools/run.py index bef92ec2a2..ce4298a4cc 100644 --- a/easybuild/tools/run.py +++ b/easybuild/tools/run.py @@ -107,7 +107,7 @@ def cache_aware_func(cmd, *args, **kwargs): @run_cache -def run(cmd, fail_on_error=True, split_stderr=False, stdin=None, +def run(cmd, fail_on_error=True, split_stderr=False, stdin=None, env=None, hidden=False, in_dry_run=False, work_dir=None, shell=True, output_file=False, stream_output=False, asynchronous=False, qa_patterns=None, qa_wait_patterns=None): @@ -117,6 +117,7 @@ def run(cmd, fail_on_error=True, split_stderr=False, stdin=None, :param fail_on_error: fail on non-zero exit code (enabled by default) :param split_stderr: split of stderr from stdout output :param stdin: input to be sent to stdin (nothing if set to None) + :param env: environment to use to run command (if None, inherit current process environment) :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) @@ -134,7 +135,7 @@ def run(cmd, fail_on_error=True, split_stderr=False, stdin=None, """ # temporarily raise a NotImplementedError until all options are implemented - if any((split_stderr, work_dir, stream_output, asynchronous)): + if any((work_dir, stream_output, asynchronous)): raise NotImplementedError if qa_patterns or qa_wait_patterns: @@ -163,7 +164,7 @@ def run(cmd, fail_on_error=True, split_stderr=False, stdin=None, if not in_dry_run and build_option('extended_dry_run'): if not hidden: silent = build_option('silent') - msg = f" running command \"{cmd_msg}s\"\n" + msg = f" running command \"{cmd_msg}\"\n" msg += f" (in {work_dir})" dry_run_msg(msg, silent=silent) @@ -179,21 +180,27 @@ def run(cmd, fail_on_error=True, split_stderr=False, stdin=None, # 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 + # stick to None (default value) when not running command via a shell + executable = '/bin/bash' if shell else None + + stderr = subprocess.PIPE if split_stderr else subprocess.STDOUT _log.info(f"Running command '{cmd_msg}' in {work_dir}") - proc = subprocess.run(cmd, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, check=fail_on_error, - input=stdin, shell=shell, executable=executable) + proc = subprocess.run(cmd, stdout=subprocess.PIPE, stderr=stderr, check=fail_on_error, + env=env, 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') + stderr_output = proc.stderr.decode('utf-8', 'ignore') if split_stderr else None - 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}") + res = RunResult(output=output, exit_code=proc.returncode, stderr=stderr_output) + + if split_stderr: + log_msg = f"Command '{cmd_msg}' exited with exit code {res.exit_code}, " + log_msg += f"with stdout:\n{res.output}\nstderr:\n{res.stderr}" + else: + log_msg = f"Command '{cmd_msg}' exited with exit code {res.exit_code} and output:\n{res.output}" + _log.info(log_msg) if not hidden: time_since_start = time_str_since(start_time) diff --git a/test/framework/modules.py b/test/framework/modules.py index 27a859282e..d0c330e622 100644 --- a/test/framework/modules.py +++ b/test/framework/modules.py @@ -50,7 +50,7 @@ from easybuild.tools.modules import EnvironmentModules, EnvironmentModulesC, EnvironmentModulesTcl, Lmod, NoModulesTool from easybuild.tools.modules import curr_module_paths, get_software_libdir, get_software_root, get_software_version from easybuild.tools.modules import invalidate_module_caches_for, modules_tool, reset_module_caches -from easybuild.tools.run import run_cmd +from easybuild.tools.run import run # number of modules included for testing purposes @@ -191,6 +191,21 @@ def test_run_module(self): regex = re.compile(r'^os\.environ\[', re.M) self.assertFalse(regex.search(out), "Pattern '%s' should not be found in: %s" % (regex.pattern, out)) + def test_list(self): + """ + Test running 'module list' via ModulesTool instance. + """ + # make very sure no modules are currently loaded + self.modtool.run_module('purge', '--force') + + out = self.modtool.list() + self.assertEqual(out, []) + + mods = ['GCC/7.3.0-2.30'] + self.modtool.load(mods) + out = self.modtool.list() + self.assertEqual([x['mod_name'] for x in out], mods) + def test_avail(self): """Test if getting a (restricted) list of available modules works.""" self.init_testmods() @@ -1317,9 +1332,9 @@ def test_module_use_bash(self): self.assertIn(modules_dir, modulepath) with self.mocked_stdout_stderr(): - out, _ = run_cmd("bash -c 'echo MODULEPATH: $MODULEPATH'", simple=False) - self.assertEqual(out.strip(), "MODULEPATH: %s" % modulepath) - self.assertIn(modules_dir, out) + res = run("bash -c 'echo MODULEPATH: $MODULEPATH'") + self.assertEqual(res.output.strip(), f"MODULEPATH: {modulepath}") + self.assertIn(modules_dir, res.output) def test_load_in_hierarchy(self): """Test whether loading a module in a module hierarchy results in loading the correct module.""" diff --git a/test/framework/run.py b/test/framework/run.py index 08e7ec4a60..00b3ca778a 100644 --- a/test/framework/run.py +++ b/test/framework/run.py @@ -369,6 +369,28 @@ def test_run_cmd_log_output(self): self.assertTrue(out.startswith('foo ') and out.endswith(' bar')) self.assertEqual(type(out), str) + def test_run_split_stderr(self): + """Test getting split stdout/stderr output from run function.""" + cmd = ';'.join([ + "echo ok", + "echo warning >&2", + ]) + + # by default, output contains both stdout + stderr + with self.mocked_stdout_stderr(): + res = run(cmd) + self.assertEqual(res.exit_code, 0) + output_lines = res.output.split('\n') + self.assertTrue("ok" in output_lines) + self.assertTrue("warning" in output_lines) + self.assertEqual(res.stderr, None) + + with self.mocked_stdout_stderr(): + res = run(cmd, split_stderr=True) + self.assertEqual(res.exit_code, 0) + self.assertEqual(res.stderr, "warning\n") + self.assertEqual(res.output, "ok\n") + def test_run_cmd_trace(self): """Test run_cmd in trace mode, and with tracing disabled.""" @@ -778,55 +800,96 @@ def test_parse_log_error(self): errors = parse_log_for_error("error failed", True) self.assertEqual(len(errors), 1) - def test_dry_run(self): - """Test use of functions under (extended) dry run.""" + def test_run_cmd_dry_run(self): + """Test use of run_cmd function under (extended) dry run.""" build_options = { 'extended_dry_run': True, 'silent': False, } init_config(build_options=build_options) + cmd = "somecommand foo 123 bar" + self.mock_stdout(True) - run_cmd("somecommand foo 123 bar") - txt = self.get_stdout() + run_cmd(cmd) + stdout = self.get_stdout() self.mock_stdout(False) expected = """ running command "somecommand foo 123 bar"\n""" - self.assertIn(expected, txt) + self.assertIn(expected, stdout) # check disabling 'verbose' self.mock_stdout(True) run_cmd("somecommand foo 123 bar", verbose=False) + stdout = self.get_stdout() self.mock_stdout(False) + self.assertNotIn(expected, stdout) # check forced run_cmd outfile = os.path.join(self.test_prefix, 'cmd.out') self.assertNotExists(outfile) self.mock_stdout(True) run_cmd("echo 'This is always echoed' > %s" % outfile, force_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") - write_file(outfile, '', forced=True) + # Q&A commands + self.mock_stdout(True) + run_cmd_qa("some_qa_cmd", {'question1': 'answer1'}) + stdout = self.get_stdout() + self.mock_stdout(False) + + expected = """ running interactive command "some_qa_cmd"\n""" + self.assertIn(expected, stdout) + + def test_run_dry_run(self): + """Test use of run function under (extended) dry run.""" + build_options = { + 'extended_dry_run': True, + 'silent': False, + } + init_config(build_options=build_options) + + cmd = "somecommand foo 123 bar" - # check forced run self.mock_stdout(True) - run("echo 'This is always echoed' > %s" % outfile, in_dry_run=True) - txt = self.get_stdout() + res = run(cmd) + stdout = self.get_stdout() self.mock_stdout(False) - self.assertExists(outfile) - self.assertEqual(read_file(outfile), "This is always echoed\n") + # fake output/exit code is returned for commands not actually run in dry run mode + self.assertEqual(res.exit_code, 0) + self.assertEqual(res.output, '') + self.assertEqual(res.stderr, None) + # check dry run output + expected = """ running command "somecommand foo 123 bar"\n""" + self.assertIn(expected, stdout) - # Q&A commands + # check enabling 'hidden' self.mock_stdout(True) - run_cmd_qa("some_qa_cmd", {'question1': 'answer1'}) - txt = self.get_stdout() + res = run(cmd, hidden=True) + stdout = self.get_stdout() self.mock_stdout(False) + # fake output/exit code is returned for commands not actually run in dry run mode + self.assertEqual(res.exit_code, 0) + self.assertEqual(res.output, '') + self.assertEqual(res.stderr, None) + # dry run output should be missing + self.assertNotIn(expected, stdout) - expected = """ running interactive command "some_qa_cmd"\n""" - self.assertIn(expected, txt) + # check forced run_cmd + outfile = os.path.join(self.test_prefix, 'cmd.out') + self.assertNotExists(outfile) + self.mock_stdout(True) + res = run("echo 'This is always echoed' > %s; echo done; false" % outfile, fail_on_error=False, in_dry_run=True) + stdout = self.get_stdout() + self.mock_stdout(False) + self.assertNotIn('running command "', stdout) + self.assertNotEqual(res.exit_code, 0) + self.assertEqual(res.output, 'done\n') + self.assertEqual(res.stderr, None) + self.assertExists(outfile) + self.assertEqual(read_file(outfile), "This is always echoed\n") def test_run_cmd_list(self): """Test run_cmd with command specified as a list rather than a string"""