Openj9: AIX JDK8 : testBCIUsingASM_inject_call_to_timer_method Segmentation error vmState=0x00040000

Created on 8 May 2020 · 19Comments · Source: eclipse/openj9

Failure link

From an internal build jvm29.ibuild.445771:

"/bluebird/builds/bld_445771/sdk/ap6480/bin/java" -version
java version "1.8.0_251"
Java(TM) SE Runtime Environment (build 8.0.7.0 - pap6480sr7-20200428_02(SR7))
IBM J9 VM (build 2.9, JRE 1.8.0 AIX ppc64-64-Bit Compressed References 20200501_445771 (JIT enabled, AOT enabled)
OpenJ9   - d25e1cb (266e5b6)
OMR      - 2571f98 (c4a6b90)
IBM      - 19f2e5e)
JCL - 20200407_01 based on Oracle jdk8u251-b08

Optional info

It appears a regression between ibuild 445695 and 445771.
Last passing build:

java version "1.8.0_251"
Java(TM) SE Runtime Environment (build 8.0.7.0 - pap6480sr7-20200428_02(SR7))
IBM J9 VM (build 2.9, JRE 1.8.0 AIX ppc64-64-Bit Compressed References 20200430_445695 (JIT enabled, AOT enabled)
OpenJ9   - 4bb0d55 (ef109f7)
OMR      - 325acab (f228516)
IBM      - 19f2e5e)
JCL - 20200407_01 based on Oracle jdk8u251-b08

https://github.com/eclipse/openj9/compare/ef109f7...266e5b6
https://github.com/eclipse/omr/compare/f228516...c4a6b90

cmdLineTester_jvmtitests_hcr_OSRG_nongold

Testing: ta001
Test start time: 2020/05/02 02:02:25 Eastern Standard Time
Running command: "bld_445771/sdk/ap6480/bin/java"  -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:ta001 -cp "bld_445771/jvmtest/test/SE80/functional/cmdLineTests/jvmtitests/jvmtitest.jar:bld_445771/jvmtest/test/SE80/TKG/lib/asm-all.jar" com.ibm.jvmti.tests.util.TestRunner

Last working command:

Running command: "bld_445695/sdk/ap6480/bin/java" -Xnocompressedrefs -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:ta001 -cp "bld_445695/jvmtest/test/SE80/functional/cmdLineTests/jvmtitests/jvmtitest.jar:bld_445695/jvmtest/test/SE80/TKG/lib/asm-all.jar" com.ibm.jvmti.tests.util.TestRunner

Failure output (captured from console output)

