堆内存使用分析,GC 日志解读

重要的东东

  • 在Java中,对象实例都是在堆上创建。一些类信息,常量,静态变量等存储在方法区。堆和方法区都是线程共享的。
  • GC机制是由JVM提供,用来清理需要清除的对象,回收堆内存。
  • GC机制将Java程序员从内存管理中解放了出来,可以更关注于业务逻辑。
  • 在Java中,GC是由一个被称为垃圾回收器的守护线程执行的。
  • 在从内存回收一个对象之前会调用对象的finalize()方法。
  • 作为一个Java开发者不能强制JVM执行GC;GC的触发由JVM依据堆内存的大小来决定。
  • System.gc()和Runtime.gc()会向JVM发送执行GC的请求,但是JVM不保证一定会执行GC。
  • 如果堆没有内存创建新的对象了,会抛出OutOfMemoryError。

什么样的对象会被GC回收?

测试环境

  • 系统 Microsoft Windows [版本 10.0.14393]
  • JDK java version "1.8.0_112"
    Java(TM) SE Runtime Environment (build 1.8.0_112-b15)
    Java HotSpot(TM) 64-Bit Server VM (build 25.112-b15, mixed mode)
  • 测试工具 IntelliJ IDEA 2017.2

示例代码

这里我们来通过一个小程序进行一下堆内存分析,代码如下:

package net.penglei.test; public class HeapTest { private static final int _1M = 1024 * 1024; public static void main(String[] args) throws InterruptedException { byte[] byte1 = new byte[2 * _1M]; byte[] byte2 = new byte[2 * _1M]; byte[] byte3 = new byte[2 * _1M]; byte[] byte4 = new byte[2 * _1M]; byte[] byte5 = new byte[2 * _1M]; byte[] byte6 = new byte[5 * _1M]; byte[] byte7 = new byte[2 * _1M]; } } 

设置JVM 参数配置

-Xms20m
-Xmx20m
-Xmn10m
-verbose:gc
-XX:+PrintGCDetails #输出详细GC日志模式 -XX:+PrintTenuringDistribution #输出每次minor GC后新的存活周期的阈值 -XX:+PrintGCTimeStamps #输出gc的触发时间 

我的 IntelliJ IDEA 配置
图片描述

图片描述

查看程序进程,堆详情

  • 查看 jps -l 看进程,通过 jmap -heap pid 查看堆的概要信息
$ jps -l
 net.penglei.test.HeapTest

堆配置

$ jmap -heap 5636

Attaching to process ID 5636, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.112-b15

using thread-local object allocation.
Parallel GC with 8 thread(s)

Heap Configuration: 
   MinHeapFreeRatio         = 0                
   MaxHeapFreeRatio         = 100 		#GC后如果发现空闲堆内存占到整个预估堆内存的N%(百分比)  
   MaxHeapSize              = 20971520 (20.0MB)	# 堆最大空闲    jvm参数 -Xms20m
   NewSize                  = 10485760 (10.0MB)	# 年轻代空间    jvm参数 -Xmn10m
   MaxNewSize               = 10485760 (10.0MB)	# 年轻代最大空间
   OldSize                  = 10485760 (10.0MB)	# 老年代空间 =(等于)堆内存大小 -(减去)年轻代大小
   NewRatio                 = 2   
   SurvivorRatio            = 8   # 年轻代内存又被分成三部分 Eden 空间 80% 而From Survivor 空间 和 To Survivor空间 分别占用10%
   MetaspaceSize            = 21807104 (20.796875MB) # 设置元空间的最大值 jvm参数 -XX:MaxMetaspaceSize
   CompressedClassSpaceSize = 1073741824 (1024.0MB)  # 类指针压缩空间大小, 默认为1G
   MaxMetaspaceSize         = 17592186044415 MB    # 是分配给类元数据空间的最大值
   G1HeapRegionSize         = 0 (0.0MB) # G1区块的大小, 取值为1M至32M. 其取值是要根据最小Heap大小划分出2048个区块

