eclipse-openj9/openj9

JDK8 Segmentation error vmState=0x00000000

connglli opened this issue · 29 comments

connglli commented

Java -version output

openjdk version "1.8.0_342-internal"
OpenJDK Runtime Environment (build 1.8.0_342-internal-_2022_06_10_15_18-b00)
Eclipse OpenJ9 VM (build master-3d06b2f9c, JRE 1.8.0 Linux amd64-64-Bit Compressed References 20220610_000000 (JIT enabled, AOT enabled)
OpenJ9   - 3d06b2f9c
OMR      - cf8ddbd1a
JCL      - 2bb179375a based on jdk8u342-b05)

Summary of problem

The given (unreduced) Test.java in following link crashes OpenJ9's JIT compiler.

Should note that

  1. Crash often happens, but the logs sometimes cannot be written. This is because it is somewhat non-determistic. That said, it sometimes crashes with exit code 255, sometimes 1, and sometimes 134.
  2. Because of 1, our submitted logs do not contain Snap.xxxx and javacore.xxx.
  3. Because of 1, our tool cannot reduce this test effectively (this is why we submit an unreduced one; sorry for that).

So please be patient when triggerring this crash.

Please also check openj9-bug-69.tar.gz for all the logs (jitdump, coredump, output) and the test (Test.java, Test.class).

Diagnostic files

By issuing

$ java -Xmx1G Test

the following crash log is given:

JVMDUMP039I Processing dump event "abort", detail "" at 2022/06/15 17:01:50 - please wait.
JVMDUMP032I JVM requested System dump using '/zdata/congli/ax-exp/ax-eval/2-ax-only/69.openj9/mutant/red/core.20220615.170150.580443.0001.dmp' in response to an event
Unhandled exception
Type=Segmentation error vmState=0x00000000
J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000080
Handler1=00007F5B3865A020 Handler2=00007F5B38442EF0 InaccessibleAddress=0000000000000000
RDI=00007F5B341BB630 RSI=00007F5B341BB630 RAX=0027015800007F5B RBX=00007F5B341BB630
RCX=0000000000008FFB RDX=00007F5B1F010978 R8=00007F5B1F011E0A R9=0000000000270D00
R10=0000000000000000 R11=00007F5B33F48A40 R12=00007F5B1F010978 R13=000000000004DD00
R14=00007F5B1F011E0A R15=000000000004DD00
RIP=00007F5B32F69BAC GS=0000 FS=0000 RSP=00007F5B3889ECC0
EFlags=0000000000010246 CS=0033 RBP=0000000000270D00 ERR=0000000000000000
TRAPNO=000000000000000D OLDMASK=0000000000000000 CR2=0000000003210000
xmm0 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm1 ffffffffffffff00 (f: 4294967040.000000, d: -nan)
xmm2 00007f5b3889f620 (f: 948565504.000000, d: 6.918390e-310)
xmm3 bfdf959f861b320a (f: 2249929216.000000, d: -4.935073e-01)
xmm4 4000d00000000000 (f: 0.000000, d: 2.101562e+00)
xmm5 bff0000000000000 (f: 0.000000, d: -1.000000e+00)
xmm6 3fc526e57720db08 (f: 1998641920.000000, d: 1.652495e-01)
xmm7 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm8 c1bbef5411000000 (f: 285212672.000000, d: -4.686695e+08)
xmm9 0000000043780000 (f: 1131937792.000000, d: 5.592516e-315)
xmm10 000000003f8f7cee (f: 1066368256.000000, d: 5.268559e-315)
xmm11 0000000043780000 (f: 1131937792.000000, d: 5.592516e-315)
xmm12 0000000043780000 (f: 1131937792.000000, d: 5.592516e-315)
xmm13 0000000043780000 (f: 1131937792.000000, d: 5.592516e-315)
xmm14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
Module=/zdata/congli/OpenJ9/jdk8/jre/lib/amd64/default/libj9jit29.so
Module_base_address=00007F5B32BFA000
Target=2_90_20220610_000000 (Linux 5.4.0-117-generic)
CPU=amd64 (128 logical CPUs) (0x3ee84d8000 RAM)
----------- Stack Backtrace -----------
_ZN2J913Recompilation12sampleMethodEPvP11TR_FrontEndS1_iS1_S1_i+0x2c (0x00007F5B32F69BAC [libj9jit29.so+0x36fbac])
jitMethodSampleInterrupt+0x3eb (0x00007F5B32D27BBB [libj9jit29.so+0x12dbbb])
dispatchAsyncEvents+0xc7 (0x00007F5B3865B617 [libj9vm29.so+0x40617])
javaCheckAsyncMessages+0xa8 (0x00007F5B38632E98 [libj9vm29.so+0x17e98])
_ZN32VM_BytecodeInterpreterCompressed3runEP10J9VMThread+0x209 (0x00007F5B386A4429 [libj9vm29.so+0x89429])
bytecodeLoopCompressed+0xad (0x00007F5B386A420D [libj9vm29.so+0x8920d])
 (0x00007F5B3874E642 [libj9vm29.so+0x133642])
---------------------------------------
JVMDUMP039I Processing dump event "gpf", detail "" at 2022/06/15 17:01:50 - please wait.
JVMDUMP010I System dump written to /zdata/congli/ax-exp/ax-eval/2-ax-only/69.openj9/mutant/red/core.20220615.170150.580443.0001.dmp
JVMDUMP032I JVM requested Snap dump using '/zdata/congli/ax-exp/ax-eval/2-ax-only/69.openj9/mutant/red/Snap.20220615.170150.580443.0004.trc' in response to an event
JVMDUMP032I JVM requested JIT dump using '/zdata/congli/ax-exp/ax-eval/2-ax-only/69.openj9/mutant/red/jitdump.20220615.170150.580443.0005.dmp' in response to an event
JVMDUMP051I JIT dump occurred in 'JIT-SamplerThread' thread 0x000000000006FC00
JVMDUMP010I JIT dump written to /zdata/congli/ax-exp/ax-eval/2-ax-only/69.openj9/mutant/red/jitdump.20220615.170150.580443.0005.dmp
JVMDUMP013I Processed dump event "abort", detail "".
pshipton commented

I was able to repeat it on 0.33 and 0.32 fairly quickly.

@0xdaryl

pshipton commented

@connglli I'm not sure how you are finding these problems. Do you think there are going to be many more?

connglli commented

Hi @pshipton, indeed what we have reported by far are obviously unique bugs of OpenJ9. Hope to improve the quality f OpenJ9.

Not sure if there are MUCH more, but there are still some in our hands. We are still working on them (many are not crashes; miscompilations instead) such that we only report unique ones and don't smash your issuetracker.

  • 👍2
0xdaryl commented

@mpirvu : could you have someone triage this crash in sampleMethod() please?

mpirvu commented

@dsouzai since you recently looked at the sampling code, could you please investigate this crash? Test case is provided and problem is reproducible. Thanks

dsouzai commented

@connglli do you mind uploading your JDK? I'm not able to reproduce the crash, and the coredump can really only be analyzed with the exact build that generated it. If you built it yourself, could you ensure that it contains the debug symbols; if you got it from somewhere, could you point me to that location?

connglli commented

@dsouzai See this link. Yep, I built it myself but I don't think there are any debugging symbols since I was building a release instead of fastdebug or slowdebug.

pshipton commented

I was chatting with dsouzai and he found a local JVM that could reproduce the crash.

  • 👍1
dsouzai commented

Thanks @connglli, I'm downloading your build anyway because I'm seeing some inconsistent things in my repro. At the time of the crash, the ouput looks similar to yours. However, when I load the core in gdb I'm seeing:

