[Java] How do I find what's getting promoted to my old generation?

原文はこちら。
https://blogs.oracle.com/poonam/how-do-i-find-whats-getting-promoted-to-my-old-generation

---

「minor/young GCでold generationに昇格しているものを見つける方法は？」という質問はたびたびいただきます。先頃、アプリケーションに対する様々な入力負荷で、old generationへ昇格されるオブジェクトの種類を知りたいというケースがありました。

少し時間がかかり、かつ面倒なやり方は、-XX:+TraceScavengeオプションを使うことです。これはデバッグバージョンにのみ含まれるオプションなので、このオプションを使用するには、HotSpot JVMのデバッグバージョンをビルドする必要があります。このオプションでは冗長な出力が生成され、young generationコレクションで処理されているすべてのオブジェクトをすべてログに記録します。

別の方法もあります。ヒープダンプからこの情報を抽出することができます。-XX:+PrintHeapAtGCオプションを付けて、収集されたヒープ境界情報とペアのminor GCの後に収集されたヒープダンプを使うと、old generationで重なっているオブジェクトを見つけることができます。

では、簡単な例を使ってどうやって実現するのかを見ていきましょう。ちょっとしたJavaプログラムを以下のオプションを付けて実行しました。

java -Xmx100m -XX:NewSize=10m -XX:+PrintGCDetails -XX:+HeapDumpBeforeFullGC -XX:+PrintHeapAtGC MemoryEater

4回のyoung generationのGCの後、old generationが一杯になって、Full GCが呼び出されました。この時点で、ヒープダンプが生成されたので、このヒープダンプを分析し、4回目のminor GCで何がold generationに昇格したのかを分析しましょう。

GCログによると、4回目のGC前後でのヒープの利用状況の詳細は以下の通りです。

{Heap before GC invocations=4 (full 0):
 PSYoungGen      total 17408K, used 17392K [0x00000000fdf00000, 0x0000000100000000, 0x0000000100000000)
  eden space 16384K, 100% used [0x00000000fdf00000,0x00000000fef00000,0x00000000fef00000)
  from space 1024K, 98% used [0x00000000fef00000,0x00000000feffc010,0x00000000ff000000)
  to   space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000)
 ParOldGen       total 68608K, used 34096K [0x00000000f9c00000, 0x00000000fdf00000, 0x00000000fdf00000)
  object space 68608K, 49% used [0x00000000f9c00000,0x00000000fbd4c000,0x00000000fdf00000)
 Metaspace       used 2612K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 285K, capacity 386K, committed 512K, reserved 1048576K

[GC (Allocation Failure) [PSYoungGen: 17392K->1024K(32768K)] 51488K->52816K(101376K), 0.0101398 secs] [Times: user=0.00 sys=0.00, real=0.00

Heap after GC invocations=4 (full 0):
 PSYoungGen      total 32768K, used 1024K [0x00000000fdf00000, 0x0000000100000000, 0x0000000100000000)
  eden space 31744K, 0% used [0x00000000fdf00000,0x00000000fdf00000,0x00000000ffe00000)
  from space 1024K, 100% used [0x00000000fff00000,0x0000000100000000,0x0000000100000000)
  to   space 1024K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x00000000fff00000)
 ParOldGen       total 68608K, used 51792K [0x00000000f9c00000, 0x00000000fdf00000, 0x00000000fdf00000)
  object space 68608K, 75% used [0x00000000f9c00000,0x00000000fce94050,0x00000000fdf00000)
 Metaspace       used 2612K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 285K, capacity 386K, committed 512K, reserved 1048576K
}

Heap Dump (before full gc): Dumping heap to java_pid31684.hprof ...

ParOldGenの'object space'の使用量の変化に着目してください。

では、Eclipse Memory Analyzer（MAT）でヒープ・ダンプ（java_pid31684.hprof）を開きましょう。でもその前に、MATがヒープダンプをロードする際に 'Keep unreachable objects' （到達不能なオブジェクトを保持）するようにMATを設定する必要があります。こうすることで、現在到達不能になっている可能性があるがJavaヒープに存在するオブジェクトも、ツールで説明および表示します。この設定を有効にするには、Window-> Preferences-> Memory Analyzerを選択します。


MATでヒープダンプを開いた後、ヒープのヒストグラムを確認しましょう。

このヒストグラムから、Javaヒープの中で最も多くの領域をbyte[]が占めていることがわかりますが、これらのbyte[]が存在する世代については何もわかりません。

上記のGCログから、old generationの開始アドレスが 0x00000000f9c00000 だったことがわかります。4回目のminor GCの前に、old generationは 0x00000000fbd4c000 まで使われ、GCの後、old generationは 0x00000000fce94050 に達しています。これはつまり、GC #4で昇格したオブジェクトが0x00000000fbd4c000 から 0x00000000fce94050 のアドレス範囲にコピーされた、ということです。以下のクエリのような式を使って、アドレス幅0x00000000fbd4c000 から 0x00000000fce94050 の範囲でold generationに存在するオブジェクトを確認することができます。

SELECT * FROM INSTANCEOF java.lang.Object t WHERE (toHex(t.@objectAddress) >= "0xfbd4c000" AND toHex(t.@objectAddress) <= "0xfce94050")

フィルタを追加して、特定のタイプのインスタンスの昇格した個数も確認できます。例えば、byte[] のフィルタを付けると、15,407個のbyte[]インスタンスが4回目のminor GCで昇格したことがわかります。

こうした簡単な手順で、old generationに何が存在するのか、young generationのサイズもしくはそれともsurvivor領域を調整し、昇格を避ける、もしくは最小限にする必要があるかどうかという点について、公正な考えを得ることができます。