JDK-6497210 : Displaying Local Java Vars in jdb crashes target VM
  • Type: Bug
  • Component: hotspot
  • Sub-Component: jvmti
  • Affected Version: 5.0u9
  • Priority: P3
  • Status: Resolved
  • Resolution: Fixed
  • OS: generic
  • CPU: generic
  • Submitted: 2006-11-24
  • Updated: 2012-02-01
  • Resolved: 2007-01-31
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 6 JDK 7 Other
6u4Fixed 7Fixed hs10Fixed
getting the values of local variables of reference type can lead to          
crashes when debugging. You can reproduce this with the attached Java        
program. Just start a VM in debugging mode and attach a debugger of you choice. 

I reproduced this issue with:

1.) jdb
2.) eclipse
3.) Netbeans

wait some time and suspend one of the worker threads. While the IDE tries to         
display the values of the local variable, the VM will crash with a very      
high probability.                                                            
The reason for this crash is the following: To get the value of a local      
variable holding an object, the VM_GetOrSetLocal VM opeation is used.        
This VM operation has a oops_do() method to update the result of getting     
 the object during a GC. Unfortunately the method does not what the          
author intended. It updates the result only *until* the VM operation was     
 executed. If a GC happens between executing the VM operation and            
returning to the requesting thread, the result is moved without notice       
and the VM can crash. To make this more probable, we GC a lot in three       
threads in the test and have a lot of local variables with objects.          
Please use attached testcase and do:
java -Xmx512m -agentlib:jdwp=transport=dt_socket,server=y,address=8000,suspend=n GetLocalVarsTest

jdb -connect com.sun.jdi.SocketAttach:hostname=localhost,port=8000
The following test is intermittently failing in C2 baseline nightly
(example is sparc Client VM, 2006-12-07, Solaris-sparc machine vm-e420r-6)
because of this bug:


This is the hs_err log below:

ss45998@vm-e420r-6 hs_err --jvm=/home/ss45998/sgoldman/libjvm.so hs_err_pid11331.log | c++filt
# An unexpected error has been detected by Java Runtime Environment:
#  Internal Error (/net/prt-sparc-q2-11/tmp/PrtBuildDir/workspace/src/share/vm/runtime/handles.cpp, 16 [ Patched ]), pid=11331, tid=55
# Java VM: Java HotSpot(TM) Client VM (20061207101238.sgoldman.6463133_deopt-M-fastdebug compiled mode)
# Error: assert(SharedSkipVerify || obj->is_oop(),"sanity check")
# If you would like to submit a bug report, please visit:
#   http://java.sun.com/webapps/bugreport/crash.jsp

---------------  T H R E A D  ---------------

Current thread (0x00973c00):  JavaThread "Thread-42" [_thread_in_vm, id=55]