...

执行完 byte3

byte[] byte3 = new byte[2 * _1M]; 
$ jmap -heap 5636 ... Heap Usage: PS Young Generation Eden Space: capacity = 8388608 (8.0MB) used = 7635080 (7.281379699707031MB) free = 753528 (0.7186203002929688MB) 91.01724624633789% used From Space: capacity = 1048576 (1.0MB) used = 0 (0.0MB) free = 1048576 (1.0MB) 0.0% used To Space: capacity = 1048576 (1.0MB) used = 0 (0.0MB) free = 1048576 (1.0MB) 0.0% used PS Old Generation capacity = 10485760 (10.0MB) used = 0 (0.0MB) free = 10485760 (10.0MB) 0.0% used 1628 interned Strings occupying 148560 bytes. 
数据区块堆总容量使用容量剩余容量使用占比
年轻代8.0MB7.28MB0.71MB91.0%
幸存者01.0MB0.00MB1.0MB0.0%
幸存者11.0MB0.00MB1.0MB0.0%
老年代10.0MB0.00MB10.MB0.0%

简单总结

  • PS Young Generation 年轻代空间,使用量达到 91.0%,内存剩余0.71MB,当下次执行byte4(占用年轻代2M内存),会触发Eden Space 空间(年轻代) Minor GC (年轻代垃圾收集)。
  • PS Old Generation 老年代空间,使用量达到 0.00%,内存剩余10.MB,当下次执行 byte4(占用年轻代2M内存),上面 Eden Space 空间(年轻代) Minor GC (年轻代垃圾收集),会老年代占用一部分内存。

执行完 byte4

byte[] byte4 = new byte[2 * _1M] 

控制台打印的GC日志

