Oracle (sun) jdk console tools.

Modern oracle JVMs (java 1.7, java 1.6) are bundled with diagnostic tools of your jvm during run-time. Here i'm going introduce the most prominent of them.

First to mention is of course VisualVM which evolves even independently of jvm releases. VisualVM allows relative deep analysis and its comprehensive enough furthermore it's open source tool.

However it reaches limits when you have to work with java version prior to 1.5. (in a real world sometimes thing changes slowly ;) Also it's often the case that it's not easy to connect over RMI remotely to productive machines, therefore its never a bad thing to be familiar with console tools modern jdk and jvm's providing. Furthermore console tools are often very handy, focused on one or few tasks, they are low resource consuming and you can build chains of such tools and reuse them in your way. So let's look on them.


Since jdk 1.5.0

The name of the command suggest that is similar to know UNIX ps but for java processes. So jps, when it called without parameters list all java processes on the local machine, which is very handy. Let's look on some examples.

2928 TestSuite  
2524 Jps  
1796 org.eclipse.equinox.launcher_1.3.0.v20120522-1813.jar  

Do you see which vmid has my Eclipse ide? ;) Here another verbose example whit program arguments and jvm params.

$jps -v -m
2928 TestSuite -Dfile.encoding=Cp1252  
5684 -Xbootclasspath/a:C:PROGRA~2Javajre6libdeploy.jar;C:PROGRA~2Javajre6libjavaws.jar;C:PROGRA~2Javajre6libplugin.jar -Xmx32m -Djava.awt.headless=true -XX:MaxDirectMemorySize=64m  
4256 Jps -v -m -Dapplication.home=C:envjava1.7.0_5jdk_64 -Xms8m  
1796 org.eclipse.equinox.launcher_1.3.0.v20120522-1813.jar -os win32 -ws win32 -arch x86_64 -showsplash C:developmenteclipse4.2\pluginsorg.eclipse.platform_4.2.0.v201206081400splash.bmp -launcher C:developmenteclipse4.2eclipse.exe -name Eclipse --launcher.library C:developmenteclipse4.2\plugins/org.eclipse.equinox.launcher.win32.win32.x86_64_1.1.200.v20120522-1813eclipse_1503.dll -startup C:developmenteclipse4.2\plugins/org.eclipse.equinox.launcher_1.3.0.v20120522-1813.jar --launcher.overrideVmargs -exitdata d50_5c -product org.eclipse.epp.package.jee.product -vm C:WINDOWSsystem32javaw.exe -vmargs -Dosgi.requiredJavaVersion=1.5 -Dhelp.lucene.tokenizer=standard -Xms40m -Xmx512m -XX:MaxPermSize=256m -jar C:developmenteclipse4.2\plugins/org.eclipse.equinox.launcher_1.3.0.v20120522-1813.jar -Dosgi.requiredJavaVersion=1.5 -Dhelp.lucene.tokenizer=standard -Xms40m -Xmx512m -XX:MaxPermSize=256m  


