Friday Feb 03, 2012

Diagnosis of a JRockit Deadlock

Recently I came across an interesting JRockit JVM deadlock. I am sharing the details of that deadlock, its diagnosis, and how to workaround that deadlock, which might be useful until the fix for that is available in a future JRockit release.

This deadlock occurred between an application Java thread and the JVM's Code Generation thread. The call traces for both the threads looked like this:

"[ACTIVE] ExecuteThread: '0' for queue:  'weblogic.kernel.Default (self-tuning)'" id=15 idx=0x54 tid=27249 prio=5 alive, native_waiting,daemon
at <unknown>(???.c)@0xffffe410
at eventTimedWaitNoTransitionImpl+79(event.c:90)@0xf7c910a0
at syncWaitForSignalNoTransition+81(synchronization.c:28)@0xf7e0d8a2
at innerNativeDoWait+894(nativelock.c:614)@0xf7d9e8cf
at nativeWait+71(nativelock.c:721)@0xf7d9ec28
at cbrCompileInCodeGenThread+451(compilerqueue.c:339)@0xf7c71b94
at dispatch_compile_request+78(compilerbroker.c:511)@0xf7c64eaf
at cbrGeableCodtRunneInfo+154(compilerbroker.c:580)@0xf7c6516b
at stubsCallJava+77(stubcall.c:112)@0xf7e061ce
at stubsCallJavaV+344(stubcall.c:276)@0xf7e065c9
at javaInvokeStaticVoidMethod+39(javacalls.c:178)@0xf7cd6098
at clsEnsureInitialized+485(class.c:256)@0xf7c4c446
at check_flags_and_clinit+28(compilerbroker.c:302)@0xf7c641fd
at cbrGetRunnableCodeInfo+37(compilerbroker.c:564)@0xf7c650f6
at stubsCallJava+77(stubcall.c:112)@0xf7e061ce
at javaInvokeMethod+280(javacalls.c:1128)@0xf7cd62a9

"(Code Generation Thread 1)" id=4 idx=0x30 tid=27235 prio=5 alive,native_waiting, daemon
at <unknown>(???.c)@0xffffe410
at eventTimedWaitNoTransitionImpl+79(event.c:90)@0xf7c910a0
at syncWaitForSignalNoTransition+81(synchronization.c:28)@0xf7e0d8a2
at innerNativeDoWait+894(nativelock.c:614)@0xf7d9e8cf
at nativeWait+71(nativelock.c:721)@0xf7d9ec28
at clsEnsureInitialized+334(class.c:219)@0xf7c4c3af
at check_flags_and_clinit+28(compilerbroker.c:302)@0xf7c641fd
at compileit+273(compilerbroker.c:317)@0xf7c64992
at cbrCompileRequest+16(compilerbroker.c:537)@0xf7c651b1
at cg_thread+876(compilerqueue.c:223)@0xf7c7168d
at thread_stub+318(lifecycle.c:808)@0xf7d5205f
at start_thread+225(:0)@0x64a832
at __clone+93(:0)@0x5cee0e

The above stack traces and the examination of the core-dump file revealed that the Java Thread (tid=27249) was initializing a class and was in the process of invoking 'clinit' method of that class. Method 'clinit' was not compiled, so it invoked dispatch_compile_request() to compile that method, which sent the compilation request to the Code Generation thread. The Code Generation thread accepted that request and got stuck in waiting for the initialization of the class of 'clinit' to complete. Now, function dispatch_compile_request() checks if the thread has enough (>64K) stack space available for code generation. If yes, then it compiles the method on the same thread otherwise passes the compilation request to the Code Generation (Compiler) thread.

