junit-team / junit5

✅ The 5th major version of the programmer-friendly testing framework for Java and the JVM
https://junit.org
Other
6.35k stars 1.48k forks source link

Certain JUnit Jupiter assertions perform slower than JUnit 4.12's #1258

Closed karayv closed 6 years ago

karayv commented 6 years ago

Overview

Accidentally I found out that JUnit 5.0.3 assertion (assertTrue) worked significantly slower comparing to JUnit 4.12.

In my 2 tests I repeat the same assertion many times. One test uses old junit, other - junit5.

https://github.com/karayv/junit-perf-demo/blob/master/src/test/java/my/perftest/JUnit5Test.java

public class JUnit5Test {
    TestRunner testRunner = new TestRunner();

    @Test
    void test() {
        testRunner.go(Assertions::assertTrue);
    }
}

I was able to pass 288230376151711744 assertions in 1.515 sec with JUnit 4 and only 17179869184 assertions in 3.015 sec with JUnit 5

I created a sample repo https://github.com/karayv/junit-perf-demo where the issue can be reproduced and possibly investigated. It contains four classes: JUnit5Test, OldJUnitTest, TestRunner and a imaginary super fast prod service - Library.

Full console output for both tests:

JUnit5Test:

Level of load: 15, duration: PT0.195S, number of operations: 1073741824
Level of load: 16, duration: PT0.771S, number of operations: 4294967296
Level of load: 17, duration: PT3.015S, number of operations: 17179869184

OldJUnitTest:

Level of load: 26, duration: PT0.185S, number of operations: 4503599627370496
Level of load: 27, duration: PT0.383S, number of operations: 18014398509481984
Level of load: 28, duration: PT0.758S, number of operations: 72057594037927936
Level of load: 29, duration: PT1.515S, number of operations: 288230376151711744
jbduncan commented 6 years ago

I believe this issue is related to https://github.com/junit-team/junit5/issues/880. :)

karayv commented 6 years ago

Oops... :)

Okay, I took a look myself

It looks like the issue is in creation of java.util.function.BooleanSupplier

If I change my JUnit4 test to

public class OldJUnitTest {
    LoadRunner testRunner = new TestRunner();

    @Test
    public void test() {
        //testRunner.go(Assert::assertTrue);

        testRunner.go((cond) -> {
            BooleanSupplier bs = () -> cond;
            Assert.assertTrue(bs.getAsBoolean());
        });
    }
}

performance degrades to the same level.

jbduncan commented 6 years ago

My intuition on this is that it's not just BooleanSupplier, but all the other lambdas which get created by "junit-jupiter-api" and maybe even the rest of the JUnit Platform as well that cause this performance degradation.

As someone independent of the JUnit 5 team, and from what I've observed so far of Java 8 and the JUnit Platform, it sounds like a worthwhile effort to me to reduce internal lambda usage as much as reasonable to attempt to speed things up. :)

sbrannen commented 6 years ago

@karayv, thanks for raising the issue!

And thanks for providing the quick-n-dirty benchmark.

sbrannen commented 6 years ago

I did some quick-n-dirty benchmarking of my own (with a simple for-loop with 1000 iterations), and my empirical results demonstrate that JUnit Jupiter's assertTrue(boolean) is on average 1ms slower than JUnit 4's assertTrue(boolean), which is IMHO negligible.

Thus, in order for the team to take any action in this regard, we really need to have some realistic benchmarks that demonstrate a significant performance degradation -- for example, using JMH.

@junit-team/junit-lambda, thoughts?

sbrannen commented 6 years ago

Tentatively slated for 5.1 RC1 in order for the team and community to investigate further prior to the 5.1 GA release.

sbrannen commented 6 years ago

Accidentally I found out that JUnit 5.0.3 assertion (assertTrue) worked significantly slower comparing to JUnit 4.12.

@karayv, can you please share with us how you accidentally discovered this?

karayv commented 6 years ago

@sbrannen Sure, I totally understand your concern, since JUnit probably in 99.9% times not used as a stress tool.

Regarding my discover. I saw a presentation where a presenter was claiming Spring DI is slow. I'm working on performance critical project and we are using Spring, so I wanted to check by myself. I created a module with a test which called a service billion square times, and my IDE was showing the time of run was 2.5 sec. By default my IDE creates modules with JUnit4. To get more accurate results I wanted to repeat the test, and I thought that JUnit5's @RepeatedTest should be handy. So keeping the code the same I switched to JUnit5 and was surprised the test had never been finished.

