开启 GC 日志

2020-11-20

之前写过一个例子,展示对象循环引用仍然会被 JVM 的垃圾收集器回收。

代码如下:

package constxiong.jvm.gc;

/**
 * 引用计数
 */
public class ReferenceCount {

    public ReferenceCount holder;

    /**
     * 占用 5 M
     */
    private byte[] appendMemory = new byte[5 * 1024 * 1024];

    public static void main(String[] args) {
        ReferenceCount obj1 = new ReferenceCount();
        ReferenceCount obj2 = new ReferenceCount();
        obj1.holder = obj2;//obj1 持有 obj2 对象
        obj2.holder = obj1;//obj2 持有 obj1 对象

        obj1 = null;
        obj2 = null;

        System.gc();
    }

}

 

如果希望看到这段代码执行过程中,GC 的执行与内存回收情况,需要给 java 命令加上参数,开启 GC 日志,这样可以辅助排查 JVM 出现的问题。

 

我本地电脑环境是 64 位 win7,JDK 8

 

1、查看 GC 基本信息

参数:

-XX:+PrintGC

执行打印结果:

[GC (System.gc())  12868K->768K(123904K), 0.0223098 secs]
[Full GC (System.gc())  768K->613K(123904K), 0.0226187 secs]

 

2、查看 GC 详细信息

参数:

-XX:+PrintGCDetails

执行打印结果:

[GC (System.gc()) [PSYoungGen: 13523K->792K(37888K)] 13523K->800K(123904K), 0.0302122 secs] [Times: user=0.08 sys=0.00, real=0.03 secs] 
[Full GC (System.gc()) [PSYoungGen: 792K->0K(37888K)] [ParOldGen: 8K->650K(86016K)] 800K->650K(123904K), [Metaspace: 3347K->3347K(1056768K)], 0.0181992 secs] [Times: user=0.06 sys=0.02, real=0.02 secs] 
Heap
 PSYoungGen      total 37888K, used 983K [0x00000000d6100000, 0x00000000d8b00000, 0x0000000100000000)
  eden space 32768K, 3% used [0x00000000d6100000,0x00000000d61f5db8,0x00000000d8100000)
  from space 5120K, 0% used [0x00000000d8100000,0x00000000d8100000,0x00000000d8600000)
  to   space 5120K, 0% used [0x00000000d8600000,0x00000000d8600000,0x00000000d8b00000)
 ParOldGen       total 86016K, used 650K [0x0000000082200000, 0x0000000087600000, 0x00000000d6100000)
  object space 86016K, 0% used [0x0000000082200000,0x00000000822a2a68,0x0000000087600000)
 Metaspace       used 3354K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 371K, capacity 388K, committed 512K, reserved 1048576K

 

3、查看 GC 前后的堆、方法区可用容量变化

参数:

-XX:+PrintHeapAtGC

执行打印结果:

{Heap before GC invocations=1 (full 0):
 PSYoungGen      total 37888K, used 13523K [0x00000000d6100000, 0x00000000d8b00000, 0x0000000100000000)
  eden space 32768K, 41% used [0x00000000d6100000,0x00000000d6e34f90,0x00000000d8100000)
  from space 5120K, 0% used [0x00000000d8600000,0x00000000d8600000,0x00000000d8b00000)
  to   space 5120K, 0% used [0x00000000d8100000,0x00000000d8100000,0x00000000d8600000)
 ParOldGen       total 86016K, used 0K [0x0000000082200000, 0x0000000087600000, 0x00000000d6100000)
  object space 86016K, 0% used [0x0000000082200000,0x0000000082200000,0x0000000087600000)
 Metaspace       used 3437K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 376K, capacity 388K, committed 512K, reserved 1048576K
Heap after GC invocations=1 (full 0):
 PSYoungGen      total 37888K, used 744K [0x00000000d6100000, 0x00000000d8b00000, 0x0000000100000000)
  eden space 32768K, 0% used [0x00000000d6100000,0x00000000d6100000,0x00000000d8100000)
  from space 5120K, 14% used [0x00000000d8100000,0x00000000d81ba020,0x00000000d8600000)
  to   space 5120K, 0% used [0x00000000d8600000,0x00000000d8600000,0x00000000d8b00000)
 ParOldGen       total 86016K, used 8K [0x0000000082200000, 0x0000000087600000, 0x00000000d6100000)
  object space 86016K, 0% used [0x0000000082200000,0x0000000082202000,0x0000000087600000)
 Metaspace       used 3437K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 376K, capacity 388K, committed 512K, reserved 1048576K
}
{Heap before GC invocations=2 (full 1):
 PSYoungGen      total 37888K, used 744K [0x00000000d6100000, 0x00000000d8b00000, 0x0000000100000000)
  eden space 32768K, 0% used [0x00000000d6100000,0x00000000d6100000,0x00000000d8100000)
  from space 5120K, 14% used [0x00000000d8100000,0x00000000d81ba020,0x00000000d8600000)
  to   space 5120K, 0% used [0x00000000d8600000,0x00000000d8600000,0x00000000d8b00000)
 ParOldGen       total 86016K, used 8K [0x0000000082200000, 0x0000000087600000, 0x00000000d6100000)
  object space 86016K, 0% used [0x0000000082200000,0x0000000082202000,0x0000000087600000)
 Metaspace       used 3437K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 376K, capacity 388K, committed 512K, reserved 1048576K
Heap after GC invocations=2 (full 1):
 PSYoungGen      total 37888K, used 0K [0x00000000d6100000, 0x00000000d8b00000, 0x0000000100000000)
  eden space 32768K, 0% used [0x00000000d6100000,0x00000000d6100000,0x00000000d8100000)
  from space 5120K, 0% used [0x00000000d8100000,0x00000000d8100000,0x00000000d8600000)
  to   space 5120K, 0% used [0x00000000d8600000,0x00000000d8600000,0x00000000d8b00000)
 ParOldGen       total 86016K, used 636K [0x0000000082200000, 0x0000000087600000, 0x00000000d6100000)
  object space 86016K, 0% used [0x0000000082200000,0x000000008229f220,0x0000000087600000)
 Metaspace       used 3437K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 376K, capacity 388K, committed 512K, reserved 1048576K}

 

4、查看 GC 过程中用户线程并发时间以及停顿的时间

参数:

-XX:+PrintGCApplicationConcurrentTime -XX:+PrintGCApplicationStoppedTime

执行打印结果:

Application time: 0.0043578 seconds
Total time for which application threads were stopped: 0.0092080 seconds, Stopping threads took: 0.0000222 seconds
Application time: 0.0028967 seconds

 

5、查看收集器自动设置堆空间各分代区域大小、收集目标等自动调节的相关信息

参数:

-XX:+PrintAdaptiveSizePolicy

执行打印结果:

AdaptiveSizePolicy::update_averages:  survived: 778288  promoted: 8192  overflow: false
AdaptiveSizeStart: 0.134 collection: 1 
AdaptiveSizeStop: collection: 1 
AdaptiveSizeStart: 0.138 collection: 2 
AdaptiveSizeStop: collection: 2 

 

6、查看熬过收集后剩余对象的年龄分布信息

参数:

-XX:+PrintTenuringDistribution

执行打印结果:

Desired survivor size 5242880 bytes, new threshold 7 (max 15)

 

7、查看 jdk jvm 全量参数设置

ConstXiong 备案号:苏ICP备16009629号-3