Segfault running test_VirtualthreadYieldResume on Power

[IBMJimmyk]

Failing test is test_VirtualthreadYieldResume under Jep425Tests_testVirtualThread.

Failure link

Test was run on a local machine. I might be able to get a shareable link to the failure in the future if necessary.

Failure output (captured from console output)

The crash output looks like this:

Unhandled exception
Type=Segmentation error vmState=0x00000000
J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
Handler1=000071EFC2B73890 Handler2=000071EFC28FCC60
R0=0000000080AD5EF1 R1=000071EF7339A7D0 R2=000071EFC2D86E00 R3=00000004056AF788
R4=000000000044E1F8 R5=0000000000000008 R6=000000000000000E R7=000071EF7339B7B0
R8=000000000044E228 R9=000000000000000E R10=000071EFC256ED50 R11=000000000044DE30
R12=0000000044224484 R13=000071EF733A68E0 R14=000000000044E1F0 R15=000000000044E700
R16=000071EF901D0038 R17=FFFFFFFFFFFFFFFF R18=000071EF7339A9B0 R19=0000000000000002
R20=0000000000000020 R21=000071EFBC90E240 R22=000071EF78002038 R23=000071EFBC90DDD0
R24=000071EF7339A9D0 R25=0000000000000000 R26=000071EF78002038 R27=000071EFC31F7200
R28=000071EF7339AA80 R29=0000000022224222 R30=000071EFC2AF6AA8 R31=000071EFC2B27E00
NIP=0000000000000000 MSR=800000014280F033 ORIG_GPR3=000071EF91B30098 CTR=000071EF91B3007C
LINK=0000000000000000 XER=0000000000000000 CCR=0000000048224422 SOFTE=0000000000000001
TRAP=0000000000000400 DAR=0000000000000000 dsisr=0000000040000000 RESULT=0000000000000000
FPR0 0000000000000001 (f: 1.000000, d: 4.940656e-324)
FPR1 4053a00140000000 (f: 1073741824.000000, d: 7.850008e+01)
FPR2 41e0000000000000 (f: 0.000000, d: 2.147484e+09)
FPR3 0000000000000009 (f: 9.000000, d: 4.446591e-323)
FPR4 000071efc2ebd5b0 (f: 3270235648.000000, d: 6.189387e-310)
FPR5 000071efc2ebd4b0 (f: 3270235392.000000, d: 6.189387e-310)
FPR6 3fe62e42fefa39ef (f: 4277811712.000000, d: 6.931472e-01)
FPR7 bfd01eae7f513a67 (f: 2136029824.000000, d: -2.518727e-01)
FPR8 bfdffffef20a4123 (f: 4060758272.000000, d: -4.999997e-01)
FPR9 bfd00ea348b88334 (f: 1220051712.000000, d: -2.508934e-01)
FPR10 bfdfd3e469fa19f5 (f: 1777998336.000000, d: -4.973079e-01)
FPR11 41cdcd6500000000 (f: 0.000000, d: 1.000000e+09)
FPR12 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR13 000071efc2d86e00 (f: 3268963840.000000, d: 6.189387e-310)
FPR14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR16 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR17 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR18 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR19 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR20 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR21 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR22 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR23 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR24 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR25 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR26 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR27 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR28 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR29 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR30 0000000000000000 (f: 0.000000, d: 0.000000e+00)
FPR31 0000000000000000 (f: 0.000000, d: 0.000000e+00)
Target=2_90_20220726_000000 (Linux 5.4.0-122-generic)
CPU=ppc64le (128 logical CPUs) (0xfecba0000 RAM)
----------- Stack Backtrace -----------
 (0x0000000000000000 [<unknown>+0x0])
runStaticMethod+0x38c (0x000071EFC2B49A2C [libj9vm29.so+0x19a2c])
enterContinuation+0x1b0 (0x000071EFC2BE77A0 [libj9vm29.so+0xb77a0])
bytecodeLoopCompressed+0x9698 (0x000071EFC2BF1208 [libj9vm29.so+0xc1208])
 (0x000071EFC2CA0D68 [libj9vm29.so+0x170d68])
