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

JDK17 Head java/util/ResourceBundle/UTF8Properties/CodePointTest.java - Segmentation error vmState=0x00040000 #14067

Closed JasonFengJ9 closed 2 years ago

JasonFengJ9 commented 2 years ago

Failure link

From an internal build job/Test_openjdk17_j9_sanity.openjdk_x86-64_mac_testList_0/24/ (mac10x64rt03):

openjdk version "17.0.1-beta" 2021-10-19
IBM Semeru Runtime Certified Edition 17.0.1+12-202112030505 (build 17.0.1-beta+12-202112030505)
Eclipse OpenJ9 VM 17.0.1+12-202112030505 (build master-3cbebb1ab, JRE 17 Mac OS X amd64-64-Bit Compressed References 20211203_48 (JIT enabled, AOT enabled)
OpenJ9   - 3cbebb1ab
OMR      - 983d156ca
JCL      - a60fb4eda99 based on jdk-17.0.1+12)

Rerun in Grinder - Change TARGET to run only the failed test targets.

Optional info

Failure output (captured from console output)

[2021-12-03T06:07:57.160Z] variation: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache Mode150
[2021-12-03T06:07:57.160Z] JVM_OPTIONS:  -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:+UseCompressedOops 

[2021-12-03T06:12:49.980Z] --------------------------------------------------
[2021-12-03T06:12:49.980Z] TEST: java/util/ResourceBundle/UTF8Properties/CodePointTest.java

