jstat徹底解説: JVMのログを読み解く

ソフトウェアテスト
スポンサーリンク
google.com, pub-5238665064291805, DIRECT, f08c47fec0942fa0

はじめに

Javaアプリケーションの性能試験では、JVM(Java Virtual Machine、Javaプログラムを実行する仮想環境)の動作を確認することが重要である。この目的でjstatが役立つ。jstatはJDK(Java Development Kit)に含まれるツールで、メモリ使用量やガベージコレクション(GC)の状況をリアルタイムに表示する。性能試験中に「メモリリークが疑われる」「GCが頻発して遅延が発生している」といった問題を特定するのに適している。本記事では、jstatの使用方法、ログの見方、解析例を解説し、性能試験時のログ分析に活用できるようになることが目的です。

基本コマンドと使い方

jstatを使用するには、監視対象のJavaプロセスのPID(プロセスID)が必要である。PIDはjpsコマンドで取得できる。jpsは実行中のJavaプロセスを一覧表示するツールである。PIDを確認後、以下のように実行する。

  • 基本構文: jstat [オプション] [間隔(ms)] [回数]
jstat -gc 12345 1000 10

→ PID 12345のGC状況を1秒間隔で10回表示。

  • 主要オプション:
  • -gc: メモリ領域の容量、使用量、GC回数を表示。
  • -gcutil: 使用率をパーセンテージで表示。
  • -gccapacity: メモリ領域の最大容量を示す。

例えば、`jstat -gcutil 12345 1s`を実行すると、1秒ごとに使用率が表示される。性能試験では、負荷をかけた状態でデータを収集すると効果的である。

ログの見方: 主要項目の解説

jstatの出力は、選択したオプションに応じて異なる統計を提供する。以下は`-gc`オプションの出力例とその意味である(Java SE 21仕様に基づく)。

jstat -gc 12345
S0C    S1C    EC      OC      MC     YGC  YGCT   FGC  FGCT   GCT
512.0  512.0  4096.0  8192.0  2048.0 10   0.150  2    0.300  0.450

  • メモリ領域の容量と使用量:
  • S0C, S1C: Survivor 0/1領域の現在の容量(KB)。Young世代の一部で、新規オブジェクトを格納する。
  • EC: Eden領域の容量(KB)。Young世代の主要なメモリプールである。
  • OC: Old世代の容量(KB)。長期間生存するオブジェクトが格納される。
  • MC: Metaspaceの容量(KB)。クラスメタデータが保存される。
    -gcutilではS0U, EU, OUで使用量が表示される。
  • ガベージコレクションの統計:
  • YGC: Young GCの回数。短期間のメモリ掃除を表す。
  • YGCT: Young GCの合計時間(秒)。
  • FGC: Full GCの回数。全体のメモリ掃除を指す。
  • FGCT: Full GCの合計時間(秒)。
  • GCT: 全GC時間(YGCT + FGCT)。

`-gcutil`の出力例:

jstat -gcutil 12345
S0     S1     E      O      M      YGC  YGCT   FGC  FGCT   GCT
0.00  50.00  80.00  95.00  60.00  10   0.150  2    0.300  0.450
  • `S0`, `S1`, `E`, `O`, `M`: それぞれSurvivor 0/1、Eden、Old、Metaspaceの使用率(%)。

ログを見ると、以下が確認できる。

  • FGCFGCTが多い場合、Old世代が満杯に近い可能性がある。
  • YGCが頻発し、YGCTが長い場合、Young世代のサイズが不適切かもしれない。
  • EUOUが容量に近づくと、メモリ不足が疑われる。
    補足: GCは不要なメモリを解放する仕組みであり、Full GCが多いと処理が一時停止して遅延が発生する。

実践例: ログから問題を特定する

性能試験中にWebアプリケーションのレスポンスが遅延したとする。jstat -gcの出力は以下の通りである。

jstat -gc 12345 1000 3
S0C    S1C    EC      OC      MC     YGC  YGCT   FGC  FGCT   GCT
512.0  512.0  4096.0  8192.0  2048.0 50   0.800  5    1.200  2.000
512.0  512.0  4096.0  8192.0  2048.0 52   0.820  6    1.500  2.320
512.0  512.0  4096.0  8192.0  2048.0 55   0.850  7    1.800  2.650

-gcutilの出力:

jstat -gcutil 12345
S0     S1     E      O      M      YGC  YGCT   FGC  FGCT   GCT
0.00  50.00  80.00  95.00  60.00  55   0.850  7    1.800  2.650

分析ステップ:

  1. O(Old)が95%に達し、FGCが7回、FGCTが1.8秒と長い。Old世代がほぼ満杯である。
  2. YGCが50から55に増加し、Eが80%。Young世代でも負荷が高い。
  3. Old世代の満杯状態がFull GCを誘発し、レスポンス遅延が発生したと推測される。

対処案:

  • -Xmxでヒープサイズを拡張(例: -Xmx16g)。
  • -XX:MaxMetaspaceSizeでMetaspaceの上限を調整(例: -XX:MaxMetaspaceSize=512m)。
  • メモリリークを疑い、プロファイラ(例: VisualVM)でオブジェクトの使用状況を調査。

まとめ

jstatを使うと、JVMのメモリとGCの状況から問題を特定できる。性能試験時のログ解析では、GC頻度やメモリ使用率の変化に注目するとよい。ただし、CPUやディスクI/Oはカバーしない。次回の記事では、mpstatによるCPU解析を解説する。

参考資料

コメント

タイトルとURLをコピーしました