Since jdk 1.5.0 (Will not be able connect to jvm's version below 1.5)

Next interesting command is jinfo. jinfo prints configuration information for a given Java process or core file or a remote debug server.  Information details include Java System properties and command line flags. Here is example with shortened output.

$jinfo 2992
Attaching to process ID 2992, please wait...  
Debugger attached successfully.  
Server compiler detected.  
JVM version is 23.1-b03

Java System Properties: = Java(TM) SE Runtime Environment  
sun.boot.library.path = C:envjava1.7.0_5jdk_64jrebin  
java.class.version = 51.0 = HotSpot 64-Bit Tiered Compilers  
sun.cpu.endian = little  

VM Flags:  


*Since jdk 1.5.0 (Will not be able connect to jvm's version below 1.5) * jmap list information about shared objects used by a java process. Also it lists heap memory details. Here further examples again.

$jmap 2992
Attaching to process ID 2992, please wait...  
Debugger attached successfully.  
Server compiler detected.  
JVM version is 23.1-b03  
0x000000005f1d0000      7272K   C:envjava1.7.0_5jdk_64jrebinserverjvm.dll  
0x000000005f9c0000      836K    C:envjava1.7.0_5jdk_64jrebinmsvcr100.dll  
0x000000006b430000      160K    C:envjava1.7.0_5jdk_64jrebinjava.dll  
0x000000006d3c0000      84K     C:envjava1.7.0_5jdk_64jrebinzip.dll  
0x00000000727b0000      60K     C:envjava1.7.0_5jdk_64jrebinverify.dll  
0x0000000077380000      1148K   C:WINDOWSsystem32kernel32.dll  
0x00000000774a0000      1000K   C:WINDOWSsystem32USER32.dll  
0x00000000775a0000      1700K   C:WINDOWSSYSTEM32ntdll.dll  
0x0000000077760000      28K     C:WINDOWSsystem32PSAPI.DLL  
0x000000013f150000      208K    C:envjava1.7.0_5jdk_64binjavaw.exe  
0x000007fefa7f0000      36K     C:WINDOWSsystem32WSOCK32.dll  
0x000007fefabe0000      236K    C:WINDOWSsystem32WINMM.dll  
0x000007fefc070000      2000K  
0x000007fefdb50000      432K    C:WINDOWSsystem32KERNELBASE.dll  

jmap has also useful options like -heap to show current heap situation. Also it has the option -histo which print memory statistic per Class. Here an example of Sting-intensive application...

$jmap -histo 2992

num     #instances         #bytes  class name  
1:        125224        4007168  java.lang.String  
2:        123817        2971608  java.util.LinkedList$Node  
3:           359        2827440  [I  
4:          5388         737888  <methodKlass>  
5:          5388         642200  <constMethodKlass>  
6:           353         400888  <constantPoolKlass>  
7:           353         256096  <instanceKlassKlass>  
8:           320         255008  <constantPoolCacheKlass>  

jmap has also aptio which is not mentuon in the documentation, but if you type -help on the consele. I'm talkin about dump option which allows to dump heap to files.

$jmap -dump:format=b,file=test_heap.bin 2992
Dumping heap to C:envjava1.7.0_5jdk_64bintest_heap.bin ...  
Heap dump file created  

This is very usefull for detailed analysis of heap, which iss done whith the nex tool.


Since jdk 1.6.0

jhat parses a java heap dump file, launches a webserver on default port 7000. So it is possible to browse through the heap. jhat even supports Object Query Language) (OQL) to query heap dumps.  To look inside the genrated heap dump we execute:

$jhat -J-mx768m  test_heap.bin

Reading from test_heap.bin...  
Dump file created Thu Aug 02 11:38:50 CEST 2012  
Snapshot read, resolving...  
Resolving 430136 objects...  
Chasing references, expect 86 dots.................................................  
Eliminating duplicate references...................................................  
Snapshot resolved.  
Started HTTP server on port 7000  
Server is ready.  

Now we can browse through parsed heap on the local server: http://localhost:7000.
Alternatively you can browse your heapdumps with MAT desktop tool.


Since jdk 1.5.0

jstat monitors jvms Garbage Collcetion (GC), Hot Spot compilation and Heap Statistic.  Therefore it's quite powerful and usefull tool. You have to give the option, vmid,  interval and count. Next exampel prints all available options.

$jstat -options


Next shows information about loaded and unload classes, corresponding bytes and time that was spend for such operations.

$jstat -class 1160
Loaded Bytes Unloaded Bytes Time  
 12049 26208,9 40 66,3 7,58

Next shows overal stistic of jvm GC. It's pick the statistic 5 times with an interval of 3 seconds.

$jstat -gc 1160 3000 5
2176,0 64,0 0,0 0,0 81536,0 1414,4 73600,0 31683,4 75776,0 75442,4 57 0,492 46 8,149 8,641  
2176,0 64,0 0,0 0,0 81536,0 2001,0 73600,0 31683,4 75776,0 75442,8 57 0,492 46 8,149 8,641  
2176,0 64,0 0,0 0,0 81536,0 18898,7 73600,0 31683,4 76160,0 76104,4 57 0,492 46 8,149 8,641  
2176,0 64,0 0,0 0,0 81536,0 19213,5 73600,0 31683,4 76160,0 76111,9 57 0,492 46 8,149 8,641  
2176,0 64,0 0,0 0,0 81536,0 20479,0 73600,0 31683,4 76160,0 76145,3 57 0,492 46 8,149 8,641  

This helps to interprete the columns:

S0C Current survivor space 0 capacity (KB).
S1C Current survivor space 1 capacity (KB).
S0U Survivor space 0 utilization (KB).
S1U Survivor space 1 utilization (KB).
EC Current eden space capacity (KB).
EU Eden space utilization (KB).
OC Current old space capacity (KB).
OU Old space utilization (KB).
PC Current permanent space capacity (KB).
PU Permanent space utilization (KB).
YGC Number of young generation GC Events.
YGCT Young generation garbage collection time.
FGC Number of full GC events.
FGCT Full garbage collection time.
GCT Total garbage collection time.

I my case we can see some increase of Eden Space utilization (EU) during the time. Please look to the documention for further information to other options. If you wannt to be able to track jstat of remote machines, you can wire them by utilising jstatd command on the remote side.


Since jdk 1.5.0

Abowe we saw GC, memory and Heap statistics, now is time for Threads, that is where jstack comes to play. jstack prints Java stack traces for a given Java process or core file or a remote debug server.

$jstack 5124

2012-08-02 22:29:34  
Full thread dump Java HotSpot(TM) 64-Bit Server VM (22.1-b02 mixed mode):

"DestroyJavaVM" prio=6 tid=0x000000000276b800 nid=0x157c waiting on condition [0x0000000000000000]
 java.lang.Thread.State: RUNNABLE


"Thread-1" prio=6 tid=0x000000000675d000 nid=0x1814 waiting on condition [0x0000000007b7f000]
 java.lang.Thread.State: TIMED_WAITING (sleeping)
 at java.lang.Thread.sleep(Native Method)
 at de.oc.profiling.tests.TestSuite$

"Thread-0" prio=6 tid=0x000000000675a000 nid=0x1810 waiting on condition [0x000000000792f000]
 java.lang.Thread.State: TIMED_WAITING (sleeping)
 at java.lang.Thread.sleep(Native Method)
 at de.oc.profiling.tests.TestSuite$

"Service Thread" daemon prio=6 tid=0x000000000673d000 nid=0x1808 runnable [0x0000000000000000]
 java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=10 tid=0x000000000673b800 nid=0x1804 waiting on condition [0x0000000000000000]
 java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=10 tid=0x0000000006736800 nid=0x50c waiting on condition [0x0000000000000000]
 java.lang.Thread.State: RUNNABLE

"Attach Listener" daemon prio=10 tid=0x000000000672f800 nid=0x17d4 waiting on condition [0x0000000000000000]
 java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x000000000672a000 nid=0x8f0 runnable [0x0000000000000000]
 java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=8 tid=0x0000000002714000 nid=0x1410 in Object.wait() [0x000000000701f000]

"Reference Handler" daemon prio=10 tid=0x000000000270d000 nid=0xee8 in Object.wait() [0x0000000006c7f000]

"VM Thread" prio=10 tid=0x0000000002705800 nid=0xca0 runnable

"GC task thread#0 (ParallelGC)" prio=6 tid=0x000000000265f800 nid=0xd60 runnable
"GC task thread#1 (ParallelGC)" prio=6 tid=0x0000000002661000 nid=0x6f8 runnable
"GC task thread#2 (ParallelGC)" prio=6 tid=0x0000000002663000 nid=0x14c0 runnable
"GC task thread#3 (ParallelGC)" prio=6 tid=0x0000000002664800 nid=0xe08 runnable
"VM Periodic Task Thread" prio=10 tid=0x000000000674f800 nid=0x180c waiting on condition

JNI global references: 123  

This is a very small stacktrace, i've cutet some threads of my application also i've cuttet a trace of
"Reference Handler" and "Finalizer" threads. So what you see it typical situation for a small app. JVm uses many threads for it's internal task. So you can see that my jvm chooses to use Parallel GC with 4 Threads, which is good choise for my 4 cores Laptop ;)  My application do not run into detlocks, so we se no message about it, otherwise we would see it clearly. Remote usage of jtrack is possible through jsadebugd.

Hope this help somebody. Feel free to share your experinces..