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

OpenJDK crash in Compiled_method=UnicodeCasingTest.test #17515

Open pshipton opened 1 year ago

pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/541 - cent7-ppcle-1 jdk_lang_1 java/lang/String/UnicodeCasingTest.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/541/openjdk_test_output.tar.gz

23:25:28  Testing on en_stderr:
23:25:28  Unhandled exception
23:25:28  Type=Segmentation error vmState=0x00000000
23:25:28  J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
23:25:28  Handler1=00003FFF97514910 Handler2=00003FFF9743D440
23:25:28  R0=0000000000000001 R1=00003FFF4A8BAC00 R2=00003FFF902E0A00 R3=00003FFF69A09738
23:25:28  R4=00003FFF881E65D8 R5=00003FFF881E65D8 R6=0000000000010000 R7=0000000000000001
23:25:28  R8=00003FFF881E6A68 R9=FFFFFFFF80000001 R10=0000000000000000 R11=00003FFED4200108
23:25:28  R12=00003FFF902E0A00 R13=00003FFF4A8C6900 R14=00003FFED41FFBA0 R15=00003FFF9077FE00
23:25:28  R16=00003FFF506B0038 R17=0000000000000010 R18=0000000000000000 R19=0000000000245498
23:25:28  R20=00003FFF69ADB3A0 R21=FFFFFFFF80000001 R22=00003FFF69ADB3A0 R23=0000000000000005
23:25:28  R24=FFFFFFFF80000001 R25=FFFFFFFFF8000001 R26=0000000000000000 R27=0000000000000000
23:25:28  R28=0000000000010000 R29=0000000000000000 R30=00003FFF881E65F0 R31=0000000000000031
23:25:28  NIP=00003FFF512CEFBC MSR=800000010280F033 ORIG_GPR3=00000000000081C8 CTR=00003FFF96707B68
23:25:28  LINK=00003FFF512CD284 XER=0000000000000000 CCR=0000000048004824 SOFTE=0000000000000001
23:25:28  TRAP=0000000000000300 DAR=0000000000000008 dsisr=0000000040000000 RESULT=0000000000000000
23:25:28  FPR0 c3d9db0180000000 (f: 2147483648.000000, d: -7.452338e+18)
23:25:28  FPR1 40570573e0000000 (f: 3758096384.000000, d: 9.208520e+01)
23:25:28  FPR2 3fb2fd4240000000 (f: 1073741824.000000, d: 7.417692e-02)
23:25:28  FPR3 3fee666660000000 (f: 1610612736.000000, d: 9.500000e-01)
23:25:28  FPR4 4006c783c0000000 (f: 3221225472.000000, d: 2.847419e+00)
23:25:28  FPR5 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR6 3fe5555560000000 (f: 1610612736.000000, d: 6.666667e-01)
23:25:28  FPR7 3f2c7e7740000000 (f: 1073741824.000000, d: 2.173920e-04)
23:25:28  FPR8 c3d9db0180000000 (f: 2147483648.000000, d: -7.452338e+18)
23:25:28  FPR9 37fb801900000000 (f: 0.000000, d: 5.051022e-39)
23:25:28  FPR10 003b003b003b003b (f: 3866683.000000, d: 1.501975e-307)
23:25:28  FPR11 003b003b003b003b (f: 3866683.000000, d: 1.501975e-307)
23:25:28  FPR12 40a43a0000000000 (f: 0.000000, d: 2.589000e+03)
23:25:28  FPR13 3fdb9b2820000000 (f: 536870912.000000, d: 4.313450e-01)
23:25:28  FPR14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR16 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR17 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR18 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR19 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR20 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR21 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR22 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR23 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR24 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR25 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR26 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR27 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR28 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR29 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR30 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  FPR31 0000000000000000 (f: 0.000000, d: 0.000000e+00)
23:25:28  
23:25:28  Compiled_method=UnicodeCasingTest.test(Ljava/lang/String;)V
23:25:28  Target=2_90_20230601_557 (Linux 3.10.0-1160.88.1.el7.ppc64le)
23:25:28  CPU=ppc64le (8 logical CPUs) (0x1de290000 RAM)
23:25:28  ----------- Stack Backtrace -----------
23:25:28  protectedBacktrace+0x24 (0x00003FFF97437484 [libj9prt29.so+0x37484])
23:25:28  omrsig_protect+0x358 (0x00003FFF9743E848 [libj9prt29.so+0x3e848])
23:25:28  omrintrospect_backtrace_thread_raw+0xe4 (0x00003FFF97437AB4 [libj9prt29.so+0x37ab4])
23:25:28  protectedIntrospectBacktraceThread+0x24 (0x00003FFF97437094 [libj9prt29.so+0x37094])
23:25:28  omrsig_protect+0x358 (0x00003FFF9743E848 [libj9prt29.so+0x3e848])
23:25:28  omrintrospect_backtrace_thread+0x98 (0x00003FFF974371A8 [libj9prt29.so+0x371a8])
23:25:28  generateDiagnosticFiles+0x140 (0x00003FFF97514790 [libj9vm29.so+0x44790])
23:25:28  omrsig_protect+0x358 (0x00003FFF9743E848 [libj9prt29.so+0x3e848])
23:25:28  structuredSignalHandler+0x1b4 (0x00003FFF97514AC4 [libj9vm29.so+0x44ac4])
23:25:28  mainSynchSignalHandler+0x260 (0x00003FFF9743D6A0 [libj9prt29.so+0x3d6a0])
23:25:28  __kernel_sigtramp_rt64+0x0 (0x00003FFF97E40478)
23:25:28   (0x00003FFF511D2D10 [<unknown>+0x0])
23:25:28  sidecarInvokeReflectMethodImpl+0x3c0 (0x00003FFF974EE6E0 [libj9vm29.so+0x1e6e0])
23:25:28  sidecarInvokeReflectMethod+0x38 (0x00003FFF974EFB78 [libj9vm29.so+0x1fb78])
23:25:28  JVM_InvokeMethod_Impl+0xb4 (0x00003FFF95B31B84 [libjclse29.so+0x81b84])
23:25:28  JVM_InvokeMethod+0x40 (0x00003FFF97A440D0 [libjvm.so+0x240d0])
23:25:28  JVM_InvokeMethod+0x34 (0x00003FFF97B16C04 [libjvm.so+0x6c04])
23:25:28  Java_jdk_internal_reflect_NativeMethodAccessorImpl_invoke0+0x24 (0x00003FFF5031D174 [libjava.so+0xd174])
23:25:28   (0x00003FFF50DE48A0 [<unknown>+0x0])
23:25:28  runJavaThread+0x340 (0x00003FFF974E94D0 [libj9vm29.so+0x194d0])
23:25:28  javaProtectedThreadProc+0xf0 (0x00003FFF975862F0 [libj9vm29.so+0xb62f0])
23:25:28  omrsig_protect+0x358 (0x00003FFF9743E848 [libj9prt29.so+0x3e848])
23:25:28  javaThreadProc+0x64 (0x00003FFF97581504 [libj9vm29.so+0xb1504])
23:25:28  thread_wrapper+0x1a8 (0x00003FFF973D13E8 [libj9thr29.so+0x113e8])
23:25:28  start_thread+0x104 (0x00003FFF97DB8CD4 [libpthread.so.0+0x8cd4])
23:25:28  clone+0xe4 (0x00003FFF97C77F14 [libc.so.6+0x127f14])
23:25:28  ---------------------------------------
pshipton commented 1 year ago

@0xdaryl fyi

pshipton commented 1 year ago

5x x 5 grinder https://openj9-jenkins.osuosl.org/job/Grinder/2480/

0xdaryl commented 1 year ago

@zl-wang : please assign for investigation

zl-wang commented 1 year ago

@bhavanisn please take a look

pshipton commented 1 year ago

The crash was not duplicated in the grinder.

bhavanisn commented 1 year ago

@pshipton As the crash is not reproducible is there a way to get the coredump files ? Not able to find core files in openjdk_test_output.tar.gz .

In parallel, I am also trying to reproduce the issue.

pshipton commented 1 year ago

The core file is found in openjdk_test_output.tar.gz at aqa-tests\TKG\output_16856733853316\jdk_lang_1\work\java\lang\String\UnicodeCasingTest\

bhavanisn commented 1 year ago

The core file is found in openjdk_test_output.tar.gz at aqa-tests\TKG\output_16856733853316\jdk_lang_1\work\java\lang\String\UnicodeCasingTest\

I see it now. I ran find . -name core* in zsh (Mac cmdline) which didn't return anything. I also looked at the path it printed out, but it was not there too. I will take a look at the file. Thank you.

pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Release/62 - cent7-ppcle-3 jdk_lang_0 java/lang/String/UnicodeCasingTest.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Release/62/openjdk_test_output.tar.gz

