JVMTI MethodExitTest test fails with JVMTI_ERROR_OPAQUE_FRAME error

[dipak-bagadiya]

Issue

The test failed due to the NotifyFramePop of the breakpoint-1 function. After looking into the stack trace, it was discovered that the enterImpl()Z(enterContinuationImpl) method was being attempted to be popped by the NotifyFramePop, which results in the JVMTI_ERROR_OPAQUE_FRAME problem.

There are other NotifyFramePop calls in the test, which fail with the same error but at different methods:

• notifyJvmtiMountEnd
• notifyJvmtiUnmountEnd

RI behavior: The same functions in the RI are skipped or hidden during the NotifyFramePop. We can follow the same behavior as RI to fix the test. Any of the below approach can be used to fix the issue.

This means that the RI is ignoring/skipping/hidding methods that are involved to transition the context from a carrier thread to a virtual thread, and vice-versa. The context switch (internal) workings are being hidden from a Java user.

Context switch (internal) workings will also include the following methods:

• notifyJvmtiMountBegin
• notifyJvmtiUnmountBegin
• notifyJvmtiHideFrames

There are three solutions:

• skip the impacted methods only in JVMTI;
• hide/ignore the impacted methods during stack walk everywhere; or
• don't match the RI since it is not defined in the specification, and exclude the test.

Test Code

• https://github.com/ibmruntimes/openj9-openjdk-jdk20/blob/openj9/test/hotspot/jtreg/serviceability/jvmti/vthread/MethodExitTest/MethodExitTest.java
• https://github.com/ibmruntimes/openj9-openjdk-jdk20/blob/openj9/test/hotspot/jtreg/serviceability/jvmti/vthread/MethodExitTest/libMethodExitTest.cpp

Test CMD

make test TEST="jtreg:test/hotspot/jtreg/serviceability/jvmti/vthread/MethodExitTest" JTREG="JAVA_OPTIONS=--enable-preview -Dvm.continuations=true;VERBOSE=all"

Test Output

enableEvents: started

Hit #0: VirtualThreadMount #320: enabling FramePop for method: java/lang/VirtualThread::notifyJvmtiMountEnd on virtual thread: 0x291908

VirtualThreadMount #320: method: java/lang/VirtualThread::notifyJvmtiMountEnd, thread: VT-CONSUMER#1
enableEvents: finished
JVMTI Stack Trace for thread VT-CONSUMER#1: frame count: 13
 0: java/lang/VirtualThread: notifyJvmtiMountEnd(Z)V
 1: java/lang/VirtualThread: yieldContinuation()Z
 2: java/lang/VirtualThread: tryYield()V
 3: java/lang/Thread: yield()V
 4: java/util/concurrent/SynchronousQueue$TransferStack: transfer(Ljava/lang/Object;ZJ)Ljava/lang/Object;
 5: java/util/concurrent/SynchronousQueue: take()Ljava/lang/Object;
 6: MethodExitTest: lambda$static$1()V
 7: MethodExitTest$$Lambda$2.0x0000000038031768: run()V
 8: java/lang/VirtualThread: runWith(Ljava/lang/Object;Ljava/lang/Runnable;)V
 9: java/lang/VirtualThread: run(Ljava/lang/Runnable;)V
10: java/lang/VirtualThread$VThreadContinuation: lambda$new$0(Ljava/lang/VirtualThread;Ljava/lang/Runnable;)V
11: java/lang/VirtualThread$VThreadContinuation$$Lambda$8.0x0000000000000000: run()V
12: jdk/internal/vm/Continuation: enter(Ljdk/internal/vm/Continuation;)V


Breakpoint #1: method: MethodExitTest::brkpt, thread: VT-PRODUCER#0
JVMTI Stack Trace for thread VT-PRODUCER#0: frame count: 8
 0: MethodExitTest: brkpt()I
 1: MethodExitTest: lambda$static$0()V
 2: MethodExitTest$$Lambda$1.0x0000000038031610: run()V
 3: java/lang/VirtualThread: runWith(Ljava/lang/Object;Ljava/lang/Runnable;)V
 4: java/lang/VirtualThread: run(Ljava/lang/Runnable;)V
 5: java/lang/VirtualThread$VThreadContinuation: lambda$new$0(Ljava/lang/VirtualThread;Ljava/lang/Runnable;)V
 6: java/lang/VirtualThread$VThreadContinuation$$Lambda$8.0x0000000000000000: run()V
 7: jdk/internal/vm/Continuation: enter(Ljdk/internal/vm/Continuation;)V

Hit #1: Breakpoint: brkpt: checking GetVirtualThread on carrier thread: 0x29fbd8, ForkJoinPool-1-worker-7
GetVirtualThread for carrier thread 0x29fbd8 returned expected virtual thread: 0x7f92a8004c88

