When does MONITOR_WAITED get thrown?
JC Beyler
jcbeyler at google.com
Fri Sep 22 03:09:55 UTC 2017
Hi David,
It does explain it, thanks for your detailed explanations :)
I'll come back if I have more questions but I think I'm good! Thanks again
and have a great weekend!
Thanks,
Jc
On Tue, Sep 19, 2017 at 3:01 PM, David Holmes <david.holmes at oracle.com>
wrote:
> 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/Ille
>> galArgumentException");
>> // 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
>>
>>
>>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openjdk.java.net/pipermail/serviceability-dev/attachments/20170921/14107ad9/attachment-0001.html>
More information about the serviceability-dev
mailing list