if (!enough_stack) {
res = cbrCompileInCodeGenThread(req, TRUE);
} else {
res = compileit(req, req->method);

In this case, stack space available with Java thread (tid=27249) was around 63K and that was the cause of the problem. Here's what was happening:-

(i) While compiling a method, the Code Generation thread wants the class of that method to be initialized, and if it is not, it waits for the class to get initialized.
(ii) A Java thread which is in the middle of initializing a class requests Code Generation thread to compile a method of that class because it does not have enough stack space to do the compilation itself and waits for the Code Generation thread to finish the compilation.

The above scenario causes a deadlock.

A simple solution to avoid the above situation is to increase the stack size for the application Java threads so that there is always enough space on the stack that the compilation can be done on the same thread itself and the need to pass the compilation requests to the Code Generation thread does not arise at least for the uninitialized classes.

The fix for this bug is progress and will be available in a future JRockit patchset release.

Monday Oct 24, 2011

JavaOne Presentation on SA Plugin for VisualVM

Here are the slides that I presented at the BOF session of 'Serviceability Agent Plugin for VisualVM' at JavaOne 2011.

Serviceability Agent Plugin for VisualVM

Sunday May 16, 2010

SA-Plugin for VisualVM

We all know Serviceability Agent - a great debugging tool for troubleshooting HotSpot VM problems.

Now Serviceability Agent is also available in VisualVM through SAPlugin. More deatils here:

Wednesday Nov 25, 2009

Adplus configuration

While working on a Java Plugin(on Windows) issue, I found one useful feature of

I was having a problem with LoadLibraryEx() and I was trying to load a dll into
another process' address space but it was not getting loaded. Adplus report was
showing DLL_Load and DLL_Unload First Chance Exceptions for the attempts of
loading and then unloading the dll. I wanted to find why the dll was getting
unloaded immediately after it was attempted to get loaded. And for this, I
wanted to obtain the stack trace or crash dump for this First Chance unloading
Exception. The default action for this event is to just log the details.
Adplus report:
  DLL_Load [ld]       return: GN GN
      1st chance: Log
      2nd chance: Log
  DLL_UnLoad [ud]       return: GN GN
      1st chance: Log
      2nd chance: Log
  Process_Shut_Down [epr]       return: VOID VOID
      1st chance: Log;Time;EventLog;Stacks;FullDump
      2nd chance: 

Then I found a way on how to change the actions for these exceptions. Adplus
can accept a configuration file where in we can specify the actions for
Exceptions. I created a conf file 'conf.txt' with following contents:

and ran adplus:

# adplus -c conf.txt

With this I could get the stack trace and crash dump of DLL_Unload event. And
adplus log contained:
  DLL_Load [ld]       return: GN GN
      1st chance: MiniDump;Stack;Log;EventLog
      2nd chance: Log
  DLL_UnLoad [ud]       return: GN GN
      1st chance: MiniDump;Stack;Log;EventLog
      2nd chance: Log
  Process_Shut_Down [epr]       return: VOID VOID
      1st chance: MiniDump;Stack;Log;EventLog
      2nd chance:

Details on Adplus configuration here:

Also, it is possible to define the actions for a specific Exception provided
you know the ExceptionCode. I could not find the code for DLL_UnLoad exception
so I used 'AllExceptions'.
<Code> { ExceptionCode | AllExceptions } </Code>

Monday Jul 13, 2009

G1 Collector

In 6u14, a preliminary version of the new Garbage First (G1) garbage collector is included.

Garbage First, or G1, is a low pause, server style garbage collector targeted for multi-processors with large memories. G1's primary advantages over the Concurrent Mark-Sweep (CMS) collector include incremental compaction, better predictability and ease of use.

For using G1, need to specify following command line options:

-XX:+UnlockExperimentalVMOptions -XX:+UseG1GC

The following options can be used to affect G1's behavior:

\* To set the max GC pause time goal in milliseconds that G1 will attempt to meet:


\* To set the time interval over which GC pauses totaling up to MaxGCPauseMillis may take place:


Sunday Jul 12, 2009

Important CMS Fixes

In this entry, I would like to talk about some CMS (Concurrent Mark Sweep) issues, their workarounds and the releases these are fixed in.

\* 6558100: CMS crash following parallel work queue overflow.
This crash is seen when -XX:+ParallelRefProcEnabled is set.
Workaround is to use -XX:-ParallelRefProcEnabled.
This is fixed in 1.4.2_17, 5.0u14 and 6u4

\* 6578335: CMS: BigApps failure with -XX:CMSInitiatingOccupancyFraction=1
For clarity sake, this issue was broken into three separate bugs 6722112, 6722113 and 6722116.

\* 6722112: CMS: Incorrect encoding of overflown ObjectArrays during concurrent precleaning.
Workaround is to use -XX:-CMSPrecleaningEnabled and also increasing the size of the marking stack via -XX:CMSMarkStackSize{,Max} would reduce the probability of hitting this bug.
This is fixed in 1.4.2_19-rev-b09, 5.0u18-rev-b03, 6u7-rev-b15 and 6u12.

\* 6722113: CMS: Incorrect overflow handling during Precleaning of Reference lists.
Workaround is to use options -XX:-CMSPrecleanRefLists1 and -XX:-CMSPrecleanRefLists2
This is fixed in 6u14, 5.0u18-rev-b05 and 6u13-rev-b05.

\* 6722116: CMS: Incorrect overflow handling when using parallel concurrent marking.
Workaround is to switch off parallel concurrent marking with -XX:-CMSConcurrentMTEnabled. Also increasing the CMS marking stack size (-XX:CMSMarkStackSize, -XX:CMSMarkStackSizeMax) would reduce the probability of hitting this bug.
This is fixed in 6u7-rev-b15 and 6u12.

So, if you face any of these above crashes, please upgrade to the JDK version in which it is fixed. And if upgrade is not possible, workaround can be used to avoid the issue.

Please note that Java SE for Business support contract is required for using Revision Releases (e.g. 1.4.2_19-rev-b09).

Saturday Dec 27, 2008

More on Windows Crash Dumps for Java Processes...

User Mode Process Dumper

There is another very good tool 'User Mode Process Dumper' that can be used to collect user dumps for crashing Java processes.

You can get it and install it from here:

After installation, run it from the Control Panel by clicking 'Process Dumper'. Add the application name to be monitored; java.exe in our case.

Set the process monitoring rules by clicking on 'Rules' button.

Here, specify the folder where dump should get created when the process crashes. Select 'Access Violation' exception to create dump when any access violation exception happens in the process.

Now, let's run the same test program.

D:\\demo>java test

You will see this message box creating the crash dump.

And then a hs_err log file will also be written:

# A fatal error has been detected by the Java Runtime Environment:
# EXCEPTION_ACCESS_VIOLATION (0xc0000005) at pc=0x10001032, pid=8112, tid=6788
# Java VM: OpenJDK Client VM (14.0-b05-internal-debug mixed mode windows-x86 )
# Problematic frame:
# C [test.dll+0x1032]
# An error report file with more information is saved as:
# D:\\demo\\hs_err_pid8112.log
# If you would like to submit a bug report, please visit:
# The crash happened outside the Java Virtual Machine in native code.
# See problematic frame for where to report the bug.

So using this tool, we get both the crash dump as well as the hs_err log file for the crash. :) And the crash dump thus created shows the crash in test.f() native method.

