Skip to content

Commit 23f631c

Browse files
m-ou-sem-ou-se
authored
Rollup merge of rust-lang#75752 - jakoschiko:test-suite-time, r=m-ou-se
libtest: Print the total time taken to execute a test suite Print the total time taken to execute a test suite by default, without any kind of flag. Closes rust-lang#75660 # Example ``` anon@anon:~/code/rust/example$ cargo test Compiling example v0.1.0 (/home/anon/code/rust/example) Finished test [unoptimized + debuginfo] target(s) in 0.18s Running target/debug/deps/example-745b64d3885c3565 running 3 tests test tests::foo ... ok test tests::bar ... ok test tests::baz ... ok test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; 1.2s Doc-tests example running 3 tests test src/lib.rs - foo (line 3) ... ok test src/lib.rs - bar (line 11) ... ok test src/lib.rs - baz (line 19) ... ok test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; 1.3s ``` ``` anon@anon:~/code/rust/example$ cargo test -- --format terse Finished test [unoptimized + debuginfo] target(s) in 0.08s Running target/debug/deps/example-745b64d3885c3565 running 3 tests ... test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; 1.2s Doc-tests example running 3 tests ... test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; 1.3s ``` ``` anon@anon:~/code/rust/example$ cargo test -- --format json -Z unstable-options Compiling example v0.1.0 (/home/anon/code/rust/example) Finished test [unoptimized + debuginfo] target(s) in 0.25s Running target/debug/deps/example-745b64d3885c3565 { "type": "suite", "event": "started", "test_count": 3 } { "type": "test", "event": "started", "name": "tests::bar" } { "type": "test", "event": "started", "name": "tests::baz" } { "type": "test", "event": "started", "name": "tests::foo" } { "type": "test", "name": "tests::foo", "event": "ok" } { "type": "test", "name": "tests::bar", "event": "ok" } { "type": "test", "name": "tests::baz", "event": "ok" } { "type": "suite", "event": "ok", "passed": 3, "failed": 0, "allowed_fail": 0, "ignored": 0, "measured": 0, "filtered_out": 0, "exec_time": "1.2s" } Doc-tests example { "type": "suite", "event": "started", "test_count": 3 } { "type": "test", "event": "started", "name": "src/lib.rs - bar (line 11)" } { "type": "test", "event": "started", "name": "src/lib.rs - baz (line 19)" } { "type": "test", "event": "started", "name": "src/lib.rs - foo (line 3)" } { "type": "test", "name": "src/lib.rs - foo (line 3)", "event": "ok" } { "type": "test", "name": "src/lib.rs - bar (line 11)", "event": "ok" } { "type": "test", "name": "src/lib.rs - baz (line 19)", "event": "ok" } { "type": "suite", "event": "ok", "passed": 3, "failed": 0, "allowed_fail": 0, "ignored": 0, "measured": 0, "filtered_out": 0, "exec_time": "1.3s" } ```
2 parents 52e3cf1 + 46993ef commit 23f631c

Some content is hidden

Large Commits have some content hidden by default. Use the searchbox below for content that may be hidden.

41 files changed

+146
-64
lines changed

‎library/test/src/console.rs

+9-1
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@
33
use std::fs::File;
44
use std::io;
55
use std::io::prelude::Write;
6+
use std::time::Instant;
67

