Fix live printing (#880)

<!-- Reference any GitHub issues resolved by this PR -->

Closes #860
Closes #843

## Introduced changes

<!-- A brief description of the changes -->

- Test from different crates no longer run in parallel
- Tests from crate are now run unordered.
- Outputs from these tests are printed immediately after test case
execution completed
- Added new macro for testing e2e tests outputs that does not depend on
test order. This macro is limited right now in that it asserts the
output line by line. This is problematic for outputs that are longer
than one line, like the whole output of `[FAIL]` test. This will be
extended in future PRs.

## Breaking changes

<!-- List of all breaking changes, if applicable -->

## Checklist

<!-- Make sure all of these are complete -->

- [x] Linked relevant issue
- [x] Updated relevant documentation
- [x] Added relevant tests
- [x] Performed self-review of the code
- [x] Added changes to `CHANGELOG.md`

(cherry picked from commit 3aba230)

Author: cptartur

crates/forge/src/lib.rs

@@ -24,7 +24,7 @@ use cairo_lang_sierra::ids::ConcreteTypeId;
 use cairo_lang_sierra::program::{Function, Program};
 use cairo_lang_sierra_to_casm::metadata::MetadataComputationConfig;
 use cairo_lang_utils::ordered_hash_map::OrderedHashMap;
-use futures::stream::{FuturesOrdered, FuturesUnordered};
+use futures::stream::FuturesUnordered;
 
 use once_cell::sync::Lazy;
 use rand::{thread_rng, RngCore};
@@ -345,38 +345,26 @@ pub async fn run(
 
     let mut fuzzing_happened = false;
     let mut summaries = vec![];
-    let mut tasks = vec![];
 
     for tests_from_crate in tests {
         let tests_from_crate = Arc::new(tests_from_crate);
         let runner_config = runner_config.clone();
-        let test_crate_type = tests_from_crate.test_crate_type;
-        let number_of_test_cases = tests_from_crate.test_cases.len();
         let runner_params = runner_params.clone();
         let cancellation_tokens = cancellation_tokens.clone();
-        tasks.push((
-            test_crate_type,
-            number_of_test_cases,
-            task::spawn({
-                async move {
-                    run_tests_from_crate(
-                        tests_from_crate,
-                        runner_config,
-                        runner_params,
-                        cancellation_tokens,
-                    )
-                    .await
-                }
-            }),
-        ));
-    }
-    for (test_crate_type, tests_len, task) in tasks {
-        pretty_printing::print_running_tests(test_crate_type, tests_len);
 
-        let (summary, was_fuzzed) = task.await??;
-        for test_case_summary in &summary.test_case_summaries {
-            pretty_printing::print_test_result(test_case_summary);
-        }
+        pretty_printing::print_running_tests(
+            tests_from_crate.test_crate_type,
+            tests_from_crate.test_cases.len(),
+        );
+
+        let (summary, was_fuzzed) = run_tests_from_crate(
+            tests_from_crate,
+            runner_config,
+            runner_params,
+            cancellation_tokens,
+        )
+        .await?;
+
         fuzzing_happened |= was_fuzzed;
         summaries.push(summary.clone());
     }
@@ -406,7 +394,7 @@ async fn run_tests_from_crate(
     );
 
     let mut was_fuzzed = false;
-    let mut tasks = FuturesOrdered::new();
+    let mut tasks = FuturesUnordered::new();
     let test_cases = &tests.test_cases;
 
     for case in test_cases.iter() {
@@ -419,7 +407,7 @@ async fn run_tests_from_crate(
         let args: Vec<ConcreteTypeId> = args.into_iter().cloned().collect();
         let runner = runner.clone();
 
-        tasks.push_back(choose_test_strategy_and_run(
+        tasks.push(choose_test_strategy_and_run(
             args,
             case.clone(),
             runner,
@@ -434,6 +422,8 @@ async fn run_tests_from_crate(
     while let Some(task) = tasks.next().await {
         let result = task??;
 
+        pretty_printing::print_test_result(&result);
+
         if result.runs().is_some() {
             was_fuzzed = true;
         }
@@ -536,7 +526,7 @@ fn run_with_fuzzing(
                 arg.debug_name
                     .as_ref()
                     .ok_or_else(|| anyhow!("Type {arg:?} does not have a debug name"))
-                    .map(smol_str::SmolStr::as_str)
+                    .map(SmolStr::as_str)
             })
             .collect::<Result<Vec<_>>>()?;
 
@@ -623,6 +613,7 @@ fn run_with_fuzzing(
             .clone();
 
         let result = result.with_runs(runs);
+
         Ok(result)
     })
 }

crates/forge/tests/e2e/collection.rs

@@ -1,3 +1,4 @@
+use crate::assert_stdout_contains;
 use assert_fs::fixture::PathCopy;
 use indoc::indoc;
 
@@ -14,11 +15,11 @@ fn collection_with_lib() {
 
     let snapbox = runner();
 
-    snapbox
-        .current_dir(&temp)
-        .assert()
-        .success()
-        .stdout_matches(indoc! {r#"
+    let output = snapbox.current_dir(&temp).assert().success();
+
+    assert_stdout_contains!(
+        output,
+        indoc! {r#"
         [..]Compiling[..]
         [..]Finished[..]
 
@@ -44,7 +45,8 @@ fn collection_with_lib() {
         [PASS] tests::fab::test_fab
         [PASS] tests::fab::fab_mod::test_fab
         Tests: 17 passed, 0 failed, 0 skipped
-        "#});
+        "#}
+    );
 }
 
 #[test]
@@ -58,11 +60,10 @@ fn collection_without_lib() {
 
     let snapbox = runner();
 
-    snapbox
-        .current_dir(&temp)
-        .assert()
-        .success()
-        .stdout_matches(indoc! {r#"
+    let output = snapbox.current_dir(&temp).assert().success();
+    assert_stdout_contains!(
+        output,
+        indoc! {r#"
         [..]Compiling[..]
         [..]Finished[..]
 
@@ -88,5 +89,6 @@ fn collection_without_lib() {
         [PASS] tests::fibfabfob::test_fob
         [PASS] tests::fibfabfob::test_fab
         Tests: 17 passed, 0 failed, 0 skipped
-        "#});
+        "#}
+    );
 }

crates/forge/tests/e2e/common/runner.rs

@@ -1,7 +1,9 @@
+use ark_std::iterable::Iterable;
 use assert_fs::fixture::{FileWriteStr, PathChild, PathCopy};
 use assert_fs::TempDir;
 use camino::Utf8PathBuf;
 use indoc::formatdoc;
+use regex::Regex;
 use snapbox::cmd::{cargo_bin, Command as SnapboxCommand};
 use std::env;
 use std::process::Command;
@@ -205,3 +207,72 @@ pub(crate) fn get_current_branch() -> String {
         String::from_utf8(output.stdout).unwrap().trim().to_string()
     }
 }
+
+pub(crate) fn find_with_wildcard(line: &str, actual: &Vec<String>) -> Option<usize> {
+    let escaped = regex::escape(line);
+    let replaced = escaped.replace("\\[\\.\\.\\]", ".*");
+    let wrapped = format!("^{replaced}$");
+    let re = Regex::new(wrapped.as_str()).unwrap();
+
+    actual.iter().position(|other| re.is_match(other))
+}
+
+pub(crate) fn is_present(line: &str, actual: &mut Vec<String>) -> bool {
+    let position = find_with_wildcard(line, actual);
+    if let Some(position) = position {
+        actual.remove(position);
+        return true;
+    }
+    false
+}
+
+pub(crate) fn assert_output_contains(output: &str, lines: &str) {
+    let asserted_lines: Vec<String> = lines.lines().map(std::convert::Into::into).collect();
+    let mut actual_lines: Vec<String> = output.lines().map(std::convert::Into::into).collect();
+
+    let mut matches = true;
+    let mut out = String::new();
+
+    for line in &asserted_lines {
+        if is_present(line, &mut actual_lines) {
+            out.push_str("| ");
+        } else {
+            matches = false;
+            out.push_str("- ");
+        }
+        out.push_str(line);
+        out.push('\n');
+    }
+    for remaining_line in actual_lines {
+        matches = false;
+        out.push_str("+ ");
+        out.push_str(&remaining_line);
+        out.push('\n');
+    }
+
+    assert!(matches, "Stdout does not match:\n\n{out}");
+}
+
+#[macro_export]
+macro_rules! assert_stdout_contains {
+    ( $output:expr, $lines:expr ) => {{
+        use $crate::e2e::common::runner::assert_output_contains;
+
+        let output = $output.get_output();
+        let stdout = String::from_utf8(output.stdout.clone()).unwrap();
+
+        assert_output_contains(&stdout, $lines);
+    }};
+}
+
+#[macro_export]
+macro_rules! assert_stderr_contains {
+    ( $output:expr, $lines:expr ) => {{
+        use $crate::e2e::common::runner::assert_output_contains;
+
+        let output = $output.get_output();
+        let stderr = String::from_utf8(output.stderr.clone()).unwrap();
+
+        assert_output_contains(&stderr, $lines);
+    }};
+}

crates/forge/tests/e2e/diagnostics_and_plugins.rs

@@ -1,3 +1,4 @@
+use crate::assert_stderr_contains;
 use indoc::indoc;
 
 use crate::e2e::common::runner::{runner, setup_package};
@@ -7,12 +8,10 @@ fn print_error_if_attributes_incorrect() {
     let temp = setup_package("diagnostics_and_plugins");
     let snapbox = runner();
 
-    snapbox
-        .current_dir(&temp)
-        .assert()
-        .code(2)
-        .stderr_matches(indoc!
-        {r#"
+    let output = snapbox.current_dir(&temp).assert().code(2);
+    assert_stderr_contains!(
+        output,
+        indoc! {r#"
             error: Plugin diagnostic: Expected fork config must be of the form `url: <double quote string>, block_id: <snforge_std::BlockId>`.
              --> lib.cairo:2:7
             #[fork(url: "https://lib.com")]
@@ -43,5 +42,6 @@ fn print_error_if_attributes_incorrect() {
             #[should_panic(url: "https://test.com")]
                           ^***********************^
 
-    "#});
+    "#}
+    );
 }

crates/forge/tests/e2e/env.rs

@@ -1,3 +1,4 @@
+use crate::assert_stdout_contains;
 use crate::e2e::common::runner::{runner, setup_package};
 use indoc::indoc;
 
@@ -6,13 +7,15 @@ fn env_var_reading() {
     let temp = setup_package("env");
     let snapbox = runner();
 
-    snapbox
+    let output = snapbox
         .current_dir(&temp)
         .env("FELT_ENV_VAR", "987654321")
         .env("STRING_ENV_VAR", "'abcde'")
         .assert()
-        .code(0)
-        .stdout_matches(indoc! {r#"
+        .code(0);
+    assert_stdout_contains!(
+        output,
+        indoc! {r#"
         [..]Compiling[..]
         [..]Finished[..]
 
@@ -21,5 +24,6 @@ fn env_var_reading() {
         Running 1 test(s) from src/
         [PASS] env::reading_env_vars
         Tests: 1 passed, 0 failed, 0 skipped
-        "#});
+        "#}
+    );
 }

crates/forge/tests/e2e/forking.rs

@@ -1,3 +1,4 @@
+use crate::assert_stdout_contains;
 use crate::e2e::common::runner::{
     runner, setup_package, setup_package_with_file_patterns, BASE_FILE_PATTERNS,
 };
@@ -8,12 +9,14 @@ fn without_cache() {
     let temp = setup_package("forking");
     let snapbox = runner();
 
-    snapbox
+    let output = snapbox
         .current_dir(&temp)
         .args(["--exact", "forking::test_fork_simple"])
         .assert()
-        .code(0)
-        .stdout_matches(indoc! {r#"
+        .code(0);
+    assert_stdout_contains!(
+        output,
+        indoc! {r#"
         [..]Compiling[..]
         [..]Finished[..]
 
@@ -22,7 +25,8 @@ fn without_cache() {
         Running 1 test(s) from src/
         [PASS] forking::test_fork_simple
         Tests: 1 passed, 0 failed, 0 skipped
-        "#});
+        "#}
+    );
 }
 
 #[test]
@@ -37,11 +41,10 @@ fn with_cache() {
     );
     let snapbox = runner();
 
-    snapbox
-        .current_dir(&temp)
-        .assert()
-        .code(1)
-        .stdout_matches(indoc! {r#"
+    let output = snapbox.current_dir(&temp).assert().code(1);
+    assert_stdout_contains!(
+        output,
+        indoc! {r#"
         [..]Compiling[..]
         [..]Finished[..]
 
@@ -57,7 +60,8 @@ fn with_cache() {
 
         Failures:
             forking::test_fork_simple
-        "#});
+        "#}
+    );
 }
 
 #[test]
@@ -68,12 +72,14 @@ fn with_clean_cache() {
     );
     let snapbox = runner();
 
-    snapbox
+    let output = snapbox
         .current_dir(&temp)
         .arg("--clean-cache")
         .assert()
-        .code(0)
-        .stdout_matches(indoc! {r#"
+        .code(0);
+    assert_stdout_contains!(
+        output,
+        indoc! {r#"
         [..]Compiling[..]
         [..]Finished[..]
 
@@ -82,5 +88,6 @@ fn with_clean_cache() {
         Running 1 test(s) from src/
         [PASS] forking::test_fork_simple
         Tests: 1 passed, 0 failed, 0 skipped
-        "#});
+        "#}
+    );
 }