eclipse-openj9 / openj9

Eclipse OpenJ9: A Java Virtual Machine for OpenJDK that's optimized for small footprint, fast start-up, and high throughput. Builds on Eclipse OMR (https://github.com/eclipse/omr) and combines with the Extensions for OpenJDK for OpenJ9 repo.
Other
3.27k stars 721 forks source link

JDK11 JIT Server : cmdLineTester_jvmtitests_hcr_OSRG_nongold_2 ** ASSERTION FAILED ** at jswalk.c:538: ((0 )) #9024

Closed JasonFengJ9 closed 3 years ago

JasonFengJ9 commented 4 years ago

Failure link

From an internal build Test_openjdk11_j9_extended.functional_x86-64_linux_jit_Nightly/32/

23:00:01  openjdk version "11.0.7-internal" 2020-04-14
23:00:01  OpenJDK Runtime Environment (build 11.0.7-internal+0-adhoc.jenkins.BuildJDK11x86-64linuxjitNightly)
23:00:01  Eclipse OpenJ9 VM (build ibm_sdk-0852f80a4a, JRE 11 Linux amd64-64-Bit Compressed References 20200328_33 (JIT enabled, AOT enabled)
23:00:01  OpenJ9   - 0852f80a4a
23:00:01  OMR      - e9bed7888
23:00:01  JCL      - 34c3dd7d55b based on jdk-11.0.7+9)

Optional info

Failure output (captured from console output)

Testing: rc013
Test start time: 2020/03/28 22:43:41 Pacific Standard Time
Running command: "/home/jenkins/workspace/Test_openjdk11_j9_extended.functional_x86-64_linux_jit_Nightly/openjdkbinary/j2sdk-image/bin/java" -XX:+UseJITServer -Xcompressedrefs -Xcompressedrefs -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation  -Xdump    -agentlib:jvmtitest=test:rc013 -cp "/home/jenkins/workspace/Test_openjdk11_j9_extended.functional_x86-64_linux_jit_Nightly/openjdk-tests/TKG/../../jvmtest/functional/cmdLineTests/jvmtitests/jvmtitest.jar:/home/jenkins/workspace/Test_openjdk11_j9_extended.functional_x86-64_linux_jit_Nightly/openjdk-tests/TKG/../TKG/lib/asm-all.jar" com.ibm.jvmti.tests.util.TestRunner
Time spent starting: 2 milliseconds
Time spent executing: 5671 milliseconds
Test result: FAILED
Output from test:
 [ERR] JITServer is currently a technology preview. Its use is not yet supported
 [ERR] JVMCDRT000E Unable to locate JIT stack map - aborting VM
 [ERR] JVMCDRT001E Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V (00000000024821F0)
 [ERR] JVMCDRT002E Failing PC: 00007F3A98A191E3 (offset 0000000000000023), metaData = 00007F3A924C5278
 [ERR] 05:43:41.866 0x244aa00j9codertvm(j9ji.110    *   ** ASSERTION FAILED ** at jswalk.c:538: ((0 ))
 [ERR] JVMDUMP039I Processing dump event "traceassert", detail "" at 2020/03/28 22:43:41 - please wait.
 [ERR] JVMDUMP032I JVM requested System dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.functional_x86-64_linux_jit_Nightly/openjdk-tests/TKG/test_output_15854512416865/cmdLineTester_jvmtitests_hcr_OSRG_nongold_2/core.20200328.224341.11863.0001.dmp' in response to an event
 [ERR] JVMPORT030W /proc/sys/kernel/core_pattern setting "|/usr/libexec/abrt-hook-ccpp %s %c %p %u %g %t e" specifies that the core dump is to be piped to an external program.  Attempting to rename either core or core.11879.
 [ERR] 
 [ERR] JVMDUMP010I System dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.functional_x86-64_linux_jit_Nightly/openjdk-tests/TKG/test_output_15854512416865/cmdLineTester_jvmtitests_hcr_OSRG_nongold_2/core.20200328.224341.11863.0001.dmp
 [ERR] JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.functional_x86-64_linux_jit_Nightly/openjdk-tests/TKG/test_output_15854512416865/cmdLineTester_jvmtitests_hcr_OSRG_nongold_2/javacore.20200328.224341.11863.0002.txt' in response to an event
 [ERR] JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.functional_x86-64_linux_jit_Nightly/openjdk-tests/TKG/test_output_15854512416865/cmdLineTester_jvmtitests_hcr_OSRG_nongold_2/javacore.20200328.224341.11863.0002.txt
 [ERR] JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.functional_x86-64_linux_jit_Nightly/openjdk-tests/TKG/test_output_15854512416865/cmdLineTester_jvmtitests_hcr_OSRG_nongold_2/Snap.20200328.224341.11863.0003.trc' in response to an event
 [ERR] JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk11_j9_extended.functional_x86-64_linux_jit_Nightly/openjdk-tests/TKG/test_output_15854512416865/cmdLineTester_jvmtitests_hcr_OSRG_nongold_2/Snap.20200328.224341.11863.0003.trc
 [ERR] JVMDUMP013I Processed dump event "traceassert", detail "".
>> Success condition was not found: [Return code: 0]

To rebuild the failed tests in =https://hyc-runtimes-jenkins.swg-devops.com/job/Grinder, use the following links: https://hyc-runtimes-jenkins.swg-devops.com/job/Grinder/parambuild/?JDK_VERSION=11&JDK_IMPL=openj9&BUILD_LIST=functional&PLATFORM=x86-64_linux&TARGET=cmdLineTester_jvmtitests_hcr_OSRG_nongold_2

pshipton commented 4 years ago

@mpirvu fyi

a7ehuo commented 4 years ago

Reproduced once out of three runs. Looks similar to #8885.

Testing: rc012
Test start time: 2020/03/31 11:04:40 Pacific Standard Time
Running command: "/root/home/ahuo/src/openj9-openjdk-jdk11/build/linux-x86_64-normal-server-release/images/jdk/bin/java" -Xcoo
mpressedrefs -Xcompressedrefs -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkk
g.foo,launch=echo -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation  -XX:+UseJITServer  -Xdump    -agenn
tlib:jvmtitest=test:rc012 -cp "/root/home/ahuo/src/openjdk-tests/TKG/../../jvmtest/functional/cmdLineTests/jvmtitests/jvmtitee
st.jar:/root/home/ahuo/src/openjdk-tests/TKG/../TKG/lib/asm-all.jar" com.ibm.jvmti.tests.util.TestRunner
Time spent starting: 2 milliseconds
Time spent executing: 3395 milliseconds
Test result: FAILED
Output from test:
 [ERR] JITServer is currently a technology preview. Its use is not yet supported
 [ERR] JVMCDRT000E Unable to locate JIT stack map - aborting VM
 [ERR] JVMCDRT001E Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V (00000000000511F0)
 [ERR] JVMCDRT002E Failing PC: 00007F069F7011E3 (offset 0000000000000023), metaData = 00007F069D3BE278
 [ERR] 18:04:40.698 0x19a00j9codertvm(j9ji.110    *   ** ASSERTION FAILED ** at jswalk.c:538: ((0 ))
 [ERR] JVMDUMP039I Processing dump event "traceassert", detail "" at 2020/03/31 11:04:40 - please wait.
 [ERR] JVMDUMP032I JVM requested System dump using '/root/home/ahuo/src/openjdk-tests/TKG/test_output_15856775065777/cmdLineTT
ester_jvmtitests_hcr_OSRG_nongold_2/core.20200331.110440.13421.0001.dmp' in response to an event
 [ERR] JVMPORT030W /proc/sys/kernel/core_pattern setting "|/usr/share/apport/apport %p %s %c %d %P" specifies that the core dd
ump is to be piped to an external program.  Attempting to rename either core or core.13437.
 [ERR]
 [ERR] JVMDUMP010I System dump written to /root/home/ahuo/src/openjdk-tests/TKG/test_output_15856775065777/cmdLineTester_jvmtt
itests_hcr_OSRG_nongold_2/core.20200331.110440.13421.0001.dmp
 [ERR] JVMDUMP032I JVM requested Java dump using '/root/home/ahuo/src/openjdk-tests/TKG/test_output_15856775065777/cmdLineTess
ter_jvmtitests_hcr_OSRG_nongold_2/javacore.20200331.110440.13421.0002.txt' in response to an event
 [ERR] JVMDUMP010I Java dump written to /root/home/ahuo/src/openjdk-tests/TKG/test_output_15856775065777/cmdLineTester_jvmtitt
ests_hcr_OSRG_nongold_2/javacore.20200331.110440.13421.0002.txt
 [ERR] JVMDUMP032I JVM requested Snap dump using '/root/home/ahuo/src/openjdk-tests/TKG/test_output_15856775065777/cmdLineTess
ter_jvmtitests_hcr_OSRG_nongold_2/Snap.20200331.110440.13421.0003.trc' in response to an event
(gdb) bt
#0  0x00007f06c24b72d1 in pthread_kill () from /lib/x86_64-linux-gnu/libpthread.so.0
#1  0x00007f06c06cfe9d in omrdump_create (portLibrary=0x7f06c1a8e320 <j9portLibrary>, 
    filename=0x7f06c228bcd0 "/root/home/ahuo/src/openjdk-tests/TKG/test_output_15856775065777/cmdLineTester_jvmtitests_hcr_OSRG_nongold_2/", dumpType=<optimized out>, userData=<optimized out>) at ../../omr/port/unix/omrosdump.c:188
#2  0x00007f06c01818e2 in doSystemDump (agent=0x7f06bc028080, 
    label=0x7f06c228bcd0 "/root/home/ahuo/src/openjdk-tests/TKG/test_output_15856775065777/cmdLineTester_jvmtitests_hcr_OSRG_nongold_2/", context=0x7f06c228c190) at dmpagent.c:751
#3  0x00007f06c017d625 in protectedDumpFunction (portLibrary=portLibrary@entry=0x7f06c1a8e320 <j9portLibrary>, 
    userData=userData@entry=0x7f06c228bc30) at dmpagent.c:2911
#4  0x00007f06c06b2fd3 in omrsig_protect (portLibrary=0x7f06c1a8e320 <j9portLibrary>, 
    fn=0x7f06c017d610 <protectedDumpFunction>, fn_arg=0x7f06c228bc30, handler=0x7f06c017d630 <signalHandler>, 
    handler_arg=0x0, flags=505, result=0x7f06c228bc28) at ../../omr/port/unix/omrsignal.c:425
#5  0x00007f06c0180d4b in runDumpFunction (agent=<optimized out>, 
    label=0x7f06c228bcd0 "/root/home/ahuo/src/openjdk-tests/TKG/test_output_15856775065777/cmdLineTester_jvmtitests_hcr_OSRG_nongold_2/", context=<optimized out>) at dmpagent.c:2885
#6  0x00007f06c0180edf in runDumpAgent (vm=vm@entry=0x7f06bc011450, agent=agent@entry=0x7f06bc028080, 
    context=context@entry=0x7f06c228c190, state=state@entry=0x7f06c228c188, detail=detail@entry=0x7f06c228c210 "", 
    timeNow=timeNow@entry=1585677880698) at dmpagent.c:2811
#7  0x00007f06c0197ccb in triggerDumpAgents (vm=0x7f06bc011450, self=0x19a00, eventFlags=524288, eventData=<optimized out>)
    at trigger.c:1033
#8  0x00007f06bbdec07d in triggerHit (thr=thr@entry=0x1a380, compName=0x7f06bafe55aa "j9codertvm", 
    traceId=traceId@entry=110, phase=phase@entry=AFTER_TRACEPOINT) at trctrigger.c:1333
#9  0x00007f06bbddf917 in fireTriggerHit (thread=0x1a3e8, phase=AFTER_TRACEPOINT, traceId=110, compName=<optimized out>)
    at trclog.c:2565
#10 raiseAssertion (traceId=4222467, modInfo=0x7f06bb35b900 <j9codertvm_UtModuleInfo>, thread=0x1a3e8) at trclog.c:2553
#11 logTracePoint (varArgs=0x7f06c228c5a8, spec=<optimized out>, traceId=<optimized out>, modInfo=<optimized out>, 
    thr=<optimized out>) at trclog.c:2131
#12 doTracePoint (thr=<optimized out>, modInfo=<optimized out>, traceId=<optimized out>, spec=<optimized out>, 
    varArgs=varArgs@entry=0x7f06c228c6a8) at trclog.c:2207
#13 0x00007f06bbdd778f in javaTrace (env=<optimized out>, modInfo=<optimized out>, traceId=<optimized out>, 
    spec=<optimized out>) at trcengine.c:1311
#14 0x00007f06baed5576 in jitWalkFrame (walkState=walkState@entry=0x7f06c228c910, walkLocals=walkLocals@entry=1, 
    stackMap=0x0) at jswalk.c:538
#15 0x00007f06baed618c in jitWalkStackFrames (walkState=0x7f06c228c910) at jswalk.c:243
#16 0x00007f06c1386e3e in walkStackFrames (currentThread=0x19a00, walkState=0x7f06c228c910) at swalk.c:335
#17 0x00007f06c1356e50 in internalGrowJavaStack (vmThread=vmThread@entry=0x19a00, newStackSize=newStackSize@entry=18520)
    at growstack.cpp:235
#18 0x00007f06c1357611 in growJavaStack (vmThread=0x19a00, newStackSize=18520) at growstack.cpp:97
#19 0x00007f06baec6c8b in old_slow_jitStackOverflow (currentThread=0x19a00) at cnathelp.cpp:896
--Type <RET> for more, q to quit, c to continue without paging--
#20 0x00007f06baed8226 in jitStackOverflow () at xnathelp.s:860
#21 0x0000000000019a00 in ?? ()
#22 0x00007f06c228cd10 in ?? ()
#23 0x0000000083610468 in ?? ()
#24 0x0000000000000011 in ?? ()
#25 0xffffffffffeea56c in ?? ()
#26 0x0000000000000000 in ?? ()
(gdb) fr 11 
#11 logTracePoint (varArgs=0x7f06c228c5a8, spec=<optimized out>, traceId=<optimized out>, modInfo=<optimized out>, 
    thr=<optimized out>) at trclog.c:2131
