学习JVM-GC收集器

1. 前言

  在上一篇文章中,介绍了JVM中垃圾回收的原理和算法。介绍了通过引用计数和对象可达性分析的算法来筛选出已经没有使用的对象,然后介绍了垃圾收集器中使用的三种收集算法:标记-清除、标记-整理、标记-复制算法。

  介绍完原理,在这篇文章中,我们将介绍当前JVM中已经实现的垃圾收集器,以及与收集器主题相关的一些内容。

  首先,我们将在上一篇文章中提到分代收集机制的基础上,介绍下现代商业JVM中普遍采用的分代回收策略。然后,按照内存分代划分的维度介绍下当前JVM中实现的收集器。最后,学习分析不同收集器的GC日志,然后结合日志分析,学习下不同情况下的对象分配策略。

2. 分代收集策略

  我们知道,当对象被创建的时候,就会给对象分配一块内存空间,而一旦对象的生命周期结束,我们就需要回收这块内存空间。但是,在一个应用程序中,不同的对象存在的时间,或者说每个对象的生命周期都是不同的。

  有些对象生命周期很短,比如Web应用程序中的request对象,它的生命周期和请求是对应的,当请求完成以后,该request对象就结束了它的职责,需要被收集器回收。有些对象的生命周期很长,比如一些全局的对象,可能会伴随整个应用程序的生命周期而存在。

  在上图中,横轴表示对象的生命周期长短,竖轴表示对应生命周期下的对象数量。观察蓝色的区域,我们可以看到大部分的对象的生命周期都很短,而生命周期长的对象,它们的数量占据了小部分。

  考虑到不同生命周期的对象的分布情况,为了合理的处理不同生命周期的对象回收问题。现代JVM的对不同生命周期的对象进行分类,对堆内存区域进行逻辑划分。按照对象的存活时间长短,将内存分为:年轻代、老年代和永久代(在Java8中去掉了永久代,以元数据空间代替)。这里我们主要关注年轻代和老年代的GC。

  JVM提供了两个参数来控制JVM堆的大小:-XX:InitialHeapSize(-Xms)-XX:MaxHeapSize(-Xmx)。JVM会根据应用程序使用内存的情况,动态扩展堆内存的大小,上图中的Virtual表示的区域,表示的就是可以扩展的内存空间。

  比如,我们可以将JVM的堆内存设置为256M,最大512M的大小,那么可以这么设置:-Xms256m -Xmx512m。如果将Xms的值和Xmx的值设置为相同,那么JVM将不能动态扩展堆内存,它的初始堆内存和最大堆内存是相同的。

2.1 年轻代

  在年轻代中,又将内存细分为Eden区和2个Survivor区,正常情况下,对象都是在Eden区被分配的。由于在年轻代,GC算法采用的是“标记-复制”算法,所以划分出了两个Survivor区,用于在执行复制算法的时候交替存放存活的对象。

  在JVM运行的时候,在年轻代,只有Eden区和其中的一个Survivor区会被使用,而另外一个Surviro区是闲置的。当在年轻代进行GC的时候,会将这次GC以后存活的对象移动到其中闲置的Survivor区中,然后清空Eden区和之前的Survivor区。这样,就可以保证每次都有一快空闲的内存用于复制。

  JVM参数NewSizeMaxNewSize分别可以控制年轻代的初始大小和最大的大小。通过设置这两个参数,可以手动控制JVM中年轻代的大小,比如-XX:NewSize=100m将年轻代的大小初始化为100m。除了通过固定值来控制年轻代的大小,还可以通过参数NewRatio来按比例控制年轻代的大小,NewRatio的值表示年轻代和老年代的比值,比如:-XX:NewRatio=6 就表示,年轻代:老年代 = 1:6,所以年轻代占据了堆内存的1/7,而老年代则占据了6/7。

  对于年轻代中的Eden区和Survivor区的大小分配,JVM提供了SurvivorRatio这个参数来控制两块区域的大小。和NewRatio一样,这个值也是用于控制Eden区和两个Survivor区的大小比例的,比如:-XX:SurvivorRatio = 8,那么表示Eden : 一个Survivor = 8 : 1,那么Eden区就占据了年轻代中的8 / 10,而两个Survivor区分别占据了 1 / 10。

  我们一般把在年轻代中进行的GC称为Minor GC

