7.3.7 Javaプロセス・JavaスレッドのCPU使用率が高騰している場合

JavaプロセスのCPU使用率が高騰した場合に、JFR/JMCを使って調査する方法を説明します。

CPU使用率高騰の原因調査

JavaプロセスのCPU使用率高騰時にスレッドダンプを採取する場合は、““HighCPULoad”イベント”を使用します。

JMCで[アウトライン]タブの[イベント・ブラウザ]を選択します。
表示された[イベント・タイプ・ツリー]から、[Fujitsu Extended Event]の[High CPU Load]を選択します。
“HighCPULoad”イベントの一覧が表示されます。
“HighCPULoad”イベントの一覧に表示される値
- 開始時間：平均CPU使用率の計測の開始時刻
- 期間：平均CPU使用率の計測期間
- 終了時間：平均CPU使用率の計測の終了時刻
- JVM User：Javaプロセスのユーザーモードでの[開始時間]から[終了時間]までの期間中の平均CPU使用率
  期間中にユーザーモードで使用したCPU時間 ÷ 期間中にシステム全体で使用可能なCPU時間
- JVM System：Javaプロセスのカーネルモードでの期間中の平均CPU使用率
  期間中にカーネルモードで使用したCPU時間 ÷期間中にシステム全体で使用可能なCPU時間
- JVM Total：期間中のユーザーモードとカーネルモードでの合計のCPU使用率の平均値
  JVM User + JVM System
以下の例の場合、CPU使用率は“95.4%”で、カーネルモードが“0.462%”、ユーザーモードが“95%”になっています。
このことから、アプリケーションのコード自体の問題であることが推測されます。
アプリケーションの処理を調査するために、“CPU使用率高騰時に記録されたスレッドダンプを調査する”を参照してください。

CPU使用率高騰時に記録されたスレッドダンプを調査する

“HighCPULoad”イベントが発生したときのアプリケーションの状態を調査する場合は、““ThreadDump”イベント”を使用します。

JMCで[アウトライン]タブの[イベント・ブラウザ]を選択します。
表示された[イベント・タイプ・ツリー]の[Thread Dump]を選択します。
“ThreadDump”イベントの一覧が表示されます。
スレッドダンプを記録した時刻が[開始時間]に表示されます。“HighCPULoad”イベントの[終了時間]の直後に記録された“ThreadDump”イベントに、CPU使用率高騰時のスレッドダンプが含まれています。
例えば、“CPU使用率高騰の原因調査”の“手順3” の画面で“2022/12/09 18:47:50.176”になっていますので、“2022/12/09 18:47:50.176”から始まる3つの“ThreadDump”イベントを調査します。
スレッドダンプを参照するためには、該当するイベント行で右クリックした際のポップアップメニューで[コピー]を選択し、いったんクリップボードにコピーした後、テキストを扱えるツールにペーストしてください。

“HighCPULoad”イベント

“HighCPULoad”イベントは、JavaプロセスのCPU使用率が指定したしきい値を超えた場合、スレッドダンプを採取するイベントです。“HighCPULoad”イベントで記録する“ThreadDump”イベントについては、“7.3.7.3 “ThreadDump”イベントについて”を参照してください。

“HighCPULoad”イベントは本製品で提供するOpenJDKが実装している拡張機能であるため、“default.jfc”および“profile.jfc”のイベント設定ファイルでは使用できません。

また、“extend.jfc”に以下のように設定されており、デフォルトで有効になっています。スタックトレースはデフォルトでは記録されない設定になっています。設定を変更する場合は、“extend.jfc”の設定を修正した別のイベント設定ファイルを作成し、使用してください。

<event name="com.fujitsu.jdk.HighCPULoad">
 <setting name="enabled">true</setting>
 <setting name="threshold">10 m</setting>
 <setting name="ratioThreshold">90 %</setting>
</event>

イベント設定ファイルの設定方法は、“イベント設定ファイル”を参照してください。

“enabled”プロパティ
- true:イベントが有効になります。
- false:イベントが無効になります。
注意
““CPULoad”イベント”が無効になっている場合、“HighCPULoad”イベントは記録されません。“CPULoad”イベントは“extend.jfc”で設定されており、デフォルトで有効になっています。“HighCPULoad”イベントを使用する場合は、“CPULoad”イベントの“enabled”プロパティを“true”から変更しないでください。
“threshold”プロパティ
Javaプロセスの平均CPU使用率を採取する間隔を指定します。指定した間隔ごとにCPU使用率が高騰しているか判定し、高騰している場合はイベントが記録されます。
値の形式：
・“<整数> <単位>”で指定します。
・<整数>前後の空白は無視します。
・<整数>に“0”を指定した場合は、“CPULoad”イベントの“period”プロパティの値が使用されます。
・<整数>と<単位>を以下のように指定します。
- ナノ秒を指定する場合: “ns”
  <整数>の指定範囲：0以上、9223372036854775807以下
- マイクロ秒を指定する場合: “us”
  <整数>の指定範囲：0以上、9223372036854775以下
- ミリ秒を指定する場合: “ms”
  <整数>の指定範囲：0以上、9223372036854以下
