RFR: 8267311: vmTestbase/gc/gctests/StringInternGC/StringInternGC.java fails when JTREG_JOBS > 25

Jie Fu jiefu at openjdk.java.net
Fri May 21 08:59:30 UTC 2021


On Fri, 21 May 2021 08:12:09 GMT, Thomas Schatzl <tschatzl at openjdk.org> wrote:

>> Hi all,
>> 
>> vmTestbase/gc/gctests/StringInternGC/StringInternGC.java fails with release VM on our many-core machines due to `-XX:MaxRAMPercentage=0`.
>> This is because `-XX:MaxRAMPercentage=0` will be 0 if JTREG_JOBS > 25 [1].
>> 
>> Reproduce:
>>  - make test TEST="vmTestbase/gc/gctests/StringInternGC/StringInternGC.java" JTREG="JOBS=26" CONF=server-release
>> 
>> `-Xmx1g` is added to make it more robust.
>> Note: we still see failure with `-Xmx512m`.
>> 
>> Thanks.
>> Best regards,
>> Jie
>> 
>> [1] https://github.com/openjdk/jdk/blob/master/make/RunTests.gmk#L741
>
> ```[119.980s][info][gc] GC(20072) Pause Young (Normal) (G1 Humongous Allocation) 101M->77M(126M) 0.404ms
> [119.982s][info][gc] GC(20071) Pause Cleanup 89M->89M(126M) 0.039ms
> [119.982s][info][gc] GC(20071) Concurrent Mark Cycle 22.748ms
> [119.994s][info][gc] GC(20073) Pause Young (Concurrent Start) (G1 Humongous Allocation) 89M->77M(126M) 0.479ms
> [119.994s][info][gc] GC(20074) Concurrent Mark Cycle
> [120.008s][info][gc] GC(20074) Pause Remark 95M->95M(126M) 0.449ms
> [120.009s][info][gc] GC(20075) Pause Young (Normal) (G1 Humongous Allocation) 101M->77M(126M) 0.397ms
> [120.011s][info][gc] GC(20074) Pause Cleanup 89M->89M(126M) 0.047ms
> [120.012s][info][gc] GC(20074) Concurrent Mark Cycle 17.564ms
> [120.023s][info][gc] GC(20076) Pause Young (Concurrent Start) (G1 Humongous Allocation) 89M->77M(126M) 0.475ms
> [120.023s][info][gc] GC(20077) Concurrent Mark Cycle
> [120.037s][info][gc] GC(20077) Pause Remark 95M->95M(126M) 0.455ms
> [120.038s][info][gc] GC(20078) Pause Young (Normal) (G1 Humongous Allocation) 101M->77M(126M) 0.387ms
> [120.040s][info][gc] GC(20077) Pause Cleanup 89M->89M(126M) 0.047ms
> [120.041s][info][gc] GC(20077) Concurrent Mark Cycle 17.251ms
> [120.052s][info][gc] GC(20079) Pause Young (Concurrent Start) (G1 Humongous Allocation) 89M->77M(126M) 0.463ms
> [120.052s][info][gc] GC(20080) Concurrent Mark Cycle
> [120.066s][info][gc] GC(20080) Pause Remark 95M->95M(126M) 0.464ms
> [120.066s][info][gc] GC(20080) Pause Cleanup 95M->95M(126M) 0.038ms
> [120.066s][info][gc] GC(20080) Concurrent Mark Cycle 13.945ms
> Failures summary:
> java.lang.OutOfMemoryError: Java heap space
> java.lang.OutOfMemoryError: Java heap space
>         at java.base/java.util.Arrays.copyOfRange(Arrays.java:3821)
>         at java.base/java.lang.StringUTF16.newString(StringUTF16.java:1179)
>         at java.base/java.lang.StringBuffer.toString(StringBuffer.java:712)
>         at gc.gctests.StringInternGC.StringInternGC$StringGenerator.generateString(StringInternGC.java:58)
>         at gc.gctests.StringInternGC.StringInternGC$StringGenerator.run(StringInternGC.java:63)
>         at nsk.share.runner.ThreadsRunner$ManagedThread.run(ThreadsRunner.java:106)
>         at java.base/java.lang.Thread.run(Thread.java:831)```
> 
> The question that comes immediately to my mind here:
> * where's the full gc to try to compact the heap?
> * and after looking at the test, I think it is pretty dumb. The test code is like:
> 
> ```public class StringInternGC extends ThreadedGCTest {
>         private int maxLength = 1000;
> 
>         private class StringGenerator implements Runnable {
>                 private StringBuffer sb = new StringBuffer();
> 
>                 private String generateString() {
>                         int length = LocalRandom.nextInt(maxLength);
>                         for (int i = 0; i < length; ++i)
>                                 sb.append((char) LocalRandom.nextInt(Integer.MAX_VALUE));
>                         return sb.toString();
>                 }
> 
> 
>                 public void run() {
>                         generateString().intern();
>                 }
>         }
> 
> 
> The test infinitely expands the original string instead of at least at some point cutting it off. Particularly if you've got a fast machine, it might extend it to be larger than any heap, and that is probably why the test just errors out without a GC at some point. This also explains why it only occurs with a release build at your place.
> 
> Please fix the test instead of working around the issue until next time we have to expand its -Xmx. Something like resetting the string after it reached a particular size (e.g. 128kb) should be enough to generate lots of unique strings.
> 
> Something like this:
> ```@@ -46,13 +46,17 @@ import nsk.share.gc.*;
>   * String pool should not overflow.
>   */
>  public class StringInternGC extends ThreadedGCTest {
> -        private int maxLength = 1000;
> +        private int maxLength = 1000; // Maximum length to add per operation.
> +        private int maxTotalLength = 128 * 1024; // Random total maximum length of the string.
>  
>          private class StringGenerator implements Runnable {
>                  private StringBuffer sb = new StringBuffer();
>  
>                  private String generateString() {
>                          int length = LocalRandom.nextInt(maxLength);
> +                        if (sb.length() > maxTotalLength) {
> +                          sb = new StringBuffer();
> +                        }
>                          for (int i = 0; i < length; ++i)
>                                  sb.append((char) LocalRandom.nextInt(Integer.MAX_VALUE));
>                          return sb.toString();
> 
> 
> Voilà, all problems gone afaict - only young-only gcs, and afaict the string table is still highly stressed with unique strings :-) What I'm not completely sure is whether causing some string table unloading (via concurrent mark, full gc) in the original test is supposed to occur. To not only stress addition of strings to the string table, but also removal. This could be added by "regular" forced (concurrent) string table unloading (not happening right now with this change).
> 
> If you agree that this fixes this problem, please change the CR title to match the problem ("StringInternGC eventually OOMEs" or so) and let's get the test fixed, not working around the problem.
> 
> I still think there is some bug in the script to let `MaxRAMPercentage` go down to zero, to be filed separately as mentioned before.

Hi @tschatzl ,

Got it.
Thanks for your nice analysis.

> If you agree that this fixes this problem, please change the CR title to match the problem ("StringInternGC eventually OOMEs" or so) and let's get the test fixed, not working around the problem.

Yes, I agree.
I tested your patch and the OOME disappeared on our machine.

> I still think there is some bug in the script to let `MaxRAMPercentage` go down to zero, to be filed separately as mentioned before.

Yes, this bug has been fixed by https://github.com/openjdk/jdk/pull/4062

Thanks.
Best regards,
Jie

-------------

PR: https://git.openjdk.java.net/jdk/pull/4086



More information about the hotspot-gc-dev mailing list