#16 <signal handler called>
#17 samplerThreadProc (entryarg=<optimized out>) at /home/jenkins/workspace/build-scripts/jobs/jdk8u/jdk8u-linux-x64-openj9/workspace/build/src/openj9/runtime/compiler/control/HookedByTheJit.cpp:6096
#18 0x00007fe27dd324f6 in thread_wrapper (arg=0x7fe2780da6c0) at /home/jenkins/workspace/build-scripts/jobs/jdk8u/jdk8u-linux-x64-openj9/workspace/build/src/omr/thread/common/omrthread.c:1724
#19 0x00007fe27f00fb1a in start_thread (arg=<optimized out>) at pthread_create.c:443
#20 0x00007fe27f094660 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Looking at the crashing instruction in samplerThreadProc:

   0x00007fe27c6a9b9a <+1690>:  mov    rax,QWORD PTR [r14+0x16b0]
   0x00007fe27c6a9ba1 <+1697>:  mov    QWORD PTR [rbp-0xa0],rbx
   0x00007fe27c6a9ba8 <+1704>:  mov    rcx,r14
   0x00007fe27c6a9bab <+1707>:  mov    rbx,QWORD PTR [rbp-0x90]
   0x00007fe27c6a9bb2 <+1714>:  mov    DWORD PTR [rbp-0x88],r13d
   0x00007fe27c6a9bb9 <+1721>:  mov    r13,rcx
   0x00007fe27c6a9bbc <+1724>:  mov    r14,rax
   0x00007fe27c6a9bbf <+1727>:  nop
=> 0x00007fe27c6a9bc0 <+1728>:  cmp    QWORD PTR [r14+0x9c0],0x0
   0x00007fe27c6a9bc8 <+1736>:  jne    0x7fe27c6a9c01 <samplerThreadProc(void*)+1793>
   0x00007fe27c6a9bca <+1738>:  test   BYTE PTR [r14+0x98],0x20
   0x00007fe27c6a9bd2 <+1746>:  je     0x7fe27c6a9c01 <samplerThreadProc(void*)+1793>
   0x00007fe27c6a9bd4 <+1748>:  mov    rax,QWORD PTR [r13+0x0]
   0x00007fe27c6a9bd8 <+1752>:  mov    rdx,QWORD PTR [rbx+0xb18]
   0x00007fe27c6a9bdf <+1759>:  mov    rsi,r14
   0x00007fe27c6a9be2 <+1762>:  mov    rdi,r13
   0x00007fe27c6a9be5 <+1765>:  call   QWORD PTR [rax+0x600]
   0x00007fe27c6a9beb <+1771>:  add    DWORD PTR [rbp-0x88],0x1
   0x00007fe27c6a9bf2 <+1778>:  mov    QWORD PTR [r14+0x50],0xffffffffffffffff
   0x00007fe27c6a9bfa <+1786>:  mov    rax,QWORD PTR [r13+0x16b0]
   0x00007fe27c6a9c01 <+1793>:  mov    r14,QWORD PTR [r14+0x1a0]
   0x00007fe27c6a9c08 <+1800>:  cmp    r14,rax
   0x00007fe27c6a9c0b <+1803>:  jne    0x7fe27c6a9bc0 <samplerThreadProc(void*)+1728>

This maps to
https://github.com/eclipse-openj9/openj9/blob/v0.32.0-release/runtime/compiler/control/HookedByTheJit.cpp#L6094-L6106

Given that r14 is the J9VMThread linked list that we're iterating over, and that at the start of the loop, the value of the J9JavaVM is stored into r13

(gdb) p ((J9JavaVM *)0x7fe2780240f0)->mainThread
$3 = (J9VMThread *) 0x18d00
(gdb) p ((J9VMThread *)0x18d00)->linkNext
$4 = (J9VMThread *) 0x1c900
(gdb) p ((J9VMThread *)0x1c900)->linkNext
$5 = (J9VMThread *) 0x20600
(gdb) p ((J9VMThread *)0x20600)->linkNext
$6 = (J9VMThread *) 0x24200
(gdb) p ((J9VMThread *)0x24200)->linkNext
$7 = (J9VMThread *) 0x27e00
(gdb) p ((J9VMThread *)0x27e00)->linkNext
$8 = (J9VMThread *) 0x2bb00
(gdb) p ((J9VMThread *)0x2bb00)->linkNext
$9 = (J9VMThread *) 0x2f700
(gdb) p ((J9VMThread *)0x2f700)->linkNext
$10 = (J9VMThread *) 0x33400
(gdb) p ((J9VMThread *)0x33400)->linkNext
$11 = (J9VMThread *) 0x37000
(gdb) p ((J9VMThread *)0x37000)->linkNext
$12 = (J9VMThread *) 0x3ac00
(gdb) p ((J9VMThread *)0x3ac00)->linkNext
$13 = (J9VMThread *) 0x3e900
(gdb) p ((J9VMThread *)0x3e900)->linkNext
$14 = (J9VMThread *) 0x109d00
(gdb) p ((J9VMThread *)0x109d00)->linkNext
$15 = (J9VMThread *) 0x3e90000000000
(gdb) p ((J9VMThread *)0x3e90000000000)->inNative
Cannot access memory at address 0x3e900000009c0

So here it looks like the list of J9VMThreads is bad. Will investigate further to see if I can diagnose the crash in sampleMethod.

dsouzai commented

I'm not particularly sure what's going on. Every time I reproduce the crash, the crash output will say one thing, but the coredump will say another. Specifically, the crash will say something like:

Type=Segmentation error vmState=0x00000000
J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000080
Handler1=00007FCC42EEEB00 Handler2=00007FCC42C4A690 InaccessibleAddress=0000000000000000
RDI=00007FCC440B3660 RSI=00007FCC440B3660 RAX=0014688800007FCC RBX=00007FCC440B3660
RCX=0000000000002EA1 RDX=00007FCC2CE0FFF8 R8=00007FCC2CE10DDA R9=0000000000147400
R10=0000000000000000 R11=00007FCC420C1A40 R12=00007FCC2CE0FFF8 R13=0000000000015200
R14=00007FCC2CE10DDA R15=0000000000015200
RIP=00007FCC40C4639C GS=0000 FS=0000 RSP=00007FCC49194CC0
EFlags=0000000000010246 CS=0033 RBP=0000000000147400 ERR=0000000000000000
TRAPNO=000000000000000D OLDMASK=0000000000000000 CR2=0000000003210000
xmm0 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm1 ffffffffffffff00 (f: 4294967040.000000, d: -nan)
xmm2 00007fcc49195620 (f: 1226397184.000000, d: 6.942382e-310)
xmm3 bfdfab5a9f8d9994 (f: 2676857344.000000, d: -4.948336e-01)
xmm4 4000d00000000000 (f: 0.000000, d: 2.101562e+00)
xmm5 ff000000ff000000 (f: 4278190080.000000, d: -5.486129e+303)
xmm6 00000000ff000000 (f: 4278190080.000000, d: 2.113707e-314)
xmm7 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm8 000000003f8f7cee (f: 1066368256.000000, d: 5.268559e-315)
xmm9 00000000c2c867f0 (f: 3267913728.000000, d: 1.614564e-314)
xmm10 00007fcc7f800000 (f: 2139095040.000000, d: 6.942427e-310)
xmm11 0000000043780000 (f: 1131937792.000000, d: 5.592516e-315)
xmm12 c1bbef5411000000 (f: 285212672.000000, d: -4.686695e+08)
xmm13 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
xmm15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
Module=/root/15338/0.33/jdk8u342-b03/jre/lib/amd64/default/libj9jit29.so
Module_base_address=00007FCC407EB000
Target=2_90_20220602_396 (Linux 4.15.0-180-generic)
CPU=amd64 (2 logical CPUs) (0x7c8cc000 RAM)
----------- Stack Backtrace -----------
_ZN2J913Recompilation12sampleMethodEPvP11TR_FrontEndS1_iS1_S1_i+0x2c (0x00007FCC40C4639C [libj9jit29.so+0x45b39c])
jitMethodSampleInterrupt+0x3eb (0x00007FCC4094E28B [libj9jit29.so+0x16328b])
dispatchAsyncEvents+0xc7 (0x00007FCC42EF00F7 [libj9vm29.so+0x400f7])
javaCheckAsyncMessages+0xa8 (0x00007FCC42EC79C8 [libj9vm29.so+0x179c8])
_ZN32VM_BytecodeInterpreterCompressed3runEP10J9VMThread+0x209 (0x00007FCC42F38E29 [libj9vm29.so+0x88e29])
bytecodeLoopCompressed+0xad (0x00007FCC42F38C0D [libj9vm29.so+0x88c0d])
 (0x00007FCC42FE3042 [libj9vm29.so+0x133042])

