zoukankan      html  css  js  c++  java
  • 曹工杂谈:手把手带你读懂 JVM 的 gc 日志

     一、前言

    今天下午本来在划水,突然看到微信联系人那一个红点点,看了下,应该是博客园的朋友。加了后,这位朋友问了我一个问题:

     

    问我,这两块有什么关系? 看到这段 gc 日志,一瞬间脑子还有点懵,嗯,这个可能要翻下书了,周志明的 Java 虚拟机那本神书里面有讲,我果断地打开了 pdf,找了起来,很快,找到了:

     

    上面发的那个图里,6762k 就是 新生代 gc 前的容量,1006k 就是新生代 gc 后的容量,9216k就是新生代的10m中(8m的eden区+1m的 from survivor区)的大小。

     

    再看后面的那几个数字,6762K-》3455K (19456K),意思就是,GC前,Java堆使用了 6762K,GC后,Java堆使用了 3455K,而19456K就是整个堆的容量(新生代9m+老年代10m)。

     

    按理说,这么解释就足够了,但是,眼尖,他提出了下面的问题(大概意思是这个,我自己配的字):

     

    这他么就尴尬了。。。怎么都解释不通了啊。。。书上怕不是错了啊。。。经过我们一番研究,得出一致结论:

     

     网上搜了下,感觉都是些理论,感觉大家都没问题,就我有问题???想起之前看虎扑帖子,有人发帖说浙江很富,没有穷人(确实富),有浙江网友回复:浙江就我一个穷人!

    我现在就是那个感觉,大家都没问题,就我有问题??

    当然,如果我就此止步了,也就不会写这个了,我和那位朋友捣鼓了一下,还是理解清楚了 gc 日志。

     

    二、gc 日志 的正确阅读方法

    友情提示:大家跑不出来和我一样效果的话,记得看看自己打断点了没。

    找这位朋友拿了他的测试代码,很简单的demo,如下:

     1 import java.util.concurrent.TimeUnit;
     2 
     3 
     4 public class AllocationTest {
     5 
     6     public static final int _1MB = 1024 * 1024;
     7 
     8 
     9     public static void main(String[] args) throws InterruptedException {
    10         byte[] allocation1, allocation2, allocation3, allocation4;
    11 
    12         allocation1 = new byte[2 * _1MB];
    13         allocation2 = new byte[2 * _1MB];
    14         allocation3 = new byte[2 * _1MB];
    15         //触发Minor GC
    16         allocation4 = new byte[4 * _1MB];
    17     }
    18 }

     

    JVM参数如下:

     -verbose:gc -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8

     

    我本地先跑了下,结果是下面这样的:

     

    这个console,和这位朋友的也不一致,我这边连那行 gc 前后的堆大小的日志都没打。因为他发我的参数里,可以看出来,没有指定垃圾收集器,那就是用了默认垃圾收集器。 而默认的垃圾收集器在不同版本的电脑上、不同版本的 JVM 上可能不一致。为了方便统一认识,我就建议大家统一用 Serial new 收集器,于是加了下面参数:

    -verbose:gc -XX:+UseSerialGC -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8

     

    这次再运行,确实可以打印出来了

     

    这里,只是重现了和这位朋友一样的问题,但问题本身,还没解决.。基于有问题就DEBUG的习惯,在下面这行打了个断点:

     1 import java.util.concurrent.TimeUnit;
     2 
     3 public class AllocationTest {
     4 
     5     public static final int _1MB = 1024 * 1024;
     6 
     7     public static void main(String[] args) throws InterruptedException {
     8         byte[] allocation1, allocation2, allocation3, allocation4;
     9 
    10         allocation1 = new byte[2 * _1MB];
    11         allocation2 = new byte[2 * _1MB];
    12         allocation3 = new byte[2 * _1MB];
    13         //触发Minor GC
    14         allocation4 = new byte[4 * _1MB];
    15 
    16         TimeUnit.SECONDS.sleep(100);
    17     }
    18 }

     

    在16行打了个断点,断点停在 16 行以后,console 如下:

     

    让我惊醒的是,这次只打了这一行,并没有打印下图这部分:

     

     其实这里已经可以分析出来 gc 的大体过程了,不过为了方便我们理解,我们可以加上以下 JVM 参数:

    -verbose:gc -XX:+UseSerialGC -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8 -XX:+PrintGC  -XX:+PrintGCTimeStamps  -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -XX:+PrintGCApplicationStoppedTime 

     

    这次,断点依然如约停在了那一行,我们看看 console,首先,下面是 gc 前的堆占用情况

     

    然后,看看 gc 后的情况:

     

    这里,我们就可以看出来了, 那3个 2m 大的对象,一开始占用了 eden区,eden区总共只有8m,那就只剩2m(实际上没剩2m,因为jvm自己占了一部分),这时候,我们要分配一个 4m 大的对象,那,JVM 在收到这个分配 4m 内存的请求后,检查了 自身的 eden区,明显不够,那就 gc 吧,也没啥好gc 的,那三个2m的对象,生命周期还没结束,我们当前的线程堆栈还维持着对它们的强引用,肯定是没法回收了。 3个 2m 的对象,活过本次gc,本来要放到 to survivor 区,但是明显放不下,于是只好丢给 老年代了。

    于是,老年代被占用了 6m 空间。

     

    理清了上述过程,再看下面那行gc 日志:

    大家可以拿计算器算下,1kb 都没差。6144 + 569 = 6713!有一种做对数学题的快感!

    三、其他收集器的表现

    我们知道,有很多种收集器组合。

    这里,我和大家试验几种,具体大家可以分析下:

    1、上图红线组合3  -XX:+UseConcMarkSweepGC -XX:+UseParNewGC

    2、红线组合4  -XX:+UseParNewGC

    3、 红线组合7,G1收集器

    -XX:+UseG1GC  这个表示看不懂了。

     更多的垃圾收集器组合,参数及配置,参考:

    JVM垃圾收集器组合--各种组合对应的虚拟机参数实践

     

    三、总结

    计算机科学,真是一门实践的学问。道友们,一起加油! 欢迎有兴趣的铜须,加群一起学习!

  • 相关阅读:
    计算程序运行时间的方法
    poj 2540 Hotter Colder 半平面交 不等式求区域面积
    poj 2954 Triangle Pick公式
    mini2440 w35 制作开机logo 去除logo光标
    java中的闰年的计算
    java中的TCP SERVER代码
    java中的程序关键字累积
    java中的比较大小的代码
    java中的记事本的最初几步
    局域网聊天工具FreeChat 1.0 开发日志
  • 原文地址:https://www.cnblogs.com/grey-wolf/p/11232968.html
Copyright © 2011-2022 走看看