OpenJDK jdk/internal/jimage/JImageReadTest.java segfault

[pshipton]

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/9 jdk_lang_1 -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage -XX:-UseCompressedOops jdk/internal/jimage/JImageReadTest.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/9/openjdk_test_output.tar.gz Not sure why but:

• the core and javacore are found in aqa-tests\TKG\output_16396548231476\jdk_lang_1\work\java\lang\WeakPairMap\Driver
• the Snap and jitdump are found in aqa-tests\TKG\output_16396548231476\jdk_lang_1\work\jdk\internal\jimage\JImageReadTest

06:52:47  rerun:
06:52:47  cd /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/aqa-tests/TKG/output_16396548231476/jdk_lang_1/work/scratch/0 && \
06:52:47  DISPLAY=:0 \
06:52:47  HOME=/home/jenkins \
06:52:47  LANG=en_US.UTF-8 \
06:52:47  PATH=/bin:/usr/bin:/usr/sbin \
06:52:47      /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/openjdkbinary/j2sdk-image/bin/java \
06:52:47          -Dtest.vm.opts='-ea -esa -Xmx512m -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage -XX:-UseCompressedOops' \
06:52:47          -Dtest.tool.vm.opts='-J-ea -J-esa -J-Xmx512m -J-Xdump:system:none -J-Xdump:heap:none -J-Xdump:system:events=gpf+abort+traceassert+corruptcache -J-XX:-JITServerTechPreviewMessage -J-XX:-UseCompressedOops' \
06:52:47          -Dtest.compiler.opts= \
06:52:47          -Dtest.java.opts= \
06:52:47          -Dtest.jdk=/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/openjdkbinary/j2sdk-image \
06:52:47          -Dcompile.jdk=/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/openjdkbinary/j2sdk-image \
06:52:47          -Dtest.timeout.factor=8.0 \
06:52:47          -Dtest.nativepath=/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/openjdkbinary/openjdk-test-image/jdk/jtreg/native \
06:52:47          -Dtest.root=/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/aqa-tests/openjdk/openjdk-jdk/test/jdk \
06:52:47          -Dtest.name=jdk/internal/jimage/JImageReadTest.java \
06:52:47          -Dtest.file=/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/aqa-tests/openjdk/openjdk-jdk/test/jdk/jdk/internal/jimage/JImageReadTest.java \
06:52:47          -Dtest.src=/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/aqa-tests/openjdk/openjdk-jdk/test/jdk/jdk/internal/jimage \
06:52:47          -Dtest.src.path=/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/aqa-tests/openjdk/openjdk-jdk/test/jdk/jdk/internal/jimage \
06:52:47          -Dtest.classes=/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/aqa-tests/TKG/output_16396548231476/jdk_lang_1/work/classes/1/jdk/internal/jimage/JImageReadTest.d \
06:52:47          -Dtest.class.path=/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/aqa-tests/TKG/output_16396548231476/jdk_lang_1/work/classes/1/jdk/internal/jimage/JImageReadTest.d \
06:52:47          -Dtest.class.path.prefix=/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/aqa-tests/TKG/output_16396548231476/jdk_lang_1/work/classes/1/jdk/internal/jimage/JImageReadTest.d:/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/aqa-tests/openjdk/openjdk-jdk/test/jdk/jdk/internal/jimage \
06:52:47          -Dtest.modules=java.base/jdk.internal.jimage \
06:52:47          -classpath /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/aqa-tests/TKG/output_16396548231476/jdk_lang_1/work/classes/1/jdk/internal/jimage/JImageReadTest.d:/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/aqa-tests/openjdk/openjdk-jdk/test/jdk/jdk/internal/jimage:/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/jvmtest/openjdk/jtreg/lib/testng.jar:/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/jvmtest/openjdk/jtreg/lib/jcommander.jar:/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/jvmtest/openjdk/jtreg/lib/javatest.jar:/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/jvmtest/openjdk/jtreg/lib/jtreg.jar \
06:52:47          com.sun.javatest.regtest.agent.TestNGRunner jdk/internal/jimage/JImageReadTest.java false JImageReadTest
06:52:47  stderr:
06:52:47  JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/aqa-tests/TKG/output_16396548231476/jdk_lang_1/work/scratch/0/javacore.20211216.115232.1413110.0002.txt
06:52:47  JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/aqa-tests/TKG/output_16396548231476/jdk_lang_1/work/scratch/0/Snap.20211216.115232.1413110.0003.trc' in response to an event
06:52:47  JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/aqa-tests/TKG/output_16396548231476/jdk_lang_1/work/scratch/0/Snap.20211216.115232.1413110.0003.trc
06:52:47  JVMDUMP032I JVM requested JIT dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/aqa-tests/TKG/output_16396548231476/jdk_lang_1/work/scratch/0/jitdump.20211216.115232.1413110.0004.dmp' in response to an event
06:52:47  JVMDUMP051I JIT dump occurred in 'pool-1-thread-1' thread 0x0000FFFF90511100
06:52:47  JVMDUMP013I Processed dump event "gpf", detail "".

