アプリケーションがハングアップ(フリーズ)した場合に、JFR/JMCを使って原因を調査する方法を説明します。
JMCでデッドロック調査
マルチスレッドのアプリケーションにおいて、複数のスレッドがお互いに他のスレッドが持っているロックの解放待ちで停止した状態になっていると、アプリケーションがデッドロックを起こします。
デッドロックの調査をする場合は、スレッドダンプを確認します。
本製品提供の“イベント設定ファイル”を使用している場合、スレッドダンプの情報は、デフォルトで““ThreadDump”イベント”に記録されます。
JMCで[アウトライン]タブの[Javaアプリケーション]から[スレッド・ダンプ]を選択します。
スレッドダンプが採取された日付を選択すると、スレッドのリストが表示されます。
リストに、[Found one Java-level deadlock]が表示されている場合は、デッドロックが発生したことを示しています。
以下の場合、Thread2はThread1が獲得したロックオブジェクトを待っており、かつThread1はThread2が獲得したロックオブジェクトを待っているために、デッドロックを起こしていることがわかります。
リストに[Java stack information for the threads listed above]が表示されている場合、デッドロックの状態にあるスレッドのスタックトレースを参照できます。
スタックトレースに表示されている、アプリケーションのソースコードとロックオブジェクトの使い方を解析してください。
解析方法は、“解析方法”を参照してください。
デッドロックの原因を特定して、デッドロックを起こさないようにアプリケーションを修正してください。
“ThreadDump”イベントには、スレッドダンプの情報が記録されます。イベントの有効・無効、およびイベントの詳細は、“イベント設定ファイル”の“jdk.Threadump”で設定します。
スレッドダンプ採取間隔を設定する場合は、“period”プロパティの値を指定します。(例えば、1秒間隔の場合は“1s”、10分間隔の場合は“10m”と指定します。) 本製品提供のイベント設定ファイルでは“everyChunk”が設定されており、以下のタイミングで記録されます。
記録の開始時
記録の終了時
チャンクファイル切り替え時
<event name="jdk.ThreadDump"> <setting name="enabled" control="thread-dump-enabled">true</setting> <setting name="period" control="thread-dump-interval">everyChunk</setting> </event> <selection name="thread-dump-interval" default="normal" label="Thread Dump"> <option label="Off" name="off">999 d</option> <option label="At least Once" name="normal">everyChunk</option> <option label="Every 60 s" name="everyMinute">60 s</option> <option label="Every 10 s" name="everyTenSecond">10 s</option> <option label="Every 1 s" name="everySecond">1 s</option> </selection>
イベント設定ファイルの設定方法は、“イベント設定ファイル”を参照してください。
チャンクファイルは、“JFRの記録方法”を参照してください。
注意
頻繁な“ThreadDump”イベントの記録は、オーバーヘッドが増加します。
JMCでロックの競合調査
マルチスレッドアプリケーションでロックを扱う場合に発生する問題として、ロック競合多発やロック待ち時間の増加があり、アプリケーションの性能に影響を与えることがあります。
これらのロック関連の問題を調査する場合は、ロックインスタンスの情報を確認します。
JMCで[アウトライン]タブの[Javaアプリケーション]から[ロック・インスタンス]を参照します。
[ロック・インスタンス]によりロックの競合を調べることができます。
ロックの獲得待ちで停止している回数や時間
ロックインスタンスの名前、アドレスおよびロックインスタンスを使用しているスレッド
以下の場合、LockSampleロックインスタンスを、2つのスレッドが獲得待ちで9回、3分5秒ブロックされていることがわかります。
2つのスレッドは、Thread1とThread2で、Thread1は4回のロックの獲得待ちで1分7秒、Thread2は5回のロック獲得待ちで1分58秒ブロックされています。スレッドを選択すると、ブロックされたときのスタックトレースを調べることができます。
アプリケーションのコードで、待ち時間や回数が意図せず多く発生しており、性能問題が起きている場合は、スレッドのスタックトレースに表示されているアプリケーションのソースコードを解析して、ロックインスタンスの使い方を確認してください。Javaライブラリで発生している場合は、ライブラリの使い方を確認してください。
CPU使用率高騰調査
アプリケーションがハングアップあるいは性能低下する原因の1つとして、想定以上にアプリケーションがCPUを消費していることがあります。その場合は、CPUを消費しているスレッドやメソッドを調査することで、原因箇所を特定できる場合があります。
JFRでは、プロセスのCPU使用率は““CPULoad”イベント”、スレッドのCPU使用率は““ThreadCPULoad”イベント”に記録されます。
JMCでこれらのイベント情報を解析する手順について説明します。
JMCで[アウトライン]タブの[イベント・ブラウザ]を選択し、プロセスおよびスレッドのCPU使用率の状況を確認します。
表示された[イベント・ブラウザ]の[イベント・タイプ・ツリー]から、プロセスのCPU使用率は[CPU Load]を、スレッドのCPU使用率は[Thread CPU Load]を選択します。
プロセスのCPU使用率[CPU Load]では、[JVM System](カーネルモードでのCPU使用率)、[JVM User](ユーザーモードでのCPU使用率)およびその合計が高負荷な状態が継続していないか確認します。
以下では、[JVM User]が90%近い状態が続いていることがわかります。
スレッドのCPU使用率[Thread CPU Load]では、[System Mode CPU Load](カーネルモードでのCPU使用率)、[User Mode JVM Load](ユーザーモードでのCPU使用率)およびその合計が高負荷な状態が継続していないか確認します。
以下では、Thread-1が45.9%、Thread-2が45.5%、合計で90%近くを使っている高負荷な状態になっています。
特定のスレッドがCPUを占有消費しているかどうかは、スレッドCPU使用率から判断できる場合があります。上記の例は、CPU2コアを搭載したマシンでの結果ですが、この場合、１コアあたりの最大CPU使用率は50%になります。Thread-1は、45.9%のCPU使用率なので、このスレッドがほぼ1コアを占有していることになります。
CPU資源を多く使っているアプリケーションのコードを特定するには、メソッドプロファイリングを使用します。
メソッドプロファイリングでは、定期的にスレッドの状態をサンプリングし、““ExecutionSample”イベント”、および““NativeMethodSample”イベント”に記録されます。
JMCで、メソッドプロファイリング情報を表示するためには、[アウトライン]タブの[Javaアプリケーション]から[メソッド・プロファイリング]を選択します。
メソッドごとに、そのメソッドがサンプリングされた数と、全サンプリング数に対する割合が表示されます。
以下では、“LoopThread”クラスの“method()”メソッドが280回カウントされ、全体の98.9%占めていることがわかります。また、［スタック・トレース］から、“LoopThread.method()”メソッドは、“LoopThread.run()”メソッドから呼ばれていることがわかります。
CPU使用率が、あらかじめ設定したしきい値を超えた場合に、警告のイベントを出すためには、本製品で提供する拡張機能を使用します。拡張機能については、“7.3.7 Javaプロセス・JavaスレッドのCPU使用率が高騰している場合”を参照してください。
JavaプロセスのCPU使用率を定期的に記録するイベントです。
CPU使用率の採取間隔はイベント設定ファイルの“period”プロパティで指定します。なお、“period”プロパティは、1ミリ秒単位で切り捨てます。
<event name="jdk.CPULoad">
<setting name="enabled">true</setting>
<setting name="period">1000 ms</setting>
</event>JavaスレッドのCPU使用率を定期的に記録するイベントです。
CPU使用率の採取間隔は、イベント設定ファイルの“period”プロパティで指定します。なお、“period”プロパティは、1ミリ秒単位で切り捨てます。
<event name="jdk.ThreadCPULoad">
<setting name="enabled">true</setting>
<setting name="period">10 s</setting>
</event>Javaメソッドのプロファイリングを実施するイベントです。
メソッドプロファイリングの間隔は、イベント設定ファイルの“period”プロパティで指定します。
メソッドのプロファイリングについては、“7.3.5 性能低下が発生した場合”の“その他の性能低下”を参照してください。
<event name="jdk.ExecutionSample">
<setting name="enabled" control="method-sampling-enabled">false</setting>
<setting name="period" control="method-sampling-java-interval">20 ms</setting>
</event>Javaネイティブメソッドのプロファイリングを実施するイベントです。
メソッドプロファイリングの間隔は、イベント設定ファイルの“period”プロパティで指定します。
<event name="jdk.NativeMethodSample">
<setting name="enabled" control="method-sampling-enabled">false</setting>
<setting name="period" control="method-sampling-native-interval">20 ms</setting>
</event>注意
使用する場合は、イベント設定ファイルで““ExecutionSample”イベント”、および““NativeMethodSample”イベント”の“enabled”プロパティに“true”を指定してください。
イベントを有効にすると、アプリケーションの性能に影響をあたえる場合があります。性能低下が発生した場合は、Javaアプリケーション起動時に以下のオプションを指定してください。
“UseMembar”は、スレッドのメモリ同期機構を選択するJavaVMオプションです。“-XX:+UseMembar”を指定した場合、メモリ同期にハードウェア命令を使用して効率的に実現します。
イベント設定ファイルの設定方法は、“イベント設定ファイル”を参照してください。