X
  • Wednesday, May 10, 2017

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

By: Poonam Parhar | Consulting Member of Technical Staff

This question comes up every now and then that how can I find what the minor/young collections are promoting to the old generation of my Java application. Recently, there was a case where the customer wanted to know the types of objects getting promoted to the old generation at different input loads for their application.

Well, one longer and a little bit tedious way is to use -XX:+TraceScavenge option. This is a non-product JVM option and hence you would need to build a debug version of the HotSpot JVM to be able to use this option. The output generated by this option is too verbose as it logs each and every object being processed by the young generation collections.

There is another way - it is possible to extract this information from the heap dumps. Heap dumps collected after minor collection(s) paired with the heap boundaries information collected with –XX:+PrintHeapAtGC option can help us find the objects piling up in the old generation.

Let’s see how we can achieve that with the help of a simple example. I ran a small Java program with the following options:

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

After 4 young generation collections, the old generation became full and a Full GC was invoked. At this point a Heap Dump was generated. Let’s analyze this heap dump to find out what got promoted to the old generation with minor GC #4.

The GC logs show the following heap usage details before and after GC #4:

{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 ...

Please note the changes in the ‘object space’ usage for the ParOldGen.

Now let’s open the heap dump java_pid31684.hprof in Eclipse MAT. But before we do that we want to make sure that MAT is configured to ‘Keep unreachable objects’ when it loads the heap dump. This would make sure that the objects that might have become unreachable now but are present in the Java Heap are also accounted and shown by the tool. Go to Window->Preferences->Memory Analyzer to enable this configuration setting.

After we open the heap dump in MAT, take a look at the heap histogram.

The histogram shows that byte[] are the objects that occupy the maximum amount of space in the Java Heap, but that does not tell anything about the generation where the significant number of these byte[] reside.

From the GC log above, we can see that the old generation's start address was 0x00000000f9c00000. Before the minor GC #4, the old generation was used up to the address 0x00000000fbd4c000, and after the GC the old generation grep up to 0x00000000fce94050. This means that the objects promoted with GC #4 were copied in the address range 0x00000000fbd4c000 to 0x00000000fce94050.

We can use a query like the following to see the objects present in the old generation in the address range 0x00000000fbd4c000 to 0x00000000fce94050.

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

We can also add a filter and see how many instances of a specific type got promoted. For example, adding a filter for byte[] shows that 15,407 instances of byte[] were promoted with minor GC #4

Following these simple steps, we can get a fair idea as to what is filling up our old generation, and whether we need to tune the young generation size or the survivor spaces to avoid or minimize those promotions.

 

Join the discussion

Comments ( 1 )
  • Anirban Pal Thursday, June 21, 2018
    Very nice
Please enter your name.Please provide a valid email address.Please enter a comment.CAPTCHA challenge response provided was incorrect. Please try again.Captcha
Oracle

Integrated Cloud Applications & Platform Services