2131            raiseAssertion(thr, modInfo, traceId);
(gdb) print traceId
$1 = <optimized out>
(gdb) print *modInfo
value has been optimized out
(gdb) print thr
$2 = <optimized out>
(gdb) print var
$3 = {{gp_offset = 32, fp_offset = 48, overflow_arg_area = 0x7f06c228c780, reg_save_area = 0x7f06c228c6c0}}
(gdb) print *spec
value has been optimized out
(gdb) print *varArgs
$5 = {gp_offset = 344, fp_offset = 0, overflow_arg_area = 0x396a7b64696e7074, reg_save_area = 0x6d76747265646f63}
a7ehuo commented 4 years ago

This intermittent failure at jswalk.c:538 is reported in multiple test cases/issues as below:

jdk8: cmdLineTester_jvmtitests_debug_openj9_none_SCC_11: #8885 cmdLineTester_jvmtitests_debug_openj9_none_SCC_5: #8170 cmdLineTester_jvmtitests_hcr_OSRG_nongold_SE80_2: #6714

jd11: cmdLineTester_jvmtitests_hcr_OSRG_nongold_2: #9024

a7ehuo commented 4 years ago

With the latest fix from #8786 (OpenJ9 - ffece8e), locally II don't see the crash with ** ASSERTION FAILED ** at jswalk.c:538: ((0 )) anymore. But the test still failed in rc001, rc020, and ta001. Not much error message from rc001 and rc020. ta001 encountered java.lang.IllegalArgumentExceptionjava.lang.IllegalArgumentException at the end.

Testing: rc001
Test start time: 2020/04/03 17:04:40 Coordinated Universal Time
Running command: "/root/home/ahuo/src/openj9-openjdk-jdk11/build/linux-x86_64-normal-server-release/images/jdk/bin/java" -Xcompressedrefs -Xcompressedrefs -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation  -XX:+UseJITServer  -Xdump    -agentlib:jvmtitest=test:rc001 -cp "/root/home/ahuo/src/openjdk-tests/TKG/../../jvmtest/functional/cmdLineTests/jvmtitests/jvmtitest.jar:/root/home/ahuo/src/openjdk-tests/TKG/../TKG/lib/asm-all.jar" com.ibm.jvmti.tests.util.TestRunner
Time spent starting: 1652 milliseconds
***[TEST INFO 2020/04/03 17:08:44] ProcessKiller detected a timeout after 240000 milliseconds!***
INFO: getUnixPID() has failed indicating this is not a UNIX System.'Debug on timeout' is currently only supported on Linux.
Output from test:
 [OUT] *** Testing [1/4]:   testRedefineMethodBody
 [OUT] Pre  Replace: 0
 [OUT] Post Replace: 100
 [OUT] *** Test took 22934 milliseconds
 [OUT] OK
 [OUT] 
 [OUT] *** Testing [2/4]:   testRedefineToSelf
 [OUT] Pre  Replace: 0
 [OUT] Post Replace: 0
 [OUT] *** Test took 27986 milliseconds
 [OUT] OK
 [OUT] 
 [OUT] *** Testing [3/4]:   testStaticFixups
 [OUT] Replacement 1 Starting
 [OUT] Replacement 1 DONE
 [OUT] Pre  Replace: 100 old: 100
 [OUT] Post Replace: 100
 [OUT] Replacement 1 Verified
 [OUT] Replacement 2 Starting
 [OUT] Replacement 2 DONE
 [OUT] Pre  Replace: 100 old: 100
 [OUT] Post Replace: 100
 [OUT] Replacement 2 Verified
 [OUT] t1_pre: 100
 [OUT] t2_pre: 100
 [OUT] t1_post: 100
 [OUT] t2_post: 100
 [OUT] *** Test took 61566 milliseconds
 [OUT] OK
 [OUT] 
 [OUT] *** Testing [4/4]:   testVTableFixups
 [OUT] Replacement 1 Starting
 [OUT] Replacement 1 DONE
 [OUT] Pre  Replace: 102 old: 202
 [OUT] Post Replace: 202
 [OUT] Replacement 2 Starting
 [OUT] Replacement 2 DONE
 [OUT] Post Replace: 202
 [OUT] *** Test took 58736 milliseconds
 [OUT] OK
 [OUT] 
 [ERR] JITServer is currently a technology preview. Its use is not yet supported
Time spent executing: 243028 milliseconds
Test result: FAILED
Output from test:

...

Testing: rc020
Test start time: 2020/04/03 17:40:53 Coordinated Universal Time
Running command: "/root/home/ahuo/src/openj9-openjdk-jdk11/build/linux-x86_64-normal-server-release/images/jdk/bin/java" -Xcompressedrefs -Xcompressedrefs -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation  -XX:+UseJITServer  -Xdump    -agentlib:jvmtitest=test:rc020 -cp "/root/home/ahuo/src/openjdk-tests/TKG/../../jvmtest/functional/cmdLineTests/jvmtitests/jvmtitest.jar:/root/home/ahuo/src/openjdk-tests/TKG/../TKG/lib/asm-all.jar" com.ibm.jvmti.tests.util.TestRunner
Time spent starting: 2 milliseconds
***[TEST INFO 2020/04/03 17:44:53] ProcessKiller detected a timeout after 240000 milliseconds!***
INFO: getUnixPID() has failed indicating this is not a UNIX System.'Debug on timeout' is currently only supported on Linux.
Output from test:
 [OUT] *** Testing [1/1]:   testIndyRedefinition
 [ERR] JITServer is currently a technology preview. Its use is not yet supported
Time spent executing: 265814 milliseconds
Test result: FAILED
Output from test:
 [OUT] *** Test took 181285 milliseconds
 [OUT] OK
 [OUT] 
...

Testing: ta001
Test start time: 2020/04/03 17:46:57 Coordinated Universal Time
Running command: "/root/home/ahuo/src/openj9-openjdk-jdk11/build/linux-x86_64-normal-server-release/images/jdk/bin/java" -Xcompressedrefs -Xcompressedrefs -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation  -XX:+UseJITServer  -Xdump    -agentlib:jvmtitest=test:ta001 -cp "/root/home/ahuo/src/openjdk-tests/TKG/../../jvmtest/functional/cmdLineTests/jvmtitests/jvmtitest.jar:/root/home/ahuo/src/openjdk-tests/TKG/../TKG/lib/asm-all.jar" com.ibm.jvmti.tests.util.TestRunner
Time spent starting: 1 milliseconds
***[TEST INFO 2020/04/03 17:50:57] ProcessKiller detected a timeout after 240000 milliseconds!***
INFO: getUnixPID() has failed indicating this is not a UNIX System.'Debug on timeout' is currently only supported on Linux.
Output from test:
 [OUT] *** Testing [1/13]:  testBCIUsingASM_InjectNPELogic
 [OUT] Pre  Replace: 1
 [OUT] Expected NullPointerException received
 [OUT] *** Test took 25195 milliseconds
 [OUT] OK
 [OUT] 
 [OUT] *** Testing [2/13]:  testBCIUsingASM_InjectNewIFBlock
 [OUT] Pre Replace result  : 5
 [OUT] Post Replace result : 1
 [OUT] *** Test took 26257 milliseconds
 [OUT] OK
 [OUT] 
 [OUT] *** Testing [3/13]:  testBCIUsingASM_InjectTryCatch_Level1_injectCatchAndThrowNewAIOBE
 [OUT] Expected NullPointerException received
 [OUT] Expected ArrayIndexOutOfBoundsException received
 [OUT] *** Test took 13099 milliseconds
 [OUT] OK
 [OUT] 
 [OUT] *** Testing [4/13]:  testBCIUsingASM_InjectTryCatch_Level2_injectCatchAndThrowNewAIOBE_catchAIOBEAndThrowNewAE
 [OUT] Expected NullPointerException received
 [OUT] Expected ArithmeticException received
 [OUT] *** Test took 9890 milliseconds
 [OUT] OK
 [OUT] 
 [OUT] *** Testing [5/13]:  testBCIUsingASM_Inject_Dead_Code
 [OUT] pre : 4
 [OUT] Expected pre-transform result received
 [OUT] post : 2
 [OUT] Expected post-transform result received
 [OUT] *** Test took 44703 milliseconds
 [OUT] OK
 [OUT] 
 [OUT] *** Testing [6/13]:  testBCIUsingASM_inject_CatchWithSelfGOTO
 [OUT] Expected pre-transform result received
 [OUT] Jumping to beginning of current catch block
 [OUT] Jumping to beginning of current catch block
 [OUT] Jumping to beginning of current catch block
 [OUT] Jumping to beginning of current catch block
 [OUT] Jumping to beginning of current catch block
 [OUT] Expected post-transform result received
 [OUT] *** Test took 9700 milliseconds
 [OUT] OK
 [OUT] 
 [OUT] *** Testing [7/13]:  testBCIUsingASM_inject_Loop2Loop_Jump
 [OUT] Expected pre-transform result received
 [OUT] Jumping to a different loop
 [OUT] Expected post-transform result received
 [OUT] *** Test took 14939 milliseconds
 [OUT] OK
 [OUT] 
 [OUT] *** Testing [8/13]:  testBCIUsingASM_inject_ParallelCatchJump
 [OUT] Expected pre-transform result received
 [OUT] Expected post-transform result received
 [OUT] *** Test took 9917 milliseconds
 [OUT] OK
 [OUT] 
 [OUT] *** Testing [9/13]:  testBCIUsingASM_inject_Unclean_Return
 [ERR] JITServer is currently a technology preview. Its use is not yet supported
Time spent executing: 373275 milliseconds
Test result: FAILED
Output from test:
 [OUT] pre : 3
 [OUT] Expected pre-transform result received
 [OUT] post : 5
 [OUT] Expected post-transform result received
 [OUT] *** Test took 44308 milliseconds
 [OUT] OK
 [OUT] 
 [OUT] *** Testing [10/13]: testBCIUsingASM_inject_call_to_timer_method
 [OUT] *** Test took 30353 milliseconds
 [OUT] OK
 [OUT] 
 [OUT] *** Testing [11/13]: testBCIUsingASM_inject_innerCatch2outerCatchJump
 [OUT] Expected pre-transform result received
 [OUT] Expected post-transform result received
 [OUT] *** Test took 4723 milliseconds
 [OUT] OK
 [OUT] 
 [OUT] *** Testing [12/13]: testBCIUsingASM_inject_stackValueUsage_After_Branch_Using_IfCompare
 [OUT] pre : 2
 [OUT] Expected pre-transform result received
 [OUT] post : 5
 [OUT] Expected post-transform result received
 [OUT] *** Test took 36963 milliseconds
 [OUT] OK
 [OUT] 
 [OUT] *** Testing [13/13]: testBCIUsingASM_inject_stackValueUsage_After_Branch_Using_MethodCall
 [OUT] pre : 10.0
 [OUT] Expected pre-transform result received
 [OUT] post : 0.1
 [OUT] Expected post-transform result received
 [OUT] *** Test took 28102 milliseconds
 [OUT] OK
 [OUT] 
 [ERR] Exception in thread "Thread-3" java.lang.IllegalArgumentException
 [ERR] Exception in thread "Thread-4" Exception in thread "Thread-5"    at org.objectweb.asm.ClassReader.<init>(Unknown Source)
 [ERR] java.lang.IllegalArgumentExceptionjava.lang.IllegalArgumentException
 [ERR] 
 [ERR]  at org.objectweb.asm.ClassReader.<init>(Unknown Source) at org.objectweb.asm.ClassReader.<init>(Unknown Source)
 [ERR]  at org.objectweb.asm.ClassReader.<init>(Unknown Source)
 [ERR]  at org.objectweb.asm.ClassReader.<init>(Unknown Source)
 [ERR]  at com.ibm.jvmti.tests.BCIWithASM.ASMTransformer.inject_call_to_timerMethod(ASMTransformer.java:1114)
 [ERR] 
 [ERR]  at org.objectweb.asm.ClassReader.<init>(Unknown Source)
 [ERR]  at org.objectweb.asm.ClassReader.<init>(Unknown Source)
 [ERR]  at org.objectweb.asm.ClassReader.<init>(Unknown Source)
 [ERR]  at org.objectweb.asm.ClassReader.<init>(Unknown Source)
 [ERR]  at com.ibm.jvmti.tests.BCIWithASM.ta001$1ProfilerThread.run(ta001.java:357)
 [ERR]  at com.ibm.jvmti.tests.BCIWithASM.ASMTransformer.inject_call_to_timerMethod(ASMTransformer.java:1114)
 [ERR]  at com.ibm.jvmti.tests.BCIWithASM.ta001$1ProfilerThread.run(ta001.java:357)
 [ERR]  at com.ibm.jvmti.tests.BCIWithASM.ASMTransformer.inject_call_to_timerMethod(ASMTransformer.java:1114)
 [ERR]  at com.ibm.jvmti.tests.BCIWithASM.ta001$1ProfilerThread.run(ta001.java:357)

---TEST RESULTS---
Number of PASSED tests: 21 out of 24
Number of FAILED tests: 3 out of 24

---SUMMARY OF FAILED TESTS---
rc001
rc020
ta001
-----------------------------
JasonFengJ9 commented 4 years ago

** ASSERTION FAILED ** at jswalk.c:532: ((0 )) occurred In another JDK8 internal build Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Nightly/53/:

===============================================
Running test cmdLineTester_jvmtitests_debug_openj9_none_SCC_11 ...
===============================================
cmdLineTester_jvmtitests_debug_openj9_none_SCC_11 Start Time: Sat Apr 18 21:34:43 2020 Epoch Time (ms): 1587270883130
variation: Mode607-OSR
JVM_OPTIONS: -XX:+UseJITServer -Xcompressedrefs -Xcompressedrefs -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:enableOSR,count=0
JITServer is currently a technology preview. Its use is not yet supported
JVMCDRT000E Unable to locate JIT stack map - aborting VM
JVMCDRT001E Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V (0000000000047918)
JVMCDRT002E Failing PC: 00007FD7DE800283 (offset 0000000000000023), metaData = 00007FD7DE1D42F8
04:34:43.310 0x16700j9codertvm(j9ji.110    *   ** ASSERTION FAILED ** at jswalk.c:532: ((0 ))
JVMDUMP039I Processing dump event "traceassert", detail "" at 2020/04/18 21:34:43 - please wait.
JVMDUMP032I JVM requested System dump using '/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Nightly/openjdk-tests/TKG/test_output_15872693439498/cmdLineTester_jvmtitests_debug_openj9_none_SCC_11/core.20200418.213443.21015.0001.dmp' in response to an event
JVMPORT030W /proc/sys/kernel/core_pattern setting "|/usr/share/apport/apport %p %s %c %d %P" specifies that the core dump is to be piped to an external program.  Attempting to rename either core or core.21027.

JVMDUMP010I System dump written to /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Nightly/openjdk-tests/TKG/test_output_15872693439498/cmdLineTester_jvmtitests_debug_openj9_none_SCC_11/core.20200418.213443.21015.0001.dmp
JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Nightly/openjdk-tests/TKG/test_output_15872693439498/cmdLineTester_jvmtitests_debug_openj9_none_SCC_11/javacore.20200418.213443.21015.0002.txt' in response to an event
JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Nightly/openjdk-tests/TKG/test_output_15872693439498/cmdLineTester_jvmtitests_debug_openj9_none_SCC_11/javacore.20200418.213443.21015.0002.txt
JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Nightly/openjdk-tests/TKG/test_output_15872693439498/cmdLineTester_jvmtitests_debug_openj9_none_SCC_11/Snap.20200418.213443.21015.0003.trc' in response to an event
JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Nightly/openjdk-tests/TKG/test_output_15872693439498/cmdLineTester_jvmtitests_debug_openj9_none_SCC_11/Snap.20200418.213443.21015.0003.trc
JVMDUMP013I Processed dump event "traceassert", detail "".

cmdLineTester_jvmtitests_debug_openj9_none_SCC_11_FAILED
a7ehuo commented 4 years ago

Also happened with cmdLineTester_jvmtitests_debug_openj9_none_SCC_7 in build Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Personal/183

===============================================
Running test cmdLineTester_jvmtitests_debug_openj9_none_SCC_7 ...
===============================================
...
Testing: rc016
Test start time: 2020/04/17 04:37:05 Eastern Standard Time
Running command: "/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Personal/openjdkbinary/j2sdk-image/bin/java" -XX:+UseJITServer -Xcompressedrefs -XX:+UseCompressedOops -Xgcpolicy:balanced -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:count=0  -Xdump    -agentlib:jvmtitest=test:rc016 -cp /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Personal/openjdk-tests/TKG/../../jvmtest/functional/cmdLineTests/jvmtitests/jvmtitest.jar:/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Personal/openjdk-tests/TKG/../TKG/lib/asm-all.jar com.ibm.jvmti.tests.util.TestRunner
Time spent starting: 4 milliseconds
Time spent executing: 2115 milliseconds
Test result: FAILED
Output from test:
 [ERR] JITServer is currently a technology preview. Its use is not yet supported
 [ERR] JVMCDRT000E Unable to locate JIT stack map - aborting VM
 [ERR] JVMCDRT001E Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V (0000000000047918)
 [ERR] JVMCDRT002E Failing PC: 00007F11FDA1B283 (offset 0000000000000023), metaData = 00007F11DEE7B2F8
 [ERR] 08:37:06.007 0x16700j9codertvm(j9ji.110    *   ** ASSERTION FAILED ** at jswalk.c:532: ((0 ))
 [ERR] JVMDUMP039I Processing dump event "traceassert", detail "" at 2020/04/17 04:37:06 - please wait.
 [ERR] JVMDUMP032I JVM requested System dump using '/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Personal/openjdk-tests/TKG/test_output_1587108872943/cmdLineTester_jvmtitests_debug_openj9_none_SCC_7/core.20200417.043706.8075.0001.dmp' in response to an event
 [ERR] JVMDUMP010I System dump written to /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Personal/openjdk-tests/TKG/test_output_1587108872943/cmdLineTester_jvmtitests_debug_openj9_none_SCC_7/core.20200417.043706.8075.0001.dmp
 [ERR] JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Personal/openjdk-tests/TKG/test_output_1587108872943/cmdLineTester_jvmtitests_debug_openj9_none_SCC_7/javacore.20200417.043706.8075.0002.txt' in response to an event
 [ERR] JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Personal/openjdk-tests/TKG/test_output_1587108872943/cmdLineTester_jvmtitests_debug_openj9_none_SCC_7/javacore.20200417.043706.8075.0002.txt
 [ERR] JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Personal/openjdk-tests/TKG/test_output_1587108872943/cmdLineTester_jvmtitests_debug_openj9_none_SCC_7/Snap.20200417.043706.8075.0003.trc' in response to an event
 [ERR] JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Personal/openjdk-tests/TKG/test_output_1587108872943/cmdLineTester_jvmtitests_debug_openj9_none_SCC_7/Snap.20200417.043706.8075.0003.trc
 [ERR] JVMDUMP013I Processed dump event "traceassert", detail "".
>> Success condition was not found: [Return code: 0]
a7ehuo commented 4 years ago

Tried the build as below on 04/30 in Grinder, FR: 1/32.

18:52:20  JITServer is ready to accept incoming requests
18:52:20  openjdk version "1.8.0_262-internal"
18:52:20  OpenJDK Runtime Environment (build 1.8.0_262-internal-jenkins_2020_04_30_14_10-b00)
18:52:20  Eclipse OpenJ9 VM (build master-ef109f7c2, JRE 1.8.0 Linux amd64-64-Bit Compressed References 20200430_1436 (JIT enabled, AOT enabled)
18:52:20  OpenJ9   - ef109f7c2
18:52:20  OMR      - f2285166b
18:52:20  JCL      - ed7c83cea53 based on jdk8u262-b01)
JasonFengJ9 commented 3 years ago

Another occurrence at JDK8 JITServer Test_openjdk8_j9_sanity.functional_x86-64_linux_jit_Nightly/203:

===============================================
Running test cmdLineTester_jvmtitests_debug_openj9_none_SCC_7 ...
===============================================
cmdLineTester_jvmtitests_debug_openj9_none_SCC_7 Start Time: Wed Oct  7 21:27:49 2020 Epoch Time (ms): 1602131269184
variation: Mode557
JVM_OPTIONS: -XX:+UseJITServer -XX:+UseCompressedOops -Xgcpolicy:balanced -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:count=0 
JITServer is currently a technology preview. Its use is not yet supported
JVMCDRT000E Unable to locate JIT stack map - aborting VM
JVMCDRT001E Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V (000000000004B048)
JVMCDRT002E Failing PC: 00007F713D9892CE (offset 000000000000002E), metaData = 00007F713C49B2F8
04:27:49.436 0x19a00j9codertvm(j9ji.110    *   ** ASSERTION FAILED ** at jswalk.c:532: ((0 ))
JVMDUMP039I Processing dump event "traceassert", detail "" at 2020/10/07 21:27:49 - please wait.

cmdLineTester_jvmtitests_debug_openj9_none_SCC_7_FAILED

Also JDK15 JITServer Test_openjdk15_j9_extended.functional_x86-64_linux_jit_Nightly/87

Testing: rc004
Test start time: 2020/10/07 19:39:23 Pacific Standard Time
Running command: "/home/jenkins/workspace/Test_openjdk15_j9_extended.functional_x86-64_linux_jit_Nightly_testList_1/openjdkbinary/j2sdk-image/bin/java" -XX:+UseJITServer -Xcompressedrefs -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation  -Xdump    -agentlib:jvmtitest=test:rc004 -cp "/home/jenkins/workspace/Test_openjdk15_j9_extended.functional_x86-64_linux_jit_Nightly_testList_1/openjdk-tests/TKG/../../jvmtest/functional/cmdLineTests/jvmtitests/jvmtitest.jar:/home/jenkins/workspace/Test_openjdk15_j9_extended.functional_x86-64_linux_jit_Nightly_testList_1/openjdk-tests/TKG/../TKG/lib/asm-all.jar" com.ibm.jvmti.tests.util.TestRunner
Time spent starting: 3 milliseconds
Time spent executing: 3119 milliseconds
Test result: FAILED
Output from test:
 [ERR] JITServer is currently a technology preview. Its use is not yet supported
 [ERR] JVMCDRT000E Unable to locate JIT stack map - aborting VM
 [ERR] JVMCDRT001E Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V (000000000004F6C8)
 [ERR] JVMCDRT002E Failing PC: 00007F9A3172E22E (offset 000000000000002E), metaData = 00007F9A3016A278
 [ERR] 02:39:23.879 0x16700j9codertvm(j9ji.110    *   ** ASSERTION FAILED ** at jswalk.c:532: ((0 ))
 [ERR] JVMDUMP039I Processing dump event "traceassert", detail "" at 2020/10/07 19:39:23 - please wait.

cmdLineTester_jvmtitests_hcr_OSRG_nongold_2_FAILED
dmitry-ten commented 3 years ago

I'm working on this bug right now, so I'll make this the issue to address all identical crashes in other tests and close other issues. I was able to reproduce the crash in cmdLineTester_jvmtitests_debug_openj9_none_SCC_3. @liqunl is helping me investigate it. The crash message:

Output from test:
 [ERR] JITServer is currently a technology preview. Its use is not yet supported
 [ERR] JVMCDRT000E Unable to locate JIT stack map - aborting VM
 [ERR] JVMCDRT001E Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V (0000000000049948)
 [ERR] JVMCDRT002E Failing PC: 00007FCAB10E4283 (offset 0000000000000023), metaData = 00007FCA933572F8
 [ERR] 19:52:27.395 0x18100j9codertvm(j9ji.110    *   ** ASSERTION FAILED ** at jswalk.c:532: ((0 ))
 [ERR] JVMDUMP039I Processing dump event "traceassert", detail "" at 2020/10/29 15:52:27 - please wait.
 [ERR] JVMDUMP032I JVM requested System dump using '/home/dmitry-ten/src/openj9-openjdk-jdk8/openj9/test/TKG/test_output_16040010978616/cmdLineTester_jvmtitests_debug_openj9_none_SCC_3/core.20201029.155227.12072.0001.dmp' in response to an event
 [ERR] JVMDUMP010I System dump written to /home/dmitry-ten/src/openj9-openjdk-jdk8/openj9/test/TKG/test_output_16040010978616/cmdLineTester_jvmtitests_debug_openj9_none_SCC_3/core.20201029.155227.12072.0001.dmp
 [ERR] JVMDUMP032I JVM requested Java dump using '/home/dmitry-ten/src/openj9-openjdk-jdk8/openj9/test/TKG/test_output_16040010978616/cmdLineTester_jvmtitests_debug_openj9_none_SCC_3/javacore.20201029.155227.12072.0002.txt' in response to an event
 [ERR] JVMDUMP010I Java dump written to /home/dmitry-ten/src/openj9-openjdk-jdk8/openj9/test/TKG/test_output_16040010978616/cmdLineTester_jvmtitests_debug_openj9_none_SCC_3/javacore.20201029.155227.12072.0002.txt
 [ERR] JVMDUMP032I JVM requested Snap dump using '/home/dmitry-ten/src/openj9-openjdk-jdk8/openj9/test/TKG/test_output_16040010978616/cmdLineTester_jvmtitests_debug_openj9_none_SCC_3/Snap.20201029.155227.12072.0003.trc' in response to an event
 [ERR] JVMDUMP010I Snap dump written to /home/dmitry-ten/src/openj9-openjdk-jdk8/openj9/test/TKG/test_output_16040010978616/cmdLineTester_jvmtitests_debug_openj9_none_SCC_3/Snap.20201029.155227.12072.0003.trc
 [ERR] JVMDUMP013I Processed dump event "traceassert", detail "".
>> Success condition was not found: [Return code: 0]

Assembly around failing pc:

e-synchronizing disassembly on method entry
0x7fcab10e4260 {java/lang/NullPointerException.<init>} +0            >|   488b442410           mov       rax, qword ptr [rsp + 0x10]
0x7fcab10e4265 {java/lang/NullPointerException.<init>} +5             |   488b742408           mov       rsi, qword ptr [rsp + 8]
0x7fcab10e426a {java/lang/NullPointerException.<init>} +10            |   4889442410           mov       qword ptr [rsp + 0x10], rax
0x7fcab10e426f {java/lang/NullPointerException.<init>} +15            |   4889742408           mov       qword ptr [rsp + 8], rsi
0x7fcab10e4274 {java/lang/NullPointerException.<init>} +20            |   483b6550             cmp       rsp, qword ptr [rbp + 0x50] J9VMThread.stackOverflowMark
0x7fcab10e4278 {java/lang/NullPointerException.<init>} +24            |   0f866d010000         jbe       0x7fcab10e43eb C>> +395
0x7fcab10e427e {java/lang/NullPointerException.<init>} +30            |   4883ec18             sub       rsp, 0x18  <<< ^+405
0x7fcab10e4282 {java/lang/NullPointerException.<init>} +34            |   0fb60d1e5e6189       movzx     ecx, byte ptr [rip - 0x769ea1e2]
0x7fcab10e4289 {java/lang/NullPointerException.<init>} +41            |   f6c101               test      cl, 1
0x7fcab10e428c {java/lang/NullPointerException.<init>} +44           *>   0f85b7000000         jne       0x7fcab10e4349 C>> +233
0x7fcab10e4292 {java/lang/NullPointerException.<init>} +50           |    0fb60d0e5e6189       movzx     ecx, byte ptr [rip - 0x769ea1f2]
0x7fcab10e4299 {java/lang/NullPointerException.<init>} +57           |    f6c101               test      cl, 1
0x7fcab10e429c {java/lang/NullPointerException.<init>} +60           |*   0f85d0000000         jne       0x7fcab10e4372 C>> +274
-------
------
0x7fcab10e4349 {java/lang/NullPointerException.<init>} +233          >||| 488bd6               mov       rdx, rsi <<< +44
0x7fcab10e434c {java/lang/NullPointerException.<init>} +236           ||| 488bc8               mov       rcx, rax
0x7fcab10e434f {java/lang/NullPointerException.<init>} +239           ||| b848990400           mov       eax, 0x49948 J9Method - {java/lang/NullPointerException.<init>}
0x7fcab10e4354 {java/lang/NullPointerException.<init>} +244           ||| 488bf1               mov       rsi, rcx
0x7fcab10e4357 GCMap  Bytecode -1:0 Registers: rcx rdx rsi  StackMap: P0x20 P0x28
0x7fcab10e4357 {java/lang/NullPointerException.<init>} +247  -1:0     ||| e8e4303f15           call      0x7fcac64d7440 (This is address of jitReportMethodEnter)

It shows that the failing PC at +35 is not valid, it's off by 1.

The stack trace shows that the stack walk was caused by stack overflow which seems to be caused by the jitted method somehow recursively calling itself.

#14 0x00007fcac64d3ba6 in jitWalkFrame (walkState=walkState@entry=0x7fcacd39fab0,
    walkLocals=walkLocals@entry=1, stackMap=0x0) at jswalk.c:532
#15 0x00007fcac64d47bc in jitWalkStackFrames (walkState=0x7fcacd39fab0) at jswalk.c:243
#16 0x00007fcacc495d7e in walkStackFrames (currentThread=0x18100, walkState=0x7fcacd39fab0) at swalk.c:335
#17 0x00007fcacc465660 in internalGrowJavaStack (vmThread=vmThread@entry=0x18100,
    newStackSize=newStackSize@entry=18632) at growstack.cpp:235
#18 0x00007fcacc465e11 in growJavaStack (vmThread=0x18100, newStackSize=18632) at growstack.cpp:97
#19 0x00007fcac64c477b in old_slow_jitStackOverflow (currentThread=0x18100) at cnathelp.cpp:1281
#20 0x00007fcac64d6856 in jitStackOverflow () at xnathelp.s:860
#21 0x0000000000018100 in ?? ()
#22 0x00007fcacd39feb0 in ?? ()
#23 0x00000000390a0498 in ?? ()
#24 0x0000000000000011 in ?? ()
#25 0xffffffffffee72ec in ?? ()
#26 0x0000000000000000 in ?? ()

The code around failing PC may conditionally jump to call to jitReportMethodEnter so this is the main suspect. It's also suspicious because this crash only appears in tests using Full Speed Debug, and method enter/exit hooks are used for it.

dmitry-ten commented 3 years ago

@liqunl could you please specify what's unclear about this crash? I don't think I understand everything entirely. @mpirvu fyi.

liqunl commented 3 years ago

The stack is interleaved with JIT frame, JIT resolve frame, JNI call-in frame. The thread seems to be looping between these frames, then we ran out of stack, and ended up in jitStackOverFlow.

It seemed to me the JIT code called to the VM, but somehow VM called back to the same JIT method. This doesn't look right, unless something happened in VM to cause it to call the NPE constructor.

The return address +35 doesn't point to a valid instruction, the one close to it is +34, but that is not a call, so it shouldn't be the return address either.

+44 may jump to an instruction that calls to jitReportMethodEnter, so I wonder if the JIT code called out to jitReportMethodEnter.

@gacholio How can I tell what VM is asked to do by the JIT? Anything you can figure out from the files I uploaded?

j9vmthread.txt javacore.txt javavm.txt kca-stack.txt NPE.init.asm.txt NPE.stackslots.txt

dmitry-ten commented 3 years ago

I was also able to get a trace file for the failing method.

NPE.log.12237.server.1.txt Note that this file was obtained from a different failing run, so the addresses will not match the ones in the files above.

gacholio commented 3 years ago

jitStackOverflow does not indicate an infinite recursion - it's also used to grow the stack from its initial small size to increasingly larger sizes, which is what appears to be happening here.

From the javacore, the failure is occuring in early thread startup (the fact that the thread is unnamed).

I won't be able to say anything more without a system core to look at.

liqunl commented 3 years ago

@dmitry-ten Could you upload the core dump to /team/triage/liqunl/openj9-9024?

dmitry-ten commented 3 years ago

Sure. Where is that folder located?

dmitry-ten commented 3 years ago

Uploaded the core dump.

liqunl commented 3 years ago

@gacholio The core and JDK is in /team/triage/liqunl/openj9-9024

gacholio commented 3 years ago

Stack is:

<18100> *** BEGIN STACK WALK, flags = 00400001 walkThread = 0x0000000000018100 ***
<18100>     ITERATE_O_SLOTS
<18100>     RECORD_BYTECODE_PC_OFFSET
<18100> Initial values: walkSP = 0x0000000000050F60, PC = 0x0000000000000005, literals = 0x0000000000000000, A0 = 0x0000000000050F80, j2iFrame = 0x0000000000000000, ELS = 0x00007FCACD39FED0, decomp = 0x0000000000000000
<18100> JIT resolve frame: bp = 0x0000000000050F80, sp = 0x0000000000050F60, pc = 0x0000000000000005, cp = 0x0000000000000000, arg0EA = 0x0000000000050F80, flags = 0x0000000000780000
<18100>     Object push (savedJITException)
<18100>         O-Slot[0x0000000000050F60] = 0x0000000000000000
<18100>     Stack overflow resolve
<18100>     unwindSP initialized to 0x0000000000050F88
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD39FD80] = UDATA(0x00000000390A0498) (jit_rax)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD39FD88] = UDATA(0x0000000000000011) (jit_rbx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD39FD90] = UDATA(0xFFFFFFFFFFEE72EC) (jit_rcx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD39FD98] = UDATA(0x0000000000000000) (jit_rdx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD39FDA0] = UDATA(0x0000000000000018) (jit_rdi)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD39FDA8] = UDATA(0x0000000000000000) (jit_rsi)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD39FDB0] = UDATA(0x0000000000006030) (jit_rbp)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD39FDB8] = UDATA(0x0000000000004000) (jit_rsp)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD39FDC0] = UDATA(0x00007FCA7945936A) (jit_r8)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD39FDC8] = UDATA(0x0000000000000000) (jit_r9)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD39FDD0] = UDATA(0x0000000000000000) (jit_r10)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD39FDD8] = UDATA(0x00000000000174F0) (jit_r11)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD39FDE0] = UDATA(0x00000000000175F8) (jit_r12)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD39FDE8] = UDATA(0x00007FCACD39FE38) (jit_r13)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD39FDF0] = UDATA(0x00007FCAC809BF70) (jit_r14)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD39FDF8] = UDATA(0x00007FCAC5E20FC9) (jit_r15)
<18100> JIT (hidden) frame: bp = 0x0000000000050F88, pc = 0x00007FCAB10E43F5, unwindSP = 0x0000000000050F88, cp = 0x0000000000049970, arg0EA = 0x0000000000050F98, jitInfo = 0x00007FCA933572F8
<18100>     Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V !j9method 0x0000000000049948
<18100>     Bytecode index = -1, inlineDepth = 0, PC offset = 0x0000000000000195
<18100>     stackMap=0x00007FCA93357489, slots=I16(0x0002) parmBaseOffset=I16(0x0008), parmSlots=U16(0x0002), localBaseOffset=I16(0x0000)
<18100>     Described JIT args starting at 0x0000000000050F90 for U16(0x0002) slots
<18100>         O-Slot: : a1[0x0000000000050F90] = 0x0000000000000000
<18100>         O-Slot: : a0[0x0000000000050F98] = 0x00000000390A0498
<18100>     JIT-RegisterMap = UDATA(0x0000000000000021)
<18100>         JIT-RegisterMap-O-Slot[0x00007FCACD39FD80] = 0x00000000390A0498 (jit_rax)
<18100>         JIT-RegisterMap-I-Slot[0x00007FCACD39FD88] = UDATA(0x0000000000000011) (jit_rbx)
<18100>         JIT-RegisterMap-I-Slot[0x00007FCACD39FD90] = UDATA(0xFFFFFFFFFFEE72EC) (jit_rcx)
<18100>         JIT-RegisterMap-I-Slot[0x00007FCACD39FD98] = UDATA(0x0000000000000000) (jit_rdx)
<18100>         JIT-RegisterMap-I-Slot[0x00007FCACD39FDA0] = UDATA(0x0000000000000018) (jit_rdi)
<18100>         JIT-RegisterMap-O-Slot[0x00007FCACD39FDA8] = 0x0000000000000000 (jit_rsi)
<18100>         JIT-RegisterMap-I-Slot[0x00007FCACD39FDB0] = UDATA(0x0000000000006030) (jit_rbp)
<18100>         JIT-RegisterMap-I-Slot[0x00007FCACD39FDB8] = UDATA(0x0000000000004000) (jit_rsp)
<18100>         JIT-RegisterMap-I-Slot[0x00007FCACD39FDC0] = UDATA(0x00007FCA7945936A) (jit_r8)
<18100>         JIT-RegisterMap-I-Slot[0x00007FCACD39FDC8] = UDATA(0x0000000000000000) (jit_r9)
<18100>         JIT-RegisterMap-I-Slot[0x00007FCACD39FDD0] = UDATA(0x0000000000000000) (jit_r10)
<18100>         JIT-RegisterMap-I-Slot[0x00007FCACD39FDD8] = UDATA(0x00000000000174F0) (jit_r11)
<18100>         JIT-RegisterMap-I-Slot[0x00007FCACD39FDE0] = UDATA(0x00000000000175F8) (jit_r12)
<18100>         JIT-RegisterMap-I-Slot[0x00007FCACD39FDE8] = UDATA(0x00007FCACD39FE38) (jit_r13)
<18100>         JIT-RegisterMap-I-Slot[0x00007FCACD39FDF0] = UDATA(0x00007FCAC809BF70) (jit_r14)
<18100>         JIT-RegisterMap-I-Slot[0x00007FCACD39FDF8] = UDATA(0x00007FCAC5E20FC9) (jit_r15)
<18100> I2J values: PC = 0x00007FCACC521914, A0 = 0x0000000000050FC0, walkSP = 0x0000000000050FA0, literals = 0x0000000000000000, JIT PC = 0x00007FCAC64E1090, pcAddress = 0x00007FCACD39FEF8, decomp = 0x0000000000000000
<18100> JNI call-in frame: bp = 0x0000000000050FC0, sp = 0x0000000000050FA0, pc = 0x00007FCACC521914, cp = 0x0000000000000000, arg0EA = 0x0000000000050FC0, flags = 0x0000000000000000
<18100>     New ELS = 0x00007FCACD3A0160
<18100> JIT resolve frame: bp = 0x0000000000050FF8, sp = 0x0000000000050FC8, pc = 0x0000000000000005, cp = 0x0000000000000000, arg0EA = 0x0000000000050FF8, flags = 0x0000000000080000
<18100>     Object push (savedJITException)
<18100>         O-Slot[0x0000000000050FD8] = 0x0000000000000000
<18100>     Object pushes starting at 0x0000000000050FC8 for 2 slots
<18100>         Push[0x0000000000050FC8] = 0x00000000390A0498
<18100>         Push[0x0000000000050FD0] = 0x0000000000000000
<18100>     Generic resolve
<18100>     unwindSP initialized to 0x0000000000051000
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0010] = UDATA(0x00000000390A0478) (jit_rax)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0018] = UDATA(0x0000000000000011) (jit_rbx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0020] = UDATA(0xFFFFFFFFFFEE72EC) (jit_rcx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0028] = UDATA(0x0000000000000000) (jit_rdx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0030] = UDATA(0x00007FCACC521914) (jit_rdi)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0038] = UDATA(0x0000000000000000) (jit_rsi)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0040] = UDATA(0x0000000000018100) (jit_rbp)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0048] = UDATA(0x0000000000004000) (jit_rsp)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0050] = UDATA(0x00007FCA7945936A) (jit_r8)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0058] = UDATA(0x0000000000000000) (jit_r9)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0060] = UDATA(0x0000000000000000) (jit_r10)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0068] = UDATA(0x00000000000175B0) (jit_r11)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0070] = UDATA(0x00000000000176B8) (jit_r12)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0078] = UDATA(0x00007FCACD3A00C8) (jit_r13)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0080] = UDATA(0x00007FCAC809BF70) (jit_r14)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0088] = UDATA(0x00007FCAC5E20FC9) (jit_r15)
<18100> JIT frame: bp = 0x0000000000051018, pc = 0x00007FCAB10E4283, unwindSP = 0x0000000000051000, cp = 0x0000000000049970, arg0EA = 0x0000000000051028, jitInfo = 0x00007FCA933572F8
<18100>     Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V !j9method 0x0000000000049948
<18100>     Bytecode index = -1, inlineDepth = 0, PC offset = 0x0000000000000023
Nov 02, 2020 12:33:04 PM com.ibm.j9ddr.vm29.events.DefaultEventListener corruptData
WARNING: CorruptData encountered iterating o-slots. walkThread = 0x0000000000018100
com.ibm.j9ddr.AddressedCorruptDataException: Unable to locate JIT stack map
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker$JITStackWalker_29_V0.jitWalkFrame(JITStackWalker.java:1077)
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker$JITStackWalker_29_V0.jitWalkStackFrames(JITStackWalker.java:257)
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker.jitWalkStackFrames(JITStackWalker.java:101)
    at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker$StackWalker_29_V0.walkStackFrames(StackWalker.java:488)
    at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker.walkStackFrames(StackWalker.java:103)
    at com.ibm.j9ddr.vm29.tools.ddrinteractive.commands.StackWalkCommand.run(StackWalkCommand.java:139)
    at com.ibm.j9ddr.tools.ddrinteractive.Context.tryCommand(Context.java:229)
    at com.ibm.j9ddr.tools.ddrinteractive.Context.execute(Context.java:202)
    at com.ibm.j9ddr.tools.ddrinteractive.DDRInteractive.execute(DDRInteractive.java:356)
    at com.ibm.j9ddr.command.CommandReader.processLine(CommandReader.java:79)
    at com.ibm.j9ddr.tools.ddrinteractive.DDRInteractive.processLine(DDRInteractive.java:331)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at com.ibm.jvm.dtfjview.CombinedContext.executeDDRInteractiveCommand(CombinedContext.java:260)
    at com.ibm.jvm.dtfjview.CombinedContext.execute(CombinedContext.java:170)
    at com.ibm.jvm.dtfjview.Session.execute(Session.java:811)
    at com.ibm.jvm.dtfjview.Session.execute(Session.java:765)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.executeJdmpviewCommand(ToolsRegistry.java:183)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.execute(ToolsRegistry.java:107)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.execute(ToolsRegistry.java:88)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.recordAndExecute(ToolsRegistry.java:72)
    at com.ibm.jvm.dtfjview.Session.runInteractive(Session.java:739)
    at com.ibm.jvm.dtfjview.Session.run(Session.java:663)
    at com.ibm.jvm.dtfjview.DTFJView.launch(DTFJView.java:52)
    at com.ibm.jvm.dtfjview.DTFJView.main(DTFJView.java:46)