but when I use gdb to look at the core:

#13 <signal handler called>
#14 samplerThreadProc (entryarg=0x7fcc440adf70)
    at /home/jenkins/workspace/build-scripts/jobs/jdk8u/jdk8u-linux-x64-openj9/workspace/build/src/openj9/runtime/compiler/control/HookedByTheJit.cpp:6150
#15 0x00007fcc42a134f6 in thread_wrapper (arg=0x7fcc440cd230)
    at /home/jenkins/workspace/build-scripts/jobs/jdk8u/jdk8u-linux-x64-openj9/workspace/build/src/omr/thread/common/omrthread.c:1724
#16 0x00007fcc48d636db in start_thread (arg=0x7fcc3cf05700) at pthread_create.c:463
#17 0x00007fcc4867061f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

the cause being the bad linked list of J9VMThread pointers. Additionally, whenever I run the test under gdb, I have never seen the crash in sampleMethod but always see the crash in samplerThreadProc.

The bad address (according to the core file) is:

=> 0x00007fcc40949af0 <+1744>:  cmp    QWORD PTR [r14+0x9b0],0x0

where r14=0x3ae0000000000. What's interesting is that if I only look at the top 32 bits 0x3ae00, that ends up being a valid J9VMThread pointer.

As such, it doesn't look like a JIT issue from what I've seen so far. @pshipton could you ask someone from the VM team to take a look?

dsouzai commented

Some additionally information; if we start looping from the main thread:

(gdb) p ((J9JavaVM *)0x00007fcc44024050)->mainThread
$10 = (J9VMThread *) 0x15200
(gdb) p ((J9VMThread *)0x15200)->linkNext
$11 = (J9VMThread *) 0x18f00
(gdb) p ((J9VMThread *)0x18f00)->linkNext
$12 = (J9VMThread *) 0x1cb00
(gdb) p ((J9VMThread *)0x1cb00)->linkNext
$13 = (J9VMThread *) 0x20700
(gdb) p ((J9VMThread *)0x20700)->linkNext
$14 = (J9VMThread *) 0x24400
(gdb) p ((J9VMThread *)0x24400)->linkNext
$15 = (J9VMThread *) 0x28000
(gdb) p ((J9VMThread *)0x28000)->linkNext
$16 = (J9VMThread *) 0x2bc00
(gdb) p ((J9VMThread *)0x2bc00)->linkNext
$17 = (J9VMThread *) 0x2f900
(gdb) p ((J9VMThread *)0x2f900)->linkNext
$18 = (J9VMThread *) 0x33500
(gdb) p ((J9VMThread *)0x33500)->linkNext
$19 = (J9VMThread *) 0x37100
(gdb) p ((J9VMThread *)0x37100)->linkNext
$20 = (J9VMThread *) 0x3ae00
(gdb) p ((J9VMThread *)0x3ae00)->linkNext
$21 = (J9VMThread *) 0x106200
(gdb) p ((J9VMThread *)0x106200)->linkNext
$22 = (J9VMThread *) 0x3ae0000000000

We eventually see that (J9VMThread *)0x106200)->linkNext leads to the bad pointer, which, if we look at the high 32 bits, is actually is the previous thread. However:

(gdb) p ((J9VMThread *)0x106200)->linkPrevious
$23 = (J9VMThread *) 0x10001a00000000

which means that 0x106200 is not a J9VMThread at all. 0x3ae00's linkPrevious is correct, and if I print out the entire J9VMThread struct at 0x3ae00 it looks sane for the most part. Somehow 0x3ae00's linkNext ends up being invalid.

dsouzai commented

Also @connglli I don't know what the expected output of the test should be, but whenever I run it, if it doesn't crash, it will print

i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,30235,-7361758
Test.iArrFld Test.dArrFld byArrFld = -6215,-4553228026621557456,0
iMeth_check_sum: -4333806183732943446
vMeth1_check_sum: 68973879509876838
vMeth_check_sum: 152689325288400263
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,24905,-14748646
Test.iArrFld Test.dArrFld byArrFld = -5870,-4553228026621557456,0
iMeth_check_sum: -8667612328627537193
vMeth1_check_sum: 137947759019753676
vMeth_check_sum: 305378650576800639

and seem to hang. Is this expected?

pshipton commented

As such, it doesn't look like a JIT issue from what I've seen so far. @pshipton could you ask someone from the VM team to take a look?

@tajila fyi
@gacholio do you have any cycles to look?

connglli commented

Absolutely not expected. The program should not hang, instead it should exit normally. This is the output of HotSpot JDK8/11/17 and Android ART:

i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,30235,-7361758
Test.iArrFld Test.dArrFld byArrFld = -6215,-4553228026621557456,0
iMeth_check_sum: -4333806183732943446
vMeth1_check_sum: 68973879509876838
vMeth_check_sum: 152689325288400263
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,24905,-14748646
Test.iArrFld Test.dArrFld byArrFld = -5870,-4553228026621557456,0
iMeth_check_sum: -8667612328627537193
vMeth1_check_sum: 137947759019753676
vMeth_check_sum: 305378650576800639
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,19575,-22135534
Test.iArrFld Test.dArrFld byArrFld = -13040,-4553228026621557456,0
iMeth_check_sum: 5445325600187420676
vMeth1_check_sum: 206921638529630514
vMeth_check_sum: 458067975865201016
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,14245,-29522422
Test.iArrFld Test.dArrFld byArrFld = -5158,-4553228026621557456,0
iMeth_check_sum: 1111519455292826929
vMeth1_check_sum: 275895518039507352
vMeth_check_sum: 610757301153601394
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,8915,-36909310
Test.iArrFld Test.dArrFld byArrFld = -11570,-4553228026621557456,0
iMeth_check_sum: -3222286689601766818
vMeth1_check_sum: 344869397549384190
vMeth_check_sum: 763446626442001773
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,3585,-44296198
Test.iArrFld Test.dArrFld byArrFld = -8111,-4553228026621557456,0
iMeth_check_sum: -7556092834496360565
vMeth1_check_sum: 413843277059261028
vMeth_check_sum: 916135951730402153
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,-1745,-51683086
Test.iArrFld Test.dArrFld byArrFld = -9792,-4553228026621557456,0
iMeth_check_sum: 6556845094318597304
vMeth1_check_sum: 482817156569137866
vMeth_check_sum: 1068825277018802534
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,-7075,-59069974
Test.iArrFld Test.dArrFld byArrFld = -9811,-4553228026621557456,0
iMeth_check_sum: 2223038949424003557
vMeth1_check_sum: 551791036079014704
vMeth_check_sum: 1221514602307202916
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,-12405,-66456862
Test.iArrFld Test.dArrFld byArrFld = -8825,-4553228026621557456,0
iMeth_check_sum: -2110767195470590190
vMeth1_check_sum: 620764915588891542
vMeth_check_sum: 1374203927595603299
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,-17735,-73843750
Test.iArrFld Test.dArrFld byArrFld = -10849,-4553228026621557456,0
iMeth_check_sum: -6444573340365183937
vMeth1_check_sum: 689738795098768380
vMeth_check_sum: 1526893252884003683
pshipton commented

