I have been using JRockit since many years 2007. I find it slower than Hotspot, but it has been always better on diagnosis and analysis of problems. Since last summer, I have been working for an international telecommunication systems vendor. We design and implement various products for telecom operators, on top of HP OpenCall Convergent Communication Platform. I am fan of Open Source and Free Software, but this platform is running “only” with JRockit VM. We have tuning it for low latencies and runs very cool, but we have faced various problems, where JRockit has helped us a lot on troubleshooting.
I will describe here a few useful commands of JRCMD. JRCMD is a small command-line tool that can be used to interact with a running JRockit instance.
- Get a thread dump
- Memory utilization
- Memory analysis of heap on a per-class basis
- State of VM
- Create a flight recording
- Produce a heap dump
1) Get a thread dump
$> jrcmd <pid> print_threads [nativestack=true]
This is the usual SIGQUIT handler, which prints all thread stacks. You can also get a thread using the classic way: “$> kill -3 <pid>”
In any case you will get a thread dump like this:
===== FULL THREAD DUMP =============== Thu Jun 21 11:38:19 2012 Oracle JRockit(R) R28.1.4-7-144370-1.6.0_26-20110617-2130-linux-ia32 "http-172.18.57.4-8080-58" id=46791 idx=0x4 tid=17680 prio=5 alive, waiting, native_blocked, daemon -- Waiting for notification on: org/apache/tomcat/util/net/JIoEndpoint$Worker@0x5eef4588[fat lock] at jrockit/vm/Threads.waitForNotifySignal(JLjava/lang/Object;)Z(Native Method) at java/lang/Object.wait(J)V(Native Method) at java/lang/Object.wait(Object.java:485) at org/apache/tomcat/util/net/JIoEndpoint$Worker.await(JIoEndpoint.java:415) ^-- Lock released while waiting: org/apache/tomcat/util/net/JIoEndpoint$Worker@0x5eef4588[fat lock] at org/apache/tomcat/util/net/JIoEndpoint$Worker.run(JIoEndpoint.java:441) at java/lang/Thread.run(Thread.java:662)[optimized] at jrockit/vm/RNI.c2java(IIIII)V(Native Method) -- end of trace "(Signal Handler)" id=2 idx=0x8 tid=21213 prio=5 alive, native_blocked, daemon "(OC Main Thread)" id=3 idx=0xc tid=21214 prio=5 alive, native_waiting, daemon "(GC Worker Thread 1)" id=? idx=0x10 tid=21215 prio=5 alive, daemon "(GC Worker Thread 2)" id=? idx=0x14 tid=21216 prio=5 alive, daemon "(Code Generation Thread 1)" id=4 idx=0x18 tid=21217 prio=5 alive, native_waiting, daemon "(Code Optimization Thread 1)" id=5 idx=0x1c tid=21218 prio=10 alive, native_waiting, daemon "(Code Optimization Thread 2)" id=6 idx=0x20 tid=21219 prio=10 alive, native_waiting, daemon "(VM Periodic Task)" id=7 idx=0x24 tid=21220 prio=10 alive, native_blocked, daemon "Finalizer" id=8 idx=0x28 tid=21221 prio=8 alive, native_waiting, daemon at jrockit/memory/Finalizer.waitForFinalizees(J[Ljava/lang/Object;)I(Native Method) at jrockit/memory/Finalizer.access$700(Finalizer.java:12)[optimized] at jrockit/memory/Finalizer$4.run(Finalizer.java:189) at java/lang/Thread.run(Thread.java:662) at jrockit/vm/RNI.c2java(IIIII)V(Native Method) -- end of trace "Reference Handler" id=9 idx=0x2c tid=21222 prio=10 alive, native_waiting, daemon at java/lang/ref/Reference.waitForActivatedQueue(J)Ljava/lang/ref/Reference;(Native Method) at java/lang/ref/Reference.access$100(Reference.java:11) at java/lang/ref/Reference$ReferenceHandler.run(Reference.java:82) at jrockit/vm/RNI.c2java(IIIII)V(Native Method) -- end of trace ... ...
2) Memory utilization
$> jrcmd <pid> print_memusage
This command can help you with out of memory errors. It analyses (in summary) the memory allocated by java process (including native code). Columns: a) The name of a memory space, b) How much memory is mapped for that space, c) Extra details. A sample run is the following:
Total mapped 2110560KB (reserved=6044KB) - Java heap 1572864KB (reserved=0KB) - GC tables 52620KB - Thread stacks 55060KB (#threads=306) - Compiled code 23872KB (used=21690KB) - Internal 776KB - OS 23368KB - Other 257328KB - Java class data 123648KB (malloced=123375KB #169700 in 29996 classes) - Native memory tracking 1024KB (malloced=296KB #8)
3) Memory analysis of heap on a per-class basis
$> jrcmd <pid> print_object_summary
Prints details of all the instances on the heap on a per-class basis, together with a differential value of how the memory usage has changed. Columns: a) Percentage of heap that objects of this class occupy, b) The total size occupied by the instances of a specific class, c) The number of instances of a specific class, d) The change in size from the first invocation of this command, e) The full name of the class. Check the next sample run, where we might have a problem with objects of class “org/adrianos/MyDTO”:
--------- Detailed Heap Statistics: --------- 61.1% 939735k 6772960 +939735k [C 16.4% 252243k 10762404 +252243k java/lang/String 7.0% 107516k 3947228 +107516k [Ljava/lang/String; 4.5% 69265k 369180 +69265k [Ljava/lang/Object; 1.6% 24127k 205889 +24127k org/adrianos/MyDTO 1.3% 19486k 1247140 +19486k java/lang/Long 1.0% 15551k 26621 +15551k [B 0.6% 8871k 9700 +8871k [I 0.6% 8710k 103896 +8710k [Ljava/util/HashMap$Entry; 1537175kB total --- --------- End of Detailed Heap Statistics ---
4) State of VM
$> jrcmd <pid> print_vm_state
This command produce an output similar to the dump file that is normally created when a JRockit instance crashes. It shows various information of VM like command line arguments of java process, uptime, CPU type, state of heap, loaded modules, libc release, etc.. Check the next excerpt of a sample run:
Uptime : 5 days, 16:29:55 on Thu Jun 21 12:02:34 2012 Version : Oracle JRockit(R) R28.1.4-7-144370-1.6.0_26-20110617-2130-linux-ia32 CPU : Intel Westmere (HT) SSE SSE2 SSE3 SSSE3 SSE4.1 SSE4.2 Core Intel64 Number CPUs : 8 Tot Phys Mem : 12632571904 (12047 MB) OS version : Red Hat Enterprise Linux Server release 5.5 (Tikanga) Linux version 2.6.18-194.26.1.el5PAE (firstname.lastname@example.org) (gcc version 4.1.2 20080704 (Red Hat 4.1.2-48)) #1 SMP Fri Oct 29 14:28:58 EDT 2010 (i686) Thread System: Linux NPTL LibC release : 2.5-stable Java locking : Lazy unlocking enabled (class banning) (transfer banning) State : JVM is running (Main thread has finished) Command Line : -Dprogram.name=run.sh -Xms1536M -Xmx1536M -Djava.net.preferIPv4Stack=true -Xverbose:gc,memory -XverboseLog:/tmp/gc-jrockit.log -Xbootclasspath/p: -XXaggressive -XXcompaction:heapParts=1536 -Xgc:genconcon -Xns:150M -XXgcThreads:2 -XXgcTrigger:50 -XXcompaction:internalPercentage=1.0 -XXcompaction:externalPercentage=1.0 -Xmanagement -Djrockit.managementserver.port=4646 -Dcom.sun.management.jmxremote.ssl=false -Djava.net.preferIPv4Stack=true -Djava.endorsed.dirs=/var/lib/OC/imsc/lib/endorsed -Dsun.java.launcher=SUN_STANDARD com.adrianos.Main Repository : /tmp/2012_06_15_19_32_40_21109 java.home : /usr/java/jrockit-jdk1.6.0_26-R28.1.4-4.0.1.orig/jre StackOverFlow: 0 StackOverFlowErrors have occured OutOfMemory : 0 OutOfMemoryErrors have occured C Heap : Good; no memory allocations have failed GC Strategy : Mode: pausetime, with strategy: genconcon (basic strategy: genconcon) GC Status : OC is not running. Last finished OC was OC#5287. : YC is not running. Last finished YC was YC#16925. YC Promotion : Last YC successfully promoted all objects YC History : Ran 3 YCs before OC#5283. : Ran 3 YCs before OC#5284. : Ran 3 YCs before OC#5285. : Ran 3 YCs before OC#5286. : Ran 3 YCs before OC#5287. : Ran 2 YCs since last OC. Heap : 0x5661a000 - 0xb661a000 (Size: 1536 MB) Compaction : (no compaction area) Allocation : TLA-min: 2048, TLA-preferred: 20480 TLA-waste limit: 2048 NurseryList : 0x869370d8 - 0x941e0390 KeepArea : 0x8da6c078 - 0x941e0390 KA Markers : [ 0x8b4857c8, 0x8da6c078 , 0x941e0390 ] Forbidden A : (none) Previous KA : 0x8b4857c8 - 0x8da6c078 Previous FA : (none) CompRefs : References are 32-bit. ... ... Loaded modules: 08048000-08057193 /usr/java/jrockit-jdk1.6.0_26-R28.1.4-4.0.1.orig/bin/java b7f12000-b7f1262b /usr/java/jrockit-jdk1.6.0_26-R28.1.4-4.0.1.orig/bin/java ... ...
5) Create a flight recording
$> jrcmd <pid> start_flightrecording name=myrecord1 filename=/var/tmp/myrecord1.jfr duration=60s compress=true settings=/my/path/xxx.jfs
Starts a JRockit Flight Recorder recording that can help you analyse the behaviour of your code and find potentials problems (like bottlenecks). This is really useful to understand what your threads are doing. There re many templates located in the JROCKIT_HOME/jre/lib/jfr directory.
6) Produce a heap dump
$> jrcmd <pid> hprofdump filename=/tmp/jrockit1.hprof
Produce heap dumps in the popular HPROF format that can be used to resolve memory leaks or have a better understanding of your code. You can analyse this file using the excellent Eclipse Memory Analyzer Tool (MAT) or default Java memory analyser VisualVM.
- You have to be careful with the last 2 commands as they are very useful, but need extra resources from JVM. Avoid to execute them on high traffic hours, except you really need them. Keep in mind that if JVM is at very “difficult” state, it will not permit such actions.
- MAT is a great tool and I love it. BUT if you want to be fully prepared you have to also play with VisualVM as exists in default installation of Hotspot. This means that VisualVM is always there and you do not need an extra graphical tool to check something simple. I have been in a such case, where I did not have internet access and my laptop use was prohibited.
I hope you will find these details useful. If you have need any clarifications, please ask.
Democracy Requires Free Software