<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0018] = UDATA(0x0000000000000011) (jit_rbx)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0058] = UDATA(0x0000000000000000) (jit_r9)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0060] = UDATA(0x0000000000000000) (jit_r10)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0068] = UDATA(0x00000000000175B0) (jit_r11)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0070] = UDATA(0x00000000000176B8) (jit_r12)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0078] = UDATA(0x00007FCACD3A00C8) (jit_r13)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0080] = UDATA(0x00007FCAC809BF70) (jit_r14)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0088] = UDATA(0x00007FCAC5E20FC9) (jit_r15)
<18100> I2J values: PC = 0x00007FCACC521914, A0 = 0x0000000000051050, walkSP = 0x0000000000051030, literals = 0x0000000000000000, JIT PC = 0x00007FCAC64E1090, pcAddress = 0x00007FCACD3A0188, decomp = 0x0000000000000000
<18100> JNI call-in frame: bp = 0x0000000000051050, sp = 0x0000000000051030, pc = 0x00007FCACC521914, cp = 0x0000000000000000, arg0EA = 0x0000000000051050, flags = 0x0000000000000000
<18100>     New ELS = 0x00007FCACD3A03F0
<18100> JIT resolve frame: bp = 0x0000000000051088, sp = 0x0000000000051058, pc = 0x0000000000000005, cp = 0x0000000000000000, arg0EA = 0x0000000000051088, flags = 0x0000000000080000
<18100>     Object push (savedJITException)
<18100>         O-Slot[0x0000000000051068] = 0x0000000000000000
<18100>     Object pushes starting at 0x0000000000051058 for 2 slots
<18100>         Push[0x0000000000051058] = 0x00000000390A0478
<18100>         Push[0x0000000000051060] = 0x0000000000000000
<18100>     Generic resolve
<18100>     unwindSP initialized to 0x0000000000051090
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A02A0] = UDATA(0x00000000390A0458) (jit_rax)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A02A8] = UDATA(0x0000000000000011) (jit_rbx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A02B0] = UDATA(0xFFFFFFFFFFEE72EC) (jit_rcx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A02B8] = UDATA(0x0000000000000000) (jit_rdx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A02C0] = UDATA(0x00007FCACC521914) (jit_rdi)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A02C8] = UDATA(0x0000000000000000) (jit_rsi)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A02D0] = UDATA(0x0000000000018100) (jit_rbp)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A02D8] = UDATA(0x0000000000004000) (jit_rsp)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A02E0] = UDATA(0x00007FCA7945936A) (jit_r8)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A02E8] = UDATA(0x0000000000000000) (jit_r9)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A02F0] = UDATA(0x0000000000000000) (jit_r10)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A02F8] = UDATA(0x0000000000017630) (jit_r11)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0300] = UDATA(0x0000000000017738) (jit_r12)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0308] = UDATA(0x00007FCACD3A0358) (jit_r13)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0310] = UDATA(0x00007FCAC809BF70) (jit_r14)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0318] = UDATA(0x00007FCAC5E20FC9) (jit_r15)
<18100> JIT frame: bp = 0x00000000000510A8, pc = 0x00007FCAB10E4283, unwindSP = 0x0000000000051090, cp = 0x0000000000049970, arg0EA = 0x00000000000510B8, jitInfo = 0x00007FCA933572F8
<18100>     Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V !j9method 0x0000000000049948
<18100>     Bytecode index = -1, inlineDepth = 0, PC offset = 0x0000000000000023
Nov 02, 2020 12:33:04 PM com.ibm.j9ddr.vm29.events.DefaultEventListener corruptData
WARNING: CorruptData encountered iterating o-slots. walkThread = 0x0000000000018100
com.ibm.j9ddr.AddressedCorruptDataException: Unable to locate JIT stack map
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker$JITStackWalker_29_V0.jitWalkFrame(JITStackWalker.java:1077)
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker$JITStackWalker_29_V0.jitWalkStackFrames(JITStackWalker.java:257)
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker.jitWalkStackFrames(JITStackWalker.java:101)
    at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker$StackWalker_29_V0.walkStackFrames(StackWalker.java:488)
    at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker.walkStackFrames(StackWalker.java:103)
    at com.ibm.j9ddr.vm29.tools.ddrinteractive.commands.StackWalkCommand.run(StackWalkCommand.java:139)
    at com.ibm.j9ddr.tools.ddrinteractive.Context.tryCommand(Context.java:229)
    at com.ibm.j9ddr.tools.ddrinteractive.Context.execute(Context.java:202)
    at com.ibm.j9ddr.tools.ddrinteractive.DDRInteractive.execute(DDRInteractive.java:356)
    at com.ibm.j9ddr.command.CommandReader.processLine(CommandReader.java:79)
    at com.ibm.j9ddr.tools.ddrinteractive.DDRInteractive.processLine(DDRInteractive.java:331)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at com.ibm.jvm.dtfjview.CombinedContext.executeDDRInteractiveCommand(CombinedContext.java:260)
    at com.ibm.jvm.dtfjview.CombinedContext.execute(CombinedContext.java:170)
    at com.ibm.jvm.dtfjview.Session.execute(Session.java:811)
    at com.ibm.jvm.dtfjview.Session.execute(Session.java:765)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.executeJdmpviewCommand(ToolsRegistry.java:183)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.execute(ToolsRegistry.java:107)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.execute(ToolsRegistry.java:88)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.recordAndExecute(ToolsRegistry.java:72)
    at com.ibm.jvm.dtfjview.Session.runInteractive(Session.java:739)
    at com.ibm.jvm.dtfjview.Session.run(Session.java:663)
    at com.ibm.jvm.dtfjview.DTFJView.launch(DTFJView.java:52)
    at com.ibm.jvm.dtfjview.DTFJView.main(DTFJView.java:46)

