4 フライト・レコーダを使用したパフォーマンス問題のトラブルシューティング

Javaアプリケーションのパフォーマンスの問題を識別し、フライト・レコーダからの記録を使用してそれらの問題をデバッグします。

フライト・レコーダでの記録の作成についてさらに学習するには、「フライト記録の生成」を参照してください。

フライト・レコーダで提供されるデータは、パフォーマンス上の問題を調査する際に役立ちます。パフォーマンス・オーバーヘッドによって結果をゆがめることなく、これほど多くのプロファイリング・データを提供するツールは他にありません。この章では、フライト・レコーダからのデータを使用して識別およびデバッグできるパフォーマンスの問題について説明します。

この章の構成は、次のとおりです。

フライト・レコーダのオーバーヘッド

パフォーマンスを測定する場合は、フライト・レコーダによって追加されるパフォーマンス・オーバーヘッドを考慮することが重要です。オーバーヘッドは、アプリケーションによって異なります。パフォーマンス・テストがセット・アップされている場合は、アプリケーションに顕著なオーバーヘッドが存在するかどうかを測定できます。

デフォルトの設定を使用して標準の一定時間の記録(プロファイリング記録)を記録するためのオーバーヘッドは、ほとんどのアプリケーションで2%未満です。通常、標準の連続記録の実行では、測定可能なパフォーマンスへの影響はありません。

デフォルトで無効になっているヒープ統計イベントを使用すると、大幅なパフォーマンス・オーバーヘッドが発生する可能性があります。これは、ヒープ統計を有効にすると、テスト実行の開始時と終了時にOldガベージ・コレクションがトリガーされるためです。これらのOld GCは、アプリケーションに追加の休止時間を与えるので、遅延を測定している場合または休止時間の影響を受けやすい環境では、ヒープ統計を有効にして実行しないでください。メモリー・リークをデバッグするとき、またはアプリケーションのライブ・セットを調査するとき、ヒープ統計は便利です。詳細は、JDK Mission Controlを使用したメモリー・リークのデバッグを参照してください。

ノート:

パフォーマンスのプロファイリングのユース・ケースでは、ヒープ統計は必要でない場合があります。

JDK Mission Controlを使用したボトルネックの検出

JMCを使用して、アプリケーションのボトルネックを検出できます。

アプリケーションのボトルネックを検出する方法の1つは、「自動分析結果」ページを分析することです。このページには、フライト記録データの包括的な自動分析が表示されます。

「Javaアプリケーション」ページの「スレッド」ページを開きます。「スレッド」ページには、次の情報が表示されます:
  • アプリケーションによる時間経過に伴うライブ・スレッド使用率をプロットするグラフ。
  • アプリケーションで使用されるすべてのライブ・スレッドの表。
  • 選択したスレッドのスタック・トレース

次に、スレッドの詳細を含むグラフを表示する記録のサンプル図を示します。

図4-1 ボトルネック-スレッド-グラフ

図4-1の説明が続きます
「図4-1 ボトルネック-スレッド-グラフ」の説明

グラフでは、各行はスレッドであり、各スレッドは複数の行を持つことができます。この図では、各スレッドは、この記録のために有効にされたJavaアプリケーション・イベントを表す行を持ちます。選択されたJavaアプリケーションのイベントはすべて、スレッド・ストール・イベントであるという重要なプロパティを持ちます。スレッド・ストールは、スレッドがイベント中にアプリケーションを実行していなかったことを示し、これらはすべて期間イベントです。期間イベントは、アプリケーションが実行されていなかった時間を測定します。

このグラフでは、各色は異なるタイプのイベントを表します。たとえば:

  • 黄色は、Java Monitor Waitイベントを表します。黄色い部分は、スレッドがオブジェクトを待機しているときです。これは多くの場合、スレッドがタスクを待機して、アイドル状態であることを意味します。
  • サーモンは、Java Monitor Blockedイベントまたは同期イベントを表します。Javaアプリケーションの重要なスレッドがブロックされた状態で多くの時間を費やしている場合は、アプリケーションの重要なセクションがシングル・スレッドであり、それがボトルネックであることを意味しています。
  • は、ソケット読取りおよびソケット書込みイベントを表します。再び、Javaアプリケーションがソケットを待機している時間が多い場合、主なボトルネックは、ネットワーク内またはアプリケーションが通信する他のマシンにある可能性があります。
  • は、イベントがない部分を表します。この部分は、スレッドがスリープ中、待機中、ソケットの読取り中ではなく、ブロックもされていないことを意味します。通常、ここはアプリケーション・コードが実行される場所です。Javaアプリケーションの重要なスレッドがアプリケーション・イベントを生成せずに多くの時間を費やしている場合、アプリケーションのボトルネックは、コードの実行に費やした時間、またはCPU自体です。

ノート:

ほとんどのJavaアプリケーション・イベント・タイプについて、20ミリ秒より長いイベントのみが記録されます。(このしきい値は、フライト記録を開始するときに変更できます。)アプリケーションがファイルへの書込み(一度に一部分のみ)などの短いタスクを多数実行しているか、非常に短時間の同期に時間を費やしているので、領域には記録されたイベントがない可能性があります。

「自動分析結果」ページには、ガベージ・コレクションに関する情報も表示されます。ガベージ・コレクションがボトルネックである可能性があるかどうかを確認するには、ガベージ・コレクションのパフォーマンスに関する次のトピックを参照してください。

JDK Mission Controlを使用したガベージ・コレクションの問題のデバッグ

JMCを使用してガベージ・コレクション(GC)の問題をデバッグできます。

HotSpotガベージ・コレクタをチューニングすると、パフォーマンスに大きな影響を与える可能性があります。概要は、ガベージ・コレクション・チューニング・ガイド を参照してください。

実行中のアプリケーションのプロファイリング・フライト記録を取得します。ヒープ統計を含めると、追加のOldガベージ・コレクションがトリガーされるので、ヒープ統計を含めないでください。良いサンプルを得るには、より長い記録を取ります(たとえば1時間)。

JMCで記録を開きます。「自動分析結果」ページの「ガベージ・コレクション」セクションを確認します。次に、実行時のガベージ・コレクション・パフォーマンスのスナップショットを提供する記録のサンプル図を示します。

図4-2 自動分析結果-ガベージ・コレクション

図4-2の説明が続きます
「図4-2自動分析結果-ガベージ・コレクション」の説明

図から、フルGCイベントがあることがわかります。これは、アプリケーションに割り当てたメモリーよりも多くのメモリーが必要であることを示しています。

さらに分析するには、「JVM内部」ページの「ガベージ・コレクション」ページを開き、GCの全体的なパフォーマンスへの影響を調査します。次に、GCの一時休止を含むグラフを表示する記録のサンプル図を示します。

図4-3 ガベージ・コレクションのパフォーマンス - GCの一時休止

図4-3の説明が続きます
「図4-3 ガベージ・コレクションのパフォーマンス - GCの一時休止」の説明

グラフから、記録からの休止の合計を確認します。「休止の合計」は、GC中にアプリケーションが一時休止した時間の合計です。多くのGCは、バックグラウンドでほとんどの処理を行います。この場合、GCの長さは重要ではなく、アプリケーションが実際に停止していた時間が重要です。したがって、「休止の合計は、GCの影響を適切に測定します。

ガベージ・コレクションの主なパフォーマンスの問題は、通常、個々のGCの時間がかかりすぎるか、GCの一時休止(GCの一時休止の合計)に多くの時間を費やしているかのいずれかです。

個々のGCに時間がかかりすぎる場合は、GCの戦略を変更する必要があります。一時休止の回数とスループット・パフォーマンスの対比となると、各GCには異なるトレードオフがあります。動作ベースのチューニングに関する項を参照してください。

また、ファイナライザや準参照の使用が少なくなるよう、アプリケーションの修正が必要になる場合もあります。ファイナライズの検出とファイナライズからの移行の詳細は、『Java Platform, Standard Edition HotSpot仮想マシン・ガベージ・コレクション・チューニング・ガイド』「ファイナライズを保留中のオブジェクトのモニター」および「ファイナライズと弱参照、ソフト参照およびファントム参照」を参照してください。

アプリケーションの一時停止に時間がかかりすぎる場合は、様々な方法でこれを解決できます。1つの方法は、Javaヒープ・サイズを増加することです。「GC構成」ページを見て、アプリケーションで使用されるヒープ・サイズを推定し、初期ヒープ・サイズおよび最大ヒープ・サイズをより高い値に変更します。ヒープが大きいほど、GC間の時間は長くなります。Javaアプリケーションにメモリー・リークがあると、GCがより頻繁になり、最後にはOutOfMemoryErrorがスローされる可能性があるので、注意が必要です。詳細は、JDK Mission Controlを使用したメモリー・リークのデバッグを参照してください。GCサイクルを減らすもう1つの方法は、割り当てる一時オブジェクトを減らすことです。「TLAB割当て」ページで、記録の過程で割り当てられているメモリー量を見てください。小さなオブジェクトは「TLAB」内に割り当てられ、大きなオブジェクトは「TLAB」外に割り当てられています。多くの場合、割当ての大半は「TLAB」内で起こります。最後に、必要なGCを減らすために割当て率を減らします。「TLAB割当て」ページを選択し、メモリー不足が最も多い割当てサイトを確認します。クラスまたはスレッドごとに表示して、最も多くの割当てを消費しているものを確認できます。

これ以外のいくつかの設定により、JavaアプリケーションのGCのパフォーマンスが向上することもあります。GCパフォーマンスの詳細は、『Java Platform, Standard Edition HotSpot仮想マシン・ガベージ・コレクション・チューニング・ガイド 』ガベージ・コレクション・チューニング・ガイドに関する項を参照してください。

