Executing large number of dynamic tests results in OutOfMemoryError: GC overhead limit exceeded

[vinayf]

Overview

When trying to run a large number of dynamic tests the framework throws an out of memory error.

For the sake of simplicity, below is a sample test I ran.

import org.junit.jupiter.api.Assertions;
import org.junit.jupiter.api.DynamicNode;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.TestFactory;

import java.util.stream.IntStream;
import java.util.stream.Stream;

import static org.junit.jupiter.api.Assertions.assertEquals;
import static org.junit.jupiter.api.DynamicTest.dynamicTest;

class RunnerTest {

    @TestFactory
    Stream<DynamicNode> dynamicTestPerformance() {
        return IntStream
                .rangeClosed(1, 14_000_000)
                .mapToObj(num -> dynamicTest("Test " + num, () -> {
                    System.out.println("Running Test " + num);
                    assertEquals(num, -1);
                }));
    }
}

I have run this using both ConsoleLauncher and maven-surefire-plugin 2.21.0, but both approaches give the same problem. Below is the error.

Running Test 1019735
Running Test 1019736
Running Test 1019737
Jun 04, 2018 3:28:25 PM org.junit.platform.launcher.core.DefaultLauncher handleThrowable
WARNING: TestEngine with ID 'junit-jupiter' failed to execute tests
java.lang.OutOfMemoryError: GC overhead limit exceeded
	at java.util.Arrays.copyOfRange(Arrays.java:3664)
	at java.lang.String.<init>(String.java:207)
	at java.lang.StringBuilder.toString(StringBuilder.java:407)
	at org.junit.platform.engine.UniqueIdFormat.encode(UniqueIdFormat.java:148)
	at org.junit.platform.engine.UniqueIdFormat.describe(UniqueIdFormat.java:134)
	at org.junit.platform.engine.UniqueIdFormat$$Lambda$153/459296537.apply(Unknown Source)
	at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:193)
	at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1380)
	at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:481)
	at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471)
	at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:708)
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
	at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:499)
	at org.junit.platform.engine.UniqueIdFormat.format(UniqueIdFormat.java:129)
	at org.junit.platform.engine.UniqueId.toString(UniqueId.java:205)
	at org.junit.platform.launcher.TestIdentifier.from(TestIdentifier.java:57)
	at org.junit.platform.launcher.core.ExecutionListenerAdapter.dynamicTestRegistered(ExecutionListenerAdapter.java:39)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor$NodeExecutor.lambda$executeRecursively$0(HierarchicalTestExecutor.java:114)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor$NodeExecutor$$Lambda$170/701141022.execute(Unknown Source)
	at org.junit.jupiter.engine.descriptor.TestFactoryTestDescriptor$$Lambda$216/133250414.accept(Unknown Source)
	at java.util.Optional.ifPresent(Optional.java:159)
	at org.junit.jupiter.engine.descriptor.TestFactoryTestDescriptor.lambda$invokeTestMethod$1(TestFactoryTestDescriptor.java:92)
	at org.junit.jupiter.engine.descriptor.TestFactoryTestDescriptor$$Lambda$210/1730173572.execute(Unknown Source)
	at org.junit.jupiter.engine.execution.ThrowableCollector.execute(ThrowableCollector.java:40)
	at org.junit.jupiter.engine.descriptor.TestFactoryTestDescriptor.invokeTestMethod(TestFactoryTestDescriptor.java:79)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:113)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:58)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor$NodeExecutor.lambda$executeRecursively$3(HierarchicalTestExecutor.java:113)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor$NodeExecutor$$Lambda$169/1268066861.execute(Unknown Source)
	at org.junit.platform.engine.support.hierarchical.SingleTestExecutor.executeSafely(SingleTestExecutor.java:66)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor$NodeExecutor.executeRecursively(HierarchicalTestExecutor.java:108)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor$NodeExecutor.execute(HierarchicalTestExecutor.java:79)

Versions

• JUnit 5.2.0
• maven-surefire-plugin 2.21.0

Use Case

I am writing a small application to find and report differences between two databases and am generating a dynamic test for each db row for comparison.

[sbrannen]

Related Stack Overflow thread: https://stackoverflow.com/questions/50629005/java-gc-overhead-limit-error-using-junit-5-testfactory-with-large-stream-of-dyna

[sbrannen]

Thanks for verifying that you encounter similar behavior with the ConsoleLauncher in addition to with Maven.

We'll look into it.

[sbrannen]

Tentatively assigned to the 5.3 backlog for team discussion

[sbrannen]

Before we investigate, could you please tell us the memory and GC configuration you are using to launch the JVM when executing these tests?

[vinayf]

-XX:InitialHeapSize=268435456 -XX:MaxHeapSize=4294967296 -XX:+PrintCommandLineFlags -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC

[gaganis]

I have tried running the provided test code on the current master and my conclusion is that trying to run such number of tests is expected for the platform to run out of memory.