21:10:28  Testing on en_stderr:
21:10:28  Unhandled exception
21:10:28  Type=Segmentation error vmState=0x00000000
21:10:28  J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
21:10:28  Handler1=00003FFFB66749B0 Handler2=00003FFFB659D440
21:10:28  R0=0000000000010000 R1=00003FFF8824AC00 R2=00000000000BDF00 R3=00000000E01B7368
21:10:28  R4=FFFFFFFF80000001 R5=0000000000000008 R6=00000000000BDF00 R7=0000000000000001
21:10:28  R8=00000000FF8E2708 R9=00000000004C0A78 R10=0000000000000020 R11=0000000000000000
21:10:28  R12=0000000000000004 R13=00003FFF88256900 R14=00000000004C0590 R15=000000000039E000
21:10:28  R16=00003FFF8A7E0038 R17=00000000004C0A78 R18=00000000FF8E2618 R19=00000000FF8E26B8
21:10:28  R20=00000000E02552E8 R21=0000000000000000 R22=FFFFFFFFF8000001 R23=0000000000000000
21:10:28  R24=0000000000000005 R25=00000000FF8E2400 R26=FFFFFFFF80000001 R27=0000000000000000
21:10:28  R28=00000000E004D898 R29=0000000000000000 R30=00000000004C0A78 R31=00000000FF8E2410
21:10:28  NIP=00003FFF911AC854 MSR=800000010280F033 ORIG_GPR3=00000000000081C8 CTR=00003FFFB5867908
21:10:28  LINK=00003FFF911A578C XER=0000000000000000 CCR=0000000042004844 SOFTE=0000000000000001
21:10:28  TRAP=0000000000000300 DAR=0000000000000004 dsisr=0000000040000000 RESULT=0000000000000000
21:10:28  FPR0 c3a61b06c0000000 (f: 3221225472.000000, d: -7.964372e+17)
21:10:28  FPR1 4055102fe0000000 (f: 3758096384.000000, d: 8.425292e+01)
21:10:28  FPR2 3fb173be40000000 (f: 1073741824.000000, d: 6.817235e-02)
21:10:28  FPR3 3fee666660000000 (f: 1610612736.000000, d: 9.500000e-01)
21:10:28  FPR4 400772bac0000000 (f: 3221225472.000000, d: 2.931020e+00)
21:10:28  FPR5 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR6 3fe5555560000000 (f: 1610612736.000000, d: 6.666667e-01)
21:10:28  FPR7 3f2a1e97e0000000 (f: 3758096384.000000, d: 1.992760e-04)
21:10:28  FPR8 c3a61b06c0000000 (f: 3221225472.000000, d: -7.964372e+17)
21:10:28  FPR9 004c004600200054 (f: 2097236.000000, d: 3.115222e-307)
21:10:28  FPR10 3806001140000000 (f: 1073741824.000000, d: 8.081620e-39)
21:10:28  FPR11 38014011c0000000 (f: 3221225472.000000, d: 6.336749e-39)
21:10:28  FPR12 40a0f00000000000 (f: 0.000000, d: 2.168000e+03)
21:10:28  FPR13 4020800000000000 (f: 0.000000, d: 8.250000e+00)
21:10:28  FPR14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR16 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR17 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR18 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR19 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR20 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR21 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR22 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR23 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR24 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR25 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR26 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR27 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR28 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR29 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR30 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  FPR31 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:10:28  
21:10:28  Compiled_method=UnicodeCasingTest.test(Ljava/lang/String;)V
21:10:28  Target=2_90_20230610_78 (Linux 3.10.0-1160.88.1.el7.ppc64le)
21:10:28  CPU=ppc64le (8 logical CPUs) (0x1de290000 RAM)
21:10:28  ----------- Stack Backtrace -----------
21:10:28  protectedBacktrace+0x24 (0x00003FFFB6597484 [libj9prt29.so+0x37484])
21:10:28  omrsig_protect+0x358 (0x00003FFFB659E848 [libj9prt29.so+0x3e848])
21:10:28  omrintrospect_backtrace_thread_raw+0xe4 (0x00003FFFB6597AB4 [libj9prt29.so+0x37ab4])
21:10:28  protectedIntrospectBacktraceThread+0x24 (0x00003FFFB6597094 [libj9prt29.so+0x37094])
21:10:28  omrsig_protect+0x358 (0x00003FFFB659E848 [libj9prt29.so+0x3e848])
21:10:28  omrintrospect_backtrace_thread+0x98 (0x00003FFFB65971A8 [libj9prt29.so+0x371a8])
21:10:28  generateDiagnosticFiles+0x140 (0x00003FFFB6674830 [libj9vm29.so+0x44830])
21:10:28  omrsig_protect+0x358 (0x00003FFFB659E848 [libj9prt29.so+0x3e848])
21:10:28  structuredSignalHandler+0x1b4 (0x00003FFFB6674B64 [libj9vm29.so+0x44b64])
21:10:28  mainSynchSignalHandler+0x260 (0x00003FFFB659D6A0 [libj9prt29.so+0x3d6a0])
21:10:28  __kernel_sigtramp_rt64+0x0 (0x00003FFFB6FA0478)
21:10:28   (0x00003FFFB5EB6F30 [libj9jit29.so+0xc46f30])
21:10:28  sidecarInvokeReflectMethodImpl+0x3c0 (0x00003FFFB664E780 [libj9vm29.so+0x1e780])
21:10:28  sidecarInvokeReflectMethod+0x38 (0x00003FFFB664FC18 [libj9vm29.so+0x1fc18])
21:10:28  JVM_InvokeMethod_Impl+0xb4 (0x00003FFFB4C91B84 [libjclse29.so+0x81b84])
21:10:28  JVM_InvokeMethod+0x40 (0x00003FFFB6BA40D0 [libjvm.so+0x240d0])
21:10:28  JVM_InvokeMethod+0x34 (0x00003FFFB6C76C04 [libjvm.so+0x6c04])
21:10:28  Java_jdk_internal_reflect_NativeMethodAccessorImpl_invoke0+0x24 (0x00003FFF8A44D174 [libjava.so+0xd174])
21:10:28   (0x00003FFF90CC3CA4 [<unknown>+0x0])
21:10:28  runJavaThread+0x340 (0x00003FFFB6649570 [libj9vm29.so+0x19570])
21:10:28  javaProtectedThreadProc+0xf0 (0x00003FFFB66E64F0 [libj9vm29.so+0xb64f0])
21:10:28  omrsig_protect+0x358 (0x00003FFFB659E848 [libj9prt29.so+0x3e848])
21:10:28  javaThreadProc+0x64 (0x00003FFFB66E1704 [libj9vm29.so+0xb1704])
21:10:28  thread_wrapper+0x1a8 (0x00003FFFB65313E8 [libj9thr29.so+0x113e8])
21:10:28  start_thread+0x104 (0x00003FFFB6F18CD4 [libpthread.so.0+0x8cd4])
21:10:28  clone+0xe4 (0x00003FFFB6DD7F14 [libc.so.6+0x127f14])
bhavanisn commented 1 year ago

There is not yet a break through still, but posting this data just to see if anything looks familiar with any crashes before.

  1. Both the crashes are at different instruction pointer, but the similar in nature that the load instruction has Null value in it. 
    
From Crash dump #1 
---------------------
0x00003fff512cefbc {UnicodeCasingTest.test} JIT [0x3ffed41ffba0]
0x00003fff512416bc {UnicodeCasingTest.test} JIT [0x3ffed4200430]
0x00003fff96d58dd0 {libj9jit29.so}{returnFromJIT0} [0x3fff4a8bac00]
0x00003fff974ee6e0 {libj9vm29.so}{sidecarInvokeReflectMethodImpl} [0x3fff4a8bb480]
0x00003fff974efb78 {libj9vm29.so}{sidecarInvokeReflectMethod} [0x3fff4a8bb5a0]
0x00003fff95b31b84 {libjclse29.so}{JVM_InvokeMethod_Impl} [0x3fff4a8bb5f0]
0x00003fff97a440d0 {libjvm.so}{JVM_InvokeMethod} [0x3fff4a8bb680]
(kca) (0x00003fff512cefbc-100)/26i
0x3fff512cef58 {UnicodeCasingTest.test} +2968                      78f2637c xor       r3, r3, r30
0x3fff512cef5c {UnicodeCasingTest.test} +2969                      94deff4b b         0x3fff512ccdf0 U>> ^+830

0x3fff512cef60 {UnicodeCasingTest.test} +2970 2d001f2c cmpwi r31, 0x2d <<< +1171 0x3fff512cef64 {UnicodeCasingTest.test} +2971 84098240 bne 0x3fff512cf8e8 C>> +3580 0x3fff512cef68 {UnicodeCasingTest.test} +2972 0100403a li r18, 1 0x3fff512cef6c {UnicodeCasingTest.test} +2973 0080003f lis r24, -0x8000 CONST 0x8000000f 0x3fff512cef70 {UnicodeCasingTest.test} +2974 0100172c cmpwi r23, 1 <<< ^+3581 0x3fff512cef74 {UnicodeCasingTest.test} +2975 a0648241 beq 0x3fff512d5414 C>> +9415 0x3fff512cef78 {UnicodeCasingTest.test} +2976 0f005838 addi r2, r24, 0xf 0x3fff512cef7c {UnicodeCasingTest.test} +2977 7026597c srawi r25, r2, 4 0x3fff512cef80 {UnicodeCasingTest.test} +2978 0000a03b li r29, 0 0x3fff512cef84 {UnicodeCasingTest.test} +2979 0100172c cmpwi r23, 1 0x3fff512cef88 {UnicodeCasingTest.test} +2980 34e48140 ble 0x3fff512cd3bc C>> ^+1201 0x3fff512cef8c {UnicodeCasingTest.test} +2981 0100603b li r27, 1 0x3fff512cef90 {UnicodeCasingTest.test} +2982 0000252c cmpdi r5, 0 <<< ^+17453 0x3fff512cef94 {UnicodeCasingTest.test} +2983 cc408241 beq 0x3fff512d3060 C>> +7130 0x3fff512cef98 {UnicodeCasingTest.test} +2984 00002528 cmpldi r5, 0 0x3fff512cef9c {UnicodeCasingTest.test} +2985 c4408241 beq 0x3fff512d3060 C>> +7130 0x3fff512cefa0 {UnicodeCasingTest.test} +2986 900a90e9 ld r12, 0xa90(r16) JITTOC 0x3fff902e0a00 J9Class - {java/lang/String} 0x3fff512cefa4 {UnicodeCasingTest.test} +2987 000045e8 ld r2, 0(r5) 0x3fff512cefa8 {UnicodeCasingTest.test} +2988 e4054278 rldicr r2, r2, 0, 0x37 0x3fff512cefac {UnicodeCasingTest.test} +2989 4060227c cmpld r2, r12 0x3fff512cefb0 {UnicodeCasingTest.test} +2990 b0408240 bne 0x3fff512d3060 C>> +7130 0x3fff512cefb4 {UnicodeCasingTest.test} +2991 00003e2c cmpdi r30, 0 0x3fff512cefb8 {UnicodeCasingTest.test} +2992 a8408241 beq 0x3fff512d3060 C>> +7130 0x3fff512cefbc {UnicodeCasingTest.test} +2993 08005a80 lwz r2, 8(r26) (kca) print $r26 %1 = 0x0000000000000000 (0)

From Crash #2