Regarding benchmarking probably you right and the project needs it in different way. Here I had no intention to measure JUnit5 performance. I just wanted to understand how different it is from JUnit4. Specifically here I believe the problem is not in numbers. JUnit5 creates new objects (lambdas) where it may be avoided. The non-lambda parameters are already evaluated so there is no need to wrap them in new lambda.

I saw you comment on my end-of-the-day super fast pull request, and I believe you're totally right. I'l try to review what you have and figure out how I can help.

I think what you are doing guys is great! And I would be super happy to contribute to JUnit5.

sbrannen commented 6 years ago

So keeping the code the same I switched to JUnit5 and was surprised the test had never been finished.

Well, that likely has nothing to do with the fact that JUnit Jupiter's assertTrue() might be slower than JUnit 4's. Rather, the fact that the tests never finished is that you had:

So the latter probably just overwhelmed the heap and your IDE which was trying to populate a GUI with those billion square times tests.

karayv commented 6 years ago

@sbrannen this is how I discovered that there is an issue. Than appeared the module above (https://github.com/karayv/junit-perf-demo) for investigation. The repeated test was for 10 times (@RepeatedTest(10)), not for billion^2. In my later test I put both JUnits in exactly same conditions with all corresponding annotations. Basically for every run the load doubles twice (x4) every time it's executed. When the execution takes more than a second the test stops. Level of load in the above reports means how many times the load was twice-doubled. JUnit5 reached 17, old JUnit - 29.

The full code looks like this:

public class TestRunner {
    private Duration printThreshhold = Duration.ofMillis(100);
    private Duration stopThreshhold = Duration.ofMillis(1000);

    private Library service = new Library();

    public void go(Consumer<Boolean> assertTrue) {
        Duration duration = Duration.ZERO;

        for (int levelOfLoad = 5; stopThreshhold.compareTo(duration) > 0; levelOfLoad++) {
            int load = 1 << levelOfLoad;

            // run the check
            long start = System.currentTimeMillis();
            for (int i1 = 0; i1 < load; i1++) {
                for (int i2 = 0; i2 < load; i2++) {
                    assertTrue.accept(service.sum2(i1, i2) >= 0);
                }
            }
            duration = Duration.ofMillis(System.currentTimeMillis() - start);

            if (duration.compareTo(printThreshhold) > 0) {
                System.out.printf("Level of load: %d, duration: %s, number of operations: %d\n", levelOfLoad, duration,
                        (long) load * load);
            }
        }
    }
}
sbrannen commented 6 years ago

My intuition on this is that it's not just BooleanSupplier, but all the other lambdas which get created by "junit-jupiter-api" and maybe even the rest of the JUnit Platform as well that cause this performance degradation.

@jbduncan, in this case it is in fact just the creation of the BooleanSupplier. There is zero other code from JUnit Jupiter or the JUnit Platform that comes into play in his benchmark.

sbrannen commented 6 years ago

This has been addressed in master in the following commits:

sbrannen commented 6 years ago

In case anyone is interested, running the following against master:

public class AssertTrueComparisons {

    private static final int ITERATIONS = 1_000_000_000;

    public static void main(String[] args) {
        junit4();
        jupiter();
        junit4();
        jupiter();
    }

    private static void junit4() {
        long startTime = System.currentTimeMillis();
        for (int i = 0; i < ITERATIONS; i++) {
            org.junit.Assert.assertTrue(i < ITERATIONS);
        }
        long duration = System.currentTimeMillis() - startTime;
        System.err.println(String.format("JUnit 4 took %s ms.", duration));
    }

    private static void jupiter() {
        long startTime = System.currentTimeMillis();
        for (int i = 0; i < ITERATIONS; i++) {
            org.junit.jupiter.api.Assertions.assertTrue(i < ITERATIONS);
        }
        long duration = System.currentTimeMillis() - startTime;
        System.err.println(String.format("Jupiter took %s ms.", duration));
    }

}

Results in something similar to the following:

JUnit 4 took 23 ms.
Jupiter took 14 ms.
JUnit 4 took 2 ms.
Jupiter took 0 ms.

So it would appear that JUnit Jupiter is now actually faster than JUnit 4 (for a basic assertTrue(boolean) invocation)... until the JIT improves the performance of JUnit 4. 😉

sbrannen commented 6 years ago

But take that with a grain of salt: it's not a benchmark.

In any case, I'd say the two are comparable now.