一个简单案例,带你看懂GC日志

本文涉及的产品
日志服务 SLS,月写入数据量 50GB 1个月
简介: GC:表明进行了一次垃圾回收,前面没有Full修饰,表明这是一次Young GCAllocation Failure:表明本次引起GC的原因是因为在年轻代中没有足够的空间能够存储新的数据了ParNew:表明本次GC发生在年轻代并且使用的是ParNew垃圾收集器。ParNew是一个Serial收集器的多线程版本,会使用多个CPU和线程完成垃圾收集工作(默认使用的线程数和CPU数相同,可以使用-XX:ParallelGCThreads参数限制)ParNew (promotion failed): 8143K->8713K(9216K) 8143K->8713K(9216K):单位是KB三个参数分别

环境准备

这样一个案例程序:

public class Main {
  public static void main(String[] args) {
    byte[] array1 = new byte[4 * 1024 * 1024];
    array1 = null;
    byte[] array2 = new byte[2 * 1024 * 1024];
    byte[] array3 = new byte[2 * 1024 * 1024];
    byte[] array4 = new byte[2 * 1024 * 1024];
    byte[] array5 = new byte[128 * 1024];
    byte[] array6 = new byte[2 * 1024 * 1024];
  }
}

我们采用如下参数来运行上述程序:

-XX:NewSize=10M -XX:MaxNewSize=10M -XX:InitialHeapSize=20M -XX:MaxHeapSize=20M -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=15 -XX:PretenureSizeThreshold=3M -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:gc.log

参数介绍:

-XX:NewSize:初始年轻代大小
-XX:MaxNewSize:最大年轻代大小
-XX:InitialHeapSize:定义堆的初始化大小,默认值是物理内存的1/64,其实就是:-Xms
-XX:MaxHeapSize:定义最大堆的大小,默认为物理内存的1/4,其实就是:-Xmx
-XX:SurvivorRatio:Eden区与Survivor区的大小比值
-XX:MaxTenuringThreshold:年轻代对象转换为老年代对象最大年龄值
-XX:PretenureSizeThreshold=3M:对象大小超过3M时直接在老年代分配内存
-XX:+UseParNewGC:使用ParNew收集器
-XX:+UseConcMarkSweepGC:使用CMS收集器
-XX:+PrintGCDetails:GC时打印详细信息
-Xloggc:输出GC日志信息到文件中

打印的GC日志情况:

0.118: [GC (Allocation Failure) 0.118: [ParNew (promotion failed): 8143K->8713K(9216K), 0.0043061 secs]0.122: [CMS: 8194K->6675K(10240K), 0.0038347 secs] 12239K->6675K(19456K), [Metaspace: 3042K->3042K(1056768K)], 0.0082981 secs] [Times: user=0.03 sys=0.01, real=0.01 secs] 
Heap
 par new generation   total 9216K, used 2213K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
  eden space 8192K,  27% used [0x00000007bec00000, 0x00000007bee297c8, 0x00000007bf400000)
  from space 1024K,   0% used [0x00000007bf500000, 0x00000007bf500000, 0x00000007bf600000)
  to   space 1024K,   0% used [0x00000007bf400000, 0x00000007bf400000, 0x00000007bf500000)
 concurrent mark-sweep generation total 10240K, used 6675K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
 Metaspace       used 3063K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 334K, capacity 388K, committed 512K, reserved 1048576K

「日志详解:」

GC:表明进行了一次垃圾回收,前面没有Full修饰,表明这是一次Young GC

Allocation Failure:表明本次引起GC的原因是因为在年轻代中没有足够的空间能够存储新的数据了

ParNew:表明本次GC发生在年轻代并且使用的是ParNew垃圾收集器。ParNew是一个Serial收集器的多线程版本,会使用多个CPU和线程完成垃圾收集工作(默认使用的线程数和CPU数相同,可以使用-XX:ParallelGCThreads参数限制)

ParNew (promotion failed): 8143K->8713K(9216K) 8143K->8713K(9216K):单位是KB,三个参数分别为:GC前该内存区域(这里是年轻代)使用容量,GC后该内存区域使用容量,该内存区域总容量。

0.0043061 secs:该内存区域GC耗时,单位是秒

CMS: 8194K->6675K(10240K), 0.0038347 secs] 12239K->6675K(19456K)8194K->6675K(10240K):GC前该内存区域(这里是老年代)使用容量变化,10240K表示该内存区域总容量, 12239K->6675K(19456K):三个参数分别为:堆区垃圾回收前的大小,堆区垃圾回收后的大小,堆区总大小

Times: user=0.03 sys=0.01, real=0.01 secs:分别表示用户态耗时,内核态耗时和总耗时

同时可以看到出现了promotion failed,那什么情况下会出现promotion failed?