runJavaThread+0x270 (0x000071EFC2B495B0 [libj9vm29.so+0x195b0])
javaProtectedThreadProc+0xf0 (0x000071EFC2BE67B0 [libj9vm29.so+0xb67b0])
omrsig_protect+0x358 (0x000071EFC28FE068 [libj9prt29.so+0x3e068])
javaThreadProc+0x64 (0x000071EFC2BE1824 [libj9vm29.so+0xb1824])
thread_wrapper+0x1a8 (0x000071EFC2B019C8 [libj9thr29.so+0x119c8])
start_thread+0x10c (0x000071EFC2F0885C [libpthread.so.0+0x885c])
clone+0x98 (0x000071EFC3128C98 [libc.so.6+0x158c98])
---------------------------------------

Test passes under Xint:

--enable-preview -Xgcpolicy:nogc -Xint

But, the Test fails under the default options where the JIT is enabled:

--enable-preview -Xgcpolicy:nogc

I narrowed things down so only one small method gets compiled at noOpt and it still fails:

--enable-preview -Xgcpolicy:nogc -Xjit:"count=5,optlevel=noopt,disableAsyncCompilation,limit={*MethodHandle.type*},tracefull,log=/root/hostdir/openj9-openjdk-jdk19/openj9/test/TKG/trace/type.log"

Under these options, only the method java/lang/invoke/MethodHandle.type()Ljava/lang/invoke/MethodType; gets JIT'd and most optimizations are disabled. It is also a very small method where the final trees look like this:

<trees
        title="Pre Instruction Selection Trees"
        method="java/lang/invoke/MethodHandle.type()Ljava/lang/invoke/MethodType;"
        hotness="no-opt">

Pre Instruction Selection Trees: for java/lang/invoke/MethodHandle.type()Ljava/lang/invoke/MethodType;

