Generate GC (Garbage Collection) log file

Garbage collection log file helps in identifying the memory problems of an application.

How to generate GC log file?

Launch the application by passing below VM arguments.

-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:<FILE_PATH>

'FILE_PATH': file path to store garbage collection logs.

-XX:+PrintGCDetails: Provide more verbose garbage collection statistics.

-XX:+PrintGCDateStamps: adds time-stamp information to the garbage collection statistics collected by using the PrintGCDetails.

For example,

HelloWorld.java

import java.util.ArrayList;
import java.util.List;

public class HelloWorld {
 public static void main(String args[]) throws Exception {
  Thread t1 = new Thread() {
   public void run() {
    while (true) {
     List<Integer> list = new ArrayList<>();

     for (int i = 0; i < 10000000; i++) {
      list.add(i);
     }
     try {
      Thread.sleep(5000);
     } catch (Exception e) {

     }
    }
   }
  };

  t1.start();
 }
}

Run the application using below command.

java -classpath . -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:GCLog HelloWorld

You can able to see below information in heap dump file ‘GCLog’.

Java HotSpot(TM) 64-Bit Server VM (25.171-b11) for windows-amd64 JRE (1.8.0_171-b11), built on Mar 28 2018 16:06:12 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 16648916k(8757636k free), swap 17697492k(8319592k free)
CommandLine flags: -XX:InitialHeapSize=266382656 -XX:MaxHeapSize=4262122496 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC 
2018-07-26T13:47:36.278+0530: 0.232: [GC (Allocation Failure) [PSYoungGen: 65536K->10736K(76288K)] 65536K->40587K(251392K), 0.0816071 secs] [Times: user=0.25 sys=0.00, real=0.08 secs] 
2018-07-26T13:47:36.385+0530: 0.339: [GC (Allocation Failure) [PSYoungGen: 62355K->10736K(141824K)] 92206K->91251K(316928K), 0.1297817 secs] [Times: user=0.44 sys=0.00, real=0.13 secs] 
2018-07-26T13:47:36.564+0530: 0.518: [GC (Allocation Failure) [PSYoungGen: 141808K->10736K(141824K)] 222323K->198442K(329728K), 0.2029467 secs] [Times: user=0.72 sys=0.06, real=0.20 secs] 
2018-07-26T13:47:36.767+0530: 0.721: [Full GC (Ergonomics) [PSYoungGen: 10736K->0K(141824K)] [ParOldGen: 187706K->171419K(408576K)] 198442K->171419K(550400K), [Metaspace: 2524K->2524K(1056768K)], 3.3043707 secs] [Times: user=6.31 sys=0.02, real=3.30 secs] 
2018-07-26T13:47:45.142+0530: 9.097: [GC (Allocation Failure) [PSYoungGen: 126624K->10738K(205312K)] 298044K->282400K(613888K), 0.1311164 secs] [Times: user=0.41 sys=0.05, real=0.13 secs] 
2018-07-26T13:47:45.368+0530: 9.322: [GC (Allocation Failure) [PSYoungGen: 205298K->10752K(272896K)] 476960K->419309K(681472K), 0.3166179 secs] [Times: user=1.05 sys=0.06, real=0.32 secs] 
2018-07-26T13:47:45.685+0530: 9.639: [Full GC (Ergonomics) [PSYoungGen: 10752K->0K(272896K)] [ParOldGen: 408557K->172590K(532480K)] 419309K->172590K(805376K), [Metaspace: 2524K->2524K(1056768K)], 3.8097647 secs] [Times: user=6.48 sys=0.00, real=3.81 secs] 
Heap
 PSYoungGen      total 272896K, used 85280K [0x000000076b500000, 0x0000000793680000, 0x00000007c0000000)
  eden space 262144K, 32% used [0x000000076b500000,0x0000000770848370,0x000000077b500000)
  from space 10752K, 0% used [0x000000077b500000,0x000000077b500000,0x000000077bf80000)
  to   space 177152K, 0% used [0x0000000788980000,0x0000000788980000,0x0000000793680000)
 ParOldGen       total 532480K, used 172590K [0x00000006c1e00000, 0x00000006e2600000, 0x000000076b500000)
  object space 532480K, 32% used [0x00000006c1e00000,0x00000006cc68b8f8,0x00000006e2600000)
 Metaspace       used 2532K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 275K, capacity 386K, committed 512K, reserved 1048576K

Previous                                                 Next                                                 Home