在进行Young GC时,Survivor Space放不下,对象只能放入老年代,而此时老年代也放不下时会出现


详细介绍

「接下来详细介绍GC过程:」

首先我们看如下代码:

byte[] array1 = new byte[4 * 1024 * 1024];
array1 = null;

这行代码直接分配了一个4MB的大对象,此时这个对象会直接进入老年代,接着array1不再引用这个对象

接着看下面的代码:

byte[] array2 = new byte[2 * 1024 * 1024];
byte[] array3 = new byte[2 * 1024 * 1024];
byte[] array4 = new byte[2 * 1024 * 1024];
byte[] array5 = new byte[128 * 1024];

连续分配了4个数组,其中3个是2MB的数组,1个是128KB的数组,如下图所示,全部会进入Eden区域中

接着会执行如下代码:

byte[] array6 = new byte[2 * 1024 * 1024];

此时还能放得下2MB的对象吗?不可能了,因为Eden区已经放不下了。因此此时会直接触发一次Young GC。

我们看下面的GC日志:

ParNew (promotion failed): 8143K->8713K(9216K), 0.0043061 secs

这行日志显示了,Eden区原来是有8000多KB的对象,但是回收之后发现一个都回收不掉,因为上述几个数组都被变量引用了一,所以一定会直接把这些存活的对象放入到老年代里去,但是此时老年代里已经有一个4MB的数组了,还能放的下3个2MB的数组和1个128KB的数组吗?

明显是不行的,此时一定会超过老年代的10MB大小。

所以此时我们看cms的gc日志:

CMS: 8194K->6675K(10240K), 0.0038347 secs] 12239K->6675K(19456K), [Metaspace: 3042K->3042K(1056768K)], 0.0082981 secs

大家可以清晰看到,此时执行了CMS垃圾回收器的Full GC,我们知道Full GC其实就是会对老年代进行Old GC, 同时一般会跟一次Young GC关联,还会触发一次元数据区(永久代)的GC。

在CMS Full GC之前,就已经触发过Young GC了,此时大家可以看到此时Young GC就已经有了,接着就是执行针对 老年代的Old GC,也就是如下日志:

CMS: 8194K->6675K(10240K), 0.0038347 secs]

「这里看到老年代从8MB左右的对象占用,变成了6MB左右的对象占用,这是怎么个过程呢?」

很简单,一定是在Young GC之后,先把2个2MB的数组放入了老年代,此时要继续放1个2MB的数组和1个128KB的数组到老年代,一定会放不下,所以此时就会触发CMS的Full GC

然后此时就会回收掉其中的一个4MB的数组,因为他已经没人引用了

接着放入进去1个2MB的数组和1个128KB的数组

所以大家再看CMS的垃圾回收日志:CMS: 8194K->6836K(10240K), 0.0049920 secs,他是从回收前的8MB变成了 6MB

最后在CMS Full GC执行完毕之后,其实年轻代的对象都进入了老年代,此时最后一行代码要在年轻代分配2MB的数组就可以成功了


补充知识

为了方便理解上述内容,补充以下知识

「Young GC触发条件:」

当年轻代Eden区域满的时候会触发一次Young GC

「Full GC触发条件:」

Full GC用于清理整个堆空间。它的触发条件主要有以下几种:

1.显式调用System.gc方法(建议JVM触发)。

2.元空间不足

3.年代空间不足,引起Full GC。这种情况比较复杂,有以下几种:

  • 大对象直接进入老年代引起,由-XX:PretenureSizeThreshold参数定义
  • Young GC时,经历过多次Young GC仍存在的对象进入老年代。
  • Young GC时,动态对象年龄判定机制会将对象提前转移老年代。年龄从小到大进行累加,当加入某个年龄段后,累加和超过survivor区域-XX:TargetSurvivorRatio的时候,从这个年龄段往上的年龄的对象进入老年代
  • Young GC时,Eden和From Space区向To Space区复制时,大于To Space区可用内存,会直接把对象转移到老年代

4.JVM的空间分配担保机制可能会触发Full GC:

空间担保分配是指在发生Young GC之前,虚拟机会检查老年代最大可用的连续空间是否大于新生代所有对象的总空间。

如果大于,则此次Young GC是安全的。

如果小于,则虚拟机会查看HandlePromotionFailure设置值是否允许担保失败。

如果HandlePromotionFailure=true,那么会继续检查老年代最大可用连续空间是否大于历次晋升到老年代的对象的平均大小,如果大于,则尝试进行一次Young GC,但这次Young GC依然是有风险的,失败后会重新发起一次Full gc;如果小于或者HandlePromotionFailure=false,则改为直接进行一次Full GC。

「GC Easy工具」