Stack: [0xf2100000,0xf2180000),  sp=0xf217eb08,  free space=506k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.so+0xe4dc8c];;  void VMError::report_and_die()+0x7f4
V  [libjvm.so+0x3d3fc8];;  void report_assertion_failure(const char*,int,const char*)+0x70
V  [libjvm.so+0x46b968];;  oop*HandleArea::allocate_handle(oop)+0xb8
V  [libjvm.so+0x976288];;  jvmtiError JvmtiEnv::GetLocalObject(JavaThread*,int,int,_jobject**)+0x1b0
V  [libjvm.so+0x803774];;  jvmti_GetLocalObject+0x17dc
C  [libjdwp.so+0x15a84];;  eventInstance+0x114
C  [libjdwp.so+0x15dc0];;  eventFilterRestricted_passesFilter+0x2d8
C  [libjdwp.so+0x17ef8];;  event_callback+0x280
C  [libjdwp.so+0x1a520];;  cbMonitorContendedEnter+0x1d4
V  [libjvm.so+0x9cde18];;  void JvmtiExport::post_monitor_contended_enter(JavaThread*,ObjectMonitor*)+0xed4
V  [libjvm.so+0xcba4d0];;  void ObjectMonitor::enter(Thread*)+0x78c
V  [libjvm.so+0xcb22f4];;  void ObjectSynchronizer::slow_enter(Handle,BasicLock*,Thread*)+0x33c
V  [libjvm.so+0xcb1cb8];;  void ObjectSynchronizer::fast_enter(Handle,BasicLock*,bool,Thread*)+0x1c0
V  [libjvm.so+0x4fea10];;  void InterpreterRuntime::monitorenter(JavaThread*,BasicObjectLock*)+0x444
v  ~BufferBlob::Interpreter
J  nsk.share.jdi.MonitorEnterExecutor.eventMethod()V
J  nsk.share.jdi.MonitorEnterExecutor.monitorEnter()V
J  nsk.share.jdi.MonitorEnterExecutor.doEventAction()V
J  nsk.share.jdi.JDIEventsDebuggee$EventActionsThread.run()V
v  ~BufferBlob::StubRoutines (1)
V  [libjvm.so+0x52907c];;  void JavaCalls::call_helper(JavaValue*,methodHandle*,JavaCallArguments*,Thread*)+0x9c0
V  [libjvm.so+0x527298];;  void JavaCalls::call_virtual(JavaValue*,KlassHandle,symbolHandle,symbolHandle,JavaCallArguments*,Thread*)+0x448
V  [libjvm.so+0x527440];;  void JavaCalls::call_virtual(JavaValue*,Handle,KlassHandle,symbolHandle,symbolHandle,Thread*)+0xf4
V  [libjvm.so+0x735c74];;  void thread_entry(JavaThread*,Thread*)+0x2c0
V  [libjvm.so+0xd194d8];;  void JavaThread::thread_main_inner()+0x238
V  [libjvm.so+0xd19288];;  void JavaThread::run()+0x614
V  [libjvm.so+0xb773d4];;  java_start+0x17c

Java frames: (J=compiled Java code, j=interpreted, Vv=VM code)
v  ~BufferBlob::Interpreter
J  nsk.share.jdi.MonitorEnterExecutor.eventMethod()V
J  nsk.share.jdi.MonitorEnterExecutor.monitorEnter()V
J  nsk.share.jdi.MonitorEnterExecutor.doEventAction()V
J  nsk.share.jdi.JDIEventsDebuggee$EventActionsThread.run()V
v  ~BufferBlob::StubRoutines (1)

---------------  P R O C E S S  ---------------

Java Threads: ( => current thread )
  0x00976c00 JavaThread "Thread-50" [_thread_blocked, id=63]
  0x00975c00 JavaThread "Thread-49" [_thread_blocked, id=62]
  0x00938000 JavaThread "Thread-48" [_thread_blocked, id=61]
  0x00937800 JavaThread "Thread-47" [_thread_blocked, id=60]
  0x00937000 JavaThread "Thread-45" [_thread_blocked, id=59]
  0x00936800 JavaThread "Thread-46" [_thread_blocked, id=58]
  0x0090c000 JavaThread "Thread-44" [_thread_in_Java, id=57]
  0x00143400 JavaThread "Thread-43" [_thread_blocked, id=56]
=>0x00973c00 JavaThread "Thread-42" [_thread_in_vm, id=55]
  0x0019a400 JavaThread "Low Memory Detector" daemon [_thread_blocked, id=11]
  0x0013b800 JavaThread "CompilerThread0" daemon [_thread_in_native, id=10]
  0x00130000 JavaThread "JDWP Command Reader" daemon [_thread_in_native, id=9]
  0x0012e000 JavaThread "JDWP Event Helper Thread" daemon [_thread_blocked, id=8]
  0x0012b400 JavaThread "JDWP Transport Listener: dt_socket" daemon [_thread_blocked, id=7]
  0x00108000 JavaThread "Signal Dispatcher" daemon [_thread_blocked, id=6]
  0x000f1400 JavaThread "Finalizer" daemon [_thread_blocked, id=5]
  0x000ec800 JavaThread "Reference Handler" daemon [_thread_blocked, id=4]
  0x0004c000 JavaThread "JDIEventsDebuggee_MainThread" [_thread_blocked, id=2]

Other Threads:
  0x000e8000 VMThread [id=3]
  0x001a0800 WatcherThread [id=12]

VM state:not at safepoint (normal execution)