- 秒を指定する場合: “s”
  <整数>の指定範囲：0以上、9223372036以下
- 分を指定する場合: “m”
  <整数>の指定範囲：0以上、153722867以下
- 時を指定する場合: “h”
  <整数>の指定範囲：0以上、2562047以下
- 日を指定する場合: “d”
  <整数>の指定範囲：0以上、106751以下
注意
“HighCPULoad”イベントの“threshold”プロパティに、““CPULoad”イベント”の“period”プロパティ値より小さい値を指定した場合、“threshold”プロパティ値ではなく、“period”プロパティ値が、CPU使用率の採取間隔になります。
“ratioThreshold”プロパティ
JavaプロセスのCPU使用率が高騰していることを判定するしきい値を指定します。“threshold”プロパティに指定した間隔で採取されたプロセスのCPU使用率が、このプロパティに指定した値以上の場合に、JavaプロセスのCPU使用率が高騰していると判定します。
値の形式：
- “<整数> ％”で指定します。
- <整数>:0以上、100以下の範囲で指定します。
- <整数>前後の空白は無視します。

7.3.7.2 JavaスレッドのCPU使用率高騰時にスレッドダンプを記録する

JavaスレッドのCPU使用率が高騰した場合に、JFR/JMCを使って調査する方法を説明します。

CPU使用率高騰の原因調査

JavaスレッドのCPU使用率高騰時のスレッドダンプを調査する場合は、““HighThreadCPULoad”イベント”を使用します。

JMCで[アウトライン]タブの[イベント・ブラウザ]を選択します。
表示された[イベント・タイプ・ツリー]から、[Fujitsu Extended Event]の[High Thread CPU Load]を選択します。
“HighThreadCPULoad”イベントの一覧が表示されます。
“HighThreadCPULoad”イベントの一覧に表示される値
- 開始時間：平均CPU使用率の計測の開始時刻
- 期間：平均CPU使用率の計測期間
- 終了時間：平均CPU使用率の計測の終了時刻
- Thread：CPU使用率が高騰したスレッド名
- User Mode CPU Load：Javaスレッドのユーザーモードでの[開始時間]から[終了時間]までの期間中の平均CPU使用率
  期間中にユーザーモードで使用したCPU時間 ÷期間中にシステム全体で使用可能なCPU時間
- System Mode CPU Load：Javaスレッドのカーネルモードでの期間中の平均CPU使用率
  期間中にカーネルモードで使用したCPU時間 ÷期間中にシステム全体で使用可能なCPU時間
- Total CPU Load：ユーザーモードとカーネルモードでの合計の平均CPU使用率
  User Mode CPU Load + System Mode CPU Load
- Thread CPU Usage：Total CPU Loadと論理プロセッサ数をかけた値
  Total CPU Load × 論理プロセッサ数
  “Thread CPU Usage”の値が、“ratioThreshold”プロパティの指定値以上の場合にCPU使用率が高騰していると判定して、“HighThreadCPULoad”イベントが記録されます。
  論理プロセッサ数は、“JMCでの論理プロセッサ数の調べ方”を参照してください。
“HighThreadCPULoad”イベントの一覧に表示されたイベントに起因する“ThreadDump”イベントを調査します。
詳細は、“CPU使用率高騰時に記録されたスレッドダンプを確認する”を参照してください。

CPU使用率高騰時に記録されたスレッドダンプを確認する

“HighThreadCPULoad”イベントが発生したときに、CPU使用率が高騰しているスレッドの状態を調べる場合は、““ThreadDump”イベント”を使用します。

JMCで[アウトライン]タブの[イベント・ブラウザ]を選択します。
表示された[イベント・タイプ・ツリー]の[Thread Dump]を選択します。
“ThreadDump”イベントの一覧が表示されます。
スレッドダンプを記録した時刻が[開始時間]に表示されます。“HighThreadCPULoad”イベントの[終了時間]の直後に記録された“ThreadDump”イベントに、CPU使用率高騰時のスレッドダンプが含まれています。
スレッドダンプを参照するためには、該当するイベント行で右クリックした際のポップアップメニューで[コピー]を選択し、いったんクリップボードにコピーした後、テキストを扱えるツールにペーストしてください。
[Thread Dump]に表示されたスレッドダンプから、“CPU使用率高騰の原因調査”の手順3”で調べたスレッド名を検索して、そのスレッドのスタックトレースを確認します。
3回のスレッドダンプのスタックトレースから、該当するアプリケーションのソースコードを調査します。
スレッドダンプの解析方法は、“7.7.3 スレッドダンプ”を参照してください。

“HighThreadCPULoad”イベント

“HighThreadCPULoad”イベントは、JavaスレッドのCPU使用率が指定したしきい値を超えた場合、スレッドダンプを採取するイベントです。“HighThreadCPULoad”イベントで記録する“ThreadDump”イベントについては、“7.3.7.3 “ThreadDump”イベントについて”を参照してください。

“HighThreadCPULoad”イベントは本製品で提供するOpenJDKが実装している拡張機能であるため、“default.jfc”および“profile.jfc”のイベント設定ファイルでは使用できません。

