search

eclipse-openj9 / openj9

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

JDK8 renaissance-db-shootout_0_FAILED - j9vmutil(j9vm).15 * ** ASSERTION FAILED ** at /home/jenkins/workspace/build-scripts/jobs/jdk8u/jdk8u-linux-x64-openj9/workspace/build/src/openj9/runtime/util/fieldutil.c:156: ((((UDATA)sectionStart % sizeof(U_32)) == 0)) #12887

Open JasonFengJ9 opened 3 years ago

JasonFengJ9 commented 3 years ago

Failure link

From an internal build Test_openjdk8_j9_extended.perf_x86-64_linux/11/ (ub20x64rt3-2):

openjdk version "1.8.0_302"
OpenJDK Runtime Environment (build 1.8.0_302-b05)
Eclipse OpenJ9 VM (build master-f6bdf7af9, JRE 1.8.0 Linux amd64-64-Bit Compressed References 20210605_150 (JIT enabled, AOT enabled)
OpenJ9   - f6bdf7af9
OMR      - bb369d1aa
JCL      - f7ae2714 based on jdk8u302-b05)

Rerun in Grinder

Optional info

Failure output (captured from console output)

[2021-06-05T03:23:56.326Z] Running test renaissance-db-shootout_0 ...
[2021-06-05T03:23:56.326Z] ===============================================
[2021-06-05T03:23:56.326Z] renaissance-db-shootout_0 Start Time: Fri Jun  4 20:23:56 2021 Epoch Time (ms): 1622863436182
[2021-06-05T03:23:56.326Z] "/home/jenkins/workspace/Test_openjdk8_j9_extended.perf_x86-64_linux/openjdkbinary/j2sdk-image/bin/java" -Xshareclasses:destroyAll; "/home/jenkins/workspace/Test_openjdk8_j9_extended.perf_x86-64_linux/openjdkbinary/j2sdk-image/bin/java" -Xshareclasses:groupAccess,destroyAll; echo "cache cleanup done";
[2021-06-05T03:23:56.326Z] JVMSHRC005I No shared class caches available
[2021-06-05T03:23:56.326Z] JVMSHRC005I No shared class caches available
[2021-06-05T03:23:56.326Z] cache cleanup done
[2021-06-05T03:23:56.326Z] variation: NoOptions
[2021-06-05T03:23:56.326Z] JVM_OPTIONS:  
[2021-06-05T03:23:56.326Z] { itercnt=1; \
[2021-06-05T03:23:56.326Z] mkdir -p "/home/jenkins/workspace/Test_openjdk8_j9_extended.perf_x86-64_linux/openjdk-tests/TKG/../TKG/output_16228620741551/renaissance-db-shootout_0"; \
[2021-06-05T03:23:56.326Z] cd "/home/jenkins/workspace/Test_openjdk8_j9_extended.perf_x86-64_linux/openjdk-tests/TKG/../TKG/output_16228620741551/renaissance-db-shootout_0"; \
[2021-06-05T03:23:56.326Z] "/home/jenkins/workspace/Test_openjdk8_j9_extended.perf_x86-64_linux/openjdkbinary/j2sdk-image/bin/java"  -jar "/home/jenkins/workspace/Test_openjdk8_j9_extended.perf_x86-64_linux/openjdk-tests/TKG/../../jvmtest/perf/renaissance/renaissance.jar" --json ""/home/jenkins/workspace/Test_openjdk8_j9_extended.perf_x86-64_linux/openjdk-tests/TKG/../TKG/output_16228620741551/renaissance-db-shootout_0"/db-shootout.json" db-shootout; \
[2021-06-05T03:23:56.326Z]  if [ $? -eq 0 ] ; then echo ""; echo "renaissance-db-shootout_0""_PASSED"; echo ""; cd /home/jenkins/workspace/Test_openjdk8_j9_extended.perf_x86-64_linux/openjdk-tests/TKG/..; rm -f -r "/home/jenkins/workspace/Test_openjdk8_j9_extended.perf_x86-64_linux/openjdk-tests/TKG/../TKG/output_16228620741551/renaissance-db-shootout_0"; else echo ""; echo "renaissance-db-shootout_0""_FAILED"; echo ""; fi; } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk8_j9_extended.perf_x86-64_linux/openjdk-tests/TKG/../TKG/output_16228620741551/TestTargetResult";
[2021-06-05T03:24:23.694Z] SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
[2021-06-05T03:24:23.694Z] SLF4J: Defaulting to no-operation (NOP) logger implementation
[2021-06-05T03:24:23.694Z] SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
[2021-06-05T03:24:31.862Z] ====== db-shootout (database), iteration 0 started ======
[2021-06-05T03:24:43.869Z] 03:24:43.455 0x765f00j9vmutil(j9vm).15     *   ** ASSERTION FAILED ** at /home/jenkins/workspace/build-scripts/jobs/jdk8u/jdk8u-linux-x64-openj9/workspace/build/src/openj9/runtime/util/fieldutil.c:156: ((((UDATA)sectionStart % sizeof(U_32)) == 0))
[2021-06-05T03:24:43.869Z] JVMDUMP039I Processing dump event "traceassert", detail "" at 2021/06/04 20:24:43 - please wait.
[2021-06-05T03:24:43.869Z] JVMDUMP032I JVM requested System dump using '/home/jenkins/workspace/Test_openjdk8_j9_extended.perf_x86-64_linux/openjdk-tests/TKG/output_16228620741551/renaissance-db-shootout_0/core.20210604.202443.3197378.0001.dmp' in response to an event
[2021-06-05T03:24:49.398Z] JVMPORT030W /proc/sys/kernel/core_pattern setting "|/usr/share/apport/apport %p %s %c %d %P %E" specifies that the core dump is to be piped to an external program.  Attempting to rename either core or core.3197447.
[2021-06-05T03:24:49.398Z] 
[2021-06-05T03:24:49.398Z] JVMDUMP010I System dump written to /home/jenkins/workspace/Test_openjdk8_j9_extended.perf_x86-64_linux/openjdk-tests/TKG/output_16228620741551/renaissance-db-shootout_0/core.20210604.202443.3197378.0001.dmp
[2021-06-05T03:24:49.398Z] JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk8_j9_extended.perf_x86-64_linux/openjdk-tests/TKG/output_16228620741551/renaissance-db-shootout_0/javacore.20210604.202443.3197378.0002.txt' in response to an event
[2021-06-05T03:24:49.398Z] JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk8_j9_extended.perf_x86-64_linux/openjdk-tests/TKG/output_16228620741551/renaissance-db-shootout_0/javacore.20210604.202443.3197378.0002.txt
[2021-06-05T03:24:49.398Z] JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk8_j9_extended.perf_x86-64_linux/openjdk-tests/TKG/output_16228620741551/renaissance-db-shootout_0/Snap.20210604.202443.3197378.0003.trc' in response to an event
[2021-06-05T03:24:49.398Z] JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk8_j9_extended.perf_x86-64_linux/openjdk-tests/TKG/output_16228620741551/renaissance-db-shootout_0/Snap.20210604.202443.3197378.0003.trc
[2021-06-05T03:24:49.398Z] JVMDUMP013I Processed dump event "traceassert", detail "".
[2021-06-05T03:24:49.398Z] 
[2021-06-05T03:24:49.398Z] renaissance-db-shootout_0_FAILED
pshipton commented 3 years ago

