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.28k stars 721 forks source link

Non-fatal assert triggered in sanity.functional with JITServer and AOT cache during ROM class packing #20046

Open cjjdespres opened 2 months ago

cjjdespres commented 2 months ago

I encountered this when running sanity.functional manually with JITServer+AOT cache (with an appropriate JITServer instance started up manually on the side) with a debug compiler configuration to test the code I wrote to ensure that methods are fully invalidated in the JITServer AOT deserializer's cache. The failure should be unrelated to those changes. The failure was in cmdLineTester_J9securityTests_0, which was the first non-excluded test that was run - I stopped the suite after that. Console log:

Running test cmdLineTester_J9securityTests_0 ...
===============================================
cmdLineTester_J9securityTests_0 Start Time: Thu Aug 22 16:26:48 2024 Epoch Time (ms): 1724358408430
variation: NoOptions
JVM_OPTIONS:  -XX:+UseJITServer -XX:JITServerPort=23789 -XX:+JITServerUseAOTCache -XX:+JITServerAOTCacheIgnoreLocalSCC -Xjit:verbose={JITServer},vlog=clientvlog.txt,suffixLogs

TESTING:
*** Starting test suite: J9 Security Tests ***
Testing: testJ9Security
Test start time: 2024/08/22 16:26:49 Eastern Standard Time
Running command: "/home/despresc/dev/testing/openj9-openjdk-jdk21/build/linux-x86_64-server-release/images/jdk/bin/java" -Djava.security.manager=allow  -XX:+UseJITServer -XX:JITServerPort=23789 -XX:+JITServerUseAOTCache -XX:+JITServerAOTCacheIgnoreLocalSCC -Xjit:verbose={JITServer},vlog=clientvlog.txt,suffixLogs -Xdump -cp "/home/despresc/dev/testing/tests-openj9-openjdk-jdk21/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/J9security/"j9security.jar com.ibm.j9.security.TestImplies
Time spent starting: 96 milliseconds
Time spent executing: 3166 milliseconds
Test result: FAILED
Output from test:
 [ERR] Assertion failed at /home/despresc/dev/testing/openj9-openjdk-jdk21/openj9/runtime/compiler/control/JITServerHelpers.cpp:332: (dst < ctx._cursor) && (memcmp(dst, str, J9UTF8_TOTAL_SIZE(str)) == 0)
 [ERR]  Must be already copied

 [ERR] Unhandled exception
 [ERR] Type=Unhandled trap vmState=0x00000000
 [ERR] J9Generic_Signal_Number=00000108 Signal_Number=00000005 Error_Value=00000000 Signal_Code=fffffffa
 [ERR] Handler1=00007FF3812EE0C0 Handler2=00007FF380E56B70
 [ERR] RDI=0000000000000002 RSI=00007FF38350B030 RAX=0000000000000000 RBX=0000000000000005
 [ERR] RCX=00007FF382CC8BBF RDX=0000000000000000 R8=0000000000000000 R9=00007FF38350B030
 [ERR] R10=0000000000000008 R11=0000000000000246 R12=000000000000014C R13=00007FF36E9E4718
 [ERR] R14=00007FF36E9E4903 R15=0000000000000001
 [ERR] RIP=00007FF382CC8BBF GS=0000 FS=0000 RSP=00007FF38350B030
 [ERR] EFlags=0000000000000246 CS=0033 RBP=00007FF36E9E3FA0 ERR=0000000000000000
 [ERR] TRAPNO=0000000000000000 OLDMASK=0000000000000000 CR2=0000000000000000
 [ERR] xmm0=42656c62616e655f (f: 1634624896.000000, d: 7.361016e+11)
 [ERR] xmm1=00000000000000ff (f: 255.000000, d: 1.259867e-321)
 [ERR] xmm2=0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] xmm3=ffffffffffffff00 (f: 4294967040.000000, d: -nan)
 [ERR] xmm4=ffffffffffffff00 (f: 4294967040.000000, d: -nan)
 [ERR] xmm5=0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] xmm6=0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] xmm7=00007ff38350d508 (f: 2203112704.000000, d: 6.950706e-310)
 [ERR] xmm8=0405060700010203 (f: 66051.000000, d: 2.696622e-289)
 [ERR] xmm9=89753b9b2305d7c9 (f: 587585472.000000, d: -4.214362e-263)
 [ERR] xmm10=8b68dcdcbd102093 (f: 3171950848.000000, d: -1.059748e-253)
 [ERR] xmm11=0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] xmm12=0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] xmm13=0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] xmm14=0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] xmm15=0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] Module=/lib64/libpthread.so.0
 [ERR] Module_base_address=00007FF382CB6000 Symbol=raise
 [ERR] Symbol_address=00007FF382CC8AB0
 [ERR] Target=2_90_20240802_000000 (Linux 4.18.0-553.8.1.el8_10.x86_64)
 [ERR] CPU=amd64 (8 logical CPUs) (0x7c7919000 RAM)
 [ERR] ----------- Stack Backtrace -----------
 [ERR] raise+0x10f (0x00007FF382CC8BBF [libpthread.so.0+0x12bbf])
 [ERR] _ZN2TR4trapEv+0x47 (0x00007FF36E621E5D [libj9jit29.so+0x5a2e5d])
 [ERR] _ZN2TR15fatal_assertionEPKciS1_S1_z+0x0 (0x00007FF36E62208C [libj9jit29.so+0x5a308c])
 [ERR] _ZN2TR9assertionEPKciS1_S1_z+0xcc (0x00007FF36E62229B [libj9jit29.so+0x5a329b])
 [ERR] _ZL12packCallbackPK10J9ROMClassPKiPKcR19ROMClassPackContext+0x105 (0x00007FF36E2A0BF8 [libj9jit29.so+0x221bf8])
 [ERR] _ZL16utf8SlotCallbackPK10J9ROMClassPKiPKcPv+0xc (0x00007FF36E29EEC7 [libj9jit29.so+0x21fec7])
 [ERR] _ZL12slotCallbackP10J9ROMClassjPvPKcS1_+0x5f (0x00007FF36E29EF67 [libj9jit29.so+0x21ff67])
 [ERR] allSlotsInROMClassDo+0xb88 (0x00007FF36E93B228 [libj9jit29.so+0x8bc228])
 [ERR] _ZN16JITServerHelpers12packROMClassEPK10J9ROMClassP9TR_MemoryP11TR_J9VMBaseRmmm+0x82d (0x00007FF36E2A09DB [libj9jit29.so+0x2219db])
 [ERR] _ZN21JITServerROMClassHash4initEPK10J9ROMClassR9TR_MemoryP11TR_J9VMBasebm+0xb1 (0x00007FF36E53BE9B [libj9jit29.so+0x4bce9b])
 [ERR] _ZN21JITServerROMClassHashC2EPK10J9ROMClassR9TR_MemoryP11TR_J9VMBasebm+0xd (0x00007FF36E52BA33 [libj9jit29.so+0x4aca33])
 [ERR] _ZN24JITServerAOTDeserializer11onClassLoadEP7J9ClassP10J9VMThread+0x296 (0x00007FF36E529EF0 [libj9jit29.so+0x4aaef0])
 [ERR] jitHookClassLoadHelper+0x125 (0x00007FF36E1D726A [libj9jit29.so+0x15826a])
 [ERR] jitHookClassLoad+0x8e (0x00007FF36E1D808D [libj9jit29.so+0x15908d])
 [ERR] J9HookDispatch+0x150 (0x00007FF3810A5480 [libj9hookable29.so+0x1480])
 [ERR] internalCreateRAMClassDone+0x1ad (0x00007FF3812D8E3D [libj9vm29.so+0x2ee3d])
 [ERR] internalCreateRAMClassFromROMClassImpl+0x593 (0x00007FF3812D9F13 [libj9vm29.so+0x2ff13])
 [ERR] internalCreateRAMClassFromROMClass+0x3bd (0x00007FF3812DEB9D [libj9vm29.so+0x34b9d])
 [ERR] internalDefineClass+0x332 (0x00007FF3814A7002 [libj9vm29.so+0x1fd002])
 [ERR] defineClassCommon+0x46a (0x00007FF36D18A2DA [libjclse29.so+0x1f2da])
 [ERR] Java_java_lang_ClassLoader_defineClassImpl1+0x101 (0x00007FF36D17D911 [libjclse29.so+0x12911])
 [ERR]  (0x00007FF2F2603E58 [<unknown>+0x0])

The assert is here:

https://github.com/eclipse-openj9/openj9/blob/193c5a4ffbde02471a09273d8a323cb4b327b721/runtime/compiler/control/JITServerHelpers.cpp#L332

and occurred when the JITServerAOTDeserializer::onClassLoad() method tried to compute the "deterministic hash" of a runtime-generated ROM class. Looking at the resulting core, the name of that ROM class was "java/lang/SecurityManager$$Lambda/0x0000000000000000".

This crash goes away in that test component when I specify -Xjit:aotCacheDisableGeneratedClassSupport. I'm also moderately sure that I ran this test suite with a debug build at least once when I was testing the ignore-local-SCC code and this assert did not fire, so it's possible that something about https://github.com/eclipse-openj9/openj9/pull/19549 has caused this assumption to be violated. It could be something related to the name truncation that happens when computing the deterministically-packed representation of a runtime-generated class. I haven't looked into it in detail yet.

cjjdespres commented 2 months ago

Attn @mpirvu.