78
use super::{
89
bench::fmt_bench_samples,
@@ -14,7 +15,7 @@ use super::{
1415
options::{Options, OutputFormat},
1516
run_tests,
1617
test_result::TestResult,
17-
time::TestExecTime,
18+
time::{TestExecTime, TestSuiteExecTime},
1819
types::{NamePadding, TestDesc, TestDescAndFn},
1920
};
2021

@@ -49,6 +50,7 @@ pub struct ConsoleTestState {
4950
pub allowed_fail: usize,
5051
pub filtered_out: usize,
5152
pub measured: usize,
53+
pub exec_time: Option<TestSuiteExecTime>,
5254
pub metrics: MetricMap,
5355
pub failures: Vec<(TestDesc, Vec<u8>)>,
5456
pub not_failures: Vec<(TestDesc, Vec<u8>)>,
@@ -72,6 +74,7 @@ impl ConsoleTestState {
7274
allowed_fail: 0,
7375
filtered_out: 0,
7476
measured: 0,
77+
exec_time: None,
7578
metrics: MetricMap::new(),
7679
failures: Vec::new(),
7780
not_failures: Vec::new(),
@@ -277,7 +280,12 @@ pub fn run_tests_console(opts: &TestOpts, tests: Vec<TestDescAndFn>) -> io::Resu
277280
};
278281
let mut st = ConsoleTestState::new(opts)?;
279282

283+
// `Instant` is currently not supported for wasm targets
284+
let is_instant_supported = !cfg!(target_arch = "wasm32");
285+
286+
let start_time = is_instant_supported.then(Instant::now);
280287
run_tests(opts, tests, |x| on_test_event(&x, &mut st, &mut *out))?;
288+
st.exec_time = start_time.map(|t| TestSuiteExecTime(t.elapsed()));
281289

282290
assert!(st.current_test_count() == st.total);
283291

‎library/test/src/formatters/json.rs

+11-4
Original file line numberDiff line numberDiff line change
@@ -47,7 +47,7 @@ impl<T: Write> JsonFormatter<T> {
4747
evt
4848
))?;
4949
if let Some(exec_time) = exec_time {
50-
self.write_message(&*format!(r#", "exec_time": "{}""#, exec_time))?;
50+
self.write_message(&*format!(r#", "exec_time": {}"#, exec_time.0.as_secs_f64()))?;
5151
}
5252
if let Some(stdout) = stdout {
5353
self.write_message(&*format!(r#", "stdout": "{}""#, EscapedString(stdout)))?;
@@ -162,24 +162,31 @@ impl<T: Write> OutputFormatter for JsonFormatter<T> {
162162
}
163163

164164
fn write_run_finish(&mut self, state: &ConsoleTestState) -> io::Result<bool> {
165-
self.writeln_message(&*format!(
165+
self.write_message(&*format!(
166166
"{{ \"type\": \"suite\", \
167167
\"event\": \"{}\", \
168168
\"passed\": {}, \
169169
\"failed\": {}, \
170170
\"allowed_fail\": {}, \
171171
\"ignored\": {}, \
172172
\"measured\": {}, \
173-
\"filtered_out\": {} }}",
173+
\"filtered_out\": {}",
174174
if state.failed == 0 { "ok" } else { "failed" },
175175
state.passed,
176176
state.failed + state.allowed_fail,
177177
state.allowed_fail,
178178
state.ignored,
179179
state.measured,
180-
state.filtered_out
180+
state.filtered_out,
181181
))?;
182182

183+
if let Some(ref exec_time) = state.exec_time {
184+
let time_str = format!(", \"exec_time\": {}", exec_time.0.as_secs_f64());
185+
self.write_message(&time_str)?;
186+
}
187+
188+
self.writeln_message(" }")?;
189+
183190
Ok(state.failed == 0)
184191
}
185192
}

‎library/test/src/formatters/pretty.rs

+9-2
Original file line numberDiff line numberDiff line change
@@ -259,7 +259,7 @@ impl<T: Write> OutputFormatter for PrettyFormatter<T> {
259259

260260
let s = if state.allowed_fail > 0 {
261261
format!(
262-
". {} passed; {} failed ({} allowed); {} ignored; {} measured; {} filtered out\n\n",
262+
". {} passed; {} failed ({} allowed); {} ignored; {} measured; {} filtered out",
263263
state.passed,
264264
state.failed + state.allowed_fail,
265265
state.allowed_fail,
@@ -269,13 +269,20 @@ impl<T: Write> OutputFormatter for PrettyFormatter<T> {
269269
)
270270
} else {
271271
format!(
272-
". {} passed; {} failed; {} ignored; {} measured; {} filtered out\n\n",
272+
". {} passed; {} failed; {} ignored; {} measured; {} filtered out",
273273
state.passed, state.failed, state.ignored, state.measured, state.filtered_out
274274
)
275275
};
276276

277277
self.write_plain(&s)?;
278278

279+
if let Some(ref exec_time) = state.exec_time {
280+
let time_str = format!("; finished in {}", exec_time);
281+
self.write_plain(&time_str)?;
282+
}
283+
284+
self.write_plain("\n\n")?;
285+
279286
Ok(success)
280287
}
281288
}

‎library/test/src/formatters/terse.rs

+9-2
Original file line numberDiff line numberDiff line change
@@ -236,7 +236,7 @@ impl<T: Write> OutputFormatter for TerseFormatter<T> {
236236

237237
let s = if state.allowed_fail > 0 {
238238
format!(
239-
". {} passed; {} failed ({} allowed); {} ignored; {} measured; {} filtered out\n\n",
239+
". {} passed; {} failed ({} allowed); {} ignored; {} measured; {} filtered out",
240240
state.passed,
241241
state.failed + state.allowed_fail,
242242
state.allowed_fail,
@@ -246,13 +246,20 @@ impl<T: Write> OutputFormatter for TerseFormatter<T> {
246246
)
247247
} else {
248248
format!(
249-
". {} passed; {} failed; {} ignored; {} measured; {} filtered out\n\n",
249+
". {} passed; {} failed; {} ignored; {} measured; {} filtered out",
250250
state.passed, state.failed, state.ignored, state.measured, state.filtered_out
251251
)
252252
};
253253

254254
self.write_plain(&s)?;
255255

256+
if let Some(ref exec_time) = state.exec_time {
257+
let time_str = format!("; finished in {}", exec_time);
258+
self.write_plain(&time_str)?;
259+
}
260+
261+
self.write_plain("\n\n")?;
262+
256263
Ok(success)
257264
}
258265
}

‎library/test/src/tests.rs

+1
Original file line numberDiff line numberDiff line change
@@ -669,6 +669,7 @@ fn should_sort_failures_before_printing_them() {
669669
allowed_fail: 0,
670670
filtered_out: 0,
671671
measured: 0,
672+
exec_time: None,
672673
metrics: MetricMap::new(),
673674
failures: vec![(test_b, Vec::new()), (test_a, Vec::new())],
674675
options: Options::new(),

‎library/test/src/time.rs

+13-2
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,9 @@
11
//! Module `time` contains everything related to the time measurement of unit tests
22
//! execution.
3-
//! Two main purposes of this module:
3+
//! The purposes of this module:
44
//! - Check whether test is timed out.
55
//! - Provide helpers for `report-time` and `measure-time` options.
6+
//! - Provide newtypes for executions times.
67
78
use std::env;
89
use std::fmt;
@@ -60,7 +61,7 @@ pub fn get_default_test_timeout() -> Instant {
6061
Instant::now() + Duration::from_secs(TEST_WARN_TIMEOUT_S)
6162
}
6263

63-
/// The meassured execution time of a unit test.
64+
/// The measured execution time of a unit test.
6465
#[derive(Debug, Clone, PartialEq)]
6566
pub struct TestExecTime(pub Duration);
6667

@@ -70,6 +71,16 @@ impl fmt::Display for TestExecTime {
7071
}
7172
}
7273

74+
/// The measured execution time of the whole test suite.
75+
#[derive(Debug, Clone, Default, PartialEq)]
76+
pub struct TestSuiteExecTime(pub Duration);
77+
78+
impl fmt::Display for TestSuiteExecTime {
79+
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
80+
write!(f, "{:.2}s", self.0.as_secs_f64())
81+
}
82+
}
83+
7384
/// Structure denoting time limits for test execution.
7485
#[derive(Copy, Clone, Debug, Default, PartialEq, Eq)]
7586
pub struct TimeThreshold {

‎src/test/run-make-fulldeps/libtest-json/Makefile

+3-3
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,6 @@ all:
1313
cat $(OUTPUT_FILE_DEFAULT) | "$(PYTHON)" validate_json.py
1414
cat $(OUTPUT_FILE_STDOUT_SUCCESS) | "$(PYTHON)" validate_json.py
1515

16-
# Compare to output file
17-
diff output-default.json $(OUTPUT_FILE_DEFAULT)
18-
diff output-stdout-success.json $(OUTPUT_FILE_STDOUT_SUCCESS)
16+
# Normalize the actual output and compare to expected output file
17+
cat $(OUTPUT_FILE_DEFAULT) | sed -r 's/\"exec_time\": [0-9]+(\.[0-9]+)?/\"exec_time\": \$$TIME/' | diff output-default.json -
18+
cat $(OUTPUT_FILE_STDOUT_SUCCESS) | sed -r 's/\"exec_time\": [0-9]+(\.[0-9]+)?/\"exec_time\": \$$TIME/' | diff output-stdout-success.json -

‎src/test/run-make-fulldeps/libtest-json/output-default.json

+1-1
Original file line numberDiff line numberDiff line change
@@ -7,4 +7,4 @@
77
{ "type": "test", "name": "c", "event": "ok" }
88
{ "type": "test", "event": "started", "name": "d" }
99
{ "type": "test", "name": "d", "event": "ignored" }
10-
{ "type": "suite", "event": "failed", "passed": 2, "failed": 1, "allowed_fail": 0, "ignored": 1, "measured": 0, "filtered_out": 0 }
10+
{ "type": "suite", "event": "failed", "passed": 2, "failed": 1, "allowed_fail": 0, "ignored": 1, "measured": 0, "filtered_out": 0, "exec_time": $TIME }

‎src/test/run-make-fulldeps/libtest-json/output-stdout-success.json

+1-1
Original file line numberDiff line numberDiff line change
@@ -7,4 +7,4 @@
77
{ "type": "test", "name": "c", "event": "ok", "stdout": "thread 'main' panicked at 'assertion failed: false', f.rs:15:5\n" }
88
{ "type": "test", "event": "started", "name": "d" }
99
{ "type": "test", "name": "d", "event": "ignored" }
10-
{ "type": "suite", "event": "failed", "passed": 2, "failed": 1, "allowed_fail": 0, "ignored": 1, "measured": 0, "filtered_out": 0 }
10+
{ "type": "suite", "event": "failed", "passed": 2, "failed": 1, "allowed_fail": 0, "ignored": 1, "measured": 0, "filtered_out": 0, "exec_time": $TIME }

‎src/test/rustdoc-ui/cfg-test.rs

+1
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
// check-pass
22
// compile-flags:--test --test-args --test-threads=1
33
// normalize-stdout-test: "src/test/rustdoc-ui" -> "$$DIR"
4+
// normalize-stdout-test "finished in \d+\.\d+s" -> "finished in $$TIME"
45

56
// Crates like core have doctests gated on `cfg(not(test))` so we need to make
67
// sure `cfg(test)` is not active when running `rustdoc --test`.

‎src/test/rustdoc-ui/cfg-test.stdout

+3-3
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,7 @@
11

22
running 2 tests
3-
test $DIR/cfg-test.rs - Bar (line 26) ... ok
4-
test $DIR/cfg-test.rs - Foo (line 18) ... ok
3+
test $DIR/cfg-test.rs - Bar (line 27) ... ok
4+
test $DIR/cfg-test.rs - Foo (line 19) ... ok
55

6-
test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
6+
test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in $TIME
77

‎src/test/rustdoc-ui/doc-test-doctest-feature.rs

+1
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
// check-pass
22
// compile-flags:--test
33
// normalize-stdout-test: "src/test/rustdoc-ui" -> "$$DIR"
4+
// normalize-stdout-test "finished in \d+\.\d+s" -> "finished in $$TIME"
45

56
#![feature(cfg_doctest)]
67

‎src/test/rustdoc-ui/doc-test-doctest-feature.stdout

+2-2
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,6 @@
11

22
running 1 test
3-
test $DIR/doc-test-doctest-feature.rs - Foo (line 10) ... ok
3+
test $DIR/doc-test-doctest-feature.rs - Foo (line 11) ... ok
44

5-
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
5+
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in $TIME
66

‎src/test/rustdoc-ui/doc-test-rustdoc-feature.rs

+1
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
// check-pass
22
// compile-flags:--test
33
// normalize-stdout-test: "src/test/rustdoc-ui" -> "$$DIR"
4+
// normalize-stdout-test "finished in \d+\.\d+s" -> "finished in $$TIME"
45

56
#![feature(doc_cfg)]
67

‎src/test/rustdoc-ui/doc-test-rustdoc-feature.stdout

+2-2
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,6 @@
11

22
running 1 test
3-
test $DIR/doc-test-rustdoc-feature.rs - Foo (line 9) ... ok
3+
test $DIR/doc-test-rustdoc-feature.rs - Foo (line 10) ... ok
44

5-
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
5+
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in $TIME
66

‎src/test/rustdoc-ui/doctest-output.rs

+1
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@
22
// aux-build:extern_macros.rs
33
// compile-flags:--test --test-args=--test-threads=1
44
// normalize-stdout-test: "src/test/rustdoc-ui" -> "$$DIR"
5+
// normalize-stdout-test "finished in \d+\.\d+s" -> "finished in $$TIME"
56
// check-pass
67

78
//! ```

‎src/test/rustdoc-ui/doctest-output.stdout

+4-4
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,8 @@
11

22
running 3 tests
3-
test $DIR/doctest-output.rs - (line 7) ... ok
4-
test $DIR/doctest-output.rs - ExpandedStruct (line 23) ... ok
5-
test $DIR/doctest-output.rs - foo::bar (line 17) ... ok
3+
test $DIR/doctest-output.rs - (line 8) ... ok
4+
test $DIR/doctest-output.rs - ExpandedStruct (line 24) ... ok
5+
test $DIR/doctest-output.rs - foo::bar (line 18) ... ok
66

7-
test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
7+
test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in $TIME
88

‎src/test/rustdoc-ui/failed-doctest-compile-fail.rs

+1
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@
33

44
// compile-flags:--test
55
// normalize-stdout-test: "src/test/rustdoc-ui" -> "$$DIR"
6+
// normalize-stdout-test "finished in \d+\.\d+s" -> "finished in $$TIME"
67
// failure-status: 101
78

89
/// ```compile_fail

‎src/test/rustdoc-ui/failed-doctest-compile-fail.stdout

+4-4
Original file line numberDiff line numberDiff line change
@@ -1,14 +1,14 @@
11

22
running 1 test
3-
test $DIR/failed-doctest-compile-fail.rs - Foo (line 8) ... FAILED
3+
test $DIR/failed-doctest-compile-fail.rs - Foo (line 9) ... FAILED
44

55
failures:
66

7-
---- $DIR/failed-doctest-compile-fail.rs - Foo (line 8) stdout ----
7+
---- $DIR/failed-doctest-compile-fail.rs - Foo (line 9) stdout ----
88
Test compiled successfully, but it's marked `compile_fail`.
99

1010
failures:
11-
$DIR/failed-doctest-compile-fail.rs - Foo (line 8)
11+
$DIR/failed-doctest-compile-fail.rs - Foo (line 9)
1212

13-
test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out
13+
test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in $TIME
1414

‎src/test/rustdoc-ui/failed-doctest-missing-codes.rs

+1
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@
33

44
// compile-flags:--test
55
// normalize-stdout-test: "src/test/rustdoc-ui" -> "$$DIR"
6+
// normalize-stdout-test "finished in \d+\.\d+s" -> "finished in $$TIME"
67
// failure-status: 101
78

89
/// ```compile_fail,E0004

‎src/test/rustdoc-ui/failed-doctest-missing-codes.stdout

+5-5
Original file line numberDiff line numberDiff line change
@@ -1,12 +1,12 @@
11

22
running 1 test
3-
test $DIR/failed-doctest-missing-codes.rs - Foo (line 8) ... FAILED
3+
test $DIR/failed-doctest-missing-codes.rs - Foo (line 9) ... FAILED
44

55
failures:
66

7-
---- $DIR/failed-doctest-missing-codes.rs - Foo (line 8) stdout ----
7+
---- $DIR/failed-doctest-missing-codes.rs - Foo (line 9) stdout ----
88
error[E0308]: mismatched types
9-
--> $DIR/failed-doctest-missing-codes.rs:9:13
9+
--> $DIR/failed-doctest-missing-codes.rs:10:13
1010
|
1111
LL | let x: () = 5i32;
1212
| -- ^^^^ expected `()`, found `i32`
@@ -19,7 +19,7 @@ For more information about this error, try `rustc --explain E0308`.
1919
Some expected error codes were not found: ["E0004"]
2020

2121
failures:
22-
$DIR/failed-doctest-missing-codes.rs - Foo (line 8)
22+
$DIR/failed-doctest-missing-codes.rs - Foo (line 9)
2323

24-
test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out
24+
test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in $TIME
2525

‎src/test/rustdoc-ui/failed-doctest-output.rs

+1
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@
55
// compile-flags:--test --test-args --test-threads=1
66
// rustc-env:RUST_BACKTRACE=0
77
// normalize-stdout-test: "src/test/rustdoc-ui" -> "$$DIR"
8+
// normalize-stdout-test "finished in \d+\.\d+s" -> "finished in $$TIME"
89
// failure-status: 101
910

1011
// doctest fails at runtime

0 commit comments

Comments
 (0)