通过阅读GC日志,我们可以了解Java虛拟机内存分配与回收策略。
内存分配与垃圾回收的参数列表
- -XX: +PrintGC 输出GC日志。类似: -verbose:gc
- -XX: +PrintGCDetails 输出GC的详细日志
- -XX: +PrintGCTimeStamps 输出GC的时间戳(以基准时间的形式)
- -XX: +PrintGCDateStamps输出GC的时间戳(以日期的形式,如2013一05一04T21 : 53:59.234+0800 )
- -XX: +PrintHeapAtGC 在进行GC的前后打印出堆的信息
- -Xloggc: . . /logs/gc. log日志文件的输出路径
/*
* JVM参数:-Xms60m -Xmx60m
*/
public class GCLogTest {
public static void main(String[] args) {
ArrayList<byte[]> list = new ArrayList<>();
for (int i = 0; i < 500; i++){
byte[] arr = new byte[1024 * 100];
list.add(arr);
}
}
}
打开GC日志:
-verbose:gc
这个只会显示总的GC堆的变化, 如下:
[GC (Allocation Failure) 15267K->13850K(58880K), 0.0030993 secs]
[GC (Allocation Failure) 29150K->29068K(58880K), 0.0042701 secs]
[Full GC (Ergonomics) 29068K->28870K(58880K), 0.0072675 secs]
[Full GC (Ergonomics) 44230K->44173K(58880K), 0.0083393 secs]
参数解析:
GC、Full GC: GC的类型,GC只在新生代上进行,Full GC包括永久代,新生代, 老年代。
Allocation Failure: GC发生的原因。
15267K->13850K:堆在GC前的大小和GC后的大小。
58880K:现在的堆大小。
0.0030993 secs: GC持续的时间。
但是如果想查看更详细的信息, 比如新生代在GC前后的变化或者老年代在GC前后的变化等,
就需要使用这个参数:
-XX:+PrintGCDetaiis
输出信息如下:
[GC (Allocation Failure) [PSYoungGen: 15267K->2548K(17920K)] 15267K->13850K(58880K), 0.0028485 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[GC (Allocation Failure) [PSYoungGen: 17848K->2556K(17920K)] 29150K->29068K(58880K), 0.0036911 secs] [Times: user=0.05 sys=0.08, real=0.00 secs]
[Full GC (Ergonomics) [PSYoungGen: 2556K->0K(17920K)] [ParOldGen: 26512K->28870K(40960K)] 29068K->28870K(58880K), [Metaspace: 3491K->3491K(1056768K)], 0.0066634 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[Full GC (Ergonomics) [PSYoungGen: 15360K->3000K(17920K)] [ParOldGen: 28870K->40872K(40960K)] 44230K->43872K(58880K), [Metaspace: 3491K->3491K(1056768K)], 0.0056879 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
Heap
PSYoungGen total 17920K, used 10054K [0x00000000fec00000, 0x0000000100000000, 0x0000000100000000)
eden space 15360K, 65% used [0x00000000fec00000,0x00000000ff5d1938,0x00000000ffb00000)
from space 2560K, 0% used [0x00000000ffd80000,0x00000000ffd80000,0x0000000100000000)
to space 2560K, 0% used [0x00000000ffb00000,0x00000000ffb00000,0x00000000ffd80000)
ParOldGen total 40960K, used 40872K [0x00000000fc400000, 0x00000000fec00000, 0x00000000fec00000)
object space 40960K, 99% used [0x00000000fc400000,0x00000000febea1a0,0x00000000fec00000)
Metaspace used 3498K, capacity 4498K, committed 4864K, reserved 1056768K
class space used 387K, capacity 390K, committed 512K, reserved 1048576K
参数解析:
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从开始到结束的时间,包括其他进程占用时间片的实际时间。
加上GC时间:
-XX:+PrintGCTimeStamps
0.101: [GC (Allocation Failure) [PSYoungGen: 15267K->2552K(17920K)] 15267K->13802K(58880K), 0.0029209 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
0.106: [GC (Allocation Failure) [PSYoungGen: 17852K->2460K(17920K)] 29102K->29012K(58880K), 0.0035817 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
0.109: [Full GC (Ergonomics) [PSYoungGen: 2460K->0K(17920K)] [ParOldGen: 26552K->28870K(40960K)] 29012K->28870K(58880K), [Metaspace: 3491K->3491K(1056768K)], 0.0073870 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
0.118: [Full GC (Ergonomics) [PSYoungGen: 15360K->3000K(17920K)] [ParOldGen: 28870K->40872K(40960K)] 44230K->43872K(58880K), [Metaspace: 3491K->3491K(1056768K)], 0.0042181 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
-XX:+PrintGCDateStamps
2022-09-08T11:37:30.424+0800: [GC (Allocation Failure) [PSYoungGen: 15267K->2552K(17920K)] 15267K->13810K(58880K), 0.0027859 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2022-09-08T11:37:30.428+0800: [GC (Allocation Failure) [PSYoungGen: 17852K->2552K(17920K)] 29110K->29020K(58880K), 0.0034724 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2022-09-08T11:37:30.431+0800: [Full GC (Ergonomics) [PSYoungGen: 2552K->0K(17920K)] [ParOldGen: 26468K->28870K(40960K)] 29020K->28870K(58880K), [Metaspace: 3491K->3491K(1056768K)], 0.0072200 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2022-09-08T11:37:30.440+0800: [Full GC (Ergonomics) [PSYoungGen: 15360K->3000K(17920K)] [ParOldGen: 28870K->40872K(40960K)] 44230K->43872K(58880K), [Metaspace: 3491K->3491K(1056768K)], 0.0050960 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
如果想把GC日志存到文件的话, 是下面这个参数:
-Xloggc:gc.log
生成的文件在项目路径下
可以用一些工具去分析这些gc日志。
常用的日志分析工具有: GCViewer、GCEasy、GCHisto、GCLogViewer 、Hpjmeter、 garbagecat等。