JVM如何读GC日志以及如何使用工具分析

最新推荐文章于 2024-04-13 13:47:55 发布

=PNZ=BeijingL

最新推荐文章于 2024-04-13 13:47:55 发布

阅读量553

点赞数

分类专栏： Java 文章标签： java

本文为CSDN博主「=PNZ=BeijingL」的原创文章，遵循 CC-BY-NC-SA 版权协议，转载请附上原文出处链接及本声明。CC-BY-NC-SA协议为创作共用-署名-非商业性-相同方式共享

本文链接：https://blog.csdn.net/Beijing_L/article/details/120217862

版权

Java 专栏收录该内容

49 篇文章

订阅专栏

GC 垃圾回收必须要保证一直性的快照中进行，一直性的意思是指分析工作期间整个系统就像静止在一个时间点上，不能在分析过程中对象关系还在发生变化，所以GC分析过程中必须要让JAVA程序停顿，Sun把这个事件称之为STW (Stop the World) , 打个比方，《深入理解Java虚拟机》里作者举了一个例子，我觉得十分恰当：当你要打扫孩子的屋子时，你会让孩子做在椅子上不动，然后才能顺利的完成打扫房间。如果你一边打扫房间，孩子一边在房间里仍东西，你将永远无法完成打扫房间的工作

GC 垃圾回收时候会让JAVA程序停顿，从GC回收器的发展来看， GC算法的设计时候考虑最多的也就是如何减少这个停顿时间。当停顿时间越少其实系统的性能也就越好。当停顿的次数或者时间越长，那么系统的性能也就越差。因此对系统而言，当系统性能变慢的时候，分析GC日志来确认问题点也就变得越来越重要了，我曾经遇到过一个问题，售后反馈说系统变得突然慢，性能很差，体验非常不好。这个问题的原因就是虚拟机在频繁Full GC，FULL GC 就会产生Stop the world, 那么整个问题就变成了为什么系统会频繁Full GC 这里不再多说，因为这是另一个故事了

下面的示例说明如何打印、保存、查看GC日志

配置JVM参数打印GC日志

Run–>Edit Configuration–>VM options: -XX:+PrintGCDetails -verbose:gc -Xloggc:d:/gc.log

-XX:+PrintGCDetails 表示打印出GC的详细信息
-verbose:gc 表示开启gc日志
-Xloggc:d:/gc.log 表示日志的存放位置

这里用的IDE是Intellij IDEA , 如果是Eclips可以在

Run–>Run/Debug Configuration–> Arguments -> VMargument中修改参数

测试代码源码，这个代码还是使用前面分析finalize方法的例子

public class FinalizeEscapeGC {
    public static FinalizeEscapeGC SAVE_HOOK = null;

    public void isAlive() {
        System.out.println("yes,i am still alive：)");
    }

    @
            Override
    protected void finalize() throws Throwable {
        super.finalize();
        System.out.println("finalize mehtod executed！");
        FinalizeEscapeGC.SAVE_HOOK = this;
    }

    public static void main(String[] args) throws Throwable {
        SAVE_HOOK = new FinalizeEscapeGC();
        //对象第一次成功拯救自己
        SAVE_HOOK = null;
        System.gc();
        //因为finalize方法优先级很低，所以暂停0.5秒以等待它
        System.out.println("sleep 500");
        Thread.sleep(500);
        System.out.println("after sleep 500");
        if (SAVE_HOOK != null) {
            SAVE_HOOK.isAlive();
        } else {
            System.out.println("no,i am dead：(");
        }
        //下面这段代码与上面的完全相同，但是这次自救却失败了
        SAVE_HOOK = null;
        System.gc();
        //因为finalize方法优先级很低，所以暂停0.5秒以等待它
        Thread.sleep(500);
        if (SAVE_HOOK != null) {
            SAVE_HOOK.isAlive();
        } else {
            System.out.println("no,i am dead：(");
        }
    }

}

执行后-Xloggc 配置的地址下会生成对应的日志，截取部分日志信息

[1.097s][info][gc,phases      ] GC(1) Phase 1: Mark live objects 2.649ms
[1.097s][info][gc,phases,start] GC(1) Phase 2: Prepare for compaction
[1.097s][info][gc,phases      ] GC(1) Phase 2: Prepare for compaction 0.377ms
[1.097s][info][gc,phases,start] GC(1) Phase 3: Adjust pointers
[1.098s][info][gc,phases      ] GC(1) Phase 3: Adjust pointers 0.832ms
[1.098s][info][gc,phases,start] GC(1) Phase 4: Compact heap
[1.099s][info][gc,phases      ] GC(1) Phase 4: Compact heap 0.675ms
[1.099s][info][gc,heap        ] GC(1) Eden regions: 1->0(3)
[1.099s][info][gc,heap        ] GC(1) Survivor regions: 0->0(0)
[1.099s][info][gc,heap        ] GC(1) Old regions: 4->1
[1.099s][info][gc,heap        ] GC(1) Humongous regions: 0->0
[1.099s][info][gc,metaspace   ] GC(1) Metaspace: 6279K->6279K(1056768K)
[1.099s][info][gc             ] GC(1) Pause Full (System.gc()) 1M->0M(8M) 5.159ms
[1.099s][info][gc,cpu         ] GC(1) User=0.00s Sys=0.00s Real=0.00s
[1.600s][info][gc,heap,exit   ] Heap
[1.600s][info][gc,heap,exit   ]  garbage-first heap   total 8192K, used 984K [0x0000000681600000, 0x0000000800000000)
[1.600s][info][gc,heap,exit   ]   region size 1024K, 1 young (1024K), 0 survivors (0K)
[1.600s][info][gc,heap,exit   ]  Metaspace       used 6294K, capacity 6475K, committed 6528K, reserved 1056768K
[1.600s][info][gc,heap,exit   ]   class space    used 548K, capacity 606K, committed 640K, reserved 1048576K

日志描述说明：

[0.702s] 表示处理使用时间
[info ] 日志等级
GC(1) Eden regions 表示GC发生的位置
3M->0M(14M) 表示GC当前状况：已经使用内存量 -> GC后内存状况（该内存区域总容量）
3.742ms ：最后1个时间表示该区域GC占用的时间
User=0.00s Sys=0.00s Real=0.00s：这里面的user、sys和real与Linux的time命令所输出的时间含义一致，分别代表用户态消耗的CPU时间、内核态消耗的CPU事件和操作从开始到结束所经过的墙钟时间（Wall Clock Time）

GC垃圾收集日志可以帮助我们优化垃圾收集暂停时间，提高整体应用程序的响应时间，预测生产中断，降低计算成本,但是通过GC日志排查问题点会有一种大海捞针的感觉。但我们可以通过一些工具来帮助我们分析GC日志，比如gceasy，使用方式也很简单

首先访问 Universal JVM GC analyzer - Java Garbage collection log analysis made easy （地址

https://gceasy.io/）通过页面选择要分析的GC日志，示意图如下