When does MONITOR_WAITED get thrown?
JC Beyler
jcbeyler at google.com
Tue Sep 19 16:26:23 UTC 2017
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.
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
2) Not good? bail without throwing
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 = 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>
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 , 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/Ille
>> galArgumentException");
>> // 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/20170919/91211b77/attachment-0001.html>
More information about the serviceability-dev
mailing list