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:
https://visualvm.dev.java.net/saplugin.html

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:

-XX:MaxGCPauseMillis=n

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

-XX:GCPauseIntervalMillis=n

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
-XX:+CMSMarkStackOverflowALot.
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:
http://www.microsoft.com/downloads/details.aspx?
FamilyID=E089CA41-6A87-40C8-BF69-28AC08570B7E&displaylang=en

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:
# http://java.sun.com/webapps/bugreport/crash.jsp
# 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:
# http://java.sun.com/webapps/bugreport/crash.jsp
# 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:

ntdll!DbgBreakPoint
jvm!VMError::show_message_box+0x7f
jvm!VMError::report_and_die+0xe7
jvm!report_error+0x2d
jvm!topLevelExceptionFilter+0x54d
jvm!os::os_exception_wrapper+0x7d
msvcr71!except_handler3+0x61
jvm!JavaCalls::call+0x23
jvm!jni_invoke_static+0xb1
jvm!jni_CallStaticVoidMethod+0x86
java+0x209e
java+0x898f
kernel32!GetModuleFileNameA+0x1b4

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: http://support.microsoft.com/kb/286350

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: http://support.microsoft.com/kb/286350

'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:

test!Java_test_f+0x22

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:

http://msdn.microsoft.com/en-us/library/bb787181(VS.85).aspx

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(" " +
args[i].toString());
}
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: " +
e.getMessage());
} 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.

Proxy.newProxyInstance(SomeInterface.getClassLoader(),
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

e.g.
D:\\openjdk7\\openjdk\\hotspot\\build\\windows>d:\\Progra~1\\Micros~1.NET\\Common7\\Tools\\vsvars32.bat
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)
e.g.
set PATH=D:\\Java\\jdk1.6.0_03\\bin;%PATH%

Now, run create.bat

---------------------
D:\\openjdk7\\openjdk\\hotspot\\build\\windows>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
vm.vcproj
\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*
NOTE: Using the following settings:
HotSpotWorkSpace=D:\\openjdk7\\openjdk\\hotspot
HotSpotBuildSpace=d:\\hotspot\\build
HotSpotJDKDist=d:\\hotspot\\bin
javac -g -d d:\\hotspot\\build\\jvmtifiles D:\\openjdk7\\openjdk\\hotspot/src/share/vm/prims/jvmtiGen.java
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...
Done.
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 x86_32.ad
\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*\*

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 libjvm.so with -g flag and loaded and used this new libjvm.so with dbx. With that, dbx was able to get all the debug information for the core file that was generated with a libjvm.so 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:
com.sun.tools.hat
com.sun.tools.hat.internal.model
com.sun.tools.hat.internal.oql
com.sun.tools.hat.internal.parser
com.sun.tools.hat.internal.server
com.sun.tools.hat.internal.util

It is possile to just build jhat.jar instead of building the whole jdk. In com.sun.tools.hat, 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.

Friday Nov 30, 2007

Building OpenJDK on Windows with NetBeans

Trying to build OpenJDK on Windows ? Here are some simple steps that may help...

Here are the softwares required for the build.

- Download OpenJDK from http://download.java.net/openjdk/jdk7/ and unzip the contents
- Download and install jdk 6.0 from http://java.sun.com/javase/downloads/index.jsp and jdk 7.0 from http://download.java.net/jdk7/binaries
- Download and install openjdk binary plugs from http://download.java.net/openjdk/jdk7/
- Install Microsoft Visual Studio .NET 2003 Professional
- Install Cygwin from http://www.cygwin.com. Make sure you install it in dos/text mode. Along with the default installation, we need to install Devel, Interpreters and Utils pakages. For the build, we need make 3.80, so if the cygwin make in not 3.80, download make bundle from http://cygwin.paracoda.com/release/make/make-3.80-1.tar.bz2 and untar it in a separate folder.
- Download and install findbugs from http://findbugs.sourceforge.net/downloads.html.
- Download and install Ant from http://ant.apache.org/bindownload.cgi
- Install Microsoft DirectX 9.0 SDK
- Download and install Microsoft Unicode library
- Install Freetype 2.3.4 from http://sourceforge.net/project/showfiles.php?group_id=3157
- Install NetBeans 6.0 from http://www.netbeans.org/downloads/

To build OpenJDK with NetBeans, open 'jdk' project in openjdk/jdk/make/netbeans/ with NetBeans. But first open a command window (cmd.exe) and set the path for following installed softwares:

set PATH=d:/utilities/usr/bin;d:\\devtools\\cygwin\\bin;D:\\devtools\\findbugs-1.3.0\\bin;
D:\\devtools\\apache-ant-1.7.0\\bin;%PATH%

Here, d:/utilities/usr/bin contains make 3.80. Also, it is setting the path for cygwin, FindBugs and ant.

then run vsvars32.bat of Microsoft Visual Studio .NET:
d:\\Progra~1\\Micros~1.NET\\Common7\\Tools\\vsvars32.bat

Now launch Netbeans from this command window.

In Netbeans, click on File->Open Project. Browse to openjdk/jdk/make/netbeans/ and select 'jdk'.

In openjdk/jdk/make/netbeans/common/make.xml file, change the location of bin/make to your 3.80 make.

<target name="-pre-init.windows" if="os.windows">
<property name="platform" value="windows"/>
<property name="make" value="d:/utilities/usr/bin/make"/>
</target>

In build.properties file, set the following environment variables:

bootstrap.jdk=d:/devtools/jdk1.7.0

