Merge pull request #4544 from Micket/earlierhooks

trigger pre-hook in `run_shell_cmd` as early as possible so dry-run + trace output is correct

easybuild/tools/run.py

@@ -356,6 +356,8 @@ def to_cmd_str(cmd):
         if not isinstance(qa_patterns, list) or any(not isinstance(x, tuple) or len(x) != 2 for x in qa_patterns):
             raise EasyBuildError("qa_patterns passed to run_shell_cmd should be a list of 2-tuples!")
 
+    interactive = bool(qa_patterns)
+
     if qa_wait_patterns is None:
         qa_wait_patterns = []
 
@@ -365,6 +367,17 @@ def to_cmd_str(cmd):
         except FileNotFoundError:
             raise EasyBuildError(CWD_NOTFOUND_ERROR)
 
+    if with_hooks:
+        hooks = load_hooks(build_option('hooks'))
+        kwargs = {
+            'interactive': interactive,
+            'work_dir': work_dir,
+        }
+        hook_res = run_hook(RUN_SHELL_CMD, hooks, pre_step_hook=True, args=[cmd], kwargs=kwargs)
+        if hook_res:
+            cmd, old_cmd = hook_res, cmd
+            _log.info("Command to run was changed by pre-%s hook: '%s' (was: '%s')", RUN_SHELL_CMD, cmd, old_cmd)
+
     cmd_str = to_cmd_str(cmd)
 
     thread_id = None
@@ -398,7 +411,6 @@ def to_cmd_str(cmd):
     else:
         tmpdir, cmd_out_fp, cmd_err_fp = None, None, None
 
-    interactive = bool(qa_patterns)
     interactive_msg = 'interactive ' if interactive else ''
 
     # early exit in 'dry run' mode, after printing the command that would be run (unless 'hidden' is enabled)
@@ -429,18 +441,6 @@ def to_cmd_str(cmd):
     else:
         executable, shell = None, False
 
-    if with_hooks:
-        hooks = load_hooks(build_option('hooks'))
-        kwargs = {
-            'interactive': interactive,
-            'work_dir': work_dir,
-        }
-        hook_res = run_hook(RUN_SHELL_CMD, hooks, pre_step_hook=True, args=[cmd], kwargs=kwargs)
-        if hook_res:
-            cmd, old_cmd = hook_res, cmd
-            cmd_str = to_cmd_str(cmd)
-            _log.info("Command to run was changed by pre-%s hook: '%s' (was: '%s')", RUN_SHELL_CMD, cmd, old_cmd)
-
     stderr = subprocess.PIPE if split_stderr else subprocess.STDOUT
 
     log_msg = f"Running {interactive_msg}shell command '{cmd_str}' in {work_dir}"

test/framework/run.py

@@ -1934,6 +1934,32 @@ def post_run_shell_cmd_hook(cmd, *args, **kwargs):
         ])
         self.assertEqual(stdout, expected_stdout)
 
+        # also check in dry run mode, to verify that pre-run_shell_cmd hook is triggered sufficiently early
+        update_build_option('extended_dry_run', True)
+
+        with self.mocked_stdout_stderr():
+            run_shell_cmd("make")
+            stdout = self.get_stdout()
+
+        expected_stdout = '\n'.join([
+            "pre-run hook 'make' in %s" % cwd,
+            '  running shell command "echo make"',
+            '  (in %s)' % cwd,
+            '',
+        ])
+        self.assertEqual(stdout, expected_stdout)
+
+        # also check with trace output enabled
+        update_build_option('extended_dry_run', False)
+        update_build_option('trace', True)
+
+        with self.mocked_stdout_stderr():
+            run_shell_cmd("make")
+            stdout = self.get_stdout()
+
+        regex = re.compile('>> running shell command:\n\techo make', re.M)
+        self.assertTrue(regex.search(stdout), "Pattern '%s' found in: %s" % (regex.pattern, stdout))
+
 
 def suite():
     """ returns all the testcases in this module """