[OUT] *** Testing [10/13]:     testBCIUsingASM_inject_call_to_timer_method
 [ERR] Unhandled exception
 [ERR] Type=Segmentation error vmState=0x00040000
 [ERR] J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000033
 [ERR] Handler1=09001000A077E8F8 Handler2=09001000A075B0E0
 [ERR] R0=7C9B02A67CF242A5 R1=0000010023A0F060 R2=09001000A0929308 R3=7C9B02A67CF242A6
 [ERR] R4=00000100103E9278 R5=00000100239D5000 R6=0000000000000000 R7=000000000000002F
 [ERR] R8=0000000000000006 R9=0000000000000000 R10=0000000000000000 R11=0000000000000000
 [ERR] R12=09001000A0140278 R13=0000010023A20800 R14=00000000301F8270 R15=0000010023A11350
 [ERR] R16=0000010020E8FAB8 R17=0000000000000001 R18=09001000A073A6E0 R19=0000010022D381B8
 [ERR] R20=000000000000001A R21=0000010023A0F218 R22=0000000000000000 R23=0000000000000000
 [ERR] R24=09001000A073A6E0 R25=09001000A0739D58 R26=00000100101857D0 R27=09001000A080DE10
 [ERR] R28=0000000000000000 R29=0000000000000000 R30=00000100103E9278 R31=0000000000000000
 [ERR] IAR=090000000751D798 LR=090000000751A210 MSR=A00000000200D032 CTR=090000000053ACE0
 [ERR] CR=2CA8120420000003 FPSCR=8200000000000000 XER=2000000382000000
 [ERR] FPR0 0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] FPR1 0076006900630065 (f: 6488165.000000, d: 1.958208e-306)
 [ERR] FPR2 0041006400610070 (f: 6357104.000000, d: 1.891483e-307)
 [ERR] FPR3 007400650072002e (f: 7471150.000000, d: 1.780196e-306)
 [ERR] FPR4 4530000000000000 (f: 0.000000, d: 1.934281e+25)
 [ERR] FPR5 412e848000000000 (f: 0.000000, d: 1.000000e+06)
 [ERR] FPR6 43300000000f4240 (f: 1000000.000000, d: 4.503600e+15)
 [ERR] FPR7 4530000000000000 (f: 0.000000, d: 1.934281e+25)
 [ERR] FPR8 006f0062006a0065 (f: 6946917.000000, d: 1.379612e-306)
 [ERR] FPR9 0063007400770065 (f: 7798885.000000, d: 8.456068e-307)
 [ERR] FPR10 0062002f00610073 (f: 6357107.000000, d: 8.010585e-307)
 [ERR] FPR11 006d002f0063006f (f: 6488175.000000, d: 1.290575e-306)
 [ERR] FPR12 3ff0000000000000 (f: 0.000000, d: 1.000000e+00)
 [ERR] FPR13 3ff0000000000000 (f: 0.000000, d: 1.000000e+00)
 [ERR] FPR14 0000002d0000002d (f: 45.000000, d: 9.548981e-313)
 [ERR] FPR15 4046800000000000 (f: 0.000000, d: 4.500000e+01)
 [ERR] FPR16 4046800000000000 (f: 0.000000, d: 4.500000e+01)
 [ERR] FPR17 4046800000000000 (f: 0.000000, d: 4.500000e+01)
 [ERR] FPR18 0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] FPR19 0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] FPR20 0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] FPR21 0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] FPR22 0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] FPR23 0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] FPR24 0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] FPR25 0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] FPR26 0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] FPR27 0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] FPR28 0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] FPR29 0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] FPR30 0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] FPR31 0000000000000000 (f: 0.000000, d: 0.000000e+00)
 [ERR] Module=/bluebird/builds/bld_445771/sdk/ap6480/jre/bin/../lib/ppc64/default/libj9thr29.so
 [ERR] Module_base_address=0900000007516000
 [ERR] Target=2_90_20200501_445771 (AIX 6.1)
 [ERR] CPU=ppc64 (48 logical CPUs) (0x600000000 RAM)
 [ERR] ----------- Stack Backtrace -----------
 [ERR] (0x090000000751A210 [libj9thr29.so+0x4210])
 [ERR] JVM_GetSystemPackage_Impl+0x380 (0x0900000006D68A64 [libjclse29.so+0x8ba64])
 [ERR] JVM_GetSystemPackage+0x4c (0x0900000004EC7A50 [libjvm.so+0xfa50])
 [ERR] JVM_GetSystemPackage+0x40 (0x0900000004E8B2E4 [libjvm.so+0x52e4])
 [ERR] Java_java_lang_Package_getSystemPackage0+0x10 (0x0900000006DAE094 [libjava.so+0x16094])
 [ERR] (0x09000000050980BC [libj9vm29.so+0x1880bc])
 [ERR] ffi_call+0x98 (0x090000000509763C [libj9vm29.so+0x18763c])
 [ERR] (0x090000000509D78C [libj9vm29.so+0x18d78c])
 [ERR] (0x0900000004F795FC [libj9vm29.so+0x695fc])
 [ERR] sendLoadClass+0x1b8 (0x0900000004F6BA5C [libj9vm29.so+0x5ba5c])
 [ERR] internalFindClassInModule+0x2730 (0x0900000004F4B754 [libj9vm29.so+0x3b754])
 [ERR] internalCreateRAMClassFromROMClass+0x23c (0x0900000004F8B880 [libj9vm29.so+0x7b880])
 [ERR] internalDefineClass+0x308 (0x0900000004FFE58C [libj9vm29.so+0xee58c])
 [ERR] defineClassCommon+0x498 (0x0900000006CFD81C [libjclse29.so+0x2081c])
 [ERR] Java_java_lang_ClassLoader_defineClassImpl+0x110 (0x0900000006CFCDF4 [libjclse29.so+0x1fdf4])
 [ERR] (0x09000000050980BC [libj9vm29.so+0x1880bc])
 [ERR] ffi_call+0x98 (0x090000000509763C [libj9vm29.so+0x18763c])
 [ERR] (0x090000000509D78C [libj9vm29.so+0x18d78c])
 [ERR] (0x0900000004F795FC [libj9vm29.so+0x695fc])
 [ERR] sendLoadClass+0x1b8 (0x0900000004F6BA5C [libj9vm29.so+0x5ba5c])
 [ERR] internalFindClassInModule+0x2730 (0x0900000004F4B754 [libj9vm29.so+0x3b754])
 [ERR] j9rtv_verifierGetRAMClass+0x254 (0x0900000004FA40D8 [libj9vm29.so+0x940d8])
 [ERR] isClassCompatible+0x41c (0x0900000004F9BE20 [libj9vm29.so+0x8be20])
 [ERR] verifyBytecodes+0x1aa0 (0x0900000004FA6064 [libj9vm29.so+0x96064])
 [ERR] j9rtv_verifyBytecodes+0xa0 (0x0900000004FA43C4 [libj9vm29.so+0x943c4])
 [ERR] j9bcv_verifyBytecodes+0x958 (0x0900000004FA2DBC [libj9vm29.so+0x92dbc])
 [ERR] IPRA.$performVerification__FP10J9VMThreadP7J9Class+0x3d4 (0x0900000004F6A438 [libj9vm29.so+0x5a438])
 [ERR] IPRA.$classInitStateMachine__FP10J9VMThreadP7J9Class16J9ClassInitState+0x67c (0x0900000004F68A20 [libj9vm29.so+0x58a20])
 [ERR] initializeClass+0x60 (0x0900000004F69C24 [libj9vm29.so+0x59c24])
 [ERR] resolveClassRef+0x3ac (0x0900000004F7DAF0 [libj9vm29.so+0x6daf0])
 [ERR] (0x09000000050D80B0 [libj9vm29.so+0x1c80b0])
 [ERR] (0x0900000004F795FC [libj9vm29.so+0x695fc])
 [ERR] runJavaThread+0x1d0 (0x0900000004F6CFF4 [libj9vm29.so+0x5cff4])
 [ERR] javaProtectedThreadProc+0x118 (0x0900000004F1243C [libj9vm29.so+0x243c])
 [ERR] (0x09000000051D3FA8 [libj9prt29.so+0x4ffa8])
 [ERR] javaThreadProc+0x68 (0x0900000004F1222C [libj9vm29.so+0x222c])
 [ERR] (0x0900000005167A84 [libj9thr29.so+0x3a84])
 [ERR] _pthread_body+0xf0 (0x0900000000515D34 [libpthreads.a+0x3d34])
 [ERR] ---------------------------------------
 [ERR] JVMDUMP039I Processing dump event "gpf", detail "" at 2020/05/02 02:03:45 - please wait.
 [ERR] JVMDUMP032I JVM requested System dump using '/tmp/bld_445771/cmdLineTester_jvmtitests_hcr_OSRG_nongold_SE80_0/core.20200502.020345.8913052.0001.dmp' in response to an event
 [ERR] JVMDUMP010I System dump written to /tmp/bld_445771/cmdLineTester_jvmtitests_hcr_OSRG_nongold_SE80_0/core.20200502.020345.8913052.0001.dmp
 [ERR] JVMDUMP032I JVM requested Java dump using '/tmp/bld_445771/cmdLineTester_jvmtitests_hcr_OSRG_nongold_SE80_0/javacore.20200502.020345.8913052.0002.txt' in response to an event
 [ERR] JVMDUMP010I Java dump written to /tmp/bld_445771/cmdLineTester_jvmtitests_hcr_OSRG_nongold_SE80_0/javacore.20200502.020345.8913052.0002.txt
 [ERR] JVMDUMP032I JVM requested Snap dump using '/tmp/bld_445771/cmdLineTester_jvmtitests_hcr_OSRG_nongold_SE80_0/Snap.20200502.020345.8913052.0003.trc' in response to an event
 [ERR] JVMDUMP010I Snap dump written to /tmp/bld_445771/cmdLineTester_jvmtitests_hcr_OSRG_nongold_SE80_0/Snap.20200502.020345.8913052.0003.trc
 [ERR] JVMDUMP007I JVM Requesting JIT dump using '/tmp/bld_445771/cmdLineTester_jvmtitests_hcr_OSRG_nongold_SE80_0/jitdump.20200502.020345.8913052.0004.dmp'
 [ERR] JVMDUMP010I JIT dump written to /tmp/bld_445771/cmdLineTester_jvmtitests_hcr_OSRG_nongold_SE80_0/jitdump.20200502.020345.8913052.0004.dmp
 [ERR] JVMDUMP013I Processed dump event "gpf", detail "".
