Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

OpenJDK crash in Compiled_method=UnicodeCasingTest.test #17515

Closed
pshipton opened this issue Jun 2, 2023 · 37 comments · Fixed by eclipse-omr/omr#7573
Closed

OpenJDK crash in Compiled_method=UnicodeCasingTest.test #17515

pshipton opened this issue Jun 2, 2023 · 37 comments · Fixed by eclipse-omr/omr#7573
Assignees
Labels
comp:jit segfault Issues that describe segfaults / JVM crashes test failure

Comments

@pshipton
Copy link
Member

pshipton commented Jun 2, 2023

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 pshipton added comp:jit test failure segfault Issues that describe segfaults / JVM crashes labels Jun 2, 2023
@pshipton
Copy link
Member Author

pshipton commented Jun 2, 2023

@0xdaryl fyi

@pshipton
Copy link
Member Author

pshipton commented Jun 2, 2023

@0xdaryl
Copy link
Contributor

0xdaryl commented Jun 2, 2023

@zl-wang : please assign for investigation

@zl-wang
Copy link
Contributor

zl-wang commented Jun 2, 2023

@bhavanisn please take a look

@pshipton
Copy link
Member Author

pshipton commented Jun 2, 2023

The crash was not duplicated in the grinder.

@bhavanisn
Copy link
Contributor

@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
Copy link
Member Author

pshipton commented Jun 5, 2023

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
Copy link
Contributor

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
Copy link
Member Author

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
Copy link
Contributor

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)

  1. 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
Copy link
Contributor

bhavanisn commented Jun 22, 2023

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
Copy link
Contributor

zl-wang commented Jun 22, 2023

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
Copy link
Contributor

zl-wang commented Jun 22, 2023

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
Copy link

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

@zl-wang
Copy link
Contributor

zl-wang commented Jun 27, 2023

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
Copy link
Contributor

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
Copy link
Contributor

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
Copy link
Contributor

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
Copy link
Member Author

pshipton commented Feb 1, 2024

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 pshipton reopened this Feb 1, 2024
@pshipton
Copy link
Member Author

pshipton commented Feb 1, 2024

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

@hzongaro
Copy link
Member

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
Copy link
Member

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
Copy link
Member Author

pshipton commented Sep 6, 2024

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])

@pshipton
Copy link
Member Author

pshipton commented Oct 7, 2024

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Release_testList_1/15/ - ubu24-ppc64le-2
jdk_lang_j9_0
java/lang/Character/UnicodeCasingTest.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Release_testList_1/15/openjdk_test_output.tar.gz

