Asked  3 Months ago    Answers:  5   Viewed   14 times

With a view to managing / reducing our build times, I want to identify which unit tests are taking the most time - in a parallel test environment using the maven-surefire-plugin.

We are using JUnit (4.10) for unit tests. We use maven (2.2.1 - some plugins we use don't yet support maven 3) as our primary build tool, and the maven-surefire-plugin (2.19) to run unit tests.

We are using the maven-surefire-plugin in parallel mode, where both the individual methods are run in parallel and the unit test classes are run in parallel - this is very important, as it significantly reduces build unit test time. The maven-surefire-plugin is configured in the .pom as follows:

  <plugin>
    <groupId>org.apache.maven.plugins</groupId>
    <artifactId>maven-surefire-plugin</artifactId>
    <version>2.19</version>
    <configuration>
      <argLine>-Xmx2G -XX:MaxPermSize=1G -XX:-UseSplitVerifier</argLine>
      <failIfNoTests>false</failIfNoTests>
      <parallel>classesAndMethods</parallel>
      <useUnlimitedThreads>true</useUnlimitedThreads>
    </configuration>
  </plugin>

However, one of the implications of this is that in the console output, the time elapsed for each JUnit test class is the aggregate time for all the methods in the class.

For example, if a test class had 10 unit test methods, each of which took 1 second to run, then the test class would take about 1 second to run (each method being run in parallel), but the output would be something like:

Running com.package.QuickParallelTest Tests run: 10, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 10.0 sec - in com.package.QuickParallelTest

This makes it difficult to distinguish in the console output from another test class with 10 unit test methods, of which 9 run almost instantly and 1 takes almost 10 seconds to run. In this case, the test class would take about 10 seconds to run (because of the one slow test method), but the maven-surefire-plugin console output would be effectively the same:

Running com.package.SlowParallelTest Tests run: 10, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 10.0 sec - in com.package.SlowParallelTest

Ideally, I would like the time elapsed to indicate how long the test class took to run (in parallel), not the aggregate time taken to run the methods separately (as if single-threaded).

So, my question(s) is/are:

  1. Is there maven-surefire-plugin setting that I am missing, so that the print summary would show time taken per class rather than aggregate for methods?
  2. Is this is a known "bug" (or "feature") in the maven-surefire-plugin? (I've checked the SureFire JIRA, but couldn't find anything like this.)
  3. Is there an alternative way for me to identify which tests are taking a long time and are therefore prime for optimisation.

EDIT:

I've tried playing with some additional configuration settings. Curiously, adding the the following to the configuration in the .pom seems to change the time elapsed in the console output to be the time taken in running the test class - however, this is (in my mind) counter-intuitive, since these settings are the default settings:

    <configuration>
      ...
      <forkCount>1</forkCount>
      <reuseForks>true</reuseForks>
    </configuration>

 Answers

45

Adding to the Maven Surefire Plugin configuration the reportFormat entry and setting its value to plain (instead of the default brief) would give you elapsed time per method.

<build>
    <plugins>
        <plugin>
            <groupId>org.apache.maven.plugins</groupId>
            <artifactId>maven-surefire-plugin</artifactId>
            <version>2.19</version>
            <configuration>
                <argLine>-Xmx2G -XX:MaxPermSize=1G -XX:-UseSplitVerifier</argLine>
                <failIfNoTests>false</failIfNoTests>
                <parallel>classesAndMethods</parallel>
                <useUnlimitedThreads>true</useUnlimitedThreads>
                <reportFormat>plain</reportFormat>
            </configuration>
        </plugin>
    </plugins>
</build>

Output with default reportFormat (brief):

-------------------------------------------------------
 T E S T S
-------------------------------------------------------
Running com.sample.mocking.InternalServiceTestCase
Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.241 sec - in com.sample.mocking.InternalServiceTestCase

Output with plain value:

-------------------------------------------------------
 T E S T S
-------------------------------------------------------
Running com.sample.mocking.InternalServiceTestCase
Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.187 sec - in com.sample.mocking.InternalServiceTestCase
test(com.sample.mocking.InternalServiceTestCase)  Time elapsed: 0.005 sec
mockTest(com.sample.mocking.InternalServiceTestCase)  Time elapsed: 0.17 sec
mockTestFailureTollerance(com.sample.mocking.InternalServiceTestCase)  Time elapsed: 0.007 sec
mockProcessfile(com.sample.mocking.InternalServiceTestCase)  Time elapsed: 0.003 sec

This option may give you further details on tests and execution time.

Friday, August 13, 2021
 
Carrot
answered 3 Months ago
53

I found a solution by using maven-dependency-plugin to copy resolved pom dependencies and additional jar.

<plugin>
<groupId>org.apache.maven.plugins</groupId>
<artifactId>maven-dependency-plugin</artifactId>
<version>2.1</version>
<executions>
    <execution>
        <id>copy-dependencies</id>
        <phase>package</phase>
        <goals>
            <goal>copy-dependencies</goal>
        </goals>
        <configuration>
            <outputDirectory>${project.build.directory}/lib</outputDirectory>
            <overWriteReleases>false</overWriteReleases>
            <overWriteSnapshots>false</overWriteSnapshots>
            <overWriteIfNewer>true</overWriteIfNewer>
            <includeScope>runtime</includeScope>
        </configuration>
    </execution>
    <execution>
        <id>copy-model</id>
        <phase>package</phase>
        <goals>
            <goal>copy</goal>
        </goals>
        <configuration>
            <artifactItems>
                <artifactItem>
                    <groupId>my.test.pkg</groupId>
                    <artifactId>my-model</artifactId>
                    <classifier>server</classifier>
                    <version>1.0.3</version>
                    <type>jar</type>
                </artifactItem>
                <artifactItem>
                    <groupId>my.test.pkg</groupId>
                    <artifactId>my-model</artifactId>
                    <classifier>server</classifier>
                    <version>1.1.0</version>
                    <type>jar</type>
                </artifactItem>
            </artifactItems>
            <outputDirectory>${project.build.directory}/lib</outputDirectory>
        </configuration>
    </execution>
</executions>

Now I just have to add the following lines in my assembly xml

    <fileSet>
        <directory>${project.build.directory}/lib</directory>
        <outputDirectory>/lib</outputDirectory>
        <filtered>false</filtered>
        <includes>
            <include>*.jar</include>
        </includes>
        <fileMode>0600</fileMode>
    </fileSet>
Monday, June 14, 2021
 
Farnabaz
answered 5 Months ago
91

According to the annotation (import org.junit.jupiter.api.Test), you are trying to run JUnit 5 tests with Maven. According to the documentation, you have to add this dependency:

<dependency>
    <groupId>org.junit.jupiter</groupId>
    <artifactId>junit-jupiter-engine</artifactId>
    <version>5.3.1</version>
    <scope>test</scope>
</dependency>

Your version of Maven comes with a version of maven-surefire-plugin which does not support JUnit 5. You could update your Maven to the latest version. You could also set the version of the maven-surefire-plugin:

<plugin>
    <groupId>org.apache.maven.plugins</groupId>
    <artifactId>maven-surefire-plugin</artifactId>
    <!-- JUnit 5 requires Surefire version 2.22.0 or higher -->
    <version>2.22.0</version>
</plugin>

See the junit5-samples for this information.

See the Maven Surefire Plugin artifact in a Maven repository. At version 3.0.0-M3 as of 2019-01.

Wednesday, August 4, 2021
 
axiomer
answered 3 Months ago
27

The maven-surefire-plugin currently doesn't let you do this. It writes all the results in separate files. You could create a feature-request in its issue tracker, if you feel like this is a missing feature.

However you can use some Linux commands to convert the output to what you need. Here are some commands that turn the separate XML files into a single file that looks like what you want:

grep testcase target/surefire-reports/TEST-*.xml |
  sed 's/.* name="(.*)" classname="(.*)" time="(.*)".*/2#1() - 3ms/g' |
  sort -n -k 3 > output.txt

Update: Numeric sorting has problems with varying number of fraction digits. Use awk version below to solve this.


The same thing could be done with awk a bit shorter and less cryptic:

grep -h testcase target/surefire-reports/TEST-*.xml |
  awk -F '"' '{printf("%s#%s() - %.3fmsn", $4, $2, $6); }' |
  sort -n -k 3 > output.txt

You have to execute these commands from the toplevel directory of your maven project after the surefire-reports were generated.

If you have multi-module project, use this instead:

find . -name TEST-*.xml -exec grep -h testcase {} ; |
  awk -F '"' '{printf("%s#%s() - %.3fmsn", $4, $2, $6); }' |
  sort -n -k 3 > output.txt

The resulting file is output.txt and contains lines of the following format:

<classname>#<methodname>() - <time>ms

The result is sorted by consumed time.

Thursday, August 12, 2021
 
capsid
answered 3 Months ago
74

I would factor the logic that needs to be tested out of main():

func main() {
    start(os.Args)
}

func start(args []string) {
    // old main() logic
}

This way you can unit-test start() without mutating os.Args.

Saturday, October 2, 2021
 
kind_robot
answered 4 Weeks ago
Only authorized users can answer the question. Please sign in first, or register a free account.
Not the answer you're looking for? Browse other questions tagged :  
Share