jvm-GC日志查看

于 2021-05-05 21:50:38 发布
阅读量749 收藏
点赞数
分类专栏： # JVM
版权声明：本文为博主原创文章，遵循 CC 4.0 BY-SA 版权协议，转载请附上原文出处链接和本声明。
本文链接：https://blog.youkuaiyun.com/cen50958/article/details/116431063
版权
本文介绍了如何通过设置JVM参数模拟频繁的Young GC，解析了JVM的GC日志，包括GC原因、时间戳、内存使用情况等，并展示了模拟对象进入老年代并触发CMS的过程，深入理解JVM垃圾回收机制。

摘要生成于 C知道 ，由 DeepSeek-R1 满血版支持， 前往体验 >

模拟出频繁Young GC

JVM参数设置

设置堆内存，快速模拟出垃圾回收

-XX:NewSize=5242880 -XX:MaxNewSize=5242880 -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=10485760 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC

“-XX:InitialHeapSize”和“-XX:MaxHeapSize”就是初始堆大小和最大堆大小

“-XX:NewSize”和“-XX:MaxNewSize”是初始新生代大小和最大新生代大小

“-XX:PretenureSizeThreshold=10485760”指定了大对象阈值是10MB、

上面参数设置堆内存10MB，其中新生代是5MB内存空间，其中Eden区占4MB，每个Survivor区占0.5MB，

大对象必须超过10MB才会直接进入老年代，年轻代使用ParNew垃圾回收器，老年代使用CMS垃圾回收器

[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-0ul4vtdA-1620222535690)(F:\学习\学习笔记\jvm\images\堆内存设置.png)]

打印出JVM GC日志

-XX:+PrintGCDetils：打印详细的gc日志
-XX:+PrintGCTimeStamps：这个参数可以打印出来每次GC发生的时间
-Xloggc:gc.log：这个参数可以设置将gc日志写入一个磁盘文件

  • 完整JVM参数设置
-XX:NewSize=5242880
-XX:MaxNewSize=5242880
-XX:InitialHeapSize=10485760
-XX:MaxHeapSize=10485760
-XX:SurvivorRatio=8
-XX:PretenureSizeThreshold=10485760
-XX:+UseParNewGC
-XX:+UseConcMarkSweepGC
-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-Xloggc:gc.log

示例代码

public static void main(String[] args) {
	byte[] array1 = new byte[1024 * 1024];
    array1 = new byte[1024 * 1024];
    array1 = new byte[1024 * 1024];
    array1 = null;

    byte[] array2 = new byte[2 * 1024 * 1024];
}

方法解读

  • 第一行：byte[] array1 = new byte[1024 * 1024];

    在JVM的Eden区内放入一个1MB的对象，同时在main线程的虚拟机栈中会压入一个main()方法的栈帧，在main()方法的栈帧内部，会有一个“array1”变量，这个变量是指向堆内存Eden区的那个1MB的数组;
    在这里插入图片描述

  • 第二行：array1 = new byte[1024 * 1024];

    此时会在堆内存的Eden区中创建第二个数组，并且让局部变量指向第二个数组，然后第一个数组就没人引用了，此时第一个数组就成了没人引用的“垃圾对象”了

在这里插入图片描述

  • 第三行：byte[] array1 = new byte[1024 * 1024];

    这行代码在堆内存的Eden区内创建了第三个数组，同时让array1变量指向了第三个数组，此时前面两个数组都没有人引用了，就都成了垃圾对象

在这里插入图片描述

  • 第四行：array1 = null;

    让array1这个变量什么都不指向了，此时会导致之前创建的3个数组全部变成垃圾对象

在这里插入图片描述

  • 第五行：byte[] array2 = new byte[2 * 1024 * 1024];

    分配一个2MB大小的数组，因为Eden区总共有4MB的大小，已经放了3个1MB的数组，此时放入2MB的数组是无法放下，所以在这个时候就会触发年轻代的Young GC

GC日志

