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

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

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

このグラフでは、各色は異なるタイプのイベントを表します。次に例を示します。

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

アプリケーションのボトルネックを検出する方法の1つは、フライト記録の次のイベントを調べることです。使用している記録テンプレートで、次のすべてのイベントが有効になっていることを確認します。

• jdk.FileRead
• jdk.FileWrite
• jdk.SocketRead
• jdk.SocketWrite
• jdk.JavaErrorThrow
• jdk.JavaExceptionThrow
• jdk.JavaMonitorEnter
• jdk.JavaMonitorWait
• jdk.ThreadStart
• jdk.ThreadEnd
• jdk.ThreadSleep
• jdk.ThreadPark

選択されたJavaアプリケーションのイベントはすべて、スレッド・ストール・イベントであるという重要なプロパティを持ちます。スレッド・ストールは、スレッドがイベント中にアプリケーションを実行していなかったことを示し、これらはすべて期間イベントです。期間イベントは、アプリケーションが実行されていなかった時間を測定します。

jfrツールを使用して、記録されたイベントを出力し、次の情報を探します。

• jdk.JavaMonitorWaitイベントでは、スレッドがモニターの待機に費やした時間が表示されます。
• jdk.ThreadSleepおよびjdk.ThreadParkイベントは、スレッドがスリープ状態または停止状態であることを示します。
• 読取りおよび書込みイベントは、I/Oに費やされた時間を示します。

Javaアプリケーションの重要なスレッドがブロックされた状態で多くの時間を費やしている場合は、アプリケーションの重要なセクションがシングル・スレッドであり、それがボトルネックであることを意味しています。Javaアプリケーションがソケットの待機に多くの時間を費やしている場合、主なボトルネックは、ネットワーク内またはアプリケーションが通信する他のマシンにある可能性があります。Javaアプリケーションの重要なスレッドがアプリケーション・イベントを生成せずに多くの時間を費やしている場合、アプリケーションのボトルネックは、コードの実行に費やした時間、またはCPU自体です。これらの各ボトルネックは、フライト記録内でさらに調査できます。

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

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

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

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

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

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

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

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

たとえば、ファイナライザまたは準参照の使用を減らすように、アプリケーションの修正が必要になる場合もあります。

アプリケーションの一時停止に時間がかかりすぎる場合は、様々な方法でこれを解決できます。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 Virtual Machineガベージ・コレクション・チューニング・ガイド』のガベージ・コレクション・チューニング・ガイドに関する項を参照してください。

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

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

jfrツールを使用して、記録されたjdk.GCPhasePauseイベントを出力します。次の例は、イベントに含まれる情報を示しています。

c:\Program Files\Java\jdk-15\bin>jfr print --events jdk.GCPhasePause \
   gctest.jfr
jdk.GCPhasePause {
  startTime = 11:19:13.779
  duration = 3.419 ms
  gcId = 1
  name = "GC Pause"
  eventThread = "VM Thread" (osThreadId = 17528)
}

jdk.GCPhasePauseイベントからの情報を使用して、各GCの一時休止の平均合計、一時休止の最大合計、および一時休止時間の合計を計算できます。一時休止合計は、GC中にアプリケーションが一時休止した時間の合計です。多くのGCは、バックグラウンドでほとんどの処理を行います。この場合、GCの長さは重要ではなく、アプリケーションが実際に停止していた時間が重要です。したがって、一時休止合計は、GCの影響を適切に測定します。

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

個々のGCに時間がかかりすぎる場合は、GCの戦略を変更する必要があります。一時休止の回数とスループット・パフォーマンスの対比となると、各GCには異なるトレードオフがあります。たとえば、ファイナライザまたは準参照の使用を減らすように、アプリケーションの修正が必要になる場合もあります。『Java Platform, Standard Edition HotSpot仮想マシン・ガベージ・コレクション・チューニング・ガイド』の動作ベースのチューニングに関する項を参照してください。

アプリケーションが一時休止している時間が多すぎる場合は、様々な回避方法があります。