JDK Mission Controlを使用した同期の問題のデバッグ

JMCを使用して、Javaアプリケーションの同期の問題をデバッグできます。

JMCでフライト記録を開き、「自動分析の結果」ページを確認します。次に、ロック時にブロックされるスレッドを示す記録のサンプル図を示します。

図4-4 同期の問題-「自動分析の結果」ページ

図4-4の説明が続きます
「図4-4同期の問題-「自動分析の結果」ページ」の説明

赤で強調表示されたページの「ロック・インスタンス」セクションに焦点を合わせます。これは潜在的な問題を示します。ロック時にブロックされているスレッドがあることがわかります。

さらに分析するには、「ロック・インスタンス」ページを開きます。次の記録のサンプル図は、ロック時にブロックされるスレッドと、ロックの取得を待機しているスレッドのスタック・トレースを示しています。

図4-5 同期の問題-ロック・インスタンス

図4-5の説明が続きます
「図4-5 同期の問題-ロック・インスタンス」の説明

アプリケーション内のスレッドがロック時に合計3時間ブロックされたことがわかります。競合における最も一般的なモニター・クラスはLoggerで、2972回ブロックされました。

通常、ロギングは、アプリケーションのボトルネックとなる可能性がある領域です。このシナリオでは、ブロッキング・イベントはすべてログ・メソッドのコールによるものと考えられます。この問題を修正するには、コードを確認して必要な変更を加えることができます。

JDK Mission Controlを使用したI/Oの問題のデバッグ

JMCのソケットI/OページまたはファイルI/Oページをモニターすることで、アプリケーションのI/Oの問題を診断できます。

Javaアプリケーションがソケット読取りソケット書込みファイルの読込みまたはファイル書込みに多くの時間を費やしている場合は、I/Oまたはネットワークがボトルネックを引き起こしている可能性があります。アプリケーションのI/Oの問題を診断するには、「自動分析の結果」ページの「Javaアプリケーション」ページの下にある「ソケットI/O」ページを開きます。次に、ソケットI/Oの詳細を示す記録のサンプル図を示します。

図4-6 ソケットI/O - Javaアプリケーション

図4-6の説明が続きます
「図4-6 ソケットI/O - Javaアプリケーション」の説明

この図は、アプリケーションで記録された最長のソケット書込みが、ホストへの81 Bの書込みに349.745ミリ秒かかったことを示しています。

ファイルまたはネットワークI/Oの問題も同様の方法で診断します。読取り/書込みの最も多いファイルを調べ、各ファイルの読取り/書込みとI/Oにかかった時間を確認します。

デフォルトでは、「ソケットI/O」ページには期間が10ミリ秒を超えるイベントがリストされます。フライト記録の開始時に、「ファイルI/Oしきい値」または「ソケットI/Oしきい値」を下げると、より多くのデータを収集できますが、パフォーマンスのオーバーヘッドが高くなる可能性があります。

JDK Mission Controlを使用したコード実行パフォーマンスのモニター

JMCを使用して、コード実行パフォーマンスをモニターできます。

Javaアプリケーションのイベントが多くない場合、アプリケーションの主なボトルネックは、実行中のコードである可能性があります。このようなシナリオでは、「自動分析結果」ページの「メソッド・プロファイリング」セクションを参照してください。次に、特定のメソッドの最適化が必要であることを示す記録のサンプル図を示します。

図4-7 コード実行パフォーマンス-「自動分析の結果」ページ

図4-7の説明が続きます
「図4-7 コード実行パフォーマンス-「自動分析結果」ページ」の説明

「Javaアプリケーション」ページを開きます。次に、「メソッド・プロファイリング」グラフとスタック・トレースを示す記録のサンプル図を示します。

図4-8 コード実行パフォーマンス- Javaアプリケーション

図4-8の説明が続きます
「図4-8 コード実行パフォーマンス- Javaアプリケーション」の説明

「スタック・トレース」ビューには、エディタでの選択内容の集約スタック・トレースおよびプロファイリング・サンプルのスタック・トレースも表示されます。この図では、これらのメソッドのいずれかに他のメソッドよりも多くのサンプルがあることがわかります。これは、JVMが他のメソッドよりもそのメソッドの実行に費やした時間が多いことを意味します。

アプリケーションのパフォーマンスを向上させるために最適化するメソッドを識別するには、「メソッド・プロファイリング」ページを開きます。次に、最適化する必要があるメソッドを示す記録のサンプル図を示します。

図4-9 コード実行パフォーマンス-メソッド・プロファイリング

図4-9の説明が続きます
「図4-9 コード実行パフォーマンス-メソッド・プロファイリング」の説明

このように、スタック・トレース・ビューでは、最もサンプリングされたメソッドは HolderOfUniqueValues.countIntersection()でした。アプリケーションのパフォーマンスを効果的に向上させるために、このメソッドを最適化するためのコードをレビューして必要な変更を加えることができます。