完整日志

Java HotSpot(TM) 64-Bit Server VM (25.241-b07) for windows-amd64 JRE (1.8.0_241-b07), built on Dec 11 2019 10:21:40 by "rejava" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 12271980k(6714636k free), swap 15185172k(8782272k free)
CommandLine flags: -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:MaxNewSize=5242880 -XX:NewSize=5242880 -XX:OldPLABSize=16 -XX:PretenureSizeThreshold=10485760 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseLargePagesIndividualAllocation -XX:+UseParNewGC 
0.389: [GC (Allocation Failure) 0.389: [ParNew: 3822K->512K(4608K), 0.0023784 secs] 3822K->638K(9728K), 0.0026065 secs] [Times: user=0.00 sys=0.00, real=0.16 secs] 
Heap
 par new generation   total 4608K, used 2601K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000)
  eden space 4096K,  51% used [0x00000000ff600000, 0x00000000ff80a558, 0x00000000ffa00000)
  from space 512K, 100% used [0x00000000ffa80000, 0x00000000ffb00000, 0x00000000ffb00000)
  to   space 512K,   0% used [0x00000000ffa00000, 0x00000000ffa00000, 0x00000000ffa80000)
 concurrent mark-sweep generation total 5120K, used 126K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
 Metaspace       used 3231K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 350K, capacity 388K, committed 512K, reserved 1048576K

GC日志解读

0.389: [GC (Allocation Failure) 0.389: [ParNew: 3822K->512K(4608K), 0.0023784 secs] 3822K->638K(9728K), 0.0026065 secs] [Times: user=0.00 sys=0.00, real=0.16 secs]
Heap

  • **GC (Allocation Failure)：**发生GC的原因，是对象分配失败
  • **0.389：**你的系统运行以后过了多少秒发生了本次GC，这里大概是运行了389毫秒发生了本次GC
  • [ParNew: 3822K->512K(4608K), 0.0023784 secs]
    • ParNew：触发的是年轻代的Yong GC，采用的ParNew垃圾回收器；
    • 3822K->512K：意思就是对年轻代执行了一次GC，GC之前都使用了4030KB了，但是GC之后只有512KB的对象是存活下来的；
    • (4608K)：年轻代可用空间是4608KB，也就是4.5MB（4MB-Eden + 0.5MB-个Survivor）
    • 0.0023784 secs：就是本次gc耗费的时间，大概是2.3ms
  • 3822K->638K(9728K)： 整个Java堆内存是总可用空间9728KB（9.5MB），其实就是年轻代4.5MB+老年代5M，然后GC前整个Java堆内存里使用了3822，GC之后Java堆内存使用了638KB
  • **[Times: user=0.00 sys=0.00, real=0.16 secs] ：**本次gc消耗的时间

JVM退出的时候打印出来的当前堆内存的使用情况

  • **par new generation total 4608K, used 2601K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000)：**意思是“ParNew”垃圾回收器负责的年轻代总共有4608KB（4.5MB）可用内存，目前是使用了2601KB（2.5MB）

    此时在JVM退出之前，为什么年轻代占用了2.5MB的内存？

    在Eden区一定有一个2MB的数组，也就是2048K，然后上次GC之后在From Survivor区中存活了一个

    512KB的对象，合计：2048KB + 512KB = 2560KB，但是年轻代为什么使用了2601KB呢？每个数组他会额外占据一些内存来存放一些自己这个对象的元数据，所以你可以认为多出来的41KB可以是数组对象额外使用的内存空间。

  • eden space 4096K, 51% used [0x00000000ff600000, 0x00000000ff80a558, 0x00000000ffa00000)
    from space 512K, 100% used [0x00000000ffa80000, 0x00000000ffb00000, 0x00000000ffb00000)
    to space 512K, 0% used [0x00000000ffa00000, 0x00000000ffa00000, 0x00000000ffa80000)：

    Eden区此时4MB的内存被使用了51%，就是因为有一个2MB的数组在里面。然后From Survivor区，512KB是100%的使用率，此时被之前gc后存活下来的512KB的未知对象给占据了

  • **concurrent mark-sweep generation total 5120K, used 126K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000) ：**CMS垃圾回收器，管理的老年代内存空间一共是5MB，此时使用了126KB的空间

  • **Metaspace used 3231K, capacity 4496K, committed 4864K, reserved 1056768K class space used 350K, capacity 388K, committed 512K, reserved 1048576K：**Metaspace元数据空间和Class空间，存放一些类信息、常量池之类的东西，此时他们的总容量，使用内存，等等