<event name="com.fujitsu.jdk.HighThreadCPULoad">
 <setting name="enabled">true</setting>
 <setting name="threshold">10 m</setting>
 <setting name="ratioThreshold">90 %</setting>
</event>

イベント設定ファイルの設定方法は、“イベント設定ファイル”を参照してください。

“enabled”プロパティ
- true:イベントを有効にします。
- false:イベントを無効にします。
注意
““ThreadCPULoad”イベント”が無効になっている場合、“HighThreadCPULoad”イベントは記録されません。“ThreadCPULoad”イベントは“extend.jfc”で設定されており、デフォルトで有効になっています。“HighThreadCPULoad”イベントを使用する場合は、“ThreadCPULoad”イベントの“enabled”プロパティを“true”から変更しないでください。
“threshold”プロパティ
Javaスレッドの平均CPU使用率を採取する間隔を指定します。指定した間隔ごとにCPU使用率が高騰しているか判定し、高騰している場合はイベントに記録されます。
値の形式：
・“<整数> <単位>”で指定します。
・<整数>前後の空白は無視します。
・<整数>に“0”を指定した場合は、“CPULoad”イベントの“period”プロパティの値が使用されます。
・<整数>と<単位>を以下のように指定します。
- ナノ秒を指定する場合: “ns”
  <整数>の指定範囲：0以上、9223372036854775807以下
- マイクロ秒を指定する場合: “us”
  <整数>の指定範囲：0以上、9223372036854775以下
- ミリ秒を指定する場合: “ms”
  <整数>の指定範囲：0以上、9223372036854以下
- 秒を指定する場合: “s”
  <整数>の指定範囲：0以上、9223372036以下
- 分を指定する場合: “m”
  <整数>の指定範囲：0以上、153722867以下
- 時を指定する場合: “h”
  <整数>の指定範囲：0以上、2562047以下
- 日を指定する場合: “d”
  <整数>の指定範囲：0以上、106751以下
注意
“HighThreadCPULoad”イベントの“threshold”プロパティに、““ThreadCPULoad”イベント”の“period”プロパティ値より小さい値を指定した場合、“threshold”プロパティ値ではなく、“period”プロパティ値が、CPU使用率の採取間隔になります。
“ratioThreshold”プロパティ
JavaスレッドのCPU使用率が高騰していることを判定するしきい値を指定します。“threshold”プロパティに指定した間隔で採取されたスレッドのCPU使用率が、このプロパティに指定した値以上の場合に、JavaスレッドのCPU使用率が高騰していると判定します。
値の形式
- “<整数> %”で指定します。
- <整数>:0以上、100以下の範囲で指定します。
- <整数>前後の空白は無視します。

参考

JMCでの論理プロセッサ数の調べ方

以下の操作で確認できます。

JMCで[アウトライン]タブの[イベント・ブラウザ]を選択します。
表示された[イベント・ブラウザ]の[イベント・タイプ・ツリー]から、[Java Virtual Machine]の[Operating System]の[Processor]の[CPU Information]を選択します。
[Cores]に表示された値が論理プロセッサ数です。

7.3.7.3 “ThreadDump”イベントについて

“HighCPULoad” イベントおよび“HighThreadCPULoad”イベントを記録した直後に、スレッドダンプを含む“ThreadDump”イベントを3秒間隔で3回記録します。なお、アプリケーションやシステムの状況によっては、“ThreadDump”イベントの記録間隔が3秒を超える場合があります。

スレッドダンプを解析することで、CPU使用率高騰時における各スレッドの実行状態がわかります。スレッドダンプの解析方法は、“7.7.3 スレッドダンプ”を参照してください。

注意

“ThreadDump”イベントは、重複して記録されません。

“HighCPULoad”イベントおよび“HighThreadCPULoad”イベントに起因する“ThreadDump”イベントが3回記録される間に、他の“ThreadDump”イベントが記録された場合は、“ThreadDump”イベントの記録が省略される場合があります。

例えば、以下の図では、“HighCPULoad”イベントに起因する“ThreadDump”イベントが3回記録されています（図中(1)(2)(3)）。(2)と(3)の間に、“HighThreadCPULoad”イベントが記録されたとき、“HighThreadCPULoad”イベントに起因して、2回の“ThreadDump”イベント（図中(4)(5)）が記録されますが、3回目の“ThreadDump”イベント（図中(6)）は記録されません。これは、“HighThreadCPULoad”イベントの直後に、“HighCPULoad”イベントに起因する“ThreadDump”イベント（図中(3)）が1回記録されているためです。

注意

“ThreadDump”イベントが無効になっている場合、“ThreadDump”イベントは記録されません。“ThreadDump”イベントは“extend.jfc”に以下のように設定されており、デフォルトで有効になっています。“HighCPULoad”イベントおよび“HighTreadCPULoad”イベントが記録されたときにスレッドダンプを採取する場合は、“ThreadDump”イベントの“enabled”プロパティを“true”から変更しないでください。

    <event name="jdk.ThreadDump">
      <setting name="enabled" control="thread-dump-enabled">true</setting>
      <setting name="period" control="thread-dump-interval">everyChunk</setting>
    </event>