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

Fri May 21 01:46:34 UTC 2021

On Thu, 20 May 2021 14:24:43 GMT, Thomas Schatzl <tschatzl at openjdk.org> wrote:

> 
> Can you
> 
> * give information about the hardware and environment used. I suspect you are running on different, much slower hardware (mine is already like 7 year old now, and wasn't top-of-the-line then), and concurrent cycles can't keep up. However it is strange anyway because the resulting full gc should clean up any garbage. So something else idk about might kick in.

I don't think the OOME is due to slow hardware since there are the same OOMEs even on our most powerful x86 cpus.

> * without MaxRAMPercentage and look if `Max memory: 132120576` in the log changes?

- Without MaxRAMPercentage=0

REASON: User specified action: run main/othervm gc.gctests.StringInternGC.StringInternGC
TIME:   123.516 seconds
messages:
command: main gc.gctests.StringInternGC.StringInternGC
reason: User specified action: run main/othervm gc.gctests.StringInternGC.StringInternGC
Mode: othervm [/othervm specified]
elapsed time (seconds): 123.516
configuration:
STDOUT:
[0.002s][info][gc] Using G1
Stress time: 120 seconds
Stress iterations factor: 1
Stress threads factor: 1
Stress runs factor: 1
Max memory: 32178700288
Sleep time: 500
Iterations: 0
Number of threads: 192
Run GC thread: false
Run mem diag thread: false
Run forever: false

- With MaxRAMPercentage=0

command: main -XX:MaxRAMPercentage=0 gc.gctests.StringInternGC.StringInternGC
reason: User specified action: run main/othervm -XX:MaxRAMPercentage=0 gc.gctests.StringInternGC.StringInternGC
Mode: othervm [/othervm specified]
elapsed time (seconds): 120.177
configuration:
STDOUT:
[0.002s][info][gc] Using G1
Stress time: 120 seconds
Stress iterations factor: 1
Stress threads factor: 1
Stress runs factor: 1
Max memory: 132120576
Sleep time: 500
Iterations: 0
Number of threads: 4
Run GC thread: false
Run mem diag thread: false
Run forever: false

> * run with `-Xlog:gc` and provide a log snippet of the last few gc invocations?
> 

[119.838s][info][gc] GC(20059) Concurrent Mark Cycle
[119.852s][info][gc] GC(20059) Pause Remark 95M->95M(126M) 0.480ms
[119.853s][info][gc] GC(20060) Pause Young (Normal) (G1 Humongous Allocation) 101M->77M(126M) 0.411ms
[119.855s][info][gc] GC(20059) Pause Cleanup 89M->89M(126M) 0.043ms
[119.855s][info][gc] GC(20059) Concurrent Mark Cycle 17.554ms
[119.872s][info][gc] GC(20061) Pause Young (Concurrent Start) (G1 Humongous Allocation) 89M->77M(126M) 0.456ms
[119.872s][info][gc] GC(20062) Concurrent Mark Cycle
[119.886s][info][gc] GC(20062) Pause Remark 95M->95M(126M) 0.489ms
[119.887s][info][gc] GC(20063) Pause Young (Normal) (G1 Humongous Allocation) 101M->77M(126M) 0.433ms
[119.889s][info][gc] GC(20062) Pause Cleanup 89M->89M(126M) 0.041ms
[119.890s][info][gc] GC(20062) Concurrent Mark Cycle 17.454ms
[119.901s][info][gc] GC(20064) Pause Young (Concurrent Start) (G1 Humongous Allocation) 89M->77M(126M) 0.479ms
[119.901s][info][gc] GC(20065) Concurrent Mark Cycle
[119.915s][info][gc] GC(20065) Pause Remark 95M->95M(126M) 0.418ms
[119.916s][info][gc] GC(20066) Pause Young (Normal) (G1 Humongous Allocation) 101M->77M(126M) 0.403ms
[119.919s][info][gc] GC(20065) Pause Cleanup 89M->89M(126M) 0.035ms
[119.919s][info][gc] GC(20065) Concurrent Mark Cycle 17.408ms
[119.930s][info][gc] GC(20067) Pause Young (Concurrent Start) (G1 Humongous Allocation) 89M->77M(126M) 0.496ms
[119.930s][info][gc] GC(20068) Concurrent Mark Cycle
[119.944s][info][gc] GC(20068) Pause Remark 95M->95M(126M) 0.405ms
[119.945s][info][gc] GC(20069) Pause Young (Normal) (G1 Humongous Allocation) 101M->77M(126M) 0.436ms
[119.948s][info][gc] GC(20068) Pause Cleanup 89M->89M(126M) 0.046ms
[119.948s][info][gc] GC(20068) Concurrent Mark Cycle 17.422ms
[119.960s][info][gc] GC(20070) Pause Young (Concurrent Start) (G1 Humongous Allocation) 89M->77M(126M) 0.460ms
[119.960s][info][gc] GC(20071) Concurrent Mark Cycle
[119.979s][info][gc] GC(20071) Pause Remark 95M->95M(126M) 0.449ms
[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)

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

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