Javaアプリケーションが以下のJavaメソッドを頻繁に実行すると、Java VMに負荷がかかり、アプリケーションの応答性能を低下させる要因になることがあります。
java.lang.System.gc()
java.lang.Runtime.gc()
以降、java.lang.System.gc()(以降、System.gc()と略する)で代表して説明します。
FJVMでは、Javaアプリケーション実行時にSystem.gc()メソッドの実行状態の確認ができるように、当該メソッドを実行したJavaスレッドのスタックトレースを出力する機能を「java.lang.System.gc()実行時におけるスタックトレース出力機能」として実装しています。
java.lang.System.gc()実行時におけるスタックトレース出力機能は、図1のオプションを指定した場合に有効となります。
本機能が有効な場合、Javaアプリケーション内でSystem.gc()メソッドが実行された場合には、当該メソッドを実行したJavaスレッドのスタックトレース情報が、図2のような形で標準出力へ出力されます。
なお、標準出力への出力結果は、FJVMのログ情報としてファイルへも格納されます。また“-verbose:gc”オプション指定などでガーベジコレクション処理の結果ログ出力を指定していた場合は、java.lang.System.gc()実行時におけるスタックトレース出力後に出力された結果ログ出力も、合わせてファイルへ格納されます。ファイル名や格納先はJava VM異常終了時のログ出力時と同じです。“8.5.8 FJVMログ”を参照してください。
図1 java.lang.System.gc()実行時におけるスタックトレース出力機能を有効にするオプション
-XX:+PrintJavaStackAtSystemGC |
図2 java.lang.System.gc()実行時におけるスタックトレース出力機能による出力例
"main" prio=10 tid=0x087c1c00 nid=0xd2a runnable [0xb75ab000..0xb75ab214]
java.lang.Thread.State: RUNNABLE
at java.lang.Runtime.gc(Native Method)
at java.lang.System.gc(System.java:928)
at SystemGC.main(SystemGC.java:8)
"main" prio=10 tid=0x087c1c00 nid=0xd2a runnable [0xb75ab000..0xb75ab214]
java.lang.Thread.State: RUNNABLE
at java.lang.Runtime.gc(Native Method)
at SystemGC.foo(SystemGC.java:4)
at SystemGC.main(SystemGC.java:10)図2の出力例の場合、SystemGC.mainからjava.lang.System.gc()が実行され、SystemGC.fooからjava.lang.Runtime.gc()が実行されたことを確認することができます。
JDK/JRE 6からスタックトレース情報にスレッドの状態を表す情報（トレース情報の前の行）が表示されるようになりました。
図中の例では「java.lang.Thread.State: RUNNABLE」となっていますが、"RUNNABLE"の部分が、"NEW"、"TIMED_WAITING (sleeping)"、"WAITING (on object monitor)"、"TIMED_WAITING (on object monitor)"、"WAITING (parking)"、"TIMED_WAITING (parking)"、"BLOCKED (on object monitor)"、"TERMINATED"、"UNKNOWN"などの表示の場合があります。