<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A02A8] = UDATA(0x0000000000000011) (jit_rbx)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A02E8] = UDATA(0x0000000000000000) (jit_r9)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A02F0] = UDATA(0x0000000000000000) (jit_r10)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A02F8] = UDATA(0x0000000000017630) (jit_r11)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0300] = UDATA(0x0000000000017738) (jit_r12)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0308] = UDATA(0x00007FCACD3A0358) (jit_r13)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0310] = UDATA(0x00007FCAC809BF70) (jit_r14)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0318] = UDATA(0x00007FCAC5E20FC9) (jit_r15)
<18100> I2J values: PC = 0x00007FCACC521914, A0 = 0x00000000000510E0, walkSP = 0x00000000000510C0, literals = 0x0000000000000000, JIT PC = 0x00007FCAC64E1090, pcAddress = 0x00007FCACD3A0418, decomp = 0x0000000000000000
<18100> JNI call-in frame: bp = 0x00000000000510E0, sp = 0x00000000000510C0, pc = 0x00007FCACC521914, cp = 0x0000000000000000, arg0EA = 0x00000000000510E0, flags = 0x0000000000000000
<18100>     New ELS = 0x00007FCACD3A0680
<18100> JIT resolve frame: bp = 0x0000000000051118, sp = 0x00000000000510E8, pc = 0x0000000000000005, cp = 0x0000000000000000, arg0EA = 0x0000000000051118, flags = 0x0000000000080000
<18100>     Object push (savedJITException)
<18100>         O-Slot[0x00000000000510F8] = 0x0000000000000000
<18100>     Object pushes starting at 0x00000000000510E8 for 2 slots
<18100>         Push[0x00000000000510E8] = 0x00000000390A0458
<18100>         Push[0x00000000000510F0] = 0x0000000000000000
<18100>     Generic resolve
<18100>     unwindSP initialized to 0x0000000000051120
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0530] = UDATA(0x00000000390A0438) (jit_rax)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0538] = UDATA(0x0000000000000011) (jit_rbx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0540] = UDATA(0xFFFFFFFFFFEE72EC) (jit_rcx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0548] = UDATA(0x0000000000000000) (jit_rdx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0550] = UDATA(0x00007FCACC521914) (jit_rdi)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0558] = UDATA(0x0000000000000000) (jit_rsi)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0560] = UDATA(0x0000000000018100) (jit_rbp)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0568] = UDATA(0x0000000000004000) (jit_rsp)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0570] = UDATA(0x00007FCA7945936A) (jit_r8)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0578] = UDATA(0x0000000000000000) (jit_r9)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0580] = UDATA(0x0000000000000000) (jit_r10)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0588] = UDATA(0x00000000000176B0) (jit_r11)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0590] = UDATA(0x00000000000177B8) (jit_r12)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0598] = UDATA(0x00007FCACD3A05E8) (jit_r13)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A05A0] = UDATA(0x00007FCAC809BF70) (jit_r14)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A05A8] = UDATA(0x00007FCAC5E20FC9) (jit_r15)
<18100> JIT frame: bp = 0x0000000000051138, pc = 0x00007FCAB10E4283, unwindSP = 0x0000000000051120, cp = 0x0000000000049970, arg0EA = 0x0000000000051148, jitInfo = 0x00007FCA933572F8
<18100>     Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V !j9method 0x0000000000049948
<18100>     Bytecode index = -1, inlineDepth = 0, PC offset = 0x0000000000000023
Nov 02, 2020 12:33:04 PM com.ibm.j9ddr.vm29.events.DefaultEventListener corruptData
WARNING: CorruptData encountered iterating o-slots. walkThread = 0x0000000000018100
com.ibm.j9ddr.AddressedCorruptDataException: Unable to locate JIT stack map
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker$JITStackWalker_29_V0.jitWalkFrame(JITStackWalker.java:1077)
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker$JITStackWalker_29_V0.jitWalkStackFrames(JITStackWalker.java:257)
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker.jitWalkStackFrames(JITStackWalker.java:101)
    at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker$StackWalker_29_V0.walkStackFrames(StackWalker.java:488)
    at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker.walkStackFrames(StackWalker.java:103)
    at com.ibm.j9ddr.vm29.tools.ddrinteractive.commands.StackWalkCommand.run(StackWalkCommand.java:139)
    at com.ibm.j9ddr.tools.ddrinteractive.Context.tryCommand(Context.java:229)
    at com.ibm.j9ddr.tools.ddrinteractive.Context.execute(Context.java:202)
    at com.ibm.j9ddr.tools.ddrinteractive.DDRInteractive.execute(DDRInteractive.java:356)
    at com.ibm.j9ddr.command.CommandReader.processLine(CommandReader.java:79)
    at com.ibm.j9ddr.tools.ddrinteractive.DDRInteractive.processLine(DDRInteractive.java:331)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at com.ibm.jvm.dtfjview.CombinedContext.executeDDRInteractiveCommand(CombinedContext.java:260)
    at com.ibm.jvm.dtfjview.CombinedContext.execute(CombinedContext.java:170)
    at com.ibm.jvm.dtfjview.Session.execute(Session.java:811)
    at com.ibm.jvm.dtfjview.Session.execute(Session.java:765)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.executeJdmpviewCommand(ToolsRegistry.java:183)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.execute(ToolsRegistry.java:107)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.execute(ToolsRegistry.java:88)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.recordAndExecute(ToolsRegistry.java:72)
    at com.ibm.jvm.dtfjview.Session.runInteractive(Session.java:739)
    at com.ibm.jvm.dtfjview.Session.run(Session.java:663)
    at com.ibm.jvm.dtfjview.DTFJView.launch(DTFJView.java:52)
    at com.ibm.jvm.dtfjview.DTFJView.main(DTFJView.java:46)