>> Success condition was not found: [Return code: 0]


---TEST RESULTS---
Number of PASSED tests: 23 out of 24
Number of FAILED tests: 1 out of 24

blocker test test failure

Source

JasonFengJ9

All 19 comments

@gacholio is this related to your #9404 change?

pshipton on 8 May 2020

Extremely unlikely - we'd need to have an exception catch class at CP index 0xFFFF or 0xFFFFFFFF.

gacholio on 8 May 2020

And in fact, that change went in prior to #9404.

gacholio on 8 May 2020

The change in question only affects a new JIT helper that isn't in use (obviously not the culprit) and the throwing of IllegalMonitorStateException from the JIT, which isn't something that's likely to occur.

gacholio on 8 May 2020

It's failing consistently, and mine is the only interesting-looking change, so I'll have a look.

gacholio on 8 May 2020

👍1

On the same machine as the failure, using the ibuild, this issue does not reproduce when I run it on the command line, inside or outside of the test harness.

gacholio on 8 May 2020

I did a build with #9404 reverted, and the issue still occurs.

gacholio on 8 May 2020

Given this has only been seen on P, the next best candidate would be:

https://github.com/eclipse/omr/commit/1c373ad24078b246811323a4b972d0c656cf7d70

gacholio on 8 May 2020

