When does MONITOR_WAITED get thrown?
David Holmes
david.holmes at oracle.com
Tue Sep 19 22:01:59 UTC 2017
Hi Jc,
On 20/09/2017 2:26 AM, JC Beyler wrote:
> Hi David,
>
> First off, thanks for looking at this case! I really apologize for my
> example being difficult to follow. I hope you won't mind if I try again :).
>
> The question is less about ordering and more on the fact that sometimes
> the MONITOR_WAITED does not get emitted it seems depending on what is
> happening for the MONITOR_WAIT event. Let me give a full working code at
> the bottom of this that show cases my question/issue.
>
> Basically, there are three cases I can think of for this test:
>
> 1) The MONITOR_WAIT callback throws an illegal exception (or another
> exception I expect would have the same issue)
> 2) The actual call from Java world to the wait is illegal due to a
> negative value for example: thread.wait(-100) AND the MONITOR_WAIT
> callback throws an illegal exception
> 3) The actual call from Java world to the wait is illegal due to a
> negative value for example: thread.wait(-100) AND the MONITOR_WAIT
> callback does not throw an exception
>
>
> What I've noticed is that the behavior is slightly different depending
> on the case:
>
> 1) In the case 1 above, we get a MONITOR_WAITED event
> 2) In the case 2 above, we get exactly the same error and I believe that
> probably because we check the argument to wait after doing the callback
> to MONITOR_WAIT; however we get MONITOR_WAITED callback at all
> 3) In the case 3 above, however, we get an illegal argument due to the
> -100 for the wait call, however we do get a MONITOR_WAITED callback.
First it is a bug that wait(-100) triggers any JVM TI events. The
IllegalArgumentException should be thrown at the Java level - and indeed
this has just been fixed. (Try using wait(-100,0) instead to see this.)
That aside, for wait(-100) you will get a MONITOR_WAIT event, then the
throwing of the IllegalArgumentException. You will never see
MONITOR_WAITED with respect to an illegal call to wait() - we simply
never hit the code that does the waiting and posts the event. (If you do
see MONITOR_WAITED then it may well be for a different wait() call.)
If the MONITOR_WAIT handler itself posts an exception, and the wait()
call is illegal then the IllegalArgumentException will replace the
exception posted by the handler.
If the handler posts an exception and the call to wait is legal then it
is as you describe below ...
> My question is really the following:
>
> - Should we not have the same behavior (Whatever that may be by the way)
> in all three cases? In all three cases, we do not wait due to an
> exception being thrown but 2 out of 3 do not have a MONITOR_WAITED event
> sent out.
>
> - When I look at the code, why this is happening is because the code
> seems to be doing this:
>
> Do the JVM_MonitorWait in jvm.cpp
> A) post the monitor wait callback
> B) Do the actual wait via ObjectSynchronizer
> i) Check the argument in ObjectSynchronizer::wait
> (src/share/vm/runtime/synchronizer.cpp)
> 1) All good? Go in ObjectMonitor::wait
> (src/share/vm/runtime/objectMonitor.cpp)
> - Check if the JNI threw, bail there after posting for waited
Other than if the thread is interrupted I don't see any check for a
pending exception. So the wait() happens, the MONITOR_WAITED is posted,
and eventually the pending exception from the MONITOR_WAIT is detected
and thrown.
> 2) Not good? bail without throwing
If the timeout is illegal it posts the IllegalArgumentException and returns.
The JVM TI spec says very little about exceptions and event callback
handlers, other than being careful not to lose existing pending
exceptions. In particular the fact there may be an exception pending,
whether from the handler or other source, does not influence subsequent
event handling directly - but obviously the logic in the VM that checks
for pending exceptions will affect whether certain callback points can
be reached if an exception is pending.
Does this explain what you observe?
Cheers,
David
------
>
>
> Note: I've added the whole code below and refactored it so that the
> output is more clear and you have all cases together in one code (I
> augmented the sleep to 5 seconds to make it clear :)):
>
> Thanks for your help,
> Jc
>
>
> --------------------------------------------------------------------------------------
>
>
> A) Here is the agent code:
> #include <jvmti.h>
> #include <stdio.h>
> #include <string.h>
>
> static void JNICALL
> monitor_wait(jvmtiEnv* jvmti, JNIEnv *env,
> jthread thread, jobject object, jlong timeout) {
> fprintf(stderr, "Waiting!\n");
>
> // Throw only every other time the first few times, then never again
> (Works out well for the Java test :)):
> // - We want it to throw the first wait but not the first join.
> // - We want it to throw the second wait but not the second join.
> // - We want it to no longer throw at all.
> static int cnt = 0;
> if (cnt++ % 2 == 0 && cnt < 4) {
> jclass newExcCls =
> env->FindClass("java/lang/IllegalArgumentException");
> // Unable to find the new exception class, give up.
> if (newExcCls == 0) {
> return;
> }
> env->ThrowNew(newExcCls, "Exception from monitor_wait");
> }
> }
>
> static void JNICALL
> monitor_waited(jvmtiEnv* jvmti, JNIEnv *env,
> jthread thread, jobject object, jboolean timed_out) {
> fprintf(stderr, "Waited!\n");
> }
>
> extern "C" JNIEXPORT jint JNICALL Agent_OnLoad(JavaVM *jvm, char *options,
> void *reserved) {
> int ernum;
>
> jvmtiEnv *jvmti;
> if (jvm->GetEnv(reinterpret_cast<void **>(&jvmti), JVMTI_VERSION) !=
> JNI_OK) {
> return JNI_ERR;
> }
>
> jvmtiEventCallbacks callbacks;
> memset(&callbacks, 0, sizeof(callbacks));
> callbacks.MonitorWait = &monitor_wait;
> callbacks.MonitorWaited = &monitor_waited;
>
> jvmtiCapabilities caps;
> memset(&caps, 0, sizeof(caps));
> caps.can_generate_monitor_events = 1;
>
> ernum = jvmti->AddCapabilities(&caps);
> ernum = jvmti->SetEventCallbacks(&callbacks,
> sizeof(jvmtiEventCallbacks));
> ernum = jvmti->SetEventNotificationMode(JVMTI_ENABLE,
> JVMTI_EVENT_MONITOR_WAIT, NULL);
> ernum = jvmti->SetEventNotificationMode(JVMTI_ENABLE,
> JVMTI_EVENT_MONITOR_WAITED, NULL);
>
> return ernum;
> }
>
> B) Here is the Java code, it's a bit long but I added comments and made
> it clear (I really hope :)):
>
> public class Main extends Thread {
> public static void main(String[] args) {
>
> for (int i = 0; i < 3; i++) {
> SecondThread st = new SecondThread("first");
>
> synchronized (st) {
> st.start();
>
> System.err.println("Starting with simple wait");
> try {
> st.wait();
> } catch(Exception e) {
> System.out.println("Here we got a monitor_waited call, the
> underlying monitor_wait callback threw: " + e);
> }
>
> System.err.println("\n\nJoining so wait/waited will show");
> try {
> st.join();
> } catch(Exception e) {
> System.err.println("Join exception, not intended for this test:
> " + e);
> }
> }
>
> st = new SecondThread("second");
>
> synchronized (st) {
> st.start();
>
> System.err.println("\n\nStarting with negative wait");
> try {
> st.wait(-100);
> } catch(Exception e) {
> System.err.println("Here we did not get a callback to
> monitor_waited though same exception as above: " + e);
> }
>
> System.err.println("\n\nJoining so wait/waited will show");
> try {
> st.join();
> } catch(Exception e) {
> System.err.println("Join exception, not intended for this test:
> " + e);
> }
> }
>
> st = new SecondThread("third");
>
> synchronized (st) {
> st.start();
>
> System.err.println("\n\nStarting with simple wait, monitor_wait
> won't throw anymore");
> try {
> st.wait(-100);
> } catch(Exception e) {
> System.err.println("Here we did not get a callback to
> monitor_waited though different exception as above: " + e);
> }
>
> System.err.println("\n\nJoining so wait/waited will show");
> try {
> st.join();
> } catch(Exception e) {
> System.err.println("Join exception, not intended for this test:
> " + e);
> }
> }
>
> System.out.println("Done");
> }
> }
>
> class SecondThread extends Thread {
> private String name;
>
> public SecondThread(String name) {
> this.name <http://this.name> = name;
> }
>
> public void run() {
> try {
> Thread.sleep(5000);
> } catch(Exception e) {
> System.err.println(e);
> }
> System.err.println("Hello from " + name);
> }
> }
>
> C) The output I get is:
> Starting with simple wait
> Waiting!
> Waited!
> Here we got a monitor_waited call, the underlying monitor_wait callback
> threw: java.lang.IllegalArgumentException: Exception from monitor_wait
>
>
> Joining so wait/waited will show
> Waiting!
> Hello from first
> Waited!
>
>
> Starting with negative wait
> Waiting!
> Here we did not get a callback to monitor_waited though same exception
> as above: java.lang.IllegalArgumentException: Exception from monitor_wait
>
>
> Joining so wait/waited will show
> Waiting!
> Hello from second
> Waited!
>
>
> Starting with simple wait, monitor_wait won't throw anymore
> Waiting!
> Here we did not get a callback to monitor_waited though different
> exception as above: java.lang.IllegalArgumentException: timeout value is
> negative
>
>
> Joining so wait/waited will show
> Waiting!
> Hello from third
> Waited!
> Done
>
>
> On Mon, Sep 18, 2017 at 3:04 PM, David Holmes <david.holmes at oracle.com
> <mailto:david.holmes at oracle.com>> wrote:
>
> Hi Jc,
>
> I found your example very difficult to follow. AFAICS you will
> potentially encounter monitor related events that are unrelated to
> the st.wait in your test code. And there are races in the test - as
> soon as st.wait releases the monitor lock then SecondThread can run,
> complete the sleep and print "Hello from A". I don't think it is
> specified exactly when the MONIOR_WAIT event is sent with respect to
> the releasing of the monitor lock.
>
> David
>
>
> On 19/09/2017 3:45 AM, JC Beyler wrote:
>
> Hi all,
>
> When looking at the documentation of
> https://docs.oracle.com/javase/7/docs/platform/jvmti/jvmti.html#MonitorWaited
> <https://docs.oracle.com/javase/7/docs/platform/jvmti/jvmti.html#MonitorWaited>
> , I see the following description:
> "Sent when a thread finishes waiting on an object."
>
> However, there seems to be a slight issue when the MONITOR_WAIT
> event handler throws an exception.
>
> Consider the following code:
>
> A) The monitor wait handler throws
>
> static void JNICALL
> monitor_wait(jvmtiEnv* jvmti, JNIEnv *env,
> jthread thread, jobject object, jlong timeout) {
> fprintf(stderr, "Waiting!\n");
>
> jclass newExcCls =
> env->FindClass("java/lang/IllegalArgumentException");
> // Unable to find the new exception class, give up.
> if (newExcCls == 0) {
> return;
> }
> env->ThrowNew(newExcCls, "Exception from monitor_wait");
> }
>
> B) The monitor waited handler does a printf:
> static void JNICALL
> monitor_waited(jvmtiEnv* jvmti, JNIEnv *env,
> jthread thread, jobject object, jboolean
> timed_out) {
> fprintf(stderr, "Waited!\n");
> }
>
> B) A second thread that will be asked to wait:
> class SecondThread extends Thread {
> public void run() {
> try {
> Thread.sleep(1);
> } catch(Exception e) {
> }
> System.out.println("Hello from A");
> }
> }
>
> C) The main thread with the wait:
> class Main extends Thread {
> public static void main(String[] args) {
> SecondThread st = new SecondThread();
>
> synchronized (st) {
> st.start();
>
> try {
> st.wait();
> } catch(InterruptedException e) {
> System.out.println("Exception caught!");
> }
> }
>
> System.out.println("Done");
> }
> }
>
> D) If I do this, what happens is that I get:
>
> Waiting!
> Waited!
> Exception in thread "main" java.lang.IllegalArgumentException:
> Exception from monitor_wait
> at java.lang.Object.wait(Native Method)
> at java.lang.Object.wait(Object.java:502)
> at Main.main(Main.java:9)
> Hello from A
>
> - As we see, we get the print out from waiting, print out from
> waited and then the exception in the waiting.
>
>
> E) If instead, we do st.wait(-100) in the main method, we get:
> Waiting!
> Exception in thread "main" java.lang.IllegalArgumentException:
> Exception from monitor_wait
> at java.lang.Object.wait(Native Method)
> at Main.main(Main.java:9)
> Hello from A
>
> Notes: the stack is slightly different, the printout waited is
> no longer there however
>
> F) If finally, we don't throw in the waiting handler but leave
> the st.wait(-100) in place:
> Waiting!
> Exception in thread "main" java.lang.IllegalArgumentException:
> timeout value is negative
> at java.lang.Object.wait(Native Method)
> at Main.main(Main.java:9)
> Hello from A
>
>
> The question thus becomes: is this normal that there is a slight
> difference between D/E/F?
>
> Should we try to fix it to have a single behavior in the three
> cases, and if so, which would be the behavior that should be the
> default?
>
> Let me know if you would like to see a full code to easily
> replicate, I gave the big parts but left out the Agent_OnLoad
> method for example.
>
> Thanks!
> Jc
>
>
More information about the serviceability-dev
mailing list