19:40:08  stderr:
19:40:08  Unhandled exception
19:40:08  Type=Segmentation error vmState=0x00000000
19:40:08  J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
19:40:08  Handler1=0000736677C40180 Handler2=000073667C1E8880
19:40:08  R0=0000000000000004 R1=000073663856AA90 R2=0000000000000000 R3=0000000000000033
19:40:08  R4=0000000000000000 R5=00000039B32FA39C R6=0000000000000001 R7=000073665F473958
19:40:08  R8=0000736656000000 R9=0000000000000001 R10=0000736676000000 R11=00007365A8264418
19:40:08  R12=00007366764D2650 R13=00007366385768E0 R14=00007365A8267F00 R15=00007366786DA900
19:40:08  R16=0000000000000000 R17=000073665F473808 R18=000073665892EA00 R19=0000000000000010
19:40:08  R20=0000000000000004 R21=FFFFFFFF80000001 R22=000000000000001F R23=0000000000000000
19:40:08  R24=0000736656084118 R25=0000000000000000 R26=00007366574826C8 R27=000073665F473760
19:40:08  R28=000073665731D6A0 R29=0000000000000033 R30=000073665F450D90 R31=0000000000000000
19:40:08  NIP=000073663BF0C814 MSR=800000000280D033 ORIG_GPR3=000073663BF0C808 CTR=000073663BF09900
19:40:08  LINK=000073663BE8A580 XER=0000000000000003 CCR=0000000048884444 SOFTE=0000000000000001
19:40:08  TRAP=0000000000000300 DAR=0000000000000008 dsisr=0000000040000000 RESULT=0000000000000000
19:40:08  FPR0=000000000001ffa0 (f: 130976.000000, d: 6.471074e-319)
19:40:08  FPR1=4050285700000000 (f: 0.000000, d: 6.463031e+01)
19:40:08  FPR2=4100000000000000 (f: 0.000000, d: 1.310720e+05)
19:40:08  FPR3=3fce840b4ac4e4d2 (f: 1254417664.000000, d: 2.384047e-01)
19:40:08  FPR4=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR5=3fe62e42fefa39ef (f: 4277811712.000000, d: 6.931472e-01)
19:40:08  FPR6=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR7=bff0000000000000 (f: 0.000000, d: -1.000000e+00)
19:40:08  FPR8=bfdffffef20a4123 (f: 4060758272.000000, d: -4.999997e-01)
19:40:08  FPR9=3fd5575b0be00b6a (f: 199232368.000000, d: 3.334568e-01)
19:40:08  FPR10=bfd00ea348b88334 (f: 1220051712.000000, d: -2.508934e-01)
19:40:08  FPR11=bfdffffef20a4123 (f: 4060758272.000000, d: -4.999997e-01)
19:40:08  FPR12=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR13=0000736678521380 (f: 2018644864.000000, d: 6.268900e-310)
19:40:08  FPR14=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR15=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR16=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR17=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR18=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR19=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR20=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR21=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR22=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR23=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR24=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR25=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR26=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR27=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR28=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR29=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR30=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  FPR31=0000000000000000 (f: 0.000000, d: 0.000000e+00)
19:40:08  
19:40:08  Compiled_method=java/lang/Integer.parseInt(Ljava/lang/String;I)I
19:40:08  Target=2_90_20241005_124 (Linux 6.8.0-41-generic)
19:40:08  CPU=ppc64le (4 logical CPUs) (0x1ea0e0000 RAM)
19:40:08  ----------- Stack Backtrace -----------
19:40:08   (0x000073663BF0C814 [<unknown>+0x0])
19:40:08  sidecarInvokeReflectMethodImpl+0x508 (0x0000736677C1A1D8 [libj9vm29.so+0x1a1d8])
19:40:08  sidecarInvokeReflectMethod+0x3c (0x0000736677C1B12C [libj9vm29.so+0x1b12c])
19:40:08  JVM_InvokeMethod_Impl+0xa8 (0x00007366761CAD38 [libjclse29.so+0x7ad38])
19:40:08  JVM_InvokeMethod+0x3c (0x000073667C7A352C [libjvm.so+0x2352c])
19:40:08  JVM_InvokeMethod+0x30 (0x000073667CB567C0 [libjvm.so+0x67c0])
19:40:08  Java_jdk_internal_reflect_NativeMethodAccessorImpl_invoke0+0x24 (0x000073664BC0C994 [libjava.so+0xc994])
19:40:08   (0x000073663BC17DAC [<unknown>+0x0])
19:40:08  runJavaThread+0x240 (0x0000736677C16830 [libj9vm29.so+0x16830])
19:40:08  javaProtectedThreadProc+0x148 (0x0000736677CAF458 [libj9vm29.so+0xaf458])
19:40:08  omrsig_protect+0x3e4 (0x000073667C1E9D34 [libj9prt29.so+0x39d34])
19:40:08  javaThreadProc+0x60 (0x0000736677CAAAC0 [libj9vm29.so+0xaaac0])
19:40:08  thread_wrapper+0x190 (0x000073667C17CBC0 [libj9thr29.so+0xcbc0])
19:40:08   (0x000073667C8B2A5C [libc.so.6+0xb2a5c])
19:40:08  ---------------------------------------

@pshipton
Copy link
Member Author

pshipton commented Nov 4, 2024

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly_testList_1/91 - ubu22-ppc64le-3
jdk_lang_j9_0
java/lang/Character/UnicodeCasingTest.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly_testList_1/91/openjdk_test_output.tar.gz

