虚拟机系列：搞懂虚拟机的日志和日志参数_垃圾收集器

Java特色就是自动垃圾回收，但是有时候垃圾回收并不是很理想，影响到我们自身服务对外提供支持了，此时，就需要根据GC的日志区看下回收的情况，以便调整出更好的效率。

这篇文章就来学习下怎么设置GC日志相关的一些参数以及怎么打印出来的日志分别是什么意思。

不同的垃圾收集器 会有不同的日志输出格式，我本地的环境是jdk1.8的，所以使用的垃圾收集器是默认的Parallel Scavenge+ Parallel old 本文就以这个收集器来测试的。

用参数 ​​-Xms50m -Xmx50m -Xmn20m​​ 来控制这块代码的的堆内存大小。

-Xms50m ： 堆内存最小50M

-Xmx50m ： 堆内存最大50M

-Xmn20m ： 新生代20M，老年代就剩余30M

含义是 Java堆最大最小都是50MB 且不可变化，由于新生代可以分为Eden区和两个Survivor区(from区和to区)，且比例是8:1:1，所以Eden区大概16M，from区和to区各2M。

PSYoungGen：表示垃圾收集器是Parallel Scavenge，回收的是新生代

ParOldGen：表示垃圾收集器是Parallel old，回收的是老年代

1. 最简单参数-XX:+PrintGC

代码如下：

/**
 * vm参数：-Xms50m -Xmx50m -Xmn20m -XX:+PrintGC
 */
public class Allocation {
    private static final int _1MB = 1024 * 1024;

    private static void testAllocation(){
        byte[] one = new byte[6*_1MB];
        byte[] two = new byte[6*_1MB];
        byte[] three = new byte[6*_1MB];
    }
    public static void main(String[] args) {
        testAllocation();
    }
}

日志输出如下：

[GC (Allocation Failure)  15360K->13162K(48640K), 0.0092840 secs]

哎，就这么简短，日志的含义就是触发了一次minor gc，在GC前，堆空间的使用量是15360K(约16M)，GC后的堆空间使用量为13162K(约12M)，整个堆的空间是48640K。最后是本次GC花费的时间 0.0092840 secs 。

PrintGC打印的日志就是这么简短，只能看到总的信息，再具体的就看不到了。

2. 详细的参数：-XX:+PrintGCDetails


配置：-Xms50m -Xmx50m -Xmn20m -XX:+PrintGCDetails


日志输入如下（代码参考上面）：

虚拟机系列：搞懂虚拟机的日志和日志参数_sed_02

