jcmdを使ってみよう

みなさんjstackでスタックトレースを出力したり、jmapでヒープダンプを取得したことがあると思います。

でも最近（？）はjcmdだけでどちらも賄えます。

まずjcmdを引数なしで実行してみましょう。

$ jcmd
62818 com.example.demo.DemoApplication
62819 jdk.jcmd/sun.tools.jcmd.JCmd
62810 org.apache.maven.wrapper.MavenWrapperMain spring-boot:run

このようにマシン上で動いているJavaアプリケーションのPIDとメインクラスが一覧されます。

次にjcmdにPIDを渡してみましょう。ここではDemoApplicationのPIDを渡してみます。

$ jcmd 62818
62818:
The following commands are available:
Compiler.CodeHeap_Analytics
Compiler.codecache
Compiler.codelist
Compiler.directives_add
Compiler.directives_clear
Compiler.directives_print
Compiler.directives_remove
Compiler.queue
GC.class_histogram
GC.class_stats
GC.finalizer_info
GC.heap_dump
GC.heap_info
GC.run
GC.run_finalization
JFR.check
JFR.configure
JFR.dump
JFR.start
JFR.stop
JVMTI.agent_load
JVMTI.data_dump
ManagementAgent.start
ManagementAgent.start_local
ManagementAgent.status
ManagementAgent.stop
Thread.print
VM.class_hierarchy
VM.classloader_stats
VM.classloaders
VM.command_line
VM.dynlibs
VM.flags
VM.info
VM.log
VM.metaspace
VM.native_memory
VM.print_touched_methods
VM.set_flag
VM.stringtable
VM.symboltable
VM.system_properties
VM.systemdictionary
VM.uptime
VM.version
help

For more information about a specific command use 'help <command>'.

このように、このプロセスに対して使用できるコマンドが一覧されます。

スタックトレースを出力してみましょう。

$ jcmd 62818 Thread.print
62818:
2019-12-04 08:49:43
Full thread dump OpenJDK 64-Bit Server VM (11.0.2+9 mixed mode):

（中略）

"Common-Cleaner" #11 daemon prio=8 os_prio=31 cpu=1.60ms elapsed=263.23s tid=0x00007f8650010800 nid=0x5c03 in Object.wait()  [0x000070000b852000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(java.base@11.0.2/Native Method)
    - waiting on <0x000000060003bee0> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(java.base@11.0.2/ReferenceQueue.java:155)
    - waiting to re-lock in wait() <0x000000060003bee0> (a java.lang.ref.ReferenceQueue$Lock)
    at jdk.internal.ref.CleanerImpl.run(java.base@11.0.2/CleanerImpl.java:148)
    at java.lang.Thread.run(java.base@11.0.2/Thread.java:834)
    at jdk.internal.misc.InnocuousThread.run(java.base@11.0.2/InnocuousThread.java:134)

"Catalina-utility-1" #15 prio=1 os_prio=31 cpu=36.80ms elapsed=257.29s tid=0x00007f864802a800 nid=0x7003 waiting on condition  [0x000070000c77f000]
   java.lang.Thread.State: WAITING (parking)
    at jdk.internal.misc.Unsafe.park(java.base@11.0.2/Native Method)
    - parking to wait for  <0x000000061c615798> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(java.base@11.0.2/LockSupport.java:194)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.2/AbstractQueuedSynchronizer.java:2081)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.2/ScheduledThreadPoolExecutor.java:1177)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(java.base@11.0.2/ScheduledThreadPoolExecutor.java:899)
    at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@11.0.2/ThreadPoolExecutor.java:1054)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.2/ThreadPoolExecutor.java:1114)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.2/ThreadPoolExecutor.java:628)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(java.base@11.0.2/Thread.java:834)

（以下略）

ヒープダンプを取得してみましょう。

$ ls
$ jcmd 62818 GC.heap_dump `pwd`/demo.hprof
62818:
Heap dump file created
$ ls
demo.hprof

こんな感じでjstackやjmapといった複数のコマンドを覚えておかなくてもjcmdだけ覚えておけば良いので楽ですね。