Also if it's run on OpenJ9 with -Xint.

pshipton commented

btw, I tried -Xgcpolicy:nogc and still got a core.

pshipton commented

It seems to work fine with -Xjit:optlevel=cold or warm
@dsouzai are there other JIT options worth trying to narrow it down?

pshipton commented

Running with -Xjit:disableinlining changes things up. In one run I got a core right way before getting any output. In another run I got Invalid JIT return address 00001D1D00001D1D in 0000000000017200 and then an assertion in swalk.c

pshipton commented

I created a vlog file from a crashing run. Then I tried excluding the hot or higher methods one by one. By using the following as a limitfile, the testcase works.

vlog1.txt

The following is what I disabled to get it working.
- (hot) Test.vMeth1(I)V @ 00007F83658F9B94-00007F83658FCAF0 MethodInProgress - Q_SZ=12 Q_SZI=12 QW=63 j9m=0000000000157A00 bcsz=731 DLT@493 compThreadID=0 CpuLoad=0%(0%avg) JvmCpu=181%

dsouzai commented

Thanks @pshipton.

I verified that with

./0.33/jdk8u342-b03/bin/java -Xshareclasses:none -Xmx1G '-Xjit:disableDynamicLoopTransfer,{Test.vMeth1(I)V}(optLevel=warm)' Test

not only do we not crash, but we also stop hanging.

If I do

./0.33/jdk8u342-b03/bin/java -Xshareclasses:none -Xmx1G '-Xjit:disableDynamicLoopTransfer,{Test.vMeth1(I)V}(optLevel=hot)' Test

or if I do optLevel=veryHot or optLevel=scorching I see the crash or assert Peter mentioned above.

@0xdaryl given that this doesn't look like a control issue anymore and also since I'm only around tomorrow for a half day and on vacation all of next week, we should transfer this to someone who can take a look more actively.

0xdaryl commented

@a7ehuo : could you take over the investigation of this please?

  • 👍1
0xdaryl commented

This is not a 0.33 regression. The hang is reproducible at least as far back as 0.24 on JDK11.

a7ehuo commented

I'm seeing different kinds of crashes including crash at samplerThreadProc happen randomly. Two crashes that happen most so far are:

(1) Core dump shows it crashed in samplerThreadProc [1]

As mentioned previously, I'm also seeing crash output shows one thing, the core shows it's in samplerThreadProc. So far it's always the linkNext (0x13c300) from IProfiler (j9vmthread 0x00040500) thread that is already invalid. There is no j9vmthread 0x13c300 on the dumped thread list [2]. However, somehow 0x13c300 can still be cast as J9VMThread. When looping through threads, The linkNext from 0x13c300 is 0x4050000000000 which is invalid and cannot be cast into J9VMThread

(2) Run test in gdb and got a crash in classHashGetName [3]

It crashed when it tries to get rom class for "java/lang/Runnable;". It looks to me the class is not initialized yet (initializeStatus = 0x00144F1800000000) [4]. I saw a comment for jitGetClassFromUTF8 saying "gets the VM class, provided it is properly initialized". @pshipton, for this second crash, I wonder if there should be some kind of defensive code in classHashGetName to check if a class is initialized before dereferencing ramClass pointer.

[1]

---- from core dump ---- 
#9  <signal handler called>
#10 0x00007f7ed9f4ee97 in raise () from /lib/x86_64-linux-gnu/libc.so.6
#11 0x00007f7ed9f50801 in abort () from /lib/x86_64-linux-gnu/libc.so.6
#12 0x00007f7ed8450e1b in mainSynchSignalHandler (signal=11, sigInfo=0x7f7eb50790f0, contextInfo=0x7f7eb5078fc0)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/omr/port/unix/omrsignal.c:1196
#13 <signal handler called>
#14 samplerThreadProc (entryarg=0x7f7ed40c46a0)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/compiler/control/HookedByTheJit.cpp:6150
#15 0x00007f7ed8c513a2 in thread_wrapper (arg=0x7f7ed44e7640)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/omr/thread/common/omrthread.c:1724
#16 0x00007f7ed98d76db in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#17 0x00007f7eda03188f in clone () from /lib/x86_64-linux-gnu/libc.so.6

(gdb) fr 14
#14 samplerThreadProc (entryarg=0x7f7ed40c46a0)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/compiler/control/HookedByTheJit.cpp:6150
6150	            if (!currentThread->inNative)

(gdb) print currentThread
$1 = (J9VMThread *) 0x4050000000000

(gdb) print entryarg
$2 = (void *) 0x7f7ed40c46a0

(gdb) print ((J9JITConfig *) entryarg)->javaVM->mainThread
$3 = (J9VMThread *) 0x1aa00


--- from console output ---

----------- Stack Backtrace -----------
resolveStaticMethodRefInto+0x17a (0x00007F7ED8ED16EA [libj9vm29.so+0x736ea])
resolveStaticMethodRef+0x22 (0x00007F7ED8ED19B2 [libj9vm29.so+0x739b2])
_ZN19TR_ResolvedJ9Method23getResolvedStaticMethodEPN2TR11CompilationEiPb+0x111 (0x00007F7ED24092D1 [libj9jit29.so+0x1f52d1]) //<---- TR_ResolvedJ9Method::getResolvedStaticMethod(TR::Compilation*, int, bool*)

_ZN2J920SymbolReferenceTable30findOrCreateStaticMethodSymbolEPN2TR20ResolvedMethodSymbolEi+0x2a (0x00007F7ED23351AA [libj9jit29.so+0x1211aa])
_ZN24TR_J9ByteCodeIlGenerator15genInvokeStaticEi+0x21 (0x00007F7ED24AF4B1 [libj9jit29.so+0x29b4b1])
_ZN24TR_J9ByteCodeIlGenerator6walkerEPN2TR5BlockE+0x1694 (0x00007F7ED24B2594 [libj9jit29.so+0x29e594])
_ZN24TR_J9ByteCodeIlGenerator18genILFromByteCodesEv+0x209 (0x00007F7ED2493659 [libj9jit29.so+0x27f659])
_ZN24TR_J9ByteCodeIlGenerator5genILEv+0x56 (0x00007F7ED2495556 [libj9jit29.so+0x281556])
_ZN3OMR20ResolvedMethodSymbol5genILEP11TR_FrontEndPN2TR11CompilationEPNS3_20SymbolReferenceTableERNS3_12IlGenRequestE+0x2a9 (0x00007F7ED276CB89 [libj9jit29.so+0x558b89])
_ZN3OMR11Compilation7compileEv+0x1dc (0x00007F7ED275296C [libj9jit29.so+0x53e96c])
_ZN2TR28CompilationInfoPerThreadBase7compileEP10J9VMThreadPNS_11CompilationEP17TR_ResolvedMethodR11TR_J9VMBaseP19TR_OptimizationPlanRKNS_16SegmentAllocatorE+0x4bf (0x00007F7ED235D88F [libj9jit29.so+0x14988f])
_ZN2TR28CompilationInfoPerThreadBase14wrappedCompileEP13J9PortLibraryPv+0x314 (0x00007F7ED235E8D4 [libj9jit29.so+0x14a8d4])
omrsig_protect+0x1e3 (0x00007F7ED8451AD3 [libj9prt29.so+0x29ad3])
_ZN2TR28CompilationInfoPerThreadBase7compileEP10J9VMThreadP21TR_MethodToBeCompiledRN2J917J9SegmentProviderE+0x309 (0x00007F7ED235C019 [libj9jit29.so+0x148019])
_ZN2TR24CompilationInfoPerThread12processEntryER21TR_MethodToBeCompiledRN2J917J9SegmentProviderE+0x1c0 (0x00007F7ED235C660 [libj9jit29.so+0x148660])
_ZN2TR24CompilationInfoPerThread14processEntriesEv+0x3b3 (0x00007F7ED235B183 [libj9jit29.so+0x147183])
_ZN2TR24CompilationInfoPerThread3runEv+0x42 (0x00007F7ED235B662 [libj9jit29.so+0x147662])
_Z30protectedCompilationThreadProcP13J9PortLibraryPN2TR24CompilationInfoPerThreadE+0x82 (0x00007F7ED235B712 [libj9jit29.so+0x147712])
omrsig_protect+0x1e3 (0x00007F7ED8451AD3 [libj9prt29.so+0x29ad3])
_Z21compilationThreadProcPv+0x1d2 (0x00007F7ED235BB52 [libj9jit29.so+0x147b52])
thread_wrapper+0x162 (0x00007F7ED8C513A2 [libj9thr29.so+0xe3a2])
start_thread+0xdb (0x00007F7ED98D76DB [libpthread.so.0+0x76db])
clone+0x3f (0x00007F7EDA03188F [libc.so.6+0x12188f])
---------------------------------------
JVMDUMP039I Processing dump event "gpf", detail "" at 2022/06/21 13:16:44 - please wait.
_ZN2J913Recompilation12sampleMethodEPvP11TR_FrontEndS1_iS1_S1_i+0x2c (0x00007F7ED267285C [libj9jit29.so+0x45e85c]) //<---- J9::Recompilation::sampleMethod(void*, TR_FrontEnd*, void*, int, void*, void*, int)

