JVM之GC日志

Posted 程序员大咖

tags:

篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了JVM之GC日志相关的知识,希望对你有一定的参考价值。

????????关注后回复 “进群” ,拉你进程序员交流群????????

作者丨Coder的技术之路

来源丨Coder的技术之路

JVM 相关的理论知识网上已经被讲的比较详细了,但是,不管是日常工作或是面试考察,越来越多的开始关注相关的实战经验。所以,小弟希望可以从之前的工作经历和前人的总结中,讲述一些 jvm 实际操作相关的知识,包括但不限于 GC 日志解析、GC 时间异常相关实例和发生原因、OOM 等 jvm 相关异常等等~不定时更新吧~ 大家一起交流。❞

让程序按期望GC

为了方便我们查看 GC 日志,我们来写个方便 GC 发生的程序,参见《深入理解 java 虚拟机》

private static final int _1MB = 1024 * 1024;

  public static void main(String[] args) {

    MyObject ob1, ob2, ob3, ob4,ob5;

    ob1 = new MyObject("ob1",2 * _1MB);
    ob2 = new MyObject("ob2",2 * _1MB);
    ob3 = new MyObject("ob3",2 * _1MB);
    ob4 = new MyObject("ob4",2 * _1MB);
  }

  privatestaticclass MyObject{
    private String name;
    privatebyte[] space;
    public MyObject(String name, int size) {
      this.name = name;
      this.space = newbyte[size];
      System.out.println(name + " init ~");
    }
  }

我们这里除了真正的内存占用的 space,还加上了 name 来标示对象顺序,虽然内存占用会不太准确,但应该是不影响我们对 gc 的理解的。

而运行时的 vm operation 我们设置为:

-Xms20M
-Xmx20M
-XX:NewSize=10M
-XX:+PrintGCDetails
-XX:SurvivorRatio=8

从理论上分析,因为我们 young 区设置了 10M,而 eden 区和 S 区的占比为 8:1,因此 eden 区应该是 8M, 两个 S 区分别都是 1M。

当我们连续创建了三个 2M 的对象之后,在创建第四个对象时,发现,eden 区放不下了,因此触发一次 young gc,实际运行后的 GC 日志如下:

ob1 init ~
ob2 init ~
ob3 init ~
[GC (Allocation Failure) [PSYoungGen: 8046K->594K(9216K)] 8046K->6746K(19456K), 0.0030729 secs][times: user=0.01 sys=0.01, real=0.00 secs]
[Full GC (Ergonomics) [PSYoungGen: 594K->0K(9216K)] [ParOldGen: 6152K->6642K(10240K)] 6746K->6642K(19456K), [Metaspace: 3088K->3088K(1056768K)], 0.0080044 secs][times: user=0.00 sys=0.00, real=0.01 secs]
ob4 init ~
Heap
PSYoungGen total 9216K, used 2289K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 27% used [0x00000007bf600000,0x00000007bf83c460,0x00000007bfe00000)
from space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
to space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
ParOldGen total 10240K, used 6642K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 64% used [0x00000007bec00000,0x00000007bf27cad8,0x00000007bf600000)
Metaspace used 3095K, capacity 4500K, committed 4864K, reserved 1056768K
class space used 339K, capacity 388K, committed 512K, reserved 1048576K

我们可以看到,在 ob3 init 之后, 确实进行了 GC,不过是一次 ygc,一次 fgc ,姑且不管 fgc 发生的原因,我们先来解析一下 GC 日志

young gc 日志解析

[GC (Allocation Failure) [PSYoungGen: 8046K->594K(9216K)] 8046K->6746K(19456K), 0.0030729 secs][times: user=0.01 sys=0.01, real=0.00 secs]
  • [GC(Allocation Failure)

   GC类型(GC原因) ,Allocation Failure基本都是空间不够,是正常的

  • [PSYoungGen: 8046K->594K(9216K)]

   GC策略:gc前内存占用->gc后内存占用(新生代总大小)

  • 8046K->6746K(19456K)

   gc前->gc后jvm堆内存占用(jvm堆大小)

  • 0.0030729 secs

   GC耗时

  • [times: user=0.01 sys=0.01, real=0.00 secs]

   [用户耗时,系统耗时,实际耗时]

full gc 日志解析

full gc 和 young gc 的日志基本上差不多的

[Full GC (Ergonomics) [PSYoungGen: 594K->0K(9216K)]         [ParOldGen: 6152K->6642K(10240K)] 6746K->6642K(19456K), [Metaspace: 3088K->3088K(1056768K)], 0.0080044 secs][times: user=0.00 sys=0.00, real=0.01 secs]
[gc类型   (gc原因)      [ygc策略]:young区gc前后变化(young总大小)] [fgc策略:old区gc前后(old区总大小)] jvm堆gc前后变化(堆总大小),[元数据区信息],                    fgc耗时         [gc耗时详细信息]




看懂GC日志有什么用

GC日志是很多jvm问题排查和定位的第一道工具。

比如 如果我们发现old区上升较快,s区却没有变化,是不是可以猜测是s区大小设置的和当前系统的对象大小不合适,导致没有进过s区的年代晋升直接到了老年代;

又或者我们发现频繁fgc, gc日志中fgc之后 堆大小变化不大,是不是可以从内存泄露这个方向去分析dump文件。

又或者我们在进行了一系列业务逻辑优化后,系统的响应任然不尽人意,碰巧公司暂时还没有成熟的监控平台,那从GC日志的耗时分析出发,就成了分析问题的必然之路了。

欢迎提交主题,提供更多文章示例~~

补充:为啥ygc之后紧着着一次fgc

最后大概解释下上述代码,为啥紧跟着一次fgc呢

GC的担保策略,其实是根据使用的gc策略而略有不同的,我们上述没有显示设置GC策略,那么在1.8的server模式下就默认使用了parallel scavenge +parallel old收集器,其担保策略规定:如果老生代的剩余空间少于下一次收集所需的剩余空间,那么现在就做一个完整的收集

那么问题来了,我们每个对象大约2M多,三个升到old的话其实也有剩余空间的,为啥就被判断成不足了呢,这个应该是gc策略在计算晋升对象平均值的时候,使用了加权平均的方法,其中的权重应该是倍数的,这样是对未来可能晋升对象所需空间的比较安全的估计,因此,有可能得到了剩余空间不足以下次晋升的结论。

补充:GC原因都有哪些

除了文中打印出的这两种,其实还有很多,有兴趣的同学可以看下"gc/shared/gcCause.hpp"  其中的判断分支应该都有一一对应

现代jdk的gc日志,进化的很好了应该已经,基本上看展示出来的gc原因也可以猜个大概。

-End-

最近有一些小伙伴,让我帮忙找一些 面试题 资料,于是我翻遍了收藏的 5T 资料后,汇总整理出来,可以说是程序员面试必备!所有资料都整理到网盘了,欢迎下载!

点击????卡片,关注后回复【面试题】即可获取

在看点这里好文分享给更多人↓↓

以上是关于JVM之GC日志的主要内容,如果未能解决你的问题,请参考以下文章

jvm之gc日志

JVM之GC日志分析与对象内存分配回收策略

JVM之GC日志续

JVM调优——之CMS GC日志分析

JVM之GC日志

浅析JVM中的GC日志