OnError JVM option

There is a JVM option 'OnError' that can be used to perform any action or invoke any tool at the occurrence of fatal error in VM.

For example:
-XX:OnError="drwtsn32 -p %p"
-XX:OnError=”userdump -p %p”

This will invoke drwtsn32/userdump whenever any fatal error occurs in VM.

UseOSErrorReporting JVM option

There is a new option UseOSErrorReporting in jdk7 that passes the exception to OS after handling and generating hs_err log file which invokes the Default System Debugger. So for example, If Dr. Watson is set as the default debugger, then with this option, after hs_err file is written, Dr. Watson would be invoked to create the crash dump for the exception.

This work is done under CR 6227246: Improve Windows unhandled structured exception reporting

Sunday Oct 19, 2008

Windows crash dumps for Java Processes

Windows Crash Dump is memory dump of a process running on a Windows system. These dumps can be very useful for debugging Java process crashes. In this entry I discuss how to collect sane Crash Dumps for Java process crashes on Windows machines that can later be analyzed using Windbg or other 'Debugging Tools For Windows'.

I have a simple java class test which uses native library test.dll using JNI. test.dll implements a 'native' method where it accesses a null pointer and causes a crash. Complete source of this crashing program is here

Windows NT, 2000 and XP

Let's first run this program on a Windows NT/2000/XP machine:

D:\\demo>java test
# An unexpected error has been detected by Java Runtime Environment:
# EXCEPTION_ACCESS_VIOLATION (0xc0000005) at pc=0x10011f68, pid=2020, tid=640
# Java VM: Java HotSpot(TM) Client VM (10.0-b19 mixed mode, sharing windows-x86)
# Problematic frame:
# C [test.dll+0x11f68]
# An error report file with more information is saved as:
# D:\\demo\\hs_err_pid2020.log
# If you would like to submit a bug report, please visit:
# The crash happened outside the Java Virtual Machine in native code.
# See problematic frame for where to report the bug.

Running this program created an hs_err log file in the same folder. Error log file contains the following stack trace:

C [test.dll+0x1032]
j test.f()V+0
j test.main([Ljava/lang/String;)V+19
v ~StubRoutines::call_stub
V [jvm.dll+0x873ed]
V [jvm.dll+0xdfb96]
V [jvm.dll+0x872be]
V [jvm.dll+0x8e501]
C [java.exe+0x14c5]
C [java.exe+0x69cd]
C [kernel32.dll+0x16fd7]

Now, let's run it with -XX:+ShowMessageBoxOnError JVM option. I get the following message box:

Attaching Visual Studio or Windbg to this process or collecting a crash dump with Dr Watson and opening that crash dump with Windbg shows the following call trace:


This shows JVM's error handling frames and does not show that the crash happened in function test.f().

This is because, by default, the First Chance Exceptions are not sent to the System Debugger. And Debuggers receive only the Second Chance Exceptions. The exception in test.f() was a first Chance Exception that was hanlded by JVM. Please see details on First and Second chance exceptions:

So how can we collect crash dumps that contain the correct stack trace of the crash. Let's try 'adplus' to collect the crash dumps.

Start adplus in crash mode:
D:\\windbg>adplus -crash -pn java.exe

and then start your java process with -XX:+ShowMessageBoxOnError

By default, adplus creates mini dumps on First Chance Exceptions and full memory dumps on Second Chance Exceptions. It can be changed; details here:

'adplus' would create dump files in a folder like Crash_Mode__Date_08-12-2008__Time_15-12-56PM. Using Windbg, open the dump created at First Chance Exception and it shows the crashing frame as:


Ah! that's what I was looking for.

Windows 2008 and Windows Vista

Dr. Watson is not available on Windows 2008 and Windows Vista

Starting with Windows Server 2008 and Windows Vista Service Pack1 (SP1), Windows has new error reporting mechanism called 'Windows Error Reporting' or WER. WER can be configured so that full user-mode dumps are collected and stored locally after a user-mode application crashes. This feature is not enabled by default. Enabling this feature requires administrator privileges. To enable and configure the feature, we need to use the following registry values under the
HKEY_LOCAL_MACHINE\\Software\\Microsoft\\Windows\\Windows Error Reporting\\LocalDumps key.

Details here:

And yes, here also we can use 'adplus' to collect Crash Dumps for First Chance and Second Chance Exceptions.

Enjoy Debugging !

Friday Jul 25, 2008

How to implement an interface using Reflection

I was trying to use classes and methods of an existing jar using Reflection. And there was an Interface in that jar which I had to implement. Now how to do that with Reflection ??

We can achieve this by using two classes in java.lang.reflect package; Proxy and InvocationHandler.

java.lang.reflect.Proxy class accomplishes implementation of interfaces by dynamically creating a class that implements a set of given interfaces. This dynamic class creation is accomplished with the static getProxyClass and newProxyInstance factory methods. Instance created with newProxyInstance() represents the proxy instance for interface(s) we want to implement.

While creating a Proxy instance, we need to supply it an invocation handler which handles the method calls for this proxy instance. This is accomplished by implementing java.lang.reflect.InvocationHandler. InvocationHandler interface has a method invoke that needs to be implemented A proxy instance forwards method calls to its invocation handler by calling invoke.

Here is the example:

public class ProxyListener implements java.lang.reflect.InvocationHandler {
public ProxyListener() {
public Object invoke(Object proxy, Method m, Object[] args) throws Throwable
Object result = null;
try {
// Prints the method being invoked
System.out.print("begin method "+ m.getName() + "(");
for(int i=0; i if(i>0) System.out.print(",");
System.out.print(" " +
System.out.println(" )");
// if the method name equals some method's name then call your method
if (m.getName().equals("someMethod")) {
result = myMethod(args[0]);
} catch (Exception e) {
throw new RuntimeException("unexpected invocation exception: " +
} finally {
System.out.println("end method " + m.getName());
return result;
Object myMethod(Object o) {

Now we use newProxyInstance to create an instance of, say interface SomeInterface, passing it the invocation handler.

Class[]{SomeInterface.class} , new ProxyListener());

and you get the proxy instance for SomeInterface. Use it wherever you need an object of SomeInterface.

And that's about it.

Saturday Apr 12, 2008

Utility to compare Class Histograms

We use the Class Histograms generated by -XX:+PrintClassHistogram jvm option quite often to diagnose memory leak issues. But we have to manually compare the histogram entries to analyze the difference between entries and the growth in heap.

I have written a utility in Java that reads the histograms from the file containing these histogram dumps and shows them in a graphical interface. One can click on these histograms and view them in this utility and can also compare any two histograms.

How it works:
- Compile the source java files located here: CompareHistogram Source

or just take the compiled jar file from here: CompareHistograms.jar

and Launch CompareHistograms class file. This will bring up the main window of the tool.
java CompareHistograms or java -jar CompareHistograms.jar
- Select the file containing histograms File->Open Histogram File. You will see this file in the "Histogram File" text field.
- It will show the histograms present in the file.
- Double click any histogram to view it.
- Select any two entries and click the "Compare Histograms" button to compare histograms.
- The histograms and histogram diffs can be exported to text files using Tools->Export Histogram menu item.

Sunday Mar 09, 2008

How to create VC++ project for HotSpot workspace

I am sure very few people would know that on Windows platform, we can create a VC++ project for the HotSpot workspace in JDK sources. It is very useful as it gives me the ability to view and browse HotSpot source code and also build it at a simple click from Visual Studio IDE. It is also very helpful in debugging hotspot issues which can be reproduced on Windows with a simple testcase(and not just at customer site :) )

So let's see how we can create this project for OpenJDK hotspot workspace on 32bit platform and open it in Visual Studio.

There is a batch file 'create.bat' in \\build\\windows\\ folder which creates the VC++ project for hotspot workspace on Windows. Before we run this batch, we need to set two environment variables.

- The 32-bit OpenJDK Windows build requires Microsoft Visual Studio .NET 2003 (VS2003) Professional Edition compiler. Once the compiler is installed, we need to run VCVARS32.BAT to set the compiler environment variables

Setting environment for using Microsoft Visual Studio .NET 2003 tools.
(If you have another version of Visual Studio or Visual C++ installed and wish
to use its tools from the command line, run vcvars32.bat for that version.)

- Set the Path to include installed jdk bin folder (jdk6 or jdk7)
set PATH=D:\\Java\\jdk1.6.0_03\\bin;%PATH%

Now, run create.bat

Usage: create HotSpotWorkSpace HotSpotBuildSpace HotSpotJDKDist

This is the interactive build setup script (as opposed to the batch
build execution script). It creates HotSpotBuildSpace if necessary,
copies the appropriate files out of HotSpotWorkSpace into it, and
builds and runs MakeDeps in it. This has the side-effect of creating
the file in the build space, which is then used in Visual C++.
The HotSpotJDKDist defines place where JVM binaries should be placed.
Environment variable FORCE_MSC_VER allows to override MSVC version autodetection.

The generated project file depends upon the include databases. If
those are changed then MakeDeps is rerun.

NOTE that it is now NOT safe to modify any of the files in the build
space, since they may be overwritten whenever this script is run or
nmake is run in that directory.

Passing those required arguments:

D:\\openjdk7\\openjdk\\hotspot\\build\\windows>create.bat D:\\openjdk7\\openjdk\\hotspot d:\\hotspot\\build d:\\hotspot\\bin
Will generate VC7 project
NOTE: Using the following settings:
javac -g -d d:\\hotspot\\build\\jvmtifiles D:\\openjdk7\\openjdk\\hotspot/src/share/vm/prims/
Generating d:\\hotspot\\build\\jvmtifiles/jvmtiEnv.hpp
Generating d:\\hotspot\\build\\jvmtifiles/jvmtiEnter.cpp
..... cut the output here ....
creating c1_ValueType.cpp
writing grand include file

writing dependencies file

Writing .vcproj file...
rm -f ad_x86_32.cpp ad_x86_32.hpp ad_x86_32_clone.cpp ad_x86_32_expand.cpp ad_x86_
d_x86_32_peephole.cpp ad_x86_32_pipeline.cpp adGlobals_x86_32.hpp dfa_x86_32.cpp
adlc -q -T -U_LP64

This creates vm.vcproj file in d:\\hotspot\\build folder.

Open this in Visual Studio .Net and have fun!

Sunday Feb 24, 2008

Debugging JVM hang with 'dbx'

Recently worked on a JVM hang problem, so posting here the steps followed in debugging this issue with dbx.

Customer was facing hard hang on a Solaris-x86 machine with jdk 1.5.0_08 and the process was not even responding to kill -3. They sent us a core file of the hung process.

For dbx to have the debug information, I re-built the product version of 1.5.0_08 with -g flag and loaded and used this new with dbx. With that, dbx was able to get all the debug information for the core file that was generated with a without any debug info.

The pstack on the core file showed that VMThread is trying to acquire Threads_lock, main thread is waiting on a condition on Threads_lock and another thread 3992 was also trying to grab Threads_lock, so this lock seemed to be causing the deadlock.

----------------- lwp# 1 / thread# 1 --------------------
fef4009b lwp_park (0, 0, 0)
fef3a909 cond_wait_queue (807c540, 807c528, 0, 0) + 3b
fef3ae02 _cond_wait (807c540, 807c528) + 66
fef3ae44 cond_wait (807c540, 807c528) + 21
fe92fc64 __1cHMonitorEwait6Mil_i_ (807c4d0, 0, 0) + 2a4
fecf526b __1cHThreadsKdestroy_vm6F_i_ (8073fb9, 0, 806dc14, fee4d33c, fee4a2a0, 10004) + 7b
feb66ea3 jni_DestroyJavaVM (fee43560) + 123
08051f8e main (2, 807017c, 80432b4) + bfb
080512fa ???????? (86, 8043468, 804346d, 8043494, 80434a8, 80434c6)
----------------- lwp# 11 / thread# 11 --------------------
fef4009b lwp_park (0, 0, 0)
fef399bb slow_lock (fbc92000, 807c528, 0) + 3d
fef39ab1 mutex_lock_impl (807c528, 0) + ec
fef39bbd mutex_lock (807c528) + 1a
fe8c9a00 __1cFMutexElock6MpnGThread__v_ (807c4d0, 8261480) + c0
fe8cc1fe __1cFMutexElock6M_v_ (807c4d0) + 4e
fe996295 __1cUSafepointSynchronizeFbegin6F_v_ (fee493fc, 8261480, fedee000, f8199b74, 3, f8199bbc) + 85
fea659c4 __1cIVMThreadEloop6M_v_ (8261480) + 134
fea66478 __1cIVMThreadDrun6M_v_ (8261480) + 88
fecbe0f2 __1cG_start6Fpv_0_ (8261480) + d2
fef3fd52 _thr_setup (fbc92000) + 4e
fef40040 _lwp_start (fbc92000, 0, 0, f8199ff8, fef40040, fbc92000)
----------------- lwp# 3992 / thread# 3992 --------------------
fef4009b lwp_park (0, 0, 0)
fef399bb slow_lock (6c173c00, 807c528, 0) + 3d
fef39ab1 mutex_lock_impl (807c528, 0) + ec
fef39bbd mutex_lock (807c528) + 1a
fe8ea95e __1cFMutexbClock_without_safepoint_check6M_v_ (807c4d0) + 7e
fe95c56e __1cUSafepointSynchronizeFblock6FpnKJavaThread__v_ (a27f780) + ee
fecb6825 __1cGParkerEpark6Mix_v_ (a27f908, 0, d964b198, 45) + 1e5
fed0963d Unsafe_Park (a27f840, 6807aba4, 0, d964b198, 45, 9480bcb8) + 1dd
f876f2f9 ???????? (0, 0, a27c330, 0, 9ae69a8, 0)
00000000 ???????? (fecf6330, fea09d40, fea03c80, fe964f40, fe91cc40, fe939c50)
00000000 ???????? (fffffd2c, 3badd9be, f468fe16, e78b7254, fe1dbbcc, 0)
00000000 ???????? ()

Now let's look at the Threads_lock in dbx.

(dbx) print -fx Threads_lock
Threads_lock = 0x807c4d0

(dbx) print -r \*((Monitor\*)0x807c4d0)
\*((class Monitor \*) 0x807c4d0) = {
Monitor::Mutex::_lock_count = 0
Monitor::Mutex::_lock_event = 0x807c500
Monitor::Mutex::_suppress_signal = 0
Monitor::Mutex::_owner = 0x97b0978 <----------------
Monitor::Mutex::_name = 0xfed97a0f "Threads_lock"
Monitor::Mutex::INVALID_THREAD = 0
Monitor::_event = (nil)
Monitor::_counter = 0
Monitor::_waiters = 1
Monitor::_tickets = 0

(dbx) print -r \*((Thread\*)0x97b0978)
\*((class Thread \*) 0x97b0978) = {
Thread::ThreadShadow::_pending_exception = (nil)
Thread::_exception_file = (nil)
Thread::_exception_line = 0
Thread::_real_malloc_address = 0x97b0d28
Thread::_rawmonitor_list = (nil)
Thread::_SR_lock = 0x9b7b890
Thread::_vm_suspend_depth = 0
Thread::_suspend_flags = 0
Thread::_active_handles = 0x97b0b48
Thread::_free_handle_block = (nil)
Thread::_last_handle_mark = 0x65c92618
Thread::_oops_do_parity = 0
Thread::_highest_lock = 0x65c92cb8 "x\^I{\^I\\xe8\^K{\^I\\xb0\\xd6\\x82\\xf4\\xa0H\\xbeu"
Thread::_unboosted_priority = NoPriority
Thread::_tlab = {
Thread::ThreadLocalAllocBuffer::_start = 0x762476d8
Thread::ThreadLocalAllocBuffer::_top = 0x7624c750
Thread::ThreadLocalAllocBuffer::_end = 0x76257308
Thread::ThreadLocalAllocBuffer::_size = 14078U
Thread::ThreadLocalAllocBuffer::_refill_waste_limit = 219U
Thread::ThreadLocalAllocBuffer::_number_of_refills = 6U
Thread::ThreadLocalAllocBuffer::_fast_refill_waste = 0
Thread::ThreadLocalAllocBuffer::_slow_refill_waste = 202U
Thread::ThreadLocalAllocBuffer::_gc_waste = 0
Thread::ThreadLocalAllocBuffer::_slow_allocations = 0
Thread::ThreadLocalAllocBuffer::_allocation_fraction = {
Thread::ThreadLocalAllocBuffer::AdaptiveWeightedAverage::_average = 0.006992618
Thread::ThreadLocalAllocBuffer::AdaptiveWeightedAverage::_sample_count = 1U
Thread::ThreadLocalAllocBuffer::AdaptiveWeightedAverage::_weight = 35U
Thread::ThreadLocalAllocBuffer::AdaptiveWeightedAverage::_last_sample = 0.006992618
Thread::ThreadLocalAllocBuffer::_target_refills = 50
Thread::ThreadLocalAllocBuffer::_global_stats = 136222936
Thread::_vm_operation_started_count = 1
Thread::_vm_operation_completed_count = 1
Thread::_current_pending_monitor = (nil)
Thread::_current_pending_monitor_is_from_java = 1
Thread::_current_waiting_monitor = (nil)
Thread::_osthread = 0x97b0b00 <-------------
Thread::_resource_area = 0x8c55f50
Thread::_handle_area = 0x98dafc0
Thread::_stack_base = 0x65c93000 ""
Thread::_stack_size = 262144U
Thread::_self_raw_id = 1731617792U

(dbx) print -r \*((OSThread\*)0x97b0b00)
\*((class OSThread \*) 0x97b0b00) = {
OSThread::_start_proc = (nil)
OSThread::_start_parm = (nil)
OSThread::_state = RUNNABLE
OSThread::_interrupted = 0
OSThread::_thread_id = 11982U
OSThread::_lwp_id = 11982U
OSThread::_caller_sigmask = {
OSThread::__sigbits = (4U, 0, 0, 0)
OSThread::_vm_created_thread = 1
OSThread::_current_callback = (nil)
OSThread::_current_callback_lock = (nil)
OSThread::_interrupt_event = 0x97b07d8
OSThread::_saved_interrupt_thread_state = _thread_new

This shows that owner of Threads_lock is thread with id 11982. Stack trace of this thread.

(dbx) thread t@11982
t@11982 (l@11982) stopped in __lwp_park at 0xfef4009b
0xfef4009b: __lwp_park+0x000b: jae __lwp_park+0x19 [ 0xfef400a9, .+0xe ]
(dbx) where
current thread: t@11982
=>[1] __lwp_park(0x0, 0x0), at 0xfef4009b
[2] mutex_lock_queue(0x67366400, 0x0, 0x88a0598, 0x0), at 0xfef3911f
[3] slow_lock(0x67366400, 0x88a0598, 0x0), at 0xfef399bb
[4] mutex_lock_impl(0x88a0598, 0x0), at 0xfef39ab1
[5] __mutex_lock(0x88a0598), at 0xfef39bbd
[6] Mutex::wait_for_lock_blocking_implementation(0xa27f908, 0x97b0978), at 0xfe9d93ba
[7] Mutex::lock(0xa27f908, 0x97b0978), at 0xfe8c99ea
[8] Mutex::lock(0xa27f908), at 0xfe8cc1fe
[9] Parker::unpark(0xa27f908), at 0xfecb69bb
[10] os::interrupt(0xa27f780), at 0xfecbf6bb
[11] Thread::interrupt(0xa27f780), at 0xfecf2ed9
[12] JVM_Interrupt(0x97b0a38, 0x65c923fc, 0x65c923d0, 0x0, 0x65c923fc, 0xf4873020, 0x0, 0xf482f600, 0x65c923fc, 0x65c92424,
0xf8202b6b, 0x0, 0xf8206399, 0x9593fdc0, 0x1, 0x0, 0x65c92400, 0xf482db6b, 0x65c92438, 0xf4873020), at 0xfeb92255
[13] 0xf820843a(0x0, 0xf8206399, 0x9593fdc0, 0x1, 0x0, 0x65c92400), at 0xf820843a
[14] 0xf8202b6b(0x0, 0x0, 0x97f59c18, 0x9593fdc0, 0x65c9243c, 0xf5746e95), at 0xf8202b6b
[15] 0xf8202b6b(0x967a0c40, 0x9, 0x968f6eb8, 0x65c92464, 0xf57472be, 0x65c92498), at 0xf8202b6b
[16] 0xf8202b6b(0x0, 0x968f6eb8, 0x967a0c40, 0x65c9249c, 0xf5845a0c, 0x65c924c4), at 0xf8202b6b
[17] 0xf8202b6b(0x1b58, 0x967a0c40, 0x65c924c8, 0xf5845674, 0x65c92524, 0xf58a1f78), at 0xf8202b6b
[18] 0xf8202b6b(0x7624c168, 0x7624c138, 0x7624c108, 0x7624c0d8, 0x7624bee8, 0x7624bd00), at 0xf8202b6b

It is trying to acquire Monitor 0xa27f908

Now, look at this Monitor:
(dbx) print -r \*((Monitor\*)0xa27f908)
\*((class Monitor \*) 0xa27f908) = {
Monitor::Mutex::_lock_count = 0
Monitor::Mutex::_lock_event = 0x88a0570 <-----------
Monitor::Mutex::_suppress_signal = 0
Monitor::Mutex::_owner = (nil)
Monitor::Mutex::_name = 0xfed97c99 "Park Semaphore"
Monitor::Mutex::INVALID_THREAD = 0
Monitor::_event = (nil)
Monitor::_counter = 0
Monitor::_waiters = 0
Monitor::_tickets = 0
(dbx) print -r \*((Event\*)0x88a0570)
More than one identifier 'Event'.
Select one of the following:
0) Cancel
1) class os::Solaris::Event
2) class Solaris::Event
> 1
\*((class os::Solaris::Event \*) 0x88a0570) = {
Event::_count = 0
Event::_nParked = 0
Event::CachePad = (-6.7529205832009e-205, -6.6220952168053e-205, -1.2786650622506e-204, -1.9668306807887e-204)
Event::_mutex = (
Event::_lwp_mutex::flags = {
Event::_lwp_mutex::flag1 = 4U
Event::_lwp_mutex::flag2 = '\\0'
Event::_lwp_mutex::ceiling = '\\0'
Event::_lwp_mutex::mbcp_type_un = {
Event::_lwp_mutex::bcptype = 0
Event::_lwp_mutex::mtype_rcount = {
Event::_lwp_mutex::count_type1 = '\\0'
Event::_lwp_mutex::count_type2 = '\\0'
Event::_lwp_mutex::magic = 19800U
Event::_lwp_mutex::lock = {
Event::_lwp_mutex::lock64 = {
Event::_lwp_mutex::pad = ""
Event::_lwp_mutex::lock32 = {
Event::_lwp_mutex::ownerpid = 0
Event::_lwp_mutex::lockword = 16842752U
Event::_lwp_mutex::owner64 = 72339069014638592ULL
Event::_lwp_mutex::data = 1813462016ULL

Event::_cond = (
Event::_lwp_cond::flags = {
Event::_lwp_cond::flag = ""
Event::_lwp_cond::type = 0
Event::_lwp_cond::magic = 17238U
Event::_lwp_cond::data = 0

Event::FreeNext = (nil)
Event::Immortal = 0

Here _lwp_mutex->data which is 0x6C173C00 is the owner thread (ulwp_t)

looking at it:
(dbx) x 0x6C173C00/30X
0x6c173c00: 0x6c173c00 0x00000000 0x00000000 0x00000000
0x6c173c10: 0x00000000 0x00000000 0x00000000 0x00000000
0x6c173c20: 0x00000000 0x00000000 0x00000000 0xfef6b740
0x6c173c30: 0x00000000 0x00000000 0x6c174000 0x6c173800
0x6c173c40: 0x00000000 0x00000000 0x00000000 0x6803b000
0x6c173c50: 0x00040000 0x00000000 0x6807b000 0x00040000
0x6c173c60: 0x6803b000 0x00040000 0x00000000 0x00000398
0x6c173c70: 0x00000f98 0x0000007f

0x00000f98 (which is 3992) is the thread id holding this Event::mutex

Now looking at thread 3992:
(dbx) thread t@3992
t@3992 (l@3992) stopped in __lwp_park at 0xfef4009b
0xfef4009b: __lwp_park+0x000b: jae __lwp_park+0x19 [ 0xfef400a9, .+0xe ]
(dbx) where
current thread: t@3992
=>[1] __lwp_park(0x0, 0x0), at 0xfef4009b
[2] mutex_lock_queue(0x6c173c00, 0x0, 0x807c528, 0x0), at 0xfef3911f
[3] slow_lock(0x6c173c00, 0x807c528, 0x0), at 0xfef399bb
[4] mutex_lock_impl(0x807c528, 0x0), at 0xfef39ab1
[5] __mutex_lock(0x807c528), at 0xfef39bbd
[6] Mutex::lock_without_safepoint_check(0x807c4d0), at 0xfe8ea95e
[7] SafepointSynchronize::block(0xa27f780), at 0xfe95c56e
[8] Parker::park(0xa27f908, 0x0, 0xd964b198, 0x45), at 0xfecb6825
[9] Unsafe_Park(0xa27f840, 0x6807aba4, 0x0, 0xd964b198, 0x45, 0x9480bcb8), at 0xfed0963d

It is waiting to lock Threads_lock.

So threads 11982 and 3992 have a deadlock.

Thread 11982 – holds Thread_lock and waiting to acquire Monitor 0xa27f908
Thread 3992 – holds lock on 0xa27f908 and waiting to acquire Threads_lock

This problem has been fixed with 6601725 in 5.0u15 and mustang.

Monday Feb 11, 2008

CR 6454676

This fix for CR 6454676 (Need -XX:+HeapDumpOnCtrlBreak to trigger heap dump on ctrl-break or ctrl-\\) was made available in 1.4.2_18 and 5.0u14. But a format string used in this fix got currupted due to SCCS mis-interpretation and caused the following bug.

6615248: SCCS tag interpetation makes code invalid

And due to this regression, HeapDumpOnCtrlBreak does not work correctly in 5.0u14. This problem has been fixed in 1.4.2_18 and 5.0u17.

Sunday Dec 09, 2007

'jhat' sources in OpenJDK

'jhat' source code is available in OpenJDK. Open 'jdk' project in NetBeans and expand 'Sources For All Platforms'. You can find the sources of 'jhat' in these packages:

It is possile to just build jhat.jar instead of building the whole jdk. In, you will find ant makefile build.xml. This can be used to build jhat.

Tuesday Dec 04, 2007

Heap Dump using -XX:+HeapDumpOnCtrlBreak

Heap Dumps are useful for Java Object Heap analysis. HeapDumpOnCtrlBreak jvm option would be available in upcoming 5.0 and 1.4.2 update releases that can be used to dump heap when a SIGQUIT signal is sent to the running process. One more feature would be available - if this option is used along with -XX:+PrintClassHistogram then both these tasks will be performed in one single VM Operation so that the Class Histogram and the Heap Dump represent the same snapshot of the process.




« December 2015