2.2 老年代

  当对象在年轻代中经历了多次Minor GC以后仍旧存活,那么当达到一定的年龄(经历过一次Minor GC,年龄加1)以后,仍旧存活的对象就会被移动到老年代中。在老年代中的对象,一般是那些存活时间相对比较长的对象。正常情况下,在老年代的GC不会像年轻代那么频繁,老年代的GC收集器,一般采用"标记-清除"算法或"标记-整理"算法来回收垃圾对象。

  老年代中的对象,除了通过年轻代提升上来的长生命周期的对象以外,在一些特殊的情况下,也会在老年代中直接分配对象。具体情况,在下面的对象分配策略一节,会具体讲述。

  老年代的GC我们一般称为Major GC

3. GC收集器

  前面,我们介绍了JVM中对堆内存进行了分代的划分。目的,就是为了可以按照不同的对象特点,合理的利用不同的垃圾收集算法来处理垃圾对象。接下来,我们来看下针对不同的内存区域和使用场景,JVM中已经实现的那些GC收集器,了解下不同的收集器的特性和适用场景以及它们的优缺点。

3.1 收集器概览

  Oracle Hotspot JVM中实现了多种垃圾收集器,针对不同的年龄代内存中的对象的生存周期和应用程序的特点,实现了多款垃圾收集器。

  单线程GC收集器包括Serial和SerialOld这两款收集器,分别用于年轻代和老年代的垃圾收集工作。后来,随着CPU多核的普及,为了更好了利用多核的优势,开发了ParNew收集器,这款收集器是Serial收集器的多线程版本。

  多线程收集器还包括Parallel Scavenge和ParallelOld收集器,这两款也分别用于年轻代和老年代的垃圾收集工作,不同的是,它们是两款可以利用多核优势的多线程收集器。

  相对来说更加复杂的还有CMS收集器。这款收集器,在运行的时候会分多个阶段进行垃圾收集,而且在一些阶段是可以和应用线程并行运行的,提高了这款收集器的收集效率。

  其中最先进的收集器,要数G1这款收集器了。这款收集器是当前最新发布的收集器,是一款面向服务端垃圾收集器。

  上面简单介绍了多款不同的垃圾收集器,虽然它们的特性不同,但是有些GC收集器可以组合使用来应对不同的应用的业务场景。下图给出了不同收集器以及它们之间是否兼容,互相兼容的收集器可以组合使用。

  接下来,我们来分别介绍下上面提到的那些GC收集器以及它们各自的特点。

3.2 年轻代收集器

  年轻代收集器包括Serial收集器、ParNew收集器以及Parallel Scavenge收集器。

Serial收集器

  Serial收集器是一款年轻代的垃圾收集器,使用标记-复制垃圾收集算法。它是一款发展历史最悠久的垃圾收集器。Serial收集器只能使用一条线程进行垃圾收集工作,并且在进行垃圾收集的时候,所有的工作线程都需要停止工作,等待垃圾收集线程完成以后,其他线程才可以继续工作。工作过程可以简单的用下图来表示:  

   从图中可以看到,Serial收集器工作的时候,其他用户线程都停止下来,等到GC过程结束以后,它们才继续执行。而且处理GC过程的只有一条线程在执行。由于Serial收集器的这种工作机制,所以在进行垃圾收集过程中,会出现STW(Stop The World)的情况,应用程序会出现停顿的状况。如果垃圾收集的时间很长,那么停顿时间也会很长,这样会导致系统响应变的迟钝,影响系统的时候。

  虽然这款年迈的垃圾收集器只能使用单核CPU,但是正是由于它不能利用多核,在一些场景下,减少了很多线程的上下文切换的开销,可以在进行垃圾收集过程中专心处理GC过程,而不会被打断,所以如果GC过程很短暂,那么这款收集器还是非常简单高效的。

  由于Serial收集器只能使用单核CPU,在现代处理器基本都是多核多线程的情况下,为了充分利用多核的优势,出现了多线程版本的垃圾收集器,比如下面将要说到的ParNew收集器。

