j9vm.test.arraylets.ArrayletAllocateTest OOM

[pshipton]

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]

@dmitripivkine can you pls take a look.

[dmitripivkine]

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]

@andrewcraik fyi this transfer to jit

[andrewcraik]

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]

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

[pshipton]

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

[dmitripivkine]

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]

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

[pshipton]

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.