jitMethodSampleInterrupt+0x3eb (0x00007F7ED2370F1B [libj9jit29.so+0x15cf1b])
dispatchAsyncEvents+0xc7 (0x00007F7ED8E9ED77 [libj9vm29.so+0x40d77])
javaCheckAsyncMessages+0xa8 (0x00007F7ED8E75648 [libj9vm29.so+0x17648])
_ZN32VM_BytecodeInterpreterCompressed3runEP10J9VMThread+0x281 (0x00007F7ED8EF00D1 [libj9vm29.so+0x920d1])
bytecodeLoopCompressed+0xad (0x00007F7ED8EEFE3D [libj9vm29.so+0x91e3d])
 (0x00007F7ED8FA8B92 [libj9vm29.so+0x14ab92])
---------------------------------------

[2]

gdb) p ((J9VMThread *) 0x1aa00)->linkNext
$4 = (J9VMThread *) 0x1e600
(gdb) p ((J9VMThread *)0x1e600)->linkNext
$5 = (J9VMThread *) 0x22300
(gdb) p ((J9VMThread *)0x22300)->linkNext
$6 = (J9VMThread *) 0x25f00
(gdb)  p ((J9VMThread *)0x25f00)->linkNext
$7 = (J9VMThread *) 0x29b00
(gdb)  p ((J9VMThread *)0x29b00)->linkNext
$8 = (J9VMThread *) 0x2d800
(gdb)  p ((J9VMThread *)0x2d800)->linkNext
$9 = (J9VMThread *) 0x31400
(gdb)  p ((J9VMThread *)0x31400)->linkNext
$10 = (J9VMThread *) 0x35000
(gdb)  p ((J9VMThread *)0x35000)->linkNext
$11 = (J9VMThread *) 0x38d00
(gdb)  p ((J9VMThread *)0x38d00)->linkNext
$12 = (J9VMThread *) 0x3c900
(gdb) p ((J9VMThread *)0x3c900)->linkNext
$13 = (J9VMThread *) 0x40500
(gdb) p ((J9VMThread *)0x40500)->linkNext //<---  IProfiler
$14 = (J9VMThread *) 0x13c300  //<---- no such thread
(gdb)  p ((J9VMThread *)0x13c300)->linkNext
$15 = (J9VMThread *) 0x4050000000000 //<----- invalid 


> !threads
	!stack 0x0001aa00	!j9vmthread 0x0001aa00	!j9thread 0x7f7ed4007b40	tid 0xf6f (3951) // (main)
	!stack 0x0001e600	!j9vmthread 0x0001e600	!j9thread 0x7f7ed40d5540	tid 0xf71 (3953) // (JIT Compilation Thread-000 Suspended)
	!stack 0x00022300	!j9vmthread 0x00022300	!j9thread 0x7f7ed40d5ab8	tid 0xf72 (3954) // (JIT Compilation Thread-001)
	!stack 0x00025f00	!j9vmthread 0x00025f00	!j9thread 0x7f7ed40d6690	tid 0xf73 (3955) // (JIT Compilation Thread-002 Suspended)
	!stack 0x00029b00	!j9vmthread 0x00029b00	!j9thread 0x7f7ed40d6c08	tid 0xf74 (3956) // (JIT Compilation Thread-003 Suspended)
	!stack 0x0002d800	!j9vmthread 0x0002d800	!j9thread 0x7f7ed40d7ba0	tid 0xf75 (3957) // (JIT Compilation Thread-004 Suspended)
	!stack 0x00031400	!j9vmthread 0x00031400	!j9thread 0x7f7ed40d8118	tid 0xf76 (3958) // (JIT Compilation Thread-005 Suspended)
	!stack 0x00035000	!j9vmthread 0x00035000	!j9thread 0x7f7ed40d90b0	tid 0xf77 (3959) // (JIT Compilation Thread-006 Suspended)
	!stack 0x00038d00	!j9vmthread 0x00038d00	!j9thread 0x7f7ed40d9628	tid 0xf78 (3960) // (JIT Diagnostic Compilation Thread-007 Suspended)
	!stack 0x0003c900	!j9vmthread 0x0003c900	!j9thread 0x7f7ed44e7640	tid 0xf79 (3961) // (JIT-SamplerThread)
	!stack 0x00040500	!j9vmthread 0x00040500	!j9thread 0x7f7ed44e7bb8	tid 0xf7a (3962) // (IProfiler)
Problem running command:

> !j9vmthread 0x0003c900
...
	0x190: struct J9VMThread* linkNext = !j9vmthread 0x0000000000040500
...
> !j9vmthread 0x0000000000040500
...
	0x190: struct J9VMThread* linkNext = !j9vmthread 0x000000000013C300
...
> !j9vmthread 0x000000000013C300
...
	0x190: struct J9VMThread* linkNext = !j9vmthread 0x0004050000000000

[3]

[Switching to Thread 0x7fffd4ba5700 (LWP 3565)]
0x00007ffff6782624 in classHashGetName (nameLength=0x7fffd4b97c00, name=<synthetic pointer>, entry=0x7ffff05c1210)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/vm/KeyHashTable.c:87
87			J9UTF8 *className = J9ROMCLASS_CLASSNAME(entry->ramClass->romClass);
(gdb) bt
#0  0x00007ffff6782624 in classHashGetName (nameLength=0x7fffd4b97c00, name=<synthetic pointer>, entry=0x7ffff05c1210)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/vm/KeyHashTable.c:87
#1  classHashEqualFn (tableNode=0x7ffff05c1210, queryNode=0x7fffd4b97ca0, userData=0x7ffff000f380)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/vm/KeyHashTable.c:122
#2  0x00007ffff6881aa7 in hashTableFindNodeInList (head=<optimized out>, entry=<optimized out>, table=<optimized out>)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/omr/util/hashtable/hashtable.c:482
#3  hashTableFind (table=0x7ffff00bb7d0, entry=0x7fffd4b97ca0)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/omr/util/hashtable/hashtable.c:459
#4  0x00007ffff6783217 in hashClassTableAt (classLoader=classLoader@entry=0x7ffff0098988, 
    className=className@entry=0x7fffefb87033 "java/lang/Runnable;", classNameLength=classNameLength@entry=18)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/vm/KeyHashTable.c:330