<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0538] = UDATA(0x0000000000000011) (jit_rbx)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0578] = UDATA(0x0000000000000000) (jit_r9)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0580] = UDATA(0x0000000000000000) (jit_r10)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0588] = UDATA(0x00000000000176B0) (jit_r11)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0590] = UDATA(0x00000000000177B8) (jit_r12)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0598] = UDATA(0x00007FCACD3A05E8) (jit_r13)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A05A0] = UDATA(0x00007FCAC809BF70) (jit_r14)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A05A8] = UDATA(0x00007FCAC5E20FC9) (jit_r15)
<18100> I2J values: PC = 0x00007FCACC521914, A0 = 0x0000000000051170, walkSP = 0x0000000000051150, literals = 0x0000000000000000, JIT PC = 0x00007FCAC64E1090, pcAddress = 0x00007FCACD3A06A8, decomp = 0x0000000000000000
<18100> JNI call-in frame: bp = 0x0000000000051170, sp = 0x0000000000051150, pc = 0x00007FCACC521914, cp = 0x0000000000000000, arg0EA = 0x0000000000051170, flags = 0x0000000000000000
<18100>     New ELS = 0x00007FCACD3A0910
<18100> JIT resolve frame: bp = 0x00000000000511A8, sp = 0x0000000000051178, pc = 0x0000000000000005, cp = 0x0000000000000000, arg0EA = 0x00000000000511A8, flags = 0x0000000000080000
<18100>     Object push (savedJITException)
<18100>         O-Slot[0x0000000000051188] = 0x0000000000000000
<18100>     Object pushes starting at 0x0000000000051178 for 2 slots
<18100>         Push[0x0000000000051178] = 0x00000000390A0438
<18100>         Push[0x0000000000051180] = 0x0000000000000000
<18100>     Generic resolve
<18100>     unwindSP initialized to 0x00000000000511B0
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A07C0] = UDATA(0x00000000390A0418) (jit_rax)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A07C8] = UDATA(0x0000000000000011) (jit_rbx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A07D0] = UDATA(0xFFFFFFFFFFEE72EC) (jit_rcx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A07D8] = UDATA(0x0000000000000000) (jit_rdx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A07E0] = UDATA(0x00007FCACC521914) (jit_rdi)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A07E8] = UDATA(0x0000000000000000) (jit_rsi)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A07F0] = UDATA(0x0000000000018100) (jit_rbp)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A07F8] = UDATA(0x0000000000004000) (jit_rsp)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0800] = UDATA(0x00007FCA7945936A) (jit_r8)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0808] = UDATA(0x0000000000000000) (jit_r9)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0810] = UDATA(0x0000000000000000) (jit_r10)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0818] = UDATA(0x0000000000017730) (jit_r11)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0820] = UDATA(0x0000000000017838) (jit_r12)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0828] = UDATA(0x00007FCACD3A0878) (jit_r13)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0830] = UDATA(0x00007FCAC809BF70) (jit_r14)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0838] = UDATA(0x00007FCAC5E20FC9) (jit_r15)
<18100> JIT frame: bp = 0x00000000000511C8, pc = 0x00007FCAB10E4283, unwindSP = 0x00000000000511B0, cp = 0x0000000000049970, arg0EA = 0x00000000000511D8, jitInfo = 0x00007FCA933572F8
<18100>     Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V !j9method 0x0000000000049948
<18100>     Bytecode index = -1, inlineDepth = 0, PC offset = 0x0000000000000023
Nov 02, 2020 12:33:04 PM com.ibm.j9ddr.vm29.events.DefaultEventListener corruptData
WARNING: CorruptData encountered iterating o-slots. walkThread = 0x0000000000018100
com.ibm.j9ddr.AddressedCorruptDataException: Unable to locate JIT stack map
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker$JITStackWalker_29_V0.jitWalkFrame(JITStackWalker.java:1077)
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker$JITStackWalker_29_V0.jitWalkStackFrames(JITStackWalker.java:257)
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker.jitWalkStackFrames(JITStackWalker.java:101)
    at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker$StackWalker_29_V0.walkStackFrames(StackWalker.java:488)
    at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker.walkStackFrames(StackWalker.java:103)
    at com.ibm.j9ddr.vm29.tools.ddrinteractive.commands.StackWalkCommand.run(StackWalkCommand.java:139)
    at com.ibm.j9ddr.tools.ddrinteractive.Context.tryCommand(Context.java:229)
    at com.ibm.j9ddr.tools.ddrinteractive.Context.execute(Context.java:202)
    at com.ibm.j9ddr.tools.ddrinteractive.DDRInteractive.execute(DDRInteractive.java:356)
    at com.ibm.j9ddr.command.CommandReader.processLine(CommandReader.java:79)
    at com.ibm.j9ddr.tools.ddrinteractive.DDRInteractive.processLine(DDRInteractive.java:331)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at com.ibm.jvm.dtfjview.CombinedContext.executeDDRInteractiveCommand(CombinedContext.java:260)
    at com.ibm.jvm.dtfjview.CombinedContext.execute(CombinedContext.java:170)
    at com.ibm.jvm.dtfjview.Session.execute(Session.java:811)
    at com.ibm.jvm.dtfjview.Session.execute(Session.java:765)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.executeJdmpviewCommand(ToolsRegistry.java:183)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.execute(ToolsRegistry.java:107)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.execute(ToolsRegistry.java:88)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.recordAndExecute(ToolsRegistry.java:72)
    at com.ibm.jvm.dtfjview.Session.runInteractive(Session.java:739)
    at com.ibm.jvm.dtfjview.Session.run(Session.java:663)
    at com.ibm.jvm.dtfjview.DTFJView.launch(DTFJView.java:52)
    at com.ibm.jvm.dtfjview.DTFJView.main(DTFJView.java:46)

<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A07C8] = UDATA(0x0000000000000011) (jit_rbx)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0808] = UDATA(0x0000000000000000) (jit_r9)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0810] = UDATA(0x0000000000000000) (jit_r10)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0818] = UDATA(0x0000000000017730) (jit_r11)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0820] = UDATA(0x0000000000017838) (jit_r12)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0828] = UDATA(0x00007FCACD3A0878) (jit_r13)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0830] = UDATA(0x00007FCAC809BF70) (jit_r14)
<18100>     JIT-Frame-RegisterMap[0x00007FCACD3A0838] = UDATA(0x00007FCAC5E20FC9) (jit_r15)
<18100> I2J values: PC = 0x00007FCACC521914, A0 = 0x0000000000051200, walkSP = 0x00000000000511E0, literals = 0x0000000000000000, JIT PC = 0x00007FCAC64E1090, pcAddress = 0x00007FCACD3A0938, decomp = 0x0000000000000000
<18100> JNI call-in frame: bp = 0x0000000000051200, sp = 0x00000000000511E0, pc = 0x00007FCACC521914, cp = 0x0000000000000000, arg0EA = 0x0000000000051200, flags = 0x0000000000000000
<18100>     New ELS = 0x00007FCACD3A0BA0
<18100> JIT resolve frame: bp = 0x0000000000051238, sp = 0x0000000000051208, pc = 0x0000000000000005, cp = 0x0000000000000000, arg0EA = 0x0000000000051238, flags = 0x0000000000080000
<18100>     Object push (savedJITException)
<18100>         O-Slot[0x0000000000051218] = 0x0000000000000000
<18100>     Object pushes starting at 0x0000000000051208 for 2 slots
<18100>         Push[0x0000000000051208] = 0x00000000390A0418
<18100>         Push[0x0000000000051210] = 0x0000000000000000
<18100>     Generic resolve
<18100>     unwindSP initialized to 0x0000000000051240
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0A50] = UDATA(0x00000000390A03F8) (jit_rax)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0A58] = UDATA(0x0000000000000011) (jit_rbx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0A60] = UDATA(0xFFFFFFFFFFEE72EC) (jit_rcx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0A68] = UDATA(0x0000000000000000) (jit_rdx)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0A70] = UDATA(0x00007FCACC521914) (jit_rdi)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0A78] = UDATA(0x0000000000000000) (jit_rsi)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0A80] = UDATA(0x0000000000018100) (jit_rbp)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0A88] = UDATA(0x0000000000004000) (jit_rsp)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0A90] = UDATA(0x00007FCA7945936A) (jit_r8)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0A98] = UDATA(0x0000000000000000) (jit_r9)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0AA0] = UDATA(0x0000000000000000) (jit_r10)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0AA8] = UDATA(0x00000000000177F0) (jit_r11)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0AB0] = UDATA(0x00000000000178F8) (jit_r12)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0AB8] = UDATA(0x00007FCACD3A0B08) (jit_r13)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0AC0] = UDATA(0x00007FCAC809BF70) (jit_r14)
<18100>     JIT-Resolve-RegisterMap[0x00007FCACD3A0AC8] = UDATA(0x00007FCAC5E20FC9) (jit_r15)
<18100> JIT frame: bp = 0x0000000000051258, pc = 0x00007FCAB10E4283, unwindSP = 0x0000000000051240, cp = 0x0000000000049970, arg0EA = 0x0000000000051268, jitInfo = 0x00007FCA933572F8
<18100>     Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V !j9method 0x0000000000049948
<18100>     Bytecode index = -1, inlineDepth = 0, PC offset = 0x0000000000000023
Nov 02, 2020 12:33:04 PM com.ibm.j9ddr.vm29.events.DefaultEventListener corruptData
WARNING: CorruptData encountered iterating o-slots. walkThread = 0x0000000000018100
com.ibm.j9ddr.AddressedCorruptDataException: Unable to locate JIT stack map
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker$JITStackWalker_29_V0.jitWalkFrame(JITStackWalker.java:1077)
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker$JITStackWalker_29_V0.jitWalkStackFrames(JITStackWalker.java:257)
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker.jitWalkStackFrames(JITStackWalker.java:101)
    at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker$StackWalker_29_V0.walkStackFrames(StackWalker.java:488)
    at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker.walkStackFrames(StackWalker.java:103)
    at com.ibm.j9ddr.vm29.tools.ddrinteractive.commands.StackWalkCommand.run(StackWalkCommand.java:139)
    at com.ibm.j9ddr.tools.ddrinteractive.Context.tryCommand(Context.java:229)
    at com.ibm.j9ddr.tools.ddrinteractive.Context.execute(Context.java:202)
    at com.ibm.j9ddr.tools.ddrinteractive.DDRInteractive.execute(DDRInteractive.java:356)
    at com.ibm.j9ddr.command.CommandReader.processLine(CommandReader.java:79)
    at com.ibm.j9ddr.tools.ddrinteractive.DDRInteractive.processLine(DDRInteractive.java:331)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at com.ibm.jvm.dtfjview.CombinedContext.executeDDRInteractiveCommand(CombinedContext.java:260)
    at com.ibm.jvm.dtfjview.CombinedContext.execute(CombinedContext.java:170)
    at com.ibm.jvm.dtfjview.Session.execute(Session.java:811)
    at com.ibm.jvm.dtfjview.Session.execute(Session.java:765)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.executeJdmpviewCommand(ToolsRegistry.java:183)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.execute(ToolsRegistry.java:107)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.execute(ToolsRegistry.java:88)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.recordAndExecute(ToolsRegistry.java:72)
    at com.ibm.jvm.dtfjview.Session.runInteractive(Session.java:739)
    at com.ibm.jvm.dtfjview.Session.run(Session.java:663)
    at com.ibm.jvm.dtfjview.DTFJView.launch(DTFJView.java:52)
    at com.ibm.jvm.dtfjview.DTFJView.main(DTFJView.java:46)

Nov 02, 2020 12:33:04 PM com.ibm.j9ddr.vm29.events.DefaultEventListener corruptData
WARNING: Corruption threshold hit. Will stop walking object slots on this thread. walkThread = 0x0000000000018100
com.ibm.j9ddr.AddressedCorruptDataException: Unable to locate JIT stack map
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker$JITStackWalker_29_V0.jitWalkFrame(JITStackWalker.java:1077)
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker$JITStackWalker_29_V0.jitWalkStackFrames(JITStackWalker.java:257)
    at com.ibm.j9ddr.vm29.j9.stackwalker.JITStackWalker.jitWalkStackFrames(JITStackWalker.java:101)
    at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker$StackWalker_29_V0.walkStackFrames(StackWalker.java:488)
    at com.ibm.j9ddr.vm29.j9.stackwalker.StackWalker.walkStackFrames(StackWalker.java:103)
    at com.ibm.j9ddr.vm29.tools.ddrinteractive.commands.StackWalkCommand.run(StackWalkCommand.java:139)
    at com.ibm.j9ddr.tools.ddrinteractive.Context.tryCommand(Context.java:229)
    at com.ibm.j9ddr.tools.ddrinteractive.Context.execute(Context.java:202)
    at com.ibm.j9ddr.tools.ddrinteractive.DDRInteractive.execute(DDRInteractive.java:356)
    at com.ibm.j9ddr.command.CommandReader.processLine(CommandReader.java:79)
    at com.ibm.j9ddr.tools.ddrinteractive.DDRInteractive.processLine(DDRInteractive.java:331)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at com.ibm.jvm.dtfjview.CombinedContext.executeDDRInteractiveCommand(CombinedContext.java:260)
    at com.ibm.jvm.dtfjview.CombinedContext.execute(CombinedContext.java:170)
    at com.ibm.jvm.dtfjview.Session.execute(Session.java:811)
    at com.ibm.jvm.dtfjview.Session.execute(Session.java:765)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.executeJdmpviewCommand(ToolsRegistry.java:183)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.execute(ToolsRegistry.java:107)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.execute(ToolsRegistry.java:88)
    at com.ibm.jvm.dtfjview.tools.ToolsRegistry.recordAndExecute(ToolsRegistry.java:72)
    at com.ibm.jvm.dtfjview.Session.runInteractive(Session.java:739)
    at com.ibm.jvm.dtfjview.Session.run(Session.java:663)
    at com.ibm.jvm.dtfjview.DTFJView.launch(DTFJView.java:52)
    at com.ibm.jvm.dtfjview.DTFJView.main(DTFJView.java:46)