@llxia there are no diagnostic files captured.

@tajila @gacholio fyi the assert.

gacholio commented 3 years ago

Without the ROM class from the core, there's little to be done other than manually eyeball the code.

Would also be good to know if the assert is reproducible.

llxia commented 3 years ago

there are no diagnostic files captured.

diagnostic files are written to the correct folder /home/jenkins/workspace/Test_openjdk8_j9_extended.perf_x86-64_linux/openjdk-tests/TKG/output_16228620741551. It looks like the machine ub20x64rt3-2 was offline so we did not complete Deploying artifact step. 

01:24:11.295  Test output artifactory URL:'https://na.artifactory.swg-devops.com/artifactory/sys-rt-generic-local/hyc-runtimes-jenkins.swg-devops.com//Test_openjdk8_j9_extended.perf_x86-64_linux/11/'
[Pipeline] sh
01:24:14.983  + tar -cf benchmark_test_output.tar.gz ./openjdk-tests/TKG/output_16228620741551
[Pipeline] getArtifactoryServer
[Pipeline] newBuildInfo
[Pipeline] artifactoryUpload
[Pipeline] }
[Pipeline] // timestamps
[Pipeline] }
[Pipeline] // stage
[Pipeline] echo
terminateJavaProcesses iteration: 1
[Pipeline] echo
PROCESSCATCH: Checking for any leftover java processes on the machine
[Pipeline] sh
ub20x64rt3-2 was marked offline: Connection was broken: java.io.EOFException
    at java.io.ObjectInputStream$PeekInputStream.readFully(ObjectInputStream.java:2799)
    at java.io.ObjectInputStream$BlockDataInputStream.readShort(ObjectInputStream.java:3274)
llxia commented 3 years ago

Grinder 5x on ub20x64rt3-2: Grinder/16061/

Update: The above Grinder passed

llxia commented 3 years ago

Grinder 100x on ub20x64rt3-2 and got 1 failure: Grinder/16143/ Artifacts

====== db-shootout (database), iteration 0 started ======
Unhandled exception
Type=Segmentation error vmState=0x00040000
J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000080
Handler1=00007F8EE7A15BD0 Handler2=00007F8EE77739F0 InaccessibleAddress=0000000000000000
RDI=000000000076D100 RSI=C97F00000000005A RAX=00007F8E73291308 RBX=000000000000000A
RCX=000000000000000A RDX=00007F8E7220A59A R8=00007F8E7220A4B0 R9=0000000000000001
R10=00007F8E73291308 R11=0000000000000000 R12=0000000000000001 R13=00007F8E7220A59A
R14=000000000076D100 R15=000000000076D100
RIP=00007F8EE7A46940 GS=0000 FS=0000 RSP=00007F8E73291090
EFlags=0000000000010206 CS=0033 RBP=C97F00000000005A ERR=0000000000000000
TRAPNO=000000000000000D OLDMASK=0000000000000000 CR2=00007F83FC399000
xmm0 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm1 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm2 00007f8e7220a59a (f: 1914742144.000000, d: 6.929260e-310)
xmm3 6974614e2f6c616e (f: 795632000.000000, d: 9.749973e+199)
xmm4 000000003f857800 (f: 1065711616.000000, d: 5.265315e-315)
xmm5 00007f8e48000080 (f: 1207959680.000000, d: 6.929225e-310)
xmm6 3faaa5aa5df25984 (f: 1576163712.000000, d: 5.204518e-02)
xmm7 0000000000000021 (f: 33.000000, d: 1.630417e-322)
xmm8 0000000000000001 (f: 1.000000, d: 4.940656e-324)
xmm9 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm10 410168318d9e74f4 (f: 2375972096.000000, d: 1.425982e+05)
xmm11 ca62c1d6ca62c1d6 (f: 3395469824.000000, d: -2.193092e+50)
xmm12 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm13 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
Module=/home/jenkins/workspace/Grinder/openjdkbinary/j2sdk-image/jre/lib/amd64/default/libj9vm29.so
Module_base_address=00007F8EE79D7000
Target=2_90_20210605_150 (Linux 5.4.0-72-generic)
CPU=amd64 (4 logical CPUs) (0xf5faa000 RAM)
----------- Stack Backtrace -----------
(0x00007F8EE7A46940 [libj9vm29.so+0x6f940])
(0x00007F8EE7A47140 [libj9vm29.so+0x70140])
(0x00007F8EE7A47380 [libj9vm29.so+0x70380])
(0x00007F8EE7A474B7 [libj9vm29.so+0x704b7])
(0x00007F8EE7A1CB14 [libj9vm29.so+0x45b14])
_Z28cacheNativeReadOptionsFieldsP7JNIEnv_P8_jobject+0x63 (0x00007F8E721DB1D3 [libleveldbjni-64-1-1587602434864644752.8+0x1c1d3])
_Z26getNativeReadOptionsFieldsP7JNIEnv_P8_jobjectPN7leveldb11ReadOptionsE+0x38 (0x00007F8E721DB2E8 [libleveldbjni-64-1-1587602434864644752.8+0x1c2e8])
Java_org_fusesource_leveldbjni_internal_NativeDB_00024DBJNI_Get+0x64 (0x00007F8E721D9B44 [libleveldbjni-64-1-1587602434864644752.8+0x1ab44])
(0x00007F8EE7B82096 [libj9vm29.so+0x1ab096])
(0x00007F8EE7B81037 [libj9vm29.so+0x1aa037])
(0x00007F8EE7A75DAB [libj9vm29.so+0x9edab])
(0x00007F8EE7A662D5 [libj9vm29.so+0x8f2d5])
(0x00007F8EE7B11642 [libj9vm29.so+0x13a642])
---------------------------------------
JVMDUMP039I Processing dump event "gpf", detail "" at 2021/06/09 22:16:37 - please wait.
JVMDUMP032I JVM requested System dump using '/home/jenkins/workspace/Grinder/openjdk-tests/TKG/output_16233021538961/renaissance-db-shootout_0/core.20210609.221637.510957.0001.dmp' in response to an event
JVMPORT030W /proc/sys/kernel/core_pattern setting "|/usr/share/apport/apport %p %s %c %d %P %E" specifies that the core dump is to be piped to an external program.  Attempting to rename either core or core.511027.