.638: [GC (Allocation Failure) Desired survivor size 1048576 bytes, new threshold 7 (max 15) [PSYoungGen: 7456K->728K(9216K)] 7456K->6880K(19456K), 0.0036244 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 641.642: [Full GC (Ergonomics) [PSYoungGen: 728K->0K(9216K)] [ParOldGen: 6152K->6700K(10240K)] 6880K->6700K(19456K), [Metaspace: 2848K->2848K(1056768K)], 0.0068164 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 

GC日志分块图解 ps(画的不好)

图片描述

$ jmap -heap 5636 ... Heap Usage: PS Young Generation Eden Space: capacity = 8388608 (8.0MB) used = 2097168 (2.0000152587890625MB) free = 6291440 (5.9999847412109375MB) 25.00019073486328% used From Space: capacity = 1048576 (1.0MB) used = 0 (0.0MB) free = 1048576 (1.0MB) 0.0% used To Space: capacity = 1048576 (1.0MB) used = 0 (0.0MB) free = 1048576 (1.0MB) 0.0% used PS Old Generation capacity = 10485760 (10.0MB) used = 6861768 (6.543891906738281MB) free = 3623992 (3.4561080932617188MB) 65.43891906738281% used 1556 interned Strings occupying 143760 bytes. 

GC日志详细分析

.638: [GC (Allocation Failure) Desired survivor size 1048576 bytes, new threshold 7 (max 15) [PSYoungGen: 7456K->728K(9216K)] 7456K->6880K(19456K), 0.0036244 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 

Parallel Scavenge 是年轻代 GC 收集器

.638: [GC (Allocation Failure) 
  • 1641.638:是本次GC发生的时间,从jvm启动起开始计时,单位为秒。这是一次Minor GC(年轻代垃圾收集),Minor GC 非常频繁,回收速度快。
Desired survivor size 1048576 bytes, new threshold 7 (max 15) 
  • 期望的幸存者大小1048576字节,新的存活周期的阈值为7(max 15)。
[PSYoungGen: 7456K->728K(9216K)] 

格式为:[PSYoungGen: a->b(c)]> 年轻代使用的是多线程垃圾收集器 Parallel Scavenge(新生代收集器,一般采用复制算法,并行的多线程收集器)

  • PSYoungGen,表示 GC发生在年轻代。
  • a 为GC前年轻代已占用空间,年轻代又细分为一个Eden 空间和From Survivor 空间 和 To Survivor空间。
  • b 为 Minor GC之后Eden空间GC后年轻代已占用空间 或者Survivor中已被占用的空间。
  • c 括号里的c表示整个年轻代的大小。
K->6880K(19456K) 

格式为:x->y(z)- x 表示GC前堆的已占用空间,

  • y 表示GC后堆已占用空间,
  • z 表示堆的总大小。
, 0.0036244 secs]
  • 表示本次GC所消耗的时间。
[Times: user=0.00 sys=0.00, real=0.00 secs] 
  • 提供cpu使用及时间消耗,user是用户态消耗的cpu时间,sys是系统态消耗的cpu时间,real是实际的消耗时间。
    老年代占用内存空间 计算方式- 老年代的内存大小 = (等于) 堆内存总大小 - (减去)年轻代内存大小。
  • 此例中就是19456K - 9216K = 10240K
    Parallel Old 是Parallel Scavenge 收集器的老年代版本
.642: [Full GC (Ergonomics) [PSYoungGen: 728K->0K(9216K)] [ParOldGen: 6152K->6700K(10240K)] 6880K->6700K(19456K), [Metaspace: 2848K->2848K(1056768K)], 0.0068164 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
.642: [Full GC (Ergonomics) 

老年代GC 又称为Major GC,经常会伴随一次Minor GC(年轻代垃圾回收)速度比较慢- 641.642:是本次GC发生的时间,从jvm启动起开始计时,单位为秒。[Full GC (Ergonomics) ,表示执行全局垃圾回收

[PSYoungGen: 728K->0K(9216K)] 

格式为:[PSYoungGen: a->b(c)]> 年轻代使用的是多线程垃圾收集器 Parallel Scavenge(新生代收集器,一般采用复制算法,并行的多线程收集器)

  • PSYoungGen,表示 GC发生在年轻代。
  • a 为GC前年轻代已占用空间,年轻代又细分为一个Eden 空间和From Survivor 空间 和 To Survivor空间。
  • b 为 Minor GC之后Eden空间GC后年轻代已占用空间 或者Survivor中已被占用的空间。
  • c 括号里的c表示整个年轻代的大小。
[ParOldGen: 6152K->6700K(10240K)] 

格式为:[ParOldGen: x->y(z)]> 老年代GC,使用 Parallel Old收集器,是Parallel Scavenge收集器的老年代版本,一搬采用多线程和“标记-整理”算法

  • ParOldGen 表示 GC 发生在老年代。
  • x 为GC前老年代已占用空间
  • y 为GC后老年代已占用空间
  • 括号里的 z 为整个老年代的大小
K->6700K(19456K) 

格式为:e->f(g)]- e 为GC前堆堆内存占用,

  • f 为GC后堆堆内存占用,
  • 括号里的 g 为JVM整个堆的总大小。
[Metaspace: 2848K->2848K(1056768K)] 

java8 特性是 把永久代 (Permanent Generation (PermGen)) 移植到元空间(Metaspace)
格式为: t->y(u)] > JDK8 HotSpot JVM 使用本地内存来存储类元数据信息并称之为:元空间(Metaspace);这与Oracle JRockit 和IBM JVM’很相似。这将是一个好消息:意味着不会再有java.lang.OutOfMemoryError: PermGen问题
默认情况下,类元数据只受可用的本地内存限制(容量取决于是32位或是64位操作系统的可用虚拟内存大小)

  • t 为元空间的垃圾回收前内存占用
  • y 为元空间的垃圾回收后内存占用
  • 括号里的 u 为JVM元空间内存总大小
, 0.0068164 secs]
  • 表示本次GC所消耗的时间。
[Times: user=0.00 sys=0.00, real=0.01 secs] 

提供cpu使用及时间消耗- user :用是用户态消耗的cpu时间

  • sys :是系统态消耗的cpu时间
  • real :本次GC是实际的消耗时间
数据区块堆总容量使用容量剩余容量使用占比
年轻代8.0MB2.00MB5.99MB25.0%
幸存者01.0MB0.00MB1.00MB0.0%
幸存者11.0MB0.00MB1.00MB0.0%
老年代10.0MB6.54MB3.45MB65.4%

简单总结

  • 年轻代 Eden Space 空间,使用量达到 25.0%,内存剩余5.99MB,当下次执行byte5(占用年轻代2M内存) 不会触发年轻代 Eden Space 空间 Minor GC(年轻代垃圾收集)。
  • 老年代空间,使用量达到 6.54%,内存剩余3.45MB,当下次执行byte5(占用年轻代2M内存),不会触发老年代空间 Major GC(老年代垃圾收集),因为年轻代空间还够用。

执行完 byte5

byte[] byte5 = new byte[2 * _1M]; 
$ jmap -heap 5636 ... Heap Usage: PS Young Generation Eden Space: capacity = 8388608 (8.0MB) used = 4356568 (4.154747009277344MB) free = 4032040 (3.8452529907226562MB) 51.9343376159668% used From Space: capacity = 1048576 (1.0MB) used = 0 (0.0MB) free = 1048576 (1.0MB) 0.0% used To Space: capacity = 1048576 (1.0MB) used = 0 (0.0MB) free = 1048576 (1.0MB) 0.0% used PS Old Generation capacity = 10485760 (10.0MB) used = 6861768 (6.543891906738281MB) free = 3623992 (3.4561080932617188MB) 65.43891906738281% used 1556 interned Strings occupying 143760 bytes. 
数据区块堆总容量使用容量剩余容量使用占比
年轻代8.0MB4.15MB3.84MB51.9%
幸存者01.0MB0.00MB1.00MB0.0%
幸存者11.0MB0.00MB1.00MB0.0%
老年代10.0MB6.54MB3.45MB65.4%

简单总结

  • 年轻代 Eden Space 空间,使用量达到 51.9%,内存剩余3.84MB,当下次执行byte6(占用年轻代5M内存),导致年轻代空间不够用了, 会触发年轻代 Eden Space 空间 Minor GC(年轻代垃圾收集),把一部分内存转移到 PS Old Generation 老年代。
  • 老年代 PS Old Generation 空间,使用量达到 6.54%,内存剩余3.45MB,当下次执行byte6(占用年轻代5M内存),由于年轻代的一部分内存,转移到了老年代,导致老年代空间不够用了,会触发老年代 PS Old Generation 空间 Major GC(老年代垃圾收集)。

执行完 byte6

byte[] byte6 = new byte[5 * _1M]; 

控制台打印的GC日志

.704: [

Full GC (Ergonomics) [PSYoungGen: 4254K->2048K(9216K)] [ParOldGen: 6700K->8745K(10240K)] 10955K->10793K(19456K), [Metaspace: 2848K->2848K(1056768K)], 0.0154383 secs ] [Times: user=0.00 sys=0.03, real=0.02 secs] 

这个GC 日志详细解读请参考,上面解读,执行完 byte4 的日志 ps(那个解读更详细)- 这个是日志其实说的就是 :年轻代G回收前后,老年代GC回收前后,整个堆的GC回收前后,原数据空间回收前后,的内存使用情况。三个内存区块GC回收所消耗的时间,提供cpu使用及时间消耗时间

简单解读GC日志

  • PS Young Generation 年轻代 Eden Space 空间,使用量达到 4254K,当执行byte6(占用年轻代5M内存),导致年轻代空间不够用了,会先触发年轻代 Eden Space 空间 Minor GC(年轻代垃圾收集),把一部分内存转移到 PS Old Generation 老年代,GC回收后 Eden Space 空间 剩余 2048K。
  • PS Old Generation 老年代空间,使用量达到 6700K,当执行byte6(占用年轻代5M内存),由于年轻代的一部分内存,转移到了老年代,导致老年代空间不够用了,会先触发老年代 PS Old Generation 空间 Major GC(老年代垃圾收集)。GC回收后 Eden Space 空间 剩余 8745K。
$ jmap -heap 5636 ... Heap Usage: PS Young Generation Eden Space: capacity = 8388608 (8.0MB) used = 7507856 (7.1600494384765625MB) free = 880752 (0.8399505615234375MB) 89.50061798095703% used From Space: capacity = 1048576 (1.0MB) used = 0 (0.0MB) free = 1048576 (1.0MB) 0.0% used To Space: capacity = 1048576 (1.0MB) used = 0 (0.0MB) free = 1048576 (1.0MB) 0.0% used PS Old Generation capacity = 10485760 (10.0MB) used = 8955872 (8.540985107421875MB) free = 1529888 (1.459014892578125MB) 85.40985107421875% used 1556 interned Strings occupying 143760 bytes. 
数据区块堆总容量使用容量剩余容量使用占比
年轻代8.0MB7.16MB0.83MB89.5%
幸存者01.0MB0.00MB1.00MB0.0%
幸存者11.0MB0.00MB1.00MB0.0%
老年代10.0MB8.54MB1.45MB85.4%

执行完 byte7

byte[] byte7 = new byte[2 * _1M]; 

简单总结

  • 参考 byte6 执行后,PS Young Generation 年轻代 Eden Space 空间,使用量达到 89.5%,内存剩余0.83MB,执行byte7(占用年轻代2M内存),导致年轻代空间不够用了,会触发Eden Space 空间(年轻代) Minor GC (年轻代垃圾收集)
  • 参考 byte6 执行后,PS Old Generation 老年代空间,使用量达到 85.4%,内存剩余1.45MB,执行byte7(占用年轻代2M内存),会导致年轻代的GC回收放到老年代,而老年代也承担不了,会 OutOfMemoryError。

控制台打印的GC日志

.298: [Full GC (Ergonomics) [PSYoungGen: 7331K->7168K(9216K)] [ParOldGen: 8745K->8745K(10240K)] 16077K->15913K(19456K), [Metaspace: 2849K->2849K(1056768K)], 0.0065366 secs] [Times: user=0.09 sys=0.02, real=0.01 secs] 10427.305: [Full GC (Allocation Failure) [PSYoungGen: 7168K->7168K(9216K)] [ParOldGen: 8745K->8745K(10240K)] 15913K->15913K(19456K), [Metaspace: 2849K->2849K(1056768K)], 0.0027873 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] Exception in thread "main" java.lang.OutOfMemoryError: Java heap space Heap at net.penglei.test.HeapTest.main(HeapTest.java:16) PSYoungGen total 9216K, used 7462K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000) eden space 8192K, 91% used [0x00000000ff600000,0x00000000ffd49b60,0x00000000ffe00000) from space 1024K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x00000000fff00000) to space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000) ParOldGen total 10240K, used 8745K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000) object space 10240K, 85% used [0x00000000fec00000,0x00000000ff48a708,0x00000000ff600000) Metaspace used 2880K, capacity 4486K, committed 4864K, reserved 1056768K class space used 309K, capacity 386K, committed 512K, reserved 1048576K Disconnected from the target VM, address: '127.0.0.1:59679', transport: 'socket' Process finished with exit code 1 。 
[Full GC (Ergonomics) [PSYoungGen: 7331K->7168K(9216K)] 
  • 本次 Minor GC 发生在PS Young Generation 年轻代 Eden Space 空间,由于老年代已经占用85.4%,老年代空间不够用,本次年轻代垃圾回收没什么太大作用,只回收了一丢丢。
[ParOldGen: 8745K->8745K(10240K)] 
  • 本次 Major GC 发生在 PS Old Generation 老年代 ,由于老年代已经占用85.4% , 空间不够回收用,导致老年代回收没有效果**
K->15913K(19456K) 

这些是告诉你,Exception 前 内存溢出前的堆占用情况

Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
Heap
	at net.penglei.test.HeapTest.main(HeapTest.java:16)
 PSYoungGen      total 9216K, used 7462K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 8192K, 91% used [0x00000000ff600000,0x00000000ffd49b60,0x00000000ffe00000)
  from space 1024K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x00000000fff00000)
  to   space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000)
 ParOldGen       total 10240K, used 8745K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
  object space 10240K, 85% used [0x00000000fec00000,0x00000000ff48a708,0x00000000ff600000)
 Metaspace       used 2880K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 309K, capacity 386K, committed 512K, reserved 1048576K
  • 此刻的 PS Young Generation 年轻代JVM 堆回收前占用16077K,年轻代JVM 堆回收后占用16077K ,JVM 堆总大小 19456K