<18100> I2J values: PC = 0x00007FCACC521914, A0 = 0x0000000000051290, walkSP = 0x0000000000051270, literals = 0x0000000000000000, JIT PC = 0x00007FCAC64E1090, pcAddress = 0x00007FCACD3A0BC8, decomp = 0x0000000000000000
<18100> JNI call-in frame: bp = 0x0000000000051290, sp = 0x0000000000051270, pc = 0x00007FCACC521914, cp = 0x0000000000000000, arg0EA = 0x0000000000051290, flags = 0x0000000000000000
<18100>     New ELS = 0x00007FCACD3A0E30
<18100> JIT resolve frame: bp = 0x00000000000512C8, sp = 0x0000000000051298, pc = 0x0000000000000005, cp = 0x0000000000000000, arg0EA = 0x00000000000512C8, flags = 0x0000000000080000
<18100>     Generic resolve
<18100>     unwindSP initialized to 0x00000000000512D0
<18100> JIT frame: bp = 0x00000000000512E8, pc = 0x00007FCAB10E4283, unwindSP = 0x00000000000512D0, cp = 0x0000000000049970, arg0EA = 0x00000000000512F8, jitInfo = 0x00007FCA933572F8
<18100>     Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V !j9method 0x0000000000049948
<18100>     Bytecode index = -1, inlineDepth = 0, PC offset = 0x0000000000000023
<18100> I2J values: PC = 0x00007FCACC521914, A0 = 0x0000000000051320, walkSP = 0x0000000000051300, literals = 0x0000000000000000, JIT PC = 0x00007FCAC64E1090, pcAddress = 0x00007FCACD3A0E58, decomp = 0x0000000000000000
<18100> JNI call-in frame: bp = 0x0000000000051320, sp = 0x0000000000051300, pc = 0x00007FCACC521914, cp = 0x0000000000000000, arg0EA = 0x0000000000051320, flags = 0x0000000000000000
<18100>     New ELS = 0x00007FCACD3A10C0
<18100> JIT resolve frame: bp = 0x0000000000051358, sp = 0x0000000000051328, pc = 0x0000000000000005, cp = 0x0000000000000000, arg0EA = 0x0000000000051358, flags = 0x0000000000080000
<18100>     Generic resolve
<18100>     unwindSP initialized to 0x0000000000051360
<18100> JIT frame: bp = 0x0000000000051378, pc = 0x00007FCAB10E4283, unwindSP = 0x0000000000051360, cp = 0x0000000000049970, arg0EA = 0x0000000000051388, jitInfo = 0x00007FCA933572F8
<18100>     Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V !j9method 0x0000000000049948
<18100>     Bytecode index = -1, inlineDepth = 0, PC offset = 0x0000000000000023
<18100> I2J values: PC = 0x00007FCACC521914, A0 = 0x00000000000513B0, walkSP = 0x0000000000051390, literals = 0x0000000000000000, JIT PC = 0x00007FCAC64E1090, pcAddress = 0x00007FCACD3A10E8, decomp = 0x0000000000000000
<18100> JNI call-in frame: bp = 0x00000000000513B0, sp = 0x0000000000051390, pc = 0x00007FCACC521914, cp = 0x0000000000000000, arg0EA = 0x00000000000513B0, flags = 0x0000000000000000
<18100>     New ELS = 0x00007FCACD3A1350
<18100> JIT resolve frame: bp = 0x00000000000513E8, sp = 0x00000000000513B8, pc = 0x0000000000000005, cp = 0x0000000000000000, arg0EA = 0x00000000000513E8, flags = 0x0000000000080000
<18100>     Generic resolve
<18100>     unwindSP initialized to 0x00000000000513F0
<18100> JIT frame: bp = 0x0000000000051408, pc = 0x00007FCAB10E4283, unwindSP = 0x00000000000513F0, cp = 0x0000000000049970, arg0EA = 0x0000000000051418, jitInfo = 0x00007FCA933572F8
<18100>     Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V !j9method 0x0000000000049948
<18100>     Bytecode index = -1, inlineDepth = 0, PC offset = 0x0000000000000023
<18100> I2J values: PC = 0x00007FCACC521914, A0 = 0x0000000000051440, walkSP = 0x0000000000051420, literals = 0x0000000000000000, JIT PC = 0x00007FCAC64E1090, pcAddress = 0x00007FCACD3A1378, decomp = 0x0000000000000000
<18100> JNI call-in frame: bp = 0x0000000000051440, sp = 0x0000000000051420, pc = 0x00007FCACC521914, cp = 0x0000000000000000, arg0EA = 0x0000000000051440, flags = 0x0000000000000000
<18100>     New ELS = 0x00007FCACD3A15E0
<18100> JIT resolve frame: bp = 0x0000000000051478, sp = 0x0000000000051448, pc = 0x0000000000000005, cp = 0x0000000000000000, arg0EA = 0x0000000000051478, flags = 0x0000000000080000
<18100>     Generic resolve
<18100>     unwindSP initialized to 0x0000000000051480
<18100> JIT frame: bp = 0x0000000000051498, pc = 0x00007FCAB10E4283, unwindSP = 0x0000000000051480, cp = 0x0000000000049970, arg0EA = 0x00000000000514A8, jitInfo = 0x00007FCA933572F8
<18100>     Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V !j9method 0x0000000000049948
<18100>     Bytecode index = -1, inlineDepth = 0, PC offset = 0x0000000000000023
<18100> I2J values: PC = 0x00007FCACC521914, A0 = 0x00000000000514D0, walkSP = 0x00000000000514B0, literals = 0x0000000000000000, JIT PC = 0x00007FCAC64E1090, pcAddress = 0x00007FCACD3A1608, decomp = 0x0000000000000000
<18100> JNI call-in frame: bp = 0x00000000000514D0, sp = 0x00000000000514B0, pc = 0x00007FCACC521914, cp = 0x0000000000000000, arg0EA = 0x00000000000514D0, flags = 0x0000000000000000
<18100>     New ELS = 0x00007FCACD3A1870
<18100> JIT resolve frame: bp = 0x0000000000051508, sp = 0x00000000000514D8, pc = 0x0000000000000005, cp = 0x0000000000000000, arg0EA = 0x0000000000051508, flags = 0x0000000000080000
<18100>     Generic resolve
<18100>     unwindSP initialized to 0x0000000000051510
<18100> JIT frame: bp = 0x0000000000051528, pc = 0x00007FCAB10E4283, unwindSP = 0x0000000000051510, cp = 0x0000000000049970, arg0EA = 0x0000000000051538, jitInfo = 0x00007FCA933572F8
<18100>     Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V !j9method 0x0000000000049948
<18100>     Bytecode index = -1, inlineDepth = 0, PC offset = 0x0000000000000023
<18100> I2J values: PC = 0x00007FCACC521914, A0 = 0x0000000000051560, walkSP = 0x0000000000051540, literals = 0x0000000000000000, JIT PC = 0x00007FCAC64E1090, pcAddress = 0x00007FCACD3A1898, decomp = 0x0000000000000000
<18100> JNI call-in frame: bp = 0x0000000000051560, sp = 0x0000000000051540, pc = 0x00007FCACC521914, cp = 0x0000000000000000, arg0EA = 0x0000000000051560, flags = 0x0000000000000000
<18100>     New ELS = 0x00007FCACD3A1B00
<18100> JIT resolve frame: bp = 0x0000000000051598, sp = 0x0000000000051568, pc = 0x0000000000000005, cp = 0x0000000000000000, arg0EA = 0x0000000000051598, flags = 0x0000000000080000
<18100>     Generic resolve
<18100>     unwindSP initialized to 0x00000000000515A0
<18100> JIT frame: bp = 0x00000000000515B8, pc = 0x00007FCAB10E4283, unwindSP = 0x00000000000515A0, cp = 0x0000000000049970, arg0EA = 0x00000000000515C8, jitInfo = 0x00007FCA933572F8
<18100>     Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V !j9method 0x0000000000049948
<18100>     Bytecode index = -1, inlineDepth = 0, PC offset = 0x0000000000000023
<18100> I2J values: PC = 0x00007FCACC521914, A0 = 0x00000000000515F0, walkSP = 0x00000000000515D0, literals = 0x0000000000000000, JIT PC = 0x00007FCAC64E1090, pcAddress = 0x00007FCACD3A1B28, decomp = 0x0000000000000000
<18100> JNI call-in frame: bp = 0x00000000000515F0, sp = 0x00000000000515D0, pc = 0x00007FCACC521914, cp = 0x0000000000000000, arg0EA = 0x00000000000515F0, flags = 0x0000000000000000
<18100>     New ELS = 0x00007FCACD3A1D90
<18100> JIT resolve frame: bp = 0x0000000000051628, sp = 0x00000000000515F8, pc = 0x0000000000000005, cp = 0x0000000000000000, arg0EA = 0x0000000000051628, flags = 0x0000000000080000
<18100>     Generic resolve
<18100>     unwindSP initialized to 0x0000000000051630
<18100> JIT frame: bp = 0x0000000000051648, pc = 0x00007FCAB10E4283, unwindSP = 0x0000000000051630, cp = 0x0000000000049970, arg0EA = 0x0000000000051658, jitInfo = 0x00007FCA933572F8
<18100>     Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V !j9method 0x0000000000049948
<18100>     Bytecode index = -1, inlineDepth = 0, PC offset = 0x0000000000000023
<18100> I2J values: PC = 0x00007FCACC521914, A0 = 0x0000000000051680, walkSP = 0x0000000000051660, literals = 0x0000000000000000, JIT PC = 0x00007FCAC64E1090, pcAddress = 0x00007FCACD3A1DB8, decomp = 0x0000000000000000
<18100> JNI call-in frame: bp = 0x0000000000051680, sp = 0x0000000000051660, pc = 0x00007FCACC521914, cp = 0x0000000000000000, arg0EA = 0x0000000000051680, flags = 0x0000000000000000
<18100>     New ELS = 0x00007FCACD3A2020
<18100> JIT resolve frame: bp = 0x00000000000516B8, sp = 0x0000000000051688, pc = 0x0000000000000005, cp = 0x0000000000000000, arg0EA = 0x00000000000516B8, flags = 0x0000000000080000
<18100>     Generic resolve
<18100>     unwindSP initialized to 0x00000000000516C0
<18100> JIT frame: bp = 0x00000000000516D8, pc = 0x00007FCAB10E4283, unwindSP = 0x00000000000516C0, cp = 0x0000000000049970, arg0EA = 0x00000000000516E8, jitInfo = 0x00007FCA933572F8
<18100>     Method: java/lang/NullPointerException.<init>(Ljava/lang/String;)V !j9method 0x0000000000049948
<18100>     Bytecode index = -1, inlineDepth = 0, PC offset = 0x0000000000000023
<18100> I2J values: PC = 0x00007FCACC521914, A0 = 0x0000000000051710, walkSP = 0x00000000000516F0, literals = 0x0000000000000000, JIT PC = 0x00007FCAC64E1090, pcAddress = 0x00007FCACD3A2048, decomp = 0x0000000000000000
<18100> JNI call-in frame: bp = 0x0000000000051710, sp = 0x00000000000516F0, pc = 0x00007FCACC521914, cp = 0x0000000000000000, arg0EA = 0x0000000000051710, flags = 0x0000000000000000
<18100>     New ELS = 0x00007FCACD3A22A0
<18100> JIT resolve frame: bp = 0x0000000000051748, sp = 0x0000000000051718, pc = 0x0000000000000005, cp = 0x0000000000000000, arg0EA = 0x0000000000051748, flags = 0x0000000000080000
<18100>     Generic resolve
<18100>     unwindSP initialized to 0x0000000000051750
<18100> JIT frame: bp = 0x0000000000051768, pc = 0x00007FCAB10E4083, unwindSP = 0x0000000000051750, cp = 0x0000000000047FF0, arg0EA = 0x0000000000051778, jitInfo = 0x00007FCA93357038
<18100>     Method: java/lang/String$CaseInsensitiveComparator.<init>(Ljava/lang/String$1;)V !j9method 0x0000000000047BF0
<18100>     Bytecode index = -1, inlineDepth = 0, PC offset = 0x0000000000000023
<18100> I2J values: PC = 0x00007FCA794703F7, A0 = 0x00000000000517B0, walkSP = 0x0000000000051788, literals = 0x0000000000046A38, JIT PC = 0x00007FCAC64E1090, pcAddress = 0x00007FCACD3A22C8, decomp = 0x0000000000000000
<18100> Bytecode frame: bp = 0x00000000000517A0, sp = 0x0000000000051788, pc = 0x00007FCA794703F7, cp = 0x00000000000447F0, arg0EA = 0x00000000000517B0, flags = 0x0000000000000000
<18100>     Method: java/lang/String.<clinit>()V !j9method 0x0000000000046A38
<18100> JNI call-in frame: bp = 0x00000000000517D8, sp = 0x00000000000517B8, pc = 0x00007FCACC521914, cp = 0x0000000000000000, arg0EA = 0x00000000000517D8, flags = 0x0000000000000000
<18100>     New ELS = 0x0000000000000000
<18100> JNI native method frame: bp = 0x0000000000051808, sp = 0x00000000000517E0, pc = 0x0000000000000007, cp = 0x0000000000000000, arg0EA = 0x0000000000051808, flags = 0x0000000000000000
<18100> <end of stack>
<18100> *** END STACK WALK (rc = STACK_CORRUPT) ***
Stack walk result: STACK_CORRUPT
gacholio commented 3 years ago