(kca) (0x00003fff911ac854-100)/26i 0x3fff911ac7f0 {UnicodeCasingTest.test} +8382 42baa578 rldicl r5, r5, 0x37, 9 0x3fff911ac7f4 {UnicodeCasingTest.test} +8383 0100c038 li r6, 1 0x3fff911ac7f8 {UnicodeCasingTest.test} +8384 ae29c27c stbx r6, r2, r5 0x3fff911ac7fc {UnicodeCasingTest.test} +8385 5020477c subf r2, r7, r4 <<< +8380 0x3fff911ac800 {UnicodeCasingTest.test} +8386 4040227c cmpld r2, r8 0x3fff911ac804 {UnicodeCasingTest.test} +8387 10008041 blt 0x3fff911ac814 C>> +8391 0x3fff911ac808 {UnicodeCasingTest.test} +8388 | f0006271 andi. r2, r11, 0xf0 0x3fff911ac80c {UnicodeCasingTest.test} +8389 | 08008240 bne 0x3fff911ac814 C>> +8391 0x3fff911ac810 {UnicodeCasingTest.test} +8390 || 111d0f48 bl 0x3fff9129e520 Trampoline {libj9jit29.so}{jitWriteBarrierStoreGenerationalAndConcurrentMark} +0
0x3fff911ac814 {UnicodeCasingTest.test} +8391 >> 00000b60 ori r11, r0, 0 <<< +8377 +8387 +8389 0x3fff911ac818 {UnicodeCasingTest.test} +8392 78aa637c xor r3, r3, r21 0x3fff911ac81c {UnicodeCasingTest.test} +8393 78aa757c xor r21, r3, r21 0x3fff911ac820 {UnicodeCasingTest.test} +8394 78aa637c xor r3, r3, r21 0x3fff911ac824 {UnicodeCasingTest.test} +8395 68f9ff4b b 0x3fff911ac18c U>> ^+7973

0x3fff911ac828 {UnicodeCasingTest.test} +8396 0000392c cmpdi r25, 0 <<< ^+17578 ^+17583 0x3fff911ac82c {UnicodeCasingTest.test} +8397 f0068241 beq 0x3fff911acf1c C>> +8841 0x3fff911ac830 {UnicodeCasingTest.test} +8398 00003928 cmpldi r25, 0 0x3fff911ac834 {UnicodeCasingTest.test} +8399 e8068241 beq 0x3fff911acf1c C>> +8841 0x3fff911ac838 {UnicodeCasingTest.test} +8400 e807d0e8 ld r6, 0x7e8(r16) JITTOC 0xbdf00 Ptr 0x3fff911ac83c {UnicodeCasingTest.test} +8401 00005980 lwz r2, 0(r25) 0x3fff911ac840 {UnicodeCasingTest.test} +8402 2e004254 rlwinm r2, r2, 0, 0, 0x17 0x3fff911ac844 {UnicodeCasingTest.test} +8403 4030227c cmpld r2, r6 0x3fff911ac848 {UnicodeCasingTest.test} +8404 d4068240 bne 0x3fff911acf1c C>> +8841 0x3fff911ac84c {UnicodeCasingTest.test} +8405 00003f2c cmpdi r31, 0 0x3fff911ac850 {UnicodeCasingTest.test} +8406 cc068241 beq 0x3fff911acf1c C>> +8841 0x3fff911ac854 {UnicodeCasingTest.test} +8407 04005780 lwz r2, 4(r23)

(kca) print $r23
%2 = 0x0000000000000000 (0)



3. Running the testcase in loop locally to reproduce the failure. No success yet.

Next: Currently I am going through on the propagation of the values in those registers. It's a big chase. Will post if I have some solid info.
bhavanisn commented 1 year ago

Out of the multiple chases on this core file, below is one of it:

Two consecutive instructions which is loading to same register r2 around the crashing instruction

Below is the snippet of instruction in the crashing area (immediately after the crashing instruction) where the r2 used in crashing instruction is used to load from r16. Traces from the jitdump on how it transformed is here. The rlwinm instruction got optimized and removed later as the result was not used in the following and it gets overwrittem by ld. But it seems like this is normal to do and way is to chase why r23 is NULL.

++++++++++++++++++++++++++++++++++++++++++++++
title="Post Stack Map"
++++++++++++++++++++++++++++++++++++++++++++++ [    0x3ffef9323e50]   171     fence   Relative[ 0d1d3820 ] (BBStart (block_3540))
 [    0x3ffef9323f40]   171     Label L14144:
 [    0x3ffef93242c0]   21      lwz     gr2, [gr23, 4]          # SymRef  <contiguous-array-size>[#305  Shadow +4] [flags 0x603 0x0 ]
 [    0x3ffef9324360]   23      rlwinm  gr2, gr2, 000000000000001F, 000000007FFFFFFF
 [    0x3ffef9324880]   3       ld      gr2, [gr16, 0]          # SymRef            0x3b06b0[#5156  final Static] [flags 0x20307 0x0 ]
 [    0x3ffef9324920]   3       ld      gr7, [gr2, 0]           # SymRef  java/lang/CharacterData00.A [I[#3485  final Static] [flags 0x20307 0x0 ]
 [    0x3ffef9324cb0]   3       cmpdi   cr0, gr7, 0
 [    0x3ffef9325210]   3       beq     cr0, Label L0739

+++++++++++++++++++++++++++++++++++++++++++++
title="Post Peephole Instructions"
+++++++++++++++++++++++++++++++++++++++++++++

 [    0x3ffef9323e50]   171     fence   Relative[ 0d1d3820 ] (BBStart (block_3540))
 [    0x3ffef9323f40]   171     Label L14144:
 [    0x3ffef93242c0]   21      lwz     gr2, [gr23, 4]          # SymRef  <contiguous-array-size>[#305  Shadow +4] [flags 0x603 0x0 ]
 [    0x3ffef9324880]   3       ld      gr2, [gr16, 0]          # SymRef            0x3b06b0[#5156  final Static] [flags 0x20307 0x0 ]
 [    0x3ffef9324920]   3       ld      gr7, [gr2, 0]           # SymRef  java/lang/CharacterData00.A [I[#3485  final Static] [flags 0x20307 0x0 ]
 [    0x3ffef9324cb0]   3       cmpdi   cr0, gr7, 0
 [    0x3ffef9325210]   3       beq     cr0, Label L0739

