diff --git a/src/command_ext.rs b/src/command_ext.rs index 1cd7ef0343..efb520ae76 100644 --- a/src/command_ext.rs +++ b/src/command_ext.rs @@ -11,11 +11,11 @@ pub(crate) trait CommandExt { fn export_scope(&mut self, settings: &Settings, scope: &Scope, unexports: &HashSet); - fn output_guard(self) -> (io::Result, Option); + fn output_guard(self, config: &Config) -> (io::Result, Option); - fn output_guard_stdout(self) -> Result; + fn output_guard_stdout(self, config: &Config) -> Result; - fn status_guard(self) -> (io::Result, Option); + fn status_guard(self, config: &Config) -> (io::Result, Option); } impl CommandExt for Command { @@ -53,12 +53,12 @@ impl CommandExt for Command { } } - fn output_guard(self) -> (io::Result, Option) { - SignalHandler::spawn(self, process::Child::wait_with_output) + fn output_guard(self, config: &Config) -> (io::Result, Option) { + SignalHandler::spawn(self, config, process::Child::wait_with_output) } - fn output_guard_stdout(self) -> Result { - let (result, caught) = self.output_guard(); + fn output_guard_stdout(self, config: &Config) -> Result { + let (result, caught) = self.output_guard(config); let output = result.map_err(OutputError::Io)?; @@ -79,7 +79,7 @@ impl CommandExt for Command { ) } - fn status_guard(self) -> (io::Result, Option) { - SignalHandler::spawn(self, |mut child| child.wait()) + fn status_guard(self, config: &Config) -> (io::Result, Option) { + SignalHandler::spawn(self, config, |mut child| child.wait()) } } diff --git a/src/evaluator.rs b/src/evaluator.rs index e3a7166bab..2618058865 100644 --- a/src/evaluator.rs +++ b/src/evaluator.rs @@ -291,7 +291,7 @@ impl<'src, 'run> Evaluator<'src, 'run> { }) .stdout(Stdio::piped()); - cmd.output_guard_stdout() + cmd.output_guard_stdout(self.context.config) } pub(crate) fn evaluate_line( diff --git a/src/justfile.rs b/src/justfile.rs index bf4623de84..8e3e8c8ad7 100644 --- a/src/justfile.rs +++ b/src/justfile.rs @@ -158,7 +158,7 @@ impl<'src> Justfile<'src> { command.export(&self.settings, &dotenv, &scope, &self.unexports); - let (result, caught) = command.status_guard(); + let (result, caught) = command.status_guard(config); let status = result.map_err(|io_error| Error::CommandInvoke { binary: binary.clone(), diff --git a/src/platform/windows.rs b/src/platform/windows.rs index 13c5f32936..24e59ab540 100644 --- a/src/platform/windows.rs +++ b/src/platform/windows.rs @@ -25,7 +25,7 @@ impl PlatformInterface for Platform { .stdout(Stdio::piped()) .stderr(Stdio::piped()); - Cow::Owned(cygpath.output_guard_stdout()?) + Cow::Owned(cygpath.output_guard_stdout(config)?) } else { // …otherwise use it as-is. Cow::Borrowed(shebang.interpreter) @@ -69,7 +69,7 @@ impl PlatformInterface for Platform { .stdout(Stdio::piped()) .stderr(Stdio::piped()); - match cygpath.output_guard_stdout() { + match cygpath.output_guard_stdout(config) { Ok(shell_path) => Ok(shell_path), Err(_) => path .to_str() diff --git a/src/recipe.rs b/src/recipe.rs index 11b8f2edac..86a7685cdf 100644 --- a/src/recipe.rs +++ b/src/recipe.rs @@ -321,7 +321,7 @@ impl<'src, D> Recipe<'src, D> { &context.module.unexports, ); - let (result, caught) = cmd.status_guard(); + let (result, caught) = cmd.status_guard(context.config); match result { Ok(exit_status) => { @@ -453,7 +453,7 @@ impl<'src, D> Recipe<'src, D> { ); // run it! - let (result, caught) = command.status_guard(); + let (result, caught) = command.status_guard(context.config); match result { Ok(exit_status) => exit_status.code().map_or_else( diff --git a/src/signal_handler.rs b/src/signal_handler.rs index 0aee6e2695..3253a649ac 100644 --- a/src/signal_handler.rs +++ b/src/signal_handler.rs @@ -105,10 +105,30 @@ impl SignalHandler { pub(crate) fn spawn( mut command: Command, + config: &Config, f: impl Fn(process::Child) -> io::Result, ) -> (io::Result, Option) { let mut instance = Self::instance(); + let color = config.color.context().stderr(); + let pfx = color.prefix(); + let sfx = color.suffix(); + + // Print an xtrace of run commands. + if config.verbosity.grandiloquent() { + // At the highest verbosity level, print the exact command as-is. + eprintln!("{pfx}+ {command:?}{sfx}"); + } else if config.verbosity.loquacious() { + // For the second highest verbosity level, reconstruct the command but don't include + // environment (can be quite noisy with many `export`ed variables). + let mut dbg_cmd = Command::new(command.get_program()); + dbg_cmd.args(command.get_args()); + if let Some(cwd) = command.get_current_dir() { + dbg_cmd.current_dir(cwd); + } + eprintln!("{pfx}+ {dbg_cmd:?}{sfx}"); + } + let child = match command.spawn() { Err(err) => return (Err(err), None), Ok(child) => child, diff --git a/tests/fallback.rs b/tests/fallback.rs index 62e96b5966..765c78584b 100644 --- a/tests/fallback.rs +++ b/tests/fallback.rs @@ -61,6 +61,7 @@ fn fallback_from_subdir_verbose_message() { Trying ../justfile ===> Running recipe `bar`... echo bar + + COMMAND_XTRACE ", )) .stdout("bar\n") diff --git a/tests/misc.rs b/tests/misc.rs index 3c572bbe52..0d59314ff2 100644 --- a/tests/misc.rs +++ b/tests/misc.rs @@ -232,7 +232,64 @@ fn verbose() { .arg("--verbose") .justfile("default:\n @echo hello") .stdout("hello\n") - .stderr("===> Running recipe `default`...\necho hello\n") + .stderr( + "\ + ===> Running recipe `default`...\n\ + echo hello\n\ + + COMMAND_XTRACE\n\ + ", + ) + .run(); +} + +#[test] +fn xtrace() { + Test::new() + .arg("--verbose") + .justfile( + r#" +export MESSAGE := "hi" +a: + echo $MESSAGE +"#, + ) + .normalize_xtrace(false) + .stdout("hi\n") + .stderr_fn(|s| { + // The lowest verbosity mode shouldn't print MESSAGE. Easier to check with a function + // than with regex. + if s.contains("MESSAGE=") { + return Err("shouldn't print env".into()); + } + Ok(()) + }) + .stderr_regex(if cfg!(windows) { + r".*\+ .*echo \$MESSAGE.*" + } else { + r".*\+ cd.*&&.*echo \$MESSAGE.*" + }) + .run(); +} + +#[test] +fn xtrace_very_verbose() { + Test::new() + .arg("-vv") + .justfile( + r#" +export MESSAGE := "hi" +a: + echo $MESSAGE +"#, + ) + .normalize_xtrace(false) + .stdout("hi\n") + .stderr_regex(if cfg!(windows) { + // `Debug for Command` doesn't print env on windows + r".*\+ .*echo \$MESSAGE.*" + } else { + r".*\+ cd.*&&.*MESSAGE=.*echo \$MESSAGE.*" + }) .run(); } @@ -2037,7 +2094,13 @@ a: ", ) .stdout("hi\n") - .stderr("\u{1b}[1;36m===> Running recipe `a`...\u{1b}[0m\n\u{1b}[1mecho hi\u{1b}[0m\n") + .stderr( + "\ + \u{1b}[1;36m===> Running recipe `a`...\u{1b}[0m\n\ + \u{1b}[1mecho hi\u{1b}[0m\n\ + \u{1b}[1;34m+ COMMAND_XTRACE\u{1b}[0m\n\ + ", + ) .run(); } @@ -2057,7 +2120,13 @@ a: ", ) .stdout("hi\n") - .stderr("\u{1b}[1;36m===> Running recipe `a`...\u{1b}[0m\necho hi\n") + .stderr( + "\ + \u{1b}[1;36m===> Running recipe `a`...\u{1b}[0m\n\ + echo hi\n\ + \u{1b}[1;34m+ COMMAND_XTRACE\u{1b}[0m\n\ + ", + ) .run(); } diff --git a/tests/test.rs b/tests/test.rs index a973212714..cfe76ef5d7 100644 --- a/tests/test.rs +++ b/tests/test.rs @@ -1,5 +1,6 @@ use { super::*, + once_cell::sync::Lazy, pretty_assertions::{assert_eq, StrComparison}, }; @@ -16,10 +17,12 @@ pub(crate) struct Test { pub(crate) env: BTreeMap, pub(crate) expected_files: BTreeMap>, pub(crate) justfile: Option, + pub(crate) normalize_xtrace: bool, pub(crate) response: Option, pub(crate) shell: bool, pub(crate) status: i32, pub(crate) stderr: String, + pub(crate) stderr_fn: Option Result<(), String>>>, pub(crate) stderr_regex: Option, pub(crate) stdin: String, pub(crate) stdout: String, @@ -46,12 +49,14 @@ impl Test { status: EXIT_SUCCESS, stderr: String::new(), stderr_regex: None, + stderr_fn: None, stdin: String::new(), stdout: String::new(), stdout_regex: None, tempdir, test_round_trip: true, unindent_stdout: true, + normalize_xtrace: true, } } @@ -132,6 +137,11 @@ impl Test { self } + pub(crate) fn stderr_fn(mut self, f: impl Fn(&str) -> Result<(), String> + 'static) -> Self { + self.stderr_fn = Some(Box::from(f)); + self + } + pub(crate) fn stdin(mut self, stdin: impl Into) -> Self { self.stdin = stdin.into(); self @@ -164,6 +174,11 @@ impl Test { self } + pub(crate) fn normalize_xtrace(mut self, normalize_xtrace: bool) -> Self { + self.normalize_xtrace = normalize_xtrace; + self + } + pub(crate) fn write(self, path: impl AsRef, content: impl AsRef<[u8]>) -> Self { let path = self.tempdir.path().join(path); fs::create_dir_all(path.parent().unwrap()).unwrap(); @@ -204,6 +219,18 @@ impl Test { } } +static XTRACE_RE: Lazy = Lazy::new(|| { + Regex::new( + r#"(?mx)^ # multiline, verbose + (?P\u{1b}\[[\d;]+m)? # match the color prefix, if available + \+.*bash.*? # match the command. Currently all tests that pass `--verbose` are + # run on bash, so this matcher is "good enough" for now. + (?P\u{1b}\[[\d;]+m)? # match the color suffix, if available + $"#, + ) + .unwrap() +}); + impl Test { #[track_caller] pub(crate) fn run(self) -> Output { @@ -267,7 +294,14 @@ impl Test { .expect("failed to wait for just process"); let output_stdout = str::from_utf8(&output.stdout).unwrap(); - let output_stderr = str::from_utf8(&output.stderr).unwrap(); + let mut output_stderr = str::from_utf8(&output.stderr).unwrap(); + + // The xtrace output can differ by working directory, shell, and flags. Normalize it. + let tmp; + if self.normalize_xtrace { + tmp = XTRACE_RE.replace_all(output_stderr, "${pfx}+ COMMAND_XTRACE${sfx}"); + output_stderr = tmp.as_ref(); + } if let Some(ref stdout_regex) = self.stdout_regex { assert!( @@ -283,9 +317,18 @@ impl Test { ); } + if let Some(ref stderr_fn) = self.stderr_fn { + match stderr_fn(output_stderr) { + Ok(()) => (), + Err(e) => panic!("Stderr function mismatch: {e}\n{output_stderr:?}\n",), + } + } + if !compare("status", output.status.code(), Some(self.status)) | (self.stdout_regex.is_none() && !compare_string("stdout", output_stdout, &stdout)) - | (self.stderr_regex.is_none() && !compare_string("stderr", output_stderr, &stderr)) + | (self.stderr_regex.is_none() + && self.stderr_fn.is_none() + && !compare_string("stderr", output_stderr, &stderr)) { panic!("Output mismatch."); }