Disassembly of NullPointerException.init<>:

   0x7fcab10e4260:  mov    0x10(%rsp),%rax
   0x7fcab10e4265:  mov    0x8(%rsp),%rsi
   0x7fcab10e426a:  mov    %rax,0x10(%rsp)
   0x7fcab10e426f:  mov    %rsi,0x8(%rsp)
   0x7fcab10e4274:  cmp    0x50(%rbp),%rsp
   0x7fcab10e4278:  jbe    0x7fcab10e43eb
   0x7fcab10e427e:  sub    $0x18,%rsp
   0x7fcab10e4282:  movzbl -0x769ea1e2(%rip),%ecx        # 0x7fca3a6fa0a7
   0x7fcab10e4289:  test   $0x1,%cl
   0x7fcab10e428c:  jne    0x7fcab10e4349
   0x7fcab10e4292:  movzbl -0x769ea1f2(%rip),%ecx        # 0x7fca3a6fa0a7
   0x7fcab10e4299:  test   $0x1,%cl
   0x7fcab10e429c:  jne    0x7fcab10e4372
   0x7fcab10e42a2:  nopw   0x0(%rax,%rax,1)
   0x7fcab10e42a8:  callq  0x7fcab10e43fa
   0x7fcab10e42ad:  movzbl -0x769ea20b(%rip),%eax        # 0x7fca3a6fa0a9
   0x7fcab10e42b4:  test   $0x1,%al
   0x7fcab10e42b7:  jne    0x7fcab10e43be
   0x7fcab10e42bd:  movzbl -0x769ea21b(%rip),%eax        # 0x7fca3a6fa0a9
   0x7fcab10e42c4:  test   $0x1,%al
   0x7fcab10e42c7:  jne    0x7fcab10e43da
   0x7fcab10e42cd:  add    $0x18,%rsp
   0x7fcab10e42d1:  retq   
   0x7fcab10e42d2:  mov    0x28(%rsp),%rax
   0x7fcab10e42d7:  mov    0x20(%rsp),%rsi
   0x7fcab10e42dc:  mov    0x154(%rbp),%ecx
   0x7fcab10e42e2:  lea    0x50(%rcx),%edi
   0x7fcab10e42e5:  movslq %edi,%rdi
   0x7fcab10e42e8:  mov    0x8e0(%rbp),%rdx
   0x7fcab10e42ef:  mov    %rax,0x0(%rdi,%rdx,1)
   0x7fcab10e42f4:  lea    0x48(%rcx),%eax
   0x7fcab10e42f7:  movslq %eax,%rax
   0x7fcab10e42fa:  mov    %rsi,0x0(%rax,%rdx,1)
   0x7fcab10e42ff:  add    $0x58,%ecx
   0x7fcab10e4302:  mov    %ecx,0x154(%rbp)
   0x7fcab10e4308:  mov    0x8e8(%rbp),%rax
   0x7fcab10e430f:  jmpq   *%rax
   0x7fcab10e4311:  mov    0x28(%rsp),%rax
   0x7fcab10e4316:  mov    0x154(%rbp),%ecx
   0x7fcab10e431c:  lea    0x50(%rcx),%edx
   0x7fcab10e431f:  movslq %edx,%rdx
   0x7fcab10e4322:  mov    0x8e0(%rbp),%rdi
   0x7fcab10e4329:  mov    %rax,0x0(%rdx,%rdi,1)
   0x7fcab10e432e:  mov    0x20(%rsp),%rsi
   0x7fcab10e4333:  lea    0x48(%rcx),%edx
   0x7fcab10e4336:  movslq %edx,%rdx
   0x7fcab10e4339:  mov    %rsi,0x0(%rdx,%rdi,1)
   0x7fcab10e433e:  add    $0x58,%ecx
   0x7fcab10e4341:  mov    %ecx,0x154(%rbp)
   0x7fcab10e4347:  jmp    0x7fcab10e42dc
   0x7fcab10e4349:  mov    %rsi,%rdx
   0x7fcab10e434c:  mov    %rax,%rcx
   0x7fcab10e434f:  mov    $0x49948,%eax
   0x7fcab10e4354:  mov    %rcx,%rsi
   0x7fcab10e4357:  callq  0x7fcac64d7440 <jitReportMethodEnter>
   0x7fcab10e435c:  mov    %rdx,%rsi
   0x7fcab10e435f:  mov    %rcx,%rax
   0x7fcab10e4362:  movzbl -0x769ea2c2(%rip),%ecx        # 0x7fca3a6fa0a7
   0x7fcab10e4369:  test   $0x1,%cl
   0x7fcab10e436c:  je     0x7fcab10e42a2
   0x7fcab10e4372:  mov    %rsi,%rdx
   0x7fcab10e4375:  mov    %rax,%rcx
   0x7fcab10e4378:  mov    $0x49548,%eax
   0x7fcab10e437d:  mov    %rcx,%rsi
   0x7fcab10e4380:  callq  0x7fcac64d7440 <jitReportMethodEnter>
   0x7fcab10e4385:  mov    %rdx,%rsi
   0x7fcab10e4388:  mov    %rcx,%rax
   0x7fcab10e438b:  nopl   0x0(%rax,%rax,1)
   0x7fcab10e4390:  callq  0x7fcab10e4413
   0x7fcab10e4395:  movzbl -0x769ea2f3(%rip),%eax        # 0x7fca3a6fa0a9
   0x7fcab10e439c:  test   $0x1,%al
   0x7fcab10e439f:  jne    0x7fcab10e43be
   0x7fcab10e43a1:  jmpq   0x7fcab10e42bd
   0x7fcab10e43a6:  xchg   %ax,%ax
   0x7fcab10e43a8:  callq  0x7fcab10e442c
   0x7fcab10e43ad:  movzbl -0x769ea30b(%rip),%eax        # 0x7fca3a6fa0a9
   0x7fcab10e43b4:  test   $0x1,%al
   0x7fcab10e43b7:  jne    0x7fcab10e43da
   0x7fcab10e43b9:  add    $0x18,%rsp
   0x7fcab10e43bd:  retq   
   0x7fcab10e43be:  mov    $0x49548,%eax
   0x7fcab10e43c3:  xor    %esi,%esi
   0x7fcab10e43c5:  callq  0x7fcac64d7860 <jitReportMethodExit>
   0x7fcab10e43ca:  movzbl -0x769ea328(%rip),%eax        # 0x7fca3a6fa0a9
   0x7fcab10e43d1:  test   $0x1,%al
   0x7fcab10e43d4:  je     0x7fcab10e42cd
   0x7fcab10e43da:  mov    $0x49948,%eax
   0x7fcab10e43df:  xor    %esi,%esi
   0x7fcab10e43e1:  callq  0x7fcac64d7860 <jitReportMethodExit>
   0x7fcab10e43e6:  add    $0x18,%rsp
   0x7fcab10e43ea:  retq   
   0x7fcab10e43eb:  mov    $0x18,%edi
   0x7fcab10e43f0:  callq  0x7fcac64d6750 <jitStackOverflow>
   0x7fcab10e43f5:  jmpq   0x7fcab10e427e
   0x7fcab10e43fa:  mov    %rax,0x10(%rsp)
   0x7fcab10e43ff:  mov    %rsi,0x8(%rsp)
   0x7fcab10e4404:  movabs $0x49148,%rdi
   0x7fcab10e440e:  jmpq   0x7fcac5ec7cc0 <interpreterStaticAndSpecialGlue>
   0x7fcab10e4413:  mov    %rax,0x10(%rsp)
   0x7fcab10e4418:  mov    %rsi,0x8(%rsp)
   0x7fcab10e441d:  movabs $0x49148,%rdi
   0x7fcab10e4427:  jmpq   0x7fcac5ec7cc0 <interpreterStaticAndSpecialGlue>
   0x7fcab10e442c:  mov    %rax,0x10(%rsp)
   0x7fcab10e4431:  mov    %rsi,0x8(%rsp)
   0x7fcab10e4436:  movabs $0x49548,%rdi
   0x7fcab10e4440:  jmpq   0x7fcac5ec7cc0 <interpreterStaticAndSpecialGlue>
gacholio commented 3 years ago

Based on the above code, I don't see anywhere that could have a JIT PC of 0x00007FCAB10E4283 (1 beyond 0x00007FCAB10E4282 which is at least a valid instruction, likely at bytecode 0).

Based on the PC appearing so many times in the stack, it's not likely to be a patching issue at 0x00007FCAB10E4282. Based on the NOPs, it looks there has been some patching of unresolved calls to the super constructor(s).

The interleaved resolve frames tell me that the recursion is likely occurring at the method enter or exit reporting, which should not be firing as the test does not reserve the capabilities or enable the events.

I suspect this is an issue with JIT server not understanding how the VM is configured. If the VM is not reporting method enter/exit, the so-called "extended method block" is not created, so the code that's querying to see if enter/exit is enabled is reading random memory.

gacholio commented 3 years ago
> !j9javavm 0x00007FCAC8013730 |grep runtimeF
    0xc8: U32 runtimeFlags = 0x00200022 (2097186)

#define J9_RUNTIME_EXTENDED_METHOD_BLOCK 0x200000

Nope - looks like the block is enabled.

dmitry-ten commented 3 years ago

Yeah, JITServer should be correctly checking with the VM if the method enter/exit tracing is enabled. Hook addresses and extended flags pointers should also be retrieved from the VM.

gacholio commented 3 years ago

I do see something suspicious - the code is testing the same byte twice for two different method enter checks (and the two exit checks). These bytes should represent the inlined super constructors, so they could not possibly have the same address for the check byte.

That doesn't explain the recursion or the bad JIT PC, but there's something clearly wrong in the codegen here. If this issue is repeatable, I suggest building a debug VM and stepping the code in question to see what the actual sequence of events is.

This is running in forced JDWP mode, so method enter and exit have very likely been hooked, but if the JDWP event handler were firing and calling back in, there would be a JNI callout frame between the JNI callin and resolve frames. The other user of the event is method trace, which does not appear to be enabled, and would not call back to java in any event.

dmitry-ten commented 3 years ago

I'm not sure I understand. This is the code that creates the IL tree for the test: https://github.com/eclipse/openj9/blob/40f5a96154580755c3bc252241c17a77c5d6d35a/runtime/compiler/env/VMJ9.cpp#L3237-L3258

   0x7fcab10e4282:  movzbl -0x769ea1e2(%rip),%ecx        # 0x7fca3a6fa0a7
   0x7fcab10e4289:  test   $0x1,%cl
   0x7fcab10e428c:  jne    0x7fcab10e4349

So it's testing the flag of enter/exit hook. Wouldn't that address be the same for all method enter checks?

gacholio commented 3 years ago

Yes, I thought it was doing the optimized version and checking the method itself, so I'm even more mystified than before about what's going on.

gacholio commented 3 years ago

If you can provide me something simple to reproduce this on Java 8 then I can step through the VM code and see what's up.

dmitry-ten commented 3 years ago

This failure is very intermittent, I can reproduce it in around 1/100 runs.

To start JITServer:
> ~/debug/j2sdk-image/bin/jitserver
To run the test:
> sudo TEST_JDK_HOME=~/debug/j2sdk-image EXTRA_OPTIONS=" -XX:+UseJITServer " make _cmdLineTester_jvmtitests_debug_openj9_none_SCC_3

The problem is that NullPointerException.<init> doesn't get compiled every run, despite the test running with count=0. I tried passing dontInline to the test, but that doesn't force the compile either. So this makes stepping through the VM code pretty difficult to setup.

dmitry-ten commented 3 years ago

Interestingly, so far I haven't seen any compilations of NullPointerException.<init> in _cmdLineTester_jvmtitests_debug_openj9_none_SCC_3 without JITServer enabled. I've done around 200 runs so far. Could there be any reasons why JIT shouldn't be compiling that method with FSD enabled?

gacholio commented 3 years ago

Does it fail every time that NPE init is compiled? If so, we can use a method selective breakOnEntry.

I can't think of any reason FSD would prevent the compilation - perhaps the root of the problem is hitting the NPE in the first place. I would not have expected there to be intentional NPEs during the construction of the comparator, though I haven't looked at the bytecodes. It's also annoying that every bcIndex seems to be -1 in the stack.

dmitry-ten commented 3 years ago

Yes, it fails every time the constructor is compiled. How is breakOnEntry used?

Hm, so if the problem is actually in java/lang/String$CaseInsensitiveComparator.<init>(Ljava/lang/String$1;)V I should probably trace that method too

gacholio commented 3 years ago

breakOnEntry is specified like any other JIT option - it can be filtered down to the method level. It inserts an int 3 instruction at the start of tagged methods which will stop in gdb/windbg so you can step from then on.

gacholio commented 3 years ago

The comparator bytecodes:

> !bytecodes 0x0000000000047BF0
  Name: <init>
  Signature: (Ljava/lang/String$1;)V
  Access Flags (1041000): default synthetic 
  Max Stack: 1
  Argument Count: 2
  Temp Count: 0

    0 aload0 
    1 invokespecial 1 java/lang/String$CaseInsensitiveComparator.<init>()V
    4 returnFromConstructor 

There's exactly one point where NPE could occur there (based on the java stack the call was not inlined), indicating that the receiver was null, which is impossible, particularly since the String static initializer that called this is not compiled (the interpreter will always throw NPE if the receiver of an invokespecial bytecode is null - all constructor invocations are invokespecial).

I'm increasingly baffled by what's going on here.

dmitry-ten commented 3 years ago

There is a similar issue where we actually get NPE instead of this failure. I wonder if that's related.

gacholio commented 3 years ago

That test is also enabling method enter and it's early on in startup so it seems likely to be the same problem.

dmitry-ten commented 3 years ago

Looking at sun/reflect/Reflection.getCallerClass trace, I don't see anything suspicious there either. It calls a method enter hook if tracing is enabled and then jumps to the native method. Since the method is so simple the only thing I can think of that can go wrong is if sometimes the method is not actually traced, but the server thinks it is traced for some reason. We do caching of which methods are traced on the server, but it's done per client and whenever a class gets unloaded or redefined tracing info of its methods gets deleted too.

dmitry-ten commented 3 years ago

There is one suspicious thing that could be related to this issue: From the failing core dump:

   0x00007fbd47987282:  movzbl 0x4be47c4e(%rip),%ecx        # 0x7fbd937ceed7
   0x00007fbd47987289:  test   $0x1,%cl
   0x00007fbd4798728c:  jne    0x7fbd47987349

0x4be47c4e(%rip) should be the address of the hook. Based on the comment, 0x4be47c4e(%rip)=0x7fbd937ceed7. However 0x7fbd937ceed7 is an invalid address. Either 0x7fbd937ceed7 is not actually the address of the hook, and I misunderstand what it means, or the address of the hook is somehow wrong. But this shouldn't be possible, because JITServer requests it from the client every time, no caching involved.

liqunl commented 3 years ago

Why is the address of hook related to rip? If the offset to rip is relative to the instruction address in the server VM, and the JIT code got relocated in the client VM, then the offset is wrong.

dmitry-ten commented 3 years ago

I'm not sure why it's rip. In the trace file it's

 movzx       ecx, byte ptr [$0x00007fb890016367]
liqunl commented 3 years ago

The rip in the instruction should be next instruction's address. I just took a look at the trace log, the offset is relative to the instruction address in the server VM.

We need to change the encoding for JITServer, but I don't know where the encoding for X86 memory reference is done. @0xdaryl May I ask for your help?

gacholio commented 3 years ago

If the address is unreadable, I would expect a crash rather than an NPE (NPE is only thrown for crashes in a small region above address 0).

dmitry-ten commented 3 years ago

https://github.com/eclipse/omr/pull/5658 fixes JIT stackmap not found crashes in cmdLineTester_jvmtitests_debug_openj9_none_SCC tests but now I see a NPE always being thrown in cmdLineTester_jvmtitests . So I'm continuing to investigate this issue. It's possible that fixing one problem just exposed another.

dmitry-ten commented 3 years ago

This should finally be fixed by eclipse/omr#5658. I'll run tests in Grinder and verify that the problem is gone, then the issue can be closed.

dmitry-ten commented 3 years ago

@mpirvu, a run of 200 tests timed out due to each test taking too long. But out of 82 tests run, all passed, so this can probably be closed.

mpirvu commented 3 years ago

Fixed by https://github.com/eclipse/omr/pull/5658 Closing based on the previous message.