実行中のJVMの診断

投稿日: 2022-10-23 2022-10-23
タグ: Java, JVM

1. 概要

Java仮想マシン（JVM）は、コンピューターがJavaプログラムを実行できるようにする仮想マシンです。この記事では、実行中のJVMを簡単に診断する方法を説明します。

JDK自体には多くのツールがあり、さまざまな開発、監視、およびトラブルシューティングのアクティビティに使用できます。 jcmd を見てみましょう。これは非常に使いやすく、実行中のJVMに関するさまざまな情報を提供できます。 さらに、jcmdは、パフォーマンスのオーバーヘッドがないか最小限の拡張JVM診断にJDK7以降で推奨されるツールです。

2. jcmd とは何ですか？

これは、実行中のJVMに診断コマンド要求を送信するユーティリティです。 ただし、JVMが実行されているのと同じマシンで使用する必要があります。詳細については、ドキュメントを参照してください。

サーバー上で実行されているサンプルJavaアプリケーションでこのユーティリティを使用する方法を見てみましょう。

3. jcmd の使い方は？

SpringInitializrとJDK11を使用して、簡単なデモWebアプリケーションを作成しましょう。それでは、サーバーを起動し、jcmdを使用して診断してみましょう。

3.1. PIDの取得

各プロセスには、PIDと呼ばれるプロセスIDが関連付けられていることがわかっています。したがって、アプリケーションに関連付けられた PID を取得するには、 jcmd を使用して、該当するすべてのJavaプロセスを次のように一覧表示します。

root@c6b47b129071:/# jcmd
65 jdk.jcmd/sun.tools.jcmd.JCmd
18 /home/pgm/demo-0.0.1-SNAPSHOT.jar
root@c6b47b129071:/#

ここでは、実行中のアプリケーションのPIDが18であることがわかります。

3.2. 可能なjcmd使用法のリストを取得する

jcmd PID helpコマンドで使用できるオプションを見つけてみましょう。

root@c6b47b129071:/# jcmd 18 help
18:
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

使用可能な診断コマンドは、HotSpotVMのバージョンによって異なる場合があります。

4. jcmdコマンド

実行中のJVMを診断するための最も便利なjcmdコマンドオプションのいくつかを調べてみましょう。

4.1. VM.version

これは、以下に示すように、JVMの基本的な詳細を取得するためのものです。

root@c6b47b129071:/# jcmd 18 VM.version
18:
OpenJDK 64-Bit Server VM version 11.0.11+9-Ubuntu-0ubuntu2.20.04
JDK 11.0.11
root@c6b47b129071:/#

ここでは、サンプルアプリケーションにOpenJDK11を使用していることがわかります。

4.2. VM.system_properties

これにより、VMに設定されているすべてのシステムプロパティが出力されます。数百行の情報が表示される場合があります。

root@c6b47b129071:/# jcmd 18 VM.system_properties
18:
#Thu Jul 22 10:56:13 IST 2021
awt.toolkit=sun.awt.X11.XToolkit
java.specification.version=11
sun.cpu.isalist=
sun.jnu.encoding=ANSI_X3.4-1968
java.class.path=/home/pgm/demo-0.0.1-SNAPSHOT.jar
java.vm.vendor=Ubuntu
sun.arch.data.model=64
catalina.useNaming=false
java.vendor.url=https\://ubuntu.com/
user.timezone=Asia/Kolkata
java.vm.specification.version=11
...

4.3. VM.flags

サンプルアプリケーションの場合、これにより、使用されたすべてのVM引数が出力されます。これは、私たちが指定したものか、JVMがデフォルトで使用したものです。ここで、以下のようにさまざまなデフォルトのVM引数に気付くことができます。

root@c6b47b129071:/# jcmd 18 VM.flags            
18:
-XX:CICompilerCount=3 -XX:CompressedClassSpaceSize=260046848 -XX:ConcGCThreads=1 -XX:G1ConcRefinementThreads=4 -XX:G1HeapRegionSize=1048576 -XX:GCDrainStackTargetSize=64 -XX:InitialHeapSize=536870912 -XX:MarkStackSize=4194304 -XX:MaxHeapSize=536870912 -XX:MaxMetaspaceSize=268435456 -XX:MaxNewSize=321912832 -XX:MinHeapDeltaBytes=1048576 -XX:NonNMethodCodeHeapSize=5830732 -XX:NonProfiledCodeHeapSize=122913754 -XX:ProfiledCodeHeapSize=122913754 -XX:ReservedCodeCacheSize=251658240 -XX:+SegmentedCodeCache -XX:ThreadStackSize=256 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseG1GC 
root@c6b47b129071:/#

