Measuring Test Execution Time with the Spring StopWatch

This post utilizes the Spring StopWatch within a TestExecutionListener to gain some basic insights about test execution times.

We create a new StopWatch for each test class in beforeTestClass and measure the execution time per test method with start/stop. Once all test methods have been executed we prettyPrint the results in afterTestClass.

The fully operational test utility ExecutionTimeTestExecutionListener looks as follows:

package de.datenkollektiv.util;

import org.springframework.test.context.TestContext;
import org.springframework.test.context.support.AbstractTestExecutionListener;
import org.springframework.util.StopWatch;

public class ExecutionTimeTestExecutionListener extends AbstractTestExecutionListener {

    private StopWatch stopWatch;

    @Override
    public void beforeTestClass(TestContext testContext) throws Exception {
        super.beforeTestClass(testContext);
        stopWatch = new StopWatch(testContext.getTestClass().getSimpleName());
        System.out.println("Running test '" + testContext.getTestClass().getSimpleName() + "'...");
    }

    @Override
    public void beforeTestMethod(TestContext testContext) throws Exception {
        super.beforeTestMethod(testContext);
        stopWatch.start(testContext.getTestMethod().getName());
    }

    @Override
    public void afterTestMethod(TestContext testContext) throws Exception {
        if (stopWatch.isRunning()) {
            stopWatch.stop();
        }
        super.afterTestMethod(testContext);
    }

    @Override
    public void afterTestClass(TestContext testContext) throws Exception {
        System.out.println(stopWatch.prettyPrint());

        System.out.println("Test '" + testContext.getTestClass().getSimpleName() + "' finished after " + stopWatch.getTotalTimeSeconds() + " seconds.");
        super.afterTestClass(testContext);
    }
}

Register the execution listener ExecutionTimeTestExecutionListener with the Spring annotation @TestExecutionListeners in your test and you are ready to go!

@ExtendWith(SpringExtension.class)
@SpringBootTest
@TestExecutionListeners({DependencyInjectionTestExecutionListener.class, ExecutionTimeTestExecutionListener.class})
public class BannerGeneratorAcceptanceTests {

    @Test
    void contextLoads() {
    }

    @Test
    void shouldGenerateSpringBootBanner() {
        ...
    }
}

After test execution the stopwatch results will be available for further investigation:

...
StopWatch 'BannerGeneratorAcceptanceTests': running time (millis) = 1079
-----------------------------------------
ms     %     Task name
-----------------------------------------
00000  000%  contextLoads
01079  100%  shouldGenerateSpringBootBanner

Test 'BannerGeneratorAcceptanceTests' finished after 1.079 seconds.

It's never been so easy to keep an eye on test execution time...