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.hol...@oracle.com <mailto:david.hol...@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


Reply via email to