[SUREFIRE-1656] Print Total Elapsed Time of Tests

maven-failsafe-plugin/src/main/java/org/apache/maven/plugin/failsafe/util/FailsafeSummaryXmlUtils.java

@@ -35,6 +35,7 @@
 import org.xml.sax.InputSource;
 
 import static java.lang.Boolean.parseBoolean;
+import static java.lang.Float.parseFloat;
 import static java.lang.Integer.parseInt;
 import static java.lang.String.format;
 import static java.nio.charset.StandardCharsets.UTF_8;
@@ -48,6 +49,8 @@
  * @since 2.20
  */
 public final class FailsafeSummaryXmlUtils {
+	private static final float ONE_SECOND = 1000.0f;
+
     private static final String FAILSAFE_SUMMARY_XML_SCHEMA_LOCATION =
             "https://maven.apache.org/surefire/maven-surefire-plugin/xsd/failsafe-summary.xsd";
 
@@ -56,6 +59,7 @@ public final class FailsafeSummaryXmlUtils {
 
     private static final String MESSAGE_ELEMENT = "<failureMessage>%s</failureMessage>";
 
+    // TODO What happened to flakes?
     private static final String FAILSAFE_SUMMARY_XML_TEMPLATE = "<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n"
             + "<failsafe-summary xmlns:xsi=\"http://www.w3.org/2001/XMLSchema-instance\""
             + " xsi:noNamespaceSchemaLocation=\"" + FAILSAFE_SUMMARY_XML_SCHEMA_LOCATION + "\""
@@ -64,6 +68,7 @@ public final class FailsafeSummaryXmlUtils {
             + "    <errors>%d</errors>\n"
             + "    <failures>%d</failures>\n"
             + "    <skipped>%d</skipped>\n"
+            + "    <time>%s</time>\n"
             + "    %s\n"
             + "</failsafe-summary>";
 
@@ -82,6 +87,7 @@ public static RunResult toRunResult(File failsafeSummaryXml) throws Exception {
             String errors = xpath.evaluate("/failsafe-summary/errors", root);
             String failures = xpath.evaluate("/failsafe-summary/failures", root);
             String skipped = xpath.evaluate("/failsafe-summary/skipped", root);
+            String elapsed = xpath.evaluate("/failsafe-summary/time", root);
             String failureMessage = xpath.evaluate("/failsafe-summary/failureMessage", root);
             String timeout = xpath.evaluate("/failsafe-summary/@timeout", root);
 
@@ -90,6 +96,8 @@ public static RunResult toRunResult(File failsafeSummaryXml) throws Exception {
                     parseInt(errors),
                     parseInt(failures),
                     parseInt(skipped),
+                    0,
+                    isBlank(elapsed) ? null : ((int) (parseFloat(elapsed) * ONE_SECOND)),
                     isBlank(failureMessage) ? null : unescapeXml(failureMessage),
                     parseBoolean(timeout));
         }
@@ -107,6 +115,7 @@ public static void fromRunResultToFile(RunResult fromRunResult, File toFailsafeS
                 fromRunResult.getErrors(),
                 fromRunResult.getFailures(),
                 fromRunResult.getSkipped(),
+                fromRunResult.getElapsed() != null ? String.valueOf(fromRunResult.getElapsed() / ONE_SECOND) : "",
                 msg);
 
         try (FileOutputStream os = new FileOutputStream(toFailsafeSummaryXml)) {

maven-failsafe-plugin/src/test/java/org/apache/maven/plugin/failsafe/MarshallerUnmarshallerTest.java

@@ -32,6 +32,7 @@
  */
 public class MarshallerUnmarshallerTest {
     @Test
+    @SuppressWarnings("checkstyle:MagicNumber")
     public void shouldUnmarshallExistingXmlFile() throws Exception {
         File xml = new File("target/test-classes/org/apache/maven/plugin/failsafe/failsafe-summary.xml");
         RunResult summary = FailsafeSummaryXmlUtils.toRunResult(xml);
@@ -44,6 +45,8 @@ public void shouldUnmarshallExistingXmlFile() throws Exception {
 
         assertThat(summary.getSkipped()).isEqualTo(3);
 
+        assertThat(summary.getElapsed()).isEqualTo(1500);
+
         assertThat(summary.getFailure())
                 .contains("There was an error in the forked processtest "
                         + "subsystem#no method RuntimeException Hi There!");
@@ -56,13 +59,15 @@ public void shouldUnmarshallExistingXmlFile() throws Exception {
     }
 
     @Test
+    @SuppressWarnings("checkstyle:MagicNumber")
     public void shouldMarshallAndUnmarshallSameXml() throws Exception {
         RunResult expected = new RunResult(
                 7,
                 1,
                 2,
                 3,
                 2,
+                1500,
                 "There was an error in the forked processtest "
                         + "subsystem#no method RuntimeException Hi There! $&>>"
                         + "\n\tat org.apache.maven.plugin.surefire.booterclient.ForkStarter"
@@ -84,6 +89,8 @@ public void shouldMarshallAndUnmarshallSameXml() throws Exception {
 
         assertThat(actual.getFailures()).isEqualTo(expected.getFailures());
 
+        assertThat(actual.getElapsed()).isEqualTo(expected.getElapsed());
+
         assertThat(actual.getSkipped()).isEqualTo(expected.getSkipped());
 
         assertThat(actual.getFailure()).isEqualTo(expected.getFailure());

maven-failsafe-plugin/src/test/java/org/apache/maven/plugin/failsafe/RunResultTest.java

@@ -56,18 +56,18 @@ public void testSerialization() throws Exception {
 
     @Test
     public void testFailures() throws Exception {
-        writeReadCheck(new RunResult(0, 1, 2, 3, "stacktraceHere", false));
+        writeReadCheck(new RunResult(0, 1, 2, 3, 220, "stacktraceHere", false));
     }
 
     @Test
     public void testSkipped() throws Exception {
-        writeReadCheck(new RunResult(3, 2, 1, 0, null, true));
+        writeReadCheck(new RunResult(3, 2, 1, 0, 50, null, true));
     }
 
     @Test
     public void testAppendSerialization() throws Exception {
         RunResult simpleAggregate = getSimpleAggregate();
-        RunResult additional = new RunResult(2, 1, 2, 2, "msg " + ((char) 0x0E01), true);
+        RunResult additional = new RunResult(2, 1, 2, 2, 500, "msg " + ((char) 0x0E01), true);
 
         File summary = SureFireFileManager.createTempFile("failsafe", "test");
         FailsafeSummaryXmlUtils.writeSummary(simpleAggregate, summary, false);
@@ -88,6 +88,8 @@ public void testAppendSerialization() throws Exception {
 
         assertThat(expected.getFlakes()).isEqualTo(2);
 
+        assertThat(expected.getElapsed()).isEqualTo(500);
+
         assertThat(expected.getFailure()).isEqualTo("msg " + ((char) 0x0E01));
 
         assertThat(expected.isTimeout()).isTrue();

maven-failsafe-plugin/src/test/resources/org/apache/maven/plugin/failsafe/failsafe-summary.xml

@@ -1 +1 @@
-<?xml version="1.0" encoding="UTF-8"?><!--~ Licensed to the Apache Software Foundation (ASF) under one~ or more contributor license agreements.  See the NOTICE file~ distributed with this work for additional information~ regarding copyright ownership.  The ASF licenses this file~ to you under the Apache License, Version 2.0 (the~ "License"); you may not use this file except in compliance~ with the License.  You may obtain a copy of the License at~~     http://www.apache.org/licenses/LICENSE-2.0~~ Unless required by applicable law or agreed to in writing,~ software distributed under the License is distributed on an~ "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY~ KIND, either express or implied.  See the License for the~ specific language governing permissions and limitations~ under the License.--><failsafe-summary result="254" timeout="false">  <completed>7</completed>  <errors>1</errors>  <failures>2</failures>  <skipped>3</skipped>  <failureMessage><![CDATA[org.apache.maven.surefire.booter.SurefireBooterForkException: ExecutionException There was an error in the forked processtest subsystem#no method RuntimeException Hi There! $&amp;&gt;&gt;	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.awaitResultsDone(ForkStarter.java:489)	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.runSuitesForkOnceMultiple(ForkStarter.java:364)	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:288)	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:240)	at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeProvider(AbstractSurefireMojo.java:1075)	at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeAfterPreconditionsChecked(AbstractSurefireMojo.java:905)	at org.apache.maven.plugin.surefire.AbstractSurefireMojo.execute(AbstractSurefireMojo.java:783)	at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:133)	at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:208)	at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:153)	at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:145)	at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:108)	at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:76)	at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build(SingleThreadedBuilder.java:51)	at org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:116)	at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:361)	at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:155)	at org.apache.maven.cli.MavenCli.execute(MavenCli.java:584)	at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:213)	at org.apache.maven.cli.MavenCli.main(MavenCli.java:157)	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)	at java.lang.reflect.Method.invoke(Method.java:498)	at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:289)	at org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:229)	at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:415)	at org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:356)Caused by: java.lang.RuntimeException: There was an error in the forked processtest subsystem#no method RuntimeException Hi There!	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:658)	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:527)	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.access$500(ForkStarter.java:117)	at org.apache.maven.plugin.surefire.booterclient.ForkStarter$1.call(ForkStarter.java:358)	at org.apache.maven.plugin.surefire.booterclient.ForkStarter$1.call(ForkStarter.java:337)	at java.util.concurrent.FutureTask.run(FutureTask.java:266)	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)	at java.lang.Thread.run(Thread.java:745)]]></failureMessage></failsafe-summary>
+<?xml version="1.0" encoding="UTF-8"?><!--~ Licensed to the Apache Software Foundation (ASF) under one~ or more contributor license agreements.  See the NOTICE file~ distributed with this work for additional information~ regarding copyright ownership.  The ASF licenses this file~ to you under the Apache License, Version 2.0 (the~ "License"); you may not use this file except in compliance~ with the License.  You may obtain a copy of the License at~~     http://www.apache.org/licenses/LICENSE-2.0~~ Unless required by applicable law or agreed to in writing,~ software distributed under the License is distributed on an~ "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY~ KIND, either express or implied.  See the License for the~ specific language governing permissions and limitations~ under the License.--><failsafe-summary result="254" timeout="false">  <completed>7</completed>  <errors>1</errors>  <failures>2</failures>  <skipped>3</skipped>  <time>1.5</time>  <failureMessage><![CDATA[org.apache.maven.surefire.booter.SurefireBooterForkException: ExecutionException There was an error in the forked processtest subsystem#no method RuntimeException Hi There! $&amp;&gt;&gt;	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.awaitResultsDone(ForkStarter.java:489)	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.runSuitesForkOnceMultiple(ForkStarter.java:364)	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:288)	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:240)	at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeProvider(AbstractSurefireMojo.java:1075)	at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeAfterPreconditionsChecked(AbstractSurefireMojo.java:905)	at org.apache.maven.plugin.surefire.AbstractSurefireMojo.execute(AbstractSurefireMojo.java:783)	at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:133)	at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:208)	at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:153)	at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:145)	at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:108)	at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:76)	at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build(SingleThreadedBuilder.java:51)	at org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:116)	at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:361)	at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:155)	at org.apache.maven.cli.MavenCli.execute(MavenCli.java:584)	at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:213)	at org.apache.maven.cli.MavenCli.main(MavenCli.java:157)	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)	at java.lang.reflect.Method.invoke(Method.java:498)	at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:289)	at org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:229)	at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:415)	at org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:356)Caused by: java.lang.RuntimeException: There was an error in the forked processtest subsystem#no method RuntimeException Hi There!	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:658)	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:527)	at org.apache.maven.plugin.surefire.booterclient.ForkStarter.access$500(ForkStarter.java:117)	at org.apache.maven.plugin.surefire.booterclient.ForkStarter$1.call(ForkStarter.java:358)	at org.apache.maven.plugin.surefire.booterclient.ForkStarter$1.call(ForkStarter.java:337)	at java.util.concurrent.FutureTask.run(FutureTask.java:266)	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)	at java.lang.Thread.run(Thread.java:745)]]></failureMessage></failsafe-summary>

maven-surefire-common/src/main/java/org/apache/maven/plugin/surefire/report/DefaultReporterFactory.java

@@ -263,7 +263,7 @@ private void mergeTestHistoryResult() {
         }
 
         // Update globalStatistics by iterating through mergedTestHistoryResult
-        int completedCount = 0, skipped = 0;
+        int completedCount = 0, skipped = 0, elapsed = -1;
 
         for (Map.Entry<String, List<TestMethodStats>> entry : mergedTestHistoryResult.entrySet()) {
             List<TestMethodStats> testMethodStats = entry.getValue();
@@ -273,6 +273,12 @@ private void mergeTestHistoryResult() {
             List<ReportEntryType> resultTypes = new ArrayList<>();
             for (TestMethodStats methodStats : testMethodStats) {
                 resultTypes.add(methodStats.getResultType());
+                if (methodStats.getElapsed() != null) {
+                    if (elapsed == -1) {
+                        elapsed = 0;
+                    }
+                    elapsed += methodStats.getElapsed();
+                }
             }
 
             switch (getTestResultType(resultTypes, reportConfiguration.getRerunFailingTestsCount())) {
@@ -303,7 +309,7 @@ private void mergeTestHistoryResult() {
             }
         }
 
-        globalStats.set(completedCount, errorTests.size(), failedTests.size(), skipped, flakyTests.size());
+        globalStats.set(completedCount, errorTests.size(), failedTests.size(), skipped, flakyTests.size(), (elapsed != -1 ? elapsed : null));
     }
 
     /**

maven-surefire-common/src/main/java/org/apache/maven/plugin/surefire/report/TestMethodStats.java

@@ -34,10 +34,13 @@ public class TestMethodStats {
 
     private final StackTraceWriter stackTraceWriter;
 
-    public TestMethodStats(String testClassMethodName, ReportEntryType resultType, StackTraceWriter stackTraceWriter) {
+    private final Integer elapsed;
+
+    public TestMethodStats(String testClassMethodName, ReportEntryType resultType, StackTraceWriter stackTraceWriter, Integer elapsed) {
         this.testClassMethodName = testClassMethodName;
         this.resultType = resultType;
         this.stackTraceWriter = stackTraceWriter;
+        this.elapsed = elapsed;
     }
 
     public String getTestClassMethodName() {
@@ -51,4 +54,8 @@ public ReportEntryType getResultType() {
     public StackTraceWriter getStackTraceWriter() {
         return stackTraceWriter;
     }
+
+    public Integer getElapsed() {
+        return elapsed;
+    }
 }

maven-surefire-common/src/main/java/org/apache/maven/plugin/surefire/report/TestSetRunListener.java

@@ -288,7 +288,8 @@ private void addTestMethodStats() {
             TestMethodStats methodStats = new TestMethodStats(
                     reportEntry.getClassMethodName(),
                     reportEntry.getReportEntryType(),
-                    reportEntry.getStackTraceWriter());
+                    reportEntry.getStackTraceWriter(),
+                    reportEntry.getElapsed());
             testMethodStats.add(methodStats);
         }
     }

maven-surefire-common/src/main/java/org/apache/maven/surefire/report/RunStatistics.java

@@ -18,12 +18,25 @@
  */
 package org.apache.maven.surefire.report;
 
+import java.text.MessageFormat;
+import java.util.Locale;
+
 import org.apache.maven.surefire.api.suite.RunResult;
 
 /**
  * @author Kristian Rosenvold
  */
 public final class RunStatistics {
+    private static final float ONE_SECOND = 1000.0f;
+
+    /*
+     * Rationale: The idea is to always display four digits for visually consistent output
+     * Important: Keep in sync with maven-surefire-report-plugin/src/main/resources/surefire-report.properties
+     */
+    private final MessageFormat elapsedTimeFormat = new MessageFormat(
+            "{0,choice,0#0|0.0<{0,number,0.000}|10#{0,number,0.00}|100#{0,number,0.0}|1000#{0,number,0}} s",
+            Locale.ROOT);
+
     private int completedCount;
 
     private int errors;
@@ -34,6 +47,8 @@ public final class RunStatistics {
 
     private int flakes;
 
+    private Integer elapsed;
+
     public synchronized int getCompletedCount() {
         return completedCount;
     }
@@ -54,12 +69,17 @@ public synchronized int getFlakes() {
         return flakes;
     }
 
-    public synchronized void set(int completedCount, int errors, int failures, int skipped, int flakes) {
+    public synchronized Integer getElapsed() {
+        return elapsed;
+    }
+
+    public synchronized void set(int completedCount, int errors, int failures, int skipped, int flakes, Integer elapsed) {
         this.completedCount = completedCount;
         this.errors = errors;
         this.failures = failures;
         this.skipped = skipped;
         this.flakes = flakes;
+        this.elapsed = elapsed;
     }
 
     public synchronized RunResult getRunResult() {
@@ -72,6 +92,7 @@ public synchronized String getSummary() {
         if (flakes > 0) {
             summary += ", Flakes: " + flakes;
         }
+        summary += ", Time elapsed: " + (elapsed != null ? elapsedTimeFormat.format(new Object[] {elapsed / ONE_SECOND}): "(unknown)");
         return summary;
     }
 }