Reverting https://github.com/eclipse/omr/pull/5150 also doesn't fix it.

gacholio on 9 May 2020

Did a build with all the OpenJ9 changes backed out, didn't fix it.
Trying now with all the OMR changes backed out as well.

pshipton on 9 May 2020

I didn't run the grinders correctly - I strongly suspect it's the P ifdef change.

gacholio on 9 May 2020

Even with OMR changes backed out, the test still fails.
I'll try the original good build to ensure it still passes.
The other thing that changed is TKG https://github.com/AdoptOpenJDK/TKG/compare/858af7b2...5467859

pshipton on 9 May 2020

The good JVM 445695 fails now, but it's running the test with the new TKG.

pshipton on 9 May 2020

If TKG is causing the VM to crash, we must have a real issue here.

gacholio on 9 May 2020

The difference is the test used to be run with -Xnocompressedrefs, and started failing when this was removed. The modes _0 and _1 both have this option removed, and both fail. This may have been done in preparation for https://github.com/eclipse/openj9/issues/8847, but seems incorrect to me. Modes 1xx should still use -Xnocompressedrefs, only NoOptions should have it removed.
@llxia

The tests in the compressed refs bucket, modes _2, _3, _4 still use -Xcompressedrefs, and these pass.

_0:
variation: Mode107-OSRG
JVM_OPTIONS: -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation

original _0:
variation: Mode107-OSRG
JVM_OPTIONS: -Xnocompressedrefs -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation

_1:
variation: Mode110-OSRG
JVM_OPTIONS: -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation -Xgcpolicy:gencon

original _1:
variation: Mode110-OSRG
JVM_OPTIONS: -Xnocompressedrefs -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation -Xgcpolicy:gencon

_2:
variation: Mode607-OSRG
JVM_OPTIONS: -Xcompressedrefs -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation

_3:
variation: Mode610-OSRG
JVM_OPTIONS: -Xcompressedrefs -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation -Xgcpolicy:gencon

_4:
variation: Mode612-OSRG
JVM_OPTIONS: -Xcompressedrefs -Xgcpolicy:gencon -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation

pshipton on 11 May 2020

I'm setting this as a blocker. If all the 1xx modes lost the -Xnocompressedrefs option, the test story is broken and we aren't testing the right things.

pshipton on 11 May 2020

110-OSRG is set to -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation -Xgcpolicy:gencon. It does not contain -Xnocompressedrefs.

https://github.com/AdoptOpenJDK/TKG/blob/3205e0d0c8631ba96d1cafa360e703ed23e972c0/resources/modes.xml#L4522-L4534

We need to update 107-OSRG and 110-OSRG in modes.xml