这里推荐一个gceasy(https://gceasy.io)工具,可以上传gc文件,然后他会利用可视化的界面来展现GC情况

如果觉得不错,点个赞,转发下再走吧,谢谢

参考:

https://www.oracle.com/java/technologies/javase/vmoptions-jsp.html

深入理解Java虚拟机(第3版)

相关实践学习
日志服务之使用Nginx模式采集日志
本文介绍如何通过日志服务控制台创建Nginx模式的Logtail配置快速采集Nginx日志并进行多维度分析。
相关文章
|
16天前
|
存储 监控 Java
JVM进阶调优系列(8)如何手把手,逐行教她看懂GC日志?| IT男的专属浪漫
本文介绍了如何通过JVM参数打印GC日志,并通过示例代码展示了频繁YGC和FGC的场景。文章首先讲解了常见的GC日志参数,如`-XX:+PrintGCDetails`、`-XX:+PrintGCDateStamps`等,然后通过具体的JVM参数和代码示例,模拟了不同内存分配情况下的GC行为。最后,详细解析了GC日志的内容,帮助读者理解GC的执行过程和GC处理机制。
|
1月前
|
Arthas 监控 Java
JVM知识体系学习七:了解JVM常用命令行参数、GC日志详解、调优三大方面(JVM规划和预调优、优化JVM环境、JVM运行出现的各种问题)、Arthas
这篇文章全面介绍了JVM的命令行参数、GC日志分析以及性能调优的各个方面,包括监控工具使用和实际案例分析。
43 3
|
1月前
|
存储 数据可视化 安全
一个简单案例,带你看懂GC日志!
一个简单案例,带你看懂GC日志!
一个简单案例,带你看懂GC日志!
|
2月前
|
Prometheus Cloud Native Go
Golang语言之Prometheus的日志模块使用案例
这篇文章是关于如何在Golang语言项目中使用Prometheus的日志模块的案例,包括源代码编写、编译和测试步骤。
53 3
Golang语言之Prometheus的日志模块使用案例
|
4月前
|
算法 安全 Java
(七)JVM成神路之GC分代篇:分代GC器、CMS收集器及YoungGC、FullGC日志剖析
在《GC基础篇》中曾谈到过分代以及分区回收的概念,但基础篇更多的是建立在GC的一些算法理论上进行高谈阔论,而本篇则重点会对于分代收集器的实现进行全面详解,其中会涵盖串行收集器、并行收集器、三色标记、SATB算法、GC执行过程、并发标记、CMS收集器等知识,本篇则偏重于分析GC机制的落地实现,也就是垃圾收集器(Garbage Collector)。
111 8
|
5月前
|
SQL 关系型数据库 MySQL
MySQL数据库——索引(3)-索引语法(创建索引、查看索引、删除索引、案例演示),SQL性能分析(SQL执行频率,慢查询日志)
MySQL数据库——索引(3)-索引语法(创建索引、查看索引、删除索引、案例演示),SQL性能分析(SQL执行频率,慢查询日志)
60 2
|
4月前
|
XML Java 数据格式
支付系统----微信支付20---创建案例项目--集成Mybatis-plus的补充,target下只有接口的编译文件,xml文件了,添加日志的写法
支付系统----微信支付20---创建案例项目--集成Mybatis-plus的补充,target下只有接口的编译文件,xml文件了,添加日志的写法
|
5月前
|
Java
GC日志打印
可以看到所有的FULL GC已经没有了,时间节省上面,大于是 0.03*3 约等于 0.1秒。
44 0
|
12天前
|
XML 安全 Java
【日志框架整合】Slf4j、Log4j、Log4j2、Logback配置模板
本文介绍了Java日志框架的基本概念和使用方法,重点讨论了SLF4J、Log4j、Logback和Log4j2之间的关系及其性能对比。SLF4J作为一个日志抽象层,允许开发者使用统一的日志接口,而Log4j、Logback和Log4j2则是具体的日志实现框架。Log4j2在性能上优于Logback,推荐在新项目中使用。文章还详细说明了如何在Spring Boot项目中配置Log4j2和Logback,以及如何使用Lombok简化日志记录。最后,提供了一些日志配置的最佳实践,包括滚动日志、统一日志格式和提高日志性能的方法。
121 30
【日志框架整合】Slf4j、Log4j、Log4j2、Logback配置模板
|
1月前
|
XML JSON Java
Logback 与 log4j2 性能对比:谁才是日志框架的性能王者?
【10月更文挑战第5天】在Java开发中,日志框架是不可或缺的工具,它们帮助我们记录系统运行时的信息、警告和错误,对于开发人员来说至关重要。在众多日志框架中,Logback和log4j2以其卓越的性能和丰富的功能脱颖而出,成为开发者们的首选。本文将深入探讨Logback与log4j2在性能方面的对比,通过详细的分析和实例,帮助大家理解两者之间的性能差异,以便在实际项目中做出更明智的选择。
220 3