javacore shows

1XHEXCPCODE    J9Generic_Signal_Number: 00000018
1XHEXCPCODE    Signal_Number: 0000000B
1XHEXCPCODE    Error_Value: 00000000
1XHEXCPCODE    Signal_Code: 00000001
1XHEXCPCODE    Handler1: 0000FFFF976681C0
1XHEXCPCODE    Handler2: 0000FFFF975DE650
1XHEXCPCODE    InaccessibleAddress: 0000000000000020
NULL
1XHEXCPMODULE  Module: /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11/openjdkbinary/j2sdk-image/lib/default/libj9vm29.so
1XHEXCPMODULE  Module_base_address: 0000FFFF97633000
NULL
1XHREGISTERS   Registers:
2XHREGISTER      R0: 0000000000000008
2XHREGISTER      R1: 0000000000000018
2XHREGISTER      R2: 0000000000000004
2XHREGISTER      R3: 0000FFFF900270E0
2XHREGISTER      R4: 0000000000000001
2XHREGISTER      R5: 0000FFFF1D70F940
2XHREGISTER      R6: 000000000000049C
2XHREGISTER      R7: 0000FFFF90426F00
2XHREGISTER      R8: 0000FFFF7028FA30
2XHREGISTER      R9: 0000FFFF900270E0
2XHREGISTER      R10: 0000000000000018
2XHREGISTER      R11: 002A69313306B7DE
2XHREGISTER      R12: 0000A7CF8AD12DFB
2XHREGISTER      R13: 0000000000001200
2XHREGISTER      R14: 0000000000000000
2XHREGISTER      R15: 0000FFFF977E1870
2XHREGISTER      R16: 0000FFFF978030C0
2XHREGISTER      R17: 0000FFFF98414F00
2XHREGISTER      R18: 0000FFFF90332D00
2XHREGISTER      R19: 0000FFFF977D5998
2XHREGISTER      R20: 0000FFFF55EDA0D0
2XHREGISTER      R21: 0000FFFF55EDA240
2XHREGISTER      R22: 0000FFFF90511100
2XHREGISTER      R23: 0000FFFF55EDA100
2XHREGISTER      R24: 0000000000000000
2XHREGISTER      R25: 0000FFFEE0011860
2XHREGISTER      R26: 0000000000000000
2XHREGISTER      R27: 0000FFFF1D70FCCA
2XHREGISTER      R28: 0000FFFF976D2318
2XHREGISTER      R29: 0000FFFF55ED9EE0
2XHREGISTER      R30: 0000FFFF976DB188
2XHREGISTER      R31: 0000FFFF55ED9EE0
2XHREGISTER      V0: 0000000000000000
2XHREGISTER      V1: FFFFFFFFFFFFFFFF
2XHREGISTER      V2: 000000003F800000
2XHREGISTER      V3: 402DFEA6AA9D85D5
2XHREGISTER      V4: BFD00EA348B88334
2XHREGISTER      V5: 3FD5575B0BE00B6A
2XHREGISTER      V6: 3FE62E42FEFA39EF
2XHREGISTER      V7: 4010040140100401
2XHREGISTER      V8: 0000000000000000
2XHREGISTER      V9: 0000000000000000
2XHREGISTER      V10: 0000000000000000
2XHREGISTER      V11: 0000000000000000
2XHREGISTER      V12: 0000000000000000
2XHREGISTER      V13: 0000000000000000
2XHREGISTER      V14: 0000000000000000
2XHREGISTER      V15: 0000000000000000
2XHREGISTER      V16: 4400000000005400
2XHREGISTER      V17: 3FD2492494229359
2XHREGISTER      V18: 3FCC71C51D8E78AF
2XHREGISTER      V19: 3FC7466496CB03DE
2XHREGISTER      V20: 0000FFFF983702D0
2XHREGISTER      V21: 0000FFFF983702C0
2XHREGISTER      V22: 0000FFFF983702B0
2XHREGISTER      V23: 00000000000000F0
2XHREGISTER      V24: 0000000000000000
2XHREGISTER      V25: 0000000000000000
2XHREGISTER      V26: 0000000000000000
2XHREGISTER      V27: 0000000000000000
2XHREGISTER      V28: 0000000000000000
2XHREGISTER      V29: 0000000000000000
2XHREGISTER      V30: 0000000000000000
2XHREGISTER      V31: 0000000000000000
2XHREGISTER      PC: 0000FFFF976D30BC
2XHREGISTER      SP: 0000FFFF55ED9EE0
2XHREGISTER      PSTATE: 0000000060001000
NULL
1XHFLAGS       VM flags:0000000000000000