模拟出对象进入老年代的场景,触发CMS

示例代码

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

GC日志

Java HotSpot(TM) 64-Bit Server VM (25.241-b07) for windows-amd64 JRE (1.8.0_241-b07), built on Dec 11 2019 10:21:40 by "rejava" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 12271980k(6872468k free), swap 15185172k(8820136k free)
CommandLine flags: -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:MaxNewSize=5242880 -XX:NewSize=5242880 -XX:OldPLABSize=16 -XX:PretenureSizeThreshold=10485760 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseLargePagesIndividualAllocation -XX:+UseParNewGC 
0.269: [GC (Allocation Failure) 0.269: [ParNew: 3724K->512K(4608K), 0.0020845 secs] 3724K->2665K(9728K), 0.0022739 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
0.272: [GC (Allocation Failure) 0.272: [ParNew: 2890K->512K(4608K), 0.0014808 secs] 5044K->3173K(9728K), 0.0015438 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
0.274: [GC (CMS Initial Mark) [1 CMS-initial-mark: 2661K(5120K)] 5249K(9728K), 0.0001400 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
0.274: [CMS-concurrent-mark-start]
0.275: [CMS-concurrent-mark: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
0.275: [CMS-concurrent-preclean-start]
0.275: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
0.275: [CMS-concurrent-abortable-preclean-start]
0.275: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 par new generation   total 4608K, used 2629K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000)
  eden space 4096K,  51% used [0x00000000ff600000, 0x00000000ff8117e8, 0x00000000ffa00000)
  from space 512K, 100% used [0x00000000ffa00000, 0x00000000ffa80000, 0x00000000ffa80000)
  to   space 512K,   0% used [0x00000000ffa80000, 0x00000000ffa80000, 0x00000000ffb00000)
 concurrent mark-sweep generation total 5120K, used 2661K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
 Metaspace       used 3226K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 349K, capacity 388K, committed 512K, reserved 1048576K
0.275: [GC (CMS Final Remark) [YG occupancy: 2629 K (4608 K)]0.275: [Rescan (parallel) , 0.0002505 secs]0.276: [weak refs processing, 0.0000247 secs]0.276: [class unloading, 0.0003900 secs]0.276: [scrub symbol table, 0.0007520 secs]0.277: [scrub string table, 0.0001941 secs][1 CMS-remark: 2661K(5120K)] 5291K(9728K), 0.0017775 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

0.274: [GC (CMS Initial Mark) [1 CMS-initial-mark: 2661K(5120K)] 5249K(9728K), 0.0001400 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
0.274: [CMS-concurrent-mark-start]
0.275: [CMS-concurrent-mark: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
0.275: [CMS-concurrent-preclean-start]
0.275: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
0.275: [CMS-concurrent-abortable-preclean-start]
0.275: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
Heap

上面的日志可以看出CMS 经过4个阶段：[CMS Initial Mark] ----> [CMS-concurrent-mark] ----> [CMS-concurrent-preclean] ----> [CMS-concurrent-abortable-preclean]

评论
添加红包

请填写红包祝福语或标题

个

红包个数最小为10个

元

红包金额最低5元

当前余额3.43元 前往充值 >
需支付：10.00元
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付元
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明：

1.余额是钱包充值的虚拟货币，按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载，可以购买VIP、付费专栏及课程。

余额充值