feat: update timed out test counting logic

Since timed out tests can now be treated as either successes or
failures, update the logic for handling them. This commit also adds
tests for exercising edge cases between `on-timeout="pass"` and
retries/flaky tests

Author: eduardorittner

fixture-data/src/nextest_tests.rs

@@ -47,6 +47,10 @@ pub static EXPECTED_TEST_SUITES: LazyLock<IdOrdMap<TestSuiteFixture>> = LazyLock
                     "test_slow_timeout_subprocess",
                     TestCaseFixtureStatus::IgnoredPass,
                 ),
+                TestCaseFixture::new(
+                    "test_flaky_slow_timeout_mod_3",
+                    TestCaseFixtureStatus::IgnoredFail
+                ),
                 TestCaseFixture::new("test_stdin_closed", TestCaseFixtureStatus::Pass),
                 TestCaseFixture::new("test_subprocess_doesnt_exit", TestCaseFixtureStatus::Leak),
                 TestCaseFixture::new("test_subprocess_doesnt_exit_fail", TestCaseFixtureStatus::FailLeak),

fixtures/nextest-tests/.config/nextest.toml

@@ -91,6 +91,19 @@ test-group = '@global'
 [profile.with-timeout-success]
 slow-timeout = { period = "10ms", terminate-after = 2, on-timeout = "pass" }
 
+[[profile.with-timeout-success.overrides]]
+filter = 'test(=test_slow_timeout_2)'
+slow-timeout = { period = "500ms", terminate-after = 2, on-timeout = "fail" }
+test-group = '@global'
+
+[[profile.with-timeout-success.overrides]]
+filter = 'test(=test_slow_timeout_subprocess)'
+slow-timeout = { period = "10ms", terminate-after = 2, on-timeout = "fail" }
+
+[profile.with-timeout-retries-success]
+slow-timeout = { period = "10ms", terminate-after = 2, on-timeout = "pass" }
+retries = 2
+
 [profile.with-junit]
 retries = 2
 

fixtures/nextest-tests/tests/basic.rs

@@ -319,6 +319,17 @@ fn test_slow_timeout_subprocess() {
     cmd.output().unwrap();
 }
 
+#[test]
+#[ignore]
+fn test_flaky_slow_timeout_mod_3() {
+    let nextest_attempt = nextest_attempt();
+    if nextest_attempt % 3 != 0 {
+        panic!("Failed because attempt {} % 3 != 0", nextest_attempt)
+    }
+    // The timeout for the with-timeout-success profile is set to 2 seconds.
+    std::thread::sleep(std::time::Duration::from_secs(4));
+}
+
 #[test]
 fn test_result_failure() -> Result<(), std::io::Error> {
     Err(std::io::Error::new(

nextest-runner/src/config/elements/slow_timeout.rs

@@ -83,11 +83,11 @@ where
 /// The result of controlling slow timeout behavior.
 ///
 /// In most situations a timed out test should be marked failing. However, there are certain
-/// classes of tests which are expected to run indefinetely long, like fuzzing, which explores a
+/// classes of tests which are expected to run indefinitely long, like fuzzing, which explores a
 /// huge state space. For these tests it's nice to be able to treat a timeout as a success since
 /// they generally check for invariants and other properties of the code under test during their
 /// execution. A timeout in this context doesn't mean that there are no failing inputs, it just
-/// means that they weren't foudn up until that moment, which is still valuable information.
+/// means that they weren't found up until that moment, which is still valuable information.
 #[derive(Clone, Copy, Debug, Deserialize, Default, PartialEq, Eq)]
 #[serde(rename_all = "kebab-case")]
 pub enum SlowTimeoutResult {
@@ -204,6 +204,19 @@ mod tests {
 
         ; "timeout result failure"
     )]
+    #[test_case(
+        indoc! {r#"
+            [profile.default]
+            slow-timeout = { period = "60s", on-timeout = "pass" }
+
+            [profile.ci]
+            slow-timeout = { period = "30s", on-timeout = "fail" }
+        "#},
+        Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Pass }),
+        Some(SlowTimeout { period: Duration::from_secs(30), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail })
+
+        ; "override on-timeout option"
+    )]
     #[test_case(
         indoc! {r#"
             [profile.default]

nextest-runner/src/reporter/displayer/imp.rs

@@ -2298,7 +2298,7 @@ fn short_status_str(result: ExecutionResult) -> Cow<'static, str> {
         } => "LKFAIL".into(),
         ExecutionResult::Timeout {
             result: SlowTimeoutResult::Pass,
-        } => "TMTPAS".into(),
+        } => "TMPASS".into(),
         ExecutionResult::Timeout {
             result: SlowTimeoutResult::Fail,
         } => "TMT".into(),

nextest-runner/src/reporter/displayer/snapshots/nextest_runner__reporter__displayer__progress__tests__one_timed_out_success_one_failure_with_cancel_reason.snap

@@ -0,0 +1,5 @@
+---
+source: nextest-runner/src/reporter/displayer/progress.rs
+expression: s
+---
+  Cancelling [ 34:17:36] 10/20: 10 running, 0 passed, 1 timed out, 0 skipped

nextest-runner/src/reporter/displayer/snapshots/nextest_runner__reporter__displayer__progress__tests__one_timed_out_success_one_failure_without_cancel_reason.snap

@@ -0,0 +1,5 @@
+---
+source: nextest-runner/src/reporter/displayer/progress.rs
+expression: s
+---
+     Running [ 34:17:36] 10/20: 10 running, 0 passed, 1 timed out, 0 skipped

nextest-runner/src/reporter/events.rs

@@ -534,7 +534,7 @@ pub struct RunStats {
     /// The number of tests that passed on retry.
     pub flaky: usize,
 
-    /// The number of tests that failed.
+    /// The number of tests that failed. Includes `leaky_failed`.
     pub failed: usize,
 
     /// The number of failed tests that were slow.
@@ -701,7 +701,20 @@ impl RunStats {
                     self.failed_slow += 1;
                 }
             }
-            ExecutionResult::Timeout { .. } => self.failed_timed_out += 1,
+            ExecutionResult::Timeout {
+                result: SlowTimeoutResult::Pass,
+            } => {
+                self.passed += 1;
+                self.passed_timed_out += 1;
+                if run_statuses.len() > 1 {
+                    self.flaky += 1;
+                }
+            }
+            ExecutionResult::Timeout {
+                result: SlowTimeoutResult::Fail,
+            } => {
+                self.failed_timed_out += 1;
+            }
             ExecutionResult::ExecFail => self.exec_failed += 1,
         }
     }
@@ -1597,7 +1610,18 @@ mod tests {
                 initial_run_count: 42,
                 not_run: 0
             }),
-            "timed out => failure"
+            "timed out => failure {:?} {:?}",
+            RunStats {
+                initial_run_count: 42,
+                finished_count: 42,
+                failed_timed_out: 1,
+                ..RunStats::default()
+            }
+            .summarize_final(),
+            FinalRunStats::Failed(RunStatsFailureKind::Test {
+                initial_run_count: 42,
+                not_run: 0
+            }),
         );
         assert_eq!(
             RunStats {