VM Mutex/Monitor currently owned by a thread: None

 def new generation   total 1984K, used 211K [0xf2c00000, 0xf2e20000, 0xf3310000)
  eden space 1792K,   2% used [0xf2c00000, 0xf2c08f70, 0xf2dc0000)
  from space 192K,  91% used [0xf2df0000, 0xf2e1c008, 0xf2e20000)
  to   space 192K,   0% used [0xf2dc0000, 0xf2dc0000, 0xf2df0000)
 tenured generation   total 4096K, used 0K [0xf3310000, 0xf3710000, 0xf6c00000)
   the space 4096K,   0% used [0xf3310000, 0xf3310000, 0xf3310200, 0xf3710000)
 compacting perm gen  total 12288K, used 2501K [0xf6c00000, 0xf7800000, 0xfac00000)
   the space 12288K,  20% used [0xf6c00000, 0xf6e71448, 0xf6e71600, 0xf7800000)
No shared spaces configured.

Dynamic libraries:
0x00010000 	/net/gtee.sfbay/export/gtee/results/MUSTANG/NIGHTLY/VM-MAIN/JDK/c2_baseline/solaris-sparcv9/jre/bin/java
0xff1b0000 	/usr/lib/libthread.so.1
0xff190000 	/net/gtee.sfbay/export/gtee/results/MUSTANG/NIGHTLY/VM-MAIN/JDK/c2_baseline/solaris-sparcv9/jre/bin/../lib/sparc/jli/libjli.so
0xff236000 	/usr/lib/libdl.so.1
0xff080000 	/usr/lib/libc.so.1
0xff226000 	/usr/platform/SUNW,Ultra-80/lib/libc_psr.so.1
0xfd400000 	/net/gtee.sfbay/export/gtee/results/MUSTANG/NIGHTLY/VM-MAIN/JDK/c2_baseline/solaris-sparcv9/jre/lib/sparc/client/libjvm.so
0xff060000 	/usr/lib/libsocket.so.1
0xff040000 	/usr/lib/libsched.so.1
0xfefe0000 	/usr/lib/libm.so.1
0xfefb0000 	/usr/lib/libCrun.so.1
0xfef90000 	/usr/lib/libdoor.so.1
0xfd300000 	/usr/lib/libnsl.so.1
0xfef70000 	/usr/lib/libmp.so.2
0xfd2e0000 	/net/gtee.sfbay/export/gtee/results/MUSTANG/NIGHTLY/VM-MAIN/JDK/c2_baseline/solaris-sparcv9/jre/lib/sparc/native_threads/libhpi.so
0xfd1b0000 	/net/gtee.sfbay/export/gtee/results/MUSTANG/NIGHTLY/VM-MAIN/JDK/c2_baseline/solaris-sparcv9/jre/lib/sparc/libjdwp.so
0xfd2b0000 	/net/gtee.sfbay/export/gtee/results/MUSTANG/NIGHTLY/VM-MAIN/JDK/c2_baseline/solaris-sparcv9/jre/lib/sparc/libnpt.so
0xfd290000 	/usr/lib/iconv/UTF-8%646.so
0xfd190000 	/usr/lib/iconv/646%UTF-8.so
0xfd150000 	/net/gtee.sfbay/export/gtee/results/MUSTANG/NIGHTLY/VM-MAIN/JDK/c2_baseline/solaris-sparcv9/jre/lib/sparc/libverify.so
0xfd100000 	/net/gtee.sfbay/export/gtee/results/MUSTANG/NIGHTLY/VM-MAIN/JDK/c2_baseline/solaris-sparcv9/jre/lib/sparc/libjava.so
0xfd0e0000 	/net/gtee.sfbay/export/gtee/results/MUSTANG/NIGHTLY/VM-MAIN/JDK/c2_baseline/solaris-sparcv9/jre/lib/sparc/libzip.so
0xfd0c0000 	/net/gtee.sfbay/export/gtee/results/MUSTANG/NIGHTLY/VM-MAIN/JDK/c2_baseline/solaris-sparcv9/jre/lib/sparc/libdt_socket.so
0xfd080000 	/usr/lib/nss_nis.so.1
0xfd050000 	/net/gtee.sfbay/export/gtee/results/MUSTANG/NIGHTLY/VM-MAIN/JDK/c2_baseline/solaris-sparcv9/jre/lib/sparc/libnet.so
0xfd020000 	/export/gtee/testbase/vm/bin/lib/solaris-sparc/nsk/share/jdi/libMonitorEnterExecutor.so