Mixed mode assembly
++++++++++++++++++++++++++++++++++++++++++++++
title="Mixed Mode Disassembly"
++++++++++++++++++++++++++++++++++++++++++++++

    0x3fff911c1c94 0000839c [    0x3ffef9323e50]                   171  fence   Relative[ 0d1d3820 ] (BBStart (block_3540))
    0x3fff911c1c94 0000839c [    0x3ffef9323f40]                   171  Label L14144:

 \\ UnicodeCasingTest.test(Ljava/lang/String;)V
 \\  108 JBinvokespecial 62 UnicodeCasingTest.convert(Ljava/lang/String;)Ljava/lang/String;
 \\      41 JBinvokestatic 70 java/lang/Integer.parseInt(Ljava/lang/String;I)I
 \\        184 JBinvokevirtual 62 java/lang/String.charAt(I)C
 \\             7 JBinvokevirtual 32 java/lang/String.lengthInternal()I
 \\               21 JBarraylength

    0x3fff911c1c94 0000839c [    0x3ffef93242c0] 80570004          21   lwz     gr2, [gr23, 4]          # SymRef  <contiguous-array-size>[#305  Shadow +4] [flags 0x603 0x0 ]

 \\ UnicodeCasingTest.test(Ljava/lang/String;)V
 \\  108 JBinvokespecial 62 UnicodeCasingTest.convert(Ljava/lang/String;)Ljava/lang/String;
 \\      41 JBinvokestatic 70 java/lang/Integer.parseInt(Ljava/lang/String;I)I
 \\        188 JBinvokestatic 64 java/lang/Character.digit(CI)I
 \\             2 JBinvokestatic 77 java/lang/Character.digit(II)I
 \\                6 JBinvokevirtual 78 java/lang/CharacterData.digit(II)I
 \\                  15 JBinvokevirtual 125 java/lang/CharacterData00.getProperties(I)I
 \\                      3 JBgetstatic 121 java/lang/CharacterData00.A [I

    0x3fff911c1c98 000083a0 [    0x3ffef9324880] e8503b60          3    ld      gr2, [gr16, 15200]              # SymRef            0x3b06b0[#5156  final Static] [flags 0x20307 0x0 ]
    0x3fff911c1c9c 000083a4 [    0x3ffef9324920] e8e20000          3    ld      gr7, [gr2, 0]           # SymRef  java/lang/CharacterData00.A [I[#3485  final Static] [flags 0x20307 0x0 ]
    0x3fff911c1ca0 000083a8 [    0x3ffef9324cb0] 2c270000          3    cmpdi   cr0, gr7, 0
    0x3fff911c1ca4 000083ac [    0x3ffef9325210] 40820008          3    bne     cr0, Label L28655

Chase down who loaded r23 with 0

Apparently first time r23 is loaded from stack where r0 writes 0 and in the instructions it is only r23 who writes/loads from/to location 0x390/912. Pasted below.

++++++++++++++++++++++++++++++++
    0x3fff911b9934 0000003c [    0x3ffef8c1f090] faee0068          0    std     [gr14, 104], gr23
------------------------
    0x3fff911b9958 00000060 [    0x3ffef8c1fbb0] 38000000          0    li      gr0, 0000000000000000
    0x3fff911b995c 00000064 [    0x3ffef8c1fd00] f80e0390          0    std     [gr14, 912], gr0

+++++++++++++++++++++++++++++++++
 \\ UnicodeCasingTest.test(Ljava/lang/String;)V
 \\   13 JBinvokespecial 62 UnicodeCasingTest.convert(Ljava/lang/String;)Ljava/lang/String;
 \\      22 JBistore 5

    0x3fff911b9aa4 000001ac [    0x3ffefa2d33f0] eaee0390          22   ld      gr23, [gr14, 912]               # SymRef  <temp slot 108>[#3696  Auto +912] [flags 0x7 0x0 ]

+++++++++++++++++++++++++++++++++

Loads/stores to 0x390 location:

0x3fff911a455c {UnicodeCasingTest.test} +25                       90030ef8 std       r0, 0x390(r14)
0x3fff911a46a4 {UnicodeCasingTest.test} +107                      9003eeea ld        r23, 0x390(r14)
0x3fff911a489c {UnicodeCasingTest.test} +233                   |  9003eefa std       r23, 0x390(r14)
0x3fff911a48d8 {UnicodeCasingTest.test} +248                      9003eefa std       r23, 0x390(r14)
0x3fff911a4d80 {UnicodeCasingTest.test} +546                      9003eefa std       r23, 0x390(r14)
0x3fff911a4dc0 {UnicodeCasingTest.test} +562                      9003eefa std       r23, 0x390(r14)
0x3fff911a4dfc {UnicodeCasingTest.test} +577                      9003eefa std       r23, 0x390(r14)
0x3fff911a4e34 {UnicodeCasingTest.test} +591                      9003eefa std       r23, 0x390(r14)
0x3fff911a4ef4 {UnicodeCasingTest.test} +639                 |||  9003eeea ld        r23, 0x390(r14)
0x3fff911a51f8 {UnicodeCasingTest.test} +832                   |  9003eefa std       r23, 0x390(r14)
0x3fff911a5254 {UnicodeCasingTest.test} +855                      9003eefa std       r23, 0x390(r14)
......
.......
0x3fff911a5e68 {UnicodeCasingTest.test} +1628                 | || 9003eefa std       r23, 0x390(r14)
0x3fff911a5e98 {UnicodeCasingTest.test} +1640                   || 9003eefa std       r23, 0x390(r14)
0x3fff911a5f4c {UnicodeCasingTest.test} +1685                 ||   9003eefa std       r23, 0x390(r14)
......

Next: was there a nullcheck done before accessing the arraylength obj.

zl-wang commented 1 year ago

r23 is expected to be an array object: the crashing load is trying to load the array length.

the first store to 0x390 frame offset is a stack slot initialization (for GC ... if it remained garbage, it can crash the GC) or originating from bytecode? at least, you can look into that for better understanding later.

listing all 0x390 accesses is not enough ... you need to see where else r23 value is established (either loaded into r23 or calculated into r23). hopefully, the two ld into r23 from 0x390 offset are all there establishing r23 value. then, we can assert that NULL r23 came from the first store (to 0x390). this at last can help us say what the problem is.

zl-wang commented 1 year ago

if you can look back up to way earlier trees (ILs), i believed you can see the NULLChk which must have been optimized out. which optimization removed it? that can point to the problem too.

vij-singh commented 1 year ago

@bhavanisn @zl-wang Any new news on this issue?

zl-wang commented 1 year ago

it is not re-producible (in 300 runs of grinder) … only investigating based on the core file. i think it is justified to defer it to 0.41.

bhavanisn commented 1 year ago

As the trace file and instructions is pretty big to analyze it would take time. It seems like we might be missing to set the initial value to gr23 (which holds the java/lang/String type) to the slack slot 0x390. In the instructions it is seen only to initilized to 0.

Place where jitcompilation logs are stored: https://ibm.ent.box.com/folder/156227182992?s=bgvcgcc6l05qddfar5hmcviq2tj9kdw5

bhavanisn commented 1 year ago

Small update on investigation: The crashing instruction is basically loading from a global register which looks initialized to NULL. Tracing back a to the IL that initialized the register which loads from temp slot and the initialization of temp slot, at the point of optimization called “general store syncing”, the store to the temp slot optimized to treetop and hence left the global register uninitialized to a proper value.

Below is the related IL:

Crashing global register (gr23) initialization is loading from temp slot 108:

n94182n  (  4)        ==>aRegLoad (in &GPR_    0x3ffef931efa0) (SeenRealReference )

 n94182n  (  8)      aRegLoad gr23   <temp slot 108>[#3696  Auto] [flags 0x7 0x0 ] (in &GPR_    0x3ffef931efa0) (SeenRealReference )  [    0x3ffeffffeec0] bci=[205,18,2290] rc=8 vc=9 vn=- li=3536 udi=61344 nc=0 flg=0x8000

Temp slot 108 Initialization:

n93429n  (  0)  astore  <temp slot 108>[#3696  Auto] [flags 0x7 0x0 ]                                [    0x3ffeffff0370] bci=[68,1,1691] rc=0 vc=9 vn=- li=550 udi=- nc=1
 n93417n  (  0)    ==>aRegLoad (in &GPR_    0x3ffef9244d50)
n59121n   BBStart <block_3538> (freq 1750)                                                    [    0x3fff0d1a1f90] bci=[199,171,647] rc=0 vc=1024 vn=- li=- udi=- nc=0
n59063n   astore  <temp slot 108>[#3696  Auto] [flags 0x7 0x0 ]                               [    0x3fff0d1a0d70] bci=[205,18,2290] rc=0 vc=1024 vn=- li=- udi=- nc=1
n59062n     aloadi  java/lang/String.value [B[#1579  final Shadow +4] [flags 0x400a0607 0x0 ]  [    0x3fff0d1a0d20] bci=[205,18,2290] rc=1 vc=1024 vn=- li=- udi=- nc=1
n59061n       aload  <auto slot 6>[#2685  Auto] [flags 0x7 0x0 ]                              [    0x3fff0d1a0cd0] bci=[204,6,1319] rc=1 vc=1024 vn=- li=- udi=- nc=0
n59122n   BBEnd </block_3538> =====

After generalStoreSyncing:

n59121n   BBStart <block_3538> (freq 604) (extension of previous block) (cold)                [    0x3fff0d1a1f90] bci=[199,171,647] rc=0 vc=3206 vn=- li=- udi=- nc=0
n59063n   **treetop**                                                                             [    0x3fff0d1a0d70] bci=[205,18,2290] rc=0 vc=6350 vn=- li=- udi=247 nc=1
n59062n     aload  <temp slot 142>[#3730  Auto] [flags 0x7 0x0 ] (createdByPRE )              [    0x3fff0d1a0d20] bci=[205,18,2290] rc=2 vc=6350 vn=- li=- udi=202 nc=0 flg=0x40000
n59066n   ifacmpeq --> block_3530 BBStart at n59028n ()                                       [    0x3fff0d1a0e60] bci=[205,18,2290] rc=0 vc=6349 vn=- li=- udi=- nc=2 flg=0x20
n59062n     ==>aload
n59065n     aconst NULL (X==0 X>=0 X<=0 )                                                     [    0x3fff0d1a0e10] bci=[205,21,2290] rc=1 vc=6349 vn=- li=- udi=- nc=0 flg=0x302
n59117n   BBEnd </block_3538> (cold)

At this point the load from temp slot 108(#3696) is still valid in the block 3540(which is where the crashing load instruction is) next to it :

n59114n   BBStart <block_3540> (freq 604) (extension of previous block) (cold) (in loop 1837)  [    0x3fff0d1a1d60] bci=[199,171,647] rc=0 vc=3202 vn=- li=- udi=- nc=0
n59071n   istore  <temp slot 109>[#3697  Auto] [flags 0x3 0x0 ]                               [    0x3fff0d1a0ff0] bci=[205,23,2290] rc=0 vc=3202 vn=- li=- udi=248 nc=1
n59070n     iushr (X>=0 cannotOverflow )                                                      [    0x3fff0d1a0fa0] bci=[205,23,2290] rc=1 vc=3202 vn=- li=- udi=- nc=2 flg=0x1100
n59068n       arraylength (X>=0 cannotOverflow )                                              [    0x3fff0d1a0f00] bci=[205,21,2290] rc=1 vc=3202 vn=- li=- udi=- nc=1 flg=0x1100
n59067n         **aload  <temp slot 108>[#3696  Auto] [flags 0x7 0x0 ]**                          [    0x3fff0d1a0eb0] bci=[205,18,2290] rc=1 vc=3202 vn=- li=- udi=203 nc=0
n59069n       iconst 1 (X!=0 X>=0 )                                                           [    0x3fff0d1a0f50] bci=[205,22,2290] rc=1 vc=3202 vn=- li=- udi=- nc=0 flg=0x104
n59073n   astore  <temp slot 110>[#3698  Auto] [flags 0x7 0x0 ]                               [    0x3fff0d1a1090] bci=[345,3,73] rc=0 vc=3202 vn=- li=- udi=249 nc=1
n59072n     aload  java/lang/CharacterData00.A [I[#3485  final Static] [flags 0x20307 0x0 ]   [    0x3fff0d1a1040] bci=[345,3,73] rc=2 vc=3202 vn=- li=- udi=- nc=0
n59076n   ifacmpeq --> block_3530 BBStart at n59028n ()                                       [    0x3fff0d1a1180] bci=[345,3,73] rc=0 vc=3202 vn=- li=- udi=- nc=2 flg=0x20
n59072n     ==>aload
n59075n     aconst NULL (X==0 X>=0 X<=0 )                                                     [    0x3fff0d1a1130] bci=[205,21,2290] rc=1 vc=3202 vn=- li=- udi=- nc=0 flg=0x302
n59108n   BBEnd </block_3540> (cold)

Talking to optimizer team (@hzongaro ) to further investigate for which trace file withtraceGeneralStoreSinking enabled will be useful. But as this is not a reproducible issue not able to get the required trace.

While running tests and in case this test fails, if we can enable to collect the trace with this option will be useful. Is there a way to do that ?

traceFull for the testcase for a good run is available in here(https://ibm.ent.box.com/file/1256829270665). The instructions generated looks different when compared to the failing case but initial bc and trees are same.

bhavanisn commented 1 year ago

As we do not have enough information to debug and it is not reproducible locally or on grinder, can we close this and re-open if it reoccurs ?

pshipton commented 7 months ago

https://hyc-runtimes-jenkins.swg-devops.com/job/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_testList_2/29 - p10rhel005 jdk_lang_j9_0 java/lang/String/UnicodeCasingTest.java

https://na.artifactory.swg-devops.com/artifactory/sys-rt-generic-local/hyc-runtimes-jenkins.swg-devops.com/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_testList_2/29/openjdk_test_output.tar.gz

18:47:52  Testing on os_GE localstderr:
18:47:52  Unhandled exception
18:47:52  Type=Segmentation error vmState=0x00000000
18:47:52  J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
18:47:52  Handler1=00007FFF98C4F5C0 Handler2=00007FFF98B79700
18:47:52  R0=0000000000000005 R1=00007FFF506FABB0 R2=0000000000000000 R3=0000000000000000
18:47:52  R4=0000000000000000 R5=0000000000000001 R6=0000000000000001 R7=0000000000000001
18:47:52  R8=00007FFF79A01220 R9=0000000000000001 R10=0000000000000000 R11=00007FFEA02932F8
18:47:52  R12=0000000000000020 R13=00007FFF507068E0 R14=00007FFEA0296BB0 R15=00007FFF944A1100
18:47:52  R16=00007FFF79A00F00 R17=00007FFF79A00E38 R18=00007FFF764BC1E8 R19=0000000000000000
18:47:52  R20=00007FFF79A01108 R21=00007FFF79A01108 R22=00007FFF764954B0 R23=00000000F8000001
18:47:52  R24=FFFFFFFF80000001 R25=0000000000000005 R26=0000000000000010 R27=00007FFF74123860
18:47:52  R28=0000000000000000 R29=0000000000000000 R30=00007FFF79A00F18 R31=00007FFF79A01220
18:47:52  NIP=00007FFF58D89E14 MSR=800000000280F033 ORIG_GPR3=00007FFF58D89E08 CTR=00007FFF58D86F00
18:47:52  LINK=00007FFF58D555B4 XER=0000000000000000 CCR=0000000044084884 SOFTE=0000000000000001
18:47:52  TRAP=0000000000000300 DAR=0000000000000008 dsisr=0000000040000000 RESULT=0000000000000000
18:47:52  FPR0 000000000001fff8 (f: 131064.000000, d: 6.475422e-319)
18:47:52  FPR1 4051a9fbe0000000 (f: 3758096384.000000, d: 7.065600e+01)
18:47:52  FPR2 3fefeaf0645072e3 (f: 1682993920.000000, d: 9.974291e-01)
18:47:52  FPR3 4020000000000000 (f: 0.000000, d: 8.000000e+00)
18:47:52  FPR4 3fce840b4ac4e4d2 (f: 1254417664.000000, d: 2.384047e-01)
18:47:52  FPR5 bfe7154748bef6c8 (f: 1220474624.000000, d: -7.213475e-01)
18:47:52  FPR6 3fe62e42fefa39ef (f: 4277811712.000000, d: 6.931472e-01)
18:47:52  FPR7 bfd2bef0a7c06ddb (f: 2814406144.000000, d: -2.929041e-01)
18:47:52  FPR8 bfdffffef20a4123 (f: 4060758272.000000, d: -4.999997e-01)
18:47:52  FPR9 bfd00ea348b88334 (f: 1220051712.000000, d: -2.508934e-01)
18:47:52  FPR10 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR11 3efcbe56d7cc347f (f: 3620484096.000000, d: 2.741195e-05)
18:47:52  FPR12 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR13 4020800000000000 (f: 0.000000, d: 8.250000e+00)
18:47:52  FPR14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR16 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR17 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR18 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR19 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR20 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR21 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR22 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR23 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR24 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR25 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR26 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR27 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR28 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR29 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR30 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  FPR31 0000000000000000 (f: 0.000000, d: 0.000000e+00)
18:47:52  
18:47:52  Compiled_method=java/lang/Integer.parseInt(Ljava/lang/String;I)I
18:47:52  Target=2_90_20240131_874 (Linux 4.18.0-513.11.1.el8_9.ppc64le)
18:47:52  CPU=ppc64le (24 logical CPUs) (0x1ef26a0000 RAM)
18:47:52  ----------- Stack Backtrace -----------
18:47:52   (0x00007FFF58D89E14 [<unknown>+0x0])
18:47:52  sidecarInvokeReflectMethodImpl+0x508 (0x00007FFF98C2AA58 [libj9vm29.so+0x1aa58])
18:47:52  sidecarInvokeReflectMethod+0x3c (0x00007FFF98C2B9AC [libj9vm29.so+0x1b9ac])
18:47:52  JVM_InvokeMethod_Impl+0xa8 (0x00007FFF92E7B3B8 [libjclse29.so+0x7b3b8])
18:47:52  JVM_InvokeMethod+0x3c (0x00007FFF992D365C [libjvm.so+0x2365c])
18:47:52  JVM_InvokeMethod+0x30 (0x00007FFF993B7410 [libjvm.so+0x7410])
18:47:52  Java_jdk_internal_reflect_NativeMethodAccessorImpl_invoke0+0x24 (0x00007FFF5240E044 [libjava.so+0xe044])
18:47:52   (0x00007FFF5883AB2C [<unknown>+0x0])
18:47:52  runJavaThread+0x240 (0x00007FFF98C270B0 [libj9vm29.so+0x170b0])
18:47:52  javaProtectedThreadProc+0x148 (0x00007FFF98CBE3B8 [libj9vm29.so+0xae3b8])
18:47:52  omrsig_protect+0x3e4 (0x00007FFF98B7ABB4 [libj9prt29.so+0x3abb4])
18:47:52  javaThreadProc+0x60 (0x00007FFF98CB9CE0 [libj9vm29.so+0xa9ce0])
18:47:52  thread_wrapper+0x190 (0x00007FFF98B0D820 [libj9thr29.so+0xd820])
18:47:52  start_thread+0xf8 (0x00007FFF99679678 [libpthread-2.28.so+0x9678])
18:47:52  clone+0x74 (0x00007FFF99528938 [libc-2.28.so+0x138938])
18:47:52  ---------------------------------------
pshipton commented 7 months ago

Reopening as there is another crash, although it's a bit different.

JasonFengJ9 commented 3 months ago

JDK11 pc64le_linux(rhel8le-svl-rt8-1)

[2024-05-27T23:55:28.228Z] variation: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage Mode501
[2024-05-27T23:55:28.228Z] JVM_OPTIONS:  -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage -Xjit -Xgcpolicy:balanced -Xnocompressedrefs -Xverbosegclog 

[2024-05-27T23:58:51.106Z] TEST: java/lang/Character/UnicodeCasingTest.java

[2024-05-27T23:58:51.107Z] stderr:
[2024-05-27T23:58:51.107Z] Unhandled exception
[2024-05-27T23:58:51.107Z] Type=Segmentation error vmState=0x00000000
[2024-05-27T23:58:51.107Z] J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
[2024-05-27T23:58:51.107Z] Handler1=00007FFFB053FC20 Handler2=00007FFFB04697C0
[2024-05-27T23:58:51.107Z] R0=0000000000000000 R1=00007FFF393FABB0 R2=0000000000000000 R3=00007FFF8DA71570
[2024-05-27T23:58:51.107Z] R4=0000000000000000 R5=0000003FFFC6D38B R6=0000000000000001 R7=00007FFF8DA716C0
[2024-05-27T23:58:51.107Z] R8=00007FFF8A680000 R9=0000000000000001 R10=0000000000000000 R11=00007FFF082BBAC0
[2024-05-27T23:58:51.107Z] R12=00007FFFAAAF29F0 R13=00007FFF394068E0 R14=00007FFF082BF690 R15=00007FFF0820F800
[2024-05-27T23:58:51.107Z] R16=00007FFF69A70038 R17=FFFFFFFFFFFFFFFF R18=0000000000000000 R19=0000000000000000
[2024-05-27T23:58:51.107Z] R20=0000000000000000 R21=00007FFF8AB841D0 R22=00007FFF8C73FFD8 R23=00000000F8000001
[2024-05-27T23:58:51.107Z] R24=FFFFFFFF80000001 R25=0000000000000005 R26=0000000000000010 R27=00007FFF8B99CD60
[2024-05-27T23:58:51.107Z] R28=0000000000000000 R29=0000000000000000 R30=00007FFF8DA39E58 R31=00007FFF8DA716D8
[2024-05-27T23:58:51.107Z] NIP=00007FFF7060E1A0 MSR=800000000280F033 ORIG_GPR3=00007FFF70607260 CTR=00007FFF7060B480
[2024-05-27T23:58:51.107Z] LINK=00007FFF705E03F8 XER=0000000000000000 CCR=0000000042884A44 SOFTE=0000000000000001
[2024-05-27T23:58:51.107Z] TRAP=0000000000000300 DAR=0000000000000008 dsisr=0000000040000000 RESULT=0000000000000000
[2024-05-27T23:58:51.107Z] FPR0=000000000001ffd0 (f: 131024.000000, d: 6.473446e-319)
[2024-05-27T23:58:51.107Z] FPR1=4050285700000000 (f: 0.000000, d: 6.463031e+01)
[2024-05-27T23:58:51.107Z] FPR2=414e41474941544e (f: 1229018240.000000, d: 3.965583e+06)
[2024-05-27T23:58:51.107Z] FPR3=45483b3844304231 (f: 1144013312.000000, d: 5.858775e+25)
[2024-05-27T23:58:51.107Z] FPR4=3fce840b4ac4e4d2 (f: 1254417664.000000, d: 2.384047e-01)
[2024-05-27T23:58:51.107Z] FPR5=bfe7154748bef6c8 (f: 1220474624.000000, d: -7.213475e-01)
[2024-05-27T23:58:51.107Z] FPR6=3fe62e42fefa39ef (f: 4277811712.000000, d: 6.931472e-01)
[2024-05-27T23:58:51.107Z] FPR7=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR8=3f2686c6c0000000 (f: 3221225472.000000, d: 1.718633e-04)
[2024-05-27T23:58:51.107Z] FPR9=205954494c494249 (f: 1279869568.000000, d: 7.556565e-153)
[2024-05-27T23:58:51.107Z] FPR10=504152474f454449 (f: 1329939584.000000, d: 4.011362e+78)
[2024-05-27T23:58:51.107Z] FPR11=40c645a900000000 (f: 0.000000, d: 1.140332e+04)
[2024-05-27T23:58:51.107Z] FPR12=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR13=0000000071b95b42 (f: 1907972992.000000, d: 9.426639e-315)
[2024-05-27T23:58:51.107Z] FPR14=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR15=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR16=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR17=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR18=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR19=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR20=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR21=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR22=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR23=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR24=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR25=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR26=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR27=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR28=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR29=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR30=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] FPR31=0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2024-05-27T23:58:51.107Z] 
[2024-05-27T23:58:51.107Z] Compiled_method=java/lang/Integer.parseInt(Ljava/lang/String;I)I
[2024-05-27T23:58:51.107Z] Target=2_90_20240527_862 (Linux 4.18.0-513.24.1.el8_9.ppc64le)
[2024-05-27T23:58:51.107Z] CPU=ppc64le (4 logical CPUs) (0x1dcc60000 RAM)
[2024-05-27T23:58:51.107Z] ----------- Stack Backtrace -----------
[2024-05-27T23:58:51.107Z]  (0x00007FFF7060E1A0 [<unknown>+0x0])
[2024-05-27T23:58:51.107Z] sidecarInvokeReflectMethodImpl+0x508 (0x00007FFFB051AED8 [libj9vm29.so+0x1aed8])
[2024-05-27T23:58:51.107Z] sidecarInvokeReflectMethod+0x3c (0x00007FFFB051BE2C [libj9vm29.so+0x1be2c])
[2024-05-27T23:58:51.107Z] JVM_InvokeMethod_Impl+0xa8 (0x00007FFFAA74BA38 [libjclse29.so+0x7ba38])
[2024-05-27T23:58:51.107Z] JVM_InvokeMethod+0x3c (0x00007FFFB0BE368C [libjvm.so+0x2368c])
[2024-05-27T23:58:51.107Z] JVM_InvokeMethod+0x30 (0x00007FFFB0CC7310 [libjvm.so+0x7310])
[2024-05-27T23:58:51.107Z] Java_jdk_internal_reflect_NativeMethodAccessorImpl_invoke0+0x24 (0x00007FFF696CDDC4 [libjava.so+0xddc4])
[2024-05-27T23:58:51.107Z]  (0x00007FFF701D2B20 [<unknown>+0x0])
[2024-05-27T23:58:51.107Z] runJavaThread+0x240 (0x00007FFFB0517530 [libj9vm29.so+0x17530])
[2024-05-27T23:58:51.107Z] javaProtectedThreadProc+0x148 (0x00007FFFB05AEDB8 [libj9vm29.so+0xaedb8])
[2024-05-27T23:58:51.107Z] omrsig_protect+0x3e4 (0x00007FFFB046AC74 [libj9prt29.so+0x3ac74])
[2024-05-27T23:58:51.107Z] javaThreadProc+0x60 (0x00007FFFB05AA480 [libj9vm29.so+0xaa480])
[2024-05-27T23:58:51.107Z] thread_wrapper+0x190 (0x00007FFFB03FD820 [libj9thr29.so+0xd820])
[2024-05-27T23:58:51.107Z] start_thread+0xf8 (0x00007FFFB0F99718 [libpthread.so.0+0x9718])
[2024-05-27T23:58:51.107Z] clone+0x74 (0x00007FFFB0E3B798 [libc.so.6+0x13b798])
[2024-05-27T23:58:51.107Z] ---------------------------------------
[2024-05-27T23:58:51.107Z] JVMDUMP039I Processing dump event "gpf", detail "" at 2024/05/27 16:57:19 - please wait.

[2024-05-28T00:22:54.877Z] jdk_lang_j9_0_FAILED

50x grinder - 7/50 failures reproduced

pshipton commented 3 months ago

@hzongaro 7/50 seems high so I've added this to the 0.46 milestone, but pls move it out if necessary.

hzongaro commented 3 months ago

Looking at part of one of the jitdump files from the recent grinder runs, I see what looks to be the same problem as @bhavanisn described earlier. Before General Store Sinking, block_2533 contains a store to #2731 that is referenced in block_2531. The store in block_2533 is the only store to #2731 on the path from the entry to the method to block_2536.

n39603n   BBStart <block_2533> (freq 1341) (extension of previous block) (cold) (in loop 19)  [    0x7ffecb7e4ab0] bci=[-1,173,648] rc=0 vc=10588 vn=- li=- udi=- nc=0        
  ...
n39566n   astore  <temp slot 354>[#2731  Auto] [flags 0x7 0x0 ]                               [    0x7ffecb7e3f20] bci=[117,7,2287] rc=0 vc=10588 vn=- li=- udi=- nc=1         
n39565n     aload  <temp slot 357>[#2734  Auto] [flags 0x7 0x0 ] (createdByPRE )              [    0x7ffecb7e3ed0] bci=[117,7,2287] rc=2 vc=10588 vn=- li=- udi=- nc=0 flg=0x40000     
n39569n   ifacmpeq --> block_2523 BBStart at n39506n ()                                       [    0x7ffecb7e4010] bci=[117,7,2287] rc=0 vc=10588 vn=- li=- udi=- nc=2 flg=0x20
n39565n     ==>aload         
n39568n     aconst NULL (X==0 )                                                               [    0x7ffecb7e3fc0] bci=[116,19,1320] rc=1 vc=10588 vn=- li=- udi=- nc=0 flg=0x2
n39597n   BBEnd </block_2533> (cold) 

n39594n   BBStart <block_2536> (freq 1341) (extension of previous block) (cold) (in loop 19)  [    0x7ffecb7e47e0] bci=[-1,173,648] rc=0 vc=10588 vn=- li=- udi=- nc=0         
n39574n   istore  <temp slot 355>[#2732  Auto] [flags 0x3 0x0 ]                               [    0x7ffecb7e41a0] bci=[117,15,2287] rc=0 vc=10588 vn=- li=- udi=- nc=1
n39573n     iushr (normalizedShift )                                                          [    0x7ffecb7e4150] bci=[117,15,2287] rc=1 vc=10588 vn=- li=- udi=- nc=2 flg=0x8000
n39571n       arraylength (X>=0 cannotOverflow )                                              [    0x7ffecb7e40b0] bci=[117,10,2287] rc=1 vc=10588 vn=- li=- udi=- nc=1 flg=0x1100
n39570n         aload  <temp slot 354>[#2731  Auto] [flags 0x7 0x0 ]                          [    0x7ffecb7e4060] bci=[117,7,2287] rc=1 vc=10588 vn=- li=- udi=- nc=0
n39572n       iload  <temp slot 353>[#2730  Auto] [flags 0x3 0x0 ] (cannotOverflow )          [    0x7ffecb7e4100] bci=[117,12,2287] rc=1 vc=10588 vn=- li=- udi=- nc=0 flg=0x1000
   ...

After General Store Sinking, that store has been removed:

n39603n   BBStart <block_2533> (freq 1341) (extension of previous block) (cold)               [    0x7ffecb7e4ab0] bci=[-1,173,648] rc=0 vc=3 vn=- li=- udi=- nc=0 
n39566n   treetop                                                                             [    0x7ffecb7e3f20] bci=[117,7,2287] rc=0 vc=1655 vn=- li=- udi=- nc=1
n39565n     aload  <temp slot 357>[#2734  Auto] [flags 0x7 0x0 ] (createdByPRE )              [    0x7ffecb7e3ed0] bci=[117,7,2287] rc=2 vc=1655 vn=- li=- udi=- nc=0 flg=0x40000
n39569n   ifacmpeq --> block_2523 BBStart at n39506n ()                                       [    0x7ffecb7e4010] bci=[117,7,2287] rc=0 vc=1654 vn=- li=- udi=- nc=2 flg=0x20
n39565n     ==>aload
n39568n     aconst NULL (X==0 )                                                               [    0x7ffecb7e3fc0] bci=[116,19,1320] rc=1 vc=1654 vn=- li=- udi=- nc=0 flg=0x2
n39597n   BBEnd </block_2533> (cold)                                                          [    0x7ffecb7e48d0] bci=[-1,173,648] rc=0 vc=3 vn=- li=- udi=- nc=0 
n39594n   BBStart <block_2536> (freq 1341) (extension of previous block) (cold)               [    0x7ffecb7e47e0] bci=[-1,173,648] rc=0 vc=3 vn=- li=- udi=- nc=0
n39574n   treetop                                                                             [    0x7ffecb7e41a0] bci=[117,15,2287] rc=0 vc=1653 vn=- li=- udi=- nc=1
n39573n     iushr (normalizedShift )                                                          [    0x7ffecb7e4150] bci=[117,15,2287] rc=1 vc=1653 vn=- li=- udi=- nc=2 flg=0x8000
n39571n       arraylength (X>=0 cannotOverflow )                                              [    0x7ffecb7e40b0] bci=[117,10,2287] rc=1 vc=1653 vn=- li=- udi=- nc=1 flg=0x1100                                                              
n39570n         aload  <temp slot 354>[#2731  Auto] [flags 0x7 0x0 ]                          [    0x7ffecb7e4060] bci=[117,7,2287] rc=1 vc=1653 vn=- li=- udi=- nc=0

I'll try to gather more logs with additional tracing of General Store Sinking enabled.

hzongaro commented 3 months ago

Having trouble reproducing the failure with tracing of General Store Sinking enabled for java/lang/Integer.parseInt. Trying again, and if that fails, I'll try to enable that further tracing in the jitdump code.

hzongaro commented 3 months ago

No luck reproducing the failure with traceGeneralStoreSinking. I will try forcing that to be enabled in the jitdump code, as I mentioned previously.

In the meanwhile, a fix won't make it into the 0.46 release, so I will move this out to 0.48.

hzongaro commented 3 months ago

I forced traceGeneralStoreSinking to be true in a jitdump, and I was able to gather more information from that trace:

Before General Store Sinking:

n54034n   BBStart <block_3678> (freq 1297) (extension of previous block) (cold) (in loop 3675)  [    0x7ffeef6ae970] bci=[-1,173,648] rc=0 vc=14868 vn=- li=- udi=- nc=0
n53992n   istore  <temp slot 352>[#3462  Auto] [flags 0x3 0x0 ]                               [    0x7ffeef6adc50] bci=[165,12,2292] rc=0 vc=14868 vn=- li=- udi=- nc=1
n53991n     iand (X>=0 cannotOverflow )                                                       [    0x7ffeef6adc00] bci=[165,12,2292] rc=1 vc=14868 vn=- li=- udi=- nc=2 flg=0x1100
n53989n       iload  <temp slot 351>[#3461  Auto] [flags 0x3 0x0 ] (cannotOverflow )          [    0x7ffeef6adb60] bci=[164,27,1325] rc=1 vc=14868 vn=- li=- udi=- nc=0 flg=0x1000
n53990n       iconst 31 (X!=0 X>=0 )                                                          [    0x7ffeef6adbb0] bci=[165,12,2292] rc=1 vc=14868 vn=- li=- udi=- nc=0 flg=0x104
n53995n   astore  <temp slot 353>[#3463  Auto] [flags 0x7 0x0 ]                               [    0x7ffeef6add40] bci=[165,7,2292] rc=0 vc=14868 vn=- li=- udi=- nc=1
n53994n     aload  <temp slot 386>[#3496  Auto] [flags 0x7 0x0 ] (createdByPRE )              [    0x7ffeef6adcf0] bci=[165,7,2292] rc=2 vc=14868 vn=- li=- udi=- nc=0 flg=0x40000
n53998n   ifacmpeq --> block_3671 BBStart at n53946n ()                                       [    0x7ffeef6ade30] bci=[165,7,2292] rc=0 vc=14868 vn=- li=- udi=- nc=2 flg=0x20
n53994n     ==>aload
n53997n     aconst NULL (X==0 X>=0 X<=0 )                                                     [    0x7ffeef6adde0] bci=[164,27,1325] rc=1 vc=14868 vn=- li=- udi=- nc=0 flg=0x302
n54028n   BBEnd </block_3678> (cold)                                                          [    0x7ffeef6ae790] bci=[-1,173,648] rc=0 vc=14868 vn=- li=- udi=- nc=0

n54025n   BBStart <block_3681> (freq 1297) (extension of previous block) (cold) (in loop 3675)  [    0x7ffeef6ae6a0] bci=[-1,173,648] rc=0 vc=14868 vn=- li=- udi=- nc=0
n54003n   istore  <temp slot 354>[#3464  Auto] [flags 0x3 0x0 ]                               [    0x7ffeef6adfc0] bci=[165,15,2292] rc=0 vc=14868 vn=- li=- udi=- nc=1
n54002n     iushr (normalizedShift )                                                          [    0x7ffeef6adf70] bci=[165,15,2292] rc=1 vc=14868 vn=- li=- udi=- nc=2 flg=0x8000
n54000n       arraylength (X>=0 cannotOverflow )                                              [    0x7ffeef6aded0] bci=[165,10,2292] rc=1 vc=14868 vn=- li=- udi=- nc=1 flg=0x1100
n53999n         aload  <temp slot 353>[#3463  Auto] [flags 0x7 0x0 ]                          [    0x7ffeef6ade80] bci=[165,7,2292] rc=1 vc=14868 vn=- li=- udi=- nc=0
n54001n       iload  <temp slot 352>[#3462  Auto] [flags 0x3 0x0 ] (cannotOverflow )          [    0x7ffeef6adf20] bci=[165,12,2292] rc=1 vc=14868 vn=- li=- udi=- nc=0 flg=0x1000
n54005n   astore  <temp slot 355>[#3465  Auto] [flags 0x7 0x0 ]                               [    0x7ffeef6ae060] bci=[169,0,210] rc=0 vc=14868 vn=- li=- udi=- nc=1
n54004n     aload  java/lang/CharacterDataLatin1.DIGITS [B[#2205  final Static] [flags 0xa0307 0x0 ]  [    0x7ffeef6ae010] bci=[169,0,210] rc=2 vc=14868 vn=- li=- udi=- nc=0
n54008n   ifacmpeq --> block_3671 BBStart at n53946n ()                                       [    0x7ffeef6ae150] bci=[169,0,210] rc=0 vc=14868 vn=- li=- udi=- nc=2 flg=0x20
n54004n     ==>aload
n54007n     aconst NULL (X==0 X>=0 X<=0 )                                                     [    0x7ffeef6ae100] bci=[164,27,1325] rc=1 vc=14868 vn=- li=- udi=- nc=0 flg=0x302
n54022n   BBEnd </block_3681> (cold)                                                          [    0x7ffeef6ae5b0] bci=[-1,173,648] rc=0 vc=14868 vn=- li=- udi=- nc=0

After General Store Sinking:

n54034n   BBStart <block_3678> (freq 1297) (extension of previous block) (cold)               [    0x7ffeef6ae970] bci=[-1,173,648] rc=0 vc=3 vn=- li=- udi=- nc=0
n53998n   ifacmpeq --> block_3671 BBStart at n53946n ()                                       [    0x7ffeef6ade30] bci=[165,7,2292] rc=0 vc=2603 vn=- li=- udi=- nc=2 flg=0x20
n53994n     aload  <temp slot 386>[#3496  Auto] [flags 0x7 0x0 ] (createdByPRE )              [    0x7ffeef6adcf0] bci=[165,7,2292] rc=2 vc=2604 vn=- li=- udi=- nc=0 flg=0x40000
n53997n     aconst NULL (X==0 X>=0 X<=0 )                                                     [    0x7ffeef6adde0] bci=[164,27,1325] rc=1 vc=2603 vn=- li=- udi=- nc=0 flg=0x302
n54028n   BBEnd </block_3678> (cold)                                                          [    0x7ffeef6ae790] bci=[-1,173,648] rc=0 vc=3 vn=- li=- udi=- nc=0
n54025n   BBStart <block_3681> (freq 1297) (extension of previous block) (cold)               [    0x7ffeef6ae6a0] bci=[-1,173,648] rc=0 vc=3 vn=- li=- udi=- nc=0
n54003n   treetop                                                                             [    0x7ffeef6adfc0] bci=[165,15,2292] rc=0 vc=2602 vn=- li=- udi=- nc=1
n54002n     iushr (normalizedShift )                                                          [    0x7ffeef6adf70] bci=[165,15,2292] rc=1 vc=2602 vn=- li=- udi=- nc=2 flg=0x8000
n54000n       arraylength (X>=0 cannotOverflow )                                              [    0x7ffeef6aded0] bci=[165,10,2292] rc=1 vc=2602 vn=- li=- udi=- nc=1 flg=0x1100
n53999n         aload  <temp slot 353>[#3463  Auto] [flags 0x7 0x0 ]                          [    0x7ffeef6ade80] bci=[165,7,2292] rc=1 vc=2602 vn=- li=- udi=- nc=0
n54001n       iload  <temp slot 352>[#3462  Auto] [flags 0x3 0x0 ] (cannotOverflow )          [    0x7ffeef6adf20] bci=[165,12,2292] rc=1 vc=2602 vn=- li=- udi=- nc=0 flg=0x1000
n54005n   astore  <temp slot 355>[#3465  Auto] [flags 0x7 0x0 ]                               [    0x7ffeef6ae060] bci=[169,0,210] rc=0 vc=2601 vn=- li=- udi=- nc=1
n54004n     aload  java/lang/CharacterDataLatin1.DIGITS [B[#2205  final Static] [flags 0xa0307 0x0 ]  [    0x7ffeef6ae010] bci=[169,0,210] rc=2 vc=2601 vn=- li=- udi=- nc=0
n54008n   ifacmpeq --> block_3671 BBStart at n53946n ()                                       [    0x7ffeef6ae150] bci=[169,0,210] rc=0 vc=2600 vn=- li=- udi=- nc=2 flg=0x20
n54004n     ==>aload
n54007n     aconst NULL (X==0 X>=0 X<=0 )                                                     [    0x7ffeef6ae100] bci=[164,27,1325] rc=1 vc=2600 vn=- li=- udi=- nc=0 flg=0x302
n54022n   BBEnd </block_3681> (cold)                                                          [    0x7ffeef6ae5b0] bci=[-1,173,648] rc=0 vc=3 vn=- li=- udi=- nc=0
n216n     BBStart <block_19> (freq 1297) (extension of previous block) (cold)                 [    0x7fff48153340] bci=[-1,0,613] rc=0 vc=3 vn=- li=- udi=- nc=0
n41729n   asynccheck  jitCheckAsyncMessages[#23  helper Method] [flags 0x400 0x0 ]            [    0x7ffef51ae330] bci=[164,2,1323] rc=0 vc=2597 vn=- li=- udi=- nc=0
n54247n   ificmpne --> block_4232 BBStart at n71335n (OSRGuard/DummyTest )                    [    0x7ffeef772c10] bci=[-1,0,613] rc=0 vc=2596 vn=- li=- udi=- nc=2 flg=0x1028
54248n     iload  unknown static[#2975  Static] [flags 0x10303 0x0 ] (cannotOverflow )       [    0x7ffeef772c60] bci=[-1,238,659] rc=1 vc=2596 vn=- li=- udi=- nc=0 flg=0x1008
n54249n     iconst 0 (X==0 X>=0 X<=0 )                                                        [    0x7ffeef772cb0] bci=[-1,238,659] rc=1 vc=2596 vn=- li=- udi=- nc=0 flg=0x302
n54264n   BBEnd </block_19> (cold)                                                            [    0x7ffeef773160] bci=[-1,173,648] rc=0 vc=3 vn=- li=- udi=- nc=0
n71319n   BBStart <block_4229> (freq 1297) (extension of previous block) (cold)               [    0x7ffee5cd0460] bci=[-1,173,648] rc=0 vc=0 vn=- li=- udi=- nc=0
n53992n   istore  <temp slot 352>[#3462  Auto] [flags 0x3 0x0 ]                               [    0x7ffeef6adc50] bci=[165,12,2292] rc=0 vc=2605 vn=- li=- udi=- nc=1
n53991n     iand (X>=0 cannotOverflow )                                                       [    0x7ffeef6adc00] bci=[165,12,2292] rc=1 vc=2605 vn=- li=- udi=- nc=2 flg=0x1100
n53989n       iload  <temp slot 351>[#3461  Auto] [flags 0x3 0x0 ] (cannotOverflow )          [    0x7ffeef6adb60] bci=[164,27,1325] rc=1 vc=2605 vn=- li=- udi=- nc=0 flg=0x1000
n53990n       iconst 31 (X!=0 X>=0 )                                                          [    0x7ffeef6adbb0] bci=[165,12,2292] rc=1 vc=2605 vn=- li=- udi=- nc=0 flg=0x104
n53995n   astore  <temp slot 353>[#3463  Auto] [flags 0x7 0x0 ]                               [    0x7ffeef6add40] bci=[165,7,2292] rc=0 vc=2604 vn=- li=- udi=- nc=1
n53994n     ==>aload
n71320n   BBEnd </block_4229> (cold)                                                          [    0x7ffee5cd04b0] bci=[-1,173,648] rc=0 vc=0 vn=- li=- udi=- nc=0

From the trace information for General Store SInking for these blocks:

  Looking for stores to sink in block_3681
    Examining node [00007FFEEF6ADFC0] in block_3681   <<<< Node n54003n in block_3681
      savedLiveCommonedLoads: {}
      calling findLocalUses on node 00007FFEEF6ADFC0 with treeVisitCount 2602
      killedSymbols: {}
      usedSymbols: {193, 194}      treeCommonedLoads: {}  <<< symIdx 193 is #3463
      setting 192 in killedSymbols
      killedSymbols: {192}
      usedSymbols: {193, 194}
      treeCommonedLoads: {}
      savedLiveCommonedLoads: {}
      killedLiveCommonedLoads: {}
      is store to local 192
         store passes some interfering and candidate tests
      creating use or kill info on movable node [00007FFEEF6ADFC0] to track kills and uses <<<< Node is a movable store, so uses and kill information is kept with the store itself
      store is potentially movable, collecting commoned loads and adding to list

  ....

  Looking for stores to sink in block_3678
    Examining node [00007FFEEF6ADD40] in block_3678
      savedLiveCommonedLoads: {160}
      calling findLocalUses on node 00007FFEEF6ADD40 with treeVisitCount 2604
      killedSymbols: {}
      usedSymbols: {160}      treeCommonedLoads: {}
      setting 193 in killedSymbols
      killedSymbols: {193}
      usedSymbols: {160}
      treeCommonedLoads: {}
      savedLiveCommonedLoads: {160}
      killedLiveCommonedLoads: {}
      is store to local 193
         store passes some interfering and candidate tests
      creating use or kill info on movable node [00007FFEEF6ADD40] to track kills and uses
      store is potentially movable, collecting commoned loads and adding to list
...

    Candidate treetop [00007FFEEF6AE060] is not movable (isStore = false)
      Did not move node 00007FFEEF6AE060 so update killed and used symbols
      Before use and def in block_3681: symbols KILLED {} USED {}
      Update use and def in block_3681: symbols KILLED {191} USED {}

...

    Candidate treetop [00007FFEEF6ADD40] is still movable
(Transformation #211 start - sink store)
[ 25579] O^O SINK STORES:  Finding placements for store [00007FFEEF6ADD40]  with tree depth 2
            TT[00007FFEEF6ADD40] Pushed sym 193 to end of source block_3678
            trying to push to block_3671
              LOSP->blockInfo[3671]: {0, 1, 1229, 1230, 1232, 1233, 1235, 1236}
              symbol not live in this successor
            trying to push to block_3681
              LOSP->blockInfo[3681]: {0, 1, 193, 194, 1229, 1230, 1232, 1233, 1235, 1236}
              added 3681 to worklist
            TT[00007FFEEF6ADD40] trying to sink into block_3681
            Counting LONAP predecessors to compare to propagation count 1
              found LONAP predecessor 3678
              store sunk to beginning of block
              liveOnNotAllPaths.in[sym=193] == true
              intersection of used with symbolsKilled[3681] is false
              symbol 193 in symbolsKilled is false
              symbolUseds == NULL? false
              intersection of killed with symbolsUsed[3681] is false
              symbol 193 in symbolsUsed is false
              LONAP->blockInfo[3681]: {0, 1, 160, 193, 194, 1229, 1230, 1232, 1233, 1236}
              store sunk to end of block
            trying to push to block_3935
              added 3935 to worklist
            trying to push to block_3671
              symbol not live in this successor
            TT[00007FFEEF6ADD40] trying to sink into block_3935
            Counting LONAP predecessors to compare to propagation count 1
              found LONAP predecessor 3681
              store sunk to beginning of block
              liveOnNotAllPaths.in[sym=193] == true
              intersection of used with symbolsKilled[3935] is false
              symbol 193 in symbolsKilled is false
              symbolUseds == NULL? false

So it looks like the store to #3463 in block_3678 which is used in block_3681 is only used in another store — n54003n 0x7ffeef6adfc0 — which is itself movable. I haven't looked into all the details of the implementation, but it looks like #3463 (193) is never included in the list of symbolsUsed for block_3681 because the store that used it actually did get moved.

However, the anchored reference to #3463 is left behind beneath a treetop node in block_3681, and is never removed by dead trees elimination. Instead it persists to code generation, where it results in a crash at run-time.

pshipton commented 1 week ago

Internal build 0.46.1 plinux jdk11 openjdk testing jdk_lang_j9_0 java/lang/Character/CheckUnicode.java Artifacts

11:23:52  Type=Segmentation error vmState=0x00000000
11:23:52  J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
11:23:52  Handler1=00007FFF8F9EFDE0 Handler2=00007FFF8F918880
11:23:52  R0=0000000000000004 R1=00007FFF18AAABB0 R2=0000000000000000 R3=0000000000000030
11:23:52  R4=0000000000000000 R5=00007FFEE4247028 R6=0000000000000015 R7=000000000000000E
11:23:52  R8=00007FFF18AAACD0 R9=00007FFEE4064FD0 R10=00007FFF8F1E7DF0 R11=00007FFEE4242B38
11:23:52  R12=0000000022884442 R13=00007FFF18AB68E0 R14=00007FFEE4246960 R15=00007FFEE4023C00
11:23:52  R16=00007FFF50F20038 R17=0000000000000000 R18=00007FFF6F222768 R19=00007FFF6EE368E0
11:23:52  R20=0000000000000010 R21=0000000000000004 R22=FFFFFFFF80000001 R23=000000000000000E
11:23:52  R24=0000000000000000 R25=00007FFF6F213F58 R26=0000000000000001 R27=000000000000000F
11:23:52  R28=0000000000000000 R29=00007FFF6F222640 R30=00007FFF6F2066C8 R31=0000000000000030
11:23:52  NIP=00007FFF53AC8FDC MSR=800000000280F033 ORIG_GPR3=00007FFF8FA26C38 CTR=00007FFF53AC61F8
11:23:52  LINK=00007FFF8EEAE0D0 XER=0000000000000000 CCR=0000000044884422 SOFTE=0000000000000001
11:23:52  TRAP=0000000000000300 DAR=0000000000000008 dsisr=0000000040000000 RESULT=0000000000000000
11:23:52  FPR0=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR1=40518a0b20000000 (f: 536870912.000000, d: 7.015693e+01)
11:23:52  FPR2=3ff0000000000000 (f: 0.000000, d: 1.000000e+00)
11:23:52  FPR3=00000000b4723397 (f: 3027383296.000000, d: 1.495726e-314)
11:23:52  FPR4=3fce840b4ac4e4d2 (f: 1254417664.000000, d: 2.384047e-01)
11:23:52  FPR5=bfe7154748bef6c8 (f: 1220474624.000000, d: -7.213475e-01)
11:23:52  FPR6=3fe62e42fefa39ef (f: 4277811712.000000, d: 6.931472e-01)
11:23:52  FPR7=3fd4043057b6ee09 (f: 1471606272.000000, d: 3.127557e-01)
11:23:52  FPR8=6e616c2e6176616a (f: 1635148160.000000, d: 5.038246e+223)
11:23:52  FPR9=bfd00ea348b88334 (f: 1220051712.000000, d: -2.508934e-01)
11:23:52  FPR10=bfdff69b0205f251 (f: 33944144.000000, d: -4.994266e-01)
11:23:52  FPR11=3ec8c8350a2154ab (f: 169956528.000000, d: 2.954252e-06)
11:23:52  FPR12=00007ffee4246fb9 (f: 3827593216.000000, d: 6.953121e-310)
11:23:52  FPR13=0000000028892e76 (f: 680078976.000000, d: 3.360037e-315)
11:23:52  FPR14=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR15=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR16=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR17=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR18=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR19=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR20=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR21=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR22=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR23=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR24=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR25=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR26=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR27=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR28=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR29=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR30=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  FPR31=0000000000000000 (f: 0.000000, d: 0.000000e+00)
11:23:52  
11:23:52  Compiled_method=java/lang/Integer.parseInt(Ljava/lang/String;I)I
11:23:52  Target=2_90_20240904_938 (Linux 4.18.0-553.16.1.el8_10.ppc64le)
11:23:52  CPU=ppc64le (4 logical CPUs) (0x1dcc50000 RAM)
11:23:52  ----------- Stack Backtrace -----------
11:23:52   (0x00007FFF53AC8FDC [<unknown>+0x0])
11:23:52  sidecarInvokeReflectMethodImpl+0x508 (0x00007FFF8F9CA698 [libj9vm29.so+0x1a698])
11:23:52  sidecarInvokeReflectMethod+0x3c (0x00007FFF8F9CB5EC [libj9vm29.so+0x1b5ec])
11:23:52  JVM_InvokeMethod_Impl+0xa8 (0x00007FFF8DBDAD58 [libjclse29.so+0x7ad58])
11:23:52  JVM_InvokeMethod+0x3c (0x00007FFF940931EC [libjvm.so+0x231ec])
11:23:52  JVM_InvokeMethod+0x30 (0x00007FFF941767C0 [libjvm.so+0x67c0])
11:23:52  Java_jdk_internal_reflect_NativeMethodAccessorImpl_invoke0+0x24 (0x00007FFF50B4C994 [libjava.so+0xc994])
11:23:52   (0x00007FFF53650AA0 [<unknown>+0x0])
11:23:52  runJavaThread+0x240 (0x00007FFF8F9C6CF0 [libj9vm29.so+0x16cf0])
11:23:52  javaProtectedThreadProc+0x148 (0x00007FFF8FA5ECF8 [libj9vm29.so+0xaecf8])
11:23:52  omrsig_protect+0x3e4 (0x00007FFF8F919D34 [libj9prt29.so+0x39d34])
11:23:52  javaThreadProc+0x60 (0x00007FFF8FA5A620 [libj9vm29.so+0xaa620])
11:23:52  thread_wrapper+0x190 (0x00007FFF8F8ACBC0 [libj9thr29.so+0xcbc0])
11:23:52  start_thread+0xf8 (0x00007FFF94449718 [libpthread.so.0+0x9718])
11:23:52  clone+0x74 (0x00007FFF942EB798 [libc.so.6+0x13b798])