"-XX:+PrintReferenceGC" - Reference Counts per GC

Java GC Tutorials - Herong's Tutorial Examples

∟"-XX:+PrintReferenceGC" - Reference Counts per GC

This section describes the garbage collection logging option, '-XX:+PrintReferenceGC', which prints object reference counts.

In this tutorial, let's try the "-XX:+PrintReferenceGC" garbage collection logging option to see what we will get in the log file:

C:\>\progra~1\java\jdk1.8.0\bin\java -Xms2m -Xmx64m 
   -XX:+PrintReferenceGC -XX:+PrintGCDetails -Xloggc:gc.log 
   GarbageCollection
Step/TotalMemory/FreeMemory/UsedMemory:
1   2031616   698408   1333208
2   3874816   1472824   2401992
3   3874816   424944   3449872
4   8970240   4441352   4528888
5   8970240   3358312   5611928   
...
(Ctrl-C)

C:\>type gc.log
0.127: [GC (Allocation Failure) 
   0.128: [DefNew...
   0.129: [SoftReference, 0 refs, 0.0000397 secs]
   0.129: [WeakReference, 0 refs, 0.0000132 secs]
   0.129: [FinalReference, 0 refs, 0.0000132 secs]
   0.129: [PhantomReference, 0 refs, 0 refs, 0.0000132 secs]
   0.129: [JNI Weak Reference, 0.0000205 secs]
      ...: 878K->64K(960K), 0.0017509 secs] 
      878K->756K(1984K), 0.0020952 secs] 
     
      
1.138: [GC (Allocation Failure) 
   1.138: [DefNew...
   1.140: [SoftReference, 0 refs, 0.0000546 secs]
   1.140: [WeakReference, 0 refs, 0.0000307 secs]
   1.141: [FinalReference, 0 refs, 0.0000290 secs]
   1.141: [PhantomReference, 0 refs, 0 refs, 0.0000303 secs]
   1.141: [JNI Weak Reference, 0.0000294 secs]
      ...: 865K->64K(960K), 0.0028124 secs]
   1.141: [Tenured...
   1.142: [SoftReference, 12 refs, 0.0000448 secs]
   1.142: [WeakReference, 0 refs, 0.0000303 secs]
   1.142: [FinalReference, 2 refs, 0.0000316 secs]
   1.142: [PhantomReference, 0 refs, 0 refs, 0.0000294 secs]
   1.142: [JNI Weak Reference, 0.0000273 secs]
      ...: 1476K->1539K(1540K), 0.0031085 secs] 
      1557K->1540K(2500K), 
      [Metaspace: 1555K->1555K(4480K)], 0.0061210 secs] 
     
...

The "-XX:+PrintReferenceGC" prints number of references processed for each reference type and time used at each GC.

"1.142: [SoftReference, 12 refs, 0.0000448 secs]" - 12 SoftReferences found during the GC and 0.0000448 seconds used.
"1.142: [WeakReference, 0 refs, 0.0000303 secs]" - 0 WeakReferences found during the GC and 0.0000303 seconds used.
"1.142: [FinalReference, 2 refs, 0.0000316 secs]" - 2 FinalReference found during the GC and 0.0000316 seconds used.
"1.142: [PhantomReference, 0 refs, 0 refs, 0.0000294 secs]" - 0 WeakReferences found during the GC and 0.0000294 seconds used.
"1.142: [JNI Weak Reference, 0.0000273 secs]" - 0 JNI Weak References found during the GC and 0.0000273 seconds used. It seems that the count "0 refs" was printed inside the "hantomReference" message.

References have significant impact on garbage collection processes. Those reference count reports can help you identify performance issues, see WeakReferences and GC.

Note that "1.138: [DefNew: ...] [Tenured: ...] [Metaspace: ...]" really represents 2 GC processes: a Young generation GC and a Tenured generation GC. Two sets of reference counts were generated, one for each GC.

Last update: 2018.

Table of Contents

About This Book

Heap Memory Area and Size Control

►JVM Garbage Collection Logging

Garbage Collection Demo Program

Garbage Collection Logging Options

"-XX:+PrintGC" - GC Logging Option for Short Messages

"-XX:+PrintGCDetails" - Option for Detailed GC Messages

"-XX:+PrintGCDateStamps" - Calendar Timestamp on GC Messages

"-XX:+PrintGCApplicationStoppedTime" - Application Pause Durations

"-XX:+PrintGCApplicationConcurrentTime" - Application Running Durations