fix(cli): CLI output inconsistencies (logs to stderr, -qqq, deprecation warnings, test progress)

cli/src/main.rs

@@ -332,14 +332,14 @@ async fn run(cli: Cli, render_sender: Sender<DisplayMessage>) -> anyhow::Result<
     }
 }
 
-fn to_trace_filter(filter: log::LevelFilter) -> tracing::Level {
+fn to_trace_filter(filter: log::LevelFilter) -> tracing::level_filters::LevelFilter {
     match filter {
-        log::LevelFilter::Debug => tracing::Level::DEBUG,
-        log::LevelFilter::Error => tracing::Level::ERROR,
-        log::LevelFilter::Info => tracing::Level::INFO,
-        log::LevelFilter::Off => tracing::Level::TRACE,
-        log::LevelFilter::Trace => tracing::Level::TRACE,
-        log::LevelFilter::Warn => tracing::Level::WARN,
+        log::LevelFilter::Debug => tracing::level_filters::LevelFilter::DEBUG,
+        log::LevelFilter::Error => tracing::level_filters::LevelFilter::ERROR,
+        log::LevelFilter::Info => tracing::level_filters::LevelFilter::INFO,
+        log::LevelFilter::Off => tracing::level_filters::LevelFilter::OFF,
+        log::LevelFilter::Trace => tracing::level_filters::LevelFilter::TRACE,
+        log::LevelFilter::Warn => tracing::level_filters::LevelFilter::WARN,
     }
 }
 
@@ -351,9 +351,12 @@ fn setup_logger(
 ) -> anyhow::Result<()> {
     let command_string = String::from(command_name);
     let sentry_layer = sentry_tracing::layer().event_mapper(move |event, context| {
+        // deprecation warnings are sent as events so we can see who still uses deprecated flags
+        let is_deprecation = *event.metadata().level() == tracing::Level::WARN
+            && event.metadata().fields().field("deprecated_flag").is_some();
         // trunk-ignore(clippy/match_ref_pats)
         match event.metadata().level() {
-            &tracing::Level::ERROR => {
+            level if *level == tracing::Level::ERROR || is_deprecation => {
                 let mut event = sentry_tracing::event_from_event(event, context);
                 event
                     .tags
@@ -380,16 +383,19 @@ fn setup_logger(
     });
 
     // make console layer toggle based on vebosity
+    // logs go to stderr so stdout is left for the command's output
+    let trace_filter = to_trace_filter(log_level_filter);
     let console_layer = tracing_subscriber::fmt::Layer::new()
         .with_target(true)
         .with_level(true)
-        .with_writer(std::io::stdout.with_max_level(to_trace_filter(log_level_filter)))
+        .with_writer(std::io::stderr)
         .with_filter(FilterFn::new(move |metadata| {
             !metadata
                 .fields()
                 .iter()
                 .any(|field| field.name() == "hidden_in_console")
-                && to_trace_filter(log_level_filter) > tracing::Level::INFO
+                && trace_filter > tracing::Level::INFO
+                && *metadata.level() <= trace_filter
         }));
 
     tracing_subscriber::registry()

cli/src/test_command.rs

@@ -79,43 +79,6 @@ pub struct TestRunResult {
     pub command_stderr: String,
 }
 
-fn lines_of(output: String) -> impl Iterator<Item = String> {
-    output
-        .lines()
-        .flat_map(|lf_line| {
-            lf_line
-                .split('\r')
-                .map(|crlf_line| crlf_line.replace('\t', "    "))
-        })
-        .collect::<Vec<String>>()
-        .into_iter()
-}
-
-impl EndOutput for TestRunResult {
-    fn output(&self) -> anyhow::Result<Vec<Line>> {
-        let mut output: Vec<Line> = Vec::new();
-
-        output.extend(vec![
-            Line::from_iter([Span::new_styled(
-                String::from("📒 Test command outputs").attribute(Attribute::Bold),
-            )?]),
-            Line::default(),
-        ]);
-
-        for stderr_line in lines_of(self.command_stderr.clone()) {
-            output.push(Line::from_iter([Span::new_unstyled_lossy(stderr_line)]));
-        }
-
-        output.push(Line::default());
-
-        for stdout_line in lines_of(self.command_stdout.clone()) {
-            output.push(Line::from_iter([Span::new_unstyled_lossy(stdout_line)]));
-        }
-
-        Ok(output)
-    }
-}
-
 pub async fn run_test(
     TestArgs {
         upload_args,
@@ -142,6 +105,7 @@ pub async fn run_test(
         RunUploadOptions {
             pre_test_context: Some(test_context),
             test_run_result: Some(test_run_result.clone()),
+            render_sender: Some(render_sender),
             ..Default::default()
         },
     )

cli/src/upload_command.rs

@@ -543,28 +543,28 @@ pub async fn run_upload(
     if upload_args.print_files.is_some() {
         let message =
             "The --print-files flag is deprecated and will be removed in a future version.";
-        tracing::error!("{message}");
+        tracing::warn!(deprecated_flag = "--print-files", "{message}");
         notices.push(Notice::deprecation(message));
     }
 
     if let Some(team) = &upload_args.team {
         if !team.is_empty() {
             let message = "The --team flag is deprecated and will be removed in a future version.";
-            tracing::error!("{message}");
+            tracing::warn!(deprecated_flag = "--team", "{message}");
             notices.push(Notice::deprecation(message));
         }
     }
 
     if upload_args.hide_banner {
         let message = "The --hide-banner flag is deprecated and does nothing. It will be removed in a future version.";
-        tracing::error!("{message}");
+        tracing::warn!(deprecated_flag = "--hide-banner", "{message}");
         notices.push(Notice::deprecation(message));
     }
 
     if upload_args.use_quarantining.is_some() {
         let message =
             "The --use-quarantining flag is deprecated. Use --disable-quarantining instead.";
-        tracing::warn!("{message}");
+        tracing::warn!(deprecated_flag = "--use-quarantining", "{message}");
         notices.push(Notice::deprecation(message));
     }
 

cli/tests/upload.rs

@@ -1248,7 +1248,7 @@ async fn falls_back_to_binary_file() {
     let meta_json = fs::File::open(tar_extract_directory.join("meta.json")).unwrap();
     assert!(serde_json::from_reader::<fs::File, BundleMeta>(meta_json).is_ok());
 
-    assert.stdout(predicate::str::contains(
+    assert.stderr(predicate::str::contains(
         "Attempting to parse bep file as binary",
     ));
 }
@@ -3865,3 +3865,53 @@ async fn upload_on_v1_when_trunk_chooses_v2_but_names_no_collection() {
         "the run must have uploaded on v1"
     );
 }
+
+// A debug log emitted while setting up the API client, so it only shows up with `--verbose`.
+const DEBUG_LOG_MARKER: &str = "Using public api address";
+
+// NOTE: must be multi threaded to start a mock server
+#[tokio::test(flavor = "multi_thread")]
+async fn upload_verbose_logs_go_to_stderr() {
+    let temp_dir = tempdir().unwrap();
+    generate_mock_git_repo(&temp_dir);
+    generate_mock_valid_junit_xmls(&temp_dir);
+
+    let state = MockServerBuilder::new().spawn_mock_server().await;
+
+    let assert = CommandBuilder::upload(temp_dir.path(), state.host.clone())
+        .verbose(true)
+        .command()
+        .arg("--team")
+        .arg("some-team")
+        .assert();
+
+    println!("{assert}");
+    // stdout is kept free of logs so it can carry machine-readable output
+    assert
+        .stdout(predicate::str::contains(DEBUG_LOG_MARKER).not())
+        .stderr(predicate::str::contains(DEBUG_LOG_MARKER))
+        .stderr(predicate::str::contains(
+            "The --team flag is deprecated and will be removed in a future version.",
+        ))
+        .stderr(predicate::str::contains("WARN"));
+}
+
+// NOTE: must be multi threaded to start a mock server
+#[tokio::test(flavor = "multi_thread")]
+async fn upload_quietest_verbosity_logs_nothing() {
+    let temp_dir = tempdir().unwrap();
+    generate_mock_git_repo(&temp_dir);
+    generate_mock_valid_junit_xmls(&temp_dir);
+
+    let state = MockServerBuilder::new().spawn_mock_server().await;
+
+    let assert = CommandBuilder::upload(temp_dir.path(), state.host.clone())
+        .extra_args(&["-qqq"])
+        .command()
+        .assert();
+
+    println!("{assert}");
+    assert
+        .stdout(predicate::str::contains(DEBUG_LOG_MARKER).not())
+        .stderr(predicate::str::contains(DEBUG_LOG_MARKER).not());
+}