开启 GC 日志

川长思鸟来 2023-01-04 13:21 156阅读 0赞

之前写过一个例子，展示对象循环引用仍然会被 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 全量参数设置**

命令：

java -XX:+PrintFlagsFinal

执行打印结果列出了 JVM 所有参数

[Global flags]
        uintx AdaptiveSizeDecrementScaleFactor          = 4                                   {product}
        uintx AdaptiveSizeMajorGCDecayTimeScale         = 10                                  {product}
        .
        .
        .
        bool ZeroTLAB                                  = false                               {product}
        intx hashCode                                  = 5                                   {product}

JDK 9 开始，部分参数是有所变动的。

详细的参数列表可以查看官方说明：

*  [https://www.oracle.com/java/technologies/javase/vmoptions-jsp.html][https_www.oracle.com_java_technologies_javase_vmoptions-jsp.html]
 *  [https://docs.oracle.com/javase/8/docs/technotes/tools/windows/java.html][https_docs.oracle.com_javase_8_docs_technotes_tools_windows_java.html]
 *  [https://docs.oracle.com/javase/8/docs/technotes/tools/unix/java.html][https_docs.oracle.com_javase_8_docs_technotes_tools_unix_java.html]
 *  [https://www.cnblogs.com/chenjack/p/12711214.html][https_www.cnblogs.com_chenjack_p_12711214.html]( 这篇中文翻译整理的全些)

--------------------

### 【Java学习资源】整理推荐 ###

*  [MAT 分析堆内存快照][MAT]
 *  [jclasslib 查看类信息][jclasslib]
 *  [增大 MAT 堆内存][MAT 1]
 *  [JVM 常用配置参数(Java 8)][JVM _Java 8]
 *  [40 道JVM面试题解答][40 _JVM]
 *  [JVM 问题排查常用指令][JVM]
 *  [jvisualvm 远程连接服务器 JVM][jvisualvm _ JVM]
 *  [字节码指令分类][Link 1]
 *  [\-verbose:gc 和 -XX:+PrintGC 的区别][-verbose_gc _ -XX_PrintGC]
 *  [JVM字节码指令表][JVM 1]
 *  [图解 Class 文件结构][Class]
 *  [Class 文件的结构][Class 1]
 *  [JVM 故障处理工具列表][JVM 2]
 *  [HotSpot 内存分配的主要规则][HotSpot]
 *  [开启 GC 日志][GC]
 *  [垃圾收集器及特点][Link 2]
 *  [JVM垃圾回收算法][JVM 3]
 *  [什么样的 Java 对象会被当垃圾回收？][Java]
 *  [内存溢出复现][Link 3]
 *  [HotSpot VM 中对象的内存分析][HotSpot VM]
 *  [JVM 控制的内存区域][JVM 4]
 *  [JVM家族][JVM 5]
 *  [Java 的发展史][Java 1]
 *  [常见 JVM dump 指令][JVM dump]

--------------------

### 【Java面试题与答案】整理推荐 ###

*  [基础与语法][Link 4]
 *  [集合][Link 5]
 *  [网络编程][Link 6]
 *  [并发编程][Link 7]
 *  [Web][]
 *  [安全][Link 8]
 *  [设计模式][Link 9]
 *  [框架][Link 10]
 *  [算法与数据结构][Link 11]
 *  [异常][Link 12]
 *  [文件解析与生成][Link 13]
 *  [Linux][]
 *  [MySQL][]
 *  [Oracle][]
 *  [Redis][]
 *  [Dubbo][]

[https_www.oracle.com_java_technologies_javase_vmoptions-jsp.html]: https://www.oracle.com/java/technologies/javase/vmoptions-jsp.html
[https_docs.oracle.com_javase_8_docs_technotes_tools_windows_java.html]: https://docs.oracle.com/javase/8/docs/technotes/tools/windows/java.html
[https_docs.oracle.com_javase_8_docs_technotes_tools_unix_java.html]: https://docs.oracle.com/javase/8/docs/technotes/tools/unix/java.html
[https_www.cnblogs.com_chenjack_p_12711214.html]: https://www.cnblogs.com/chenjack/p/12711214.html
[MAT]: https://www.javanav.com/val/c3466d5a4ae54cbbacff48a77764eefc.html
[jclasslib]: https://www.javanav.com/val/f6c5cf9df8554a788b403bdc4c711564.html
[MAT 1]: https://www.javanav.com/val/60b1b34a85474c9ba01858ff435c0abe.html
[JVM _Java 8]: https://www.javanav.com/val/d76fe4761aa64973b6ae730326aa6d34.html
[40 _JVM]: https://www.javanav.com/val/93550f179edb4a77bbf4d35faa6d560c.html
[JVM]: https://www.javanav.com/val/731835b642a548e8a7d7c14aeab161e6.html
[jvisualvm _ JVM]: https://www.javanav.com/val/925604ea926e42aa9f936df96b6c69d0.html
[Link 1]: https://www.javanav.com/val/ecd6c327f9164c358ee168a8f4d6cdfa.html
[-verbose_gc _ -XX_PrintGC]: https://www.javanav.com/val/3159ceb444204e0a830b921dee94d9d1.html
[JVM 1]: https://www.javanav.com/val/2e69020292844506ac038fa6942f359f.html
[Class]: https://www.javanav.com/val/296686d016a147f5b91d8ad82c6f048d.html
[Class 1]: https://www.javanav.com/val/b21a17ddecf543239060a2af5ed9c21e.html
[JVM 2]: https://www.javanav.com/val/a52a3d4ee8df4a7b9d2262572ed303dd.html
[HotSpot]: https://www.javanav.com/val/6b9865caa5f84c348f9485c558df4551.html
[GC]: https://www.javanav.com/val/acbb4071b64240b49145a1baf7856551.html
[Link 2]: https://www.javanav.com/val/391b81f602e74370aa62b8e1b5d84d83.html
[JVM 3]: https://www.javanav.com/val/bbee490647d7459984be9d612dc4b75e.html
[Java]: https://www.javanav.com/val/00c98517d5e940248f6c50403d184dd5.html
[Link 3]: https://www.javanav.com/val/2a7fd81371534120a3e86935cc1ecb01.html
[HotSpot VM]: https://www.javanav.com/val/49e9ce5857744a39a88b1977d84086c7.html
[JVM 4]: https://www.javanav.com/val/34d7eadd6bdb4f179913fe172c4a144b.html
[JVM 5]: https://www.javanav.com/val/c850f57e1cee4024a12e3ac449d2757d.html
[Java 1]: https://www.javanav.com/val/f6a20dc008d6431bb54ba6afc71cbefe.html
[JVM dump]: https://www.javanav.com/val/200700af5dfe459d957e04e93c813a0c.html
[Link 4]: https://www.javanav.com/interview/93b0069472fd479393006c0e73043fc4.html
[Link 5]: https://www.javanav.com/interview/4147d95e693945e7a50345fd33ec817e.html
[Link 6]: https://www.javanav.com/interview/68a57ffc78de4133bb890bdd502ac418.html
[Link 7]: https://www.javanav.com/interview/36a24fa3258e45c89873f474ce914912.html
[Web]: https://www.javanav.com/interview/4e27cb63adb440c6825a159d35cf4010.html
[Link 8]: https://www.javanav.com/interview/03affb2ce3f04fda8853f714e5764906.html
[Link 9]: https://www.javanav.com/interview/07a32a9ff17a4006a53550ce658cafed.html
[Link 10]: https://www.javanav.com/interview/5c466456e9b54ab0a749b5948e51f1d3.html
[Link 11]: https://www.javanav.com/interview/943f917041ee4f05add24539f5b861b2.html
[Link 12]: https://www.javanav.com/interview/d3f058cfc05d4c6dadd821b622e84d36.html
[Link 13]: https://www.javanav.com/interview/67a50996c28f418e83b109ea42fc3eff.html
[Linux]: https://www.javanav.com/interview/00cccb81729540d1923bd0a0ef49533a.html
[MySQL]: https://www.javanav.com/interview/d311e78502a845f1a4bb307bd6aec2b3.html
[Oracle]: https://www.javanav.com/interview/5f29e9677edf4a16be3dce30d257c9ab.html
[Redis]: https://www.javanav.com/interview/066c62b3af4d4827b2243a822c3084a9.html
[Dubbo]: https://www.javanav.com/interview/9a3e7a7740324757abaab953f7ebc455.html