openj9 icon indicating copy to clipboard operation
openj9 copied to clipboard

Published 20 hours ago • verified publisher icon eclipse-openj9

ClassLoadingTest_5m ASSERTION FAILED ** at openj9\runtime\vm\KeyHashTable.c:313: (!((0 != ((((UDATA)clazz)) & ((0x100 - 1))))))

Open JasonFengJ9 opened this issue 4 years ago • 37 comments

Failure link

From an internal build Test_openjdk11_j9_sanity.system_x86-64_windows_testList_0/61/ (win16x64rt3-2):

java version "11.0.12" 2021-07-20
Java(TM) SE Runtime Environment 11.0.12.0-IBM (build 11.0.12+6)
Eclipse OpenJ9 VM 11.0.12.0-IBM (build master-5d3e13320, JRE 11 Windows Server 2016 amd64-64-Bit Compressed References 20210705_117 (JIT enabled, AOT enabled)
OpenJ9   - 5d3e13320
OMR      - 45201fd39
JCL      - 9de823a9c2 based on jdk-11.0.12+6)

Rerun in Grinder

Optional info

Failure output (captured from console output)

[2021-07-05T23:04:38.863Z] Running test ClassLoadingTest_5m_0 ...
[2021-07-05T23:04:40.715Z] ===============================================
[2021-07-05T23:04:40.715Z] ClassLoadingTest_5m_0 Start Time: Mon Jul  5 16:04:23 2021 Epoch Time (ms): 1625526263465
[2021-07-05T23:04:40.715Z] "C:/Users/jenkins/workspace/Test_openjdk11_j9_sanity.system_x86-64_windows_testList_0/openjdkbinary/j2sdk-image\\bin\\java" -Xshareclasses:destroyAll; "C:/Users/jenkins/workspace/Test_openjdk11_j9_sanity.system_x86-64_windows_testList_0/openjdkbinary/j2sdk-image\\bin\\java" -Xshareclasses:groupAccess,destroyAll; echo "cache cleanup done";
[2021-07-05T23:04:40.715Z] JVMSHRC005I No shared class caches available
[2021-07-05T23:04:42.873Z] JVMSHRC005I No shared class caches available
[2021-07-05T23:04:42.873Z] cache cleanup done
[2021-07-05T23:04:42.873Z] variation: Mode150
[2021-07-05T23:04:42.873Z] JVM_OPTIONS:  -XX:+UseCompressedOops 

[2021-07-05T23:05:35.038Z] CLT 16:05:18.440 - Completed 13.3%. Number of tests started=6793 (+3704)
[2021-07-05T23:05:45.800Z] CLT stderr 23:05:27.849 0x59eb00    j9vm.225    *   ** ASSERTION FAILED ** at C:\workspace\openjdk-build\workspace\build\src\openj9\runtime\vm\KeyHashTable.c:313: (!((0 != ((((UDATA)clazz)) & ((0x100 - 1))))))
[2021-07-05T23:05:45.800Z] CLT stderr JVMDUMP039I Processing dump event "traceassert", detail "" at 2021/07/05 16:05:27 - please wait.

[2021-07-05T23:06:31.457Z] STF 16:06:15.282 - Overall result: **FAILED**
[2021-07-05T23:06:31.457Z] 
[2021-07-05T23:06:31.457Z] ClassLoadingTest_5m_0_FAILED

30x grinder Grinder/16795/

JasonFengJ9 avatar Jul 06 '21 15:07 JasonFengJ9

@gacholio fyi

pshipton avatar Jul 06 '21 15:07 pshipton

Core / SDK links?

gacholio avatar Jul 06 '21 16:07 gacholio

Core / SDK links?

Passed via slack message.

JasonFengJ9 avatar Jul 06 '21 16:07 JasonFengJ9 