21:04:57  Type=Segmentation error vmState=0x00000000
21:04:57  J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
21:04:57  Handler1=00007D5A2C9406D0 Handler2=00007D5A2C868860
21:04:57  R0=0000000000000005 R1=00007D59E4FAAA20 R2=0000000000000000 R3=0000000000000031
21:04:57  R4=0000000000000000 R5=0000003EAD057A8A R6=0000000000000001 R7=00007D5A0AF513F0
21:04:57  R8=00007D5A06B00000 R9=0000000000000001 R10=00007D5A26B00000 R11=00007D5984287668
21:04:57  R12=00007D5A26D728B0 R13=00007D59E4FB68E0 R14=00007D598428B010 R15=00007D598401AB00
21:04:57  R16=0000000000000000 R17=00007D5A0AF512A0 R18=0000000000000000 R19=0000000000000000
21:04:57  R20=0000000000000010 R21=000000000000000F R22=00000000F8000001 R23=FFFFFFFF80000001
21:04:57  R24=0000000000000005 R25=00007D5A0AF64698 R26=00007D5A07DE2D10 R27=00007D5A0AF511F8
21:04:57  R28=0000000000000000 R29=00007D5A0AF51408 R30=00007D5A07C030C8 R31=0000000000000000
21:04:57  NIP=00007D59EC96C88C MSR=800000000280D033 ORIG_GPR3=00007D59EC96C880 CTR=00007D59EC96B000
21:04:57  LINK=00007D59EC927E00 XER=0000000000000003 CCR=0000000048884444 SOFTE=0000000000000001
21:04:57  TRAP=0000000000000300 DAR=0000000000000008 dsisr=0000000040000000 RESULT=0000000000000000
21:04:57  FPR0=000000000001fff8 (f: 131064.000000, d: 6.475422e-319)
21:04:57  FPR1=4050285700000000 (f: 0.000000, d: 6.463031e+01)
21:04:57  FPR2=3ff0000000000000 (f: 0.000000, d: 1.000000e+00)
21:04:57  FPR3=3fce840b4ac4e4d2 (f: 1254417664.000000, d: 2.384047e-01)
21:04:57  FPR4=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR5=3fe62e42fefa39ef (f: 4277811712.000000, d: 6.931472e-01)
21:04:57  FPR6=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR7=bff0000000000000 (f: 0.000000, d: -1.000000e+00)
21:04:57  FPR8=bfdffffef20a4123 (f: 4060758272.000000, d: -4.999997e-01)
21:04:57  FPR9=3fd5575b0be00b6a (f: 199232368.000000, d: 3.334568e-01)
21:04:57  FPR10=bfd00ea348b88334 (f: 1220051712.000000, d: -2.508934e-01)
21:04:57  FPR11=bfdffffef20a4123 (f: 4060758272.000000, d: -4.999997e-01)
21:04:57  FPR12=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR13=00007d5a28524e80 (f: 676482688.000000, d: 6.809518e-310)
21:04:57  FPR14=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR15=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR16=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR17=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR18=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR19=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR20=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR21=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR22=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR23=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR24=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR25=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR26=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR27=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR28=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR29=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR30=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  FPR31=0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:04:57  
21:04:57  Compiled_method=java/lang/Integer.parseInt(Ljava/lang/String;I)I
21:04:57  Target=2_90_20241102_837 (Linux 5.15.0-122-generic)
21:04:57  CPU=ppc64le (4 logical CPUs) (0x1fb170000 RAM)
21:04:57  ----------- Stack Backtrace -----------
21:04:57   (0x00007D59EC96C88C [<unknown>+0x0])
21:04:57  sidecarInvokeReflectMethodImpl+0x508 (0x00007D5A2C91A1F8 [libj9vm29.so+0x1a1f8])
21:04:57  sidecarInvokeReflectMethod+0x3c (0x00007D5A2C91B14C [libj9vm29.so+0x1b14c])
21:04:57  JVM_InvokeMethod_Impl+0xa8 (0x00007D5A26BBACF8 [libjclse29.so+0x7acf8])
21:04:57  JVM_InvokeMethod+0x3c (0x00007D5A2D0A352C [libjvm.so+0x2352c])
21:04:57  JVM_InvokeMethod+0x30 (0x00007D5A2D1867C0 [libjvm.so+0x67c0])
21:04:57  Java_jdk_internal_reflect_NativeMethodAccessorImpl_invoke0+0x24 (0x00007D59E60CC944 [libjava.so+0xc944])
21:04:57   (0x00007D59EC729B2C [<unknown>+0x0])
21:04:57  runJavaThread+0x240 (0x00007D5A2C916850 [libj9vm29.so+0x16850])
21:04:57  javaProtectedThreadProc+0x148 (0x00007D5A2C9B0418 [libj9vm29.so+0xb0418])
21:04:57  omrsig_protect+0x3e4 (0x00007D5A2C869D14 [libj9prt29.so+0x39d14])
21:04:57  javaThreadProc+0x60 (0x00007D5A2C9ABA80 [libj9vm29.so+0xaba80])
21:04:57  thread_wrapper+0x190 (0x00007D5A2C7FCBC0 [libj9thr29.so+0xcbc0])
21:04:57   (0x00007D5A2D275804 [libc.so.6+0xb5804])