JVMDUMP010I System dump written to /home/jenkins/workspace/Grinder/openjdk-tests/TKG/output_16233021538961/renaissance-db-shootout_0/core.20210609.221637.510957.0001.dmp
JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Grinder/openjdk-tests/TKG/output_16233021538961/renaissance-db-shootout_0/javacore.20210609.221637.510957.0002.txt' in response to an event
JVMDUMP010I Java dump written to /home/jenkins/workspace/Grinder/openjdk-tests/TKG/output_16233021538961/renaissance-db-shootout_0/javacore.20210609.221637.510957.0002.txt
JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Grinder/openjdk-tests/TKG/output_16233021538961/renaissance-db-shootout_0/Snap.20210609.221637.510957.0003.trc' in response to an event
JVMDUMP010I Snap dump written to /home/jenkins/workspace/Grinder/openjdk-tests/TKG/output_16233021538961/renaissance-db-shootout_0/Snap.20210609.221637.510957.0003.trc
JVMDUMP032I JVM requested JIT dump using '/home/jenkins/workspace/Grinder/openjdk-tests/TKG/output_16233021538961/renaissance-db-shootout_0/jitdump.20210609.221637.510957.0004.dmp' in response to an event
JVMDUMP051I JIT dump occurred in 'Thread-13' thread 0x000000000076D100
JVMDUMP010I JIT dump written to /home/jenkins/workspace/Grinder/openjdk-tests/TKG/output_16233021538961/renaissance-db-shootout_0/jitdump.20210609.221637.510957.0004.dmp
JVMDUMP013I Processed dump event "gpf", detail "".
pshipton commented 3 years ago

@llxia I get a 404 error trying to open the artifacts link.

gacholio commented 3 years ago

I managed to download it. If you can, please provide the download link for the SDK under test and I'll grab that too.

llxia commented 3 years ago

@gacholio SDK link. You can also find it in CUSTOMIZED_SDK_URL in Grinder/16143/. CUSTOMIZED_SDK_URL also contains test-image, debug-image links

gacholio commented 3 years ago

Got them, thanks.