[Full GC (Allocation Failure)
[PSYoungGen: 7168K->7168K(9216K)] [ParOldGen: 8745K->8745K(10240K)] 15913K->15913K(19456K)
  • PSYoungGen 年轻代 Minor GC , ParOldGen 老年代 Major GC 老年代承担不了 15913K 内存,然后就 OutOfMemoryError 堆内存溢出了
  • 为什了 老年代这次要 承担15913K 内存呢?因为前两次 Full GC 都没有成功,导致内存积压了一些在堆空间,堆空间自然放不下,然后要放到老年代,老年代放不下就堆内存溢出了

总结 内存分配与回收策略

  • 对象优先在新生代分配
  • 大对象直接进入老年代
  • 长期存活的对象将进入老年代
  • 动态对象年龄判断:如果在Survivor空间中相同年龄所有对象大小总和大于Survivor空间的一半,大于或等于该年龄的对象直接进入老年代。
  • 空间分配担保:发生Minor GC前,虚拟机会先检查老年代最大可用连续空间是否大于新生代所有对象总空间,如果不成立,虚拟机会查看HandlePromotionFailure设置值是否允许担保失败,如果允许继续检查老年代最大可用的连续空间是否大于历次晋升到老年代的平均大小,如果大于会尝试进行一次Minor GC;如果小于或者不允许冒险,会进行一次Full GC。

1 对象优先在eden分配

大多数情况下,对象优先在新生代的Eden区分配。 当Eden区没有足够的空间时,虚拟机将发起一次Minor GC。 Minor GC与Full GC。

  • Minor GC:新生代GC,非常频繁,回收速度快。
  • Fulll GC:老年代GC,又称为Major GC,经常会伴随一次Minor GC,速度比较慢。

2 大对象直接进入老年代

  • 大对象是指需要大量连续的内存空间的Java对象,最典型的大对象就是那种很长的字符串以及数组。
  • 虚拟机提供了一个参数:PretenureSizeThreshold,大于这个参数的对象将直接在老年代分配。

3 长期存活的对象将进入老年代

  • 虚拟机给每个对象定义了一个对象年龄计数器(Age),对象每经过一次Minor GC后仍然存活,且能被Survivor容纳的话,年龄就 +1 ,当年龄增加到一定程度(默认为15),就会被晋升到老年代中,这个阈值可以通过参数 MaxTenuringThreshold 来设置。

4.动态对象年龄的判定

4 动态对象年龄判定

  • 如果在Survivor空间中相同年龄所有对象大小的总和大于Survivor空间的一半,年龄大于或等于该年龄的对象就可以直接进入老年代。

5 空间分配担保

  • 为了更好的适应不同程序的内存状况,对象年龄不是必须到达阈值才会进入老年代。
  • 只要老年代的连续空间大于新生代对象总大小或者历次晋升的平均大小就会进行Minor GC,否则将进行Full GC。
    转至:http://www.ymq.io/2017/08/10/jvm-6-gc-log/