ParNew收集器

  ParNew垃圾收集器是Serial收集器的多线程版本,使用标记-复制垃圾收集算法。为了利用CPU多核多线程的优势,ParNew收集器可以运行多个收集线程来进行垃圾收集工作。这样可以提高垃圾收集过程的效率。

  和上面的Serial收集器比较,可以明显看到,在垃圾收集过程中,GC线程是多线程执行的,而在Serial收集器中,只有一个GC线程在处理垃圾收集过程。ParNew收集器在很多时候都是作为服务端的年轻代收集器的选择,除了它具有比Serial收集器更好的性能外,还有一个原因是,多线程版本的年轻代收集器中,只有它可以和CMS这款优秀的老年代收集器一起搭配搭配使用。

  作为一款多线程收集器,当它运行在单CPU的机器上的时候,由于不能利用多核的优势,在线程收集过程中可能会出现频繁上下文切换,导致额外的开销,所以在单CPU的机器上,ParNew收集器的性能不一定好于Serial这款单线程收集器。如果机器是多CPU的,那么ParNew还是可以很好的提高GC收集的效率的。

  ParNew收集器默认开启的垃圾收集线程数是和当前机器的CPU数量相同的,为了控制GC收集线程的数量,可以通过参数-XX:ParallelGCThreads来控制垃圾收集线程的数量。

Parallel Scavenge收集器

  Parallel Scavenge收集器是是一款年轻代的收集器,它使用标记-复制垃圾收集算法。和ParNew一样,它也会一款多线程的垃圾收集器,但是它又和ParNew有很大的不同点。

  Parallel Scavenge收集器和其他收集器的关注点不同。其他收集器,比如ParNew和CMS这些收集器,它们主要关注的是如何缩短垃圾收集的时间。而Parallel Scavenge收集器关注的是如何控制系统运行的吞吐量。这里说的吞吐量,指的是CPU用于运行应用程序的时间和CPU总时间的占比,吞吐量 = 代码运行时间 / (代码运行时间 + 垃圾收集时间)。如果虚拟机运行的总的CPU时间是100分钟,而用于执行垃圾收集的时间为1分钟,那么吞吐量就是99%。

  直观上,好像以缩短垃圾收集的停顿时间为目的和以控制吞吐量为目的差不多,但是适用的场景却不同。对于那些桌面应用程序,为了得到良好的用户体验,在交互过程中,需要得到快速的响应,所以系统的停顿时间要尽可能的快以避免影响到系统的响应速度,只要保证每次停顿的时间很短暂,假设每次停顿时间为10ms,那么即使发生很多次的垃圾收集过程,假设1000次,也不会影响到系统的响应速度,不会影响到用户的体验。对于一些后台计算任务,它不需要和用户进行交互,所以短暂的停顿时间对它而言并不需要,对于计算任务而言,更好的利用CPU时间,提高计算效率才是需要的,所以假设每次停顿时间相对很长,有100ms,而由于花费了很长的时间进行垃圾收集,那么垃圾收集的次数就会降下来,假设只有5次,那么显然,使用以吞吐量为目的的垃圾收集器,可以更加有效的利用CPU来完成计算任务。所以,在用户界面程序中,使用低延迟的垃圾收集器会有很好的效果,而对于后台计算任务的系统,高吞吐量的收集器才是首选。

  Parallel Scavenge收集器提供了两个参数用于控制吞吐量。-XX:MaxGCPauseMillis用于控制最大垃圾收集停顿时间,-XX:GCTimeRatio用于直接控制吞吐量的大小。MaxGCPauseMillis参数的值允许是一个大于0的整数,表示毫秒数,收集器会尽可能的保证每次垃圾收集耗费的时间不超过这个设定值。但是如果这个这个值设定的过小,那么Parallel Scavenge收集器为了保证每次垃圾收集的时间不超过这个限定值,会导致垃圾收集的次数增加和增加年轻代的空间大小,垃圾收集的吞吐量也会随之下降。GCTimeRatio这个参数的值应该是一个0-100之间的整数,表示应用程序运行时间和垃圾收集时间的比值。如果把值设置为19,即系统运行时间 : GC收集时间 = 19 : 1,那么GC收集时间就占用了总时间的5%(1 / (19 + 1) = 5%),该参数的默认值为99,即最大允许1%(1 / (1 + 99) = 1%)的垃圾收集时间。

  Parallel Scavenge收集器还有一个参数:-XX:UseAdaptiveSizePolicy。这是一个开关参数,当开启这个参数以后,就不需要手动指定新生代的内存大小(-Xmn)、Eden区和Survivor区的比值(-XX:SurvivorRatio)以及晋升到老年代的对象的大小(-XX:PretenureSizeThreshold)等参数了,虚拟机会根据当前系统的运行情况动态调整合适的设置值来达到合适的停顿时间和合适的吞吐量,这种方式称为GC自适应调节策略。

  Parallel Scavenge收集器也是一款多线程收集器,但是由于目的是为了控制系统的吞吐量,所以这款收集器也被称为吞吐量优先收集器。