@hzongaro
Copy link
Member

Several months ago, @vijaysun-omr and I discussed my observation that trees were left behind that contained references to stores that had been sunk passed those references. A later pass of Dead Trees Elimination would ordinarily remove those trees but failed to in this case, because that optimization decided to stop prematurely:

[ 26371] O^O DEAD TREES ELIMINATION: Remove tree : [00007FFEEB5F14A0] ([00007FFF48ACC3A0] = iushr)
         O^O DEAD TREES ELIMINATION: node count 72369 exceeds limit 49151
         O^O DEAD TREES ELIMINATION: Global index limit exceeded; stopping

At the time he asked how Dead Store Elimination handles similar situations as it might remove a store that in turn allows another store to be removed. I've finally come back to this issue, and it appears that a similar problem must have been encountered in Dead Store Elimination about ten years ago. That optimization contains logic that looks for "unsafe" references that appear in trees beneath treetop nodes that have been left behind by that optimization. This can be seen in the implementation of the UnsafeSubexpressionRemoval class and its use in TR_IsolatedStoreRemoval::perform()

I will look at refactoring the code that deals with unsafe references from Dead Store Elimination so that it can be used by General Store Sinking as well.

@hzongaro
Copy link
Member

hzongaro commented Nov 15, 2024

I managed to create a reduced test case that reproduces this problem, with a heavy dose of compiler options to set up the scenario in the IL:

$ cat Test17515.java
public class Test17515 {
    public static final int sub(int i, int parr[]) {
        if (parr == null) return 0;
        int[] arr = parr;
        int doubleLen = arr.length * 2;
        if (i >= -1 && i < 100) {
            return doubleLen + arr.length;
        }
        return 1;
    }

    public static final void main(String[] args) {
        sub(17, new int[256]);
        sub(3, new int[256]);
    }
}
$ java -Xjit:{Test17515.sub*}\(optLevel=hot,traceGeneralStoreSinking,disableGlobalCopyPropagation,disableLocalCSE,disableGlobalDSE,lastOptIndex=177,optDetails,log=test17515.optfile.log\),count=1,disableAsyncCompilation Test17515
Exception in thread "main" java.lang.NullPointerException
        at Test17515.sub(Test17515.java)
        at Test17515.main(Test17515.java:14)

Update: Removed the compactLocals option. I had added that while looking into a different problem.

@hzongaro
Copy link
Member

I'll need to ensure the fix handles stores that have a non-zero reference count correctly. This will need to move out to 0.51.

@pshipton
Copy link
Member Author

pshipton commented Jan 7, 2025

@pshipton
Copy link
Member Author

@hzongaro hzongaro marked this as a duplicate of #17922 Jan 22, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
comp:jit segfault Issues that describe segfaults / JVM crashes test failure
Projects
None yet
Development

Successfully merging a pull request may close this issue.

7 participants