Skip to content

Commit 7bd3aec

Browse files
eduardorittnereduardorittner
committed
feat: treat timeouts as failure or success based on config
Adds a new configuration option inside "slow-timeout": "on-timeout" which when set to "pass" makes nextest treat timed out tests as passing. The logic for actually counting how many timed out tests were treated as successes will be made in a followup commit.
1 parent 8832117 commit 7bd3aec

File tree

13 files changed

+221
-48
lines changed

13 files changed

+221
-48
lines changed

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

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -88,6 +88,9 @@ filter = 'test(=test_slow_timeout_2)'
8888
slow-timeout = { period = "500ms", terminate-after = 2 }
8989
test-group = '@global'
9090

91+
[profile.with-timeout-success]
92+
slow-timeout = { period = "10ms", terminate-after = 2, on-timeout = "pass" }
93+
9194
[profile.with-junit]
9295
retries = 2
9396

‎nextest-runner/default-config.toml‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -88,7 +88,11 @@ fail-fast = true
8888
# which will cause slow tests to be terminated after the specified number of
8989
# periods have passed.
9090
# Example: slow-timeout = { period = "60s", terminate-after = 2 }
91-
slow-timeout = { period = "60s" }
91+
#
92+
# The 'on-timeout' parameter controls whether timeouts are treated as failures (the default)
93+
# or successes.
94+
# Example: slow-timeout = { period = "60s", on-timeout = "pass" }
95+
slow-timeout = { period = "60s", on-timeout = "fail" }
9296

9397
# Treat a test as leaky if after the process is shut down, standard output and standard error
9498
# aren't closed within this duration.

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

Lines changed: 52 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,8 @@ pub struct SlowTimeout {
1515
pub(crate) terminate_after: Option<NonZeroUsize>,
1616
#[serde(with = "humantime_serde", default = "default_grace_period")]
1717
pub(crate) grace_period: Duration,
18+
#[serde(default)]
19+
pub(crate) on_timeout: SlowTimeoutResult,
1820
}
1921

2022
impl SlowTimeout {
@@ -24,6 +26,7 @@ impl SlowTimeout {
2426
period: far_future_duration(),
2527
terminate_after: None,
2628
grace_period: Duration::from_secs(10),
29+
on_timeout: SlowTimeoutResult::Fail,
2730
};
2831
}
2932

@@ -61,6 +64,7 @@ where
6164
period,
6265
terminate_after: None,
6366
grace_period: default_grace_period(),
67+
on_timeout: SlowTimeoutResult::Fail,
6468
}))
6569
}
6670
}
@@ -76,6 +80,25 @@ where
7680
deserializer.deserialize_any(V)
7781
}
7882

