libtest: Print the total time taken to execute a test suite

6 files changed, 54 insertions, 11 deletions

diff --git a/library/test/src/console.rs b/library/test/src/console.rs
index ff741e3bd53..1721c3c14f9 100644
--- a/library/test/src/console.rs
+++ b/library/test/src/console.rs
@@ -3,6 +3,7 @@
 use std::fs::File;
 use std::io;
 use std::io::prelude::Write;
+use std::time::Instant;
 
 use super::{
     bench::fmt_bench_samples,
@@ -14,7 +15,7 @@ use super::{
     options::{Options, OutputFormat},
     run_tests,
     test_result::TestResult,
-    time::TestExecTime,
+    time::{TestExecTime, TestSuiteExecTime},
     types::{NamePadding, TestDesc, TestDescAndFn},
 };
 
@@ -49,6 +50,7 @@ pub struct ConsoleTestState {
     pub allowed_fail: usize,
     pub filtered_out: usize,
     pub measured: usize,
+    pub exec_time: Option<TestSuiteExecTime>,
     pub metrics: MetricMap,
     pub failures: Vec<(TestDesc, Vec<u8>)>,
     pub not_failures: Vec<(TestDesc, Vec<u8>)>,
@@ -72,6 +74,7 @@ impl ConsoleTestState {
             allowed_fail: 0,
             filtered_out: 0,
             measured: 0,
+            exec_time: None,
             metrics: MetricMap::new(),
             failures: Vec::new(),
             not_failures: Vec::new(),
@@ -277,7 +280,14 @@ pub fn run_tests_console(opts: &TestOpts, tests: Vec<TestDescAndFn>) -> io::Resu
     };
     let mut st = ConsoleTestState::new(opts)?;
 
+    // Prevent the usage of `Instant` in some cases:
+    // - It's currently not supported for wasm targets.
+    // - We disable it for miri because it's not available when isolation is enabled.
+    let is_instant_supported = !cfg!(target_arch = "wasm32") && !cfg!(miri);
+
+    let start_time = is_instant_supported.then(Instant::now);
     run_tests(opts, tests, |x| on_test_event(&x, &mut st, &mut *out))?;
+    st.exec_time = start_time.map(|t| TestSuiteExecTime(t.elapsed()));
 
     assert!(st.current_test_count() == st.total);
 
diff --git a/library/test/src/formatters/json.rs b/library/test/src/formatters/json.rs
index 4dc4162700c..57b6d1a0202 100644
--- a/library/test/src/formatters/json.rs
+++ b/library/test/src/formatters/json.rs
@@ -47,7 +47,7 @@ impl<T: Write> JsonFormatter<T> {
             evt
         ))?;
         if let Some(exec_time) = exec_time {
-            self.write_message(&*format!(r#", "exec_time": "{}""#, exec_time))?;
+            self.write_message(&*format!(r#", "exec_time": {}"#, exec_time.0.as_secs_f64()))?;
         }
         if let Some(stdout) = stdout {
             self.write_message(&*format!(r#", "stdout": "{}""#, EscapedString(stdout)))?;
@@ -162,7 +162,7 @@ impl<T: Write> OutputFormatter for JsonFormatter<T> {
     }
 
     fn write_run_finish(&mut self, state: &ConsoleTestState) -> io::Result<bool> {
-        self.writeln_message(&*format!(
+        self.write_message(&*format!(
             "{{ \"type\": \"suite\", \
              \"event\": \"{}\", \
              \"passed\": {}, \
@@ -170,16 +170,23 @@ impl<T: Write> OutputFormatter for JsonFormatter<T> {
              \"allowed_fail\": {}, \
              \"ignored\": {}, \
              \"measured\": {}, \
-             \"filtered_out\": {} }}",
+             \"filtered_out\": {}",
             if state.failed == 0 { "ok" } else { "failed" },
             state.passed,
             state.failed + state.allowed_fail,
             state.allowed_fail,
             state.ignored,
             state.measured,
-            state.filtered_out
+            state.filtered_out,
         ))?;
 
+        if let Some(ref exec_time) = state.exec_time {
+            let time_str = format!(", \"exec_time\": {}", exec_time.0.as_secs_f64());
+            self.write_message(&time_str)?;
+        }
+
+        self.writeln_message(" }")?;
+
         Ok(state.failed == 0)
     }
 }
diff --git a/library/test/src/formatters/pretty.rs b/library/test/src/formatters/pretty.rs
index 8c90b57b3ba..6fa36929841 100644
--- a/library/test/src/formatters/pretty.rs
+++ b/library/test/src/formatters/pretty.rs
@@ -259,7 +259,7 @@ impl<T: Write> OutputFormatter for PrettyFormatter<T> {
 
         let s = if state.allowed_fail > 0 {
             format!(
-                ". {} passed; {} failed ({} allowed); {} ignored; {} measured; {} filtered out\n\n",
+                ". {} passed; {} failed ({} allowed); {} ignored; {} measured; {} filtered out",
                 state.passed,
                 state.failed + state.allowed_fail,
                 state.allowed_fail,
@@ -269,13 +269,20 @@ impl<T: Write> OutputFormatter for PrettyFormatter<T> {
             )
         } else {
             format!(
-                ". {} passed; {} failed; {} ignored; {} measured; {} filtered out\n\n",
+                ". {} passed; {} failed; {} ignored; {} measured; {} filtered out",
                 state.passed, state.failed, state.ignored, state.measured, state.filtered_out
             )
         };
 
         self.write_plain(&s)?;
 
+        if let Some(ref exec_time) = state.exec_time {
+            let time_str = format!("; finished in {}", exec_time);
+            self.write_plain(&time_str)?;
+        }
+
+        self.write_plain("\n\n")?;
+
         Ok(success)
     }
 }
diff --git a/library/test/src/formatters/terse.rs b/library/test/src/formatters/terse.rs
index 1ae7846a99e..6f46f7255a4 100644
--- a/library/test/src/formatters/terse.rs
+++ b/library/test/src/formatters/terse.rs
@@ -236,7 +236,7 @@ impl<T: Write> OutputFormatter for TerseFormatter<T> {
 
         let s = if state.allowed_fail > 0 {
             format!(
-                ". {} passed; {} failed ({} allowed); {} ignored; {} measured; {} filtered out\n\n",
+                ". {} passed; {} failed ({} allowed); {} ignored; {} measured; {} filtered out",
                 state.passed,
                 state.failed + state.allowed_fail,
                 state.allowed_fail,
@@ -246,13 +246,20 @@ impl<T: Write> OutputFormatter for TerseFormatter<T> {
             )
         } else {
             format!(
-                ". {} passed; {} failed; {} ignored; {} measured; {} filtered out\n\n",
+                ". {} passed; {} failed; {} ignored; {} measured; {} filtered out",
                 state.passed, state.failed, state.ignored, state.measured, state.filtered_out
             )
         };
 
         self.write_plain(&s)?;
 
+        if let Some(ref exec_time) = state.exec_time {
+            let time_str = format!("; finished in {}", exec_time);
+            self.write_plain(&time_str)?;
+        }
+
+        self.write_plain("\n\n")?;
+
         Ok(success)
     }
 }
diff --git a/library/test/src/tests.rs b/library/test/src/tests.rs
index 85a0705f69c..74313cc4438 100644
--- a/library/test/src/tests.rs
+++ b/library/test/src/tests.rs
@@ -669,6 +669,7 @@ fn should_sort_failures_before_printing_them() {
         allowed_fail: 0,
         filtered_out: 0,
         measured: 0,
+        exec_time: None,
         metrics: MetricMap::new(),
         failures: vec![(test_b, Vec::new()), (test_a, Vec::new())],
         options: Options::new(),
diff --git a/library/test/src/time.rs b/library/test/src/time.rs
index 96c090f9b01..130792fa5d7 100644
--- a/library/test/src/time.rs
+++ b/library/test/src/time.rs
@@ -1,8 +1,9 @@
 //! Module `time` contains everything related to the time measurement of unit tests
 //! execution.
-//! Two main purposes of this module:
+//! The purposes of this module:
 //! - Check whether test is timed out.
 //! - Provide helpers for `report-time` and `measure-time` options.
+//! - Provide newtypes for executions times.
 
 use std::env;
 use std::fmt;
@@ -60,7 +61,7 @@ pub fn get_default_test_timeout() -> Instant {
     Instant::now() + Duration::from_secs(TEST_WARN_TIMEOUT_S)
 }
 
-/// The meassured execution time of a unit test.
+/// The measured execution time of a unit test.
 #[derive(Debug, Clone, PartialEq)]
 pub struct TestExecTime(pub Duration);
 
@@ -70,6 +71,16 @@ impl fmt::Display for TestExecTime {
     }
 }
 
+/// The measured execution time of the whole test suite.
+#[derive(Debug, Clone, Default, PartialEq)]
+pub struct TestSuiteExecTime(pub Duration);
+
+impl fmt::Display for TestSuiteExecTime {
+    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
+        write!(f, "{:.2}s", self.0.as_secs_f64())
+    }
+}
+
 /// Structure denoting time limits for test execution.
 #[derive(Copy, Clone, Debug, Default, PartialEq, Eq)]
 pub struct TimeThreshold {