日志概述 通过阅读 Gc 日志,我们可以了解 Java 虚拟机内存分配与回收策略。 内存分配与垃圾回收的参数列表
-XX:+PrintGC
输出 GC 日志。类似:-verbose:gc
<font style="background-color:#FADB14;">-XX:+PrintGCDetails</font>
输出 GC 的详细日志
-XX:+PrintGCTimestamps
输出 GC 的时间戳(以基准时间的形式)
-XX:+PrintGCDatestamps
输出 GcC 的时间戳(以日期的形式,如 2013-05-04T21:53:59.234+0800)
-XX:+PrintHeapAtGC
在进行 GC 的前后打印出堆的信息
-Xloggc:../logs/gc.log
日志文件的输出路径
-XX:+PrintGC(输出简易GC日志信息) 1 2 3 4 5 6 7 8 9 10 11 12 13 -verbose:gc-XX:+PrintGC 这个只会显示总的 GC 堆的变化,如下: [GC (Allocation Failure) 80832K->19298K(227840K),0.0084018 secs] [GC (Metadata GC Threshold) 109499K->21465K(228352K),0.0184066 secs] [Full GC (Metadata GC Threshold) 21465K->16716K(201728K),0.0619261 secs] 参数详解 GC、Full GC:GC的类型,GC只在新生代上进行,Full GC包括永生代,新生代,老年代。 Allocation Failure:GC发生的原因。 80832K-> 19298K:堆在GC前的大小和GC后的大小。 228840k:现在的堆大小。 0.0084018 secs:GC持续的时间。
-XX:+PrintGCDetails(输出详细GC信息) 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 -verbose:gc -XX:+PrintGCDetails 输入信息如下 [GC (Allocation Failure) [PSYoungGen:70640K->10116K(141312K)] 80541K->20017K(227328K),0.0172573 secs] [Times:user=0.03 sys=0.00,real=0.02 secs] [GC (Metadata GC Threshold) [PSYoungGen:98859K->8154K(142336K)] 108760K->21261K(228352K),0.0151573 secs] [Times:user=0.00 sys=0.01,real=0.02 secs] [Full GC (Metadata GC Threshold)[PSYoungGen:8154K->0K(142336K)] [ParOldGen:13107K->16809K(62464K)] 21261K->16809K(204800K),[Metaspace:20599K->20599K(1067008K)],0.0639732 secs] [Times:user=0.14 sys=0.00,real=0.06 secs] 参数解析 GC,Full FC:同样是GC的类型 Allocation Failure:GC原因 PSYoungGen:使用了Parallel Scavenge并行垃圾收集器的新生代GC前后大小的变化 ParOldGen:使用了Parallel Old并行垃圾收集器的老年代GC前后大小的变化 Metaspace: 元数据区GC前后大小的变化,JDK1.8中引入了元数据区以替代永久代 xxx secs:指GC花费的时间 Times:user:指的是垃圾收集器花费的所有CPU时间,sys:花费在等待系统调用或系统事件的时间,real:GC从开始到结束的时间,包括其他进程占用时间片的实际时间。
-XX:+PrintGCTimestamps -XX:+PrintGCDatestamps(格式化) 打开 GC 日志
1 2 3 4 5 6 -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimestamps -XX:+PrintGCDatestamps 输入信息如下 2019-09-24T22:15:24.518+0800: 3.287: [GC (Allocation Failure) [PSYoungGen:136162K->5113K(136192K)] 141425K->17632K(222208K),0.0248249 secs] [Times:user=0.05 sys=0.00,real=0.03 secs] 2019-09-24T22:15:25.559+0800: 4.329: [GC (Metadata GC Threshold) [PSYoungGen:97578K->10068K(274944K)] 110096K->22658K(360960K),0.0094071 secs] [Times: user=0.00 sys=0.00,real=0.01 secs] 2019-09-24T22:15:25.569+0800: 4.338: [Full GC (Metadata GC Threshold) [PSYoungGen:10068K->0K(274944K)][ParoldGen:12590K->13564K(56320K)] 22658K->13564K(331264K),[Metaspace:20590K->20590K(1067008K)],0.0494875 secs] [Times: user=0.17 sys=0.02,real=0.05 secs]
-XX:+PrintHeapAtGC(在进行GC前后打印日志信息) 1 -verbose:gc -XX:+PrintHeapAtGC
-Xloggc:path(打印输出日志) 说明:带上了日期和实践
如果想把 GC 日志存到文件的话,是下面的参数:
日志补充说明
“[GC
“和”[Full GC
“说明了这次垃圾收集的停顿类型,如果有”Full”则说明 GC 发生了”Stop The World”
各个不同垃圾回收器显示的名称
使用 Serial 收集器在新生代的名字是 Default New Generation,因此显示的是”[DefNew
“
使用 ParNew 收集器在新生代的名字会变成”[ParNew
“,意思是”Parallel New Generation”
使用 Parallel scavenge 收集器在新生代的名字是”[PSYoungGen
“,老年代为ParOldGen
使用 G1 收集器的话,会显示为”garbage-first heap”
老年代的收集和新生代道理一样,名字也是收集器决定的
Allocation Failure 表明本次引起 GC 的原因是因为在年轻代中没有足够的空间能够存储新的数据了。
[PSYoungGen:5986K->696K(8704K) ] 5986K->704K(9216K) 中括号内:GC 回收前年轻代大小,回收后大小,(年轻代总大小) 括号外:GC 回收前年轻代和老年代大小,回收后大小,(年轻代和老年代总大小)
user 代表用户态回收耗时,sys 内核态回收耗时,rea 实际耗时。由于多核的原因,时间总和可能会超过 real 时间
1 2 3 4 5 6 7 8 9 Heap(堆) PSYoungGen(Parallel Scavenge收集器新生代)total 9216K,used 6234K [0x00000000ff600000 ,0x0000000100000000 ,0x0000000100000000 ) eden space(堆中的Eden区默认占比是8 )8192K,768 used [0x00000000ff600000 ,0x00000000ffc16b08 ,0x00000000ffe00000 ) from space(堆中的Survivor,这里是From Survivor区默认占比是1 )1024K, 0 % used [0x00000000fff00000 ,0x00000000fff00000 ,0x0000000100000000 ) to space(堆中的Survivor,这里是to Survivor区默认占比是1 ,需要先了解一下堆的分配策略)1024K, 0 % used [0x00000000ffe00000 ,0x00000000ffe00000 ,0x00000000fff00000 ) ParOldGen(老年代总大小和使用大小)total 10240K, used 7001K [0x00000000fec00000 ,0x00000000ff600000 ,0x00000000ff600000 ) object space(显示个使用百分比)10240K,688 used [0x00000000fec00000 ,0x00000000ff2d6630 ,0x00000000ff600000 ) PSPermGen(永久代总大小和使用大小)total 21504K, used 4949K [0x00000000f9a00000 ,0x00000000faf00000 ,0x00000000fec00000 ) object space(显示个使用百分比,自己能算出来)21504K, 238 used [0x00000000f9a00000 ,0x00000000f9ed55e0 ,0x00000000faf00000 )
Minor GC 日志
Full GC 日志
举例 视频:https://www.bilibili.com/video/BV1PJ411n7xZ?p=198&spm_id_from=pageDriver
设置 JVM 参数
1 2 3 4 5 6 7 8 9 10 11 12 13 /* 参数说明: -Xms:初始堆总大小20M,Xmx最大20M -Xmn:新生代大小10M -XX:SurvivorRatio=8:Eden占新生代的8/10,From幸存区和To幸存区各占新生代的1/10 -XX:+PrintGCDetails打印GC细节 -XX:+UseSerialGC:使用最简单的串行垃圾收集器 */ -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8 -XX:+UseSerialGC --测试OOM -Xms10m -Xmx10m -XX:+PrintGCDetails
代码
1 2 3 4 5 6 7 8 9 private static final int _1MB = 1024 * 1024 ;public static void testAllocation () { byte [] allocation1, allocation2, allocation3, allocation4; allocation1 = new byte [2 * _1MB]; allocation2 = new byte [2 * _1MB]; allocation3 = new byte [2 * _1MB]; allocation4 = new byte [4 * _1MB]; }
JDK7下
JDK8
可以用一些工具去分析这些 GC 日志
常用的日志分析工具有:GCViewer、GCEasy、GCHisto、GCLogViewer、Hpjmeter、garbagecat 等
[ ](https://www.infoq.com/articles/azul_gc_in_detail )