[2021-12-03T06:12:49.982Z] STDERR:
[2021-12-03T06:12:49.982Z] Unhandled exception
[2021-12-03T06:12:49.982Z] Type=Segmentation error vmState=0x00040000
[2021-12-03T06:12:49.982Z] J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
[2021-12-03T06:12:49.982Z] Handler1=0000000004A380A0 Handler2=0000000003985DE0 InaccessibleAddress=0000000000000018
[2021-12-03T06:12:49.982Z] RDI=0000700003903430 RSI=0000700003903438 RAX=0000000000000000 RBX=0000700003903420
[2021-12-03T06:12:49.982Z] RCX=000000009FC4F578 RDX=000000000CBAE570 R8=000000009FC4F578 R9=00000000A2C9B2D0
[2021-12-03T06:12:49.982Z] R10=0000000000000000 R11=000000000CBAE6AB R12=0000000000000000 R13=0000000000000000
[2021-12-03T06:12:49.982Z] R14=000000000CBAE570 R15=0000700003903420
[2021-12-03T06:12:49.982Z] RIP=0000000004AA815A GS=0000 FS=0000 RSP=00007000039031A0
[2021-12-03T06:12:49.982Z] RFlags=0000000000010246 CS=002B RBP=0000700003903410 ERR=0000001800000004
[2021-12-03T06:12:49.982Z] TRAPNO=000000040000000E CPU=0018000000040000 FAULTVADDR=0000000000000018
[2021-12-03T06:12:49.982Z] XMM0 0000000000000005 (f: 5.000000, d: 2.470328e-323)
[2021-12-03T06:12:49.982Z] XMM1 ac72f17222e4a77f (f: 585410432.000000, d: -1.418971e-94)
[2021-12-03T06:12:49.982Z] XMM2 000e1781000e1781 (f: 923521.000000, d: 1.959708e-308)
[2021-12-03T06:12:49.982Z] XMM3 3e3235fc184d733c (f: 407728960.000000, d: 4.240050e-09)
[2021-12-03T06:12:49.982Z] XMM4 3ec6daf9c443a555 (f: 3292767488.000000, d: 2.724573e-06)
[2021-12-03T06:12:49.982Z] XMM5 0000000001d50000 (f: 30736384.000000, d: 1.518579e-316)
[2021-12-03T06:12:49.982Z] XMM6 3fdeeb20c640ddf4 (f: 3326139904.000000, d: 4.831011e-01)
[2021-12-03T06:12:49.982Z] XMM7 4028f40b5ed9812d (f: 1591312640.000000, d: 1.247665e+01)
[2021-12-03T06:12:49.982Z] XMM8 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2021-12-03T06:12:49.982Z] XMM9 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2021-12-03T06:12:49.982Z] XMM10 0000000000000006 (f: 6.000000, d: 2.964394e-323)
[2021-12-03T06:12:49.982Z] XMM11 0000000000000008 (f: 8.000000, d: 3.952525e-323)
[2021-12-03T06:12:49.982Z] XMM12 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2021-12-03T06:12:49.982Z] XMM13 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2021-12-03T06:12:49.982Z] XMM14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2021-12-03T06:12:49.982Z] XMM15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2021-12-03T06:12:49.982Z] Module=/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_x86-64_mac_testList_0/openjdkbinary/j2sdk-image/Contents/Home/lib/default/libj9vm29.dylib
[2021-12-03T06:12:49.982Z] Module_base_address=0000000004A00000 Symbol=_ZN32VM_BytecodeInterpreterCompressed3runEP10J9VMThread
[2021-12-03T06:12:49.982Z] Symbol_address=0000000004A8B3E0
[2021-12-03T06:12:49.982Z] Target=2_90_20211203_48 (Mac OS X 10.15.7)
[2021-12-03T06:12:49.982Z] CPU=amd64 (8 logical CPUs) (0x400000000 RAM)
[2021-12-03T06:12:49.982Z] ----------- Stack Backtrace -----------
[2021-12-03T06:12:49.982Z] ---------------------------------------
[2021-12-03T06:12:49.982Z] JVMDUMP039I Processing dump event "gpf", detail "" at 2021/12/03 01:12:27 - please wait.
[2021-12-03T06:12:49.982Z] JVMDUMP032I JVM requested System dump using '/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_x86-64_mac_testList_0/aqa-tests/TKG/output_16385116759614/jdk_util_0/work/scratch/1/core.20211203.011227.53478.0001.dmp' in response to an event
[2021-12-03T06:12:49.982Z] JVMDUMP010I System dump written to /Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_x86-64_mac_testList_0/aqa-tests/TKG/output_16385116759614/jdk_util_0/work/scratch/1/core.20211203.011227.53478.0001.dmp
[2021-12-03T06:12:49.982Z] JVMDUMP032I JVM requested Java dump using '/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_x86-64_mac_testList_0/aqa-tests/TKG/output_16385116759614/jdk_util_0/work/scratch/1/javacore.20211203.011227.53478.0002.txt' in response to an event
[2021-12-03T06:12:49.982Z] JVMDUMP010I Java dump written to /Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_x86-64_mac_testList_0/aqa-tests/TKG/output_16385116759614/jdk_util_0/work/scratch/1/javacore.20211203.011227.53478.0002.txt
[2021-12-03T06:12:49.982Z] JVMDUMP032I JVM requested Snap dump using '/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_x86-64_mac_testList_0/aqa-tests/TKG/output_16385116759614/jdk_util_0/work/scratch/1/Snap.20211203.011227.53478.0003.trc' in response to an event
[2021-12-03T06:12:49.982Z] JVMDUMP010I Snap dump written to /Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_x86-64_mac_testList_0/aqa-tests/TKG/output_16385116759614/jdk_util_0/work/scratch/1/Snap.20211203.011227.53478.0003.trc
[2021-12-03T06:12:49.982Z] JVMDUMP032I JVM requested JIT dump using '/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_x86-64_mac_testList_0/aqa-tests/TKG/output_16385116759614/jdk_util_0/work/scratch/1/jitdump.20211203.011227.53478.0004.dmp' in response to an event
[2021-12-03T06:12:49.982Z] JVMDUMP051I JIT dump occurred in 'MainThread' thread 0x000000000CBA7100
[2021-12-03T06:12:49.982Z] JVMDUMP053I JIT dump is recompiling java/nio/charset/CharsetDecoder.decode(Ljava/nio/ByteBuffer;Ljava/nio/CharBuffer;Z)Ljava/nio/charset/CoderResult;
[2021-12-03T06:12:49.982Z] JVMDUMP053I JIT dump is recompiling sun/nio/cs/StreamDecoder.implRead([CII)I
[2021-12-03T06:12:49.982Z] JVMDUMP053I JIT dump is recompiling java/util/Properties$LineReader.readLine()I
[2021-12-03T06:12:49.982Z] JVMDUMP010I JIT dump written to /Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_x86-64_mac_testList_0/aqa-tests/TKG/output_16385116759614/jdk_util_0/work/scratch/1/jitdump.20211203.011227.53478.0004.dmp
[2021-12-03T06:12:49.982Z] JVMDUMP013I Processed dump event "gpf", detail "".

[2021-12-03T06:12:49.983Z] TEST RESULT: Failed. Unexpected exit from test [exit code: 255]
[2021-12-03T06:12:49.983Z] --------------------------------------------------
[2021-12-03T06:18:29.385Z] Test results: passed: 883; failed: 1
[2021-12-03T06:18:31.220Z] Report written to /Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_x86-64_mac_testList_0/jvmtest/openjdk/report/html/report.html
[2021-12-03T06:18:31.220Z] Results written to /Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_x86-64_mac_testList_0/aqa-tests/TKG/output_16385116759614/jdk_util_0/work
[2021-12-03T06:18:31.220Z] Error: Some tests failed or other problems occurred.
[2021-12-03T06:18:31.220Z] 
[2021-12-03T06:18:31.220Z] jdk_util_0_FAILED

Tagging comp:vm according to vmState [0x40000]: {J9VMSTATE_JNI}.

pshipton commented 2 years ago

~Possibly a dup of https://github.com/eclipse-openj9/openj9/issues/13983~

pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_x86-64_linux_Nightly/144 - cent7-x64-6 jdk_util_0 -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:+UseCompressedOops java/util/ResourceBundle/UTF8Properties/CodePointTest.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_sanity.openjdk_x86-64_linux_Nightly/144/openjdk_test_output.tar.gz

00:37:31  ACTION: main -- Failed. Unexpected exit from test [exit code: 255]
00:37:31  REASON: User specified action: run main/othervm -Djava.util.PropertyResourceBundle.encoding=ISO-8859-1 CodePointTest 
00:37:31  TIME:   14.31 seconds
00:37:31  messages:
00:37:31  command: main -Djava.util.PropertyResourceBundle.encoding=ISO-8859-1 CodePointTest
00:37:31  reason: User specified action: run main/othervm -Djava.util.PropertyResourceBundle.encoding=ISO-8859-1 CodePointTest 
00:37:31  Mode: othervm [/othervm specified]
00:37:31  elapsed time (seconds): 14.31
00:37:31  configuration:
00:37:31  STDOUT:
00:37:31  STDERR:
00:37:31  Unhandled exception
00:37:31  Type=Segmentation error vmState=0x00040000
00:37:31  J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
00:37:31  Handler1=00007F2D97A360F0 Handler2=00007F2D97792CB0 InaccessibleAddress=0000000000000018
00:37:31  RDI=00000000001C7A9B RSI=00000000001A8B50 RAX=0000000000000000 RBX=00000000001C7830
00:37:31  RCX=00007F2D97DEC460 RDX=00000000001C78D0 R8=0000000000000000 R9=0000000000000000
00:37:31  R10=0000000000000000 R11=00007F2D9CF9F750 R12=000000009FC49E38 R13=0000000000002000
00:37:31  R14=00007F2D70C11140 R15=0000000000000000
00:37:31  RIP=00007F2D97A95181 GS=0000 FS=0000 RSP=00007F2D70C10DD0
00:37:31  EFlags=0000000000010202 CS=0033 RBP=0000000000000004 ERR=0000000000000004
00:37:31  TRAPNO=000000000000000E OLDMASK=0000000000000000 CR2=0000000000000018
00:37:31  xmm0 0000000000000005 (f: 5.000000, d: 2.470328e-323)
00:37:31  xmm1 4f8cc2cefc1183b8 (f: 4229006336.000000, d: 1.626120e+75)
00:37:31  xmm2 000e1781000e1781 (f: 923521.000000, d: 1.959708e-308)
00:37:31  xmm3 000000003479a438 (f: 880387136.000000, d: 4.349690e-315)
00:37:31  xmm4 00000000bcb3e27a (f: 3165905408.000000, d: 1.564165e-314)
00:37:31  xmm5 00000000395a743c (f: 962229312.000000, d: 4.754044e-315)
00:37:31  xmm6 00000000bd31562a (f: 3174127104.000000, d: 1.568227e-314)
00:37:31  xmm7 000000003bf90000 (f: 1006174208.000000, d: 4.971161e-315)
00:37:31  xmm8 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:37:31  xmm9 000000003e17cee7 (f: 1041747712.000000, d: 5.146917e-315)
00:37:31  xmm10 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:37:31  xmm11 0000ff0000000000 (f: 0.000000, d: 1.385239e-309)
00:37:31  xmm12 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:37:31  xmm13 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:37:31  xmm14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:37:31  xmm15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:37:31  Module=/home/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_x86-64_linux_Nightly/openjdkbinary/j2sdk-image/lib/default/libj9vm29.so
00:37:31  Module_base_address=00007F2D979F6000
00:37:31  Target=2_90_20220131_147 (Linux 3.10.0-1127.19.1.el7.x86_64)
00:37:31  CPU=amd64 (4 logical CPUs) (0x1e8cf4000 RAM)
00:37:31  ----------- Stack Backtrace -----------
00:37:31  (0x00007F2D97A95181 [libj9vm29.so+0x9f181])
00:37:31  (0x00007F2D97A88D55 [libj9vm29.so+0x92d55])
00:37:31  (0x00007F2D97B2C742 [libj9vm29.so+0x136742])
00:37:31  ---------------------------------------
pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_x86-64_linux_Nightly/160 - cent7-x64-6 jdk_util_0 -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:+UseCompressedOops java/util/ResourceBundle/UTF8Properties/CodePointTest.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_sanity.openjdk_x86-64_linux_Nightly/160/openjdk_test_output.tar.gz

00:25:47  ACTION: main -- Failed. Unexpected exit from test [exit code: 255]
00:25:47  REASON: User specified action: run main/othervm -Djava.util.PropertyResourceBundle.encoding=ISO-8859-1 CodePointTest 
00:25:47  TIME:   24.709 seconds
00:25:47  messages:
00:25:47  command: main -Djava.util.PropertyResourceBundle.encoding=ISO-8859-1 CodePointTest
00:25:47  reason: User specified action: run main/othervm -Djava.util.PropertyResourceBundle.encoding=ISO-8859-1 CodePointTest 
00:25:47  Mode: othervm [/othervm specified]
00:25:47  elapsed time (seconds): 24.709
00:25:47  configuration:
00:25:47  STDOUT:
00:25:47  STDERR:
00:25:47  Unhandled exception
00:25:47  Type=Segmentation error vmState=0x00040000
00:25:47  J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
00:25:47  Handler1=00007F7074248140 Handler2=00007F706FD9D190 InaccessibleAddress=0000000000000018
00:25:47  RDI=00000000001C7BAB RSI=00000000001A8E50 RAX=0000000000000000 RBX=00000000001C7A10
00:25:47  RCX=00007F70745FE460 RDX=00000000001C7AB0 R8=0000000000000000 R9=00000000FE96CF30
00:25:47  R10=0000000000000000 R11=00007F707561A750 R12=000000009FC53880 R13=0000000000002000
00:25:47  R14=00007F7044F4C140 R15=0000000000000000
00:25:47  RIP=00007F70742A6166 GS=0000 FS=0000 RSP=00007F7044F4BDD0
00:25:47  EFlags=0000000000010202 CS=0033 RBP=0000000000000000 ERR=0000000000000004
00:25:47  TRAPNO=000000000000000E OLDMASK=0000000000000000 CR2=0000000000000018
00:25:47  xmm0 0000000000000005 (f: 5.000000, d: 2.470328e-323)
00:25:47  xmm1 39b12b30e196ac3f (f: 3784748032.000000, d: 8.464830e-31)
00:25:47  xmm2 000e1781000e1781 (f: 923521.000000, d: 1.959708e-308)
00:25:47  xmm3 000000003452023d (f: 877789760.000000, d: 4.336858e-315)
00:25:47  xmm4 000000003cac469c (f: 1017923200.000000, d: 5.029209e-315)
00:25:47  xmm5 000000003950f4bf (f: 961606848.000000, d: 4.750969e-315)
00:25:47  xmm6 000000003d2ec4c3 (f: 1026475200.000000, d: 5.071461e-315)
00:25:47  xmm7 000000004b7cf6e0 (f: 1266480896.000000, d: 6.257247e-315)
00:25:47  xmm8 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:25:47  xmm9 00000000fdb604a8 (f: 4256564480.000000, d: 2.103022e-314)
00:25:47  xmm10 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:25:47  xmm11 0000ff0000000000 (f: 0.000000, d: 1.385239e-309)
00:25:47  xmm12 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:25:47  xmm13 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:25:47  xmm14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:25:47  xmm15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:25:47  Module=/home/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_x86-64_linux_Nightly/openjdkbinary/j2sdk-image/lib/default/libj9vm29.so
00:25:47  Module_base_address=00007F7074208000
00:25:47  Target=2_90_20220217_164 (Linux 3.10.0-1127.19.1.el7.x86_64)
00:25:47  CPU=amd64 (4 logical CPUs) (0x1e8cf4000 RAM)
00:25:47  ----------- Stack Backtrace -----------
00:25:47  _ZN32VM_BytecodeInterpreterCompressed3runEP10J9VMThread+0xb386 (0x00007F70742A6166 [libj9vm29.so+0x9e166])
00:25:47  bytecodeLoopCompressed+0x95 (0x00007F707429ADD5 [libj9vm29.so+0x92dd5])
00:25:47   (0x00007F707433E5B2 [libj9vm29.so+0x1365b2])
00:25:47  ---------------------------------------
pshipton commented 2 years ago

@tajila fyi

tajila commented 2 years ago

The crash happens on a Jit-to-interpreter transistion

> !stackslots 0x1c0500
<1c0500> *** BEGIN STACK WALK, flags = 00400001 walkThread = 0x00000000001C0500 ***
<1c0500>    ITERATE_O_SLOTS
<1c0500>    RECORD_BYTECODE_PC_OFFSET
<1c0500> Initial values: walkSP = 0x00000000001C7A00, PC = 0x00007F70158E5979, literals = 0x000000000026F228, A0 = 0x00000000001C7AB0, j2iFrame = 0x00000000001C7A98, ELS = 0x00007F7044F4C3B0, decomp = 0x0000000000000000
<1c0500> J2I frame: bp = 0x00000000001C7A98, sp = 0x00000000001C7A00, pc = 0x00007F70158E5979, cp = 0x000000000026EF70, arg0EA = 0x00000000001C7AB0, flags = 0x0000000010000000
<1c0500>    Method: sun/nio/cs/ISO_8859_1$Decoder.decodeLoop(Ljava/nio/ByteBuffer;Ljava/nio/CharBuffer;)Ljava/nio/charset/CoderResult; !j9method 0x000000000026F228
<1c0500>    Bytecode index = 17
<1c0500>    Using local mapper
<1c0500>    Locals starting at 0x00000000001C7AB0 for 0x0000000000000003 slots
<1c0500>        I-Slot: a0[0x00000000001C7AB0] = 0x000000009FC53880
<1c0500>        I-Slot: a1[0x00000000001C7AA8] = 0x000000009FD9DBA8
<1c0500>        I-Slot: a2[0x00000000001C7AA0] = 0x00000000FE96CF30
<1c0500>    Pending stack starting at 0x00000000001C7A10 for UDATA(0x0000000000000003) slots
<1c0500>        O-Slot: p0[0x00000000001C7A10] = 0x000000009FC53880
<1c0500>        O-Slot: p1[0x00000000001C7A08] = 0x000000009FD9DBA8
<1c0500>        O-Slot: p2[0x00000000001C7A00] = 0x00000000FE96CF30
<1c0500>    JIT-J2I-RegisterMap[0x00000000001C7A40] = UDATA(0x0000000000000000) (jit_rbx)
<1c0500>    JIT-J2I-RegisterMap[0x00000000001C7A78] = UDATA(0x00000000FE96CF30) (jit_r9)
<1c0500>    JIT-J2I-RegisterMap[0x00000000001C7A70] = UDATA(0x000000009FD9D2F8) (jit_r10)
<1c0500>    JIT-J2I-RegisterMap[0x00000000001C7A68] = UDATA(0x0000000000000004) (jit_r11)
<1c0500>    JIT-J2I-RegisterMap[0x00000000001C7A60] = UDATA(0x0000000000000000) (jit_r12)
<1c0500>    JIT-J2I-RegisterMap[0x00000000001C7A58] = UDATA(0x00000000001AC500) (jit_r13)
<1c0500>    JIT-J2I-RegisterMap[0x00000000001C7A50] = UDATA(0x0000000000000000) (jit_r14)
<1c0500>    JIT-J2I-RegisterMap[0x00000000001C7A48] = UDATA(0x00000000FE96CF60) (jit_r15)
<1c0500> JIT inline frame: bp = 0x00000000001C7B18, pc = 0x00007F704C3A1F8F, unwindSP = 0x00000000001C7AA0, cp = 0x00000000001A9010, arg0EA = 0x0000000000000000, jitInfo = 0x00007F7045A095F8
<1c0500>    Method: java/nio/charset/CharsetDecoder.decode(Ljava/nio/ByteBuffer;Ljava/nio/CharBuffer;Z)Ljava/nio/charset/CoderResult; !j9method 0x00000000001A9760
<1c0500>    Bytecode index = 57, inlineDepth = 1, PC offset = 0x0000000000002847
<1c0500> JIT frame: bp = 0x00000000001C7B18, pc = 0x00007F704C3A1F8F, unwindSP = 0x00000000001C7AA0, cp = 0x00000000001A83B0, arg0EA = 0x00000000001C7B38, jitInfo = 0x00007F7045A095F8
<1c0500>    Method: sun/nio/cs/StreamDecoder.implRead([CII)I !j9method 0x00000000001A8F50
<1c0500>    Bytecode index = 61, inlineDepth = 0, PC offset = 0x00000000000015A7
<1c0500>    stackMap=0x00007F7045A09FE8, slots=I16(0x0004) parmBaseOffset=I16(0x0018), parmSlots=U16(0x0002), localBaseOffset=I16(0xFFE0)
<1c0500>    Described JIT args starting at 0x00000000001C7B30 for U16(0x0002) slots
<1c0500>        O-Slot: : a1[0x00000000001C7B30] = 0x00000000A32A7BC0
<1c0500>        O-Slot: : a0[0x00000000001C7B38] = 0x000000009FD9DB50
<1c0500>    Described JIT temps starting at 0x00000000001C7AF8 for IDATA(0x0000000000000004) slots
<1c0500>        O-Slot: : t3[0x00000000001C7AF8] = 0x00000000FE96CF30
<1c0500>        O-Slot: : t2[0x00000000001C7B00] = 0x000000009FD9DBA8
<1c0500>        O-Slot: : t1[0x00000000001C7B08] = 0x000000009FD9DB80
<1c0500>        I-Slot: : t0[0x00000000001C7B10] = 0x0000000000000206
<1c0500>    JIT-RegisterMap = UDATA(0x0000000000000000)
<1c0500>    JIT-Frame-RegisterMap[0x00000000001C7AE0] = UDATA(0x000000009FD9D240) (jit_rbx)
<1c0500>    JIT-Frame-RegisterMap[0x00000000001C7AE8] = UDATA(0x000000009FD9D240) (jit_r9)
<1c0500>    JIT-Frame-RegisterMap[0x00000000001C7A70] = UDATA(0x000000009FD9D2F8) (jit_r10)
<1c0500>    JIT-Frame-RegisterMap[0x00000000001C7A68] = UDATA(0x0000000000000004) (jit_r11)
<1c0500>    JIT-Frame-RegisterMap[0x00000000001C7A60] = UDATA(0x0000000000000000) (jit_r12)
<1c0500>    JIT-Frame-RegisterMap[0x00000000001C7A58] = UDATA(0x00000000001AC500) (jit_r13)
<1c0500>    JIT-Frame-RegisterMap[0x00000000001C7A50] = UDATA(0x0000000000000000) (jit_r14)
<1c0500>    JIT-Frame-RegisterMap[0x00000000001C7A48] = UDATA(0x00000000FE96CF60) (jit_r15)
<1c0500> I2J values: PC = 0x00007F7015747110, A0 = 0x00000000001C7BA8, walkSP = 0x0000000000000000, literals = 0x00000000001A8E50, JIT PC = 0x00007F70686B05D0, pcAddress = 0x00000000001C7A30, decomp = 0x0000000000000000
<1c0500> Bytecode frame: bp = 0x00000000001C7B58, sp = 0x0000000000000000, pc = 0x00007F7015747110, cp = 0x00000000001A83B0, arg0EA = 0x00000000001C7BA8, flags = 0x0000000000000000
tajila commented 2 years ago

We crash in startProfilingRecord

IDATA count = (IDATA)(UDATA)_literals->extra;

Literals is corrupt

pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk18_j9_sanity.openjdk_x86-64_linux_Nightly/8 - ub18-x86-1 jdk_util_0 - -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:+UseCompressedOops java/util/ResourceBundle/UTF8Properties/CodePointTest.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk18_j9_sanity.openjdk_x86-64_linux_Nightly/8/openjdk_test_output.tar.gz

01:05:46  ACTION: main -- Failed. Unexpected exit from test [exit code: 255]
01:05:46  REASON: User specified action: run main/othervm -Djava.util.PropertyResourceBundle.encoding=ISO-8859-1 CodePointTest 
01:05:46  TIME:   13.917 seconds
01:05:46  messages:
01:05:46  command: main -Djava.util.PropertyResourceBundle.encoding=ISO-8859-1 CodePointTest
01:05:46  reason: User specified action: run main/othervm -Djava.util.PropertyResourceBundle.encoding=ISO-8859-1 CodePointTest 
01:05:46  Mode: othervm [/othervm specified]
01:05:46  elapsed time (seconds): 13.917
01:05:46  configuration:
01:05:46  STDOUT:
01:05:46  STDERR:
01:05:46  Unhandled exception
01:05:46  Type=Segmentation error vmState=0x00030000
01:05:46  J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
01:05:46  Handler1=00007F0388124220 Handler2=00007F0383D9D190 InaccessibleAddress=00000000000007D1
01:05:46  RDI=00000000001EA858 RSI=0000000000000006 RAX=0000000000000000 RBX=0000000000000000
01:05:46  RCX=0000000000000000 RDX=00000000000007D1 R8=00000000001EA858 R9=00007F032D74DFF6
01:05:46  R10=00000000001EA7F8 R11=0000000004200000 R12=00007F03468002E0 R13=0000000004200000
01:05:46  R14=0000000000000000 R15=0000000000000000
01:05:46  RIP=00007F0388164D40 GS=0000 FS=0000 RSP=00007F0346800240
01:05:46  EFlags=0000000000010216 CS=0033 RBP=00000000001A6800 ERR=0000000000000004
01:05:46  TRAPNO=000000000000000E OLDMASK=0000000000000000 CR2=00000000000007D1
01:05:46  xmm0 0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:05:46  xmm1 0000000000000006 (f: 6.000000, d: 2.964394e-323)
01:05:46  xmm2 0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:05:46  xmm3 0000000000000006 (f: 6.000000, d: 2.964394e-323)
01:05:46  xmm4 0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:05:46  xmm5 00000000001ea852 (f: 2009170.000000, d: 9.926619e-318)
01:05:46  xmm6 00000000000007d1 (f: 2001.000000, d: 9.886254e-321)
01:05:46  xmm7 00000000001e9db0 (f: 2006448.000000, d: 9.913170e-318)
01:05:46  xmm8 0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:05:46  xmm9 0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:05:46  xmm10 0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:05:46  xmm11 0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:05:46  xmm12 0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:05:46  xmm13 0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:05:46  xmm14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:05:46  xmm15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
01:05:46  Module=/home/jenkins/workspace/Test_openjdk18_j9_sanity.openjdk_x86-64_linux_Nightly/openjdkbinary/j2sdk-image/lib/default/libj9vm29.so
01:05:46  Module_base_address=00007F03880E4000
01:05:46  Target=2_90_20220301_18 (Linux 4.15.0-143-generic)
01:05:46  CPU=amd64 (4 logical CPUs) (0x5e2804000 RAM)
01:05:46  ----------- Stack Backtrace -----------
01:05:46  walkStackFrames+0xac0 (0x00007F0388164D40 [libj9vm29.so+0x80d40])
01:05:46  internalGrowJavaStack+0x285 (0x00007F03881245E5 [libj9vm29.so+0x405e5])
01:05:46  growJavaStack+0x11 (0x00007F0388125001 [libj9vm29.so+0x41001])
01:05:46  _ZN32VM_BytecodeInterpreterCompressed3runEP10J9VMThread+0xa601 (0x00007F03881815C1 [libj9vm29.so+0x9d5c1])
01:05:46  bytecodeLoopCompressed+0x95 (0x00007F0388176FB5 [libj9vm29.so+0x92fb5])
01:05:46   (0x00007F038821A792 [libj9vm29.so+0x136792])
01:05:46  ---------------------------------------
pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_x86-64_linux_Nightly/173/ - cent7-x64-1 jdk_util_0 java/util/ResourceBundle/UTF8Properties/CodePointTest.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_sanity.openjdk_x86-64_linux_Nightly/173/openjdk_test_output.tar.gz

23:39:38  Unhandled exception
23:39:38  Type=Segmentation error vmState=0x00040000
23:39:38  J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
23:39:38  Handler1=00007FBDFB820140 Handler2=00007FBDFB57D190 InaccessibleAddress=FFFFFFFFFFFFFFF8
23:39:38  RDI=FFFFFFFFFFFFFFF8 RSI=00000000001C0600 RAX=FFFFFFFFFFFFFFF8 RBX=00007FBD9D7471C8
23:39:38  RCX=00000000001AA050 RDX=00007FBD00000418 R8=0000000000000000 R9=00000000FBAA4D58
23:39:38  R10=00000000FBAA8070 R11=00007FBE00C67750 R12=00000000FBAA8070 R13=0000000000002000
23:39:38  R14=00007FBDD416F140 R15=0000000000000000
23:39:38  RIP=00007FBE00C35A03 GS=0000 FS=0000 RSP=00007FBDD416EDC8
23:39:38  EFlags=0000000000010287 CS=0033 RBP=00007FBDD416F380 ERR=0000000000000007
23:39:38  TRAPNO=000000000000000E OLDMASK=0000000000000000 CR2=FFFFFFFFFFFFFFF8
23:39:38  xmm0 0000000000000005 (f: 5.000000, d: 2.470328e-323)
23:39:38  xmm1 003100790065006b (f: 6619243.000000, d: 9.457591e-308)
23:39:38  xmm2 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:39:38  xmm3 6b0a1d3d64317965 (f: 1680963968.000000, d: 4.192027e+207)
23:39:38  xmm4 6b0a1b3d62317965 (f: 1647409536.000000, d: 4.190773e+207)
23:39:38  xmm5 6b0a333d33337965 (f: 859011456.000000, d: 4.205822e+207)
23:39:38  xmm6 6b0a313d31337965 (f: 825457024.000000, d: 4.204567e+207)
23:39:38  xmm7 6b0a263d36327965 (f: 909277568.000000, d: 4.197670e+207)
23:39:38  xmm8 6b0a243d34327965 (f: 875723136.000000, d: 4.196416e+207)
23:39:38  xmm9 0a293d393279656b (f: 846816640.000000, d: 1.025956e-259)
23:39:38  xmm10 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:39:38  xmm11 0000ff0000000000 (f: 0.000000, d: 1.385239e-309)
23:39:38  xmm12 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:39:38  xmm13 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:39:38  xmm14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:39:38  xmm15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:39:38  Module=/lib64/libc.so.6
23:39:38  Module_base_address=00007FBE00AD9000
23:39:38  Target=2_90_20220306_177 (Linux 3.10.0-1160.25.1.el7.x86_64)
23:39:38  CPU=amd64 (4 logical CPUs) (0x1e8cf3000 RAM)
23:39:38  ----------- Stack Backtrace -----------
23:39:38  __memmove_ssse3_back+0x27f3 (0x00007FBE00C35A03 [libc.so.6+0x15ca03])
23:39:38  _ZN32VM_BytecodeInterpreterCompressed3runEP10J9VMThread+0x76e (0x00007FBDFB87354E [libj9vm29.so+0x9354e])
23:39:38  bytecodeLoopCompressed+0x95 (0x00007FBDFB872DD5 [libj9vm29.so+0x92dd5])
23:39:38   (0x00007FBDFB9165B2 [libj9vm29.so+0x1365b2])
23:39:38  ---------------------------------------
tajila commented 2 years ago

The core above shows we are getting a corrupt ELS when returning from a JIT frame.

> !j9vmentrylocalstorage 0x00007FBDD416F3B0
J9VMEntryLocalStorage at 0x7fbdd416f3b0 {
  Fields for J9VMEntryLocalStorage:
    0x0: struct J9VMEntryLocalStorage* oldEntryLocalStorage = !j9vmentrylocalstorage 0x00007FBDD416FB90
    0x8: UDATA* jitGlobalStorageBase = !j9x 0x00007FBDD416F1D0
    0x10: struct J9I2JState i2jState = !j9i2jstate 0x00007FBDD416F3C0
    0x30: UDATA* jitFPRegisterStorageBase = !j9x 0x00007FBDD416F250
    0x38: UDATA[] jitTempSpace = !j9x 0x00007FBDD416F3E8
    0x58: void** machineSPSaveSlot = !j9x 0x00007FBDD416F1C0
}

> !j9i2jstate 0x00007FBDD416F3C0
J9I2JState at 0x7fbdd416f3c0 {
  Fields for J9I2JState:
    0x0: UDATA* returnSP = !j9x 0x0000000000000000 //<-- corrupt value
    0x8: UDATA* a0 = !j9x 0x00000000001C7BD8
    0x10: struct J9Method* literals = !j9method 0x00000000001AA050 // sun/nio/cs/StreamDecoder.read([CII)I
    0x18: U8* pc = !j9x 0x00007FBD9D7471C8 // "�""
}

When we attempt to copy the args back on to the stack we crash with NULL as the dest arg to memmove

tajila commented 2 years ago

@0xdaryl can someone from the JIT team take a look

0xdaryl commented 2 years ago

Sorry, missed the tag. @a7ehuo, could you look into this one please?

tajila commented 2 years ago

It looks like we are returning from 

> !j9method 0x00000000001AA150
J9Method at 0x1aa150 {
  Fields for J9Method:
    0x0: U8* bytecodes = !j9x 0x00007FBD9D747694 // "�
    0x8: struct J9ConstantPool* constantPool = !j9constantpool 0x00000000001A9590 (flags = 0x0)
    0x10: void* methodRunAddress = !j9x 0x0000000000000018
    0x18: volatile void* extra = !j9x 0x00007FBDD7584F88
}
Signature: sun/nio/cs/StreamDecoder.implRead([CII)I !bytecodes 0x00000000001AA150
ROM Method: !j9rommethod 0x00007FBD9D747680 (edited)

in sun/nio/cs/StreamDecoder.read BC 180

a7ehuo commented 2 years ago

Ran jdk_util_0 in Grinder (21986) 15x: all passed Ran jdk_util_0 CodePointTest.java test locally 150x: all passed

a7ehuo commented 2 years ago

Another 20x runs in Grinder (22003) passed Locally ran CodePointTest.java test 500x: all passed

a7ehuo commented 2 years ago

@tajila All other fields in entryLocalStorage->i2jState look valid except for returnSP after the execution returns from sun/nio/cs/StreamDecoder.implRead([CII)I(JIT'd) back to sun/nio/cs/StreamDecoder.read([CII)I (interpreted). Is entryLocalStorage->i2jState set up in jitTransition before the execution goes into the JIT'd method? I haven't found places in the JIT that modify entryLocalStorage->i2jState. What other code that could modify entryLocalStorage->i2jState during this interpreter->jit->interpreter transition? 

> !j9i2jstate 0x00007FBDD416F3C0
J9I2JState at 0x7fbdd416f3c0 {
  Fields for J9I2JState:
    0x0: UDATA* returnSP = !j9x 0x0000000000000000 // invalid 
    0x8: UDATA* a0 = !j9x 0x00000000001C7BD8 // on-java-stack(0x1c0500) Ptr Obj - {sun/nio/cs/StreamDecoder} // 0x1c7bd8: 0x00000000fbaa2c70 Obj - {sun/nio/cs/StreamDecoder}
    0x10: struct J9Method* literals = !j9method 0x00000000001AA050 // sun/nio/cs/StreamDecoder.read([CII)I
    0x18: U8* pc = !j9x 0x00007FBD9D7471C8 // "�"" // within the byte code range: 7fbd9d747114 -- 7fbd9d7471d8. Offset 0xB4(180)
}
bytecodes of sun/nio/cs/StreamDecoder.read([CII)I <-- 0x1AA050
...
  169 iload 7
  171 aload0 
  172 aload1
  173 iload 4
  175 iload 4
  177 iload 5
  179 iadd 
  180 invokevirtual 34 sun/nio/cs/StreamDecoder.implRead([CII)I
  183 iadd 
  184 aload 6
  186 monitorexit 
  187 return1
...
tajila commented 2 years ago

@gacholio Is i2jState only modified by the interpreter?

gacholio commented 2 years ago

It can also be modified by decompilation, DLT transition or stack grow (not a real modification in this case, just updating moved pointers).

gacholio commented 2 years ago

I don't see anywhere that would be writing a 0 to the returnSP.

tajila commented 2 years ago

@JasonFengJ9 Has this issue been reproduced recently? I think we will need more diagnostic information

JasonFengJ9 commented 2 years ago

Has this issue been reproduced recently?

Not in recent builds (just checked x86-64_mac & x86-64_linux ), will launch grinders after infra maintenance.

JasonFengJ9 commented 2 years ago

x86-64_mac 50x grinder - job/Grinder/22313/ x86-64_linux 50x grinder - job/Grinder/22311/

JasonFengJ9 commented 2 years ago

Both grinder passed, I think this can be closed, and re-open if further investigation is possible.

pshipton commented 2 years ago

@JasonFengJ9 can you pls try grinders on a 0.32 build. The most recent build is https://openj9-jenkins.osuosl.org/job/Pipeline-Release-0.32.0-Build17/1/ but I've also just started https://openj9-jenkins.osuosl.org/job/Pipeline-Release-0.32.0-Build17/2/ to pick up the latest fix for hidden frames.

JasonFengJ9 commented 2 years ago

x86-64_mac 50x grinder - job/Grinder/22365/ - passed x86-64_linux 50x grinder - job/Grinder/22366/ - passed

pshipton commented 2 years ago

Since this can't be repeated in the head stream or the 0.32 steam, I'm ok to close this and reopen if the problem is seen again. I'll start by removing it from the milestone plan.

@0xdaryl I think there may still be some investigation into the existing core, pls close if appropriate once investigations have completed.

pshipton commented 2 years ago

Hmm, although the grinders were on the individual test and not on jdk_util_0. Sometimes problems only re-occur when running the larger, longer running, set of tests. @JasonFengJ9 can you please start some grinders on jdk_util_0.

JasonFengJ9 commented 2 years ago

x86-64_mac 50x grinder - job/Grinder/22389/ - unrelated failures x86-64_linux 50x grinder - job/Grinder/22390/ - passed

JasonFengJ9 commented 2 years ago

The failure wasn't reproduced in grinders above.

pshipton commented 2 years ago

Grinders are on the 0.32 release branch, I see Jason removed this issue from the milestone.

@0xdaryl I think there may still be some investigation into the existing core, pls close if appropriate once investigations have completed.

a7ehuo commented 2 years ago

I haven't found much from the compiled method. It's not DLT compiled. 

04:39:20.988118000  0x000000000001ac00 j9jit.44            Event       + (cold) sun/nio/cs/StreamDecoder.implRead([CII)I @ 0x7fbdd7584f88-0x7fbdd75856e7/0x0-0x7fbdd75856e7 time=6910us 0x1aa150 0x7fbdd4c2dab8 RR=- Q_SZ=0 bcsz=243 mem=16384KB     GCR 

(kca) j9m 0x7fbdd7584f88
J9Method for JIT Method: {sun/nio/cs/StreamDecoder.implRead}
Method   {ClassPath/Name.MethodName}: {sun/nio/cs/StreamDecoder.implRead}
                           Signature: ([CII)I
                              Access: 
                    J9Class/J9Method: 0x00000000001a9d00 / 0x00000000001aa150
               Compiled Method Start: 0x00007fbdd7584f88 (1955 bytes)
                      ByteCode Start: 0x00007fbd9d747694 (243 bytes)
                   ROM Constant Pool: 0x00007fbd9d7468f0 (99 entries)
                       Constant Pool: 0x00000000001a9590 (0 entries)
pshipton commented 2 years ago

I assume there is nothing else going on there, closing.