3.3 老年代收集器

  老年代收集包括:Serial Old收集器、Parallel Old收集器以及CMS收集器。

Serial Old收集器

  Serial Old收集器是Serial收集器的老年代版本,它也是一款使用"标记-整理"算法的单线程的垃圾收集器。这款收集器主要用于客户端应用程序中作为老年代的垃圾收集器,也可以作为服务端应用程序的垃圾收集器,当它用于服务端应用系统中的时候,主要是在JDK1.5版本之前和Parallel Scavenge年轻代收集器配合使用,或者作为CMS收集器的后备收集器。

Parallel Old收集器

  Parallel Old收集器是Parallel Scavenge收集器的老年代版本,使用"标记-整理"算法。这个收集器是在JDK1.6版本中出现的,所以在JDK1.6之前,新生代的Parallel Scavenge只能和Serial Old这款单线程的老年代收集器配合使用。Parallel Old垃圾收集器和Parallel Scavenge收集器一样,也是一款关注吞吐量的垃圾收集器,和Parallel Scavenge收集器一起配合,可以实现对Java堆内存的吞吐量优先的垃圾收集策略。

  Parallel Old垃圾收集器的工作原理和Parallel Scavenge收集器类似。

  

CMS收集器

  CMS收集器是目前老年代收集器中比较优秀的垃圾收集器。CMS是Concurrent Mark Sweep,从名字可以看出,这是一款使用"标记-清除"算法的并发收集器。CMS