Hit #1: Breakpoint: brkpt: checking GetThreadLocalStorage on carrier thread: 0x29fbd8
GetThreadLocalStorage for carrier thread returned value 111 as expected

Hit #1: Breakpoint: brkpt: enabling MethodExit events on carrier thread: 0x29fbd8
Hit #1: Breakpoint: brkpt: enabling FramePop event for method: jdk/internal/vm/Continuation::enterImpl on carrier thread: 0x29fbd8
check_jvmti_status: JVMTI function returned error: JVMTI_ERROR_OPAQUE_FRAME (32)
STDERR:

Fatal error: Breakpoint: error in JVMTI NotifyFramePop

[thallium]

Note that RI's continuation class doesn't have the enterImpl method, so even if we skip the notifyJVMTI* frames we would still fail this test due to implementation difference. FYI @babsingh

[babsingh]

Note that RI's continuation class doesn't have the enterImpl method, so even if we skip the notifyJVMTI* frames we would still fail this test due to implementation difference. FYI @babsingh

OpenJ9's enterImpl == RI's enterSpecial: The same method is named differently in RI. RI has custom logic to hide the method frame associated to enterSpecial during stackwalk. Since we have our own Continuation impl, we can apply the new JvmtiMountTransition annotation (#17520) to Continuation.enterImpl. The support for JvmtiMountTransition should skip/ignore the enterImpl frame similar to the notifyJVMTI* frames.

[thallium]

After adding code to skip methods with JvmtiMountTransition annotation, the JVMTI_ERROR_OPAQUE_FRAME error is gone but the test would still fail most of the time due to MethodExit event reported between the first and the second brake point hit (it's check here). Between the two brake point hits, the producer thread may yield so the MethodExit event seems completely normal to me.

Also, modifying the agent code can easily mess up the result. For example, enabling MethodEnter event causes the RI to fail but MethodEnter event shouldn't affect the test result at all.

[babsingh]

After adding code to skip methods with JvmtiMountTransition annotation, the JVMTI_ERROR_OPAQUE_FRAME error is gone

@thallium Please create a PR for the work associated with the JvmtiMountTransition annotation.

the test would still fail most of the time due to MethodExit event reported between the first and the second brake point hit (it's check here)

@thallium To verify if our understanding and assumptions of the test are correct, please share your findings with the loom-dev mailing list: https://mail.openjdk.org/mailman/listinfo/loom-dev. You will have to subscribe before posting a message. We will address this issue once we receive feedback from the loom-dev mailing list.

[babsingh]

Conclusion

The test explicitly checks that no JVMTI MethodExit event is triggered by the PRODUCER vthread's carrier thread between breakpoint_hit1 and breakpoint_hit2. This check is incorrect. The test will need to be fixed. My detailed explanation is below. I have written an email to the loom-dev mailing list to see if the test can be fixed in the RI's HEAD stream.

Test Source Code

• MethodExitTest.java
• libMethodExitTest.cpp

Problem

vthread - virtual thread.

In breakpoint_hit2, the test fails intermittently because the JVMTI MethodExit event is triggered by the PRODUCER vthread's carrier thread.

Between breakpoint_hit1 and breakpoint_hit2, the test doesn't expect the PRODUCER vthread's carrier thread to RUN. So, the test explicitly checks that no JVMTI MethodExit event is triggered by the PRODUCER vthread's carrier thread.

But, the PRODUCER vthread unmounts and mounts between breakpoint_hit1 and breakpoint_hit2. Whenever a vthread unmounts, the corresponding carrier thread is mounted and allowed to RUN.

PRODUCER vthread unmounts while inserting an element to the SynchronousQueue, which is a blocking queue. Insert and remove operations are synchronized. vthread will yield and unmount if it has to wait on such an operation. More details are in the stack traces below.

Stack traces

// breakpoint_hit1
Breakpoint #1: method: MethodExitTest::brkpt, thread: VT-PRODUCER#0
JVMTI Stack Trace for thread VT-PRODUCER#0: frame count: 7
 0: MethodExitTest: brkpt()I
 1: MethodExitTest: lambda$static$0()V
 2: MethodExitTest$$Lambda.0x00000000d7030b98: run()V
 3: java/lang/VirtualThread: runWith(Ljava/lang/Object;Ljava/lang/Runnable;)V
 4: java/lang/VirtualThread: run(Ljava/lang/Runnable;)V
 5: java/lang/VirtualThread$VThreadContinuation$1: run()V
 6: jdk/internal/vm/Continuation: enter(Ljdk/internal/vm/Continuation;)V

...

// PRODUCER vthread unmounts while inserting into the SynchronousQueue
Hit #1: VirtualThreadUnmount #340: enabling FramePop for method: java/lang/VirtualThread::notifyJvmtiUnmount on virtual thread: 0x27e640

VirtualThreadUnmount #340: method: java/lang/VirtualThread::notifyJvmtiUnmount, thread: VT-PRODUCER#0
JVMTI Stack Trace for thread VT-PRODUCER#0: frame count: 12
 0: java/lang/VirtualThread: yieldContinuation()Z
 1: java/lang/VirtualThread: tryYield()V
 2: java/lang/Thread: yield()V
 3: java/util/concurrent/SynchronousQueue$TransferStack: transfer(Ljava/lang/Object;ZJ)Ljava/lang/Object;
 4: java/util/concurrent/SynchronousQueue: put(Ljava/lang/Object;)V
 5: MethodExitTest: qPut(Ljava/lang/String;)V
 6: MethodExitTest: lambda$static$0()V
 7: MethodExitTest$$Lambda.0x00000000d7030b98: run()V
 8: java/lang/VirtualThread: runWith(Ljava/lang/Object;Ljava/lang/Runnable;)V
 9: java/lang/VirtualThread: run(Ljava/lang/Runnable;)V
10: java/lang/VirtualThread$VThreadContinuation$1: run()V
11: jdk/internal/vm/Continuation: enter(Ljdk/internal/vm/Continuation;)V

...

// PRODUCER vthread mounts
Hit #1: VirtualThreadMount #343: enabling FramePop for method: java/lang/VirtualThread::notifyJvmtiMount on virtual thread: 0x27e640

VirtualThreadMount #343: method: java/lang/VirtualThread::notifyJvmtiMount, thread: VT-PRODUCER#0
JVMTI Stack Trace for thread VT-PRODUCER#0: frame count: 12
 0: java/lang/VirtualThread: yieldContinuation()Z
 1: java/lang/VirtualThread: tryYield()V
 2: java/lang/Thread: yield()V
 3: java/util/concurrent/SynchronousQueue$TransferStack: transfer(Ljava/lang/Object;ZJ)Ljava/lang/Object;
 4: java/util/concurrent/SynchronousQueue: put(Ljava/lang/Object;)V
 5: MethodExitTest: qPut(Ljava/lang/String;)V
 6: MethodExitTest: lambda$static$0()V
 7: MethodExitTest$$Lambda.0x00000000d7030b98: run()V
 8: java/lang/VirtualThread: runWith(Ljava/lang/Object;Ljava/lang/Runnable;)V
 9: java/lang/VirtualThread: run(Ljava/lang/Runnable;)V
10: java/lang/VirtualThread$VThreadContinuation$1: run()V
11: jdk/internal/vm/Continuation: enter(Ljdk/internal/vm/Continuation;)V

...

// breakpoint_hit2
Breakpoint #2: method: MethodExitTest::brkpt, thread: VT-PRODUCER#0
JVMTI Stack Trace for thread VT-PRODUCER#0: frame count: 7
 0: MethodExitTest: brkpt()I
 1: MethodExitTest: lambda$static$0()V
 2: MethodExitTest$$Lambda.0x00000000d7030b98: run()V
 3: java/lang/VirtualThread: runWith(Ljava/lang/Object;Ljava/lang/Runnable;)V
 4: java/lang/VirtualThread: run(Ljava/lang/Runnable;)V
 5: java/lang/VirtualThread$VThreadContinuation$1: run()V
 6: jdk/internal/vm/Continuation: enter(Ljdk/internal/vm/Continuation;)V

[babsingh]

Discussion from the loom-dev mailing list: The initial intent of the test was to run two carrier threads with -Djdk.defaultScheduler.parallelism=2 and two virtual threads. Under these conditions, the assumption was that the two virtual threads won't unmount because there is a 1-to-1 relationship between the carrier and virtual threads. Currently, the test is run with -Djdk.defaultScheduler.parallelism=2 but three virtual threads. Due the imbalance in the ratio between the carrier and virtual threads, it is not possible to guarantee that the virtual threads won't unmount. Even after balancing the ratio between the carrier and virtual threads, it won't be possible to guarantee that the virtual threads won't unmount because the decision to unmount a virtual thread can vary on different factors such as the virtual thread scheduler and the API used while running the virtual threads. In this test case, SynchronousQueue is used which has the ability to invoke yield on the virtual thread and unmount it. I am not sure if the test will be fixed in the near future or a completely new test will be introduced. I plan to permanently disable this test since it is based on a false assumption and it doesn't test a behaviour documented in the specification.

[babsingh]

Opened adoptium/aqa-tests#4777 to permanently disable MethodExitTest.

[babsingh]

Closing: adoptium/aqa-tests#4777 has been merged and it permanently disables MethodExitTest.