search

eclipse-openj9 / openj9

Eclipse OpenJ9: A Java Virtual Machine for OpenJDK that's optimized for small footprint, fast start-up, and high throughput. Builds on Eclipse OMR (https://github.com/eclipse/omr) and combines with the Extensions for OpenJDK for OpenJ9 repo.
Other
3.27k stars 720 forks source link

j9vm.test.arraylets.ArrayletAllocateTest OOM #9969

Open pshipton opened 4 years ago

pshipton commented 4 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_sanity.functional_s390x_linux_OMR_testList_1/22 J9vmTest_4

+++ j9vm.test.arraylets.ArrayletAllocateTest: +++
command: /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_OMR_testList_1/openjdkbinary/j2sdk-image/bin/java  -XX:+UseCompressedOops -Xjit -Xgcpolicy:balanced  -Xdump -Xms65m -Xmx65m  -Xdisableexcessivegc  -Xbootclasspath:/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_OMR_testList_1/openjdkbinary/j2sdk-image/jre/lib/s390x/compressedrefs/jclSC180/vm.jar:/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_OMR_testList_1/openjdkbinary/j2sdk-image/jre/lib/se-service.jar:/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_OMR_testList_1/openjdkbinary/j2sdk-image/jre/lib/rt.jar:/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_OMR_testList_1/openjdkbinary/j2sdk-image/jre/lib/resources.jar:/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_OMR_testList_1/openjdkbinary/j2sdk-image/jre/lib/jsse.jar:/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_OMR_testList_1/openjdkbinary/j2sdk-image/jre/lib/charsets.jar:/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_OMR_testList_1/openjdkbinary/j2sdk-image/jre/lib/jce.jar -classpath /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_OMR_testList_1/openjdk-tests/TKG/../../jvmtest/functional/VM_Test/VM_Test.jar:/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_OMR_testList_1/openjdk-tests/TKG/../TKG/lib/asm-all.jar  j9vm.test.arraylets.ArrayletAllocateTest 

Testing array allocation...
    Testing arrays from 1 to 32...
    Testing arrays from 32 to 64...
    Testing arrays from 96 to 128...
    Testing arrays from 224 to 256...
    Testing arrays from 480 to 512...
    Testing arrays from 992 to 1024...
    Testing arrays from 2016 to 2048...
    Testing arrays from 4064 to 4096...
    Testing arrays from 8160 to 8192...
    Testing arrays from 16352 to 16384...
    Testing arrays from 32736 to 32768...
    Testing arrays from 65504 to 65536...
    Testing arrays from 131040 to 131072...
    Testing arrays from 262112 to 262144...
    Testing arrays from 524256 to 524288...
    Testing arrays from 1048544 to 1048576...
    Testing arrays from 2097120 to 2097152...
    Testing arrays from 4194272 to 4194304...
Array allocation tests passed.
Testing hashed array allocation and growth...
    Testing arrays from 1 to 32...
    Testing arrays from 32 to 64...
    Testing arrays from 96 to 128...
    Testing arrays from 224 to 256...
    Testing arrays from 480 to 512...
    Testing arrays from 992 to 1024...
    Testing arrays from 2016 to 2048...
    Testing arrays from 4064 to 4096...
    Testing arrays from 8160 to 8192...
    Testing arrays from 16352 to 16384...
    Testing arrays from 32736 to 32768...
    Testing arrays from 65504 to 65536...
    Testing arrays from 131040 to 131072...
    Testing arrays from 262112 to 262144...
    Testing arrays from 524256 to 524288...
    Testing arrays from 1048544 to 1048576...
    Testing arrays from 2097120 to 2097152...
JVMDUMP039I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" at 2020/06/19 20:56:19 - please wait.
pshipton commented 4 years ago

@dmitripivkine can you pls take a look.

dmitripivkine commented 4 years ago

O-slot in JIT frame kept large Arraylet alive unnecessary so there is no room left:

