JDK-8210040 : [TESTBUG] TestOptionsWithRanges is very slow
  • Type: Bug
  • Component: hotspot
  • Sub-Component: runtime
  • Priority: P2
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2018-08-28
  • Updated: 2019-10-15
  • Resolved: 2018-08-29
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 11 JDK 12
11.0.3Fixed 12 b09Fixed
Related Reports
Blocks :  
Relates :  
Description
In our continuous testing environment, runtime/CommandLine/OptionsValidation/TestOptionsWithRanges takes a very long time to execute, often taking up to an hour of wall clock time.

The test executes about 1625 child JVM processes in fastdebug builds. Each process tries to trigger GC:

        createWeakRef();
        do {
            garbage = new byte[8192];
            i++;
            /* Initiate GC after 5 iterations */
            if (i > 5) {
                System.gc();
            }
        } while(weakRef.get() != null);

The main problem is the execution time of each child process is highly dependent on the heap size, which by default scales according to the physical RAM size of the test host.

On my machine with 64GB ram, the test runs extremely slowly and times out after an hour.

The fix is to specify a small heap size when spawning the child JVM processes. With -Xmx1024m, the total run time of fastproduct is reduced to about 7 minutes on my machine.

Also, -XX:-ZapUnusedHeapArea should be specified for fastdebug VMs. Otherwise some GCs such as CMS will spend lots of time filling the heap with junk (which might be useful for some GC tests, but it's really unnecessary for this test).
Comments
approved subject to review
07-11-2018

Fix Request I would like to downport this test fix. It speeds up this test nicely. I also requested downporting 8210043 as that is a prerequisite. Unfortunately the patch does not apply cleanly. A line in the context changed ("@bug 8205633" was added). Besides resolving the conflict, no changes are required. I sent RFR for the resolved change: http://mail.openjdk.java.net/pipermail/jdk-updates-dev/2018-November/000282.html
07-11-2018

See optval.tar.gz in the attachment. You can use it to see how fast (or slow) TestOptionsWithRanges runs with different command-line args. Here's a run with my fastdebug VM on my machine with 64GB RAM and 32 logical cores: [OK speed] $ time bash doit.sh "$JAVA -Xmx1024m -XX:-ZapUnusedHeapArea" < fd.opts.list 1 0:00.87 -server -XX:+UseConcMarkSweepGC -XX:CMSAbortablePrecleanMinWorkPerIteration=0 optionsvalidation.JVMStartup 2 0:00.37 -server -XX:+UseConcMarkSweepGC -XX:CMSAbortablePrecleanMinWorkPerIteration=18446744073709551615 optionsvalidation.JVMStartup 3 0:00.51 -server -XX:+UseConcMarkSweepGC -XX:CMSAbortablePrecleanMinWorkPerIteration=1 optionsvalidation.JVMStartup 4 0:00.38 -server -XX:+UseConcMarkSweepGC -XX:CMSAbortablePrecleanMinWorkPerIteration=2147483648 optionsvalidation.JVMStartup .... 1624 0:00.48 -server -XX:+UseSerialGC -XX:NewSizeThreadIncrease=2147483648 optionsvalidation.JVMStartup 1625 0:00.56 -server -XX:+UseSerialGC -XX:NewSizeThreadIncrease=4294967296 optionsvalidation.JVMStartup real 7m11.864s user 6m44.492s sys 4m24.768s [very slow] time bash doit.sh "$JAVA -XX:-ZapUnusedHeapArea" < fd.opts.list 1 0:00.66 -server -XX:+UseConcMarkSweepGC -XX:CMSAbortablePrecleanMinWorkPerIteration=0 optionsvalidation.JVMStartup 2 0:07.14 -server -XX:+UseConcMarkSweepGC -XX:CMSAbortablePrecleanMinWorkPerIteration=18446744073709551615 optionsvalidation.JVMStartup 3 0:01.16 -server -XX:+UseConcMarkSweepGC -XX:CMSAbortablePrecleanMinWorkPerIteration=1 optionsvalidation.JVMStartup 4 0:07.19 -server -XX:+UseConcMarkSweepGC -XX:CMSAbortablePrecleanMinWorkPerIteration=2147483648 optionsvalidation.JVMStartup ^C [extremely slow] $ time bash doit.sh "$JAVA" < fd.opts.list 1 0:33.92 -server -XX:+UseConcMarkSweepGC -XX:CMSAbortablePrecleanMinWorkPerIteration=0 optionsvalidation.JVMStartup 2 0:02.63 -server -XX:+UseConcMarkSweepGC -XX:CMSAbortablePrecleanMinWorkPerIteration=18446744073709551615 optionsvalidation.JVMStartup 3 0:37.41 -server -XX:+UseConcMarkSweepGC -XX:CMSAbortablePrecleanMinWorkPerIteration=1 optionsvalidation.JVMStartup ^C^C^C^C
28-08-2018