Skip to content

Commit 0c34d2b

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 95e058f commit 0c34d2b

File tree

13 files changed

+205
-45
lines changed

13 files changed

+205
-45
lines changed

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

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

88+
[profile.with-timeout-success]
89+
slow-timeout = { period = "10ms", terminate-after = 2, on-timeout = "pass" }
90+
8891
[profile.with-junit]
8992
retries = 2
9093

‎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: 53 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::default(),
6468
}))
6569
}
6670
}
@@ -76,6 +80,26 @@ where
7680
deserializer.deserialize_any(V)
7781
}
7882

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

88112
#[test_case(
89113
"",
90-
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: None, grace_period: Duration::from_secs(10) }),
114+
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail }),
91115
None
92116
93117
; "empty config is expected to use the hardcoded values"
@@ -97,7 +121,7 @@ mod tests {
97121
[profile.default]
98122
slow-timeout = "30s"
99123
"#},
100-
Ok(SlowTimeout { period: Duration::from_secs(30), terminate_after: None, grace_period: Duration::from_secs(10) }),
124+
Ok(SlowTimeout { period: Duration::from_secs(30), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail }),
101125
None
102126
103127
; "overrides the default profile"
@@ -110,8 +134,8 @@ mod tests {
110134
[profile.ci]
111135
slow-timeout = { period = "60s", terminate-after = 3 }
112136
"#},
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) })
137+
Ok(SlowTimeout { period: Duration::from_secs(30), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail }),
138+
Some(SlowTimeout { period: Duration::from_secs(60), terminate_after: Some(NonZeroUsize::new(3).unwrap()), grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail })
115139
116140
; "adds a custom profile 'ci'"
117141
)]
@@ -123,8 +147,8 @@ mod tests {
123147
[profile.ci]
124148
slow-timeout = "30s"
125149
"#},
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) })
150+
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: Some(NonZeroUsize::new(3).unwrap()), grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail }),
151+
Some(SlowTimeout { period: Duration::from_secs(30), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail })
128152
129153
; "ci profile uses string notation"
130154
)]
@@ -136,8 +160,8 @@ mod tests {
136160
[profile.ci]
137161
slow-timeout = "30s"
138162
"#},
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) })
163+
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: Some(NonZeroUsize::new(3).unwrap()), grace_period: Duration::from_secs(1), on_timeout: SlowTimeoutResult::Fail }),
164+
Some(SlowTimeout { period: Duration::from_secs(30), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail })
141165
142166
; "timeout grace period"
143167
)]
@@ -146,7 +170,7 @@ mod tests {
146170
[profile.default]
147171
slow-timeout = { period = "60s" }
148172
"#},
149-
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: None, grace_period: Duration::from_secs(10) }),
173+
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail }),
150174
None
151175
152176
; "partial table"
@@ -161,6 +185,26 @@ mod tests {
161185
162186
; "zero terminate-after should fail"
163187
)]
188+
#[test_case(
189+
indoc! {r#"
190+
[profile.default]
191+
slow-timeout = { period = "60s", on-timeout = "pass" }
192+
"#},
193+
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Pass }),
194+
None
195+
196+
; "timeout result success"
197+
)]
198+
#[test_case(
199+
indoc! {r#"
200+
[profile.default]
201+
slow-timeout = { period = "60s", on-timeout = "fail" }
202+
"#},
203+
Ok(SlowTimeout { period: Duration::from_secs(60), terminate_after: None, grace_period: Duration::from_secs(10), on_timeout: SlowTimeoutResult::Fail }),
204+
None
205+
206+
; "timeout result failure"
207+
)]
164208
#[test_case(
165209
indoc! {r#"
166210
[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: 10 additions & 2 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},
@@ -340,7 +340,15 @@ fn non_success_kind_and_type(kind: UnitKind, result: ExecutionResult) -> (NonSuc
340340
NonSuccessKind::Failure,
341341
format!("{kind} failure with exit code {code}"),
342342
),
343-
ExecutionResult::Timeout => (NonSuccessKind::Failure, format!("{kind} timeout")),
343+
ExecutionResult::Timeout {
344+
result: SlowTimeoutResult::Fail,
345+
} => (NonSuccessKind::Failure, format!("{kind} timeout")),
346+
ExecutionResult::Timeout {
347+
result: SlowTimeoutResult::Pass,
348+
} => (
349+
NonSuccessKind::Failure,
350+
format!("{kind} passed but timed out"),
351+
),
344352
ExecutionResult::ExecFail => (NonSuccessKind::Error, "execution failure".to_owned()),
345353
ExecutionResult::Leak {
346354
result: LeakTimeoutResult::Pass,

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

Lines changed: 34 additions & 9 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,
@@ -1906,7 +1910,14 @@ impl<'a> DisplayReporterImpl<'a> {
19061910
"{}: exited with code 0, but leaked handles",
19071911
"failed".style(self.styles.fail),
19081912
),
1909-
Some(ExecutionResult::Timeout) => {
1913+
Some(ExecutionResult::Timeout {
1914+
result: SlowTimeoutResult::Pass,
1915+
}) => {
1916+
write!(writer, "{}", "passed with timeout".style(self.styles.skip))
1917+
}
1918+
Some(ExecutionResult::Timeout {
1919+
result: SlowTimeoutResult::Fail,
1920+
}) => {
19101921
write!(writer, "{}", "timed out".style(self.styles.fail))
19111922
}
19121923
Some(ExecutionResult::Fail {
@@ -2173,7 +2184,7 @@ fn show_finished_status_info_line(result: ExecutionResult) -> bool {
21732184
// again.
21742185
false
21752186
}
2176-
ExecutionResult::Timeout => {
2187+
ExecutionResult::Timeout { .. } => {
21772188
// Show this to be clear what happened.
21782189
true
21792190
}
@@ -2218,7 +2229,12 @@ fn status_str(result: ExecutionResult) -> Cow<'static, str> {
22182229
ExecutionResult::Leak {
22192230
result: LeakTimeoutResult::Fail,
22202231
} => "LEAK-FAIL".into(),
2221-
ExecutionResult::Timeout => "TIMEOUT".into(),
2232+
ExecutionResult::Timeout {
2233+
result: SlowTimeoutResult::Pass,
2234+
} => "TIMEOUT-PASS".into(),
2235+
ExecutionResult::Timeout {
2236+
result: SlowTimeoutResult::Fail,
2237+
} => "TIMEOUT".into(),
22222238
}
22232239
}
22242240

@@ -2256,7 +2272,12 @@ fn short_status_str(result: ExecutionResult) -> Cow<'static, str> {
22562272
ExecutionResult::Leak {
22572273
result: LeakTimeoutResult::Fail,
22582274
} => "LKFAIL".into(),
2259-
ExecutionResult::Timeout => "TMT".into(),
2275+
ExecutionResult::Timeout {
2276+
result: SlowTimeoutResult::Pass,
2277+
} => "TMPASS".into(),
2278+
ExecutionResult::Timeout {
2279+
result: SlowTimeoutResult::Fail,
2280+
} => "TMT".into(),
22602281
}
22612282
}
22622283

@@ -2507,10 +2528,11 @@ mod tests {
25072528
setup_scripts_timed_out: 0,
25082529
passed: 5,
25092530
passed_slow: 0,
2531+
passed_timed_out: 0,
25102532
flaky: 0,
25112533
failed: 0,
25122534
failed_slow: 0,
2513-
timed_out: 0,
2535+
failed_timed_out: 0,
25142536
leaky: 0,
25152537
leaky_failed: 0,
25162538
exec_failed: 0,
@@ -2543,10 +2565,11 @@ mod tests {
25432565
setup_scripts_timed_out: 0,
25442566
passed: 5,
25452567
passed_slow: 1,
2568+
passed_timed_out: 2,
25462569
flaky: 1,
25472570
failed: 2,
25482571
failed_slow: 0,
2549-
timed_out: 1,
2572+
failed_timed_out: 1,
25502573
leaky: 1,
25512574
leaky_failed: 0,
25522575
exec_failed: 1,
@@ -2630,10 +2653,11 @@ mod tests {
26302653
setup_scripts_timed_out: 0,
26312654
passed: 0,
26322655
passed_slow: 0,
2656+
passed_timed_out: 0,
26332657
flaky: 0,
26342658
failed: 0,
26352659
failed_slow: 0,
2636-
timed_out: 0,
2660+
failed_timed_out: 0,
26372661
leaky: 0,
26382662
leaky_failed: 0,
26392663
exec_failed: 0,
@@ -2693,10 +2717,11 @@ mod tests {
26932717
setup_scripts_timed_out: 0,
26942718
passed: 17,
26952719
passed_slow: 4,
2720+
passed_timed_out: 3,
26962721
flaky: 2,
26972722
failed: 2,
26982723
failed_slow: 1,
2699-
timed_out: 1,
2724+
failed_timed_out: 1,
27002725
leaky: 1,
27012726
leaky_failed: 2,
27022727
exec_failed: 1,

0 commit comments

Comments
 (0)