JVM GC日志查看分析(四)

1
-XX:NewSize=5242880 -XX:MaxNewSize=5242880 -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:gc.log

上面”-XX:InitialHeapSize” 和 “-XX:MaxHeapSize”就是初始堆大小和最大堆大小,”-XX:NewSize”和”-XX:MaxNewSize”是初始新生代大小和最大新生代大小,”-XX:PretenureSizeThreshold=10485760”指定了大对象阈值是10MB。

相当于给堆内存分配10MB内存空间,其中新生代5MB内存空间,其中Eden区占4MB,每个Survivor区占0.5MB(8:1:1默认),大对象必须超过10MB才会直接进入老年代,年轻代使用ParNew垃圾回收器,老年代使用CMS垃圾回收器。

-XX:+PrintGCDetail:打印详细的gc日志

-XX:+PrintGCTimeStamps:这个参数设置可以打印出来每次GC发生时间

-Xloggc:gc.log:这个参数可以设置将gc日志写入一个磁盘文件

程序代码如下以及运行之后打印出来的GC日志:

1
2
3
4
5
6
7
8
9
10
11
12
13
public class YoungGCTest {
public static void main(String args[]){
// 1M
byte[] barry1 = new byte[1024 * 1024];
// 1M
barry1 = new byte[1024 * 1024];
// 1M
barry1 = new byte[1024 * 1024];
barry1 = null;
// 此处需要进行垃圾回收
byte[] barry2 = new byte[1024 * 1024 * 2];
}
}
1
2
3
4
5
6
7
8
9
10
11
12
13
Java HotSpot(TM) 64-Bit Server VM (25.144-b01) for windows-amd64 JRE (1.8.0_144-b01), built on Jul 21 2017 21:57:33 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 8324764k(3970340k free), swap 16647628k(11305344k free)
CommandLine flags: -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:MaxNewSize=5242880 -XX:MaxTenuringThreshold=6 -XX:NewSize=5242880 -XX:OldPLABSize=16 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseLargePagesIndividualAllocation -XX:+UseParNewGC
0.324: [GC (Allocation Failure) 0.337: [ParNew: 3395K->510K(4608K), 0.0014480 secs] 3395K->1790K(9728K), 0.0151349 secs] [Times: user=0.00 sys=0.00, real=0.02 secs]
0.339: [GC (Allocation Failure) 0.339: [ParNew: 2678K->108K(4608K), 0.0012876 secs] 3957K->1896K(9728K), 0.0013118 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
Heap
par new generation total 4608K, used 2226K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000)
eden space 4096K, 51% used [0x00000000ff600000, 0x00000000ff811660, 0x00000000ffa00000)
from space 512K, 21% used [0x00000000ffa00000, 0x00000000ffa1b300, 0x00000000ffa80000)
to space 512K, 0% used [0x00000000ffa80000, 0x00000000ffa80000, 0x00000000ffb00000)
concurrent mark-sweep generation total 5120K, used 1787K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
Metaspace used 3435K, capacity 4496K, committed 4864K, reserved 1056768K
class space used 375K, capacity 388K, committed 512K, reserved 1048576K

一次GC日志概要说明

1
0.118: [GC (Allocation Failure) 0.118: [ParNew: 3412K->510K(4608K), 0.0019145 secs] 3412K->1819K(9728K), 0.0020001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
  • GC (Allocation Failure) 表示发生了一次GC

    上面需要分配一个2MB的内存空间,结果Eden区内存不足,所以就出现了“Allocation Failure”,也就是对象分配失败,所以就触发了一次Young GC

  • GC发生时间

    0.118GC发生时间,也就是代表程序运行0.118秒之后,系统就发生了GC,大概也就是100都毫秒之后吧

  • GC类型[ParNew: 3395K->510K(4608K), 0.0014480 secs]

    ParNew:Young GC,也就是执行了ParNew垃圾回收器

    3395K->510K(4608K):4608(4.5MB)代表年轻代内存空间大小;3395K->510K意思是Eden区所占用的空间为3395KB,然后GC之后还剩余510KB;0.0014480 secs:本次GC所花费时间

  • 3412K->1819K(9728K), 0.0020001 secs

    9728K:整个堆空间大小9.5MB;GC前整个堆内存使用3412KB,GC之后使用1819KB

  • [Times: user=0.00 sys=0.00, real=0.00 secs]

    GC所消耗时间,这里是以秒为单位,所以基本上就是为0了

以上基本上就是对一次GC日志的简要说明;不过从上面的日志看,按照代码分析,理论上就只会执行一次GC,即前面申请了3MB的对象,然后把应用设置为空,即这3MB的对象没有引用关联了,代表是可回收的,然后申请2MB的对象,申请不下之后执行YoungGC,也就是上面文字概要说明的GC 情况;

至于最后的一次YoungGC是由于程序执行结束后,它又触发了一次GC

Heap整个堆的GC日志信息如下:

1
2
3
4
par new generation   total 4608K, used 2226K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000)
eden space 4096K, 51% used [0x00000000ff600000, 0x00000000ff811660, 0x00000000ffa00000)
from space 512K, 21% used [0x00000000ffa00000, 0x00000000ffa1b300, 0x00000000ffa80000)
to space 512K, 0% used [0x00000000ffa80000, 0x00000000ffa80000, 0x00000000ffb00000)

ParNew 垃圾回收器执行情况,一共4608(4.5MB)

Eden:4096KB(4MB),使用51%,相当于最后2MB的空间

S0:512K(0.5MB)使用21%,其他晋升的对象内存空间

S1:512K(0.5MB)使用0%

1
2
3
concurrent mark-sweep generation total 5120K, used 1787K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
Metaspace used 3435K, capacity 4496K, committed 4864K, reserved 1056768K
class space used 375K, capacity 388K, committed 512K, reserved 1048576K

CMS垃圾回收器执行情况,一共5120K(5MB),使用了1787K

Metaspace:元数据空间与Class空间、类信息、常量等;

分享到 评论