Send trace messages to stderr

NEWS.md

@@ -2,7 +2,9 @@
 
 ## Unreleased
 
-- New: generate key-value map values.
+- New: generate key-value map values from types like `BTreeMap<String, Vec<u8>>`.
+
+- Changed: Send trace messages to stderr rather stdout, in part so that it won't pollute json output.
 
 ## 23.10.0
 

src/console.rs

@@ -12,6 +12,7 @@ use std::time::{Duration, Instant};
 use camino::{Utf8Path, Utf8PathBuf};
 use console::{style, StyledObject};
 
+use nutmeg::Destination;
 use tracing::Level;
 use tracing_subscriber::fmt::MakeWriter;
 use tracing_subscriber::prelude::*;
@@ -128,7 +129,7 @@ impl Console {
             );
         }
         s.push('\n');
-        self.view.message(&s);
+        self.message(&s);
     }
 
     /// Update that a test timeout was auto-set.
@@ -215,7 +216,11 @@ impl Console {
     }
 
     pub fn message(&self, message: &str) {
-        self.view.message(message)
+        // A workaround for nutmeg not being able to coordinate writes to both stdout and
+        // stderr...
+        // <https://github.com/sourcefrog/nutmeg/issues/11>
+        self.view.clear();
+        print!("{}", message);
     }
 
     pub fn tick(&self) {
@@ -563,7 +568,9 @@ impl nutmeg::Model for CopyModel {
 }
 
 fn nutmeg_options() -> nutmeg::Options {
-    nutmeg::Options::default().print_holdoff(Duration::from_millis(50))
+    nutmeg::Options::default()
+        .print_holdoff(Duration::from_millis(50))
+        .destination(Destination::Stderr)
 }
 
 /// Return a styled string reflecting the moral value of this outcome.

tests/cli/config.rs

@@ -130,7 +130,7 @@ fn tree_fails_without_needed_feature() {
         .arg(testdata.path())
         .assert()
         .failure()
-        .stdout(predicates::str::contains(
+        .stderr(predicates::str::contains(
             "test failed in an unmutated tree",
         ));
 }

tests/cli/error_value.rs

@@ -92,10 +92,15 @@ fn warn_if_error_value_starts_with_err() {
         .arg(tmp_src_dir.path())
         .assert()
         .code(0)
-        .stderr(predicate::str::is_empty())
-        .stdout(predicate::str::contains(
+        .stderr(predicate::str::contains(
             "error_value option gives the value of the error, and probably should not start with Err(: got Err(anyhow!(\"mutant\"))"
-        ));
+        ))
+        .stdout(indoc! { "\
+            src/lib.rs:3: replace even_is_ok -> Result<u32, &\'static str> with Ok(0)
+            src/lib.rs:3: replace even_is_ok -> Result<u32, &\'static str> with Ok(1)
+            src/lib.rs:3: replace even_is_ok -> Result<u32, &\'static str> with Err(Err(anyhow!(\"mutant\")))
+        "
+        });
 }
 
 #[test]

tests/cli/main.rs

@@ -1021,14 +1021,14 @@ fn already_failing_tests_are_detected_before_running_mutants() {
                 .and(predicate::str::contains("thread 'test_factorial' panicked"))
                 .and(predicate::str::contains("72")) // the failing value should be in the output
                 .and(predicate::str::contains("lib.rs:11:5"))
-                .and(predicate::str::contains(
-                    "cargo test failed in an unmutated tree, so no mutants were tested",
-                ))
                 .and(
                     predicate::str::contains("test result: FAILED. 0 passed; 1 failed;")
                         .normalize(),
                 ),
-        );
+        )
+        .stderr(predicate::str::contains(
+            "cargo test failed in an unmutated tree, so no mutants were tested",
+        ));
 }
 
 #[test]
@@ -1044,7 +1044,7 @@ fn already_failing_doctests_are_detected() {
         .stdout(contains(
             "this function takes 1 argument but 3 arguments were supplied",
         ))
-        .stdout(predicate::str::contains(
+        .stderr(predicate::str::contains(
             "cargo test failed in an unmutated tree, so no mutants were tested",
         ));
 }
@@ -1092,7 +1092,7 @@ fn source_tree_typecheck_fails() {
         .stdout(contains("build --tests")) // Caught at the check phase
         .stdout(contains("lib.rs:6"))
         .stdout(contains("*** result: "))
-        .stdout(contains(
+        .stderr(contains(
             "build failed in an unmutated tree, so no mutants were tested",
         ));
 }
@@ -1131,8 +1131,8 @@ fn timeout_when_unmutated_tree_test_hangs() {
         .assert()
         .code(4) // exit_code::CLEAN_TESTS_FAILED
         .stdout(is_match(r"Unmutated baseline \.\.\. TIMEOUT in \d+\.\ds").unwrap())
-        .stdout(contains("timeout"))
-        .stdout(contains(
+        .stderr(contains("timeout"))
+        .stderr(contains(
             "cargo test failed in an unmutated tree, so no mutants were tested",
         ));
 }
@@ -1212,9 +1212,10 @@ fn interrupt_caught_and_kills_children() {
         .expect("read stderr");
     println!("stderr:\n{stderr}");
 
-    assert!(stdout.contains("interrupted"));
-    assert!(stdout.contains("terminating child process"));
-    assert!(stdout.contains("terminated child exit status"));
+    assert!(stderr.contains("interrupted"));
+    // Also because of `--level=trace` we see some debug details.
+    assert!(stderr.contains("terminating child process"));
+    assert!(stderr.contains("terminated child exit status"));
 }
 
 /// A tree that hangs when some functions are mutated does not hang cargo-mutants

tests/cli/trace.rs

@@ -15,8 +15,8 @@ fn env_var_controls_trace() {
         .arg("testdata/tree/never_type")
         .assert()
         // This is a debug!() message; it should only be seen if the trace var
-        // was wired correctly.
-        .stdout(predicate::str::contains(
+        // was wired correctly to stderr.
+        .stderr(predicate::str::contains(
             "No mutants generated for this return type",
         ));
 }