...

1XMCURTHDINFO  Current thread
3XMTHREADINFO      "pool-1-thread-1" J9VMThread:0x0000FFFF90511100, omrthread_t:0x0000FFFF90503950, java/lang/Thread:0x0000FFFF700EE080, state:R, prio=5
3XMJAVALTHREAD            (java/lang/Thread getId:0x19, isDaemon:true)
3XMTHREADINFO1            (native thread ID:0x15902C, native priority:0x5, native policy:UNKNOWN, vmstate:R, vm thread flags:0x00000020)
3XMTHREADINFO2            (native stack address range from:0x0000FFFF55E9C000, to:0x0000FFFF55EDC000, size:0x40000)
3XMCPUTIME               CPU usage total: 0.076548960 secs, current category="Application"
3XMHEAPALLOC             Heap bytes allocated since last GC cycle=0 (0x0)
1INTERNAL                    Unable to obtain lock context information
3XMTHREADINFO3           Java callstack:
4XESTACKTRACE                at (Missing Method)
3XMTHREADINFO3           Native callstack:
4XENATIVESTACK               (0x0000FFFF975DB2A8 [libj9prt29.so+0x262a8])

[pshipton]

@tajila fyi

[tajila]

I wasnt able to view the native stack (gdb kept crashing), we don't have a ub20-aarch machine internally. I looked at the java stack and it looks like we are in a JIT resolve frame.

[tajila]

30 job grinder - https://openj9-jenkins.osuosl.org/job/Grinder/481/

[pshipton]

we don't have a ub20-aarch machine internally

You can use the external machine, just open an infra issue and ask Adam to set you up.

[tajila]

Native stack frame

#12 <signal handler called>
#13 0x0000ffff976d30bc in VM_VMHelpersFull::methodHandleCompiledEntryPoint (methodHandle=0x0, currentThread=<optimized out>, vm=<optimized out>) at /home/jenkins/workspace/Build_JDK11_aarch64_linux_OpenJDK11/openj9/runtime/oti/VMHelpers.hpp:349
#14 VM_BytecodeInterpreterFull::run (vmThread=<optimized out>, this=0xffff55eda0d0) at /home/jenkins/workspace/Build_JDK11_aarch64_linux_OpenJDK11/openj9/runtime/vm/BytecodeInterpreter.hpp:10359
#15 bytecodeLoopFull (currentThread=<optimized out>) at /home/jenkins/workspace/Build_JDK11_aarch64_linux_OpenJDK11/openj9/runtime/vm/BytecodeInterpreter.inc:112
#16 0x0000ffff9774a448 in c_cInterpreter () at /home/jenkins/workspace/Build_JDK11_aarch64_linux_OpenJDK11/build/linux-aarch64-normal-server-release/vm/runtime/vm/arm64cinterp.s:111

[tajila]

We are crashing because of a NULL methodHandle being passed to VM_VMHelpers::methodHandleCompiledEntryPoint

Given that are JIT resolve frame is on the Java stack, my guess is that this was called from a J2I transition

[tajila]

lll need more runs to confirm, this seems to be failry reproduceable though, it failed 2/30

[tajila]

another grinder with debug asserts https://openj9-jenkins.osuosl.org/job/Grinder/485/

[tajila]

The tempslot is NULL (((_currentThread->tempSlot != 0)) ) in invokevarhandle. This is openj9 implementation.

[tajila]

@babsingh can you please take a look at this

[babsingh]

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.