------------------------------------------------------------------------------------------------------------------------------------------------------------------------
n1n       BBStart <block_2>                                                                   [    0x71ef90b34510] bci=[-1,0,468] rc=0 vc=17 vn=- li=2 udi=- nc=1
n15n        GlRegDeps                                                                         [    0x71ef90b34970] bci=[-1,0,468] rc=1 vc=17 vn=- li=- udi=- nc=1
n3n           aRegLoad gr3   this<'this' parm Ljava/lang/invoke/MethodHandle;>[#383  Parm] [flags 0xc0000107 0x0 ] (X!=0 X>=0 sharedMemory )  [    0x71ef90b345b0] bci=[-1,0,468] rc=2 vc=17
vn=- li=2 udi=- nc=0 flg=0x104
n13n      treetop                                                                             [    0x71ef90b348d0] bci=[-1,1,468] rc=0 vc=17 vn=- li=- udi=- nc=1
n10n        iu2l                                                                              [    0x71ef90b347e0] bci=[-1,1,468] rc=2 vc=17 vn=- li=2 udi=- nc=1
n9n           iloadi  java/lang/invoke/MethodHandle.type Ljava/lang/invoke/MethodType;[#384  final Shadow +4] [flags 0x400a0607 0x0 ]  [    0x71ef90b34790] bci=[-1,1,468] rc=1 vc=17 vn=- li
=2 udi=- nc=1
n3n             ==>aRegLoad
n7n       areturn                                                                             [    0x71ef90b346f0] bci=[-1,4,468] rc=0 vc=17 vn=- li=2 udi=- nc=1
n4n         l2a                                                                               [    0x71ef90b34600] bci=[-1,1,468] rc=1 vc=17 vn=- li=2 udi=- nc=1
n11n          lshl (compressionSequence )                                                     [    0x71ef90b34830] bci=[-1,1,468] rc=1 vc=17 vn=- li=2 udi=- nc=2 flg=0x800
n10n            ==>iu2l
n8n             iconst 3                                                                      [    0x71ef90b34740] bci=[-1,1,468] rc=1 vc=17 vn=- li=2 udi=- nc=0
n2n       BBEnd </block_2>                                                                    [    0x71ef90b34560] bci=[-1,4,468] rc=0 vc=17 vn=- li=2 udi=- nc=0

index:       node global index
bci=[x,y,z]: byte-code-info [callee-index, bytecode-index, line-number]
rc:          reference count
vc:          visit count
vn:          value number
li:          local index
udi:         use/def index
nc:          number of children
addr:        address size in bytes
flg:         node flags

Number of nodes = 11, symRefCount = 385
</trees>

If there's any other info that might be useful, feel free to ask.

[tajila]

@fengxue-IS please take a look

[llxia]

The test is updated to run with -Xint atm: #15684

[fengxue-IS]

Confirmed that this is a platform specific issue on power, running this in grinder results in 20/20 passes for axz linux, 20/20 failure in plinux/ppc_aix using -Xint

FAILED: test_VirtualthreadYieldResume
java.lang.AssertionError: Virtual Thread 0: incorrect result of 1(2)

will need to investigate further to know what exactly is missing here

[IBMJimmyk]

That's unexpected. Under -Xint the test passed for me on Linux on Power. I didn't try AIX. I forget exactly how many times I tried it, but it was quite a few.

[fengxue-IS]

The test failure I got is using build which included #15678, which used the new design of direct transition. I am not sure why the test only fails on power, I will try to add some debug output to the test and see.

[fengxue-IS]

after poking a bit with the test code, the failures come from exception thrown during the sleep call.

java.lang.IllegalStateException: Continuation is pinned: MONITOR
   	at java.base/jdk.internal.vm.Continuation.yield(Continuation.java:211)
  	at java.base/java.lang.VirtualThread.yieldContinuation(VirtualThread.java:370)
  	at java.base/java.lang.VirtualThread.parkNanos(VirtualThread.java:532)
  	at java.base/java.lang.VirtualThread.doSleepNanos(VirtualThread.java:713)
  	at java.base/java.lang.VirtualThread.sleepNanos(VirtualThread.java:686)
  	at java.base/java.lang.Thread.sleep(Thread.java:549)
  	at org.openj9.test.jep425.VirtualThreadTests.lambda$test_VirtualthreadYieldResume$1(VirtualThreadTests.java:80)
  	at java.base/java.util.concurrent.ThreadPerTaskExecutor$ThreadBoundFuture.run(ThreadPerTaskExecutor.java:352)
  	at java.base/java.lang.VirtualThread.run(VirtualThread.java:287)
  	at java.base/java.lang.VirtualThread$VThreadContinuation.lambda$new$0(VirtualThread.java:174)
  	at java.base/jdk.internal.vm.Continuation.execute(Continuation.java:156)

@babsingh do you see any reason for the Continuation to be pinned in the test code?

[babsingh]

@babsingh do you see any reason for the Continuation to be pinned in the test code?

Paths, where ownedMonitorCount is incremented and decremented, may have an inconsistency. PPC has global lock reservation enabled. We need to track the increments and decrements for ownedMonitorCount to determine the source of the failure. Since the failure goes away with -Xint, I presume the failure arises from the JIT paths.

[fengxue-IS]

@babsingh do you see any reason for the Continuation to be pinned in the test code?

Paths, where ownedMonitorCount is incremented and decremented, may have an inconsistency. PPC has global lock reservation enabled. We need to track the increments and decrements for ownedMonitorCount to determine the source of the failure. Since the failure goes away with -Xint, I presume the failure arises from the JIT paths.

These failure come from -Xint with #15678 change set, so it is not from JIT code, will have to look at where the Monitor is incremented/decremented, I will add some debug trace to the monitor count during yield failure, I am wondering if we may missed locations where it should be +/-ed.