垃圾收集器是一款以获取最短停顿时间为目标的收集器。由于现代互联网中的应用,比较重视服务的响应速度和系统的停顿时间,所以CMS收集器非常适合在这种场景下使用。

  CMS收集器的运行过程相对上面提到的几款收集器要复杂一些。  

  从图中可以看出,CMS收集器的工作过程可以分为4个阶段:

  • 初始标记(CMS initial mark)阶段
  • 并发标记(CMS concurrent mark)阶段
  • 重新标记(CMS remark)阶段
  • 并发清除(CMS concurrent sweep)阶段

  从图中可以看出,在这4个阶段中,初始标记和重新标记这两个阶段都是只有GC线程在运行,用户线程会被停止,所以这两个阶段会发送STW(Stop The World)。初始标记阶段的工作是标记GC Roots可以直接关联到的对象,速度很快。并发标记阶段,会从GC Roots 出发,标记处所有可达的对象,这个过程可能会花费相对比较长的时间,但是由于在这个阶段,GC线程和用户线程是可以一起运行的,所以即使标记过程比较耗时,也不会影响到系统的运行。重新标记阶段,是对并发标记期间因用户程序运行而导致标记变动的那部分记录进行修正,重新标记阶段耗时一般比初始标记稍长,但是远小于并发标记阶段。最终,会进行并发清理阶段,和并发标记阶段类似,并发清理阶段不会停止系统的运行,所以即使相对耗时,也不会对系统运行产生大的影响。

  由于并发标记和并发清理阶段是和应用系统一起执行的,而初始标记和重新标记相对来说耗时很短,所以可以认为CMS收集器在运行过程中,是和应用程序是并发执行的。由于CMS收集器是一款并发收集和低停顿的垃圾收集器,所以CMS收集器也被称为并发低停顿收集器。

  虽然CMS收集器可以是实现低延迟并发收集,但是也存在一些不足。

  首先,CMS收集器对CPU资源非常敏感。对于并发实现的收集器而言,虽然可以利用多核优势提高垃圾收集的效率,但是由于收集器在运行过程中会占用一部分的线程,这些线程会占用CPU资源,所以会影响到应用系统的运行,会导致系统总的吞吐量降低。CMS默认开始的回收线程数是(Ncpu + 3) / 4,其中Ncpu是机器的CPU数。所以,当机器的CPU数量为4个以上的时候,垃圾回收线程将占用不少于%25的CPU资源,并且随着CPU数量的增加,垃圾回收线程占用的CPU资源会减少。但是,当CPU资源少于4个的时候,垃圾回收线程占用的CPU资源的比例会增大,会影响到系统的运行,假设有2个CPU的情况下,垃圾回收线程将会占据超过50%的CPU资源。所以,在选用CMS收集器的时候,需要考虑,当前的应用系统,是否对CPU资源敏感。

  其次,CMS收集器在处理垃圾收集的过程中,可能会产生浮动垃圾,由于它无法处理浮动垃圾,所以可能会出现Concurrent Mode Failure问题而导致触发一次Full GC。所谓的浮动垃圾,是由于CMS收集器的并发清理阶段,清理线程是和用户线程一起运行,如果在清理过程中,用户线程产生了垃圾对象,由于过了标记阶段,所以这些垃圾对象就成为了浮动垃圾,CMS无法在当前垃圾收集过程中集中处理这些垃圾对象。由于这个原因,CMS收集器不能像其他收集器那样等到完全填满了老年代以后才进行垃圾收集,需要预留一部分空间来保证当出现浮动垃圾的时候可以有空间存放这些垃圾对象。在JDK 1.5中,默认当老年代使用了68%的时候会激活垃圾收集,这是一个保守的设置,如果在应用中老年代增长不是很快,可以通过参数"-XX:CMSInitiatingOccupancyFraction"控制触发的百分比,以便降低内存回收次数来提供性能。在JDK 1.6中,CMS收集器的激活阀值变成了92%。如果在CMS运行期间没有足够的内存来存放浮动垃圾,那么就会导致"Concurrent Mode Failure"失败,这个时候,虚拟机将启动后备预案,临时启动Serial Old收集器来对老年代重新进行垃圾收集,这样会导致垃圾收集的时间边长,特别是当老年代内存很大的时候。所以对参数"-XX:CMSInitiatingOccupancyFraction"的设置,过高,会导致发生Concurrent Mode Failure,过低,则浪费内存空间。

  CMS的最后一个问题,就是它在进行垃圾收集时使用的"标记-清除"算法。上一篇文章介绍垃圾回收原理的时候,我们讲到"标记-清除"算法,在进行垃圾清理以后,会出现很多内存碎片,过多的内存碎片会影响大对象的分配,会导致即使老年代内存还有很多空闲,但是由于过多的内存碎片,不得不提前触发垃圾回收。为了解决这个问题,CMS收集器提供了一个"-XX:+UseCMSCompactAtFullCollection"参数,用于CMS收集器在必要的时候对内存碎片进行压缩整理。由于内存碎片整理过程不是并发的,所以会导致停顿时间变长。"-XX:+UseCMSCompactAtFullCollection"参数默认是开启的。虚拟机还提供了一个"-XX:CMSFullGCsBeforeCompaction"参数,来控制进行过多少次不压缩的Full GC以后,进行一次带压缩的Full GC,默认值是0,表示每次在进行Full GC前都进行碎片整理。

  虽然CMS收集器存在上面提到的这些问题,但是毫无疑问,CMS当前仍然是非常优秀的垃圾收集器。

4. GC日志分析

  垃圾收集器在进行垃圾收集的过程中,可以输出日志,我们通过日志,可以看到当前垃圾收集器的运行情况。通过gc日志,我们可以观察垃圾收集器的行为,以及当前应用程序的GC情况和内存使用情况。学会查看和分析垃圾收集日志,一方面可以帮助我们学习垃圾收集器;另一方面,在必要的时候,可以帮助我们定位问题,解决问题,对JVM进行优化。

  默认,JVM不会打印出GC日志信息,可以通过参数-XX:+PrintGC或-verbose:gc来设置JVM输出gc日志到终端中。

  JVM参数:-XX:+PrintGC -XX:+UseSerialGC -Xms10m -Xmx10m

