openj9
openj9 copied to clipboard
eclipse-openj9
segfaults running cmdLineTester_jvmtitests_hcr_OSRG_nongold rc021
See also https://github.com/eclipse-openj9/openj9/issues/14014#issuecomment-988963294 rc021 is a new test introduced by https://github.com/eclipse-openj9/openj9/pull/14063
Dec 6:
https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_aarch64_linux_Nightly_testList_1/44
cmdLineTester_jvmtitests_hcr_OSRG_nongold_SE80_2
-Xcompressedrefs -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation
https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_ppc64le_linux_Nightly_testList_0/156
cmdLineTester_jvmtitests_hcr_OSRG_nongold_SE80_0
-Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation -Xnocompressedrefs
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.functional_aarch64_linux_Nightly_testList_1/48
cmdLineTester_jvmtitests_hcr_OSRG_nongold_0
-Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation
cmdLineTester_jvmtitests_hcr_OSRG_nongold_2
-Xcompressedrefs -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.functional_aarch64_linux_Nightly_testList_0/49 cmdLineTester_jvmtitests_hcr_OSRG_nongold_2
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.functional_aarch64_linux_Nightly_testList_1/49 cmdLineTester_jvmtitests_hcr_OSRG_nongold_0
Dec 7: https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_aarch64_linux_Nightly_testList_1/46 cmdLineTester_jvmtitests_hcr_OSRG_nongold_SE80_0
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.functional_aarch64_linux_Nightly_testList_0/50 cmdLineTester_jvmtitests_hcr_OSRG_nongold_2
Dec 8: https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_aarch64_linux_Nightly_testList_0/47 cmdLineTester_jvmtitests_hcr_OSRG_nongold_SE80_2
Dec 9: https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_aarch64_linux_Nightly_testList_1/48 cmdLineTester_jvmtitests_hcr_OSRG_nongold_SE80_2
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.functional_aarch64_linux_Nightly_testList_1/52 cmdLineTester_jvmtitests_hcr_OSRG_nongold_0 cmdLineTester_jvmtitests_hcr_OSRG_nongold_2
Dec 10: https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_aarch64_linux_Nightly_testList_1/49 cmdLineTester_jvmtitests_hcr_OSRG_nongold_SE80_0 cmdLineTester_jvmtitests_hcr_OSRG_nongold_SE80_2
Dec 11: https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_aarch64_linux_Release_testList_0/5/ https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_aarch64_linux_Release_testList_1/5/ https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.functional_aarch64_linux_Release_testList_1/5/
Dec 13: https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_aarch64_linux_Nightly_testList_0/51/ https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_aarch64_linux_Nightly_testList_1/51/ https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.functional_aarch64_linux_Nightly_testList_0/55/ https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.functional_aarch64_linux_Nightly_testList_1/55/
Dec 14: https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_aarch64_linux_Nightly_testList_1/52/ https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.functional_aarch64_linux_Nightly_testList_0/56/
Dec 15: https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_aarch64_linux_Nightly_testList_1/53/
These aarch64 failures happen every day, I'm not going to keep reporting them.
I'll just note one on AIX Dec 16 https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_ppc64_aix_Nightly_testList_0/168/
Set as a blocker due to the frequent failures. This does not necessarily indicate the problem needs to be fixed with blocking priority. Whether the problem is fixed or the test removed until it can be fixed is TBD.
I've tentatively set this to the 0.30 milestone as we don't know if the problem is an existing problem exposed by the new test, or a problem introduced by the new changes https://github.com/eclipse-openj9/openj9/pull/14063.
Here is the Java stacktrace:
<31ba00> *** BEGIN STACK WALK, flags = 00400001 walkThread = 0x000000000031BA00 ***
<31ba00> ITERATE_O_SLOTS
<31ba00> RECORD_BYTECODE_PC_OFFSET
<31ba00> Initial values: walkSP = 0x0000000000451D80, PC = 0x0000FFFF49463173, literals = 0x000000000002F558, A0 = 0x0000000000451DD8, j2iFrame = 0x0000000000451E78, ELS = 0x0000FFFF791875D0, decomp = 0x0000FFFEB800BD40
<31ba00> Bytecode frame: bp = 0x0000000000451D98, sp = 0x0000000000451D80, pc = 0x0000FFFF49463173, cp = 0x000000000002BF90, arg0EA = 0x0000000000451DD8, flags = 0x0000000000000000
<31ba00> Method: java/lang/Class.buildAnnotations(Ljava/util/LinkedHashMap;)Ljava/util/LinkedHashMap; !j9method 0x000000000002F558
<31ba00> Bytecode index = 27
<31ba00> Using debug local mapper
<31ba00> Locals starting at 0x0000000000451DD8 for 0x0000000000000008 slots
<31ba00> O-Slot: a0[0x0000000000451DD8] = 0x000000008378B498
<31ba00> O-Slot: a1[0x0000000000451DD0] = 0x0000000083ADC138
<31ba00> O-Slot: t2[0x0000000000451DC8] = 0x00000000836802A0
<31ba00> O-Slot: t3[0x0000000000451DC0] = 0x000000000000FFFF
<31ba00> O-Slot: t4[0x0000000000451DB8] = 0x0000000000000000
<31ba00> I-Slot: t5[0x0000000000451DB0] = 0x0000000000000000
<31ba00> I-Slot: t6[0x0000000000451DA8] = 0x0000000000000000
<31ba00> I-Slot: t7[0x0000000000451DA0] = 0x0000000000000000
<31ba00> Pending stack starting at 0x0000000000451D80 for UDATA(0x0000000000000001) slots
<31ba00> O-Slot: p0[0x0000000000451D80] = 0x000000000000FFFF
<31ba00> J2I frame: bp = 0x0000000000451E78, sp = 0x0000000000451DE0, pc = 0x0000FFFF4946333F, cp = 0x000000000002BF90, arg0EA = 0x0000000000451EF0, flags = 0x0000000010000000
<31ba00> Method: java/lang/Class.getAnnotationCache()Ljava/lang/Class$AnnotationCache; !j9method 0x000000000002F578
<31ba00> Bytecode index = 191
<31ba00> Using debug local mapper
<31ba00> Locals starting at 0x0000000000451EF0 for 0x000000000000000F slots
<31ba00> O-Slot: a0[0x0000000000451EF0] = 0x000000008378B498
<31ba00> O-Slot: t1[0x0000000000451EE8] = 0x0000000000000000
<31ba00> O-Slot: t2[0x0000000000451EE0] = 0x0000000083A938B0
<31ba00> I-Slot: t3[0x0000000000451ED8] = 0x0000000000000000
<31ba00> I-Slot: t4[0x0000000000451ED0] = 0x000000000000001E
<31ba00> I-Slot: t5[0x0000000000451EC8] = 0x0000000000000000
<31ba00> I-Slot: t6[0x0000000000451EC0] = 0x000000000043FF60
<31ba00> O-Slot: t7[0x0000000000451EB8] = 0x0000000083A938D8
<31ba00> O-Slot: t8[0x0000000000451EB0] = 0x0000000083ADC0F8
<31ba00> O-Slot: t9[0x0000000000451EA8] = 0x0000000083ADC138
<31ba00> O-Slot: t10[0x0000000000451EA0] = 0x0000000083ADC0F8
<31ba00> I-Slot: t11[0x0000000000451E98] = 0x0000000000000003
<31ba00> I-Slot: t12[0x0000000000451E90] = 0x0000000000000003
<31ba00> I-Slot: t13[0x0000000000451E88] = 0x0000000083ADC0B8
<31ba00> I-Slot: t14[0x0000000000451E80] = 0x0000000083752290
<31ba00> Pending stack starting at 0x0000000000451DF0 for UDATA(0x0000000000000003) slots
<31ba00> O-Slot: p0[0x0000000000451DF0] = 0x0000000083ADC1F0
<31ba00> O-Slot: p1[0x0000000000451DE8] = 0x0000000083ADC1F0
<31ba00> O-Slot: p2[0x0000000000451DE0] = 0x0000000083ADC138
<31ba00> JIT-J2I-RegisterMap[0x0000000000451E20] = UDATA(0x0000000083A5A858) (jit_r21)
<31ba00> JIT-J2I-RegisterMap[0x0000000000451E28] = UDATA(0x0000000000543600) (jit_r22)
<31ba00> JIT-J2I-RegisterMap[0x0000000000451E30] = UDATA(0x0000000083A37570) (jit_r23)
<31ba00> JIT-J2I-RegisterMap[0x0000000000451E38] = UDATA(0x0000000000000000) (jit_r24)
<31ba00> JIT-J2I-RegisterMap[0x0000000000451E40] = UDATA(0x0000000083A37540) (jit_r25)
<31ba00> JIT-J2I-RegisterMap[0x0000000000451E48] = UDATA(0x0000000000000000) (jit_r26)
<31ba00> JIT-J2I-RegisterMap[0x0000000000451E50] = UDATA(0x0000000083E11E78) (jit_r27)
<31ba00> JIT-J2I-RegisterMap[0x0000000000451E58] = UDATA(0x0000000083A375A0) (jit_r28)
<31ba00> (ws pcaddr = 0x0000000000451E70, dc tos = 0x0000FFFEB800BD40, pcaddr = 0x0000000000451E70, pc = 0x0000FFFF8C352AE0)
<31ba00> JIT frame: bp = 0x0000000000451FD8, pc = 0x0000FFFF8C352AE0, unwindSP = 0x0000000000451EF0, cp = 0x000000000002BF90, arg0EA = 0x0000000000451FE0, jitInfo = 0x0000FFFE71F72738
<31ba00> Method: java/lang/Class.getDeclaredAnnotations()[Ljava/lang/annotation/Annotation; !j9method 0x000000000002F378
<31ba00> Bytecode index = 1, inlineDepth = 0, PC offset = 0x0000FFFF8C352ADD
<31ba00> stackMap=0x0000FFFE71F72868, slots=I16(0x0001) parmBaseOffset=I16(0x0008), parmSlots=U16(0x0001), localBaseOffset=I16(0xFF90)
<31ba00> Described JIT args starting at 0x0000000000451FE0 for U16(0x0001) slots
<31ba00> O-Slot: : a0[0x0000000000451FE0] = 0x000000008378B498
<31ba00> Described JIT temps starting at 0x0000000000451F68 for IDATA(0x000000000000000E) slots
<31ba00> Address 0x0000FFFE71F72B60
<31ba00> Num internal ptr map bytes U8(0x07)
<31ba00> Address 0x0000FFFE71F72B61
<31ba00> Index of first internal ptr I16(0x000B)
<31ba00> Address 0x0000FFFE71F72B63
<31ba00> Offset of first internal ptr I16(0xFFE0)
<31ba00> Address 0x0000FFFE71F72B65
<31ba00> Num distinct pinning arrays U8(0x02)
<31ba00> Before object slot walk &address : 0x0000000000451FC0 address : 0x0000000000000000 bp 0x0000000000451FD8 offset of first internal ptr I16(0xFFE0)
<31ba00> After object slot walk for pinning array with &address : 0x0000000000451FC0 old address 0x0000000000000000 new address 0x0000000000000000 displacement IDATA(0x0000000000000000)
<31ba00> For pinning array U8(0x01) num internal pointer stack slots U8(0x01)
<31ba00> Before object slot walk &address : 0x0000000000451FB8 address : 0x0000000000000000 bp 0x0000000000451FD8 offset of first internal ptr I16(0xFFE0)
<31ba00> After object slot walk for pinning array with &address : 0x0000000000451FB8 old address 0x0000000000000000 new address 0x0000000000000000 displacement IDATA(0x0000000000000000)
<31ba00> For pinning array U8(0x00) num internal pointer stack slots U8(0x01)
<31ba00> O-Slot: : t13[0x0000000000451F68] = 0x0000000000000000
<31ba00> O-Slot: : t12[0x0000000000451F70] = 0x0000000000000000
<31ba00> O-Slot: : t11[0x0000000000451F78] = 0x0000000000000000
<31ba00> O-Slot: : t10[0x0000000000451F80] = 0x0000000000000000
<31ba00> O-Slot: : t9[0x0000000000451F88] = 0x0000000000000000
<31ba00> O-Slot: : t8[0x0000000000451F90] = 0x0000000000000000
<31ba00> I-Slot: : t7[0x0000000000451F98] = 0x0000FFFF4945B67A
<31ba00> I-Slot: : t6[0x0000000000451FA0] = 0x000000000000000D
<31ba00> I-Slot: : t5[0x0000000000451FA8] = 0x0000000000000000
<31ba00> I-Slot: : t4[0x0000000000451FB0] = 0x0000000083680000
<31ba00> I-Slot: : t3[0x0000000000451FB8] = 0x0000000000000000
<31ba00> I-Slot: : t2[0x0000000000451FC0] = 0x0000000000000000
<31ba00> I-Slot: : t1[0x0000000000451FC8] = 0x0000000000000000
<31ba00> I-Slot: : t0[0x0000000000451FD0] = 0x0000000000000000
<31ba00> JIT-RegisterMap = UDATA(0x0000000000000000)
<31ba00> JIT-OSRBuffer = 0x0000FFFEB800BD78, numberOfFrames = 1
<31ba00> JIT-OSRFrame = 0x0000FFFEB800BD88, bytecodePC = 0x0000FFFF49462B21, numberOfLocals = UDATA(0x0000000000000003), maxStack = UDATA(0x0000000000000002), pendingStackHeight = UDATA(0x0000000000000000)
<31ba00> Method: java/lang/Class.getDeclaredAnnotations()[Ljava/lang/annotation/Annotation; !j9method 0x000000000002F378
<31ba00> Bytecode index = 1
<31ba00> Using debug local mapper
<31ba00> Locals starting at 0x0000FFFEB800BDE0 for 0x0000000000000003 slots
<31ba00> O-Slot: a0[0x0000FFFEB800BDE0] = 0x0000000000000000
<31ba00> I-Slot: t1[0x0000FFFEB800BDD8] = 0x0000000000000000
<31ba00> I-Slot: t2[0x0000FFFEB800BDD0] = 0x0000000000000000
<31ba00> JIT-Frame-RegisterMap[0x0000000000451F20] = UDATA(0x0000000083A5A858) (jit_r21)
<31ba00> JIT-Frame-RegisterMap[0x0000000000451F28] = UDATA(0x0000000000543600) (jit_r22)
<31ba00> JIT-Frame-RegisterMap[0x0000000000451E30] = UDATA(0x0000000083A37570) (jit_r23)
<31ba00> JIT-Frame-RegisterMap[0x0000000000451F30] = UDATA(0x0000000000000000) (jit_r24)
<31ba00> JIT-Frame-RegisterMap[0x0000000000451F38] = UDATA(0x0000000083A37540) (jit_r25)
<31ba00> JIT-Frame-RegisterMap[0x0000000000451F40] = UDATA(0x0000000000000000) (jit_r26)
<31ba00> JIT-Frame-RegisterMap[0x0000000000451E50] = UDATA(0x0000000083E11E78) (jit_r27)
<31ba00> JIT-Frame-RegisterMap[0x0000000000451E58] = UDATA(0x0000000083A375A0) (jit_r28)
<31ba00> (ws pcaddr = 0x0000000000451FD8, dc tos = 0x0000FFFEB8004320, pcaddr = 0x0000000000452060, pc = 0x0000FFFF8C3509C4)
<31ba00> I2J values: PC = 0x0000FFFF9C274EB8, A0 = 0x0000000000452080, walkSP = 0x0000000000451FE8, literals = 0x0000000000543948, JIT PC = 0x0000FFFFA093C684, pcAddress = 0x0000000000451E10, decomp = 0x0000FFFEB8004320
<31ba00> J2I frame: bp = 0x0000000000452068, sp = 0x0000000000451FE8, pc = 0x0000FFFF9C274EB8, cp = 0x00000000005437C0, arg0EA = 0x0000000000452080, flags = 0x0000000010000000
<31ba00> Method: com/ibm/jvmti/tests/redefineClasses/rc021$1AnnotationFetch.run()V !j9method 0x0000000000543948
<31ba00> Bytecode index = 4
<31ba00> Using debug local mapper
<31ba00> Locals starting at 0x0000000000452080 for 0x0000000000000003 slots
<31ba00> O-Slot: a0[0x0000000000452080] = 0x0000000083A5A828
<31ba00> O-Slot: t1[0x0000000000452078] = 0x000000008378B498
<31ba00> I-Slot: t2[0x0000000000452070] = 0x0000000000000000
The crash occurs on an invokeVirtual with O-Slot: p0[0x0000000000451D80] = 0x000000000000FFFF receiver
Method and bytecodes
> !j9method 0x000000000002F558
J9Method at 0x2f558 {
Fields for J9Method:
0x0: U8* bytecodes = !j9x 0x0000FFFF49463158 // "*�L"
0x8: struct J9ConstantPool* constantPool = !j9constantpool 0x000000000002BF90 (flags = 0x0)
0x10: void* methodRunAddress = !j9x 0x0000000000000006
0x18: volatile void* extra = !j9x 0x0000000000000003
}
Signature: java/lang/Class.buildAnnotations(Ljava/util/LinkedHashMap;)Ljava/util/LinkedHashMap; !bytecodes 0x000000000002F558
ROM Method: !j9rommethod 0x0000FFFF49463144
Next Method: !j9method 0x000000000002F578
> !bytecodes 0x000000000002F558
Name: buildAnnotations
Signature: (Ljava/util/LinkedHashMap;)Ljava/util/LinkedHashMap;
Access Flags (12240002): private
Max Stack: 4
Argument Count: 2
Temp Count: 6
0 aload0
1 invokevirtual 76 java/lang/Class.getSuperclass()Ljava/lang/Class;
4 astore2
5 aload2
6 ifnonnull 11
9 aload1
10 return1
11 aload2
12 invokespecial 328 java/lang/Class.getAnnotationCache()Ljava/lang/Class$AnnotationCache;
15 getfield 329 java/lang/Class$AnnotationCache.annotationMap Ljava/util/LinkedHashMap;
18 astore3
19 aconstnull
20 astore 4
22 aload3
23 ifnull 135
26 aload3
27 invokevirtual 348 java/util/LinkedHashMap.entrySet()Ljava/util/Set; //<-crash here
There is a c_jitDecompileOnReturn on the thread right before the crash.
A new bytecode frame is built a 0x451d88, this would mean that the java/lang/Class.buildAnnotations bytecode frame is the frame that was just built.
The method being decompiled is java/lang/Class.getSuperclass()
Looking at the bytecodes the result of this call is used in:
12 invokespecial 328 java/lang/Class.getAnnotationCache()Ljava/lang/Class$AnnotationCache;
then
15 getfield 329 java/lang/Class$AnnotationCache.annotationMap Ljava/util/LinkedHashMap;
then it becomes the receiver for
27 invokevirtual 348 java/util/LinkedHashMap.entrySet()Ljava/util/Set;
clone() doesn't seem to be involved here, but the rest looks similar to #14014
I will try to get more diagnostics, but right now it looks like there was a bad return value from c_jitDecompileOnReturn which is identical to the problem we had in #14014
The receiver that java/lang/Class.getSuperclass() is called on is com/ibm/jvmti/tests/redefineClasses/rc021_testAnnotationCache_O, thats the class that is being redefined.
The jitDecompileOnReturn registered on java/lang/Class.getSuperclass()Ljava/lang/Class; which has the following bytecodes:
> !bytecodes 0x000000000002F018
Name: getSuperclass
Signature: ()Ljava/lang/Class;
Access Flags (2050001): public
Max Stack: 1
Argument Count: 1
Temp Count: 0
0 aload0
1 invokestatic 290 java/lang/J9VMInternals.getSuperclass(Ljava/lang/Class;)Ljava/lang/Class;
4 return1
The return value from the JIT is
> !j9object 0x836802a0
!J9Object 0x00000000836802A0 {
struct J9Class* clazz = !j9class 0x38300 // com/ibm/jit/JITHelpers
Object flags = 0x00000000;
I lockword = 0x00000000 (offset = 0) (java/lang/Object) <hidden>
}
which is incorrect.
It does look like we have a JITHelpers::getSuperclass(Class<?> clazz) helper. @0xdaryl @jdmpapin Are there optimizations that replace java/lang/J9VMInternals.getSuperclass with JITHelpers::getSuperclass(Class<?> clazz) JITHelpers::getSuperclass(Class<?> clazz) ?
Are there optimizations that replace
java/lang/J9VMInternals.getSuperclasswithJITHelpers::getSuperclass(Class<?> clazz)?
Yes, this is done unconditionally early during IL generation. I'm not familiar with this particular transformation just yet to say whether it should be correct or not, but this could be another one that we bar from occurring under involuntary OSR.
https://github.com/eclipse-openj9/openj9/blob/95691ded2b58e145270e084e66647ab5f148c2a8/runtime/compiler/env/VMJ9.cpp#L8034
The JIT will investigate this angle.
Also seen in an internal build job_output.php?id=22227520 (win10x64vs2)
Testing: rc021
Running command: "w:\builds\bld_18036/sdk/wa6480\bin\java" -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation -Xnocompressedrefs -Xdump -agentlib:jvmtitest=test:rc021 -cp "w:\builds\bld_18036/jvmtest/test/SE80\functional\cmdLineTests\jvmtitests\jvmtitest.jar;w:\builds\bld_18036/jvmtest/test/SE80\TKG\lib\asm-all.jar" com.ibm.jvmti.tests.util.TestRunner
Output from test:
[OUT] *** Testing [1/2]:testAnnotatedTypes
[OUT] OK
[OUT] *** Testing [2/2]:testAnnotationCacheAfterRedefine
[ERR] Unhandled exception
[ERR] Type=Segmentation error vmState=0x00000000
[ERR] Windows_ExceptionCode=c0000005 J9Generic_Signal=00000004 ExceptionAddress=00007FF99317D736 ContextFlags=0010005f
[ERR] Handler1=00007FF9931A76A0 Handler2=00007FF99462BD40 InaccessibleReadAddress=000000000000000E
[ERR] RDI=0000000681FFF3B8 RSI=0000000000000000 RAX=0000000000000000 RBX=000001347EF1AB40
[ERR] RCX=0000000000000006 RDX=00007FF413322980 R8=00007FF9A0153180 R9=0000000000000006
[ERR] R10=00000134003BE88E R11=0000000681FFEBD0 R12=00007FF413322980 R13=0000000000000006
[ERR] R14=000001340178DA48 R15=0000000681FFF3A0
[ERR] RIP=00007FF99317D736 RSP=0000000681FFED00 RBP=0000013401545200 EFLAGS=0000000000010206
[ERR] FS=0053 ES=002B DS=002B
[ERR] Module=w:\builds\bld_18036\sdk\wa6480\jre\bin\default\j9vm29.dll
[ERR] Module_base_address=00007FF993120000 Offset_in_DLL=000000000005d736
[ERR] Target=2_90_20211208_18036 (Windows 10 10.0 build 18363)
[ERR] CPU=amd64 (4 logical CPUs) (0x1fff08000 RAM)
[ERR] ----------- Stack Backtrace -----------
[ERR] hashClassTableAtString+0x6 (keyhashtable.c:653, 0x00007FF99317D736 [j9vm29+0x5d736])
[ERR] internalFindClassString+0x66 (classsupport.c:301, 0x00007FF993192306 [j9vm29+0x72306])
[ERR] ?run@VM_DebugBytecodeInterpreterFull@@QEAA_KPEAUJ9VMThread@@@Z+0x11093 (0x00007FF993150BC3 [j9vm29+0x30bc3])
[ERR] (0x0000000681FFF3C8)
[ERR] (0x0000013401545200)
[ERR] (0x0000000681FFF3A8)
[ERR] (0x0000000681FFF3B8)
[ERR] (0x0000000000000008)
[ERR] (0x0000000000000001)
[ERR] (0x0000000600000000)
[ERR] (0x0000000681FFF3A8)
[ERR] (0x0000000681FFF3B8)
[ERR] (0x0000000681FFF3A0)
[ERR] (0x0000000681FFF3B0)
[ERR] (0x0000000681FFF3C8)
[ERR] (0x0000000681FFF3D0)
[ERR] (0x000001340178DAD0)
[ERR] (0x0000000000000020)
[ERR] (0x0000000681FFF3F8)
[ERR] (0x0000000681FFF3D8)
[ERR] (0x000000000002AB02)
[ERR] rasinfoNames+0x1a4c (0x00007FF99329513C [j9vm29+0x17513c])
[ERR] RtlGetCurrentServiceSessionId+0xb8d (0x00007FF9A8C0130D [ntdll+0x4130d])
[ERR] RtlFreeHeap+0x51 (0x00007FF9A8C006E1 [ntdll+0x406e1])
[ERR] omrmem_free_memory+0x5f (omrmemtag.c:208, 0x00007FF9946227EF [j9prt29+0x127ef])
[ERR] jitDecompileMethod+0xf1 (decomp.cpp:508, 0x00007FF98C1ADE71 [j9jit29+0x6cde71])
[ERR] (0x0000000000000001)
[ERR] (0x0000000000000001)
[ERR] (0x0000000000000008)
[ERR] ---------------------------------------
[ERR] JVMDUMP039I Processing dump event "gpf", detail "" at 2021/12/09 00:51:42 - please wait.
[ERR] JVMDUMP051I JIT dump occurred in 'pool-2-thread-30' thread 0x0000013401545200
[ERR] JVMDUMP053I JIT dump is recompiling java/util/concurrent/ThreadPoolExecutor.runWorker(Ljava/util/concurrent/ThreadPoolExecutor$Worker;)V
[ERR] 0000013401545200: Object neither in heap nor stack-allocated in thread pool-2-thread-30
[ERR] 0000013401545200:O-Slot=000001340178DA70
[ERR] 0000013401545200:O-Slot value=000001340017CEA0
[ERR] 0000013401545200:PC=0000000000000003
[ERR] 0000013401545200:framesWalked=0
[ERR] 0000013401545200:arg0EA=000001340178DA78
[ERR] 0000013401545200:walkSP=000001340178DA40
[ERR] 0000013401545200:literals=0000000000000008
[ERR] 0000013401545200:jitInfo=0000000000000000
[ERR] 0000013401545200:method=00000134003DB970 (java/lang/VMAccess.findClassOrNull(Ljava/lang/String;Ljava/lang/ClassLoader;)Ljava/lang/Class;) (Interpreted)
[ERR] 0000013401545200:stack=0000013401786E30-000001340178DE80
[ERR] 0000013401545200: Object neither in heap nor stack-allocated in thread pool-2-thread-30
[ERR] 0000013401545200:O-Slot=000001340178DA98
[ERR] 0000013401545200:O-Slot value=000001340017CEA0
[ERR] 0000013401545200:PC=00000134003BE88E
[ERR] 0000013401545200:framesWalked=1
[ERR] 0000013401545200:arg0EA=000001340178DAA8
[ERR] 0000013401545200:walkSP=000001340178DA80
[ERR] 0000013401545200:literals=00000134003DB990
[ERR] 0000013401545200:jitInfo=0000000000000000
[ERR] 0000013401545200:method=00000134003DB990 (java/lang/VMAccess.findClassOrNullHelper(Ljava/lang/String;Ljava/lang/ClassLoader;)Ljava/lang/Class;) (Interpreted)
[ERR] 0000013401545200:stack=0000013401786E30-000001340178DE80
[ERR] 0000013401545200: Object neither in heap nor stack-allocated in thread pool-2-thread-30
[ERR] 0000013401545200:O-Slot=000001340178DAD8
[ERR] 0000013401545200:O-Slot value=000001340017CEA0
[ERR] 0000013401545200:PC=00000134007C9633
[ERR] 0000013401545200:framesWalked=2
[ERR] 0000013401545200:arg0EA=000001340178DAD8
[ERR] 0000013401545200:walkSP=000001340178DAB0
[ERR] 0000013401545200:literals=00000134007E14B8
[ERR] 0000013401545200:jitInfo=0000000000000000
[ERR] 0000013401545200:method=00000134007E14B8 (com/ibm/oti/vm/BootstrapClassLoader.loadClass(Ljava/lang/String;)Ljava/lang/Class;) (Interpreted)
[ERR] 0000013401545200:stack=0000013401786E30-000001340178DE80
[ERR] Unhandled exception
[ERR] Type=Segmentation error vmState=0x00020002
[ERR] Windows_ExceptionCode=c0000005 J9Generic_Signal=00000004 ExceptionAddress=00007FF993201CEB ContextFlags=0010005f
[ERR] Handler1=00007FF9931A76A0 Handler2=00007FF99462BD40 InaccessibleReadAddress=FFFFFFFFFFFFFFFF
[ERR] RDI=00000006827FD9F0 RSI=0000000000000098 RAX=07FFFFFFFFFFFFFF RBX=0000000000000001
[ERR] RCX=FFFFFFFFFFFFFFFE RDX=00000006827FDA38 R8=FFFFFFFFFFFFFFFE R9=00000134017CD080
[ERR] R10=0000000000000000 R11=00000006827FD9F0 R12=0000000000000000 R13=0000000000000006
[ERR] R14=00007FF9953B6350 R15=0000000000000000
[ERR] RIP=00007FF993201CEB RSP=00000006827FD950 RBP=0000013400162060 EFLAGS=0000000000010A07
[ERR] FS=0053 ES=002B DS=002B
[ERR] Module=w:\builds\bld_18036\sdk\wa6480\jre\bin\default\j9vm29.dll
[ERR] Module_base_address=00007FF993120000 Offset_in_DLL=00000000000e1ceb
[ERR] Target=2_90_20211208_18036 (Windows 10 10.0 build 18363)
[ERR] CPU=amd64 (4 logical CPUs) (0x1fff08000 RAM)
[ERR] ----------- Stack Backtrace -----------
[ERR] j9stackmap_StackBitsForPC+0x1eb (stackmap.c:136, 0x00007FF993201CEB [j9vm29+0xe1ceb])
[ERR] walkBytecodeFrameSlots+0x322 (swalk.c:894, 0x00007FF9931DD4B2 [j9vm29+0xbd4b2])
[ERR] walkBytecodeFrame+0x1ba (swalk.c:1002, 0x00007FF9931DDE1A [j9vm29+0xbde1a])
[ERR] walkStackFrames+0x4fe (swalk.c:328, 0x00007FF9931DCF5E [j9vm29+0xbcf5e])
[ERR] GC_VMThreadStackSlotIterator::scanSlots+0xa5 (vmthreadstackslotiterator.cpp:115, 0x00007FF98EB06785 [j9gc29+0x16785])
[ERR] MM_RootScanner::scanOneThread+0x10e (rootscanner.cpp:521, 0x00007FF98EB0356E [j9gc29+0x1356e])
[ERR] MM_RootScanner::scanThreads+0xb3 (rootscanner.cpp:488, 0x00007FF98EB03873 [j9gc29+0x13873])
[ERR] MM_RootScanner::scanRoots+0x7d (rootscanner.cpp:921, 0x00007FF98EB026FD [j9gc29+0x126fd])
[ERR] MM_MarkingDelegate::scanRoots+0x20a (markingdelegate.cpp:255, 0x00007FF98EC2371A [j9gc29+0x13371a])
[ERR] MM_ParallelMarkTask::run+0x11b (parallelmarktask.cpp:53, 0x00007FF98ECA4AEB [j9gc29+0x1b4aeb])
[ERR] MM_ParallelDispatcher::run+0x5f (paralleldispatcher.cpp:589, 0x00007FF98EBEE3AF [j9gc29+0xfe3af])
[ERR] MM_ParallelGlobalGC::markAll+0x1ce (parallelglobalgc.cpp:958, 0x00007FF98EC4C5CE [j9gc29+0x15c5ce])
[ERR] MM_ParallelGlobalGC::mainThreadGarbageCollect+0x22f (parallelglobalgc.cpp:463, 0x00007FF98EC4D06F [j9gc29+0x15d06f])
[ERR] MM_ParallelGlobalGC::internalGarbageCollect+0x73 (parallelglobalgc.cpp:1238, 0x00007FF98EC4D673 [j9gc29+0x15d673])
[ERR] MM_Collector::garbageCollect+0x327 (collector.cpp:502, 0x00007FF98EBF1207 [j9gc29+0x101207])
[ERR] MM_MemorySubSpaceFlat::allocationRequestFailed+0x797 (memorysubspaceflat.cpp:154, 0x00007FF98EC9E417 [j9gc29+0x1ae417])
[ERR] MM_MemorySubSpaceGeneric::allocateTLH+0x207 (memorysubspacegeneric.cpp:379, 0x00007FF98EC9FA57 [j9gc29+0x1afa57])
[ERR] MM_TLHAllocationSupport::refresh+0x3aa (tlhallocationsupport.cpp:242, 0x00007FF98EC0D7CA [j9gc29+0x11d7ca])
[ERR] MM_TLHAllocationSupport::allocateFromTLH+0x118 (tlhallocationsupport.cpp:310, 0x00007FF98EC0DA48 [j9gc29+0x11da48])
[ERR] MM_TLHAllocationInterface::allocateObject+0x258 (tlhallocationinterface.cpp:194, 0x00007FF98EC07E68 [j9gc29+0x117e68])
[ERR] OMR_GC_AllocateObject+0x251 (omrgcalloc.cpp:39, 0x00007FF98EC294B1 [j9gc29+0x1394b1])
[ERR] J9AllocateObject+0x290 (mgcalloc.cpp:414, 0x00007FF98EB12590 [j9gc29+0x22590])
[ERR] ?run@VM_DebugBytecodeInterpreterFull@@QEAA_KPEAUJ9VMThread@@@Z+0x29499 (0x00007FF993168FC9 [j9vm29+0x48fc9])
[ERR] ---------------------------------------
[ERR] JVMDUMP039I Processing dump event "gpf", detail "" at 2021/12/09 00:51:44 - please wait.
Time spent executing: 240189 milliseconds
Test result: FAILED
Also at job/Test_openjdk8_j9_extended.functional_aarch64_linux_testList_1/73/, job/Test_openjdk8_j9_extended.functional_aarch64_linux_testList_4/9/.
Another manifestation at JDK11 Windows.
win16x64rt2-4 - job/Test_openjdk11_j9_extended.functional_x86-64_windows_testList_0/115/
[2021-12-11T06:01:56.221Z] variation: Mode607-OSRG
[2021-12-11T06:01:56.221Z] JVM_OPTIONS: -Xcompressedrefs -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation
[2021-12-11T06:03:34.897Z] Testing: rc021
[2021-12-11T06:03:34.897Z] Test start time: 2021/12/10 22:03:27 Pacific Standard Time
[2021-12-11T06:03:34.897Z] Running command: "C:/Users/jenkins/workspace/Test_openjdk11_j9_extended.functional_x86-64_windows_testList_0/openjdkbinary/j2sdk-image\\bin\\java" -Xcompressedrefs -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation -Xdump -agentlib:jvmtitest=test:rc021 -cp "C:/Users/jenkins/workspace/Test_openjdk11_j9_extended.functional_x86-64_windows_testList_0/aqa-tests///..//jvmtest\functional\cmdLineTests\jvmtitests\jvmtitest.jar;C:/Users/jenkins/workspace/Test_openjdk11_j9_extended.functional_x86-64_windows_testList_0/aqa-tests/\TKG\lib\asm-all.jar" com.ibm.jvmti.tests.util.TestRunner
[2021-12-11T06:03:34.897Z] Time spent starting: 63 milliseconds
[2021-12-11T06:03:57.908Z] Time spent executing: 21103 milliseconds
[2021-12-11T06:03:57.908Z] Test result: FAILED
[2021-12-11T06:03:57.908Z] Output from test:
[2021-12-11T06:03:57.908Z] [OUT] *** Testing [1/2]: testAnnotatedTypes
[2021-12-11T06:03:57.908Z] [OUT] Exception during annotation fetch:
[2021-12-11T06:03:57.908Z] [OUT] java.lang.NullPointerException
[2021-12-11T06:03:57.908Z] [OUT] at java.base/java.util.Objects.requireNonNull(Objects.java:221)
[2021-12-11T06:03:57.908Z] [OUT] at java.base/java.lang.reflect.Proxy.<init>(Proxy.java:322)
[2021-12-11T06:03:57.908Z] [OUT] at com.sun.proxy.$Proxy0.<init>(Unknown Source)
[2021-12-11T06:03:57.909Z] [OUT] at jdk.internal.reflect.GeneratedConstructorAccessor5.newInstance(Unknown Source)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/java.lang.reflect.Proxy.newProxyInstance(Proxy.java:1022)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/java.lang.reflect.Proxy.newProxyInstance(Proxy.java:1008)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/sun.reflect.annotation.AnnotationParser$1.run(AnnotationParser.java:306)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/sun.reflect.annotation.AnnotationParser$1.run(AnnotationParser.java:304)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/java.security.AccessController.doPrivileged(AccessController.java:682)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/sun.reflect.annotation.AnnotationParser.annotationForMap(AnnotationParser.java:304)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/sun.reflect.annotation.AnnotationParser.parseAnnotation2(AnnotationParser.java:294)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/sun.reflect.annotation.AnnotationParser.parseAnnotations2(AnnotationParser.java:121)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/sun.reflect.annotation.AnnotationParser.parseSelectAnnotations(AnnotationParser.java:102)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/sun.reflect.annotation.AnnotationType.<init>(AnnotationType.java:145)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/sun.reflect.annotation.AnnotationType.getInstance(AnnotationType.java:85)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/sun.reflect.annotation.AnnotationParser.parseAnnotation2(AnnotationParser.java:267)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/sun.reflect.annotation.AnnotationParser.parseAnnotation(AnnotationParser.java:227)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/sun.reflect.annotation.TypeAnnotationParser.parseTypeAnnotation(TypeAnnotationParser.java:421)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/sun.reflect.annotation.TypeAnnotationParser.parseTypeAnnotations(TypeAnnotationParser.java:360)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/sun.reflect.annotation.TypeAnnotationParser.buildAnnotatedTypes(TypeAnnotationParser.java:110)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/sun.reflect.annotation.TypeAnnotationParser.buildAnnotatedInterfaces(TypeAnnotationParser.java:205)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/com.ibm.oti.reflect.TypeAnnotationParser.buildAnnotatedInterfaces(TypeAnnotationParser.java:113)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/java.lang.Class.getAnnotatedInterfaces(Class.java:2741)
[2021-12-11T06:03:57.909Z] [OUT] at com.ibm.jvmti.tests.redefineClasses.rc021$2AnnotationFetch.run(rc021.java:134)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[2021-12-11T06:03:57.909Z] [OUT] at java.base/java.lang.Thread.run(Thread.java:866)
[2021-12-11T06:03:57.918Z] >> Success condition was not found: [Return code: 0]
One on AIX https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_ppc64_aix_Nightly_testList_0/168
@0xdaryl Either this isn't fixed by https://github.com/eclipse-openj9/openj9/pull/14163 or there is more than one problem. There was a plinux failure in the nightly last night but https://github.com/eclipse-openj9/openj9/pull/14163 is included in the build. aarch64 did run clean last night.
https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_ppc64le_linux_Nightly_testList_0/167
Also https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.functional_x86-64_windows_Nightly_testList_1/174
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.functional_x86-64_windows_Nightly_testList_1/176 https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_ppc64_aix_Release_testList_0/16/
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.functional_x86-64_mac_Nightly_testList_1/166/
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.functional_s390x_linux_Nightly_testList_0/180/
can you please take a look at this?
Yes. I have a few existing tasks from last year. So, I will take a look at this sometime next week.
My mistake @babsingh I didnt mean this one, I meant https://github.com/eclipse-openj9/openj9/issues/14166
https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_ppc64le_linux_Release_testList_0/18/ https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_x86-64_mac_Nightly_testList_1/179/ https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.functional_ppc64le_linux_Nightly_testList_0/176/
https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_aarch64_linux_Nightly_testList_1/66
@0xdaryl can you update this with the current state for the 0.30 release? We have about a week till the release date
On x86 Linux I'm seeing a failure rate of ~~1/50 (2 NPEs out of 100 runs)~~ (EDIT: actually 2/200 == 1/100). I'm trying to get failure artifacts now, and also verifying whether the fix is somehow being subverted or whether this is a different problem altogether.
The AArch64 failures referenced above is actually a crash during GVP, albeit in the same test. It isn't clear whether (or how) this is related to the original problem.
The SEGV on AArch64 in https://github.com/eclipse-openj9/openj9/issues/14115#issuecomment-1009956805 seems to have occurred in the following location, where javaLangClass in x21 is 0x100000, and the result of offsetOfObjectVftField() in x0 is 0:
https://github.com/eclipse-openj9/openj9/blob/684717766630da76ef64c0fedb269e3965900ede/runtime/compiler/env/VMJ9.cpp#L8391
I ran the failing test overnight with -Xdump options and saw two failures that produced NPEs. Unfortunately, there is an issue with core file generation such that cores weren't produced, but javacores were. I'm looking into how to fix the core file generation.
It took several hundred runs overnight, but I have a corefile produced on the NPE. Hopefully it will be useable.
https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_ppc64le_linux_Nightly_testList_0/179/ https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_x86-64_linux_Nightly_testList_0/173/
The current problem is a different problem than the one originally uncovered by this issue and fixed in 14163. The NPE has still been seen after disabling all native inlining, newInstanceImpl opt, and method inlining. It can also be reproduced with noopt (but not with -Xint). Reproduction rate is about 1/50.
This problem does tend to go into remission when diagnostic options are applied, but I've made some progress getting an OSR log and vlog when the failure occurs. Investigation continues.
The failure has only been seen with the stress JIT options to force particular OSR behaviour. It has not been seen in default mode through hundreds of runs. Given this fact and its reproduction rate suggests this isn't a blocker.
This fails often in the nightly builds and should be fixed with high priority. Given the previous information, plus the test is new and the failure is not a regression, I agree this problem should not block the release. I'm moving it forward.
From the weekend: https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_x86-32_windows_Nightly_testList_0/184 https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_ppc64le_linux_Nightly_testList_0/182
From last night: https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_aarch64_linux_Nightly_testList_1/72 https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.functional_ppc64le_linux_Nightly_testList_0/183