-
Bug
-
Resolution: Fixed
-
P3
-
1.4.0
-
rc1
-
generic
-
generic
-
Verified
Reproducable with latest build of 1.3.1 and merlin release on all platforms.
With 1.3.1 and Merlin release, it appears that JVMPI_EVENT MONITOR_WAIT events are sent _after_ the lock in question has already been released, allowing another thread to acquire the lock before a JVMPI client sees or has time to process a MONITOR_WAIT event.
According to the JVMPI spec, this event is "Sent when a thread is ABOUT TO wait on an object" (emphasis mine). This implies the monitor has not yet been released. Since the event is dispatched in the thread doing the wait(), it should be impossible for another thread to acquire the monitor until a JVMPI client has finished handling the MONITOR_WAIT.
However, with 1.3 and Merlin, this is not the observed behaviour.
The included test case consists of a simple JVMPI client, latewait.c and three Java classes, Lock, LateWait01, and LW01_Producer. The Java program is a simple producer/consumer. It calls native methods in Lock when it enters or exits a synchronized block. The JVMPI client tracks the state of the monitor based on these calls to the native methods, and MONITOR_WAIT and MONITOR_WAITED events.
MONITOR_WAIT is an implicit unlock of the monitor, but as stated above this unlock should not actually happen until after the event has been handled. The client does a sleep() when handling MONITOR_WAIT to simulate slow handling, or an unlucky context switch.
The client will exit with an error if it detects that one thread locks the monitor while it believes another thread still owns it, or unlocks a monitor that is unowned or not owned by it.
java -Xrunlatewait LateWait01
With 1.3 or Merlin, you will see output like:
0x80518b8: lock
0x80518b8: wait: sleeping
0x80f0b00: lock
locked by thread 0x80f0b00 while still held by 0x80518b8
or sometimes:
0x80518b8: lock
0x80f0b00: lock
locked by thread 0x80f0b00 while still held by 0x80518b8
Either of these indicate the bug being reported: thread 0x80f0b00
is able to enter a synchronized block and call Lock.lock() while
the MONITOR_WAIT event is still being dispatched to 0x80518b8.
The same client will not run unmodified with a 1.2.2 JVM, because
it uses the JVMPI_INTERFACE_1_1 for jobject2jobjectID, but if you
modify it to either call jobject2jobjectID directly or grope around
off the jobject pointer to get the JVMPI ID, you will see that 1.2.2
does NOT show this behaviour. You get output like:
0x80518b8: lock
0x80518b8: wait: sleeping
0x80518b8: unlock
0x80f0b00: lock
0x80f0b00: unlock
0x80518b8: waited
0x80518b8: lock
Consumed: 0
0x80518b8: unlock
etc.
Reproduction :
Compile latewait.c file and build liblatewait.so file.
Compile the Java classes, then execute:
prithvi 619 =>$JAVA_HOME/bin/java -Xrunlatewait LateWait01
10146c: lock
10146c: unlock
27fb4: lock
Consumed: 0
27fb4: unlock
27fb4: lock
27fb4: wait: sleeping
10146c: lock
locked by thread 10146c while still held by 27fb4
prithvi 620 =>$JAVA_HOME/bin/java -Xrunlatewait LateWait01
27fb4: lock
10146c: lock
locked by thread 10146c while still held by 27fb4
prithvi 621 =>$JAVA_HOME/bin/java -version
java version "1.3.1"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.3.1-b24)
Java HotSpot(TM) Client VM (build 1.3.1-b24, mixed mode)
See the attached source files.
With 1.3.1 and Merlin release, it appears that JVMPI_EVENT MONITOR_WAIT events are sent _after_ the lock in question has already been released, allowing another thread to acquire the lock before a JVMPI client sees or has time to process a MONITOR_WAIT event.
According to the JVMPI spec, this event is "Sent when a thread is ABOUT TO wait on an object" (emphasis mine). This implies the monitor has not yet been released. Since the event is dispatched in the thread doing the wait(), it should be impossible for another thread to acquire the monitor until a JVMPI client has finished handling the MONITOR_WAIT.
However, with 1.3 and Merlin, this is not the observed behaviour.
The included test case consists of a simple JVMPI client, latewait.c and three Java classes, Lock, LateWait01, and LW01_Producer. The Java program is a simple producer/consumer. It calls native methods in Lock when it enters or exits a synchronized block. The JVMPI client tracks the state of the monitor based on these calls to the native methods, and MONITOR_WAIT and MONITOR_WAITED events.
MONITOR_WAIT is an implicit unlock of the monitor, but as stated above this unlock should not actually happen until after the event has been handled. The client does a sleep() when handling MONITOR_WAIT to simulate slow handling, or an unlucky context switch.
The client will exit with an error if it detects that one thread locks the monitor while it believes another thread still owns it, or unlocks a monitor that is unowned or not owned by it.
java -Xrunlatewait LateWait01
With 1.3 or Merlin, you will see output like:
0x80518b8: lock
0x80518b8: wait: sleeping
0x80f0b00: lock
locked by thread 0x80f0b00 while still held by 0x80518b8
or sometimes:
0x80518b8: lock
0x80f0b00: lock
locked by thread 0x80f0b00 while still held by 0x80518b8
Either of these indicate the bug being reported: thread 0x80f0b00
is able to enter a synchronized block and call Lock.lock() while
the MONITOR_WAIT event is still being dispatched to 0x80518b8.
The same client will not run unmodified with a 1.2.2 JVM, because
it uses the JVMPI_INTERFACE_1_1 for jobject2jobjectID, but if you
modify it to either call jobject2jobjectID directly or grope around
off the jobject pointer to get the JVMPI ID, you will see that 1.2.2
does NOT show this behaviour. You get output like:
0x80518b8: lock
0x80518b8: wait: sleeping
0x80518b8: unlock
0x80f0b00: lock
0x80f0b00: unlock
0x80518b8: waited
0x80518b8: lock
Consumed: 0
0x80518b8: unlock
etc.
Reproduction :
Compile latewait.c file and build liblatewait.so file.
Compile the Java classes, then execute:
prithvi 619 =>$JAVA_HOME/bin/java -Xrunlatewait LateWait01
10146c: lock
10146c: unlock
27fb4: lock
Consumed: 0
27fb4: unlock
27fb4: lock
27fb4: wait: sleeping
10146c: lock
locked by thread 10146c while still held by 27fb4
prithvi 620 =>$JAVA_HOME/bin/java -Xrunlatewait LateWait01
27fb4: lock
10146c: lock
locked by thread 10146c while still held by 27fb4
prithvi 621 =>$JAVA_HOME/bin/java -version
java version "1.3.1"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.3.1-b24)
Java HotSpot(TM) Client VM (build 1.3.1-b24, mixed mode)
See the attached source files.