It was worth attending Staffan Larsen's (Oracle Java Serviceability Architect) presentation "Diagnosing Your Application on the JVM" (Hilton Plaza A/B) just for learning of the new jcmd command-line tool provided with Oracle's JVM 7. The rest of the presentation was "bonus" for me, which was nice for the last session I attended on Wednesday of JavaOne 2012.
The Oracle HotSpot JDK provides jcmd, a command-line tool designed to be both backwards compatible and forward adaptable for future versions of Java. It is designed to support new tools and features that come with new SDKs in a standardized approach. The following screen snapshot shows it used for most basic jps-like functionality (Larsen mentioned jps almost as briefly as I just did and referred to jcmd as "like jps but more powerful").
As the above image shows, jcmd can be used like jps.
Larsen showed some handy features of the jcmd command. He had some small sample Java applications that helped him to demonstrate jcmd. For my purposes, I'm running jconsole in one terminal on my machine and then I'll run jcmd commands against that JVM in which jconsole is running. The next screen snapshot shows how the basic (no arguments) jcmd call provides information on that JConsole process.
jcmd supports execution against JVM processes either by process ID (pid) or by process name. The next screen snapshot shows running jcmd against the JConsole process by that name and passing it help to see which options can be run against that particular process. Note that I tried unsuccessfully to run this against 'dustin' (no existing process) to prove that jcmd is really showing options available for running processes.
The feature demonstrated in the last screen snapshot is one of the most compelling reasons for moving from existing command-line tools provided with the Oracle JDK to jcmd. This image shows how jcmd can provide a list of the available options on a per process basis, allowing for ultimate flexibility in terms of supporting past versions or future versions of Java that support different/new commands.
Just as jcmd <pid> help (or replace pid with process name) lists the available operations that can be run by jcmd against a particular JVM process, this same help mechanism can be run against any one of those specific listed commands [with syntax jcmd <pid> <command_name> help (or use process name instead of pid)], though I could not get this to work properly on my Windows machine.
The next image shows actually running that command against that JVM process rather than simply asking for help on it.
In the two screen snapshots immediately above, I ran jcmd against the pid instead of the process name simply to show that it works against both process ID as well as name. The next screen snapshot shows executing jcmd against the JVM process to get VM flags and command-line options from the JVM process (the pid of this instance of JConsole process is 3556).
Running jcmd's Thread.print command against a supporting JVM process makes easy work of viewing the targeted JVM's threads. The following output is generated from running jcmd JConsole Thread.print against my running JConsole process.
3556: 2012-10-04 23:39:36 Full thread dump Java HotSpot(TM) Client VM (23.2-b09 mixed mode, sharing): "TimerQueue" daemon prio=6 tid=0x024bf000 nid=0x1194 waiting on condition [0x069af000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x23cf2db0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.DelayQueue.take(DelayQueue.java:209) at javax.swing.TimerQueue.run(TimerQueue.java:171) at java.lang.Thread.run(Thread.java:722) "DestroyJavaVM" prio=6 tid=0x024be400 nid=0x1460 waiting on condition [0x00000000] java.lang.Thread.State: RUNNABLE "AWT-EventQueue-0" prio=6 tid=0x024bdc00 nid=0x169c waiting on condition [0x0525f000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x291a90b0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.awt.EventQueue.getNextEvent(EventQueue.java:521) at java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:213) at java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:163) at java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:151) at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:147) at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:139) at java.awt.EventDispatchThread.run(EventDispatchThread.java:97) "Thread-2" prio=6 tid=0x024bd800 nid=0x4a8 in Object.wait() [0x04bef000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x2917ed80> (a java.io.PipedInputStream) at java.io.PipedInputStream.read(PipedInputStream.java:327) - locked <0x2917ed80> (a java.io.PipedInputStream) at java.io.PipedInputStream.read(PipedInputStream.java:378) - locked <0x2917ed80> (a java.io.PipedInputStream) at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:283) at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:325) at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:177) - locked <0x29184e28> (a java.io.InputStreamReader) at java.io.InputStreamReader.read(InputStreamReader.java:184) at java.io.BufferedReader.fill(BufferedReader.java:154) at java.io.BufferedReader.readLine(BufferedReader.java:317) - locked <0x29184e28> (a java.io.InputStreamReader) at java.io.BufferedReader.readLine(BufferedReader.java:382) at sun.tools.jconsole.OutputViewer$PipeListener.run(OutputViewer.java:109) "Thread-1" prio=6 tid=0x024bd000 nid=0x17dc in Object.wait() [0x047af000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x29184ee8> (a java.io.PipedInputStream) at java.io.PipedInputStream.read(PipedInputStream.java:327) - locked <0x29184ee8> (a java.io.PipedInputStream) at java.io.PipedInputStream.read(PipedInputStream.java:378) - locked <0x29184ee8> (a java.io.PipedInputStream) at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:283) at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:325) at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:177) - locked <0x2918af80> (a java.io.InputStreamReader) at java.io.InputStreamReader.read(InputStreamReader.java:184) at java.io.BufferedReader.fill(BufferedReader.java:154) at java.io.BufferedReader.readLine(BufferedReader.java:317) - locked <0x2918af80> (a java.io.InputStreamReader) at java.io.BufferedReader.readLine(BufferedReader.java:382) at sun.tools.jconsole.OutputViewer$PipeListener.run(OutputViewer.java:109) "AWT-Windows" daemon prio=6 tid=0x024bc800 nid=0x16e4 runnable [0x0491f000] java.lang.Thread.State: RUNNABLE at sun.awt.windows.WToolkit.eventLoop(Native Method) at sun.awt.windows.WToolkit.run(WToolkit.java:299) at java.lang.Thread.run(Thread.java:722) "AWT-Shutdown" prio=6 tid=0x024bc400 nid=0x157c in Object.wait() [0x04c6f000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x2918b098> (a java.lang.Object) at java.lang.Object.wait(Object.java:503) at sun.awt.AWTAutoShutdown.run(AWTAutoShutdown.java:287) - locked <0x2918b098> (a java.lang.Object) at java.lang.Thread.run(Thread.java:722) "Java2D Disposer" daemon prio=10 tid=0x024bbc00 nid=0x3b8 in Object.wait() [0x0482f000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x2918b128> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135) - locked <0x2918b128> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151) at sun.java2d.Disposer.run(Disposer.java:145) at java.lang.Thread.run(Thread.java:722) "Service Thread" daemon prio=6 tid=0x024bb800 nid=0x1260 runnable [0x00000000] java.lang.Thread.State: RUNNABLE "C1 CompilerThread0" daemon prio=10 tid=0x024c6400 nid=0x120c waiting on condition [0x00000000] java.lang.Thread.State: RUNNABLE "Attach Listener" daemon prio=10 tid=0x024bb000 nid=0x1278 waiting on condition [0x00000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" daemon prio=10 tid=0x024bac00 nid=0xe3c runnable [0x00000000] java.lang.Thread.State: RUNNABLE "Finalizer" daemon prio=8 tid=0x024a9c00 nid=0x15c4 in Object.wait() [0x046df000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x2918b358> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135) - locked <0x2918b358> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:177) "Reference Handler" daemon prio=10 tid=0x024a4c00 nid=0xe40 in Object.wait() [0x0475f000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x2917e9c0> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:503) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) - locked <0x2917e9c0> (a java.lang.ref.Reference$Lock) "VM Thread" prio=10 tid=0x024a3800 nid=0x164c runnable "VM Periodic Task Thread" prio=10 tid=0x024e7c00 nid=0xcf0 waiting on condition JNI global references: 563
Larsen showed how to use thread information provided by jcmd to resolve a deadlock.
Larsen showed getting a class histogram from the running JVM process with jcmd. This is done using the command jcmd <pid> GC.class_histogram. A very small subset of its output is shown next (the pid of this JConsole process is 4080 this time).
4080: num #instances #bytes class name ---------------------------------------------- 1: 1730 3022728 [I 2: 5579 6381683: 5579 447072 4: 645 340288 5: 4030 337448 [C 6: 645 317472 7: 602 218704 8: 942 167280 [B 9: 826 97720 java.lang.Class 10: 3662 87888 java.lang.String 11: 2486 79552 javax.swing.text.html.parser.ContentModel 12: 3220 77280 java.util.Hashtable$Entry 13: 1180 67168 [S 14: 2503 60072 java.util.HashMap$Entry 15: 181 59368 16: 971 43584 [Ljava.lang.Object; 17: 1053 41160 [[I 18: 206 29040 [Ljava.util.HashMap$Entry; 19: 111 27880 [Ljava.util.Hashtable$Entry; 20: 781 18744 java.util.concurrent.ConcurrentHashMap$HashEntry 21: 1069 17104 java.lang.Integer 22: 213 9816 [Ljava.util.concurrent.ConcurrentHashMap$HashEntry; 23: 202 9696 java.util.HashMap 24: 201 9280 [Ljava.lang.String; 25: 24 8416 [[I
Larsen also demonstrated jstat and several of its useful functions. He demonstrated use of jstat -gcnew (new generation behavior), jstat -precompilation (compilation method statistics), and jstat -options (displays options).
During the course of his presentation, Larsen needed to convert a decimal number (pid?) to its hexadecimal representation for comparing it to the output of another tool. He used the handy printf "%x\n" <pid> command to get the hexadecimal representation of the pid.
Larsen demonstrated use of VisualVM to compare two heap dumps and browse a heap dump. He also demonstrated the VisualVM Profiler.
Larsen moved from the tools previously covered aimed at running JVMs to tools that can be used to analyze JVM core files. He returned to jstack to analyze contents of the core file.
Larsen talked about remotely accessing JVM information via JMX and tools like jconsole and jvisualvm. He demonstrated that jcmd can be used to start JMX exposure as well: ManagementServer.start "with a bunch of parameters." Larsen feels that VisualVM and JConsole would use ManagementServer.start rather than Attach API if implemented today.
jstat can also connect to daemon remotely through use of jstatd. There is no encryption or authentication with jstatd.
jps and jcmd find what's running on system using "well-known file for each JVM": /hsperfdata_<user>/<pod> This file is created on JVM startup and deleted on JVM shutdown. Unused previous files are deleted on startup, so jps and jcmd, as Java programs themselves, will clean these old ones up.
The Attach API "allows sending 'commands' for executionin the JVM," but only works on local machine and for current/same user. This is what jcmd and jstack use. Larsen then went onto explain the different mechanics of using the Attach API for Linux/BSD/Solaris (uses temporary file creation) versus Windows (uses code injection). I employed the Attach API in my post Groovy, JMX, and the Attach API.
Diagnostic commands are "helper routines inside the JVM" that produce "text output." They can be executed via the jcmd utility (and soon via JMX). They each have a self-describing facility: jcmd PerfCounter.print to see the raw contents.
Larsen showed an informative table comparing "communicating with the JVM" approaches: attach, jvmstat, JMX, jstatd, and Serviceability Agent (SA). The SA "should be used as a last resort ('typically for a JVM that is hung')" and uses a "debugger to read information."
Larsen transitioned to talk of future tools. He started this portion of the presentation with coverage of Java Flight Recorder. Java Flight Recorder is a "JVM-built-in profiler and tracer" with "low overhead" and is "always on." Other coming tools are Java Mission Control ("graphical tool providing very detailed runtime monitoring details"), more diagnostic commands for jcmd ("eventually replacing jstack, jmap, jinfo" for various reasons), JMX 2.0 ("something we're picking up again; it was started a very long time ago"), improved logging for JVM (JVM Enhancement Proposal [JEP] 158), and Java Discovery Protocol (anticipating forthcoming JEP for this).
One question asked was if one could see MBeans in VisualVM as can be done in JConsole. As I've blogged on, there is a VisualVM plug-in for doing just that.
Although I felt somewhat comfortable with the Oracle HotSpot JDK command line tools, I was unfamiliar with jcmd and appreciated Larsen's coverage of it. I learned some other things along the way as well. My only complaint is that Larsen's presentation (especially the demonstration) was so rapid fire and so content-rich that I wish I could see it again.
A related (but older) presentation with some of the same content is available at http://www.oracle.com/javaone/lad-en/session-presentations/corejava/22260-enok-1439100.pdf
No comments:
Post a Comment