[GC (Allocation Failure)  1922K->1394K(9920K), 0.0021245 secs]
[Full GC (Allocation Failure)  7585K->7538K(9920K), 0.0023668 secs]

  当设置了"-XX:+PrintGC"或者"-verbose:gc"以后就会输出类似输出上面的GC日志。这是最简单的GC日志,包含了垃圾收集过程中的信息。其中红色部分的"GC"和"Full GC"表示这次GC的类型,而绿色部分的"Allocation Failure"表示表示发生这次GC的原因,从上面的日志可以看出,是由于内存分配失败导致的GC。后面的黄色部分"1922K->1394K(9920K)"表示这次GC导致JVM中堆内存的使用量从1922K降低到了1394K,其中括号中表示当前整个JVM堆的大小。最后蓝色部分的"0.0021245 secs"表示这次GC持续的时间。

  上面输出的是简单格式的GC日志,虽然提供了一些信息,但是通过这些信息,我们没法知道这次GC发生的时候,这次GC是发生在老年代还是在年轻代,是否有对象从年轻代被移动到了老年代等信息,所以我们希望可以看到更加详尽的信息。这个时候,我们需要设置-XX:+PrintGCDetails参数来输出更加详细的GC日志,下面我们结合不同的收集器组合,来分析下它们的输出日志。

Serial GC + Serial Old

  Serial GC和Serial Old收集器是比较早的单线程收集器,工作原理我们在上面已经介绍过了。这里,我们来看下使用这两款收集器进行垃圾收集的时候,输出的日志格式是怎么样的。首先我们需要设置JVM参数:

  JVM参数:-XX:+PrintGC -XX:+PrintGCDetails -XX:+UseSerialGC -Xms10m -Xmx10m

[GC (Allocation Failure) 
[DefNew: 1922K->319K(3072K), 0.0027356 secs] 1922K->1394K(9920K), 0.0027698 secs]
[Times: user=0.00 sys=0.00, real=0.00 secs]
[Full GC (Allocation Failure)
[Tenured: 6514K->6484K(6848K), 0.0025899 secs] 8562K->8532K(9920K), [Metaspace: 2984K->2984K(1056768K)], 0.0026153 secs]
[Times: user=0.00 sys=0.00, real=0.00 secs]

   可以发现,通过设置了"-XX:+PrintGCDetails"以后,输出的GC日志信息多了很多。我们先来看第一条,红色部分"GC"表示这次发生的是Minor GC,绿色部分"Allocation Failure"表示导致这次GC的原因是内存分配失败。接下来,黄色部分的内容,则和前面的日志有些区别了,这里输出的内容相对比较详细。"DefNew: 1922K->319K(3072K), 0.0027356 secs] 1922K->1394K(9920K), 0.0027698 secs",其中DefNew表示这次GC发生在年轻代(不同的收集器,日志的格式不一定相同),接下来"1922K->319K"表示这次GC导致年轻代使用的内存从1922K降到319K,括号中的"3072K"表示年轻代中的堆内存大小为3072K。"0.0027356 secs"表示这次年轻代GC耗时0.0027356s。后面的"1922K->1393K"表示总的堆内存(年轻代 + 老年代)的使用情况的变化,从1922K降低到1394K, 括号中的"9920K"表示总的堆内存的大小。最后的"0.0027698 secs"表示这次GC总的消耗的时间。最后是这次GC消耗的时间的统计,其中user表示用户态CPU执行的时间,sys表示内核态CPU执行的时间,这两个时间不包括被挂起消耗的时间,而real表示的是实际的时间,可以认为是墙上时钟走过的时间。

  下面的这条日志,"Full GC"表示这次GC是一次Major GC,后面的原因和上面一样。我们来看下黄色部分,"Tenured"表示这次GC发生在老年代,其中"6524K->6484K"表示老年代内存从6524K降低到6484K。后面的时间"0.0025899 secs"表示这次老年代GC耗时0.0025899s。接下来的"8562K -> 8532K"和上面提到的一样,表示整个堆内存的变化。最后的时间表示这次GC的总耗时为"0.0026153s"。

Parallel Scanvage + Parallel Old

  不同的垃圾收集器,输出的日志信息也不是完全相同的,上面我们看到的日志,是使用Serial GC和Serial Old收集器输出的gc日志,而下面的日志信息,则是使用Parallel Scavenge收集器和Parallel Old收集器输出的日志。

  JVM参数:-XX:+PrintGC -XX:+UseParallelOldGC -XX:+PrintGCDetails -Xms10m -Xmx10m