同様に、 VM.command_line 、 VM.uptime 、 VM.dynlibs、などの他のコマンドも、使用される他のさまざまなプロパティに関する他の基本的で有用な詳細を提供します。

上記のコマンドはすべて、主にさまざまなJVM関連の詳細を取得するためのものです。次に、JVMに関連するトラブルシューティングに役立ついくつかのコマンドを調べてみましょう。

4.4. Thread.print

このコマンドは、インスタントスレッドダンプを取得するためのものです。したがって、実行中のすべてのスレッドのスタックトレースが出力されます。以下はそれを使用する方法であり、使用中のスレッドの数に応じて長い出力を与える可能性があります。

root@c6b47b129071:/# jcmd 18 Thread.print
18:
2021-07-22 10:58:08
Full thread dump OpenJDK 64-Bit Server VM (11.0.11+9-Ubuntu-0ubuntu2.20.04 mixed mode, sharing):

Threads class SMR info:
_java_thread_list=0x00007f21cc0028d0, length=25, elements={
0x00007f2210244800, 0x00007f2210246800, 0x00007f221024b800, 0x00007f221024d800,
0x00007f221024f800, 0x00007f2210251800, 0x00007f2210253800, 0x00007f22102ae800,
0x00007f22114ef000, 0x00007f21a44ce000, 0x00007f22114e3800, 0x00007f221159d000,
0x00007f22113ce800, 0x00007f2210e78800, 0x00007f2210e7a000, 0x00007f2210f20800,
0x00007f2210f22800, 0x00007f2210f24800, 0x00007f2211065000, 0x00007f2211067000,
0x00007f2211069000, 0x00007f22110d7800, 0x00007f221122f800, 0x00007f2210016000,
0x00007f21cc001000
}

"Reference Handler" #2 daemon prio=10 os_prio=0 cpu=2.32ms elapsed=874.34s tid=0x00007f2210244800 nid=0x1a waiting on condition  [0x00007f221452a000]
   java.lang.Thread.State: RUNNABLE
	at java.lang.ref.Reference.waitForReferencePendingList([email protected]/Native Method)
	at java.lang.ref.Reference.processPendingReferences([email protected]/Reference.java:241)
	at java.lang.ref.Reference$ReferenceHandler.run([email protected]/Reference.java:213)

"Finalizer" #3 daemon prio=8 os_prio=0 cpu=0.32ms elapsed=874.34s tid=0x00007f2210246800 nid=0x1b in Object.wait()  [0x00007f22144e9000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait([email protected]/Native Method)
	- waiting on <0x00000000f7330898> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove([email protected]/ReferenceQueue.java:155)
	- waiting to re-lock in wait() <0x00000000f7330898> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove([email protected]/ReferenceQueue.java:176)
	at java.lang.ref.Finalizer$FinalizerThread.run([email protected]/Finalizer.java:170)

"Signal Dispatcher" #4 daemon prio=9 os_prio=0 cpu=0.40ms elapsed=874.33s tid=0x00007f221024b800 nid=0x1c runnable  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

他のオプションを使用したスレッドダンプのキャプチャに関する詳細な説明は、ここにあります。

4.5. GC.class_histogram

ヒープの使用に関する重要な情報を提供する別のjcmdコマンドを使用してみましょう。さらに、これにより、多くのインスタンスを持つすべてのクラス（外部またはアプリケーション固有）が一覧表示されます。繰り返しますが、使用中のクラスの数に応じて、リストは数百行になる場合があります。

root@c6b47b129071:/# jcmd 18 GC.class_histogram
18:
 num     #instances         #bytes  class name (module)