VM Arguments:
jvm_args: -Xcomp -DHANGINGJAVA24717 -XX:-PrintVMOptions -XX:CompileThreshold=100 -Xdebug -Xrunjdwp:transport=dt_socket,address=vm-e420r-6:65269,suspend=y 
java_command: nsk.share.jdi.MonitorEventsDebuggee -arch=solaris-sparc -waittime=2 -debugee.vmkind=java -transport.address=dynamic -debugee.vmkeys=-client -Xcomp -DHANGINGJAVA24717 -XX:-PrintVMOptions -XX:CompileThreshold=100 -pipe.port=65268
Launcher Type: SUN_STANDARD

Environment Variables:

Signal Handlers:
SIGSEGV: [libjvm.so+0xe4ef94], sa_mask[0]=0x7fbffeff, sa_flags=0x0000000c
SIGBUS: [libjvm.so+0xe4ef94], sa_mask[0]=0x7fbffeff, sa_flags=0x0000000c
SIGFPE: [libjvm.so+0xb7f844], sa_mask[0]=0x7fbffeff, sa_flags=0x0000000c
SIGPIPE: [libjvm.so+0xb7f844], sa_mask[0]=0x7fbffeff, sa_flags=0x0000000c
SIGILL: [libjvm.so+0xb7f844], sa_mask[0]=0x7fbffeff, sa_flags=0x0000000c
SIGUSR1: [libjvm.so+0xb7f864], sa_mask[0]=0x00000000, sa_flags=0x00000008
SIGUSR2: [libjvm.so+0xb7f844], sa_mask[0]=0x7fbffeff, sa_flags=0x0000000c
SIGHUP: [libjvm.so+0xb7a41c], sa_mask[0]=0x7fbffeff, sa_flags=0x00000004
SIGINT: [libjvm.so+0xb7a41c], sa_mask[0]=0x7fbffeff, sa_flags=0x00000004
SIGQUIT: [libjvm.so+0xb7a41c], sa_mask[0]=0x7fbffeff, sa_flags=0x00000004
SIGTERM: [libjvm.so+0xb7a41c], sa_mask[0]=0x7fbffeff, sa_flags=0x00000004
SIGQUIT: [libjvm.so+0xb7a41c], sa_mask[0]=0x7fbffeff, sa_flags=0x00000004
SIGTERM: [libjvm.so+0xb7a41c], sa_mask[0]=0x7fbffeff, sa_flags=0x00000004
SIGUSR1: [libjvm.so+0xb7f864], sa_mask[0]=0x00000000, sa_flags=0x00000008
SIGUSR2: [libjvm.so+0xb7f844], sa_mask[0]=0x7fbffeff, sa_flags=0x0000000c

---------------  S Y S T E M  ---------------

OS:                        Solaris 9 9/04 s9s_u7wos_09 SPARC
           Copyright 2004 Sun Microsystems, Inc.  All Rights Reserved.
                        Use is subject to license terms.
                             Assembled 29 June 2004

uname:SunOS 5.9 Generic_117171-07 sun4u  (T2 libthread)
rlimit: STACK 10000k, CORE infinity, NOFILE 65536, AS infinity
load average:1.50 1.36 1.28

CPU:total 4 has_v8, has_v9, has_vis1

Memory: 8k page, physical 2097152k(1240424k free)

vm_info: Java HotSpot(TM) Client VM (20061207101238.sgoldman.6463133_deopt-M-fastdebug) for solaris-sparc, built on Dec  7 2006 10:53:12 by "PRT" with unknown Workshop:0x580