83+
/// The result of controlling slow timeout behavior.
84+
///
85+
/// In most situations a timed out test should be marked failing. However, there are certain
86+
/// classes of tests which are expected to run indefinitely long, like fuzzing, which explores a
87+
/// huge state space. For these tests it's nice to be able to treat a timeout as a success since
88+
/// they generally check for invariants and other properties of the code under test during their
89+
/// execution. A timeout in this context doesn't mean that there are no failing inputs, it just
90+
/// means that they weren't found up until that moment, which is still valuable information.
91+
#[derive(Clone, Copy, Debug, Deserialize, Default, PartialEq, Eq)]
92+
#[serde(rename_all = "kebab-case")]
93+
pub enum SlowTimeoutResult {
94+
#[default]
95+
/// The test is marked as failed.
96+
Fail,
97+
98+
/// The test is marked as passed.
99+
Pass,
100+
}
101+
79102
#[cfg(test)]
80103
mod tests {
81104
use super::*;
@@ -87,7 +110,7 @@ mod tests {
87110

88111
#[test_case(
89112
"",
90-
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: None, grace_period: Duration::from_secs(10) }),
113+
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail }),
91114
None
92115
93116
; "empty config is expected to use the hardcoded values"
@@ -97,7 +120,7 @@ mod tests {
97120
[profile.default]
98121
slow-timeout = "30s"
99122
"#},
100-
Ok(SlowTimeout { period: Duration::from_secs(30), terminate_after: None, grace_period: Duration::from_secs(10) }),
123+
Ok(SlowTimeout { period: Duration::from_secs(30), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail }),
101124
None
102125
103126
; "overrides the default profile"
@@ -110,8 +133,8 @@ mod tests {
110133
[profile.ci]
111134
slow-timeout = { period = "60s", terminate-after = 3 }
112135
"#},
113-
Ok(SlowTimeout { period: Duration::from_secs(30), terminate_after: None, grace_period: Duration::from_secs(10) }),
114-
Some(SlowTimeout { period: Duration::from_secs(60), terminate_after: Some(NonZeroUsize::new(3).unwrap()), grace_period: Duration::from_secs(10) })
136+
Ok(SlowTimeout { period: Duration::from_secs(30), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail }),
137+
Some(SlowTimeout { period: Duration::from_secs(60), terminate_after: Some(NonZeroUsize::new(3).unwrap()), grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail })
115138
116139
; "adds a custom profile 'ci'"
117140
)]
@@ -123,8 +146,8 @@ mod tests {
123146
[profile.ci]
124147
slow-timeout = "30s"
125148
"#},
126-
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: Some(NonZeroUsize::new(3).unwrap()), grace_period: Duration::from_secs(10) }),
127-
Some(SlowTimeout { period: Duration::from_secs(30), terminate_after: None, grace_period: Duration::from_secs(10) })
149+
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: Some(NonZeroUsize::new(3).unwrap()), grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail }),
150+
Some(SlowTimeout { period: Duration::from_secs(30), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail })
128151
129152
; "ci profile uses string notation"
130153
)]
@@ -136,8 +159,8 @@ mod tests {
136159
[profile.ci]
137160
slow-timeout = "30s"
138161
"#},
139-
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: Some(NonZeroUsize::new(3).unwrap()), grace_period: Duration::from_secs(1) }),
140-
Some(SlowTimeout { period: Duration::from_secs(30), terminate_after: None, grace_period: Duration::from_secs(10) })
162+
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: Some(NonZeroUsize::new(3).unwrap()), grace_period: Duration::from_secs(1), on_timeout: SlowTimeoutResult::Fail }),
163+
Some(SlowTimeout { period: Duration::from_secs(30), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail })
141164
142165
; "timeout grace period"
143166
)]
@@ -146,7 +169,7 @@ mod tests {
146169
[profile.default]
147170
slow-timeout = { period = "60s" }
148171
"#},
149-
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: None, grace_period: Duration::from_secs(10) }),
172+
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail }),
150173
None
151174
152175
; "partial table"
@@ -161,6 +184,26 @@ mod tests {
161184
162185
; "zero terminate-after should fail"
163186
)]
187+
#[test_case(
188+
indoc! {r#"
189+
[profile.default]
190+
slow-timeout = { period = "60s", on-timeout = "pass" }
191+
"#},
192+
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Pass }),
193+
None
194+
195+
; "timeout result success"
196+
)]
197+
#[test_case(
198+
indoc! {r#"
199+
[profile.default]
200+
slow-timeout = { period = "60s", on-timeout = "fail" }
201+
"#},
202+
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail }),
203+
None
204+
205+
; "timeout result failure"
206+
)]
164207
#[test_case(
165208
indoc! {r#"
166209
[profile.default]

‎nextest-runner/src/config/overrides/imp.rs‎

Lines changed: 28 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1019,7 +1019,11 @@ impl<'de> Deserialize<'de> for PlatformStrings {
10191019
#[cfg(test)]
10201020
mod tests {
10211021
use super::*;
1022-
use crate::config::{core::NextestConfig, elements::LeakTimeoutResult, utils::test_helpers::*};
1022+
use crate::config::{
1023+
core::NextestConfig,
1024+
elements::{LeakTimeoutResult, SlowTimeoutResult},
1025+
utils::test_helpers::*,
1026+
};
10231027
use camino_tempfile::tempdir;
10241028
use indoc::indoc;
10251029
use std::{num::NonZeroUsize, time::Duration};
@@ -1066,6 +1070,11 @@ mod tests {
10661070
filter = "test(override5)"
10671071
retries = 8
10681072
1073+
# Override 6 -- timeout result success
1074+
[[profile.default.overrides]]
1075+
filter = "test(timeout_success)"
1076+
slow-timeout = { period = "30s", on-timeout = "pass" }
1077+
10691078
[profile.default.junit]
10701079
path = "my-path.xml"
10711080
@@ -1108,6 +1117,7 @@ mod tests {
11081117
overrides.slow_timeout(),
11091118
SlowTimeout {
11101119
period: Duration::from_secs(60),
1120+
on_timeout: SlowTimeoutResult::default(),
11111121
terminate_after: None,
11121122
grace_period: Duration::from_secs(10),
11131123
}
@@ -1159,6 +1169,7 @@ mod tests {
11591169
period: Duration::from_secs(120),
11601170
terminate_after: Some(NonZeroUsize::new(1).unwrap()),
11611171
grace_period: Duration::ZERO,
1172+
on_timeout: SlowTimeoutResult::default(),
11621173
}
11631174
);
11641175
assert_eq!(
@@ -1197,6 +1208,22 @@ mod tests {
11971208
let overrides = profile.settings_for(&query);
11981209
assert_eq!(overrides.retries(), RetryPolicy::new_without_delay(8));
11991210

1211+
// This query matches override 6.
1212+
let query = TestQuery {
1213+
binary_query: target_binary_query.to_query(),
1214+
test_name: "timeout_success",
1215+
};
1216+
let overrides = profile.settings_for(&query);
1217+
assert_eq!(
1218+
overrides.slow_timeout(),
1219+
SlowTimeout {
1220+
period: Duration::from_secs(30),
1221+
on_timeout: SlowTimeoutResult::Pass,
1222+
terminate_after: None,
1223+
grace_period: Duration::from_secs(10),
1224+
}
1225+
);
1226+
12001227
// This query does not match any overrides.
12011228
let query = TestQuery {
12021229
binary_query: target_binary_query.to_query(),

‎nextest-runner/src/reporter/aggregator/junit.rs‎

Lines changed: 8 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -5,7 +5,7 @@
55
66
use crate::{
77
config::{
8-
elements::{JunitConfig, LeakTimeoutResult},
8+
elements::{JunitConfig, LeakTimeoutResult, SlowTimeoutResult},
99
scripts::ScriptId,
1010
},
1111
errors::{DisplayErrorChain, WriteEventError},
@@ -339,7 +339,9 @@ fn non_success_kind_and_type(kind: UnitKind, result: ExecutionResult) -> (NonSuc
339339
NonSuccessKind::Failure,
340340
format!("{kind} failure with exit code {code}"),
341341
),
342-
ExecutionResult::Timeout => (NonSuccessKind::Failure, format!("{kind} timeout")),
342+
ExecutionResult::Timeout {
343+
result: SlowTimeoutResult::Fail,
344+
} => (NonSuccessKind::Failure, format!("{kind} timeout")),
343345
ExecutionResult::ExecFail => (NonSuccessKind::Error, "execution failure".to_owned()),
344346
ExecutionResult::Leak {
345347
result: LeakTimeoutResult::Pass,
@@ -353,7 +355,10 @@ fn non_success_kind_and_type(kind: UnitKind, result: ExecutionResult) -> (NonSuc
353355
NonSuccessKind::Error,
354356
format!("{kind} exited with code 0, but leaked handles so was marked failed"),
355357
),
356-
ExecutionResult::Pass => {
358+
ExecutionResult::Pass
359+
| ExecutionResult::Timeout {
360+
result: SlowTimeoutResult::Pass,
361+
} => {
357362
unreachable!("this is a failure status")
358363
}
359364
}

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

Lines changed: 43 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,11 @@ use super::{
1919
};
2020
use crate::{
2121
cargo_config::CargoConfigs,
22-
config::{elements::LeakTimeoutResult, overrides::CompiledDefaultFilter, scripts::ScriptId},
22+
config::{
23+
elements::{LeakTimeoutResult, SlowTimeoutResult},
24+
overrides::CompiledDefaultFilter,
25+
scripts::ScriptId,
26+
},
2327
errors::WriteEventError,
2428
helpers::{
2529
DisplayCounterIndex, DisplayScriptInstance, DisplayTestInstance, plural,
@@ -787,14 +791,21 @@ impl<'a> DisplayReporterImpl<'a> {
787791
let last_status = run_statuses.last_status();
788792
let test_output_display = match last_status.result {
789793
ExecutionResult::Pass
794+
| ExecutionResult::Timeout {
795+
result: SlowTimeoutResult::Pass,
796+
}
790797
| ExecutionResult::Leak {
791798
result: LeakTimeoutResult::Pass,
792799
} => self.unit_output.success_output(*success_output),
793800
ExecutionResult::Leak {
794801
result: LeakTimeoutResult::Fail,
795802
}
796-
| ExecutionResult::Fail { .. }
797-
| ExecutionResult::Timeout => self.unit_output.failure_output(*failure_output),
803+
| ExecutionResult::Timeout {
804+
result: SlowTimeoutResult::Fail,
805+
}
806+
| ExecutionResult::Fail { .. } => {
807+
self.unit_output.failure_output(*failure_output)
808+
}
798809
ExecutionResult::ExecFail => self.unit_output.exec_fail_output(*failure_output),
799810
};
800811

@@ -1923,7 +1934,14 @@ impl<'a> DisplayReporterImpl<'a> {
19231934
"{}: exited with code 0, but leaked handles",
19241935
"failed".style(self.styles.fail),
19251936
),
1926-
Some(ExecutionResult::Timeout) => {
1937+
Some(ExecutionResult::Timeout {
1938+
result: SlowTimeoutResult::Pass,
1939+
}) => {
1940+
write!(writer, "{}", "passed with timeout".style(self.styles.skip))
1941+
}
1942+
Some(ExecutionResult::Timeout {
1943+
result: SlowTimeoutResult::Fail,
1944+
}) => {
19271945
write!(writer, "{}", "timed out".style(self.styles.fail))
19281946
}
19291947
Some(ExecutionResult::Fail {
@@ -2190,7 +2208,7 @@ fn show_finished_status_info_line(result: ExecutionResult) -> bool {
21902208
// again.
21912209
false
21922210
}
2193-
ExecutionResult::Timeout => {
2211+
ExecutionResult::Timeout { .. } => {
21942212
// Show this to be clear what happened.
21952213
true
21962214
}
@@ -2235,7 +2253,12 @@ fn status_str(result: ExecutionResult) -> Cow<'static, str> {
22352253
ExecutionResult::Leak {
22362254
result: LeakTimeoutResult::Fail,
22372255
} => "LEAK-FAIL".into(),
2238-
ExecutionResult::Timeout => "TIMEOUT".into(),
2256+
ExecutionResult::Timeout {
2257+
result: SlowTimeoutResult::Pass,
2258+
} => "TIMEOUT-PASS".into(),
2259+
ExecutionResult::Timeout {
2260+
result: SlowTimeoutResult::Fail,
2261+
} => "TIMEOUT".into(),
22392262
}
22402263
}
22412264

@@ -2273,7 +2296,12 @@ fn short_status_str(result: ExecutionResult) -> Cow<'static, str> {
22732296
ExecutionResult::Leak {
22742297
result: LeakTimeoutResult::Fail,
22752298
} => "LKFAIL".into(),
2276-
ExecutionResult::Timeout => "TMT".into(),
2299+
ExecutionResult::Timeout {
2300+
result: SlowTimeoutResult::Pass,
2301+
} => "TMPASS".into(),
2302+
ExecutionResult::Timeout {
2303+
result: SlowTimeoutResult::Fail,
2304+
} => "TMT".into(),
22772305
}
22782306
}
22792307

@@ -2521,10 +2549,11 @@ mod tests {
25212549
setup_scripts_timed_out: 0,
25222550
passed: 5,
25232551
passed_slow: 0,
2552+
passed_timed_out: 0,
25242553
flaky: 0,
25252554
failed: 0,
25262555
failed_slow: 0,
2527-
timed_out: 0,
2556+
failed_timed_out: 0,
25282557
leaky: 0,
25292558
leaky_failed: 0,
25302559
exec_failed: 0,
@@ -2557,10 +2586,11 @@ mod tests {
25572586
setup_scripts_timed_out: 0,
25582587
passed: 5,
25592588
passed_slow: 1,
2589+
passed_timed_out: 2,
25602590
flaky: 1,
25612591
failed: 2,
25622592
failed_slow: 0,
2563-
timed_out: 1,
2593+
failed_timed_out: 1,
25642594
leaky: 1,
25652595
leaky_failed: 0,
25662596
exec_failed: 1,
@@ -2644,10 +2674,11 @@ mod tests {
26442674
setup_scripts_timed_out: 0,
26452675
passed: 0,
26462676
passed_slow: 0,
2677+
passed_timed_out: 0,
26472678
flaky: 0,
26482679
failed: 0,
26492680
failed_slow: 0,
2650-
timed_out: 0,
2681+
failed_timed_out: 0,
26512682
leaky: 0,
26522683
leaky_failed: 0,
26532684
exec_failed: 0,
@@ -2704,10 +2735,11 @@ mod tests {
27042735
setup_scripts_timed_out: 0,
27052736
passed: 17,
27062737
passed_slow: 4,
2738+
passed_timed_out: 3,
27072739
flaky: 2,
27082740
failed: 2,
27092741
failed_slow: 1,
2710-
timed_out: 1,
2742+
failed_timed_out: 1,
27112743
leaky: 1,
27122744
leaky_failed: 2,
27132745
exec_failed: 1,

0 commit comments

Comments
 (0)