-------------------------------------------------------
   1:         41457        2466648  [B ([email protected])
   2:         38656         927744  java.lang.String ([email protected])
   3:          6489         769520  java.lang.Class ([email protected])
   4:         21497         687904  java.util.concurrent.ConcurrentHashMap$Node ([email protected])
   5:          6570         578160  java.lang.reflect.Method ([email protected])
   6:          6384         360688  [Ljava.lang.Object; ([email protected])
   7:          9668         309376  java.util.HashMap$Node ([email protected])
   8:          7101         284040  java.util.LinkedHashMap$Entry ([email protected])
   9:          3033         283008  [Ljava.util.HashMap$Node; ([email protected])
  10:          2919         257000  [I ([email protected])
  11:           212         236096  [Ljava.util.concurrent.ConcurrentHashMap$Node; ([email protected])

ただし、これで明確な画像が得られない場合は、ヒープダンプを取得できます。次に見てみましょう。

4.6. GC.heap_dump

このコマンドは、インスタントJVMヒープダンプを提供します。したがって、ヒープダンプをファイルに抽出して、後で分析することができます。

root@c6b47b129071:/# jcmd 18 GC.heap_dump ./demo_heap_dump
18:
Heap dump file created
root@c6b47b129071:/#

ここで、demo_heap_dumpはヒープダンプファイル名です。さらに、これはアプリケーションjarが配置されているのと同じ場所に作成されます。

4.7. JFRコマンドオプション

以前の記事では、JFRとJMCを使用したJavaアプリケーションの監視について説明しました。次に、アプリケーションのパフォーマンスの問題を分析するために使用できるjcmdコマンドを調べてみましょう。

JFR（またはJava Flight Recorder）は、JDKに組み込まれているプロファイリングおよびイベント収集フレームワークです。 JFR を使用すると、JVMおよびJavaアプリケーションの動作に関する詳細な低レベルの情報を収集できます。さらに、 JMC を使用して、JFRによって収集されたデータを視覚化できます。したがって、JFRとJMCは一緒になって完全なツールチェーンを作成し、低レベルで詳細なランタイム情報を継続的に収集します。

JMC の使用方法はこの記事の範囲外ですが、jcmdを使用してJFRファイルを作成する方法を説明します。 JFRは商用機能です。したがって、デフォルトでは無効になっています。ただし、これは「 jcmdPIDVM.unlock_commercial_features」を使用して有効にできます。

ただし、記事にはOpenJDKを使用しました。したがって、JFRが有効になります。次に、次のようにjcmdコマンドを使用してJFRファイルを生成しましょう。

root@c6b47b129071:/# jcmd 18 JFR.start name=demo_recording settings=profile delay=10s duration=20s filename=./demorecording.jfr
18:
Recording 1 scheduled to start in 10 s. The result will be written to:

/demorecording.jfr
root@c6b47b129071:/# jcmd 18 JFR.check
18:
Recording 1: name=demo_recording duration=20s (delayed)
root@c6b47b129071:/# jcmd 18 JFR.check
18:
Recording 1: name=demo_recording duration=20s (running)
root@c6b47b129071:/# jcmd 18 JFR.check
18:
Recording 1: name=demo_recording duration=20s (stopped)

jarアプリケーションが配置されているのと同じ場所にサンプルJFR記録ファイル名demorecording.jfrを作成しました。さらに、この記録は20秒で、要件に従って構成されます。

また、 JFR.check コマンドを使用して、JFRの記録状況を確認することができます。また、 JFR.stop コマンドを使用して、記録を即座に停止および破棄できます。一方、 JFR.dump コマンドを使用すると、記録を即座に停止してダンプできます。

4.8. VM.native_memory

これは、JVM上のヒープおよび非ヒープメモリに関する多くの有用な詳細を提供できる最高のコマンドの1つです。したがって、これを使用してメモリ使用量を調整し、メモリリークを検出できます。ご存知のように、JVMメモリはヒープメモリと非ヒープメモリに大別できます。また、完全なJVMメモリ使用量の詳細を取得するには、このユーティリティを使用できます。さらに、これはコンテナベースのアプリケーションのメモリサイズを定義するのに役立ちます。

この機能を使用するには、追加のVM引数を使用してアプリケーションを再起動する必要があります。 – XX：NativeMemoryTracking = summaryまたは-XX：NativeMemoryTracking =detail。 NMTを有効にすると、5％〜10％のパフォーマンスオーバーヘッドが発生することに注意してください。

これにより、診断する新しいPIDが得られます。

root@c6b47b129071:/# jcmd 19 VM.native_memory
19:

Native Memory Tracking:

Total: reserved=1159598KB, committed=657786KB
-                 Java Heap (reserved=524288KB, committed=524288KB)
                            (mmap: reserved=524288KB, committed=524288KB) 
 
-                     Class (reserved=279652KB, committed=29460KB)
                            (classes #6425)
                            (  instance classes #5960, array classes #465)
                            (malloc=1124KB #15883) 
                            (mmap: reserved=278528KB, committed=28336KB) 
                            (  Metadata:   )
                            (    reserved=24576KB, committed=24496KB)
                            (    used=23824KB)
                            (    free=672KB)
                            (    waste=0KB =0.00%)
                            (  Class space:)
                            (    reserved=253952KB, committed=3840KB)
                            (    used=3370KB)
                            (    free=470KB)
                            (    waste=0KB =0.00%)
 
-                    Thread (reserved=18439KB, committed=2699KB)
                            (thread #35)
                            (stack: reserved=18276KB, committed=2536KB)
                            (malloc=123KB #212) 
                            (arena=39KB #68)
 
-                      Code (reserved=248370KB, committed=12490KB)
                            (malloc=682KB #3839) 
                            (mmap: reserved=247688KB, committed=11808KB) 
 
-                        GC (reserved=62483KB, committed=62483KB)
                            (malloc=10187KB #7071) 
                            (mmap: reserved=52296KB, committed=52296KB) 
 
-                  Compiler (reserved=146KB, committed=146KB)
                            (malloc=13KB #307) 
                            (arena=133KB #5)
 
-                  Internal (reserved=460KB, committed=460KB)
                            (malloc=428KB #1421) 
                            (mmap: reserved=32KB, committed=32KB) 
 
-                     Other (reserved=16KB, committed=16KB)
                            (malloc=16KB #3) 
 
-                    Symbol (reserved=6593KB, committed=6593KB)
                            (malloc=6042KB #72520) 
                            (arena=552KB #1)
 
-    Native Memory Tracking (reserved=1646KB, committed=1646KB)
                            (malloc=9KB #113) 
                            (tracking overhead=1637KB)
 
-        Shared class space (reserved=17036KB, committed=17036KB)
                            (mmap: reserved=17036KB, committed=17036KB) 
 
-               Arena Chunk (reserved=185KB, committed=185KB)
                            (malloc=185KB) 
 
-                   Logging (reserved=4KB, committed=4KB)
                            (malloc=4KB #191) 
 
-                 Arguments (reserved=18KB, committed=18KB)
                            (malloc=18KB #489) 
 
-                    Module (reserved=124KB, committed=124KB)
                            (malloc=124KB #1521) 
 
-              Synchronizer (reserved=129KB, committed=129KB)
                            (malloc=129KB #1089) 
 
-                 Safepoint (reserved=8KB, committed=8KB)
                            (mmap: reserved=8KB, committed=8KB)

ここでは、 Javaヒープメモリ以外のさまざまなメモリタイプの詳細を確認できます。 クラスは、クラスメタデータの格納に使用されるJVMメモリを定義します。同様に、 Thread は、アプリケーションスレッドが使用しているメモリを定義します。また、コードは、 JIT- で生成されたコードを格納するために使用されるメモリを提供し、コンパイラ自体にはある程度のスペース使用量があり、GCは一部を占有しますスペースも。

さらに、 reserved は、アプリケーションに必要なメモリの見積もりを提供します。また、 commitd は、割り当てられた最小メモリを示します。

5. メモリリークを診断する

JVMにメモリリークがあるかどうかを特定する方法を見てみましょう。したがって、最初に、最初にベースラインを用意する必要があります。次に、上記のメモリタイプのいずれかでメモリが一貫して増加しているかどうかを理解するために、しばらく監視する必要があります。

まず、JVMのメモリ使用量を次のようにベースラインしましょう。

root@c6b47b129071:/# jcmd 19 VM.native_memory baseline
19:
Baseline succeeded

ここで、しばらくの間、通常または頻繁に使用するアプリケーションを使用します。最後に、 diff を使用して、ベースライン以降の変更を次のように識別します。

root@c6b47b129071:/# jcmd 19 VM.native_memory summary.diff
19:

Native Memory Tracking:

Total: reserved=1162150KB +2540KB, committed=660930KB +3068KB

-                 Java Heap (reserved=524288KB, committed=524288KB)
                            (mmap: reserved=524288KB, committed=524288KB)
 
-                     Class (reserved=281737KB +2085KB, committed=31801KB +2341KB)
                            (classes #6821 +395)
                            (  instance classes #6315 +355, array classes #506 +40)
                            (malloc=1161KB +37KB #16648 +750)
                            (mmap: reserved=280576KB +2048KB, committed=30640KB +2304KB)
                            (  Metadata:   )
                            (    reserved=26624KB +2048KB, committed=26544KB +2048KB)
                            (    used=25790KB +1947KB)
                            (    free=754KB +101KB)
                            (    waste=0KB =0.00%)
                            (  Class space:)
                            (    reserved=253952KB, committed=4096KB +256KB)
                            (    used=3615KB +245KB)
                            (    free=481KB +11KB)
                            (    waste=0KB =0.00%)
 
-                    Thread (reserved=18439KB, committed=2779KB +80KB)
                            (thread #35)
                            (stack: reserved=18276KB, committed=2616KB +80KB)
                            (malloc=123KB #212)
                            (arena=39KB #68)
 
-                      Code (reserved=248396KB +21KB, committed=12772KB +213KB)
                            (malloc=708KB +21KB #3979 +110)
                            (mmap: reserved=247688KB, committed=12064KB +192KB)
 
-                        GC (reserved=62501KB +16KB, committed=62501KB +16KB)
                            (malloc=10205KB +16KB #7256 +146)
                            (mmap: reserved=52296KB, committed=52296KB)
 
-                  Compiler (reserved=161KB +15KB, committed=161KB +15KB)
                            (malloc=29KB +15KB #341 +34)
                            (arena=133KB #5)
 
-                  Internal (reserved=495KB +35KB, committed=495KB +35KB)
                            (malloc=463KB +35KB #1429 +8)
                            (mmap: reserved=32KB, committed=32KB)
 
-                     Other (reserved=52KB +36KB, committed=52KB +36KB)
                            (malloc=52KB +36KB #9 +6)
 
-                    Symbol (reserved=6846KB +252KB, committed=6846KB +252KB)
                            (malloc=6294KB +252KB #76359 +3839)
                            (arena=552KB #1)
 
-    Native Memory Tracking (reserved=1727KB +77KB, committed=1727KB +77KB)
                            (malloc=11KB #150 +2)
                            (tracking overhead=1716KB +77KB)
 
-        Shared class space (reserved=17036KB, committed=17036KB)
                            (mmap: reserved=17036KB, committed=17036KB)
 
-               Arena Chunk (reserved=186KB, committed=186KB)
                            (malloc=186KB)
 
-                   Logging (reserved=4KB, committed=4KB)
                            (malloc=4KB #191)
 
-                 Arguments (reserved=18KB, committed=18KB)
                            (malloc=18KB #489)
 
-                    Module (reserved=124KB, committed=124KB)
                            (malloc=124KB #1528 +7)
 
-              Synchronizer (reserved=132KB +3KB, committed=132KB +3KB)
                            (malloc=132KB +3KB #1111 +22)
 
-                 Safepoint (reserved=8KB, committed=8KB)
                            (mmap: reserved=8KB, committed=8KB)

GCが機能するにつれて、メモリ使用量の増減に気付くでしょう。ただし、メモリ使用量が制御不能に増加している場合は、メモリリークの問題である可能性があります。したがって、これらの統計から、ヒープ、スレッド、コード、クラス、などのメモリリーク領域を特定できます。また、アプリケーションでより多くのメモリが必要な場合は、対応するVM引数をそれぞれ調整できます。

メモリリークがHeapにある場合は、ヒープダンプを取得するか（前に説明したように）、Xmxを調整することができます。同様に、メモリリークがスレッドにある場合、we は未処理の再帰命令を探すか、Xssを調整できます。

6. 結論

この記事では、さまざまなシナリオでJVMを診断するためのユーティリティについて説明しました。

また、 jcmd コマンドと、さまざまなパフォーマンス関連の分析のためにヒープダンプ、スレッドダンプ、JFR記録を取得するためのさまざまな使用法についても説明しました。最後に、jcmdを使用してメモリリークを診断する方法も検討しました。

getdocs

13036