make.options=\\
ALT_BOOTDIR=D:/Java/jdk1.6.0_03 \\
ALT_BINARY_PLUGS_PATH=D:/devtools/openjdk-binary-plugs \\
ALT_JDK_IMPORT_PATH=d:/devtools/jdk1.7.0 \\
ALT_DXSDK_PATH=d:/devtools/dxsdk9 \\
ALT_COMPILER_PATH=D:/Progra~1/Micros~1.NET/Vc7/bin \\
ALT_MSDEVTOOLS_PATH= D:/Progra~1/Micros~1.NET/Common7/Tools/Bin \\
ALT_MSVCR71_DLL_PATH= D:/Progra~1/Micros~1.NET/SDK/v1.1/Bin \\
ALT_FREETYPE_LIB_PATH=d:/devtools/freetype-2.3.4/lib \\
ALT_FREETYPE_HEADERS_PATH=d:/devtools/freetype-2.3.4/include \\
ALT_UNICOWS_LIB_PATH=d:/devtools/unicows \\
ALT_UNICOWS_DLL_PATH=d:/devtools/unicows \\
LD_LIBRARY_PATH= \\
CLASSPATH= \\
JAVA_HOME= \\
SHLVL=1 \\
OPENJDK=true

And that's all we need to do. Start the build (press F11 or right click on jdk project and click Build)

Thursday Jul 05, 2007

How to programmatically obtain GC information

Here's a small program which uses GarbageCollectorMXBean MBean to programmatically obtain the GC information of the running java process. Call it's printGCInfo in your applcation whenever you want to get the last GC information.
import com.sun.management.GcInfo;
import javax.management.MBeanServer;
import java.lang.management.ManagementFactory;
import com.sun.management.GarbageCollectorMXBean;
import java.lang.management.MemoryUsage;
import java.util.Iterator;
import java.util.Map;
import java.util.Set;

public class GCInformation {
    
    private static final String GC_BEAN_NAME =
         "java.lang:type=GarbageCollector,name=ConcurrentMarkSweep";
    private static volatile GarbageCollectorMXBean gcMBean;
    
    /\*\* Creates a new instance of GCInformation \*/
    public GCInformation() {
    }
    
    // initialize the GC MBean field
    private static void initGCMBean() {
        if (gcMBean == null) {
            synchronized (GCInformation.class) {
                if (gcMBean == null) {
                    gcMBean = getGCMBean();
                }
            }
        }
    }    
    // get the GarbageCollectorMXBean MBean from the
    // platform MBean server
    private static GarbageCollectorMXBean getGCMBean() {
        try {
            MBeanServer server = ManagementFactory.getPlatformMBeanServer();
            GarbageCollectorMXBean bean = 
                ManagementFactory.newPlatformMXBeanProxy(server,
                GC_BEAN_NAME, GarbageCollectorMXBean.class);
            return bean;
        } catch (RuntimeException re) {
            throw re;
        } catch (Exception exp) {
            throw new RuntimeException(exp);
        }
    }
    
    /\*\*
     \* Call this method from your application whenever you 
     \* want to get the last gc info
     \*
     \*/
    static boolean printGCInfo() {
        // initialize GC MBean
        initGCMBean();
        try {
            GcInfo gci = gcMBean.getLastGcInfo();
            long id = gci.getId();
            long startTime = gci.getStartTime();
            long endTime = gci.getEndTime();
            long duration = gci.getDuration();
            
            if (startTime == endTime) {
                return false;   // no gc
            }
            System.out.println("GC ID: "+id);
            System.out.println("Start Time: "+startTime);
            System.out.println("End Time: "+endTime);
            System.out.println("Duration: "+duration);
            Map mapBefore = gci.getMemoryUsageBeforeGc();
            Map mapAfter = gci.getMemoryUsageAfterGc();

            System.out.println("Before GC Memory Usage Details....");
            Set memType = mapBefore.keySet();
            Iterator it = memType.iterator();
            while(it.hasNext()) {
                String type = (String)it.next();
                System.out.println(type);
                MemoryUsage mu1 = mapBefore.get(type);
                System.out.print("Initial Size: "+mu1.getInit());
                System.out.print(" Used: "+ mu1.getUsed());
                System.out.print(" Max: "+mu1.getMax());
                System.out.print(" Committed: "+mu1.getCommitted());
                System.out.println(" ");
            }
            
            System.out.println("After GC Memory Usage Details....");
            memType = mapAfter.keySet();
            it = memType.iterator();
            while(it.hasNext()) {
                String type = (String)it.next();
                System.out.println(type);
                MemoryUsage mu2 = mapAfter.get(type);
                System.out.print("Initial Size: "+mu2.getInit());
                System.out.print(" Used: "+ mu2.getUsed());
                System.out.print(" Max: "+mu2.getMax());
                System.out.print(" Committed: "+mu2.getCommitted());
                System.out.println(" ");
            }
        } catch (RuntimeException re) {
            throw re;
        } catch (Exception exp) {
            throw new RuntimeException(exp);
        }
        return true;
    }
    
    /\*\*
     \* @param args the command line arguments
     \*/
    public static void main(String[] args) {
        // Print the last gc information
        boolean ret = printGCInfo();        
    }    
}
Note that the GarbageCollector name used here is "ConcurrentMarkSweep" because I was running my appication with Concurrent Mark Sweep collector. Please use the appropriate Collector name from the list of Collector names I had posted in my previous entry.
About

poonam

Search

Categories
Archives
« April 2014
SunMonTueWedThuFriSat
  
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
   
       
Today