#5  0x00007ffff6747ffe in loadNonArrayClass (exception=<synthetic pointer>, options=4, classLoader=0x7ffff0098988, 
    classNameLength=18, className=0x7fffefb87033 "java/lang/Runnable;", j9module=0x0, vmThread=0x1e600)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/vm/classsupport.c:1013
#6  internalFindClassInModule (vmThread=0x1e600, j9module=0x0, className=0x7fffefb87033 "java/lang/Runnable;", 
    classNameLength=18, classLoader=0x7ffff0098988, options=4)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/vm/classsupport.c:1148
#7  0x00007fffefb54e09 in jitGetClassInClassloaderFromUTF8 (vmStruct=<optimized out>, classLoader=<optimized out>, 
    signatureChars=<optimized out>, signatureLength=<optimized out>)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/jit_vm/ctsupport.cpp:70
#8  0x00007fffef3e5fe0 in TR_J9VM::getClassFromSignature (this=0x7fffd00078d0, sig=0x7fffefb87033 "java/lang/Runnable;", 
    sigLength=18, constantPool=0x1b7370)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/compiler/env/VMJ9.cpp:7235
#9  0x00007fffef2dae3b in J9::Compilation::getCachedClassPointer (this=<optimized out>, 
    which=which@entry=J9::Compilation::RUNNABLE_CLASS_POINTER)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/compiler/compile/J9Compilation.cpp:1452
#10 0x00007fffef2daf8a in J9::Compilation::getRunnableClassPointer (this=<optimized out>)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/compiler/compile/J9Compilation.cpp:1399
#11 0x00007fffef4748e1 in TR_EscapeAnalysis::createCandidateIfValid (this=this@entry=0x7fffcf043220, 
    node=node@entry=0x7fffcf0a3020, classInfo=@0x7fffd4b97e88: 0x0, foundUserAnnotation=foundUserAnnotation@entry=false)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/compiler/optimizer/EscapeAnalysis.cpp:1722
#12 0x00007fffef474ca1 in TR_EscapeAnalysis::findCandidates (this=this@entry=0x7fffcf043220)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/compiler/optimizer/EscapeAnalysis.cpp:1636
#13 0x00007fffef4977c6 in TR_EscapeAnalysis::performAnalysisOnce (this=this@entry=0x7fffcf043220)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/compiler/optimizer/EscapeAnalysis.cpp:673
#14 0x00007fffef49a0f8 in TR_EscapeAnalysis::perform (this=0x7fffcf043220)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/compiler/optimizer/EscapeAnalysis.cpp:320
#15 0x00007fffef901147 in OMR::Optimizer::performOptimization (this=this@entry=0x7fffcf0c0760, 
    optimization=optimization@entry=0x7fffefc34968 <eachEscapeAnalysisPassOpts+8>, firstOptIndex=firstOptIndex@entry=0, 
    lastOptIndex=lastOptIndex@entry=2147483647, doTiming=doTiming@entry=0)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/omr/compiler/optimizer/OMROptimizer.cpp:2053
#16 0x00007fffef901709 in OMR::Optimizer::performOptimization (this=this@entry=0x7fffcf0c0760, 
    optimization=optimization@entry=0x7fffefc349c0 <cheapObjectAllocationOpts>, firstOptIndex=firstOptIndex@entry=0, 
    lastOptIndex=lastOptIndex@entry=2147483647, doTiming=doTiming@entry=0)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/omr/compiler/optimizer/OMROptimizer.cpp:1600
#17 0x00007fffef901709 in OMR::Optimizer::performOptimization (this=this@entry=0x7fffcf0c0760, 
    optimization=optimization@entry=0x7fffefc348f8 <cheapGlobalValuePropagationOpts+56>, 
    firstOptIndex=firstOptIndex@entry=0, lastOptIndex=lastOptIndex@entry=2147483647, doTiming=doTiming@entry=0)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/omr/compiler/optimizer/OMROptimizer.cpp:1600
#18 0x00007fffef901709 in OMR::Optimizer::performOptimization (this=this@entry=0x7fffcf0c0760, 
    optimization=optimization@entry=0x7fffefbc5d60 <cheapWarmStrategyOpts+96>, firstOptIndex=firstOptIndex@entry=0, 
--Type <RET> for more, q to quit, c to continue without paging--
    lastOptIndex=lastOptIndex@entry=2147483647, doTiming=doTiming@entry=0)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/omr/compiler/optimizer/OMROptimizer.cpp:1600
#19 0x00007fffef902a0b in OMR::Optimizer::optimize (this=0x7fffcf0c0760)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/omr/compiler/optimizer/OMROptimizer.cpp:1128
#20 0x00007fffef6f4ab7 in OMR::Compilation::performOptimizations (this=this@entry=0x7fffcf000000)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/omr/compiler/compile/OMRCompilation.cpp:1267
#21 0x00007fffef6fa0b5 in OMR::Compilation::compile (this=this@entry=0x7fffcf000000)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/omr/compiler/compile/OMRCompilation.cpp:1064
#22 0x00007fffef30488f in TR::CompilationInfoPerThreadBase::compile (this=this@entry=0x7fffe4bbb070, 
    vmThread=vmThread@entry=0x1e600, compiler=<optimized out>, compilee=compilee@entry=0x7fffd4ba1a28, vm=..., 
    optimizationPlan=<optimized out>, scratchSegmentProvider=...)

[4]


(gdb) print entry
$1 = (KeyHashTableClassEntry *) 0x7ffff05c1210

(gdb) print entry->ramClass
$2 = (J9Class *) 0x147200
(gdb) print entry->ramClass->romClass
$3 = (struct J9ROMClass *) 0x1471b000007fff
(gdb) print *0x1471b000007fff
Cannot access memory at address 0x1471b000007fff

