文章目录
01-GC日志参数
参数 | 说明 |
---|---|
-verbose:gc | 输出gc日志信息,默认输出到标准输出 |
-XX:+PrintGC | 输出GC日志。类似:-verbose:gc |
-XX:+PrintGCDetails | 在发生垃圾回收时打印内存回收相处的日志, 并在进程退出时输出当前内存各区域分配情况 |
-XX:+PrintGCTimeStamps | 输出GC发生时的时间戳 |
-XX:+PrintGCDateStamps | 输出GC发生时的时间戳(以日期的形式,例如:2013-05-04T21:53:59.234+0800) |
-XX:+PrintHeapAtGC | 每一次GC前和GC后,都打印堆信息 |
-Xloggc: | 表示把GC日志写入到一个文件中去,而不是打印到标准输出中 |
02-GC日志格式
复习:GC分类
针对HotSpot VM的实现,它里面的GC按照回收区域又分为两大种类型:一种是部分收集(Partial GC),一种是整堆收集(Full GC)。
- 部分收集:不是完整收集整个Java堆的垃圾收集。其中又分为:
- 新生代收集(Minor GC / Young GC):只是新生代(Eden\S0,S1)的垃圾收集
- 老年代收集(Minor GC / Old GC):只是老年代的垃圾收集。
- 目前,只有CMS GC会有单独收集老年代的行为。
- 注意,很多时候Major GC会和Full GC混淆使用,需要具体分辨是老年代回收还是整堆回收。
- 混合收集(Mixed GC):收集整个新生代以及部分老年代的垃圾收集。
- 目前只有G1 GC会有这种行为。
- 整堆收集(Full GC):收集整个Java堆和方法区的垃圾收集。
哪些情况会触发Full GC?
- 老年代空间不足
- 方法去空间不足
- 显式调用System.gc()
- Minor GC进入老年代的数据的平均大小 大于 老年代的可用内存
- 大对象直接进入老年,而老年代的可用空间不足
不同GC类的GC细节
/**
* -XX:+PrintCommandLineFlags
*
* -XX:+UseSerialGC:表明新生代使用Serial GC ,同时老年代使用Serial Old GC
*
* -XX:+UseParNewGC:标明新生代使用ParNew GC
*
* -XX:+UseParallelGC:表明新生代使用Parallel GC
* -XX:+UseParallelOldGC : 表明老年代使用 Parallel Old GC
* 说明:二者可以相互激活
*/
public class GCUseTest {
public static void main(String[] args) {
ArrayList<byte[]> list = new ArrayList<>();
while(true){
byte[] arr = new byte[1024 * 10];//10kb
list.add(arr);
// try {
// Thread.sleep(5);
// } catch (InterruptedException e) {
// e.printStackTrace();
// }
}
}
}
GC日志分类
Minor GC
[GC (Allocation Failure) [PSYoungGen: 131072K->21486K(152576K)] 131072K->125625K(500736K), 0.0264772 secs] [Times: user=0.05 sys=0.34, real=0.03 secs]
规律:
[名称: GC前内存占用 -> GC后内存占用 (该区内存总大小)
Full GC
[Full GC (Ergonomics) [PSYoungGen: 21491K->0K(283648K)] [ParOldGen: 234962K->255123K(543744K)] 256454K->255123K(827392K), [Metaspace: 2941K->2941K(1056768K)], 0.0377849 secs] [Times: user=0.45 sys=0.00, real=0.04 secs]
规律:
[名称: GC前内存占用 -> GC后内存占用 (该区内存总大小)
日志结构剖析
垃圾收集器
- 使用Serial收集器在新生代的名字是Defual New Generation,因此显示的是:”[DefNew]"
- 使用ParNew收集器在新生代的名字会变成"[ParNew",意思是“Parallel New Generation"
- 使用Parallel Scavenge收集器在新生代的名字是"[PSYoungGen",这里的JDK1.7使用的就是PSYoungGen
- 使用Parallel Old Generation收集器在老年代的名字是"[ParOldGen"
- 使用G1收集器的话,会显示为“garbage-first heap"
Allocation Failuer
表明本次因此GC的原因是因为在年轻代没有足够的空间能够存储新的数据了。
GC前后情况
通过前面图示,我们发现GC日志的规律一般都是:GC前内存占用 -> GC后内存占用(该区域内存总大小)
[PSYoungGen: 16302K->2044K(18432K)] 16302K->15130K(59392K), 0.0033553 secs]
中括号内:GC胡思后前年轻代堆大小,回收后大小,(年轻代堆总大小)
括号外:GC回收前年轻代和老年代大小,回收后大小,(年轻代和老年代总大小)
GC时间
GC日志中有三个时间:user,sys和real
- user - 进程执行用户态代码(核心之外)所使用的时间。这是执行此进程所使用的实际CPU时间,其他进程和此进程阻塞的时间并不包括在内。垃圾收集的情况下,表示GC线程执行所使用的CPU总时间。
- sys - 进程在内核态消耗所用的时钟时间。即在内核执行系统调用或等待系统时间所使用的CPU时间
- real -这个时间包括其他进程使用的时间片和进程阻塞的时间(比如等待I/O完成)。对于并行gc,这个数字应该接近(用户时间+系统时间)除以垃圾收集器使用的线程数。
由于多核的原因,一般的GC事件中,real time是小于sys + user time的,因为一般是多个线程并发的去做GC,所以real time是要小于sys + user time的。如果real > sys + user的话,则应用可能存在下列问题:IO负载非常重要或者是CPU不够用。
Minor GC 日志解析
2020-11-20T17:19:43.265-0800
添加-XX:+PrintGCDateStamps参数
日志打印时间 日期格式 如
2013-05-04T21:53:59.234+0800
0.822:
添加-XX:+PrintGCTimeStamps该参数
gc发生时,Java虚拟机启动以来经过的秒数
[GC(Allocation Failure)
发生了一次垃圾回收,这是一次Minior GC。它不区分新生代还是老年代GC,括号里的内容是gc发生的原因,这里的Allocation Failure的原因是新生代中没有足够区域能够存放需要分配的数据而失败
[PSYoungGen:76800K->8433K(89600K)
PSYoungGen:表示GC发生的区域,区域名称与使用的GC收集器是密切相关的
- Serial收集器:Default New Generation 显示Defnew
- ParNew收集器:ParNew
- Parallel Scanvenge收集器:PSYoung
- 老年代和新生代同理,也是和收集器名称相关
76800K->8433K(89600K):GC前该内存区域已使用容量->GC后盖区域容量(该区域总容量)
- 如果是新生代,总容量则会显示整个新生代内存的9/10,即eden+from/to区
- 如果是老年代,总容量则是全身内存大小,无变化
76800K->8449K(294400K)
虽然本次是Minor GC,只会进行新生代的垃圾收集,但是也肯定会打印堆中总容量相关信息
在显示完区域容量GC的情况之后,会接着显示整个堆内存区域的GC情况:GC前堆内存已使用容量->GC后堆内存容量(堆内存总容量),并且堆内存总容量 = 9/10 新生代 + 老年代,然后堆内存总容量肯定小于初始化的内存大小
,0.0088371
整个GC所花费的时间,单位是秒
[Times:user=0.02 sys=0.01,real=0.01 secs]
- user:指CPU工作在用户态所花费的时间
- sys:指CPU工作在内核态所花费的时间
- real:指在此次事件中所花费的总时间
Full GC日志解析
2020-11-20T17:19:43.794-0800
添加-XX:+PrintGCDateStamps参数
日志打印时间 日期格式 如
2013-05-04T21:53:59.234+0800
1.351
添加-XX:+PrintGCTimeStamps该参数
gc发生时,Java虚拟机启动以来经过的秒数
Full GC(Metadata GCThreshold)
括号中是gc发生的原因,原因:Metaspace区不够用了。
除此之外,还有另外两种情况会引起Full GC,如下:
1、Full GC(FErgonomics)
原因:JVM自适应调整导致的GC
2、Full GC(System)
原因:调用了System.gc()方法
[PSYoungGen: 100082K->0K(89600K)]
PSYoungGen:表示GC发生的区域,区域名称与使用的GC收集器是密切相关的
- Serial收集器:Default New Generation 显示DefNew
- ParNew收集器:ParNew
- Parallel Scanvenge收集器:PSYoungGen
- 老年代和新生代同理,也是和收集器名称相关
10082K->0K(89600K):GC前该内存区域已使用容量->GC该区域容量(该区域总容量)
- 如果是新生代,总容量会显示整个新生代内存的9/10,即eden+from/to区
- 如果是老年代,总容量则是全部内存大小,无变化
ParOldGen:32K->9638K(204800K)
老年代区域没有发生GC,因此本次GC是metaspace引起的
10114K->9638K(294400K),
在显示完区域容量GC的情况之后,会接着显示整个堆内存区域的GC情况:GC前堆内存已使用容量->GC后堆内存容量(堆内存总容量),并且堆内存总容量 = 9/10 新生代 + 老年代,然后堆内存总容量肯定小于初始化的内存大小
[Meatspace:20158K->20156K(1067008K)],
metaspace GC 回收2K空间
03-GC日志分析工具
上面介绍了GC日志的打印及含义,但是GC日志看起来比较麻烦,本节将会介绍一下GC日志可视化分析工具GCeasy和GCviewer等。通过GC日志可视化分析工具,我们可以很方便的看到JVM各个分代的内存使用情况、垃圾回收次数、垃圾回收的原因、垃圾回收占用的时间、吞吐量等,这些是指标在我们进行JVM调优的时候是很有用的。
如果想把GC日志存在文件的话,是下面这个参数:
-Xloggc:/path/to/gc.log
然后就可以用一些空间去分析这些gc日志。
GCeasy(比较实用)
GCeasy是一款在线的GC日志分析器,可以通过GC日志分析、进行内存泄漏检查、GC暂停原因分析、JVM配置建议优化等功能。而且是可以免费试用的。
GCViewer(停止维护)
上面介绍了一款在线的GC日志分析器,下面介绍一个离线版的GCViewer
GCViewer是一个免费的、开源的分析小工具,用于可视化查看由SUN/Oracle,IBM,HP和BEA Java虚拟机产生的垃圾收集器的日志。
GCViewer用于可视化Java VM选项-verbose:gc和.NET生成的数据-Xloggc:。它还计算与垃圾回收相关的性能指标(吞吐量I累积的暂停,最长的暂停等)。当通过更改世代大小或设置初始堆大小来调整应用程序的垃圾时,此功能非常有用。
下载地址:https://github.com/chewiebug/GCViewer/wiki/Changelog
使用
双击或者java -jar gcviewer-1.37-SNAPSHOT.jar
其他工具(可以忽略)
GChisto
- GChisto是一款专业分析gc日志的工具,可以通过gc日志来分析:MinorGC、Full GC的次数、频率、持续时间等,通过列表、报表、图表等不同形式来反应gc的情况。
- 虽然界面略显粗略,但是功能还是不错的。
HPjmeter
- 工具很强大,但是只能打开由以下参数生成的GC log,-verbose:gc -Xloggc:gc.log。添加其他参数生成的gc.log无法打开
- HPjmeter集成了以前的HPjtune功能,可以分析在HP机器上产生的垃圾回收日志文件