The platform is storing all generated TestIdentifier instances(ie the information about each test) and also -for failing tests- the AssertionFailedError instances(ie all information about how a specific test failed). Both hold a plethora of useful information that is later used for printing the results, creating test reports etc.

So I have done 2 things

a) investigated a heap dump using visualvm to see if we are keeping references to information that we no longer need, or intermediate computations but was not able to find anything to suggest a 'memory leak'

b) run the dynamic tests to see whether we have an effectively constant memory need for each dynamic test or if we grow non-linearly. My results suggest the memory need for each dynamic test is effectively constant.

Here are my results:

Heap Size(MB)	# of failing tests before OOME	avg bytes per test	# of succeeding tests before OOME	avg bytes per test
100	34186	3067	85511	1226
200	68959	3041	173537	1208
300	103098	3051	261282	1204
500	174421	3006	437588	1198
700	243840	3010	621225	1182
1000	351321	2985	882458	1188
1300	455214	2995	1158260	1177
1600	561879	2986	1431362	1172
2000	705124	2974	1768683	1186
2400	841884	2989	2131622	1181
3000	1056497	2978	2681563	1173
3600	1268773	2975	3145728	1200
4048	1428356	2972	3578920	1186

If we actually need/want to support unlimited number of tests then the current 2-step model of 1) running and storing all the information and 2) process the stored results will always cause the platform to eventually run out of memory.

@junit-team/junit-lambda Have you guys pondered on this issue before?

[marcphilipp]

@gaganis Thanks for the excellent analysis! We'll discuss this issue in the team. I think there's certainly room for improvement but I don't see us moving away from the 2-step model.

[gaganis]

One thing that stood out to me while I was looking into this, is how verbose the uniqueIds are for this case in TestIdentifier.

And we also keep both the id and the parentId they do take up quite a few bytes.

An example identifier from the example contains these:

uniqueId = "[engine:junit-jupiter]/[class:com.example.project.RunnerTest]/[test-factory:dynamicTestPerformance()]/[dynamic-test:#67602]"
parentId = "[engine:junit-jupiter]/[class:com.example.project.RunnerTest]/[test-factory:dynamicTestPerformance()]"

So these in Java 9 with compacted strings these would require almost a quarter of a KB and almost half a KB in Java 8(without compaction).

This identifier format is very practical from a human readability perspective and it could also be parseable.

If the format of these ids is purely internal to the platform and is not used/expected by other tools then we could examine if it would make sense to adopt a sorter form.

[sbrannen]

Base 64 encoding? 😝

[sbrannen]

All kidding aside, when the issue was first raised I actually assumed the combined tracking of all test identifiers and test descriptors could be one of the culprits.

[sbrannen]

investigated a heap dump using visualvm to see if we are keeping references to information that we no longer need, or intermediate computations but was not able to find anything to suggest a 'memory leak'

Out of curiosity, did you see anything alarming with regard to annotation caching in org.junit.platform.commons.util.AnnotationUtils.annotationCache?

I'd be interested in knowing if that causes any issues, especially since that cache is currently unbounded.

[sbrannen]

Oh wait... the annotation cache could never be an issue if all that's run are dynamic tests.

We'd need an actual, realistic, large test suite to see any issues there. 😉

[gaganis]

Out of curiosity, did you see anything alarming with regard to annotation caching in org.junit.platform.commons.util.AnnotationUtils.annotationCache?

I saw no issues there :)

I'd be interested in knowing if that causes any issues.

I can see why you are worried after taking a look at the code. This cache has no size limit. :)

[sbrannen]

Mmmmmm... I've always pondered converting that to a bounded cache with an LRU eviction policy (like I did with the application context caching in the Spring TestContext Framework).

Maybe I really should do that. 🤔

[sbrannen]

Voila!

#1459

[vlsi]

@marcphilipp , do you think something like not reporting every invocation separately could be merged to junit5?

I see you don't want to maintain property-based testing solution, however, it does sound weird that jqwik is a full-blown test engine. For instance, they have to duplicate the implementation for @Disabled and so on.

It would be nice if property-based testing could be integrated with junit5 execution engine via an external extension.
WDYT?

It looks like the ability to selectively disable storing of all the individual results would be beneficial for both regular JUnit5 users (== avoid storing individual TestDescriptors), and it would enable creating property-based tests via extensions.

see jqwik-team/jqwik#84
/cc @jlink

[marcphilipp]

I'd be okay with adding an option to TestTemplateInvocationContextProvider to not report individual invocations.

[marcphilipp]

I created a draft PR with a bunch of improvements. /cc @ben-manes

[jbduncan]

I'm not sure why, but I find the result of this exciting! Great work, @marcphilipp. 👏

[marcphilipp]

Thanks! 😊

[mindhaq]

Wow, really great work!

As a former colleague of @vinayf I can really appreciate that, even though the project where we came up with it is a thing of the past.