Skip to content

Commit 97e4159

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 342aa17 commit 97e4159

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},
@@ -339,7 +339,15 @@ 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")),
345+
ExecutionResult::Timeout {
346+
result: SlowTimeoutResult::Pass,
347+
} => (
348+
NonSuccessKind::Failure,
349+
format!("{kind} passed but timed out"),
350+
),
343351
ExecutionResult::ExecFail => (NonSuccessKind::Error, "execution failure".to_owned()),
344352
ExecutionResult::Leak {
345353
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

@@ -2504,10 +2525,11 @@ mod tests {
25042525
setup_scripts_timed_out: 0,
25052526
passed: 5,
25062527
passed_slow: 0,
2528+
passed_timed_out: 0,
25072529
flaky: 0,
25082530
failed: 0,
25092531
failed_slow: 0,
2510-
timed_out: 0,
2532+
failed_timed_out: 0,
25112533
leaky: 0,
25122534
leaky_failed: 0,
25132535
exec_failed: 0,
@@ -2540,10 +2562,11 @@ mod tests {
25402562
setup_scripts_timed_out: 0,
25412563
passed: 5,
25422564
passed_slow: 1,
2565+
passed_timed_out: 2,
25432566
flaky: 1,
25442567
failed: 2,
25452568
failed_slow: 0,
2546-
timed_out: 1,
2569+
failed_timed_out: 1,
25472570
leaky: 1,
25482571
leaky_failed: 0,
25492572
exec_failed: 1,
@@ -2627,10 +2650,11 @@ mod tests {
26272650
setup_scripts_timed_out: 0,
26282651
passed: 0,
26292652
passed_slow: 0,
2653+
passed_timed_out: 0,
26302654
flaky: 0,
26312655
failed: 0,
26322656
failed_slow: 0,
2633-
timed_out: 0,
2657+
failed_timed_out: 0,
26342658
leaky: 0,
26352659
leaky_failed: 0,
26362660
exec_failed: 0,
@@ -2687,10 +2711,11 @@ mod tests {
26872711
setup_scripts_timed_out: 0,
26882712
passed: 17,
26892713
passed_slow: 4,
2714+
passed_timed_out: 3,
26902715
flaky: 2,
26912716
failed: 2,
26922717
failed_slow: 1,
2693-
timed_out: 1,
2718+
failed_timed_out: 1,
26942719
leaky: 1,
26952720
leaky_failed: 2,
26962721
exec_failed: 1,

0 commit comments

Comments
 (0)