我们来逐句解释下上面日志的含义

  1. [GC (Allocation Failure) [PSYoungGen: 15105K->946K(17920K)] 15105K->13242K(48640K), 0.0118657 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
    GC (Allocation Failure)表示发生的minor GC，新生代回收前使用量15105K，回收后使用量946K(总共17920K)，整个堆占用从15105K下降到13242K(整堆的大小是48640K) 。最后是GC花费的时间，user表示用户态CPU耗时，sys表示系统CPU耗时，real表示GC的实际经历的时间
  2. PSYoungGen total 17920K, used 7397K
    年轻代 总空间17920K，已使用了7397K (年轻代=eden+from/to)
  3. eden space 15360K, 42% used
    eden区空间15360K，已使用了42%
  4. from space 2560K, 36% used
    from区空间2560K，已使用了36%
  5. to space 2560K, 0% used
    to区空间2560K，已使用0%
  6. ParOldGen total 30720K, used 12296K / object space 30720K, 40% used
    老年代总空间30720K。已使用了12296K，百分比是40%
  7. Metaspace used 3348K
    元空间的使用，是不占用堆内存的

上面的是GC详细日志的参数输出内容，还有个更详细的参数，回收前回收后都打印出来，上面的日志如果看不出回收信息 还可以通过对比了解。

补充：当老年代内存不足的时候还会发生full GC，日志如下

0.211: [Full GC (Ergonomics) [PSYoungGen: 914K->0K(17920K)] [ParOldGen: 26632K->27351K(30720K)] 27546K->27351K(48640K), [Metaspace: 3350K->3350K(1056768K)], 0.0084485 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]

3. 回收前后详细参数：-XX:+PrintHeapAtGC


-Xms50m -Xmx50m -Xmn20m -XX:+PrintHeapAtGC


日志输入如下（代码参考上面）：

虚拟机系列：搞懂虚拟机的日志和日志参数_堆内存_03

大部分都和上面日志内容是一样的，具体含义参考上面的，不过这次是打印了两个日志，

  • Heap before GC invocations=1 (full 0)：GC发生之前的堆空间的信息
  • Heap after GC invocations=1 (full 0)：GC发生之后堆空间的信息

4. GC发生的时间参数：-XX:PrintGCTimeStamps


-Xms50m -Xmx50m -Xmn20m -XX:+PrintGC -XX:+PrintGCTimeStamps


日志如下(代码参考上面)

0.199: [GC (Allocation Failure)  9268K->6970K(48640K), 0.0073891 secs]

上面中的【0.199】就是这次GC发生的时间 （这个时间是虚拟机启动后的偏移量）

5. 应用程序执行时间参数：-XX:+PrintGCApplicationConcurrentTime


-Xms50m -Xmx50m -Xmn20m -XX:+PrintGCTimeStamps -XX:+PrintGC -XX:+PrintGCApplicationConcurrentTime


日志如下(代码参考上面)

0.236: Application time: 0.0088226 seconds
0.236: [GC (Allocation Failure)  9268K->7018K(48640K), 0.0080782 secs]
0.251: Application time: 0.0074303 seconds

如上输出的是程序执行的时间

6. 应用程序停顿时间参数：-XX:+PrintGCApplicationStoppedTime


-Xms50m -Xmx50m -Xmn20m -XX:+PrintGCTimeStamps -XX:+PrintGC -XX:+PrintGCApplicationStoppedTime


日志如下(代码参考上面)

0.181: [GC (Allocation Failure)  15360K->13210K(48640K), 0.0107874 secs]
0.192: Total time for which application threads were stopped: 0.0109662 seconds, Stopping threads took: 0.0000396 seconds

如上输出的是程序暂停的时间

7. 日志落盘参数：-Xloggc


-Xms50m -Xmx50m -Xmn20m -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:/Users/ajisun/Desktop/logs/gc.log


默认情况下gc的日志会输出在控制台，但是不方便我们保存和分析定位问题，所以虚拟机还提供了日志输出文件的方式 ，用参数 -Xloggc来指定， 启动程序之后日志输出在对应目录下的gc.log文件中

虚拟机系列：搞懂虚拟机的日志和日志参数_堆内存_04

8. 总结

文中总共介绍了7种GC日志相关的参数，我们可以根据这几种参数调整日志的输出。根据日志的内存观察系统的情况以及排查问题。

  • 最简单参数-XX:+PrintGC
  • 详细的参数：-XX:+PrintGCDetails
  • 回收前后详细参数：-XX:+PrintHeapAtGC
  • GC发生的时间参数：-XX:PrintGCTimeStamps
  • 应用程序执行时间参数：-XX:+PrintGCApplicationConcurrentTime
  • 应用程序停顿时间参数：-XX:+PrintGCApplicationStoppedTime
  • 日志落盘参数：-Xloggc

​


我是纪先生，用输出倒逼输入而持续学习，持续分享技术系列文章，以及全网值得收藏好文，欢迎关注公众号，做一个持续成长的技术人。



个人网站


1. 虚拟机系列：jvm运行时堆内存如何分代；

2. 虚拟机系列：jvm中的垃圾回收算法；

3. 虚拟机系列：jvm运行时数据区域；

4. 虚拟机系列：JVM中对象的创建,内存布局和访问定位；

5. 虚拟机系列：JVM中的垃圾收集器；

6. 虚拟机系列：JVM中的内存分配；