<169af00> JIT frame: bp = 0x0000000001758CD8, pc = 0x000003FF7BBA1DAC, unwindSP = 0x0000000001758C40, cp = 0x00000000017D2460, arg0EA = 0x0000000001758CE0, jitInfo = 0x000003FF7968EE78
<169af00>   Method: j9vm/test/arraylets/ArrayletAllocateTest.main([Ljava/lang/String;)V !j9method 0x00000000017D28D0
<169af00>   Bytecode index = 347, inlineDepth = 0, PC offset = 0x00000000000037B2
<169af00>   stackMap=0x000003FF7968F363, slots=I16(0x0001) parmBaseOffset=I16(0x0010), parmSlots=U16(0x0000), localBaseOffset=I16(0xFFF8)
<169af00>   Described JIT temps starting at 0x0000000001758CD0 for IDATA(0x0000000000000001) slots
<169af00>       O-Slot: : t0[0x0000000001758CD0] = 0x000000000F1C5FE8 <--- problematic slot
<169af00>   JIT-RegisterMap = UDATA(0x0000000000000000)
<169af00>   JIT-Frame-RegisterMap[0x0000000001758C50] = UDATA(0x000000000172E600) (jit_r6)
<169af00>   JIT-Frame-RegisterMap[0x0000000001758C58] = UDATA(0x0000000010E938C0) (jit_r7)
<169af00>   JIT-Frame-RegisterMap[0x0000000001758C60] = UDATA(0x0000000010E9A548) (jit_r8)
<169af00>   JIT-Frame-RegisterMap[0x0000000001758C68] = UDATA(0x000000000169AF00) (jit_r9)
<169af00>   JIT-Frame-RegisterMap[0x0000000001758C70] = UDATA(0x0000000010E96540) (jit_r10)
<169af00>   JIT-Frame-RegisterMap[0x0000000001758C78] = UDATA(0x0000000000000000) (jit_r11)

<169af00>   JIT-Frame-RegisterMap[0x0000000001758C80] = UDATA(0x0000000000000000) (jit_r12)
<169af00> I2J values: PC = 0x000003FF92214BDA, A0 = 0x0000000001758D10, walkSP = 0x0000000001758CF0, literals = 0x0000000000000000, JIT PC = 0x000003FF91062730, pcAddress = 0x000003FF92AFE950, decomp = 0x0000000000000000

> !j9object 0x000000000F1C5FE8
!J9IndexableObject 0x000000000F1C5FE8 {
    struct J9Class* clazz = !j9arrayclass 0x16BC400   // [J
    Object flags = 0x00000000;
    U_32 size = 0x00400000;
    [0] =  1, 0x0000000000000001, 0.00000000F

> !dumpallregions stats
    FREE: 12
    ARRAYLET_LEAF: 114
    BUMP_ALLOCATED: 1
    BUMP_ALLOCATED_MARKED: 3
    ++++ TOTAL: 130

!j9object 0x000000000F1C5FE8 has been used in a previous iteration of the test and not required any more:

    Testing arrays from 2097120 to 2097152...
    Testing arrays from 4194272 to 4194304... <---- object 0xF1C5FE8 was used here
Array allocation tests passed.
Testing hashed array allocation and growth...
    Testing arrays from 1 to 32...

However O-Slot: : t0[0x0000000001758CD0] = 0x000000000F1C5FE8 keeps it alive and does not allow to collect it. This object uses 64 regions of 130 so there is no room left in the heap for test continuation.

dmitripivkine commented 4 years ago

@andrewcraik fyi this transfer to jit

andrewcraik commented 4 years ago

I suspect this is again a liveness issue that might be addressed by -Xjit:enableAggressiveLiveness - if that fixes it is the test valid - do we have to release the memory - there is no requirement to do so as far as I know...

pshipton commented 4 years ago

So should we run all the sanity.functional testing with -Xjit:enableAggressiveLiveness?

pshipton commented 4 years ago

Actually this is a command line test so we could modify just this test to use the option.

dmitripivkine commented 3 years ago

Test source: https://github.com/eclipse/openj9/blob/master/test/functional/VM_Test/src/j9vm/test/arraylets/ArrayletAllocateTest.java

There is accurate bookkeeping for alive Arraylets in the object heap Stats for regions:

    FREE: 12
    ARRAYLET_LEAF: 114
    BUMP_ALLOCATED: 1
    BUMP_ALLOCATED_MARKED: 3
    ++++ TOTAL: 130

So 64 regions taken by Arraylet referred from O-slot:

<169af00>       O-Slot: : t0[0x0000000001758CD0] = 0x000000000F1C5FE8

> !j9object 0x000000000F1C5FE8
!J9IndexableObject 0x000000000F1C5FE8 {
    struct J9Class* clazz = !j9arrayclass 0x16BC400   // [J
    Object flags = 0x00000000;
    U_32 size = 0x00400000;
    [0] =  1, 0x0000000000000001, 0.00000000F

The reminder of 114 - 64 = 50 leaves are kept alive by j9vm/test/arraylets/ArrayletAllocateTest class Statics (please be aware this data is from different core and would not be consistent with data mentioned above but it is irrelevant, picture is the same):

> !j9statics 0x0000000000153D00
Static fields in j9vm/test/arraylets/ArrayletAllocateTest:
    0x0000000000154010 rangeSize I (!j9romstaticfieldshape 0x00003FFFA079CD38) = 0x00000020 (32)
    0x0000000000153FE8 bytes [B (!j9romstaticfieldshape 0x00003FFFA079CD48) = !j9object 0x00000000FFC00038 <--- 4 leaf regions
    0x0000000000153FF0 shorts [S (!j9romstaticfieldshape 0x00003FFFA079CD54) = !j9object 0x00000000FFF80000 <--- 7 leaf regions
    0x0000000000153FF8 ints [I (!j9romstaticfieldshape 0x00003FFFA079CD60) = !j9object 0x00000000FCB80000 <--- 15 leaf regions
    0x0000000000154000 longs [J (!j9romstaticfieldshape 0x00003FFFA079CD6C) = !j9object 0x00000000FFC00060 <--- 16 leaf regions
    0x0000000000154008 objects [Ljava/lang/Object; (!j9romstaticfieldshape 0x00003FFFA079CD78) = !j9object 0x00000000FFC00000 <--- 8 leaf regions
>

> !j9object 0x00000000FFC00038 <--- 4 leaf regions
!J9IndexableObject 0x00000000FFC00038 {
    struct J9Class* clazz = !j9arrayclass 0x35200   // [B
    Object flags = 0x00000008;
    U_32 size = 0x001FFFE0;
    [0] =   1, 0x01
...
}
> !j9object 0x00000000FFF80000 <--- 7 leaf regions + hybrid reminder in spine
!J9IndexableObject 0x00000000FFF80000 {
    struct J9Class* clazz = !j9arrayclass 0x35600   // [S
    Object flags = 0x00000008;
    U_32 size = 0x001FFFE0;
    [0] =      1, 0x0001
...
}
> !j9object 0x00000000FCB80000 <--- 15 leaf regions + hybrid reminder in spine
!J9IndexableObject 0x00000000FCB80000 {
    struct J9Class* clazz = !j9arrayclass 0x35A00   // [I
    Object flags = 0x00000008;
    U_32 size = 0x001FFFE0; 
    [0] =          1, 0x00000001, 0.00000000F
...
}
> !j9object 0x00000000FFC00060 <--- 16 leaf regions
!J9IndexableObject 0x00000000FFC00060 {
    struct J9Class* clazz = !j9arrayclass 0x35E00   // [J
    Object flags = 0x0000000A;
    U_32 size = 0x00100000;
    [0] =  1, 0x0000000000000001, 0.00000000F
...
}
> !j9object 0x00000000FFC00000 <--- 8 leaf regions
!J9IndexableObject 0x00000000FFC00000 {
    struct J9Class* clazz = !j9arrayclass 0x45100   // [L
    Object flags = 0x00000018;
    U_32 size = 0x00100000;
    [0] = !fj9object 0xffc17960 = !j9object 0xffc17960
    [1] = null
...
}
>

So total leaves from Statics 4 + 7 + 15 + 16 + 8 = 50, we discovered roots for all alive Arraylets in the object heap.

Again, an Arraylet from O-slot (64) plus five Arraylets from class Statics (4 + 7 + 15 + 16 + 8) = 114 leaves total.

rmnattas commented 3 years ago

The failure doesn't happen anymore. Issue can be closed and reopen if it appears again.

pshipton commented 3 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.functional_s390x_linux_Nightly_testList_1/97 J9vmTest_3 j9vm.test.arraylets.ArrayletAllocateTest

Array allocation tests passed.
Testing hashed array allocation and growth...
    Testing arrays from 1 to 32...
    Testing arrays from 32 to 64...
    Testing arrays from 96 to 128...
    Testing arrays from 224 to 256...
    Testing arrays from 480 to 512...
    Testing arrays from 992 to 1024...
    Testing arrays from 2016 to 2048...
    Testing arrays from 4064 to 4096...
    Testing arrays from 8160 to 8192...
    Testing arrays from 16352 to 16384...
    Testing arrays from 32736 to 32768...
    Testing arrays from 65504 to 65536...
    Testing arrays from 131040 to 131072...
    Testing arrays from 262112 to 262144...
    Testing arrays from 524256 to 524288...
    Testing arrays from 1048544 to 1048576...
    Testing arrays from 2097120 to 2097152...
JVMDUMP039I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" at 2021/09/12 23:25:28 - please wait.
pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.functional_ppc64_aix_Nightly_testList_0/93 - aix71-p8-2 J9vmTest_4

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_sanity.functional_ppc64_aix_Nightly_testList_0/93/functional_test_output.tar.gz

+++ j9vm.test.arraylets.ArrayletAllocateTest: +++
command: /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_ppc64_aix_Nightly_testList_0/openjdkbinary/j2sdk-image/bin/java  -XX:+UseCompressedOops -Xjit -Xgcpolicy:balanced  -Xdump -Xms65m -Xmx65m  -Xdisableexcessivegc   -classpath /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_ppc64_aix_Nightly_testList_0/aqa-tests/TKG/../../jvmtest/functional/VM_Test/VM_Test.jar:/home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_ppc64_aix_Nightly_testList_0/aqa-tests/TKG/../TKG/lib/asm-all.jar  j9vm.test.arraylets.ArrayletAllocateTest 
...
Array allocation tests passed.
Testing hashed array allocation and growth...
    Testing arrays from 1 to 32...
    Testing arrays from 32 to 64...
    Testing arrays from 96 to 128...
    Testing arrays from 224 to 256...
    Testing arrays from 480 to 512...
    Testing arrays from 992 to 1024...
    Testing arrays from 2016 to 2048...
    Testing arrays from 4064 to 4096...
    Testing arrays from 8160 to 8192...
    Testing arrays from 16352 to 16384...
    Testing arrays from 32736 to 32768...
    Testing arrays from 65504 to 65536...
    Testing arrays from 131040 to 131072...
    Testing arrays from 262112 to 262144...
    Testing arrays from 524256 to 524288...
    Testing arrays from 1048544 to 1048576...
    Testing arrays from 2097120 to 2097152...
JVMDUMP039I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" at 2021/11/27 01:30:47 - please wait.
pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.functional_ppc64_aix_Nightly_testList_0/107 - aix71-p8-9 J9vmTest_4

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_sanity.functional_ppc64_aix_Nightly_testList_0/107/functional_test_output.tar.gz

+++ j9vm.test.arraylets.ArrayletAllocateTest: +++
command: /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_ppc64_aix_Nightly_testList_0/openjdkbinary/j2sdk-image/bin/java  -XX:+UseCompressedOops -Xjit -Xgcpolicy:balanced  -Xdump -Xms65m -Xmx65m  -Xdisableexcessivegc   -classpath /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_ppc64_aix_Nightly_testList_0/aqa-tests/TKG/../../jvmtest/functional/VM_Test/VM_Test.jar:/home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_ppc64_aix_Nightly_testList_0/aqa-tests/TKG/../TKG/lib/asm-all.jar  j9vm.test.arraylets.ArrayletAllocateTest 
...
Testing hashed array allocation and growth...
    Testing arrays from 1 to 32...
    Testing arrays from 32 to 64...
    Testing arrays from 96 to 128...
    Testing arrays from 224 to 256...
    Testing arrays from 480 to 512...
    Testing arrays from 992 to 1024...
    Testing arrays from 2016 to 2048...
    Testing arrays from 4064 to 4096...
    Testing arrays from 8160 to 8192...
    Testing arrays from 16352 to 16384...
    Testing arrays from 32736 to 32768...
    Testing arrays from 65504 to 65536...
    Testing arrays from 131040 to 131072...
    Testing arrays from 262112 to 262144...
    Testing arrays from 524256 to 524288...
    Testing arrays from 1048544 to 1048576...
    Testing arrays from 2097120 to 2097152...
JVMDUMP039I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" at 2021/12/09 05:59:29 - please wait.
pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.functional_s390x_linux_OMR_testList_1/192 J9vmTest_4 -XX:+UseCompressedOops -Xjit -Xgcpolicy:balanced

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_sanity.functional_s390x_linux_OMR_testList_1/192/functional_test_output.tar.gz

+++ j9vm.test.arraylets.ArrayletAllocateTest: +++
command: /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_OMR_testList_1/openjdkbinary/j2sdk-image/bin/java  -XX:+UseCompressedOops -Xjit -Xgcpolicy:balanced  -Xdump -Xms65m -Xmx65m  -Xdisableexcessivegc   -classpath /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_OMR_testList_1/aqa-tests/TKG/../../jvmtest/functional/VM_Test/VM_Test.jar:/home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_OMR_testList_1/aqa-tests/TKG/../TKG/lib/asm-all.jar  j9vm.test.arraylets.ArrayletAllocateTest 

Testing array allocation...
    Testing arrays from 1 to 32...
    Testing arrays from 32 to 64...
    Testing arrays from 96 to 128...
    Testing arrays from 224 to 256...
    Testing arrays from 480 to 512...
    Testing arrays from 992 to 1024...
    Testing arrays from 2016 to 2048...
    Testing arrays from 4064 to 4096...
    Testing arrays from 8160 to 8192...
    Testing arrays from 16352 to 16384...
    Testing arrays from 32736 to 32768...
    Testing arrays from 65504 to 65536...
    Testing arrays from 131040 to 131072...
    Testing arrays from 262112 to 262144...
    Testing arrays from 524256 to 524288...
    Testing arrays from 1048544 to 1048576...
    Testing arrays from 2097120 to 2097152...
    Testing arrays from 4194272 to 4194304...
Array allocation tests passed.
Testing hashed array allocation and growth...
    Testing arrays from 1 to 32...
    Testing arrays from 32 to 64...
    Testing arrays from 96 to 128...
    Testing arrays from 224 to 256...
    Testing arrays from 480 to 512...
    Testing arrays from 992 to 1024...
    Testing arrays from 2016 to 2048...
    Testing arrays from 4064 to 4096...
    Testing arrays from 8160 to 8192...
    Testing arrays from 16352 to 16384...
    Testing arrays from 32736 to 32768...
    Testing arrays from 65504 to 65536...
    Testing arrays from 131040 to 131072...
    Testing arrays from 262112 to 262144...
    Testing arrays from 524256 to 524288...
    Testing arrays from 1048544 to 1048576...
    Testing arrays from 2097120 to 2097152...
JVMDUMP039I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" at 2022/03/13 11:18:30 - please wait.
pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.functional_s390x_linux_Nightly_testList_1/287 J9vmTest_4 -XX:+UseCompressedOops -Xjit -Xgcpolicy:balanced

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_sanity.functional_s390x_linux_Nightly_testList_1/287/functional_test_output.tar.gz

+++ j9vm.test.arraylets.ArrayletAllocateTest: +++
command: /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_Nightly_testList_1/openjdkbinary/j2sdk-image/bin/java  -XX:+UseCompressedOops -Xjit -Xgcpolicy:balanced  -Xdump -Xms65m -Xmx65m  -Xdisableexcessivegc   -classpath /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/VM_Test/VM_Test.jar:/home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../TKG/lib/asm-all.jar  j9vm.test.arraylets.ArrayletAllocateTest 

Testing array allocation...
    Testing arrays from 1 to 32...
    Testing arrays from 32 to 64...
    Testing arrays from 96 to 128...
    Testing arrays from 224 to 256...
    Testing arrays from 480 to 512...
    Testing arrays from 992 to 1024...
    Testing arrays from 2016 to 2048...
    Testing arrays from 4064 to 4096...
    Testing arrays from 8160 to 8192...
    Testing arrays from 16352 to 16384...
    Testing arrays from 32736 to 32768...
    Testing arrays from 65504 to 65536...
    Testing arrays from 131040 to 131072...
    Testing arrays from 262112 to 262144...
    Testing arrays from 524256 to 524288...
    Testing arrays from 1048544 to 1048576...
    Testing arrays from 2097120 to 2097152...
    Testing arrays from 4194272 to 4194304...
Array allocation tests passed.
Testing hashed array allocation and growth...
    Testing arrays from 1 to 32...
    Testing arrays from 32 to 64...
    Testing arrays from 96 to 128...
    Testing arrays from 224 to 256...
    Testing arrays from 480 to 512...
    Testing arrays from 992 to 1024...
    Testing arrays from 2016 to 2048...
    Testing arrays from 4064 to 4096...
    Testing arrays from 8160 to 8192...
    Testing arrays from 16352 to 16384...
    Testing arrays from 32736 to 32768...
    Testing arrays from 65504 to 65536...
    Testing arrays from 131040 to 131072...
    Testing arrays from 262112 to 262144...
    Testing arrays from 524256 to 524288...
    Testing arrays from 1048544 to 1048576...
    Testing arrays from 2097120 to 2097152...
JVMDUMP039I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError" at 2022/05/26 04:36:41 - please wait.
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
    at j9vm.test.arraylets.ArrayletAllocateTest.main(ArrayletAllocateTest.java:79)
JasonFengJ9 commented 1 year ago

JDK19 internal build(pll011)

openjdk version "19.0.1" 2022-10-18
IBM Semeru Runtime Open Edition 19.0.1+10 (build 19.0.1+10)
Eclipse OpenJ9 VM 19.0.1+10 (build master-a2475ea96, JRE 19 AIX ppc64-64-Bit Compressed References 20221018_15 (JIT enabled, AOT enabled)
OpenJ9   - a2475ea96
OMR      - 7d8ea8b6b
JCL      - 5168276e58 based on jdk-19.0.1+10)

[2022-12-31T21:01:12.494Z] variation: Mode301
[2022-12-31T21:01:12.494Z] JVM_OPTIONS:  -Xgcpolicy:metronome -Xnocompressedrefs 

[2022-12-31T21:02:32.044Z] +++ j9vm.test.arraylets.ArrayletAllocateTest: +++
[2022-12-31T21:02:32.044Z] command: /home/jenkins/workspace/Test_openjdk19_j9_sanity.functional_ppc64_aix_testList_2/openjdkbinary/j2sdk-image/bin/java  -Xgcpolicy:metronome -Xnocompressedrefs  -Xdump -Xms65m -Xmx65m  -Xdisableexcessivegc   -classpath /home/jenkins/workspace/Test_openjdk19_j9_sanity.functional_ppc64_aix_testList_2/aqa-tests/TKG/../../jvmtest/functional/VM_Test/VM_Test.jar:/home/jenkins/workspace/Test_openjdk19_j9_sanity.functional_ppc64_aix_testList_2/aqa-tests/TKG/../TKG/lib/asm-all.jar  j9vm.test.arraylets.ArrayletAllocateTest 
[2022-12-31T21:02:32.044Z] 
[2022-12-31T21:02:32.044Z] Testing array allocation...
[2022-12-31T21:02:32.386Z]  Testing arrays from 1 to 32...
[2022-12-31T21:02:32.386Z]  Testing arrays from 32 to 64...
[2022-12-31T21:02:32.386Z]  Testing arrays from 96 to 128...
[2022-12-31T21:02:32.386Z]  Testing arrays from 224 to 256...
[2022-12-31T21:02:32.386Z]  Testing arrays from 480 to 512...
[2022-12-31T21:02:32.386Z]  Testing arrays from 992 to 1024...
[2022-12-31T21:02:32.386Z]  Testing arrays from 2016 to 2048...
[2022-12-31T21:02:32.386Z]  Testing arrays from 4064 to 4096...
[2022-12-31T21:02:32.386Z]  Testing arrays from 8160 to 8192...
[2022-12-31T21:02:32.386Z]  Testing arrays from 16352 to 16384...
[2022-12-31T21:02:32.386Z]  Testing arrays from 32736 to 32768...
[2022-12-31T21:02:32.386Z]  Testing arrays from 65504 to 65536...
[2022-12-31T21:02:32.386Z]  Testing arrays from 131040 to 131072...
[2022-12-31T21:02:32.386Z]  Testing arrays from 262112 to 262144...
[2022-12-31T21:02:32.727Z]  Testing arrays from 524256 to 524288...
[2022-12-31T21:02:33.069Z]  Testing arrays from 1048544 to 1048576...
[2022-12-31T21:02:33.800Z]  Testing arrays from 2097120 to 2097152...
[2022-12-31T21:02:35.605Z] Array allocation tests passed.
[2022-12-31T21:02:35.605Z] Testing hashed array allocation and growth...
[2022-12-31T21:02:35.605Z]  Testing arrays from 1 to 32...
[2022-12-31T21:02:35.605Z]  Testing arrays from 32 to 64...
[2022-12-31T21:02:35.605Z]  Testing arrays from 96 to 128...
[2022-12-31T21:02:35.605Z]  Testing arrays from 224 to 256...
[2022-12-31T21:02:35.605Z]  Testing arrays from 480 to 512...
[2022-12-31T21:02:35.605Z]  Testing arrays from 992 to 1024...
[2022-12-31T21:02:35.605Z]  Testing arrays from 2016 to 2048...
[2022-12-31T21:02:35.605Z]  Testing arrays from 4064 to 4096...
[2022-12-31T21:02:35.605Z]  Testing arrays from 8160 to 8192...
[2022-12-31T21:02:35.605Z]  Testing arrays from 16352 to 16384...
[2022-12-31T21:02:35.605Z]  Testing arrays from 32736 to 32768...
[2022-12-31T21:02:35.605Z]  Testing arrays from 65504 to 65536...
[2022-12-31T21:02:35.605Z]  Testing arrays from 131040 to 131072...
[2022-12-31T21:02:35.605Z]  Testing arrays from 262112 to 262144...
[2022-12-31T21:02:35.605Z]  Testing arrays from 524256 to 524288...
[2022-12-31T21:02:36.360Z]  Testing arrays from 1048544 to 1048576...
[2022-12-31T21:02:36.360Z] JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2022/12/31 16:02:36 - please wait.
[2022-12-31T21:02:36.360Z] JVMDUMP032I JVM requested System dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.functional_ppc64_aix_testList_2/aqa-tests/TKG/output_16725189855649/J9vmTest_1/core.20221231.160236.16908708.0001.dmp' in response to an event
[2022-12-31T21:02:39.446Z] JVMDUMP010I System dump written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.functional_ppc64_aix_testList_2/aqa-tests/TKG/output_16725189855649/J9vmTest_1/core.20221231.160236.16908708.0001.dmp
[2022-12-31T21:02:39.446Z] JVMDUMP032I JVM requested Heap dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.functional_ppc64_aix_testList_2/aqa-tests/TKG/output_16725189855649/J9vmTest_1/heapdump.20221231.160236.16908708.0002.phd' in response to an event
[2022-12-31T21:02:39.446Z] JVMDUMP010I Heap dump written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.functional_ppc64_aix_testList_2/aqa-tests/TKG/output_16725189855649/J9vmTest_1/heapdump.20221231.160236.16908708.0002.phd
[2022-12-31T21:02:39.446Z] JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.functional_ppc64_aix_testList_2/aqa-tests/TKG/output_16725189855649/J9vmTest_1/javacore.20221231.160236.16908708.0003.txt' in response to an event
[2022-12-31T21:02:39.446Z] JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.functional_ppc64_aix_testList_2/aqa-tests/TKG/output_16725189855649/J9vmTest_1/javacore.20221231.160236.16908708.0003.txt
[2022-12-31T21:02:39.446Z] JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.functional_ppc64_aix_testList_2/aqa-tests/TKG/output_16725189855649/J9vmTest_1/Snap.20221231.160236.16908708.0004.trc' in response to an event
[2022-12-31T21:02:39.446Z] JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.functional_ppc64_aix_testList_2/aqa-tests/TKG/output_16725189855649/J9vmTest_1/Snap.20221231.160236.16908708.0004.trc
[2022-12-31T21:02:39.446Z] JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
[2022-12-31T21:02:39.446Z] Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
[2022-12-31T21:02:39.446Z]  at j9vm.test.arraylets.ArrayletAllocateTest.main(ArrayletAllocateTest.java:79)
[2022-12-31T21:02:39.446Z] no-zero exit value: 1
[2022-12-31T21:02:39.446Z] *** Test FAILED *** (j9vm.test.arraylets.ArrayletAllocateTest)

[2022-12-31T21:04:58.880Z] 70 passed / 1 failed
[2022-12-31T21:04:58.880Z] -----------------------------------
[2022-12-31T21:04:58.880Z] J9vmTest_1_FAILED
pshipton commented 9 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.functional_s390x_linux_Nightly_testList_0/692/

pshipton commented 7 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.functional_s390x_linux_Nightly_testList_1/730

pshipton commented 7 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.functional_s390x_linux_OpenJDK8_testList_0/73

pshipton commented 5 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk22_j9_sanity.functional_x86-64_mac_Nightly_testList_1/43

pshipton commented 5 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.functional_s390x_linux_Nightly_testList_1/217

pshipton commented 1 week ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.functional_s390x_linux_Nightly_testList_1/318

dmitripivkine commented 1 week ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.functional_s390x_linux_Nightly_testList_1/318

Lets do Arraylet leaves bookkeeping:

> !dumpallregions stats
    FREE: 19
    ARRAYLET_LEAF: 105
    ADDRESS_ORDERED: 1
    ADDRESS_ORDERED_MARKED: 5
    ++++ TOTAL: 130

So, 105 regions are used as Arraylet leaves. One Arraylet 0xFC7800B0 occupied 32 leaves is referenced from O-slot directly:

<17c1800> JIT frame: bp = 0x00000000018C0218, pc = 0x000003FF7A9E9118, unwindSP = 0x00000000018C0110, cp = 0x0000000001994ED0, arg0EA = 0x00000000018C0220, jitInfo = 0x000003FF78C2B408
<17c1800>   Method: j9vm/test/arraylets/ArrayletAllocateTest.main([Ljava/lang/String;)V !j9method 0x00000000019953E8
<17c1800>   Bytecode index = 295, inlineDepth = 0, PC offset = 0x000000000000281E
<17c1800>   stackMap=0x000003FF78C2B892, slots=I16(0x0001) parmBaseOffset=I16(0x0010), parmSlots=U16(0x0000), localBaseOffset=I16(0xFFB8)
<17c1800>   Described JIT temps starting at 0x00000000018C01D0 for IDATA(0x0000000000000009) slots
<17c1800>       O-Slot: : t8[0x00000000018C01D0] = 0x00000000FFC62068
<17c1800>       O-Slot: : t7[0x00000000018C01D8] = 0x00000000FFC62038
<17c1800>       O-Slot: : t6[0x00000000018C01E0] = 0x00000000FC780070
<17c1800>       O-Slot: : t5[0x00000000018C01E8] = 0x00000000FFC62008
<17c1800>       O-Slot: : t4[0x00000000018C01F0] = 0x00000000FFC4E0C8
<17c1800>       O-Slot: : t3[0x00000000018C01F8] = 0x00000000FFC37CC8
<17c1800>       O-Slot: : t2[0x00000000018C0200] = 0x00000000FC7800B0 <-- [L size 0x00400000 32 leaves
<17c1800>       O-Slot: : t1[0x00000000018C0208] = 0x00000000FC780150
<17c1800>       O-Slot: : t0[0x00000000018C0210] = 0x00000000FFC4E4D8
<17c1800>   JIT-RegisterMap = UDATA(0x0000000000000000)
<17c1800>   JIT-Frame-RegisterMap[0x00000000018C0140] = UDATA(0x00000000FEDC07D8) (jit_r6)
<17c1800>   JIT-Frame-RegisterMap[0x00000000018C0148] = UDATA(0x00000000FEEF3B48) (jit_r7)
<17c1800>   JIT-Frame-RegisterMap[0x00000000018C0150] = UDATA(0x000003FF943B0868) (jit_r8)
<17c1800>   JIT-Frame-RegisterMap[0x00000000018C0158] = UDATA(0x000003FF9402AA80) (jit_r9)
<17c1800>   JIT-Frame-RegisterMap[0x00000000018C0160] = UDATA(0x000003FF9B5FE4E0) (jit_r10)
<17c1800>   JIT-Frame-RegisterMap[0x00000000018C0168] = UDATA(0x000003FF943B0868) (jit_r11)
<17c1800>   JIT-Frame-RegisterMap[0x00000000018C0170] = UDATA(0x0000000000006024) (jit_r12)

Five Arraylets are referenced from class j9vm/test/arraylets/ArrayletAllocateTest Statics:

> !j9statics 0x0000000001995200
Static fields in j9vm/test/arraylets/ArrayletAllocateTest:
    0x0000000001995520 rangeSize I (!j9romstaticfieldshape 0x000003FF9BB5F1F8) = 0x00000020 (32)
    0x00000000019954F8 bytes [B (!j9romstaticfieldshape 0x000003FF9BB5F208) = !j9object 0x00000000FC7B7470 <-- [B size = 0x001FFFE1 (4 leaves)
    0x0000000001995500 shorts [S (!j9romstaticfieldshape 0x000003FF9BB5F214) = !j9object 0x00000000FC7B7428 <-- [S size = 0x001FFFE1 (8 leaves)
    0x0000000001995508 ints [I (!j9romstaticfieldshape 0x000003FF9BB5F220) = !j9object 0x00000000FCA80000 <-- [I size = 0x001FFFE1 (15 leaves)
    0x0000000001995510 longs [J (!j9romstaticfieldshape 0x000003FF9BB5F22C) = !j9object 0x00000000FF980000 <-- [J size 0x001FFFE0 (31 leaves)
    0x0000000001995518 objects [Ljava/lang/Object; (!j9romstaticfieldshape 0x000003FF9BB5F238) = !j9object 0x00000000FF880000 <-- [L size = 0x001FFFE0 (15 leaves)

So, total 32+4+8+15+31+15 = 105, we found all leaves

The OOM has been thrown an attempt to allocate another Arraylet required 32 regions:

00:16:15.142341050  0x17C1800 j9mm.101             Event       J9AllocateIndexableObject() returning NULL! 16777128 bytes requested for object of class 0x17e5000 from memory space 'Flat' id=0x3ff9410c670

but we do have 19 free regions only.

GC part works correctly. However I can't conclude is this test valid or not. There is no -Xjit:enableAggressiveLiveness specified. This option might prevent storing an Arraylet reference in O-slot. I don't know is it enough to pass the test when there are 73 leaves regions are held by references from class statics.