SUGGESTED FIX The fix needs a minor tweak to make gcc 4.1.1 happy: ------- src/share/vm/prims/jvmtiImpl.hpp ------- *** /tmp/geta26261 Wed Jan 24 10:08:59 2007 --- /tmp/getb26261 Wed Jan 24 10:08:59 2007 *************** *** 421,428 **** VM_GetOrSetLocal(JavaThread* thread, jint depth, jint index, BasicType type, jvalue value); // Constructor for object getter ! VM_GetOrSetLocal::VM_GetOrSetLocal(JavaThread* thread, JavaThread* calling_thread, ! jint depth, int index); // Constructor for object setter VM_GetOrSetLocal(JavaThread* thread, jint depth, jint index, Handle* value);--- 421,428 ---- VM_GetOrSetLocal(JavaThread* thread, jint depth, jint index, BasicType type, jvalue value); // Constructor for object getter ! VM_GetOrSetLocal(JavaThread* thread, JavaThread* calling_thread, jint depth,! int index); // Constructor for object setter VM_GetOrSetLocal(JavaThread* thread, jint depth, jint index, Handle* value);

SUGGESTED FIX Please, see the suggested fix in the webrev hs_lobj.Dec6.tar.gz saved in attachment. The idea is to create a jobject in the VM_GetOrSetLocal::doit() instead of keeping naked oop and unsafely relying on the VM_GetOrSetLocal::oops_do() to correct its location.

EVALUATION A VM operation is excluded from the list of VM operations after it is completed. This is caused the GC to be not able to find the VM_GetOrSetLocal operation in the list. So, the VM_GetOrSetLocal::oops_do() function is not called after the GC moves the _oop_result object (after the VM_GetOrSetLocal operation is completed). Please, see the tracing details proving this theory in the comment. It means that keeping an oop in a VM operation object is not safe even if an VM_GetOrSetLocal::oop_do() function is defined. This problem can be fixed (as suggested above) by creating an oop Handle inside the VM_GetOrSetLocal::doit() function.

EVALUATION Ok. I've finally found the cause of this bug. It is a race condition between the threads: VMTread and the JVMTIAgent executing the JVMTI GetLocalObject. The reason of that is that the JVMTIAgent thread is not suspended at safepoints. The GetLocalObject functions takes an oop pointer and creates a handle of the local object from the field of a VM_GetOrSetLocal object. But this handle must be created at a safepoint inside VM_GetOrSetLocal::doit(): JvmtiEnv::GetLocalObject(JavaThread* java_thread, jint depth, jint slot, jobject* value_ptr) { VM_GetOrSetLocal op(java_thread, depth, slot, T_OBJECT); VMThread::execute(&op); jvmtiError err = op.result(); if (err != JVMTI_ERROR_NONE) { return err; } else { oop obj = op.oop_value(); *value_ptr = jni_reference(((Handle)obj)()); return JVMTI_ERROR_NONE; } } /* end GetLocalObject */ This crash is gone if oop handle is created inside the doit() at safepoint. I'm going to check if there are other places in JVMTI where similar problem exists.

EVALUATION This failure is reproducible with Mustang Server VM on: Solaris-amd64 (64-bit mode), Solaris-sparc (32-bit) and Soalris-sparcv9 (64-bit) Also it is reproducible with the Client VM on Solaris-i586. It is also reproducible with jdk1.5 fcs and 5.u9. This test is well reproducible if to increase the Runner threads count to 6. In such a case the count of objects in the loop can be reduced to 4-5 as follows: private static class Runner implements Runnable { public void run() { Object[] roots = new Object[1024]; while (true) { Int index = (int) (Math.random() * roots.length); Object o0 = new Object(); Object o1 = new Object(); Object o2 = new Object(); Object o3 = new Object(); Object o4 = new Object(); Object o5 = new Object(); roots[index] = new Object[1024 * 8]; } } } Both creating new Object objects and ssigning new Object[1024 * 8] to the roots[index] is important to make VM to crash. Putting the loop content into statically synchronized block makes the test to stop crashing the VM. Also it is important that the allocated arrays are big enough, like now in the test: Object[1024 * 8]. So, my initial quess is that there is an old VM bug with a data race either in GC or in the JVMTI. Another guess is that this crash somehow depends on safepoints. I have to investigate this bug more to find out the exact cause of the crash. Anyway, it is very interesting bug. Matthias, thanks a lot for creating the bug and providing the test!