gacholio commented 3 years ago 
> !stackslots 0x76d100
<76d100> *** BEGIN STACK WALK, flags = 00400001 walkThread = 0x000000000076D100 ***
<76d100>    ITERATE_O_SLOTS
<76d100>    RECORD_BYTECODE_PC_OFFSET
<76d100> Initial values: walkSP = 0x0000000000761880, PC = 0x0000000000000007, literals = 0x0000000000000008, A0 = 0x00000000007618D8, j2iFrame = 0x0000000000000000, ELS = 0x00007F8E73291B70, decomp = 0x0000000000000000
<76d100> JNI native method frame: bp = 0x00000000007618A8, sp = 0x0000000000761880, pc = 0x0000000000000007, cp = 0x0000000000000000, arg0EA = 0x00000000007618D8, flags = 0x0000000000000001
<76d100>    Method: org/fusesource/leveldbjni/internal/NativeDB$DBJNI.Get(JLorg/fusesource/leveldbjni/internal/NativeReadOptions;Lorg/fusesource/leveldbjni/internal/NativeSlice;J)J !j9method 0x00000000005B1BE8
<76d100>    Object pushes starting at 0x0000000000761880 for 1 slots
<76d100>        Push[0x0000000000761880] = 0x00000000C8815578
<76d100>    Using signature mapper
<76d100>    Arguments starting at 0x00000000007618D8 for UDATA(0x0000000000000006) slots
<76d100>        I-Slot: a0[0x00000000007618D8] = 0x00000000FFDE9550
<76d100>        I-Slot: a1[0x00000000007618D0] = 0x00007F8EE827E650
<76d100>        O-Slot: a2[0x00000000007618C8] = 0x00000000FFDE93C8
<76d100>        O-Slot: a3[0x00000000007618C0] = 0x00000000FFDE94B0
<76d100>        I-Slot: a4[0x00000000007618B8] = 0x000000000075AF48
<76d100>        I-Slot: a5[0x00000000007618B0] = 0x00007F8E48010460
<76d100> Bytecode frame: bp = 0x00000000007618F0, sp = 0x00000000007618E0, pc = 0x00007F8EE8BDC966, cp = 0x00000000005A27F0, arg0EA = 0x0000000000761940, flags = 0x0000000000000000
<76d100>    Method: org/fusesource/leveldbjni/internal/NativeDB.get(Lorg/fusesource/leveldbjni/internal/NativeReadOptions;Lorg/fusesource/leveldbjni/internal/NativeSlice;)[B !j9method 0x00000000005A2FF0
<76d100>    Bytecode index = 22
<76d100>    Using local mapper
<76d100>    Locals starting at 0x0000000000761940 for 0x000000000000000A slots
<76d100>        I-Slot: a0[0x0000000000761940] = 0x00000000C2D58C38
<76d100>        I-Slot: a1[0x0000000000761938] = 0x00000000FFDE93C8
<76d100>        I-Slot: a2[0x0000000000761930] = 0x00000000FFDE94B0
<76d100>        O-Slot: t3[0x0000000000761928] = 0x00000000FFDE9550
<76d100>        I-Slot: t4[0x0000000000761920] = 0x00000000FFDE9490
<76d100>        I-Slot: t5[0x0000000000761918] = 0x00007F8EE5BE64E0
<76d100>        I-Slot: t6[0x0000000000761910] = 0x00000000FFDE9468
<76d100>        I-Slot: t7[0x0000000000761908] = 0x0000000000000004
<76d100>        I-Slot: t8[0x0000000000761900] = 0x0000000000000000
<76d100>        I-Slot: t9[0x00000000007618F8] = 0x0000000000000000
<76d100> Bytecode frame: bp = 0x0000000000761958, sp = 0x0000000000761948, pc = 0x00007F8EE8BDC91E, cp = 0x00000000005A27F0, arg0EA = 0x0000000000761970, flags = 0x0000000000000000
<76d100>    Method: org/fusesource/leveldbjni/internal/NativeDB.get(Lorg/fusesource/leveldbjni/internal/NativeReadOptions;Lorg/fusesource/leveldbjni/internal/NativeBuffer;)[B !j9method 0x00000000005A2FD0
<76d100>    Bytecode index = 10
<76d100>    Using local mapper
<76d100>    Locals starting at 0x0000000000761970 for 0x0000000000000003 slots
<76d100>        I-Slot: a0[0x0000000000761970] = 0x00000000C2D58C38
<76d100>        I-Slot: a1[0x0000000000761968] = 0x00000000FFDE93C8
<76d100>        I-Slot: a2[0x0000000000761960] = 0x00000000FFDE9490
<76d100> Bytecode frame: bp = 0x0000000000761988, sp = 0x0000000000761978, pc = 0x00007F8EE8BDC8AC, cp = 0x00000000005A27F0, arg0EA = 0x00000000007619B8, flags = 0x0000000000000000
<76d100>    Method: org/fusesource/leveldbjni/internal/NativeDB.get(Lorg/fusesource/leveldbjni/internal/NativeReadOptions;[B)[B !j9method 0x00000000005A2FB0
<76d100>    Bytecode index = 20
<76d100>    Using local mapper
<76d100>    Locals starting at 0x00000000007619B8 for 0x0000000000000006 slots
<76d100>        I-Slot: a0[0x00000000007619B8] = 0x00000000C2D58C38
<76d100>        I-Slot: a1[0x00000000007619B0] = 0x00000000FFDE93C8
<76d100>        I-Slot: a2[0x00000000007619A8] = 0x00000000FFDE9220
<76d100>        O-Slot: t3[0x00000000007619A0] = 0x00000000FFDE9490
<76d100>        I-Slot: t4[0x0000000000761998] = 0x00000000007619F0
<76d100>        I-Slot: t5[0x0000000000761990] = 0x00007F8EE8BE67A7
<76d100> Bytecode frame: bp = 0x00000000007619D0, sp = 0x00000000007619C0, pc = 0x00007F8EE8BE67AB, cp = 0x00000000005B2AE0, arg0EA = 0x00000000007619F0, flags = 0x0000000000000000
<76d100>    Method: org/fusesource/leveldbjni/internal/JniDB.get([BLorg/iq80/leveldb/ReadOptions;)[B !j9method 0x00000000005B33D0
<76d100>    Bytecode index = 27
<76d100>    Using local mapper
<76d100>    Locals starting at 0x00000000007619F0 for 0x0000000000000004 slots
<76d100>        I-Slot: a0[0x00000000007619F0] = 0x00000000C2D55B70
<76d100>        I-Slot: a1[0x00000000007619E8] = 0x00000000FFDE9220
<76d100>        I-Slot: a2[0x00000000007619E0] = 0x00000000FFDE9328
<76d100>        I-Slot: t3[0x00000000007619D8] = 0x00000000FFDE9328
<76d100> Bytecode frame: bp = 0x0000000000761A08, sp = 0x00000000007619F8, pc = 0x00007F8EE8BE675E, cp = 0x00000000005B2AE0, arg0EA = 0x0000000000761A18, flags = 0x0000000000000000
<76d100>    Method: org/fusesource/leveldbjni/internal/JniDB.get([B)[B !j9method 0x00000000005B33B0
<76d100>    Bytecode index = 26
<76d100>    Using local mapper
<76d100>    Locals starting at 0x0000000000761A18 for 0x0000000000000002 slots
<76d100>        I-Slot: a0[0x0000000000761A18] = 0x00000000C2D55B70
<76d100>        I-Slot: a1[0x0000000000761A10] = 0x00000000FFDE9220
<76d100> Bytecode frame: bp = 0x0000000000761A30, sp = 0x0000000000761A20, pc = 0x00007F8E4D3B8430, cp = 0x0000000000759BC0, arg0EA = 0x0000000000761A68, flags = 0x0000000000000000
<76d100>    Method: org/lmdbjava/bench/LevelDb$1.run()V !j9method 0x00000000007576D0
<76d100>    Bytecode index = 148
<76d100>    Using local mapper
<76d100>    Locals starting at 0x0000000000761A68 for 0x0000000000000007 slots
<76d100>        O-Slot: a0[0x0000000000761A68] = 0x00000000FFDE5B78
<76d100>        O-Slot: t1[0x0000000000761A60] = 0x00000000FFDE9200
<76d100>        I-Slot: t2[0x0000000000761A58] = 0x00000000FFDE9238
<76d100>        I-Slot: t3[0x0000000000761A50] = 0x00000000000FFF9C
<76d100>        I-Slot: t4[0x0000000000761A48] = 0x0000000000000000
<76d100>        I-Slot: t5[0x0000000000761A40] = 0x0000000000000000
<76d100>        I-Slot: t6[0x0000000000761A38] = 0x0000000000000000
<76d100> JNI call-in frame: bp = 0x0000000000761A90, sp = 0x0000000000761A70, pc = 0x00007F8EE7B94BA4, cp = 0x0000000000000000, arg0EA = 0x0000000000761A90, flags = 0x0000000000000000
<76d100>    New ELS = 0x0000000000000000
<76d100> JNI native method frame: bp = 0x0000000000761AB8, sp = 0x0000000000761A98, pc = 0x0000000000000007, cp = 0x0000000000000000, arg0EA = 0x0000000000761AB8, flags = 0x0000000000000000
<76d100> <end of stack>
<76d100> *** END STACK WALK (rc = NONE) ***
gacholio commented 3 years ago 
> !j9object 0x00000000C8815578
!J9Object 0x00000000C8815578 {
    struct J9Class* clazz = !j9class 0x44500 // java/lang/Class
    Object flags = 0x0000003A;
    I lockword = 0x00000000 (offset = 0) (java/lang/Object) <hidden>
    J vmRef = 0x000000000075A200 (offset = 4) (java/lang/Class)
    Ljava/lang/ClassLoader; classLoader = !fj9object 0xc2abebd8 (offset = 12) (java/lang/Class)
    Ljava/security/ProtectionDomain; protectionDomain = !fj9object 0xc30b7028 (offset = 16) (java/lang/Class)
    Ljava/lang/String; classNameString = !fj9object 0x0 (offset = 20) (java/lang/Class)
    Ljava/lang/String; fileNameString = !fj9object 0x0 (offset = 24) (java/lang/Class)
    Ljava/lang/Class$AnnotationVars; annotationVars = !fj9object 0x0 (offset = 28) (java/lang/Class)
    Ljava/lang/ClassValue$ClassValueMap; classValueMap = !fj9object 0x0 (offset = 32) (java/lang/Class)
    Ljava/lang/Class$EnumVars; enumVars = !fj9object 0x0 (offset = 36) (java/lang/Class)
    Ljava/lang/J9VMInternals$ClassInitializationLock; initializationLock = !fj9object 0x0 (offset = 40) (java/lang/Class)
    Ljava/lang/Object; methodHandleCache = !fj9object 0x0 (offset = 44) (java/lang/Class)
    Ljava/lang/Class$ClassRepositoryHolder; classRepoHolder = !fj9object 0x0 (offset = 48) (java/lang/Class)
    Ljava/lang/Class$AnnotationCache; annotationCache = !fj9object 0x0 (offset = 52) (java/lang/Class)
    Ljava/lang/Class$MetadataCache; metadataCache = !fj9object 0x0 (offset = 56) (java/lang/Class)
    [Ljava/lang/Class; cachedInterfaces = !fj9object 0x0 (offset = 60) (java/lang/Class)
    Ljava/lang/Class; cachedDeclaringClass = !fj9object 0x0 (offset = 64) (java/lang/Class)
    Ljava/lang/Class; cachedEnclosingClass = !fj9object 0x0 (offset = 68) (java/lang/Class)
    Ljava/lang/Class$ReflectCache; reflectCache = !fj9object 0x0 (offset = 72) (java/lang/Class)
}
> !j9class 0x000000000075A200
J9Class at 0x75a200 {
  Fields for J9Class:
    0x0: UDATA eyecatcher = 0x0000000099669966 (2573637990)
    0x8: struct J9ROMClass* romClass = !j9romclass 0x00007F8E4D3B8960
    0x10: void** superclasses = !j9x 0x000000000075A0C8
    0x18: UDATA classDepthAndFlags = 0x00000000000E0001 (917505)
    0x20: U32 classDepthWithFlags = 0x00000000 (0)
    0x24: U32 classFlags = 0x00000000 (0)
    0x28: struct J9ClassLoader* classLoader = !j9classloader 0x00007F8EE80D0108
    0x30: struct J9Object* classObject = !j9object 0x00000000C8815578 // java/lang/Class
    0x38: volatile UDATA initializeStatus = 0x0000000000000001 (1)
    0x40: struct J9Method* ramMethods = !j9method 0x000000000075A528 // org/fusesource/leveldbjni/internal/NativeReadOptions.<init>()V
    0x48: UDATA* ramStatics = !j9x 0x0000000000000000
    0x50: struct J9Class* arrayClass = !j9class 0x0000000000000000
    0x58: UDATA totalInstanceSize = 0x0000000000000014 (20)
    0x60: struct J9ITable* lastITable = !j9itable 0x00007F8EE7B9D900
    0x68: UDATA* instanceDescription = !j9x 0x0000000000000001
    0x70: UDATA* instanceLeafDescription = !j9x 0x0000000000000001
    0x78: UDATA instanceHotFieldDescription = 0x0000000000000000 (0)
    0x80: UDATA selfReferencingField1 = 0x0000000000000000 (0)
    0x88: UDATA selfReferencingField2 = 0x0000000000000000 (0)
    0x90: struct J9Method* initializerCache = !j9method 0x0000000000000000
    0x98: UDATA romableAotITable = 0x00007F8EE5BE6270 (140251716543088)
    0xa0: UDATA packageID = 0x00007F8EE8BDBE89 (140251766832777)
    0xa8: struct J9Module* module = !j9module 0x0000000000000000
    0xb0: struct J9Class* subclassTraversalLink = !j9class 0x0000000000759E00 // org/iq80/leveldb/ReadOptions
    0xb8: struct J9Class* subclassTraversalReverseLink = !j9class 0x000000000075AC00 // org/fusesource/leveldbjni/internal/NativeStdString$StdStringJNI
    0xc0: void** iTable = !j9x 0x0000000000000000
    0xc8: UDATA castClassCache = 0x0000000000000000 (0)
    0xd0: void** jniIDs = !j9x 0x00007F8E38012640
    0xd8: UDATA lockOffset = 0x0000000000000004 (4)
    0xe0: U32 paddingForGLRCounters = 0x00000000 (0)
    0xe4: U16 reservedCounter = 0x0000 (0)
    0xe6: U16 cancelCounter = 0x0000 (0)
    0xe8: UDATA newInstanceCount = 0x0000000000000BB8 (3000)
    0xf0: IDATA backfillOffset = 0x0000000000000018 (24)
    0xf8: struct J9Class* replacedClass = !j9class 0x0000000000000000
    0x100: UDATA finalizeLinkOffset = 0x0000000000000000 (0)
    0x108: struct J9Class* nextClassInSegment = !j9class 0x0000000000759E00 // org/iq80/leveldb/ReadOptions
    0x110: UDATA* ramConstantPool = !j9x 0x000000000075A3E0
    0x118: struct J9Object** callSites = !j9x 0x0000000000000000
    0x120: struct J9Object** methodTypes = !j9x 0x0000000000000000
    0x128: struct J9Object** varHandleMethodTypes = !j9x 0x0000000000000000
    0x130: struct J9VMCustomSpinOptions* customSpinOption = !j9vmcustomspinoptions 0x0000000000000000
    0x138: void** staticSplitMethodTable = !j9x 0x0000000000000000
    0x140: void** specialSplitMethodTable = !j9x 0x0000000000000000
    0x148: struct J9JITExceptionTable* jitMetaDataList = !j9jitexceptiontable 0x0000000000000000
    0x150: struct J9Class* gcLink = !j9class 0x0000000000000000
    0x158: struct J9Class* hostClass = !j9class 0x000000000075A200 // org/fusesource/leveldbjni/internal/NativeReadOptions
    0x160: struct J9FlattenedClassCache* flattenedClassCache = !j9flattenedclasscache 0x0000000000000000
    0x168: struct J9ClassHotFieldsInfo* hotFieldsInfo = !j9classhotfieldsinfo 0x0000000000000000
}
Class name: org/fusesource/leveldbjni/internal/NativeReadOptions
To view static fields, use !j9statics 0x000000000075A200
To view instance shape, use !j9classshape 0x000000000075A200
gacholio commented 3 years ago

Crash here:

  0x7f8ee7a46940 <findFieldInClass+32>: mov    0x8(%rsi),%rcx <- RSI=C97F00000000005A
gacholio commented 3 years ago

Arg registers are: RDI RSI RDX RCX R8 R9

RDI=000000000076D100 RSI=C97F00000000005A RAX=00007F8E73291308 RBX=000000000000000A
RCX=000000000000000A RDX=00007F8E7220A59A R8=00007F8E7220A4B0 R9=0000000000000001
R10=00007F8E73291308 R11=0000000000000000 R12=0000000000000001 R13=00007F8E7220A59A
R14=000000000076D100 R15=000000000076D100
RIP=00007F8EE7A46940 GS=0000 FS=0000 RSP=00007F8E73291090
EFlags=0000000000010206 CS=0033 RBP=C97F00000000005A ERR=0000000000000000

findFieldInClass(J9VMThread *vmStruct, J9Class *clazz, U_8 *fieldName, UDATA fieldNameLength, U_8 *signature, UDATA signatureLength, UDATA *offsetOrAddress, J9Class **definingClass)

RDI vmStruct (current thread) RSI clazz RDX fieldName RCX fieldNameLength 0x7F8E7220A59A : 66 69 6c 6c 5f 63 61 63 68 65 [ fill_cache ] R8 fieldSignature R9 fieldSignatureLength 0x7F8E7220A4B0 : 5a [ Z ]

gacholio commented 3 years ago

The native stack:

0x7f8e73291090: 0x0000000000000005  0x00007f8e7220a4b0
0x7f8e732910a0: 0x00007f8e9945a680  0x000000000076d100
0x7f8e732910b0: 0x000000000075a200  0x00007f8eed410b6e
0x7f8e732910c0: 0x00007f8e7220c913  0x00000000007618c8
0x7f8e732910d0: 0x00007f8ee8054240  0x00007f8e4d3b8aa0
0x7f8e732910e0: 0x0000000000000002  0x00007f8e4d3b8aa0
0x7f8e732910f0: 0x000000000000000c  0x0000000000000014
0x7f8e73291100: 0x0000000000000004  0x0000000000000001
0x7f8e73291110: 0xffffffffffffffff  0x00007f8e4d3b8960
0x7f8e73291120: 0x000000000000000c  0x000000000000000c
0x7f8e73291130: 0x0000000000000004  0xffffffffffffffff
0x7f8e73291140: 0x0000000000000001  0x0000000000000000
0x7f8e73291150: 0x0000000000000000  0x0000000000000003
0x7f8e73291160: 0x0000000000000004  0x0000000000000000
0x7f8e73291170: 0x0000000000000000  0x0000000000000000
0x7f8e73291180: 0x0000000000000000  0x0000000000000000
0x7f8e73291190: 0x0000000000000000  0x0000000000000000
0x7f8e732911a0: 0x0000000000000000  0x0000000000000000
0x7f8e732911b0: 0x0000000000000000  0x0000000000000000
0x7f8e732911c0: 0x0000000000000000  0x0000000000000000
0x7f8e732911d0: 0x0000000000000000  0x0000000000000000
0x7f8e732911e0: 0x0000000000000000  0x0000000000000000
0x7f8e732911f0: 0x0000000000000000  0x0000000000000000
0x7f8e73291200: 0x0000000000000000  0xffffffffffffffff
0x7f8e73291210: 0x0000000000000021  0x00007f8e73291300
0x7f8e73291220: 0x00007f8e73291308  0x000000000076d100
0x7f8e73291230: 0x000000000000000a  0xc97f00000000005a
0x7f8e73291240: 0x000000000076d100
                                    0x00007f8ee7a47140 <- findField RA
0x7f8e73291250: 0x00007f8e73291300  0x00007f8e73291308
0x7f8e73291260: 0x00007f8e7220a59a  0x00007f8e7220a4b0
0x7f8e73291270: 0x0000000000000001  0xc97f00000000005a
0x7f8e73291280: 0x0000000000000000  0x0000000000000000
0x7f8e73291290: 0x0000000000000000  0xc97f00000000005a
0x7f8e732912a0: 0x0000000000000000  0x000000000076d100
0x7f8e732912b0: 0x0000000000000000  0x000000000076d100
0x7f8e732912c0: 0x00007f8e732913e8  0x0000000000000000
0x7f8e732912d0: 0xc97f00000000005A   <- bogus class in r15 in instanceFieldOffsetWithSourceClass
                                    0x00007f8ee7a47380 <- instanceFieldOffsetWithSourceClass RA
0x7f8e732912e0: 0x00007f8e73291308  0x00007f8e73291300
0x7f8e732912f0: 0x0000000000000000  0x0000000000000007
0x7f8e73291300: 0x00007f8e4d1eae78  0x00007f8e4d3b8aa0
0x7f8e73291310: 0x000000000076d100  0x00007f8e7220a4b0
0x7f8e73291320: 0x0000000000000001  0x00007f8ee7dd8280
0x7f8e73291330: 0x000000000076cd90  
                                        0x00007f8ee7a474b7 <- instanceFieldOffset RA
0x7f8e73291340: 0x00007f8e732913e8  0x00007f8e732913e0
0x7f8e73291350: 0x0000000000000000  0x0000000000000000
0x7f8e73291360: 0x00007f8e7220a4b0  
                                        0x00007f8ee7a1cb14 <- getMethodOrFieldID RA
0x7f8e73291370: 0x00007f8e732913e8  0x00007f8e732913e0
0x7f8e73291380: 0x0000000000000000  0x00007f8ee7a1c9ee
0x7f8e73291390: 0x00007f8e7220a59a  0x0000000000000001
0x7f8e732913a0: 0x0000000000000000  0x00007f8e732913f0
0x7f8e732913b0: 0x0000000000000410  0x00007f8e732913e0
0x7f8e732913c0: 0x00007f8e7220a59a  0x00007f8e7220a4b0
0x7f8e732913d0: 0x00007f8e732913e8  0x0000000000000000
0x7f8e732913e0: 0x0000000000000000  0x0000000000000000
0x7f8e732913f0: 0x0000000000000000  0x0000000000000000
0x7f8e73291400: 0x0000000000000000  0x0000000000000000
0x7f8e73291410: 0x0000000000000000  0x0000000000000000
0x7f8e73291420: 0x0000000000000000  0x000000000076d100
0x7f8e73291430: 0x00007f8e7241b6e0  0x00007f8e732914c0
0x7f8e73291440: 0x00007f8e7241b6e0  0x00007f8e48010460
0x7f8e73291450: 0x0000000000000000
                                        0x00007f8e721db1d3 <- RA in JNI code calling GetFieldID
gacholio commented 3 years ago 
   0x7f8ee7a1c740 <getMethodOrFieldID>: push   %r15
   0x7f8ee7a1c742 <getMethodOrFieldID+2>:   push   %r14
   0x7f8ee7a1c744 <getMethodOrFieldID+4>:   mov    %rsi,%r14 <- r14 now classReference
   0x7f8ee7a1c747 <getMethodOrFieldID+7>:   push   %r13
   0x7f8ee7a1c749 <getMethodOrFieldID+9>:   push   %r12
   0x7f8ee7a1c74b <getMethodOrFieldID+11>:  mov    %r8,%r12
   0x7f8ee7a1c74e <getMethodOrFieldID+14>:  push   %rbp
   0x7f8ee7a1c74f <getMethodOrFieldID+15>:  push   %rbx
   0x7f8ee7a1c750 <getMethodOrFieldID+16>:  mov    %rdi,%rbx
   0x7f8ee7a1c753 <getMethodOrFieldID+19>:  mov    %rdx,%rdi
   0x7f8ee7a1c756 <getMethodOrFieldID+22>:  and    $0x1,%r12d
   0x7f8ee7a1c75a <getMethodOrFieldID+26>:  mov    %rcx,%rbp
   0x7f8ee7a1c75d <getMethodOrFieldID+29>:  sub    $0x98,%rsp
   0x7f8ee7a1c764 <getMethodOrFieldID+36>:  lea    0x3bbb15(%rip),%r13        # 0x7f8ee7dd8280 <j9vm_UtActive>
   0x7f8ee7a1c76b <getMethodOrFieldID+43>:  and    $0x2,%r8d
   0x7f8ee7a1c76f <getMethodOrFieldID+47>:  mov    %rdx,(%rsp)
   0x7f8ee7a1c773 <getMethodOrFieldID+51>:  setne  0x4f(%rsp)
   0x7f8ee7a1c778 <getMethodOrFieldID+56>:  mov    %r8,0x10(%rsp)
   0x7f8ee7a1c77d <getMethodOrFieldID+61>:  movzbl 0x4f(%rsp),%eax
   0x7f8ee7a1c782 <getMethodOrFieldID+66>:  movzbl 0x7a(%r13),%edx
   0x7f8ee7a1c787 <getMethodOrFieldID+71>:  test   %dl,%dl
   0x7f8ee7a1c789 <getMethodOrFieldID+73>:  je     0x7f8ee7a1c7bb <getMethodOrFieldID+123>
   0x7f8ee7a1c78b <getMethodOrFieldID+75>:  lea    0x3bbdae(%rip),%rsi        # 0x7f8ee7dd8540 <j9vm_UtModuleInfo>
   0x7f8ee7a1c792 <getMethodOrFieldID+82>:  sub    $0x8,%rsp
   0x7f8ee7a1c796 <getMethodOrFieldID+86>:  mov    %rcx,%r9
   0x7f8ee7a1c799 <getMethodOrFieldID+89>:  mov    %rdi,%r8
   0x7f8ee7a1c79c <getMethodOrFieldID+92>:  or     $0x7a,%dh
   0x7f8ee7a1c79f <getMethodOrFieldID+95>:  lea    0x1744aa(%rip),%rcx        # 0x7f8ee7b90c50
   0x7f8ee7a1c7a6 <getMethodOrFieldID+102>: mov    %rbx,%rdi
   0x7f8ee7a1c7a9 <getMethodOrFieldID+105>: mov    0x20(%rsi),%r10
   0x7f8ee7a1c7ad <getMethodOrFieldID+109>: push   %rax
   0x7f8ee7a1c7ae <getMethodOrFieldID+110>: xor    %eax,%eax
   0x7f8ee7a1c7b0 <getMethodOrFieldID+112>: push   %r12
   0x7f8ee7a1c7b2 <getMethodOrFieldID+114>: push   %r14
   0x7f8ee7a1c7b4 <getMethodOrFieldID+116>: callq  *(%r10)
   0x7f8ee7a1c7b7 <getMethodOrFieldID+119>: add    $0x20,%rsp
   0x7f8ee7a1c7bb <getMethodOrFieldID+123>: movq   $0x0,0x9b8(%rbx)
   0x7f8ee7a1c7c6 <getMethodOrFieldID+134>: cmpq   $0x20,0x98(%rbx)
   0x7f8ee7a1c7ce <getMethodOrFieldID+142>: jne    0x7f8ee7a1cbe8 <getMethodOrFieldID+1192>
   0x7f8ee7a1c7d4 <getMethodOrFieldID+148>: cmpq   $0x1,0x10(%rsp)
   0x7f8ee7a1c7da <getMethodOrFieldID+154>: movq   (%rsp),%xmm2
   0x7f8ee7a1c7df <getMethodOrFieldID+159>: mov    %rbp,0x8(%rsp)
   0x7f8ee7a1c7e4 <getMethodOrFieldID+164>: movhps 0x8(%rsp),%xmm2
   0x7f8ee7a1c7e9 <getMethodOrFieldID+169>: sbb    %rax,%rax
   0x7f8ee7a1c7ec <getMethodOrFieldID+172>: and    $0xc,%eax
   0x7f8ee7a1c7ef <getMethodOrFieldID+175>: add    $0x4,%rax
   0x7f8ee7a1c7f3 <getMethodOrFieldID+179>: or     $0x4,%ah
   0x7f8ee7a1c7f6 <getMethodOrFieldID+182>: mov    %rax,0x20(%rsp)
   0x7f8ee7a1c7fb <getMethodOrFieldID+187>: lea    0x50(%rsp),%rax
   0x7f8ee7a1c800 <getMethodOrFieldID+192>: movaps %xmm2,0x30(%rsp)
   0x7f8ee7a1c805 <getMethodOrFieldID+197>: mov    %rax,0x28(%rsp)
   0x7f8ee7a1c80a <getMethodOrFieldID+202>: lea    0x58(%rsp),%rax
   0x7f8ee7a1c80f <getMethodOrFieldID+207>: mov    %rax,0x40(%rsp)
   0x7f8ee7a1c814 <getMethodOrFieldID+212>: lea    0x60(%rsp),%rax
   0x7f8ee7a1c819 <getMethodOrFieldID+217>: mov    %rax,0x18(%rsp)
   0x7f8ee7a1c81e <getMethodOrFieldID+222>: xchg   %ax,%ax
   0x7f8ee7a1c820 <getMethodOrFieldID+224>: mov    (%r14),%rax <- rax is jlClass
   0x7f8ee7a1c823 <getMethodOrFieldID+227>: xor    %r15d,%r15d
   0x7f8ee7a1c826 <getMethodOrFieldID+230>: movq   $0x0,0x50(%rsp)
   0x7f8ee7a1c82f <getMethodOrFieldID+239>: movq   $0x0,0x58(%rsp)
   0x7f8ee7a1c838 <getMethodOrFieldID+248>: test   %rax,%rax
   0x7f8ee7a1c83b <getMethodOrFieldID+251>: je     0x7f8ee7a1c862 <getMethodOrFieldID+290>

   0x7f8ee7a1c83d <getMethodOrFieldID+253>: mov    0x8(%rbx),%rcx <- rcx is VM
   0x7f8ee7a1c841 <getMethodOrFieldID+257>: mov    0xd0(%rcx),%edx <- edx is extendedRuntimeFlags2
   0x7f8ee7a1c847 <getMethodOrFieldID+263>: mov    0xa10(%rcx),%rcx <- rcx is offset for vmRef (4)
   0x7f8ee7a1c84e <getMethodOrFieldID+270>: and    $0x2,%edx <- CR flag
   0x7f8ee7a1c851 <getMethodOrFieldID+273>: cmp    $0x1,%edx
   0x7f8ee7a1c854 <getMethodOrFieldID+276>: sbb    %rdx,%rdx
   0x7f8ee7a1c857 <getMethodOrFieldID+279>: add    %rcx,%rax <- rax has field offset added
   0x7f8ee7a1c85a <getMethodOrFieldID+282>: and    $0x4,%edx <- edx is 4 or 0
   0x7f8ee7a1c85d <getMethodOrFieldID+285>: mov    0x4(%rdx,%rax,1),%r15 <- r15 is J9Class of jlClass

   0x7f8ee7a1c862 <getMethodOrFieldID+290>: movzbl 0x7b(%r13),%edx
gacholio commented 3 years ago

The class ref on stack is valid (org/fusesource/leveldbjni/internal/NativeReadOptions) and the field it's looking for seems to exist:

> !j9classshape 0x000000000075A200
Instance fields in org/fusesource/leveldbjni/internal/NativeReadOptions:

offset     name signature   (declaring class)
0   lockword    I   (java/lang/Object) <hidden>
12  verify_checksums    Z   (org/fusesource/leveldbjni/internal/NativeReadOptions)
16  fill_cache  Z   (org/fusesource/leveldbjni/internal/NativeReadOptions)
4   snapshot    J   (org/fusesource/leveldbjni/internal/NativeReadOptions)

Total instance size: 20
gacholio commented 3 years ago

The code for fetching the class has been optimized by the compiler to avoid branching, but it should always result in a header size of 4 or 8 being skipped (the fixed 4 in the address expression plus the 0 or 4 in the register), so I don't see where we could have found that bad J9Class pointer.

gacholio commented 3 years ago

@llxia Do we have the source for the leveldbjni native library?

llxia commented 3 years ago

I did not find it in https://github.com/renaissance-benchmarks/renaissance

gacholio commented 3 years ago

Based on the native stack and code, it appears that a bad JNI ref has been passed as the class to GetFieldID:

0x7f8e73291330: 0x000000000076cd90

This does not appear to contain the bad J9Class value, but the memory may have been overwritten.

gacholio commented 3 years ago

There will be no progress on this until I can see the source for the JNI native.