• Javaヒープ・サイズを大きくしてください。Javaヒープが大きいほど、GC間の時間は長くなります。Javaアプリケーションにメモリー・リークがあると、GCがますます頻繁になり、最後にはOutOfMemoryErrorがスローされる可能性があるので、注意が必要です。詳細は、JDK Mission Controlを使用したメモリー・リークのデバッグを参照してください。

• GCの数を減らすには、より少ない一時オブジェクトを割り当てます。小さなオブジェクトは「TLAB」内に割り当てられ、大きなオブジェクトは「TLAB」外に割り当てられています。多くの場合、割当ての大半は「TLAB」内で起こります。jdk.ObjectAllocationInNewTLABおよびjdk.ObjectAllocationOutsideTLABイベントは、一時オブジェクトの割当てに関する情報を提供します。

• 必要なGCを減らすために割当て率を減らします。jdk.ThreadAllocationStatisticsイベントは、スレッドごとの割当てに関する情報を提供します。

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

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

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

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

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

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

最も競合しているロック、およびロックの取得を待機しているスレッドのスタック・トレースを参照してください。通常、問題になると予想されていなかった競合を探します。ロギングは、一部のアプリケーションで予想外のボトルネックになる可能性がある共通領域です。

プログラムの更新後またはいずれかの特定の時間に、Javaアプリケーションのパフォーマンスの低下が見られる場合は、状況がよいときにフライト記録を取り、状況が悪いときに別のフライト記録を取って、大きく増加している同期サイトを探します。

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

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

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

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

アプリケーションのI/O問題を診断するには、フライト記録で次のイベントを参照してください。使用している記録テンプレートで、次のすべてのイベントが有効になっていることを確認します。

• jdk.SocketWrite
• jdk.SocketRead
• jdk.FileWrite
• jdk.FileRead

フライト記録のソケットの読取りおよび書込み情報を使用して、特定のリモート・アドレスからの読取り数、読取りの合計バイト数、および待機に費やした合計時間を計算します。各イベントを参照して、所要時間および読み取ったデータを分析します。

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

デフォルトでは、期間が20ミリ秒より長いイベントのみが記録されます。フライト記録を開始するとき、より多くのデータを収集するために、ファイルI/Oのしきい値またはソケットI/Oのしきい値を下げることができますが、パフォーマンスへの影響が大きくなる可能性があります。

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

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

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

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

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

jdk.CPULoadイベントを参照し、一定期間にわたるCPU使用率を確認します。これは、記録されているJVMのCPU使用率とマシン上の総CPU使用率を示しています。JVMのCPU使用率は低いが、マシンのCPU使用率が高い場合は、他のアプリケーションが多くのCPUを消費している可能性があります。その場合は、Topやタスク・マネージャなどのOSツールを使用してシステムで実行している他のアプリケーションを調べ、CPUの使用率が高いプロセスを確認してください。

自分のアプリケーションがCPU時間を多く使用している場合は、jdk.ThreadCPULoadイベントを参照し、最もCPU時間を使用するスレッドを特定します。この情報はメソッド・サンプリングに基づいているので、サンプル数が少ない場合には100%正確でないことがあります。記録が実行されているとき、JVMはスレッドをサンプリングします。デフォルトでは、連続記録ではいくつかのメソッド・サンプリングのみが実行され、プロファイリング記録ではできるかぎり多く実行されます。メソッド・サンプリングでは、コードを実行しているスレッドだけからデータを収集します。I/O待ち、スリープ中、ロック待ちなどのスレッドはサンプリングされません。したがって、メソッド・サンプルが多いスレッドは、CPU時間を最も多く使用しているスレッドですが、各スレッドがどのくらいのCPUを使用しているかはわかりません。

「コード」タブ・グループの「ホット・メソッド」タブは、アプリケーションが実行時間の大半を費やしている場所を見つけるのに役立ちます。このタブには、スタックの上位メソッドによりグループ化されたすべてのサンプルが表示されます。「呼出しツリー」タブを使用して、スタック・トレースの最下位のメソッドから始め、上方に移動します。Thread.runから始めて、最も多くサンプリングされている呼出しを参照します。