みなさん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
だけ覚えておけば良いので楽ですね。