[GC (Allocation Failure) --
[PSYoungGen: 1391K->1391K(2560K)] 7537K->7537K(9728K), 0.0007436 secs]
[Times: user=0.00 sys=0.00, real=0.00 secs]
[Full GC (Allocation Failure)
[PSYoungGen: 1391K->1374K(2560K)]
[ParOldGen: 6145K->6145K(7168K)] 7537K->7520K(9728K), [Metaspace: 2984K->2984K(1056768K)], 0.0037697 secs]
[Times: user=0.01 sys=0.00, real=0.01 secs]

  可以看到,使用Parallel Scavenge 和 Parallel Old收集器输出的日志,会有一些不同,不过日志内容大体上差不多。最后,我们来看下CMS垃圾收集器的日志是怎么样的,相对上面几款收集器,CMS相对更加复杂,从它输出的日志也可以看出来。

ParNew + Concurrent Mark Sweep(CMS)

  下面,我们来看下ParNew配合CMS收集器在进行垃圾收集的时候,输出的GC 日志信息。

  JVM参数:-XX:+PrintGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -Xms10m -Xmx10m

[GC (Allocation Failure) [ParNew: 2418K->0K(3072K), 0.0032236 secs] 3508K->3455K(9920K), 0.0032520 secs] 
[Times: user=0.01 sys=0.00, real=0.00 secs]
[GC (CMS Initial Mark) [1 CMS-initial-mark: 3455K(6848K)] 4479K(9920K), 0.0005566 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] [CMS-concurrent-mark-start] [CMS-concurrent-mark: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] [CMS-concurrent-preclean-start] [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] [GC (CMS Final Remark) [YG occupancy: 1024 K (3072 K)]
[Rescan (parallel) , 0.0001118 secs][weak refs processing, 0.0000191 secs][class unloading, 0.0002858 secs]
[scrub symbol table, 0.0003506 secs][scrub string table, 0.0001305 secs]
[1 CMS-remark: 3455K(6848K)] 4479K(9920K), 0.0009500 secs]
[Times: user=0.00 sys=0.00, real=0.01 secs] [CMS-concurrent-sweep-start] [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] [CMS-concurrent-reset-start] [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

  通过第一条日志,可以看出我们使用"-XX:+UseConcMarkSweepGC"指定CMS垃圾收集器的时候,使用的是ParNew + CMS收集器组合。下面输出的一堆日志,就是CMS收集器在进行垃圾收集过程中输出的信息。可以明显的看到,CMS在进行垃圾收集的过程中,经历了4个阶段,在日志中我用4中颜色标记出来了。需要注意的是黄色部分,这是CMS的重新标记的阶段,在上面我们介绍CMS收集器的时候说过,在这个阶段,是会出现Stop The World的,所以如果这个阶段消耗的时间比较长,则会影响应用的响应时间。

其他日志参数

  有时候,我们需要在GC日志中输出时间值,这样我们就可以知道这次GC发生的具体时间点。我们可以通过JVM参数"-XX:+PrintGCTimeStamps" 和"-XX:+PrintGCDateStamps"来设置日志输出的时间。使用"-XX:+PrintGCTimeStamps"参数,可以在输出的日志前加上产生日志的时间戳:

7.327: [GC (Allocation Failure) 7.327: [DefNew: 2095K->2095K(3072K), 0.0000209 secs]

  可以看到,输出的日志中,在头部包含了一个时间戳,表示从JVM启动以来经过的秒数。而"-XX:+PrintGCDateStamps"则表示输出日志时的当前时间,相对来说更加直观:

2017-02-24T00:14:38.611-0800: [GC (Allocation Failure) 
2017-02-24T00:14:38.611-0800: [DefNew: 1922K->319K(3072K), 0.0025676 secs] 1922K->1394K(9920K), 0.0026134 secs]

  除了将日志输出到控制台,我们还可以将日志输出到日志文件中,这样就可以通过分析日志文件来分析系统的GC情况了,一般在服务器运行过程中,我们都会将GC日志输出到指定的文件中,供需要的时候分析。可以通过JVM参数"-Xloggc:<file>"来指定日志输出的目录。  

5. 总结

  在这篇文章中,我们讨论了现代Java虚拟机中已经实现了的垃圾收集器。从分代收集策略出发,结合上一篇文章中介绍的垃圾收集原理,介绍了多款垃圾收集器的是实现。最后,我们分析了垃圾收集器的GC日志,学习如何通过垃圾收集的日志,分析当前系统的垃圾收集的状况。文章到这里差不多就介绍, 希望这篇文章可以帮助到大家!

posted @ 2017-02-27 21:23  Duke2016  阅读(8586)  评论(0编辑  收藏  举报