> !j9class 0x147200
J9Class at 0x147200 {
  Fields for J9Class:
	0x0: UDATA eyecatcher = 0x9D66F1F800000000 (-7104725314676195328)
	0x8: struct J9ROMClass* romClass = !j9romclass 0x001471B000007FFF
	0x10: void** superclasses = !j9x 0x001E000100000000
	0x18: UDATA classDepthAndFlags = 0x0000000000000000 (0)
	0x20: U32 classDepthWithFlags = 0x00000000 (0)
	0x24: U32 classFlags = 0xF0098988 (4027156872)
	0x28: struct J9ClassLoader* classLoader = !j9classloader 0xC002AA0800007FFF
	0x30: struct J9Object* classObject = !j9object 0x0000000100000000<FAULT>
	0x38: volatile UDATA initializeStatus = 0x00144F1800000000 (5716464032022528) <------- not initialized!
...
a7ehuo commented

I'm still investigating. I saw the issue even with an older build back to January. Not sure if it should be a blocker now for the 0.33 release.

Meanwhile, Most of the times, instead of a crash, now I'm seeing a hang which was also reported earlier. It seems stuck running Test.vMeth1(I)V at scorching [1]. I used perf to look at the hot instructions [2]. However, the sequence of the instructions shown in perf.data.jitted don't match any instruction sequence in the compiled log.

[1]

/root/home/ahuo/src/linux/tools/perf/perf record -k 1 -e cycles /root/home/ahuo/src/openj9-openjdk-jdk11/build/linux-x86_64-normal-server-release/images/jdk/bin/java -Xmx1G -agentpath:/root/home/ahuo/src/linux/tools/perf/libperf-jvmti.so '-Xjit:disableInterpreterProfilingThread,disableDynamicLoopTransfer,verbose={compileStart|compileEnd|sampling|hwprofiler|recompile},vlog=logs/vlog,{Test.vMeth1(I)V}(traceFull,traceILGen,traceCG,log=logs/log)' Test

/root/home/ahuo/src/linux/tools/perf/perf inject -i perf.data --jit -o perf.data.jitted

/root/home/ahuo/src/linux/tools/perf/perf report -I perf.data.jitted

Overhead  Command          Shared Object        Symbol
  95.19%  main             jitted-11216-353.so  [.] Test.vMeth1(int)
   0.34%  main             libj9vm29.so         [.] VM_BytecodeInterpreterCompressed::run
   0.29%  JIT Compilation  libc-2.27.so         [.] vfprintf

[2]

  0.00 │        nop                                                                                                         ▒
  1.15 │1278:   lea         rcx,[rsp+0x38]                                                                                  ▒
  1.08 │        mov         eax,DWORD PTR [rcx+rbx*1+0x0]                                                                   ▒
 12.78 │        cmp         eax,DWORD PTR [rbx+rcx*1+0x4]                                                                   ▒
  0.00 │      ↓ jg          1e05                                                                                            ▒
  1.84 │        add         r8d,0x1                                                                                         ▒
  6.74 │128f:   sub         rbx,0xfffffffffffffffc                                                                          ▒
  1.43 │        mov         rax,QWORD PTR [rsp+0xb8]                                                                        ▒
  9.99 │        add         rax,0x1                                                                                         ▒
  2.26 │        mov         QWORD PTR [rsp+0xb8],rax                                                                        ▒
 14.03 │        mov         ecx,r11d                                                                                        ▒
  0.75 │        cmp         rax,rcx                                                                                         ▒
  0.00 │      ↑ jl          1278
a7ehuo commented

With the following combination of -Xjit options, now I could sort of reliably reproduce the "Invalid JIT return address ..." failure.

-Xjit:limit={Test.vMeth1(I)V},disableinlining,disableDynamicLoopTransfer,inhibitRecompilation,disableLoopStrider,{*}(optLevel=hot,traceFull,traceILGen,traceCG,log=logs/jitlog)
jitlog.7107.42123.20220706.141523.7107.log

The stack walk happened because of jitHandleNullPointerExceptionTrap. Based on the PC for JIT stack frame (0x00007FFFD4E3B441), I believe it tries to access the boolean array bArr which is not valid any more on the second iteration of the outer loop. bArr is supposed to be saved at temp slot $rsp+0x100. So far I haven't found any instructions that corrupt this temp slot.

            for (i15 = 1; i15 < 4; ++i15) {
                i3 = i15;
                for (i17 = 1; i17 < 2; ++i17) {
                    bArr[i17] = Test.bFld;  // block_9: bArr is invalid on the second iteration of the outer loop

0x7fffd4e3b438 00000404 [0x7fffcfc2d940] 48 8b 8c 24 00 01 00 00            mov	rcx, qword ptr [rsp+0x100]		# L8RegMem, SymRef  <temp slot 61>[#675  Auto +256] [flags 0x4007 0x0 ]
0x7fffd4e3b440 0000040c [0x7fffcfc2d9e0] 88 41 11                           mov	byte ptr [rcx+0x11], al		# S1MemReg, SymRef  <array-shadow>[#226  Shadow +17] [flags 0x80000601 0x0 ]

Thread 2 "main" hit Breakpoint 1, 0x00007fffd4e3b435 in ?? ()
(gdb) x ($rsp+0x100)
0x110d30:	0xffe7e2d0

Thread 2 "main" hit Breakpoint 1, 0x00007fffd4e3b435 in ?? ()
(gdb) x ($rsp+0x100)
0x110d30:	0x00001d1d

> whatis 0xffe7e2d0
	heap #1 - name: Generational@7ffff0092bd0
		0xffe7e2d0 is within heap segment: ffc30000 -- 100000000
		0xffe7e2d0 is the start of an object of type [Z
> whatis 0x00001d1d
	heap #1 - name: Generational@7ffff0092bd0
		0x1d1d is not within this heap.

------------------------------
 n335n    (  0)  bstorei  <array-shadow>[#226  Shadow] [flags 0x80000601 0x0 ] (cannotOverflow storeAlreadyEvaluated )  [0x7fffcf075870] bci=[-1,210,135] rc=0 vc=11 vn=- li=9 udi=- nc=2 flg=0x1000
 n334n    (  0)    aladd (X>=0 internalPtr sharedMemory )                                             [0x7fffcf075820] bci=[-1,210,135] rc=0 vc=11 vn=- li=9 udi=- nc=2 flg=0x8100
 n324n    (  0)      aload  <temp slot 61>[#512  Auto] [flags 0x4007 0x0 ] (in &GPR_0897) (X!=0 sharedMemory )  [0x7fffcf075500] bci=[-1,203,135] rc=0 vc=11 vn=- li=9 udi=55488 nc=0 flg=0x4
 n333n    (  0)      lconst 17 (highWordZero X!=0 X>=0 cannotOverflow )                               [0x7fffcf0757d0] bci=[-1,210,135] rc=0 vc=11 vn=- li=9 udi=- nc=0 flg=0x5104
 n779n    (  0)    i2b (in GPR_0896) (X>=0 unneededConv lazyClobber cannotOverflow )                  [0x7fffcf07e330] bci=[-1,0,113] rc=0 vc=11 vn=- li=9 udi=54752 nc=1 flg=0x3500
 n778n    (  0)      iand (in GPR_0896) (X>=0 cannotOverflow )                                        [0x7fffcf07e2e0] bci=[-1,0,113] rc=0 vc=11 vn=- li=9 udi=54752 nc=2 flg=0x1100
 n777n    (  0)        bu2i (X>=0 unneededConv )                                                      [0x7fffcf07e290] bci=[-1,0,113] rc=0 vc=11 vn=- li=9 udi=- nc=1 flg=0x500
 n327n    (  0)          i2b (in GPR_0896) (unneededConv )                                            [0x7fffcf0755f0] bci=[-1,210,135] rc=0 vc=11 vn=- li=9 udi=54752 nc=1 flg=0x400
 n326n    (  0)            iload  Test.bFld Z[#432  Static] [flags 0x301 0x0 ] (in GPR_0896) (cannotOverflow )  [0x7fffcf0755a0] bci=[-1,207,135] rc=0 vc=11 vn=- li=9 udi=54752 nc=0 flg=0x1000
 n776n    (  1)        iconst 1 (X!=0 X>=0 )                                                          [0x7fffcf07e240] bci=[-1,0,113] rc=1 vc=11 vn=- li=9 udi=- nc=0 flg=0x104
------------------------------

 [0x7fffcfc2d660]	mov	GPR_0896, dword ptr [$0x000000000018fb40]		# L4RegMem, SymRef  Test.bFld Z[#673  Static] [flags 0x301 0x0 ]
 [0x7fffcfc2d700]	and	GPR_0896, 0x00000001	# AND4RegImms
 [0x7fffcfc2d940]	mov	&GPR_0897, qword ptr [vfp]		# L8RegMem, SymRef  <temp slot 61>[#675  Auto] [flags 0x4007 0x0 ]
 [0x7fffcfc2d9e0]	mov	byte ptr [&GPR_0897+0x11], GPR_0896		# S1MemReg, SymRef  <array-shadow>[#226  Shadow +17] [flags 0x80000601 0x0 ]

#14 0x00007ffff67a0ff3 in invalidJITReturnAddress (walkState=<optimized out>)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/vm/swalk.c:1602
#15 0x00007fffefb28385 in jitWalkStackFrames (walkState=0x1ad00)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/codert_vm/jswalk.c:283
#16 0x00007ffff679ff13 in walkStackFrames (currentThread=<optimized out>, walkState=0x1ad00)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/vm/swalk.c:346
#17 0x00007ffff67c4c91 in VM_BytecodeInterpreterCompressed::inlThrowableFillInStackTrace (_pc=<optimized out>, 
    _sp=<optimized out>, this=<optimized out>)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/vm/BytecodeInterpreter.hpp:3068
#18 VM_BytecodeInterpreterCompressed::run (this=0x1c69, this@entry=0x7ffff7fe65f0, vmThread=0x0)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/vm/BytecodeInterpreter.hpp:10269
#19 0x00007ffff67b2e3d in bytecodeLoopCompressed (currentThread=<optimized out>)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/vm/BytecodeInterpreter.inc:112
--Type <RET> for more, q to quit, c to continue without paging--
#20 0x00007ffff686bb92 in c_cInterpreter ()
    at /root/home/ahuo/src/openj9-openjdk-jdk11/build/linux-x86_64-normal-server-release/vm/runtime/vm/xcinterp.s:168
#21 0x00007ffff673ca5d in internalSendExceptionConstructor (currentThread=0x7ffff7fe6720, currentThread@entry=0x1aa00, 
    exceptionClass=0x6b900, exception=0xffec8ab8, detailMessage=<optimized out>, detailMessage@entry=0x0, 
    constructorIndex=<optimized out>, constructorIndex@entry=0)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/vm/callin.cpp:624
#22 0x00007ffff6754e19 in internalSetCurrentExceptionWithCause (currentThread=0x1aa00, exceptionNumber=<optimized out>, 
    detailMessage=0x0, utfMessage=<optimized out>, cause=<optimized out>)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/vm/exceptionsupport.c:725
#23 0x00007ffff6755475 in setCurrentExceptionWithUtfCause (currentThread=<optimized out>, exceptionNumber=<optimized out>, 
    detailMessage=<optimized out>, utfMessage=<optimized out>, cause=<optimized out>)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/vm/exceptionsupport.c:807
#24 0x00007fffefb18213 in setCurrentExceptionFromJIT (detailMessage=0x0, exceptionNumber=6, currentThread=0x1aa00)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/codert_vm/cnathelp.cpp:384
#25 old_slow_jitHandleNullPointerExceptionTrap (currentThread=0x1aa00)
    at /root/home/ahuo/src/openj9-openjdk-jdk11/openj9/runtime/codert_vm/cnathelp.cpp:1547
#26 0x00007fffefb39115 in jitHandleNullPointerExceptionTrap ()
    at /root/home/ahuo/src/openj9-openjdk-jdk11/build/linux-x86_64-normal-server-release/vm/runtime/codert_vm/xnathelp.s:10424
#27 0x000000000001aa00 in ?? ()
#28 0x00007ffff7fe7a40 in ?? ()
#29 0x0000000000000001 in ?? ()
#30 0x0000005800000058 in ?? ()
#31 0x00001d1d00001d1d in ?? ()
#32 0x000000000001aa00 in ?? ()
#33 0x00007ffff7fe70a0 in ?? ()
#34 0x0000000000000001 in ?? ()
#35 0x000000000001aa00 in ?? ()
#36 0x00007ffff73b2895 in ?? () from /lib/x86_64-linux-gnu/libdl.so.2
#37 0x00007ffff7fe6b00 in ?? ()
#38 0x0000000000000001 in ?? ()
#39 0x0000000000000058 in ?? ()
#40 0x0000000000000012 in ?? ()
#41 0x0000000000000006 in ?? ()
#42 0x00000000ffec2980 in ?? ()
#43 0x00000000ffe7e2d0 in ?? ()
#44 0x000000000000015c in ?? ()
#45 0xc1bbef5411000000 in ?? ()
#46 0x0000000000000000 in ?? ()
0xdaryl commented

We won't be able to get to the bottom of this for 0.35. Moving to 0.36.

0xdaryl commented

Moving to 0.38 release.

0xdaryl commented

No change on the status of this one. Moving out to 0.40.

a7ehuo commented

Verified the test with Java 8, 11, 17 release 0.40.0. The crash is no longer reproducible.

Eclipse OpenJ9 VM (build openj9-0.40.0, JRE 1.8.0 Linux amd64-64-Bit Compressed References 20230810_729 (JIT enabled, AOT enabled)
OpenJ9   - d12d10c9e
OMR      - e80bff83b
JCL      - c4d2c2bafb based on jdk8u382-b05)

Eclipse OpenJ9 VM 11.0.20.1 (build openj9-0.40.0, JRE 11 Linux amd64-64-Bit Compressed References 20230824_836 (JIT enabled, AOT enabled)
OpenJ9   - d12d10c9e
OMR      - e80bff83b
JCL      - 0880e8df04 based on jdk-11.0.20.1+1)

Eclipse OpenJ9 VM 17.0.8.1 (build openj9-0.40.0, JRE 17 Linux amd64-64-Bit Compressed References 20230824_549 (JIT enabled, AOT enabled)
OpenJ9   - d12d10c9e
OMR      - e80bff83b
JCL      - 8ecf238a124 based on jdk-17.0.8.1+1)

$ java -Xmx1G Test

i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,30235,-7361758
Test.iArrFld Test.dArrFld byArrFld = -6215,-4553228026621557456,0
iMeth_check_sum: -4333806183732943446
vMeth1_check_sum: 68973879509876838
vMeth_check_sum: 152689325288400263
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,24905,-14748646
Test.iArrFld Test.dArrFld byArrFld = -5870,-4553228026621557456,0
iMeth_check_sum: -8667612328627537193
vMeth1_check_sum: 137947759019753676
vMeth_check_sum: 305378650576800639
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,19575,-22135534
Test.iArrFld Test.dArrFld byArrFld = -13040,-4553228026621557456,0
iMeth_check_sum: 5445325600187420676
vMeth1_check_sum: 206921638529630514
vMeth_check_sum: 458067975865201016
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,14245,-29522422
Test.iArrFld Test.dArrFld byArrFld = -5158,-4553228026621557456,0
iMeth_check_sum: 1111519455292826929
vMeth1_check_sum: 275895518039507352
vMeth_check_sum: 610757301153601394
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,8915,-36909310
Test.iArrFld Test.dArrFld byArrFld = -11570,-4553228026621557456,0
iMeth_check_sum: -3222286689601766818
vMeth1_check_sum: 344869397549384190
vMeth_check_sum: 763446626442001773
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,3585,-44296198
Test.iArrFld Test.dArrFld byArrFld = -8111,-4553228026621557456,0
iMeth_check_sum: -7556092834496360565
vMeth1_check_sum: 413843277059261028
vMeth_check_sum: 916135951730402153
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,-1745,-51683086
Test.iArrFld Test.dArrFld byArrFld = -9792,-4553228026621557456,0
iMeth_check_sum: 6556845094318597304
vMeth1_check_sum: 482817156569137866
vMeth_check_sum: 1068825277018802534
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,-7075,-59069974
Test.iArrFld Test.dArrFld byArrFld = -9811,-4553228026621557456,0
iMeth_check_sum: 2223038949424003557
vMeth1_check_sum: 551791036079014704
vMeth_check_sum: 1221514602307202916
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,-12405,-66456862
Test.iArrFld Test.dArrFld byArrFld = -8825,-4553228026621557456,0
iMeth_check_sum: -2110767195470590190
vMeth1_check_sum: 620764915588891542
vMeth_check_sum: 1374203927595603299
i i1 i26 = 10,2,228
i27 i28 i29 = -32086,5,62030
i30 i31 i32 = -13,-11445,-12
i33 f5 d4 = -11445,1189327188,-4610980709689745411
i34 i35 i36 = 192,23,-63490
i37 i38 i39 = 2,233,-167
iArr lArr iArr1 = 3133,-79021568,-15872
bArr1 fArr2 dArr1 = 5590,-4527139448580505600,4684513218568894638
Test.instanceCount Test.bFld Test.iFld = 1,1,52991
Test.byFld Test.sFld Test.lArrFld = 1,-17735,-73843750
Test.iArrFld Test.dArrFld byArrFld = -10849,-4553228026621557456,0
iMeth_check_sum: -6444573340365183937
vMeth1_check_sum: 689738795098768380
vMeth_check_sum: 1526893252884003683