<59eb00> *** BEGIN STACK WALK, flags = 00400001 walkThread = 0x000000000059EB00 ***
<59eb00> 	ITERATE_O_SLOTS
<59eb00> 	RECORD_BYTECODE_PC_OFFSET
<59eb00> Initial values: walkSP = 0x00000000011C6830, PC = 0x0000000000000006, literals = 0x0000000000000008, A0 = 0x00000000011C6788, j2iFrame = 0x00000000011C6AA0, ELS = 0x000000DCBB4FF620, decomp = 0x0000000000000000
<59eb00> JIT JNI call-out frame: bp = 0x00000000011C6858, sp = 0x00000000011C6830, pc = 0x0000000000000006, cp = 0x0000000000062DC0, arg0EA = 0x00000000011C6788, flags = 0x0000000020000000
<59eb00> 	Method: java/lang/ClassLoader.defineClassImpl(Ljava/lang/String;[BIILjava/lang/Object;)Ljava/lang/Class; !j9method 0x0000000000064848
<59eb00> 	Object pushes starting at 0x00000000011C6830 for 1 slots
<59eb00> 		Push[0x00000000011C6830] = 0x00000007F0DD2510
<59eb00> JIT frame: bp = 0x00000000011C68C8, pc = 0x00007FFD65011259, unwindSP = 0x00000000011C6860, cp = 0x0000000000062DC0, arg0EA = 0x00000000011C6900, jitInfo = 0x0000028C6455DA68
<59eb00> 	Method: java/lang/ClassLoader.defineClassInternal(Ljava/lang/String;[BIILjava/security/ProtectionDomain;Z)Ljava/lang/Class; !j9method 0x0000000000064768
<59eb00> 	Bytecode index = 120, inlineDepth = 0, PC offset = 0x0000000000000231
<59eb00> 	stackMap=0x0000028C6455DBEE, slots=I16(0x0007) parmBaseOffset=I16(0x0010), parmSlots=U16(0x0006), localBaseOffset=I16(0xFFE0)
<59eb00> 	Described JIT args starting at 0x00000000011C68D8 for U16(0x0006) slots
<59eb00> 		O-Slot: : a5[0x00000000011C68D8] = 0x00000007F0DD2510
<59eb00> 		I-Slot: : a4[0x00000000011C68E0] = 0x0000000000000184
<59eb00> 		I-Slot: : a3[0x00000000011C68E8] = 0x0000000000000000
<59eb00> 		O-Slot: : a2[0x00000000011C68F0] = 0x00000007F0D10478
<59eb00> 		O-Slot: : a1[0x00000000011C68F8] = 0x00000007003D66C8
<59eb00> 		O-Slot: : a0[0x00000000011C6900] = 0x00000007F0921840
<59eb00> 	Described JIT temps starting at 0x00000000011C68A8 for IDATA(0x0000000000000004) slots
<59eb00> 		I-Slot: : t3[0x00000000011C68A8] = 0x0000000000000000
<59eb00> 		O-Slot: : t2[0x00000000011C68B0] = 0x00000007F0DD2510
<59eb00> 		O-Slot: : t1[0x00000000011C68B8] = 0x00000007F0DD2510
<59eb00> 		O-Slot: : t0[0x00000000011C68C0] = 0x0000000000000000
<59eb00> 	JIT-RegisterMap = UDATA(0x0000000000000000)
<59eb00> 	JIT-Frame-RegisterMap[0x00000000011C6890] = UDATA(0x0000000000000000) (jit_rbx)
<59eb00> 	JIT-Frame-RegisterMap[0x00000000011C6898] = UDATA(0x00000007F0921840) (jit_r9)
<59eb00> JIT inline frame: bp = 0x00000000011C69A8, pc = 0x00007FFD652B9638, unwindSP = 0x00000000011C68D0, cp = 0x0000000000062DC0, arg0EA = 0x0000000000000000, jitInfo = 0x0000028C645D51E8
<59eb00> 	Method: java/lang/ClassLoader.defineClass(Ljava/lang/String;[BIILjava/security/ProtectionDomain;)Ljava/lang/Class; !j9method 0x0000000000064748
<59eb00> 	Bytecode index = 9, inlineDepth = 2, PC offset = 0x00007FFD652B9541
<59eb00> JIT inline frame: bp = 0x00000000011C69A8, pc = 0x00007FFD652B9638, unwindSP = 0x00000000011C68D0, cp = 0x00000000000E1F70, arg0EA = 0x0000000000000000, jitInfo = 0x0000028C645D51E8
<59eb00> 	Method: java/security/SecureClassLoader.defineClass(Ljava/lang/String;[BIILjava/security/CodeSource;)Ljava/lang/Class; !j9method 0x00000000000E21E0
<59eb00> 	Bytecode index = 12, inlineDepth = 1, PC offset = 0x00007FFD652B94E1
<59eb00> JIT frame: bp = 0x00000000011C69A8, pc = 0x00007FFD652B9638, unwindSP = 0x00000000011C68D0, cp = 0x0000000000570F90, arg0EA = 0x00000000011C69C0, jitInfo = 0x0000028C645D51E8
<59eb00> 	Method: java/net/URLClassLoader.defineClass(Ljava/lang/String;Ljdk/internal/loader/Resource;)Ljava/lang/Class; !j9method 0x0000000000572488
<59eb00> 	Bytecode index = 12, inlineDepth = 0, PC offset = 0x0000000000000D10
<59eb00> 	stackMap=0x0000028C645D59E6, slots=I16(0x0003) parmBaseOffset=I16(0x0008), parmSlots=U16(0x0003), localBaseOffset=I16(0xFF98)
<59eb00> 	Described JIT args starting at 0x00000000011C69B0 for U16(0x0003) slots
<59eb00> 		O-Slot: : a2[0x00000000011C69B0] = 0x00000007F0D0ECC8
<59eb00> 		O-Slot: : a1[0x00000000011C69B8] = 0x00000007003D66C8
<59eb00> 		O-Slot: : a0[0x00000000011C69C0] = 0x00000007F0921840
<59eb00> 	Described JIT temps starting at 0x00000000011C6940 for IDATA(0x000000000000000D) slots
<59eb00> 		I-Slot: : t12[0x00000000011C6940] = 0x00000007F0D106B0
<59eb00> 		I-Slot: : t11[0x00000000011C6948] = 0x00000007F09170B0
<59eb00> 		I-Slot: : t10[0x00000000011C6950] = 0x00000007F0D0ECE8
<59eb00> 		I-Slot: : t9[0x00000000011C6958] = 0x0000000000000184
<59eb00> 		I-Slot: : t8[0x00000000011C6960] = 0x00000007F0926150
<59eb00> 		I-Slot: : t7[0x00000000011C6968] = 0x00000007F0D0ECC8
<59eb00> 		O-Slot: : t6[0x00000000011C6970] = 0x00000007F0D0ECC8
<59eb00> 		I-Slot: : t5[0x00000000011C6978] = 0x00000007F0921840
<59eb00> 		I-Slot: : t4[0x00000000011C6980] = 0x00000007F0D10620
<59eb00> 		I-Slot: : t3[0x00000000011C6988] = 0x00000007F09170B0
<59eb00> 		I-Slot: : t2[0x00000000011C6990] = 0x00000007003D66C8
<59eb00> 		O-Slot: : t1[0x00000000011C6998] = 0x00000007F0D10620
<59eb00> 		I-Slot: : t0[0x00000000011C69A0] = 0x0000000000000202
<59eb00> 	JIT-RegisterMap = UDATA(0x0000000000000202)
<59eb00> 		JIT-RegisterMap-O-Slot[0x00000000011C6890] = 0x0000000000000000 (jit_rbx)
<59eb00> 		JIT-RegisterMap-O-Slot[0x00000000011C6898] = 0x00000007F0921840 (jit_r9)
<59eb00> 	JIT-Frame-RegisterMap[0x00000000011C6920] = UDATA(0x00000007F0CECA98) (jit_rbx)
<59eb00> 	JIT-Frame-RegisterMap[0x00000000011C6928] = UDATA(0x0000000000000000) (jit_r9)
...

gacholio avatar Jul 06 '21 17:07 gacholio

Assertion is here:

https://github.com/eclipse-openj9/openj9/blob/8702ab5bbe79424943502f8b765414e84e88a09e/runtime/vm/KeyHashTable.c#L300-L321

gacholio avatar Jul 06 '21 17:07 gacholio

Hashtable nodes:

J9HashTable at 0x28c68049100 {
  Fields for J9HashTable:
	0x0: const U8* tableName = !j9x 0x00007FFD795DB130 // "C:\workspace\openjdk-build\workspace\build\src\openj9\runtime\vm\KeyHashTable.c:297"
	0x8: U32 tableSize = 0x00000011 (17)
	0xc: U32 numberOfNodes = 0x00000006 (6)
	0x10: U32 numberOfTreeNodes = 0x00000000 (0)
	0x14: U32 entrySize = 0x00000008 (8)
	0x18: U32 listNodeSize = 0x00000010 (16)
	0x1c: U32 treeNodeSize = 0x00000018 (24)
	0x20: U32 nodeAlignment = 0x00000008 (8)
	0x24: U32 flags = 0x00000009 (9)
	0x28: U32 memoryCategory = 0x00000002 (2)
	0x2c: U32 listToTreeThreshold = 0xFFFFFFFF (4294967295)
	0x30: void** nodes = !j9x 0x0000028C67C4A580
	0x38: class J9Pool* listNodePool = !j9pool 0x0000000000000000
	0x40: class J9Pool* treeNodePool = !j9pool 0x0000000000000000
	0x48: class J9Pool* treePool = !j9pool 0x0000000000000000
	0x50: class J9AVLTree* avlTreeTemplate = !j9avltree 0x0000000000000000
	0x58: void* hashFn = !j9x 0x00007FFD794F59F0
	0x60: void* hashEqualFn = !j9x 0x00007FFD794F63A0
	0x68: void* printFn = !j9x 0x0000000000000000
	0x70: class OMRPortLibrary* portLibrary = !omrportlibrary 0x00007FFD82487CF0
	0x78: void* equalFnUserData = !j9x 0x0000028C462E1550
	0x80: void* hashFnUserData = !j9x 0x0000028C462E1550
	0x88: class J9HashTable* previous = !j9hashtable 0x0000000000000000
}

0x28C67C4A580 :  0000000000000000 000000000018e900 [ ................ ] 
0x28C67C4A590 :  0000028c67f7bf81 0000000000000000 [ ...g............ ] 
0x28C67C4A5A0 :  000000000006c100 0000000000000000 [ ................ ] 
0x28C67C4A5B0 :  0000000000000000 00000000011b9d00 [ ................ ] 
0x28C67C4A5C0 :  0000000000000000 0000000000000000 [ ................ ] 
0x28C67C4A5D0 :  0000000000000000 0000000000041200 [ ................ ] 
0x28C67C4A5E0 :  000000000006a500 0000000000000000 [ ................ ] 
0x28C67C4A5F0 :  0000000000000000 0000000000000000 [ ................ ] 
0x28C67C4A600 :  0000000000000000

gacholio avatar Jul 06 '21 18:07 gacholio 

  37  Id: 1114.165c Suspend: 0 Teb: 000000dc`6b516000 Unfrozen
Child-SP          RetAddr           Call Site
000000dc`bb4fde48 00007ffd`89774daf ntdll!NtWaitForSingleObject+0x14
000000dc`bb4fde50 00007ffd`80b28e90 KERNELBASE!WaitForSingleObjectEx+0x8f
000000dc`bb4fdef0 00007ffd`7d7c5603 j9prt29!omrdump_create+0x300 [c:\workspace\openjdk-build\workspace\build\src\omr\port\win32\omrosdump.c @ 185]
000000dc`bb4fdf90 00007ffd`7d7c50f5 j9dmp29!doSystemDump+0xa3 [c:\workspace\openjdk-build\workspace\build\src\openj9\runtime\rasdump\dmpagent.c @ 751]
000000dc`bb4fdff0 00007ffd`80b2b4a6 j9dmp29!protectedDumpFunction+0x15 [c:\workspace\openjdk-build\workspace\build\src\openj9\runtime\rasdump\dmpagent.c @ 2904]
000000dc`bb4fe020 00007ffd`80b2cbe4 j9prt29!runInTryExcept+0x16 [c:\workspace\openjdk-build\workspace\build\src\omr\port\win64amd\omrsignal.c @ 220]
000000dc`bb4fe060 00007ffd`7d7c3094 j9prt29!omrsig_protect+0x214 [c:\workspace\openjdk-build\workspace\build\src\omr\port\win64amd\omrsignal.c @ 285]
000000dc`bb4fe240 00007ffd`7d7d9c95 j9dmp29!runDumpAgent+0x2f4 [c:\workspace\openjdk-build\workspace\build\src\openj9\runtime\rasdump\dmpagent.c @ 2804]
000000dc`bb4fe720 00007ffd`7d3b9fd4 j9dmp29!triggerDumpAgents+0x355 [c:\workspace\openjdk-build\workspace\build\src\openj9\runtime\rasdump\trigger.c @ 1047]
000000dc`bb4fea90 00007ffd`7d3adce0 j9trc29!triggerHit+0x314 [c:\workspace\openjdk-build\workspace\build\src\openj9\runtime\rastrace\trctrigger.c @ 1333]
000000dc`bb4feb10 00007ffd`7d3b0471 j9trc29!raiseAssertion+0xf0 [c:\workspace\openjdk-build\workspace\build\src\openj9\runtime\rastrace\trclog.c @ 2557]
000000dc`bb4fec00 00007ffd`7d3abf79 j9trc29!logTracePoint+0x441 [c:\workspace\openjdk-build\workspace\build\src\openj9\runtime\rastrace\trclog.c @ 2133]
000000dc`bb4fecf0 00007ffd`7d3a9f28 j9trc29!doTracePoint+0x109 [c:\workspace\openjdk-build\workspace\build\src\openj9\runtime\rastrace\trclog.c @ 2210]
000000dc`bb4fed30 00007ffd`794f520f j9trc29!javaTrace+0x58 [c:\workspace\openjdk-build\workspace\build\src\openj9\runtime\rastrace\trcengine.c @ 1313]
000000dc`bb4fed80 00007ffd`794b56f6 j9vm29!hashClassTableAt+0x8f [c:\workspace\openjdk-build\workspace\build\src\openj9\runtime\vm\keyhashtable.c @ 313]
000000dc`bb4fedf0 00007ffd`794b81b0 j9vm29!internalFindClassInModule+0x3e6 [c:\workspace\openjdk-build\workspace\build\src\openj9\runtime\vm\classsupport.c @ 1144]
000000dc`bb4feeb0 00007ffd`794bc4d8 j9vm29!internalFindClassUTF8+0x20 [c:\workspace\openjdk-build\workspace\build\src\openj9\runtime\vm\classsupport.c @ 1122]
000000dc`bb4feef0 00007ffd`7955a695 j9vm29!internalCreateRAMClassFromROMClass+0x348 [c:\workspace\openjdk-build\workspace\build\src\openj9\runtime\vm\createramclass.cpp @ 3456]
000000dc`bb4ff020 00007ffd`7bbdf546 j9vm29!internalDefineClass+0x8b5 [c:\workspace\openjdk-build\workspace\build\src\openj9\runtime\bcutil\defineclass.c @ 175]
000000dc`bb4ff160 00007ffd`7bbd2f3c jclse29!defineClassCommon+0x666 [c:\workspace\openjdk-build\workspace\build\src\openj9\runtime\jcl\common\jcldefine.c @ 216]

gacholio avatar Jul 13 '21 20:07 gacholio

July 9 https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.system_x86-64_windows_Nightly_testList_2/47/ ClassLoadingTest_5m_0

CLT stderr 07:11:42.938 0x1038100    j9vm.225    *   ** ASSERTION FAILED ** at F:\Users\jenkins\workspace\Build_JDK11_x86-64_windows_Nightly\openj9\runtime\vm\KeyHashTable.c:313: (!((0 != ((((UDATA)clazz)) & ((0x100 - 1))))))

pshipton avatar Jul 15 '21 19:07 pshipton

JDK8 occurrence at https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.system_x86-64_windows_Nightly/71/tapResults/

===============================================
Running test ClassLoadingTest_5m_1 ...
===============================================
ClassLoadingTest_5m_1 Start Time: Fri Aug 13 00:49:02 2021 Epoch Time (ms): 1628833742215
variation: Mode650
JVM_OPTIONS:  -XX:-UseCompressedOops 

CLT 00:49:28.903 - Completed 6.7%. Number of tests started=2651
CLT stderr 05:49:48.340 0x46bc00    j9vm.225    *   ** ASSERTION FAILED ** at F:\Users\jenkins\workspace\Build_JDK8_x86-64_windows_Nightly\openj9\runtime\vm\KeyHashTable.c:313: (!((0 != ((((UDATA)clazz)) & ((0x100 - 1))))))
CLT stderr JVMDUMP039I Processing dump event "traceassert", detail "" at 2021/08/13 00:49:48 - please wait.

ClassLoadingTest_5m_1_FAILED

To rebuild the failed tests in <Jenkins URL>=https://openj9-jenkins.osuosl.org/job/Grinder, use the following links: 01:55:10 https://openj9-jenkins.osuosl.org/job/Grinder/parambuild/?JDK_VERSION=8&JDK_IMPL=openj9&JDK_VENDOR=eclipse&BUILD_LIST=system&PLATFORM=x86-64_windows&TARGET=ClassLoadingTest_5m_1

JasonFengJ9 avatar Aug 13 '21 21:08 JasonFengJ9

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_special.system_x86-64_windows_Personal_testList_3/27/ ClassLoadingTest_special_5m_0 JVM_OPTIONS: -Xjit -Xgcpolicy:optthruput -Xnocompressedrefs

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_special.system_x86-64_windows_Personal_testList_3/27/system_test_output.tar.gz

CLT stderr 19:28:30.139 0xcf069ab700    j9vm.225    *   ** ASSERTION FAILED ** at F:\Users\jenkins\workspace\Build_JDK11_x86-64_windows_Personal\openj9\runtime\vm\KeyHashTable.c:313: (!((0 != ((((UDATA)clazz)) & ((0x100 - 1))))))

pshipton avatar Aug 24 '21 15:08 pshipton

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.system_x86-64_windows_Nightly_testList_0/19 ClassLoadingTest_CS_5m_0 -Xgcpolicy:gencon -Xgc:concurrentScavenge

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_sanity.system_x86-64_windows_Nightly_testList_0/19/system_test_output.tar.gz

CLT stderr 02:35:34.229 0x83bd00    j9vm.225    *   ** ASSERTION FAILED ** at f:\users\jenkins\workspace\build_jdk17_x86-64_windows_nightly\openj9\runtime\vm\KeyHashTable.c:313: (!((0 != ((((UDATA)clazz)) & ((0x100 - 1))))))

pshipton avatar Sep 10 '21 14:09 pshipton

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_special.system_ppc64_aix_Personal_testList_3/16 ClassLoadingTest_special_5m_0 variation: Mode101 -Xjit -Xgcpolicy:optthruput -Xnocompressedrefs

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_special.system_ppc64_aix_Personal_testList_3/16/system_test_output.tar.gz

CLT stderr 20:31:39.653 0x10021cf7500    j9vm.225    *   ** ASSERTION FAILED ** at /home/jenkins/workspace/Build_JDK11_ppc64_aix_Personal/openj9/runtime/vm/KeyHashTable.c:313: (!((0 != ((((UDATA)clazz)) & ((0x100 - 1))))))

pshipton avatar Sep 20 '21 13:09 pshipton

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.system_x86-32_windows_Nightly_testList_2/105 ClassLoadingTest_5m_2 variation: Mode1000 JVM_OPTIONS: (none)

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk8_j9_sanity.system_x86-32_windows_Nightly_testList_2/105/system_test_output.tar.gz

CLT 22:46:41.289 - Completed 6.7%. Number of tests started=2417
CLT stderr 03:46:42.429 0x26b62700    j9vm.225    *   ** ASSERTION FAILED ** at F:\Users\jenkins\workspace\Build_JDK8_x86-32_windows_Nightly\openj9\runtime\vm\KeyHashTable.c:313: (!((0 != ((((UDATA)clazz)) & ((0x100 - 1))))))

pshipton avatar Sep 28 '21 12:09 pshipton

Attempting to reproduce locally, no success so far.

gacholio avatar Sep 28 '21 16:09 gacholio

An occurrence at job/Test_openjdk17_j9_special.system_x86-64_windows_Personal/49/tapResults/

===============================================
Running test ClassLoadingTest_special_5m_15 ...
===============================================
ClassLoadingTest_special_5m_15 Start Time: Mon Oct  4 23:37:35 2021 Epoch Time (ms): 1633415855222
variation: Mode554
JVM_OPTIONS:  -Xcompressedrefs -Xgcpolicy:balanced -XXgc:tarokEnableExpensiveAssertions,fvtest_tarokPGCRotateCollectors -Xjit:count=0,optlevel=hot,gcOnResolve,rtResolve 

openjdk version "17-internal" 2021-09-14
OpenJDK Runtime Environment (build 17-internal+0-adhoc.jenkins.buildjdk17x86-64windowspersonal)
Eclipse OpenJ9 VM (build openj9-0.29.0-m2, JRE 17 Windows Server 2016 amd64-64-Bit Compressed References 20211004_72 (JIT enabled, AOT enabled)
OpenJ9   - 828307692e8
OMR      - aabfc12b978
JCL      - 23999d8072a based on jdk-17+35)

CLT stderr 06:42:44.808 0x578c00    j9vm.225    *   ** ASSERTION FAILED ** at c:\users\jenkins\workspace\build_jdk17_x86-64_windows_personal\openj9\runtime\vm\KeyHashTable.c:313: (!((0 != ((((UDATA)clazz)) & ((0x100 - 1))))))
CLT stderr JVMDUMP039I Processing dump event "traceassert", detail "" at 2021/10/04 23:42:44 - please wait.

ClassLoadingTest_special_5m_15_FAILED

JasonFengJ9 avatar Oct 05 '21 12:10 JasonFengJ9

Occurred at JDK11 0.29.0 release build job/Test_openjdk11_j9_special.system_x86-64_windows_testList_2/95/tapResults/ (win16x64rt-1-3a)

[2021-10-23T00:35:51.130Z] Running test ClassLoadingTest_special_5m_29 ...
[2021-10-23T00:35:51.907Z] ===============================================
[2021-10-23T00:35:51.907Z] ClassLoadingTest_special_5m_29 Start Time: Fri Oct 22 17:35:51 2021 Epoch Time (ms): 1634949351735
[2021-10-23T00:35:51.907Z] "C:/Users/jenkins/workspace/Test_openjdk11_j9_special.system_x86-64_windows_testList_2/openjdkbinary/j2sdk-image\\bin\\java" -Xshareclasses:destroyAll; "C:/Users/jenkins/workspace/Test_openjdk11_j9_special.system_x86-64_windows_testList_2/openjdkbinary/j2sdk-image\\bin\\java" -Xshareclasses:groupAccess,destroyAll; echo "cache cleanup done";
[2021-10-23T00:35:53.524Z] JVMSHRC005I No shared class caches available
[2021-10-23T00:35:54.256Z] JVMSHRC005I No shared class caches available
[2021-10-23T00:35:54.256Z] cache cleanup done
[2021-10-23T00:35:54.256Z] variation: -Xgcpolicy:gencon -Xgc:dynamicBreadthFirstScanOrdering
[2021-10-23T00:35:55.021Z] JVM_OPTIONS:  -Xgcpolicy:gencon -Xgc:dynamicBreadthFirstScanOrdering 

[2021-10-23T00:36:04.260Z] java version "11.0.13" 2021-10-19
[2021-10-23T00:36:04.260Z] IBM Semeru Runtime Certified Edition 11.0.13.0 (build 11.0.13+8)
[2021-10-23T00:36:04.260Z] Eclipse OpenJ9 VM 11.0.13.0 (build openj9-0.29.0, JRE 11 Windows Server 2016 amd64-64-Bit Compressed References 20211022_171 (JIT enabled, AOT enabled)
[2021-10-23T00:36:04.260Z] OpenJ9   - e1e72c497
[2021-10-23T00:36:04.260Z] OMR      - 299b6a2d2
[2021-10-23T00:36:04.260Z] JCL      - 43ed76284c based on jdk-11.0.13+8)

[2021-10-23T00:39:28.916Z] CLT 17:39:26.878 - Completed 66.7%. Number of tests started=44532 (+5359)
[2021-10-23T00:39:40.455Z] CLT stderr 00:39:38.935 0x52b400    j9vm.225    *   ** ASSERTION FAILED ** at C:\workspace\openjdk-build\workspace\build\src\openj9\runtime\vm\KeyHashTable.c:313: (!((0 != ((((UDATA)clazz)) & ((0x100 - 1))))))
[2021-10-23T00:39:40.455Z] CLT stderr JVMDUMP039I Processing dump event "traceassert", detail "" at 2021/10/22 17:39:38 - please wait.
[2021-10-23T00:39:40.455Z] CLT stderr JVMDUMP032I JVM requested System dump using 'C:\Users\jenkins\workspace\Test_openjdk11_j9_special.system_x86-64_windows_testList_2\aqa-tests\TKG\output_16349309878300\ClassLoadingTest_special_5m_29\20211022-173555-ClassloadingLoadTest\results\core.20211022.173938.3504.0001.dmp' in response to an event
[2021-10-23T00:39:40.455Z] STF 17:39:39.105 - Found dump at: C:\Users\jenkins\workspace\Test_openjdk11_j9_special.system_x86-64_windows_testList_2\aqa-tests\TKG\output_16349309878300\ClassLoadingTest_special_5m_29\20211022-173555-ClassloadingLoadTest\results\core.20211022.173938.3504.0001.dmp
[2021-10-23T00:39:40.455Z] CLT stderr core file generated - C:\Users\jenkins\workspace\Test_openjdk11_j9_special.system_x86-64_windows_testList_2\aqa-tests\TKG\output_16349309878300\ClassLoadingTest_special_5m_29\20211022-173555-ClassloadingLoadTest\results\core.20211022.173938.3504.0001.dmp
[2021-10-23T00:39:59.255Z] CLT 17:39:56.406 - Completed 76.6%. Number of tests started=47201 (+2669)
[2021-10-23T00:39:59.255Z] CLT stderr 04.0001.dmp
[2021-10-23T00:39:59.255Z] CLT stderr JVMDUMP032I JVM requested Java dump using 'C:\Users\jenkins\workspace\Test_openjdk11_j9_special.system_x86-64_windows_testList_2\aqa-tests\TKG\output_16349309878300\ClassLoadingTest_special_5m_29\20211022-173555-ClassloadingLoadTest\results\javacore.20211022.173938.3504.0002.txt' in response to an event
[2021-10-23T00:39:59.255Z] STF 17:39:56.859 - Found dump at: C:\Users\jenkins\workspace\Test_openjdk11_j9_special.system_x86-64_windows_testList_2\aqa-tests\TKG\output_16349309878300\ClassLoadingTest_special_5m_29\20211022-173555-ClassloadingLoadTest\results\javacore.20211022.173938.3504.0002.txt
[2021-10-23T00:39:59.255Z] CLT stderr javacore file generated - C:\Users\jenkins\workspace\Test_openjdk11_j9_special.system_x86-64_windows_testList_2\aqa-tests\TKG\output_16349309878300\ClassLoadingTest_special_5m_29\20211022-173555-ClassloadingLoadTest\results\javacore.20211022.173938.3504.0002.txt
[2021-10-23T00:40:24.713Z] CLT 17:40:24.140 - Completed 85.8%. Number of tests started=47215 (+14)
[2021-10-23T00:40:24.713Z] CLT stderr 2.txt
[2021-10-23T00:40:24.713Z] CLT stderr JVMDUMP032I JVM requested Snap dump using 'C:\Users\jenkins\workspace\Test_openjdk11_j9_special.system_x86-64_windows_testList_2\aqa-tests\TKG\output_16349309878300\ClassLoadingTest_special_5m_29\20211022-173555-ClassloadingLoadTest\results\Snap.20211022.173938.3504.0003.trc' in response to an event
[2021-10-23T00:40:24.713Z] STF 17:40:24.165 - Found dump at: C:\Users\jenkins\workspace\Test_openjdk11_j9_special.system_x86-64_windows_testList_2\aqa-tests\TKG\output_16349309878300\ClassLoadingTest_special_5m_29\20211022-173555-ClassloadingLoadTest\results\Snap.20211022.173938.3504.0003.trc
[2021-10-23T00:40:24.713Z] CLT stderr JVMDUMP010I Snap dump written to C:\Users\jenkins\workspace\Test_openjdk11_j9_special.system_x86-64_windows_testList_2\aqa-tests\TKG\output_16349309878300\ClassLoadingTest_special_5m_29\20211022-173555-ClassloadingLoadTest\results\Snap.20211022.173938.3504.0003.trc
[2021-10-23T00:40:24.713Z] CLT stderr JVMDUMP013I Processed dump event "traceassert", detail "".
[2021-10-23T00:40:25.446Z] STF 17:40:25.185 - **FAILED** Process CLT ended with exit code (4294967295) and not the expected exit code/s (0)
[2021-10-23T00:40:25.446Z] STF 17:40:25.186 - Monitoring Report Summary:
[2021-10-23T00:40:25.446Z] STF 17:40:25.186 -   o Process CLT has crashed unexpectedly
[2021-10-23T00:40:25.446Z] STF 17:40:25.187 - Killing processes: CLT
[2021-10-23T00:40:25.446Z] STF 17:40:25.188 -   o Process CLT pid 3504 is not running
[2021-10-23T00:40:25.446Z] **FAILED** at step 1 (Run classloading tests). Expected return value=0 Actual=1 at C:/Users/jenkins/workspace/Test_openjdk11_j9_special.system_x86-64_windows_testList_2/aqa-tests/\TKG\output_16349309878300\ClassLoadingTest_special_5m_29/20211022-173555-ClassloadingLoadTest/execute.pl line 98.
[2021-10-23T00:40:26.177Z] STF 17:40:25.722 - **FAILED** execute script failed. Expected return value=0 Actual=1
[2021-10-23T00:40:26.177Z] STF 17:40:25.722 - 
[2021-10-23T00:40:26.177Z] STF 17:40:25.722 - ====================   T E A R D O W N   ====================
[2021-10-23T00:40:26.177Z] STF 17:40:25.722 - Running teardown: perl C:/Users/jenkins/workspace/Test_openjdk11_j9_special.system_x86-64_windows_testList_2/aqa-tests/\TKG\output_16349309878300\ClassLoadingTest_special_5m_29/20211022-173555-ClassloadingLoadTest/tearDown.pl
[2021-10-23T00:40:26.177Z] STF 17:40:26.049 - TEARDOWN stage completed
[2021-10-23T00:40:26.177Z] STF 17:40:26.083 - 
[2021-10-23T00:40:26.177Z] STF 17:40:26.083 - =====================   R E S U L T S   =====================
[2021-10-23T00:40:26.177Z] STF 17:40:26.083 - Stage results:
[2021-10-23T00:40:26.177Z] STF 17:40:26.083 -   setUp:     pass
[2021-10-23T00:40:26.177Z] STF 17:40:26.083 -   execute:  *fail*
[2021-10-23T00:40:26.177Z] STF 17:40:26.083 -   teardown:  pass
[2021-10-23T00:40:26.177Z] STF 17:40:26.083 - 
[2021-10-23T00:40:26.177Z] STF 17:40:26.083 - Overall result: **FAILED**
[2021-10-23T00:40:26.177Z] 
[2021-10-23T00:40:26.177Z] ClassLoadingTest_special_5m_29_FAILED

JasonFengJ9 avatar Oct 25 '21 14:10 JasonFengJ9

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_special.system_x86-64_windows_Personal_testList_3/47 ClassLoadingTest_special_5m_0 -Xjit -Xgcpolicy:optthruput -Xnocompressedrefs

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_special.system_x86-64_windows_Personal_testList_3/47/system_test_output.tar.gz

CLT stderr 19:25:05.979 0x4eb563800    j9vm.225    *   ** ASSERTION FAILED ** at F:\Users\jenkins\workspace\Build_JDK11_x86-64_windows_Personal\openj9\runtime\vm\KeyHashTable.c:313: (!((0 != ((((UDATA)clazz)) & ((0x100 - 1))))))

pshipton avatar Nov 01 '21 13:11 pshipton

From an internal build job/Test_openjdk17_j9_special.system_x86-64_windows_testList_2/74/tapResults/ (win16x64rt2-2)

CLT 05:14:09.330 - Completed 81.2%. Number of tests started=13700 (+1095)
CLT stderr 13:14:10.549 0x2e0aa702900    j9vm.225    *   ** ASSERTION FAILED ** at c:\workspace\openjdk-build\workspace\build\src\openj9\runtime\vm\KeyHashTable.c:313: (!((0 != ((((UDATA)clazz)) & ((0x100 - 1))))))
CLT stderr JVMDUMP039I Processing dump event "traceassert", detail "" at 2021/11/17 05:14:10 - please wait.

JasonFengJ9 avatar Nov 18 '21 13:11 JasonFengJ9

With the change in #13969 this failure will now manifest as a print to the console followed by the "unreachable" assertion instead.

gacholio avatar Nov 23 '21 17:11 gacholio

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.system_x86-64_windows_Nightly_testList_0/160 ClassLoadingTest_5m_1 -XX:-UseCompressedOops

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk8_j9_sanity.system_x86-64_windows_Nightly_testList_0/160/system_test_output.tar.gz

CLT stderr <000000B69C7A9100> hashClassTableAt: Unaligned class value 000000B69F5413A1
CLT stderr 07:51:12.368 0xb69c7a9100    j9vm.249    *   ** ASSERTION FAILED ** at F:\Users\jenkins\workspace\Build_JDK8_x86-64_windows_Nightly\openj9\runtime\vm\KeyHashTable.c:73: ((0 ))

pshipton avatar Nov 29 '21 13:11 pshipton

0x000000B69F5413A1 is the tagged ROM class for:

Class Name: net/adoptopenjdk/test/classloading/deadlock/package2/CL2_B
Superclass Name: java/lang/Object

The tag indicates this is in the table as a package ID.

> !stackslots 0x000000B69C7A9100
<b69c7a9100> *** BEGIN STACK WALK, flags = 00400001 walkThread = 0x000000B69C7A9100 ***
<b69c7a9100> 	ITERATE_O_SLOTS
<b69c7a9100> 	RECORD_BYTECODE_PC_OFFSET
<b69c7a9100> Initial values: walkSP = 0x000000B69C6F53D0, PC = 0x0000000000000006, literals = 0x0000000000000008, A0 = 0x000000B69C6F5178, j2iFrame = 0x000000B69C6F5660, ELS = 0x000000B69EEFF7F0, decomp = 0x0000000000000000
<b69c7a9100> JIT JNI call-out frame: bp = 0x000000B69C6F53F8, sp = 0x000000B69C6F53D0, pc = 0x0000000000000006, cp = 0x000000B69AD785B0, arg0EA = 0x000000B69C6F5178, flags = 0x0000000020000000
<b69c7a9100> 	Method: java/lang/ClassLoader.defineClassImpl(Ljava/lang/String;[BIILjava/lang/Object;)Ljava/lang/Class; !j9method 0x000000B69AD79B50
<b69c7a9100> 	Object pushes starting at 0x000000B69C6F53D0 for 1 slots
<b69c7a9100> 		Push[0x000000B69C6F53D0] = 0x00007FF71F039B08
<b69c7a9100> JIT inline frame: bp = 0x000000B69C6F5528, pc = 0x00007FFF4F8B6170, unwindSP = 0x000000B69C6F5400, cp = 0x000000B69AD785B0, arg0EA = 0x0000000000000000, jitInfo = 0x000000B69B3EDEA8
<b69c7a9100> 	Method: java/lang/ClassLoader.defineClassInternal(Ljava/lang/String;[BIILjava/security/ProtectionDomain;Z)Ljava/lang/Class; !j9method 0x000000B69AD79A90
<b69c7a9100> 	Bytecode index = 120, inlineDepth = 3, PC offset = 0x000000000009ED28
<b69c7a9100> JIT inline frame: bp = 0x000000B69C6F5528, pc = 0x00007FFF4F8B6170, unwindSP = 0x000000B69C6F5400, cp = 0x000000B69AD785B0, arg0EA = 0x0000000000000000, jitInfo = 0x000000B69B3EDEA8
<b69c7a9100> 	Method: java/lang/ClassLoader.defineClass(Ljava/lang/String;[BIILjava/security/ProtectionDomain;)Ljava/lang/Class; !j9method 0x000000B69AD79A70
<b69c7a9100> 	Bytecode index = 9, inlineDepth = 2, PC offset = 0x000000000029F148
<b69c7a9100> JIT inline frame: bp = 0x000000B69C6F5528, pc = 0x00007FFF4F8B6170, unwindSP = 0x000000B69C6F5400, cp = 0x000000B69ADF0BF0, arg0EA = 0x0000000000000000, jitInfo = 0x000000B69B3EDEA8
<b69c7a9100> 	Method: java/security/SecureClassLoader.defineClass(Ljava/lang/String;[BIILjava/security/CodeSource;)Ljava/lang/Class; !j9method 0x000000B69ADF0F18
<b69c7a9100> 	Bytecode index = 12, inlineDepth = 1, PC offset = 0x00000000000023E8
<b69c7a9100> JIT frame: bp = 0x000000B69C6F5528, pc = 0x00007FFF4F8B6170, unwindSP = 0x000000B69C6F5400, cp = 0x000000B69ADF0FE0, arg0EA = 0x000000B69C6F5540, jitInfo = 0x000000B69B3EDEA8
<b69c7a9100> 	Method: java/net/URLClassLoader.defineClass(Ljava/lang/String;Lsun/misc/Resource;)Ljava/lang/Class; !j9method 0x000000B69ADF2808
<b69c7a9100> 	Bytecode index = 12, inlineDepth = 0, PC offset = 0x0000000000000AA8
<b69c7a9100> 	stackMap=0x000000B69B3EE430, slots=I16(0x0003) parmBaseOffset=I16(0x0008), parmSlots=U16(0x0003), localBaseOffset=I16(0xFF50)
<b69c7a9100> 	Described JIT args starting at 0x000000B69C6F5530 for U16(0x0003) slots
<b69c7a9100> 		O-Slot: : a2[0x000000B69C6F5530] = 0x00007FF71F3E33A8
<b69c7a9100> 		O-Slot: : a1[0x000000B69C6F5538] = 0x00007FF6A2F70B88
<b69c7a9100> 		O-Slot: : a0[0x000000B69C6F5540] = 0x00007FF71F093548

> !j9x 0x00007FF6A2F70B88,100,8
0x7FF6A2F70B88 :  000000b69ad12600 00007ff6a2f70ba0 [ .&.............. ] 
0x7FF6A2F70B98 :  ce9f0c160000003a 000000b69ad0e100 [ :............... ] 
0x7FF6A2F70BA8 :  000000000000003a 00007ff6a2f70bb8 [ :............... ] 
0x7FF6A2F70BB8 :  002e00740065006e 0070006f00640061 [ n.e.t...a.d.o.p. ] 
0x7FF6A2F70BC8 :  00650070006f0074 006b0064006a006e [ t.o.p.e.n.j.d.k. ] 
0x7FF6A2F70BD8 :  007300650074002e 006c0063002e0074 [ ..t.e.s.t...c.l. ] 
0x7FF6A2F70BE8 :  006c007300730061 006900640061006f [ a.s.s.l.o.a.d.i. ] 
0x7FF6A2F70BF8 :  0064002e0067006e 006c006400610065 [ n.g...d.e.a.d.l. ] 
0x7FF6A2F70C08 :  002e006b0063006f 006b006300610070 [ o.c.k...p.a.c.k. ] 
0x7FF6A2F70C18 :  0032006500670061 0032004c0043002e [ a.g.e.2...C.L.2. ] 
0x7FF6A2F70C28 :  000000000043005f 000000b69aba250a [ _.C......%...... ]

The class being loaded is _C, not sure how we get to _B.

gacholio avatar Nov 29 '21 18:11 gacholio

The package ID value and the RAM class are in the hash table:

> !j9x 0x000000B69FA2AFB0,100,8
0xB69FA2AFB0 :  0000000000000000 000000b69af4d900 [ ................ ] 
0xB69FA2AFC0 :  000000b69f5413a1 0000000000000000 [ ..T............. ] 
0xB69FA2AFD0 :  000000b69ad81700 0000000000000000 [ ................ ] 
0xB69FA2AFE0 :  0000000000000000 000000b69f65bc00 [ ..........e..... ] 
0xB69FA2AFF0 :  0000000000000000 0000000000000000 [ ................ ] 
0xB69FA2B000 :  0000000000000000 000000b69ab9b600 [ ................ ] 
0xB69FA2B010 :  000000b69ad7fa00 0000000000000000 [ ................ ] 
0xB69FA2B020 :  0000000000000000 0000000000000000 [ ................ ] 
0xB69FA2B030 :  0000000000000000 2fb5d427b7654321 [ ........!Ce.'../ ] 
> !j9class 0x000000b69f65bc00
J9Class at 0xb69f65bc00 {
  Fields for J9Class:
	0x0: U64 eyecatcher = 0x0000000099669966 (2573637990)
	0x8: class J9ROMClass* romClass = !j9romclass 0x000000B69F5413A0
	0x10: void** superclasses = !j9x 0x000000B69F65BDB0
	0x18: U64 classDepthAndFlags = 0x00000000000E0001 (917505)
	0x20: U32 classDepthWithFlags = 0x00000000 (0)
	0x24: U32 classFlags = 0x00000000 (0)
	0x28: class J9ClassLoader* classLoader = !j9classloader 0x000000B69F5582D8
	0x30: class J9Object* classObject = !j9object 0x00007FF6A31B4B58 // java/lang/Class
	0x38: volatile U64 initializeStatus = 0x0000000000000003 (3)
	0x40: class J9Method* ramMethods = !j9method 0x000000B69F65BE18 // net/adoptopenjdk/test/classloading/deadlock/package2/CL2_B.<init>()V
	0x48: U64* ramStatics = !j9x 0x0000000000000000
	0x50: class J9Class* arrayClass = !j9class 0x0000000000000000
	0x58: U64 totalInstanceSize = 0x0000000000000008 (8)
	0x60: class J9ITable* lastITable = !j9itable 0x00007FFF636527A8
	0x68: U64* instanceDescription = !j9x 0x0000000000000001
	0x70: U64* instanceLeafDescription = !j9x 0x0000000000000001
	0x78: U64 instanceHotFieldDescription = 0x0000000000000000 (0)
	0x80: U64 selfReferencingField1 = 0x0000000000000000 (0)
	0x88: U64 selfReferencingField2 = 0x0000000000000000 (0)
	0x90: class J9Method* initializerCache = !j9method 0x0000000000000000
	0x98: U64 romableAotITable = 0x00007FFF631AAA10 (140734856079888)
	0xa0: U64 packageID = 0x000000B69F5413A1 (784357135265)
	0xa8: class J9Module* module = !j9module 0x0000000000000000
	0xb0: class J9Class* subclassTraversalLink = !j9class 0x000000B69F65B400 // net/adoptopenjdk/test/classloading/deadlock/package1/CL1_A
	0xb8: class J9Class* subclassTraversalReverseLink = !j9class 0x000000B69F65E200 // net/adoptopenjdk/test/classloading/deadlock/package1/CL1_A
	0xc0: void** iTable = !j9x 0x0000000000000000
	0xc8: U64 castClassCache = 0x0000000000000000 (0)
	0xd0: void** jniIDs = !j9x 0x0000000000000000
	0xd8: U64 lockOffset = 0x0000000000000008 (8)
	0xe0: U32 paddingForGLRCounters = 0x00000000 (0)
	0xe4: U16 reservedCounter = 0x0000 (0)
	0xe6: U16 cancelCounter = 0x0000 (0)
	0xe8: U64 newInstanceCount = 0x0000000000000BB8 (3000)
	0xf0: I64 backfillOffset = 0x0000000000000010 (16)
	0xf8: class J9Class* replacedClass = !j9class 0x0000000000000000
	0x100: U64 finalizeLinkOffset = 0x0000000000000000 (0)
	0x108: class J9Class* nextClassInSegment = !j9class 0x0000000000000000
	0x110: U64* ramConstantPool = !j9x 0x000000B69F65BDE0
	0x118: void** callSites = !j9x 0x0000000000000000
	0x120: void** methodTypes = !j9x 0x0000000000000000
	0x128: void** varHandleMethodTypes = !j9x 0x0000000000000000
	0x130: class J9VMCustomSpinOptions* customSpinOption = !j9vmcustomspinoptions 0x0000000000000000
	0x138: void** staticSplitMethodTable = !j9x 0x0000000000000000
	0x140: void** specialSplitMethodTable = !j9x 0x0000000000000000
	0x148: class J9JITExceptionTable* jitMetaDataList = !j9jitexceptiontable 0x0000000000000000
	0x150: class J9Class* gcLink = !j9class 0x0000000000000000
	0x158: class J9Class* hostClass = !j9class 0x000000B69F65BC00 // net/adoptopenjdk/test/classloading/deadlock/package2/CL2_B
	0x160: class J9FlattenedClassCache* flattenedClassCache = !j9flattenedclasscache 0x0000000000000000
	0x168: class J9ClassHotFieldsInfo* hotFieldsInfo = !j9classhotfieldsinfo 0x0000000000000000
}
Class name: net/adoptopenjdk/test/classloading/deadlock/package2/CL2_B

gacholio avatar Nov 29 '21 18:11 gacholio

I've looked through the code again and I still don't see how we could get this wrong. The table appears well-formed and there's no possibility of slot re-use in hash tables that aren't being deleted from.

gacholio avatar Nov 30 '21 16:11 gacholio

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.system_x86-64_windows_Nightly_testList_2/104/tapResults/ ClassLoadingTest_5m_1 -XX:-UseCompressedOops

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_sanity.system_x86-64_windows_Nightly_testList_2/104/system_test_output.tar.gz

CLT stderr <000000879DB74D00> hashClassTableAt: Unaligned class value 00000087A1F2A051
CLT stderr 04:53:06.664 0x879db74d00    j9vm.249    *   ** ASSERTION FAILED ** at f:\users\jenkins\workspace\build_jdk17_x86-64_windows_nightly\openj9\runtime\vm\KeyHashTable.c:73: ((0 ))

pshipton avatar Dec 06 '21 17:12 pshipton

Observed at an internal build job/Test_openjdk11_j9_special.system_x86-64_windows_testList_2/122/.

java version "11.0.14-beta" 2022-01-18
IBM Semeru Runtime Certified Edition 11.0.14+6-202112100209 (build 11.0.14-beta+6-202112100209)
Eclipse OpenJ9 VM 11.0.14+6-202112100209 (build master-9f6e55d3a, JRE 11 Windows Server 2016 amd64-64-Bit Compressed References 20211210_206 (JIT enabled, AOT enabled)
OpenJ9   - 9f6e55d3a
OMR      - 5a958d708
JCL      - c7623ca29d based on jdk-11.0.14+6)

[2021-12-10T09:59:10.392Z] variation: Mode107
[2021-12-10T09:59:10.392Z] JVM_OPTIONS:  -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:count=0 -Xnocompressedrefs 

[2021-12-10T10:00:58.163Z] CLT stderr 
[2021-12-10T10:00:58.163Z] CLT stderr <0000024347799500> hashClassTableAt: Unaligned class value 0000024347B960F1
[2021-12-10T10:00:58.164Z] CLT stderr 10:00:56.846 0x24347799500    j9vm.249    *   ** ASSERTION FAILED ** at C:\workspace\openjdk-build\workspace\build\src\openj9\runtime\vm\KeyHashTable.c:73: ((0 ))
[2021-12-10T10:00:58.164Z] CLT stderr JVMDUMP039I Processing dump event "traceassert", detail "" at 2021/12/10 02:00:56 - please wait.

[2021-12-10T10:01:19.015Z] ClassLoadingTest_special_5m_3_FAILED

JasonFengJ9 avatar Dec 10 '21 13:12 JasonFengJ9

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.system_ppc64_aix_Release_testList_1/16 - aix71-p8-8 ClassLoadingTest_5m_1 -XX:-UseCompressedOops

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk8_j9_sanity.system_ppc64_aix_Release_testList_1/16/system_test_output.tar.gz

CLT 00:23:36.278 - Completed 53.4%. Number of tests started=10433 (+1397)
CLT stderr 
CLT stderr <000001002463B700> hashClassTableAt: Unaligned class value 0000010027493D31
CLT stderr 05:23:37.782 0x1002463b700    j9vm.249    *   ** ASSERTION FAILED ** at /home/jenkins/workspace/Build_JDK8_ppc64_aix_Release/openj9/runtime/vm/KeyHashTable.c:73: ((0 ))

pshipton avatar Dec 20 '21 15:12 pshipton

I have a customer reporting the same assert on JRE 1.8.0 z/OS s390x-64 (build 8.0.6.0 - pmz6480sr6-20191107_01(SR6)) .. The assert text is: 05:25:04.251924703 0x123A3100 j9vm.225 Assert * ** ASSERTION FAILED ** at ./KeyHashTable.c:288: (!((0 != ((((UDATA)clazz)) & ((0x100 - 1))))))

with crashing stack: {libj9trc29.so}{logTracePoint} {libj9trc29.so}{doTracePoint} {libj9trc29.so}{javaTrace} {libj9vm29.so}{hashClassTableAt} {libj9vm29.so}{loadNonArrayClass} {libj9vm29.so}{internalFindClassUTF8} {libj9jit29.so}{jitGetClassFromUTF8} {libj9jit29.so}{TR_J9VM::getClassFromSignature(const char*,int,J9ConstantPool*)} {libj9jit29.so}{TR::SymbolValidationManager::validateWellKnownClasses(const unsigned long*)} {libj9jit29.so}{TR_RelocationRecordGroup::applyRelocations(TR_RelocationRuntime*,TR_RelocationTarget*,unsig...} {libj9jit29.so}{TR_RelocationRuntime::relocateAOTCodeAndData(unsigned char*,unsigned char*,unsigned char*,u...}

This looks very similar to the one being discussed here

SajinaKandy avatar Jan 18 '22 20:01 SajinaKandy

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.system_ppc64_aix_Nightly_testList_0/197

pshipton avatar Jan 31 '22 16:01 pshipton

Hi @gacholio were you able to get anything more on this. The customer who reported this case is asking for more details about the possible cause and a possible workaround with any VM arguments if at all possible. Thanks !

SajinaKandy avatar Feb 09 '22 18:02 SajinaKandy

No, there has been no progress in determining the root cause.

You could ask the customer to try -XX:-FastClassHashTable

gacholio avatar Feb 09 '22 20:02 gacholio