4. GC 算法(实现篇) - GC参考手册
2017年02月05日 23:58:36
阅读数:6862
您应该已经阅读了前面的章节:
学习了GC算法的相关概念之后, 我们将介绍在JVM中这些算法的具体实现。首先要记住的是, 大多数JVM都需要使用两种不同的GC算法 —— 一种用来清理年轻代, 另一种用来清理老年代。
我们可以选择JVM内置的各种算法。如果不通过参数明确指定垃圾收集算法, 则会使用宿主平台的默认实现。本章会详细介绍各种算法的实现原理。
下面是关于Java 8中各种组合的垃圾收集器概要列表,对于之前的Java版本来说,可用组合会有一些不同:
Young | Tenured | JVM options |
---|---|---|
Incremental(增量GC) | Incremental | -Xincgc |
Serial | Serial | -XX:+UseSerialGC |
Parallel Scavenge | Serial | -XX:+UseParallelGC -XX:-UseParallelOldGC |
Parallel New | Serial | N/A |
Serial | Parallel Old | N/A |
Parallel Scavenge | Parallel Old | -XX:+UseParallelGC -XX:+UseParallelOldGC |
Parallel New | Parallel Old | N/A |
Serial | CMS | -XX:-UseParNewGC -XX:+UseConcMarkSweepGC |
Parallel Scavenge | CMS | N/A |
Parallel New | CMS | -XX:+UseParNewGC -XX:+UseConcMarkSweepGC |
G1 | -XX:+UseG1GC |
看起来有些复杂, 不用担心。主要使用的是上表中黑体字表示的这四种组合。其余的要么是被废弃(deprecated), 要么是不支持或者是不太适用于生产环境。所以,接下来我们只介绍下面这些组合及其工作原理:
- 年轻代和老年代的串行GC(Serial GC)
- 年轻代和老年代的并行GC(Parallel GC)
- 年轻代的并行GC(Parallel New) + 老年代的CMS(Concurrent Mark and Sweep)
- G1, 负责回收年轻代和老年代
Serial GC(串行GC)
Serial GC 对年轻代使用 mark-copy(标记-复制) 算法, 对老年代使用 mark-sweep-compact(标记-清除-整理)算法. 顾名思义, 两者都是单线程的垃圾收集器,不能进行并行处理。两者都会触发全线暂停(STW),停止所有的应用线程。
因此这种GC算法不能充分利用多核CPU。不管有多少CPU内核, JVM 在垃圾收集时都只能使用单个核心。
要启用此款收集器, 只需要指定一个JVM启动参数即可,同时对年轻代和老年代生效:
java -XX:+UseSerialGC com.mypackages.MyExecutableClass
该选项只适合几百MB堆内存的JVM,而且是单核CPU时比较有用。 对于服务器端来说, 因为一般是多个CPU内核, 并不推荐使用, 除非确实需要限制JVM所使用的资源。大多数服务器端应用部署在多核平台上, 选择 Serial GC 就表示人为的限制系统资源的使用。 导致的就是资源闲置, 多的CPU资源也不能用来降低延迟,也不能用来增加吞吐量。
下面让我们看看Serial GC的垃圾收集日志, 并从中提取什么有用的信息。为了打开GC日志记录, 我们使用下面的JVM启动参数:
-XX:+PrintGCDetails -XX:+PrintGCDateStamps
-XX:+PrintGCTimeStamps
产生的GC日志输出类似这样(为了排版,已手工折行):
2015-05-26T14:45:37.987-0200:
151.126: [GC (Allocation Failure)
151.126: [DefNew: 629119K->69888K(629120K), 0.0584157 secs]
1619346K->1273247K(2027264K), 0.0585007 secs]
[Times: user=0.06 sys=0.00, real=0.06 secs]
2015-05-26T14:45:59.690-0200:
172.829: [GC (Allocation Failure)
172.829: [DefNew: 629120K->629120K(629120K), 0.0000372 secs]
172.829: [Tenured: 1203359K->755802K(1398144K), 0.1855567 secs]
1832479K->755802K(2027264K),
[Metaspace: 6741K->6741K(1056768K)], 0.1856954 secs]
[Times: user=0.18 sys=0.00, real=0.18 secs]
此GC日志片段展示了在JVM中发生的很多事情。 实际上,在这段日志中产生了两个GC事件, 其中一次清理的是年轻代,另一次清理的是整个堆内存。让我们先来分析前一次GC,其在年轻代中产生。
Minor GC(小型GC)
以下代码片段展示了清理年轻代内存的GC事件:
2015-05-26T14:45:37.987-0200
1 :151.1262
2 : [GC
3 (Allocation Failure
4 151.126:
[DefNew
5 :629119K->69888K
6(629120K)
7 , 0.0584157 secs]1619346K->1273247K
8
(2027264K)
9,0.0585007 secs
10][Times: user=0.06 sys=0.00, real=0.06 secs]
11
2015-05-26T14:45:37.987-0200
– GC事件开始的时间. 其中-0200
表示西二时区,而中国所在的东8区为+0800
。
151.126
– GC事件开始时,相对于JVM启动时的间隔时间,单位是秒。
GC
– 用来区分 Minor GC 还是 Full GC 的标志。GC
表明这是一次小型GC(Minor GC)
Allocation Failure
– 触发 GC 的原因。本次GC事件, 是由于年轻代中没有空间来存放新的数据结构引起的。
DefNew
– 垃圾收集器的名称。这个神秘的名字表示的是在年轻代中使用的: 单线程, 标记-复制(mark-copy), 全线暂停(STW) 垃圾收集器。
629119K->69888K
– 在垃圾收集之前和之后年轻代的使用量。
(629120K)
– 年轻代总的空间大小。
1619346K->1273247K
– 在垃圾收集之前和之后整个堆内存的使用情况。
(2027264K)
– 可用堆的总空间大小。
0.0585007 secs
– GC事件持续的时间,以秒为单位。
[Times: user=0.06 sys=0.00, real=0.06 secs]
– GC事件的持续时间, 通过三个部分来衡量:
user – 在此次垃圾回收过程中, 所有 GC线程所消耗的CPU时间之和。
sys – GC过程中中操作系统调用和系统等待事件所消耗的时间。
real – 应用程序暂停的时间。因为串行垃圾收集器(Serial Garbage Collector)只使用单线程, 因此 real time 等于 user 和 system 时间的总和。
可以从上面的日志片段了解到, 在GC事件中,JVM 的内存使用情况发生了怎样的变化。此次垃圾收集之前, 堆内存总的使用量为 1,619,346K。其中,年轻代使用了 629,119K。可以算出,老年代使用量为 990,227K。
更重要的信息蕴含在下一批数字中, 垃圾收集之后, 年轻代的使用量减少了 559,231K, 但堆内存的总体使用量只下降了 346,099K。 从中可以算出,有 213,132K 的对象从年轻代提升到了老年代。
此次GC事件也可以用下面的示意图来说明, 显示的是GC开始之前, 以及刚刚结束之后, 这两个时间点内存使用情况的快照:
Full GC(完全GC)
理解第一次 minor GC 事件后,让我们看看日志中的第二次GC事件:
2015-05-26T14:45:59.690-0200
1 :172.829
2 : [GC (Allocation Failure 172.829:
[DefNew: 629120K->629120K(629120K), 0.0000372 secs
3] 172.829:[Tenured
4:
1203359K->755802K
5(1398144K)
6,0.1855567 secs
7 ]1832479K->755802K
8
(2027264K)
9,[Metaspace: 6741K->6741K(1056768K)]
10
[Times: user=0.18 sys=0.00, real=0.18 secs]
11
>
2015-05-26T14:45:59.690-0200
– GC事件开始的时间. 其中-0200
表示西二时区,而中国所在的东8区为+0800
。172.829
– GC事件开始时,相对于JVM启动时的间隔时间,单位是秒。
[DefNew: 629120K->629120K(629120K), 0.0000372 secs
– 与上面的示例类似, 因为内存分配失败,在年轻代中发生了一次 minor GC。此次GC同样使用的是 DefNew 收集器, 让年轻代的使用量从 629120K 降为 0。注意,JVM对此次GC的报告有些问题,误将年轻代认为是完全填满的。此次垃圾收集消耗了 0.0000372秒。
Tenured
– 用于清理老年代空间的垃圾收集器名称。Tenured 表明使用的是单线程的全线暂停垃圾收集器, 收集算法为 标记-清除-整理(mark-sweep-compact )。1203359K->755802K
– 在垃圾收集之前和之后老年代的使用量。(1398144K)
– 老年代的总空间大小。0.1855567 secs
– 清理老年代所花的时间。1832479K->755802K
– 在垃圾收集之前和之后,整个堆内存的使用情况。(2027264K)
– 可用堆的总空间大小。[Metaspace: 6741K->6741K(1056768K)]
– 关于 Metaspace 空间, 同样的信息。可以看出, 此次GC过程中 Metaspace 中没有收集到任何垃圾。[Times: user=0.18 sys=0.00, real=0.18 secs]
– GC事件的持续时间, 通过三个部分来衡量:
- user – 在此次垃圾回收过程中, 所有 GC线程所消耗的CPU时间之和。
- sys – GC过程中中操作系统调用和系统等待事件所消耗的时间。
- real – 应用程序暂停的时间。因为串行垃圾收集器(Serial Garbage Collector)只使用单线程, 因此 real time 等于 user 和 system 时间的总和。
和 Minor GC 相比,最明显的区别是 —— 在此次GC事件中, 除了年轻代, 还清理了老年代和Metaspace. 在GC事件开始之前, 以及刚刚结束之后的内存布局,可以用下面的示意图来说明:
Parallel GC(并行GC)
并行垃圾收集器这一类组合, 在年轻代使用 标记-复制(mark-copy)算法, 在老年代使用 标记-清除-整理(mark-sweep-compact)算法。年轻代和老年代的垃圾回收都会触发STW事件,暂停所有的应用线程来执行垃圾收集。两者在执行 标记和 复制/整理阶段时都使用多个线程, 因此得名“(Parallel)”。通过并行执行, 使得GC时间大幅减少。
通过命令行参数 -XX:ParallelGCThreads=NNN
来指定 GC 线程数。 其默认值为CPU内核数。
可以通过下面的任意一组命令行参数来指定并行GC:
java -XX:+UseParallelGC com.mypackages.MyExecutableClass
java -XX:+UseParallelOldGC com.mypackages.MyExecutableClass
java -XX:+UseParallelGC -XX:+UseParallelOldGC com.mypackages.MyExecutableClass
并行垃圾收集器适用于多核服务器,主要目标是增加吞吐量。因为对系统资源的有效使用,能达到更高的吞吐量:
- 在GC期间, 所有 CPU 内核都在并行清理垃圾, 所以暂停时间更短
- 在两次GC周期的间隔期, 没有GC线程在运行,不会消耗任何系统资源
另一方面, 因为此GC的所有阶段都不能中断, 所以并行GC很容易出现长时间的停顿. 如果延迟是系统的主要目标, 那么就应该选择其他垃圾收集器组合。
译者注: 长时间卡顿的意思是,此GC启动之后,属于一次性完成所有操作, 于是单次 pause 的时间会较长。
让我们看看并行垃圾收集器的GC日志长什么样, 从中我们可以得到哪些有用信息。下面的GC日志中显示了一次 minor GC 暂停 和一次 major GC 暂停:
2015-05-26T14:27:40.915-0200: 116.115: [GC (Allocation Failure)
[PSYoungGen: 2694440K->1305132K(2796544K)]
9556775K->8438926K(11185152K)
, 0.2406675 secs]
[Times: user=1.77 sys=0.01, real=0.24 secs]
2015-05-26T14:27:41.155-0200: 116.356: [Full GC (Ergonomics)
[PSYoungGen: 1305132K->0K(2796544K)]
[ParOldGen: 7133794K->6597672K(8388608K)] 8438926K->6597672K(11185152K),
[Metaspace: 6745K->6745K(1056768K)]
, 0.9158801 secs]
[Times: user=4.49 sys=0.64, real=0.92 secs]
Minor GC(小型GC)
第一次GC事件表示发生在年轻代的垃圾收集:
2015-05-26T14:27:40.915-0200
1:116.115
2:[ GC
3 (Allocation Failure
4)
[PSYoungGen
5:2694440K->1305132K
6(2796544K)
7]9556775K->8438926K
8
(11185152K)
9,0.2406675 secs
10]
[Times: user=1.77 sys=0.01, real=0.24 secs]
11
>
2015-05-26T14:27:40.915-0200
– GC事件开始的时间. 其中-0200
表示西二时区,而中国所在的东8区为+0800
。116.115
– GC事件开始时,相对于JVM启动时的间隔时间,单位是秒。GC
– 用来区分 Minor GC 还是 Full GC 的标志。GC
表明这是一次小型GC(Minor GC)Allocation Failure
– 触发垃圾收集的原因。本次GC事件, 是由于年轻代中没有适当的空间存放新的数据结构引起的。PSYoungGen
– 垃圾收集器的名称。这个名字表示的是在年轻代中使用的: 并行的 标记-复制(mark-copy), 全线暂停(STW) 垃圾收集器。2694440K->1305132K
– 在垃圾收集之前和之后的年轻代使用量。(2796544K)
– 年轻代的总大小。9556775K->8438926K
– 在垃圾收集之前和之后整个堆内存的使用量。(11185152K)
– 可用堆的总大小。0.2406675 secs
– GC事件持续的时间,以秒为单位。[Times: user=1.77 sys=0.01, real=0.24 secs]
– GC事件的持续时间, 通过三个部分来衡量:
- user – 在此次垃圾回收过程中, 由GC线程所消耗的总的CPU时间。
- sys – GC过程中中操作系统调用和系统等待事件所消耗的时间。
- real – 应用程序暂停的时间。在 Parallel GC 中, 这个数字约等于: (user time + system time)/GC线程数。 这里使用了8个线程。 请注意,总有一定比例的处理过程是不能并行进行的。
所以,可以简单地算出, 在垃圾收集之前, 堆内存总使用量为 9,556,775K。 其中年轻代为 2,694,440K。同时算出老年代使用量为 6,862,335K. 在垃圾收集之后, 年轻代使用量减少为 1,389,308K, 但总的堆内存使用量只减少了 1,117,849K
。这表示有大小为 271,459K 的对象从年轻代提升到老年代。
Full GC(完全GC)
学习了并行GC如何清理年轻代之后, 下面介绍清理整个堆内存的GC日志以及如何进行分析:
2015-05-26T14:27:41.155-0200
:116.356
: [Full GC
(Ergonomics
)
[PSYoungGen: 1305132K->0K(2796544K)]
[ParOldGen
:7133794K->6597672K
(8388608K)
]8438926K->6597672K
(11185152K)
,
[Metaspace: 6745K->6745K(1056768K)]
,0.9158801 secs
,
[Times: user=4.49 sys=0.64, real=0.92 secs]
2015-05-26T14:27:41.155-0200
– GC事件开始的时间. 其中-0200
表示西二时区,而中国所在的东8区为+0800
。116.356
– GC事件开始时,相对于JVM启动时的间隔时间,单位是秒。 我们可以看到, 此次事件在前一次 MinorGC完成之后立刻就开始了。Full GC
– 用来表示此次是 Full GC 的标志。Full GC
表明本次清理的是年轻代和老年代。Ergonomics
– 触发垃圾收集的原因。Ergonomics
表示JVM内部环境认为此时可以进行一次垃圾收集。[PSYoungGen: 1305132K->0K(2796544K)]
– 和上面的示例一样, 清理年轻代的垃圾收集器是名为 “PSYoungGen” 的STW收集器, 采用标记-复制(mark-copy)算法。 年轻代使用量从 1305132K 变为0
, 一般 Full GC 的结果都是这样。ParOldGen
– 用于清理老年代空间的垃圾收集器类型。在这里使用的是名为 ParOldGen 的垃圾收集器, 这是一款并行 STW垃圾收集器, 算法为 标记-清除-整理(mark-sweep-compact)。7133794K->6597672K
– 在垃圾收集之前和之后老年代内存的使用情况。(8388608K)
– 老年代的总空间大小。8438926K->6597672K
– 在垃圾收集之前和之后堆内存的使用情况。(11185152K)
– 可用堆内存的总容量。[Metaspace: 6745K->6745K(1056768K)]
– 类似的信息,关于 Metaspace 空间的。可以看出, 在GC事件中 Metaspace 里面没有回收任何对象。0.9158801 secs
– GC事件持续的时间,以秒为单位。[Times: user=4.49 sys=0.64, real=0.92 secs]
– GC事件的持续时间, 通过三个部分来衡量:
- user – 在此次垃圾回收过程中, 由GC线程所消耗的总的CPU时间。
- sys – GC过程中中操作系统调用和系统等待事件所消耗的时间。
- real – 应用程序暂停的时间。在 Parallel GC 中, 这个数字约等于: (user time + system time)/GC线程数。 这里使用了8个线程。 请注意,总有一定比例的处理过程是不能并行进行的。
同样,和 Minor GC 的区别是很明显的 —— 在此次GC事件中, 除了年轻代, 还清理了老年代和 Metaspace. 在GC事件前后的内存布局如下图所示:
Concurrent Mark and Sweep(并发标记-清除)
CMS的官方名称为 “Mostly Concurrent Mark and Sweep Garbage Collector”(主要并发-标记-清除-垃圾收集器). 其对年轻代采用并行 STW方式的 mark-copy (标记-复制)算法, 对老年代主要使用并发 mark-sweep (标记-清除)算法。
CMS的设计目标是避免在老年代垃圾收集时出现长时间的卡顿。主要通过两种手段来达成此目标。
- 第一, 不对老年代进行整理, 而是使用空闲列表(free-lists)来管理内存空间的回收。
- 第二, 在 mark-and-sweep (标记-清除) 阶段的大部分工作和应用线程一起并发执行。
也就是说, 在这些阶段并没有明显的应用线程暂停。但值得注意的是, 它仍然和应用线程争抢CPU时间。默认情况下, CMS 使用的并发线程数等于CPU内核数的 1/4
。
通过以下选项来指定CMS垃圾收集器:
java -XX:+UseConcMarkSweepGC com.mypackages.MyExecutableClass
如果服务器是多核CPU,并且主要调优目标是降低延迟, 那么使用CMS是个很明智的选择. 减少每一次GC停顿的时间,会直接影响到终端用户对系统的体验, 用户会认为系统非常灵敏。 因为多数时候都有部分CPU资源被GC消耗, 所以在CPU资源受限的情况下,CMS会比并行GC的吞吐量差一些。
和前面的GC算法一样, 我们先来看看CMS算法在实际应用中的GC日志, 其中包括一次 minor GC, 以及一次 major GC 停顿:
2015-05-26T16:23:07.219-0200: 64.322: [GC (Allocation Failure) 64.322:
[ParNew: 613404K->68068K(613440K), 0.1020465 secs]
10885349K->10880154K(12514816K), 0.1021309 secs]
[Times: user=0.78 sys=0.01, real=0.11 secs]
2015-05-26T16:23:07.321-0200: 64.425: [GC (CMS Initial Mark)
[1 CMS-initial-mark: 10812086K(11901376K)]
10887844K(12514816K), 0.0001997 secs]
[Times: user=0.00 sys=0.00, real=0.00 secs]
2015-05-26T16:23:07.321-0200: 64.425: [CMS-concurrent-mark-start]
2015-05-26T16:23:07.357-0200: 64.460: [CMS-concurrent-mark: 0.035/0.035 secs]
[Times: user=0.07 sys=0.00, real=0.03 secs]
2015-05-26T16:23:07.357-0200: 64.460: [CMS-concurrent-preclean-start]
2015-05-26T16:23:07.373-0200: 64.476: [CMS-concurrent-preclean: 0.016/0.016 secs]
[Times: user=0.02 sys=0.00, real=0.02 secs]
2015-05-26T16:23:07.373-0200: 64.476: [CMS-concurrent-abortable-preclean-start]
2015-05-26T16:23:08.446-0200: 65.550: [CMS-concurrent-abortable-preclean: 0.167/1.074 secs]
[Times: user=0.20 sys=0.00, real=1.07 secs]
2015-05-26T16:23:08.447-0200: 65.550: [GC (CMS Final Remark)
[YG occupancy: 387920 K (613440 K)]
65.550: [Rescan (parallel) , 0.0085125 secs]
65.559: [weak refs processing, 0.0000243 secs]
65.559: [class unloading, 0.0013120 secs]
65.560: [scrub symbol table, 0.0008345 secs]
65.561: [scrub string table, 0.0001759 secs]
[1 CMS-remark: 10812086K(11901376K)]
11200006K(12514816K), 0.0110730 secs]
[Times: user=0.06 sys=0.00, real=0.01 secs]
2015-05-26T16:23:08.458-0200: 65.561: [CMS-concurrent-sweep-start]
2015-05-26T16:23:08.485-0200: 65.588: [CMS-concurrent-sweep: 0.027/0.027 secs]
[Times: user=0.03 sys=0.00, real=0.03 secs]
2015-05-26T16:23:08.485-0200: 65.589: [CMS-concurrent-reset-start]
2015-05-26T16:23:08.497-0200: 65.601: [CMS-concurrent-reset: 0.012/0.012 secs]
[Times: user=0.01 sys=0.00, real=0.01 secs]
Minor GC(小型GC)
日志中的第一次GC事件是清理年轻代的小型GC(Minor GC)。让我们来分析 CMS 垃圾收集器的行为:
2015-05-26T16:23:07.219-0200
:64.322
:[GC
(Allocation Failure
) 64.322:
[ParNew
:613404K->68068K
(613440K)
,0.1020465 secs
]
10885349K->10880154K
(12514816K)
,0.1021309 secs
]
[Times: user=0.78 sys=0.01, real=0.11 secs]
>
2015-05-26T16:23:07.219-0200
– GC事件开始的时间. 其中-0200
表示西二时区,而中国所在的东8区为+0800
。64.322
– GC事件开始时,相对于JVM启动时的间隔时间,单位是秒。GC
– 用来区分 Minor GC 还是 Full GC 的标志。GC
表明这是一次小型GC(Minor GC)Allocation Failure
– 触发垃圾收集的原因。本次GC事件, 是由于年轻代中没有适当的空间存放新的数据结构引起的。ParNew
– 垃圾收集器的名称。这个名字表示的是在年轻代中使用的: 并行的 标记-复制(mark-copy), 全线暂停(STW)垃圾收集器, 专门设计了用来配合老年代使用的 Concurrent Mark & Sweep 垃圾收集器。613404K->68068K
– 在垃圾收集之前和之后的年轻代使用量。(613440K)
– 年轻代的总大小。0.1020465 secs
– 垃圾收集器在 w/o final cleanup 阶段消耗的时间10885349K->10880154K
– 在垃圾收集之前和之后堆内存的使用情况。(12514816K)
– 可用堆的总大小。0.1021309 secs
– 垃圾收集器在标记和复制年轻代存活对象时所消耗的时间。包括和ConcurrentMarkSweep收集器的通信开销, 提升存活时间达标的对象到老年代,以及垃圾收集后期的一些最终清理。[Times: user=0.78 sys=0.01, real=0.11 secs]
– GC事件的持续时间, 通过三个部分来衡量:
- user – 在此次垃圾回收过程中, 由GC线程所消耗的总的CPU时间。
- sys – GC过程中中操作系统调用和系统等待事件所消耗的时间。
- real – 应用程序暂停的时间。在并行GC(Parallel GC)中, 这个数字约等于: (user time + system time)/GC线程数。 这里使用的是8个线程。 请注意,总是有固定比例的处理过程是不能并行化的。
从上面的日志可以看出,在GC之前总的堆内存使用量为 10,885,349K, 年轻代的使用量为 613,404K。这意味着老年代使用量等于 10,271,945K。GC之后,年轻代的使用量减少了 545,336K, 而总的堆内存使用只下降了 5,195K。可以算出有 540,141K 的对象从年轻代提升到老年代。
Full GC(完全GC)
现在, 我们已经熟悉了如何解读GC日志, 接下来将介绍一种完全不同的日志格式。下面这一段很长很长的日志, 就是CMS对老年代进行垃圾收集时输出的各阶段日志。为了简洁,我们对这些阶段逐个介绍。 首先来看CMS收集器整个GC事件的日志:
2015-05-26T16:23:07.321-0200: 64.425: [GC (CMS Initial Mark)
[1 CMS-initial-mark: 10812086K(11901376K)]
10887844K(12514816K), 0.0001997 secs]
[Times: user=0.00 sys=0.00, real=0.00 secs]
2015-05-26T16:23:07.321-0200: 64.425: [CMS-concurrent-mark-start]
2015-05-26T16:23:07.357-0200: 64.460: [CMS-concurrent-mark: 0.035/0.035 secs]
[Times: user=0.07 sys=0.00, real=0.03 secs]
2015-05-26T16:23:07.357-0200: 64.460: [CMS-concurrent-preclean-start]
2015-05-26T16:23:07.373-0200: 64.476: [CMS-concurrent-preclean: 0.016/0.016 secs]
[Times: user=0.02 sys=0.00, real=0.02 secs]
2015-05-26T16:23:07.373-0200: 64.476: [CMS-concurrent-abortable-preclean-start]
2015-05-26T16:23:08.446-0200: 65.550: [CMS-concurrent-abortable-preclean: 0.167/1.074 secs]
[Times: user=0.20 sys=0.00, real=1.07 secs]
2015-05-26T16:23:08.447-0200: 65.550: [GC (CMS Final Remark)
[YG occupancy: 387920 K (613440 K)]
65.550: [Rescan (parallel) , 0.0085125 secs]
65.559: [weak refs processing, 0.0000243 secs]
65.559: [class unloading, 0.0013120 secs]
65.560: [scrub symbol table, 0.0008345 secs]
65.561: [scrub string table, 0.0001759 secs]
[1 CMS-remark: 10812086K(11901376K)]
11200006K(12514816K), 0.0110730 secs]
[Times: user=0.06 sys=0.00, real=0.01 secs]
2015-05-26T16:23:08.458-0200: 65.561: [CMS-concurrent-sweep-start]
2015-05-26T16:23:08.485-0200: 65.588: [CMS-concurrent-sweep: 0.027/0.027 secs]
[Times: user=0.03 sys=0.00, real=0.03 secs]
2015-05-26T16:23:08.485-0200: 65.589: [CMS-concurrent-reset-start]
2015-05-26T16:23:08.497-0200: 65.601: [CMS-concurrent-reset: 0.012/0.012 secs]
[Times: user=0.01 sys=0.00, real=0.01 secs]
只是要记住 —— 在实际情况下, 进行老年代的并发回收时, 可能会伴随着多次年轻代的小型GC. 在这种情况下, 大型GC的日志中就会掺杂着多次小型GC事件, 像前面所介绍的一样。
阶段 1: Initial Mark(初始标记). 这是第一次STW事件。 此阶段的目标是标记老年代中所有存活的对象, 包括 GC ROOR 的直接引用, 以及由年轻代中存活对象所引用的对象。 后者也非常重要, 因为老年代是独立进行回收的。
2015-05-26T16:23:07.321-0200: 64.42
1: [GC (CMS Initial Mark
1
[1 CMS-initial-mark:10812086K
1(11901376K)
1]10887844K
1(12514816K)
1,
0.0001997 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
1
>
2015-05-26T16:23:07.321-0200: 64.42
– GC事件开始的时间. 其中-0200
是时区,而中国所在的东8区为 +0800。 而 64.42 是相对于JVM启动的时间。 下面的其他阶段也是一样,所以就不再重复介绍。CMS Initial Mark
– 垃圾回收的阶段名称为 “Initial Mark”。 标记所有的 GC Root。10812086K
– 老年代的当前使用量。(11901376K)
– 老年代中可用内存总量。10887844K
– 当前堆内存的使用量。(12514816K)
– 可用堆的总大小。0.0001997 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
– 此次暂停的持续时间, 以 user, system 和 real time 3个部分进行衡量。
阶段 2: Concurrent Mark(并发标记). 在此阶段, 垃圾收集器遍历老年代, 标记所有的存活对象, 从前一阶段 “Initial Mark” 找到的 root 根开始算起。 顾名思义, “并发标记”阶段, 就是与应用程序同时运行,不用暂停的阶段。 请注意, 并非所有老年代中存活的对象都在此阶段被标记, 因为在标记过程中对象的引用关系还在发生变化。
在上面的示意图中, “Current object” 旁边的一个引用被标记线程并发删除了。
2015-05-26T16:23:07.321-0200: 64.425: [CMS-concurrent-mark-start]
2015-05-26T16:23:07.357-0200: 64.460: [CMS-concurrent-mark
1:035/0.035 secs
1]
[Times: user=0.07 sys=0.00, real=0.03 secs]
1
>
CMS-concurrent-mark
– 并发标记(“Concurrent Mark”) 是CMS垃圾收集中的一个阶段, 遍历老年代并标记所有的存活对象。035/0.035 secs
– 此阶段的持续时间, 分别是运行时间和相应的实际时间。[Times: user=0.07 sys=0.00, real=0.03 secs]
–Times
这部分对并发阶段来说没多少意义, 因为是从并发标记开始时计算的,而这段时间内不仅并发标记在运行,程序也在运行
阶段 3: Concurrent Preclean(并发预清理). 此阶段同样是与应用线程并行执行的, 不需要停止应用线程。 因为前一阶段是与程序并发进行的,可能有一些引用已经改变。如果在并发标记过程中发生了引用关系变化,JVM会(通过“Card”)将发生了改变的区域标记为“脏”区(这就是所谓的卡片标记,Card Marking)。
在预清理阶段,这些脏对象会被统计出来,从他们可达的对象也被标记下来。此阶段完成后, 用以标记的 card 也就被清空了。
此外, 本阶段也会执行一些必要的细节处理, 并为 Final Remark 阶段做一些准备工作。
>
2015-05-26T16:23:07.357-0200: 64.460: [CMS-concurrent-preclean-start]
2015-05-26T16:23:07.373-0200: 64.476: [
CMS-concurrent-preclean
:0.016/0.016 secs
][Times: user=0.02 sys=0.00, real=0.02 secs]
>
CMS-concurrent-preclean
– 并发预清理阶段, 统计此前的标记阶段中发生了改变的对象。0.016/0.016 secs
– 此阶段的持续时间, 分别是运行时间和对应的实际时间。[Times: user=0.02 sys=0.00, real=0.02 secs]
– Times 这部分对并发阶段来说没多少意义, 因为是从并发标记开始时计算的,而这段时间内不仅GC的并发标记在运行,程序也在运行。
阶段 4: Concurrent Abortable Preclean(并发可取消的预清理). 此阶段也不停止应用线程. 本阶段尝试在 STW 的 Final Remark 之前尽可能地多做一些工作。本阶段的具体时间取决于多种因素, 因为它循环做同样的事情,直到满足某个退出条件( 如迭代次数, 有用工作量, 消耗的系统时间,等等)。
>
2015-05-26T16:23:07.373-0200: 64.476: [CMS-concurrent-abortable-preclean-start]
2015-05-26T16:23:08.446-0200: 65.550: [CMS-concurrent-abortable-preclean1: 0.167/1.074 secs2][Times: user=0.20 sys=0.00, real=1.07 secs]3
>
CMS-concurrent-abortable-preclean
– 此阶段的名称: “Concurrent Abortable Preclean”。
0.167/1.074 secs
– 此阶段的持续时间, 运行时间和对应的实际时间。有趣的是, 用户时间明显比时钟时间要小很多。通常情况下我们看到的都是时钟时间小于用户时间, 这意味着因为有一些并行工作, 所以运行时间才会小于使用的CPU时间。这里只进行了少量的工作 — 0.167秒的CPU时间,GC线程经历了很多系统等待。从本质上讲,GC线程试图在必须执行 STW暂停之前等待尽可能长的时间。默认条件下,此阶段可以持续最多5秒钟。
[Times: user=0.20 sys=0.00, real=1.07 secs]
– “Times” 这部分对并发阶段来说没多少意义, 因为是从并发标记开始时计算的,而这段时间内不仅GC的并发标记线程在运行,程序也在运行
此阶段可能显著影响STW停顿的持续时间, 并且有许多重要的配置选项和失败模式。
阶段 5: Final Remark(最终标记). 这是此次GC事件中第二次(也是最后一次)STW阶段。本阶段的目标是完成老年代中所有存活对象的标记. 因为之前的 preclean 阶段是并发的, 有可能无法跟上应用程序的变化速度。所以需要 STW暂停来处理复杂情况。
通常CMS会尝试在年轻代尽可能空的情况运行 final remark 阶段, 以免接连多次发生 STW 事件。
看起来稍微比之前的阶段要复杂一些:
2015-05-26T16:23:08.447-0200: 65.550
: [GC (CMS Final Remark
) [YG occupancy: 387920 K (613440 K)
]
65.550:[Rescan (parallel) , 0.0085125 secs]
65.559: [weak refs processing, 0.0000243 secs]65.559
: [class unloading, 0.0013120 secs]65.560
: [scrub string table, 0.0001759 secs
]
[1 CMS-remark:10812086K(11901376K)
]11200006K(12514816K)
,0.0110730 secs
][Times: user=0.06 sys=0.00, real=0.01 secs]
>
2015-05-26T16:23:08.447-0200: 65.550
– GC事件开始的时间. 包括时钟时间,以及相对于JVM启动的时间. 其中-0200
表示西二时区,而中国所在的东8区为+0800
。CMS Final Remark
– 此阶段的名称为 “Final Remark”, 标记老年代中所有存活的对象,包括在此前的并发标记过程中创建/修改的引用。YG occupancy: 387920 K (613440 K)
– 当前年轻代的使用量和总容量。[Rescan (parallel) , 0.0085125 secs]
– 在程序暂停时重新进行扫描(Rescan),以完成存活对象的标记。此时 rescan 是并行执行的,消耗的时间为 0.0085125秒。weak refs processing, 0.0000243 secs]65.559
– 处理弱引用的第一个子阶段(sub-phases)。 显示的是持续时间和开始时间戳。class unloading, 0.0013120 secs]65.560
– 第二个子阶段, 卸载不使用的类。 显示的是持续时间和开始的时间戳。scrub string table, 0.0001759 secs
– 最后一个子阶段, 清理持有class级别 metadata 的符号表(symbol tables),以及内部化字符串对应的 string tables。当然也显示了暂停的时钟时间。10812086K(11901376K)
– 此阶段完成后老年代的使用量和总容量11200006K(12514816K)
– 此阶段完成后整个堆内存的使用量和总容量0.0110730 secs
– 此阶段的持续时间。[Times: user=0.06 sys=0.00, real=0.01 secs]
– GC事件的持续时间, 通过不同的类别来衡量: user, system and real time。
在5个标记阶段完成之后, 老年代中所有的存活对象都被标记了, 现在GC将清除所有不使用的对象来回收老年代空间:
阶段 6: Concurrent Sweep(并发清除). 此阶段与应用程序并发执行,不需要STW停顿。目的是删除未使用的对象,并收回他们占用的空间。
>
2015-05-26T16:23:08.458-0200: 65.561: [CMS-concurrent-sweep-start] 2015-05-26T16:23:08.485-0200: 65.588: [
CMS-concurrent-sweep
:0.027/0.027 secs
][Times: user=0.03 sys=0.00, real=0.03 secs]
>
CMS-concurrent-sweep
– 此阶段的名称, “Concurrent Sweep”, 清除未被标记、不再使用的对象以释放内存空间。0.027/0.027 secs
– 此阶段的持续时间, 分别是运行时间和实际时间[Times: user=0.03 sys=0.00, real=0.03 secs]
– “Times”部分对并发阶段来说没有多少意义, 因为是从并发标记开始时计算的,而这段时间内不仅是并发标记在运行,程序也在运行。
阶段 7: Concurrent Reset(并发重置). 此阶段与应用程序并发执行,重置CMS算法相关的内部数据, 为下一次GC循环做准备。
>
2015-05-26T16:23:08.485-0200: 65.589: [CMS-concurrent-reset-start] 2015-05-26T16:23:08.497-0200: 65.601: [
CMS-concurrent-reset
:0.012/0.012 secs
][Times: user=0.01 sys=0.00, real=0.01 secs]
>
CMS-concurrent-reset
– 此阶段的名称, “Concurrent Reset”, 重置CMS算法的内部数据结构, 为下一次GC循环做准备。0.012/0.012 secs
– 此阶段的持续时间, 分别是运行时间和对应的实际时间[Times: user=0.01 sys=0.00, real=0.01 secs]
– “Times”部分对并发阶段来说没多少意义, 因为是从并发标记开始时计算的,而这段时间内不仅GC线程在运行,程序也在运行。
总之, CMS垃圾收集器在减少停顿时间上做了很多给力的工作, 大量的并发线程执行的工作并不需要暂停应用线程。 当然, CMS也有一些缺点,其中最大的问题就是老年代内存碎片问题, 在某些情况下GC会造成不可预测的暂停时间, 特别是堆内存较大的情况下。
G1 – Garbage First(垃圾优先算法)
G1最主要的设计目标是: 将STW停顿的时间和分布变成可预期以及可配置的。事实上, G1是一款软实时垃圾收集器, 也就是说可以为其设置某项特定的性能指标. 可以指定: 在任意 xx
毫秒的时间范围内, STW停顿不得超过 x
毫秒。 如: 任意1秒暂停时间不得超过5毫秒. Garbage-First GC 会尽力达成这个目标(有很大的概率会满足, 但并不完全确定,具体是多少将是硬实时的[hard real-time])。
为了达成这项指标, G1 有一些独特的实现。首先, 堆不再分成连续的年轻代和老年代空间。而是划分为多个(通常是2048个)可以存放对象的 小堆区(smaller heap regions)。每个小堆区都可能是 Eden区, Survivor区或者Old区. 在逻辑上, 所有的Eden区和Survivor区合起来就是年轻代, 所有的Old区拼在一起那就是老年代:
这样的划分使得 GC不必每次都去收集整个堆空间, 而是以增量的方式来处理: 每次只处理一部分小堆区,称为此次的回收集(collection set). 每次暂停都会收集所有年轻代的小堆区, 但可能只包含一部分老年代小堆区:
G1的另一项创新, 是在并发阶段估算每个小堆区存活对象的总数。用来构建回收集(collection set)的原则是: 垃圾最多的小堆区会被优先收集。这也是G1名称的由来: garbage-first。
要启用G1收集器, 使用的命令行参数为:
java -XX:+UseG1GC com.mypackages.MyExecutableClass
- 1
- 2
Evacuation Pause: Fully Young(转移暂停:纯年轻代模式)
在应用程序刚启动时, G1还未执行过(not-yet-executed)并发阶段, 也就没有获得任何额外的信息, 处于初始的 fully-young 模式. 在年轻代空间用满之后, 应用线程被暂停, 年轻代堆区中的存活对象被复制到存活区, 如果还没有存活区,则选择任意一部分空闲的小堆区用作存活区。
复制的过程称为转移(Evacuation), 这和前面讲过的年轻代收集器基本上是一样的工作原理。转移暂停的日志信息很长,为简单起见, 我们去除了一些不重要的信息. 在并发阶段之后我们会进行详细的讲解。此外, 由于日志记录很多, 所以并行阶段和“其他”阶段的日志将拆分为多个部分来进行讲解:
0.134: [GC pause (G1 Evacuation Pause) (young), 0.0144119 secs]
[Parallel Time: 13.9 ms, GC Workers: 8]
…
[Code Root Fixup: 0.0 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 0.1 ms]
[Other: 0.4 ms]
…
[Eden: 24.0M(24.0M)->0.0B(13.0M)
Survivors: 0.0B->3072.0K
Heap: 24.0M(256.0M)->21.9M(256.0M)]
[Times: user=0.04 sys=0.04, real=0.02 secs]
>
0.134: [GC pause (G1 Evacuation Pause) (young), 0.0144119 secs]
– G1转移暂停,只清理年轻代空间。暂停在JVM启动之后 134 ms 开始, 持续的系统时间为 0.0144秒 。[Parallel Time: 13.9 ms, GC Workers: 8]
– 表明后面的活动由8个 Worker 线程并行执行, 消耗时间为13.9毫秒(real time)。…
– 为阅读方便, 省略了部分内容,请参考后文。[Code Root Fixup: 0.0 ms]
– 释放用于管理并行活动的内部数据。一般都接近于零。这是串行执行的过程。[Code Root Purge: 0.0 ms]
– 清理其他部分数据, 也是非常快的, 但如非必要则几乎等于零。这是串行执行的过程。[Other: 0.4 ms]
– 其他活动消耗的时间, 其中有很多是并行执行的。…
– 请参考后文。[Eden: 24.0M(24.0M)->0.0B(13.0M)
– 暂停之前和暂停之后, Eden 区的使用量/总容量。Survivors: 0.0B->3072.0K
– 暂停之前和暂停之后, 存活区的使用量。Heap: 24.0M(256.0M)->21.9M(256.0M)]
– 暂停之前和暂停之后, 整个堆内存的使用量与总容量。[Times: user=0.04 sys=0.04, real=0.02 secs]
– GC事件的持续时间, 通过三个部分来衡量:
- user – 在此次垃圾回收过程中, 由GC线程所消耗的总的CPU时间。
- sys – GC过程中, 系统调用和系统等待事件所消耗的时间。
- real – 应用程序暂停的时间。在并行GC(Parallel GC)中, 这个数字约等于: (user time + system time)/GC线程数。 这里使用的是8个线程。 请注意,总是有一定比例的处理过程是不能并行化的。
说明: 系统时间(wall clock time, elapsed time), 是指一段程序从运行到终止,系统时钟走过的时间。一般来说,系统时间都是要大于CPU时间
最繁重的GC任务由多个专用的 worker 线程来执行。下面的日志描述了他们的行为:
[Parallel Time: 13.9 ms, GC Workers: 8]
[GC Worker Start (ms)
: Min: 134.0, Avg: 134.1, Max: 134.1, Diff: 0.1]
[Ext Root Scanning (ms)
: Min: 0.1, Avg: 0.2, Max: 0.3, Diff: 0.2, Sum: 1.2]
[Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Processed Buffers: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0]
[Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Code Root Scanning (ms)
: Min: 0.0, Avg: 0.0, Max: 0.2, Diff: 0.2, Sum: 0.2]
[Object Copy (ms)
: Min: 10.8, Avg: 12.1, Max: 12.6, Diff: 1.9, Sum: 96.5]
[Termination (ms)
: Min: 0.8, Avg: 1.5, Max: 2.8, Diff: 1.9, Sum: 12.2]
[Termination Attempts
: Min: 173, Avg: 293.2, Max: 362, Diff: 189, Sum: 2346]
[GC Worker Other (ms)
: Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
GC Worker Total (ms)
: Min: 13.7, Avg: 13.8, Max: 13.8, Diff: 0.1, Sum: 110.2]
[GC Worker End (ms)
: Min: 147.8, Avg: 147.8, Max: 147.8, Diff: 0.0]
>
[Parallel Time: 13.9 ms, GC Workers: 8]
– 表明下列活动由8个线程并行执行,消耗的时间为13.9毫秒(real time)。[GC Worker Start (ms)
– GC的worker线程开始启动时,相对于 pause 开始的时间戳。如果Min
和Max
差别很大,则表明本机其他进程所使用的线程数量过多, 挤占了GC的CPU时间。[Ext Root Scanning (ms)
– 用了多长时间来扫描堆外(non-heap)的root, 如 classloaders, JNI引用, JVM的系统root等。后面显示了运行时间, “Sum” 指的是CPU时间。[Code Root Scanning (ms)
– 用了多长时间来扫描实际代码中的 root: 例如局部变量等等(local vars)。[Object Copy (ms)
– 用了多长时间来拷贝收集区内的存活对象。[Termination (ms)
– GC的worker线程用了多长时间来确保自身可以安全地停止, 这段时间什么也不用做, stop 之后该线程就终止运行了。[Termination Attempts
– GC的worker 线程尝试多少次 try 和 teminate。如果worker发现还有一些任务没处理完,则这一次尝试就是失败的, 暂时还不能终止。[GC Worker Other (ms)
– 一些琐碎的小活动,在GC日志中不值得单独列出来。GC Worker Total (ms)
– GC的worker 线程的工作时间总计。[GC Worker End (ms)
– GC的worker 线程完成作业的时间戳。通常来说这部分数字应该大致相等, 否则就说明有太多的线程被挂起, 很可能是因为坏邻居效应(noisy neighbor) 所导致的。
此外,在转移暂停期间,还有一些琐碎执行的小活动。这里我们只介绍其中的一部分, 其余的会在后面进行讨论。
[Other: 0.4 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.2 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.1 ms]
[Humongous Register: 0.0 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.0 ms]
>
[Other: 0.4 ms]
– 其他活动消耗的时间, 其中有很多也是并行执行的。[Ref Proc: 0.2 ms]
– 处理非强引用(non-strong)的时间: 进行清理或者决定是否需要清理。[Ref Enq: 0.0 ms]
– 用来将剩下的 non-strong 引用排列到合适的 ReferenceQueue中。[Free CSet: 0.0 ms]
– 将回收集中被释放的小堆归还所消耗的时间, 以便他们能用来分配新的对象。
Concurrent Marking(并发标记)
G1收集器的很多概念建立在CMS的基础上,所以下面的内容需要你对CMS有一定的理解. 虽然也有很多地方不同, 但并发标记的目标基本上是一样的. G1的并发标记通过 Snapshot-At-The-Beginning(开始时快照) 的方式, 在标记阶段开始时记下所有的存活对象。即使在标记的同时又有一些变成了垃圾. 通过对象是存活信息, 可以构建出每个小堆区的存活状态, 以便回收集能高效地进行选择。
这些信息在接下来的阶段会用来执行老年代区域的垃圾收集。在两种情况下是完全地并发执行的: 一、如果在标记阶段确定某个小堆区只包含垃圾; 二、在STW转移暂停期间, 同时包含垃圾和存活对象的老年代小堆区。
当堆内存的总体使用比例达到一定数值时,就会触发并发标记。默认值为 45%
, 但也可以通过JVM参数 InitiatingHeapOccupancyPercent
来设置。和CMS一样, G1的并发标记也是由多个阶段组成, 其中一些是完全并发的, 还有一些阶段需要暂停应用线程。
阶段 1: Initial Mark(初始标记)。 此阶段标记所有从GC root 直接可达的对象。在CMS中需要一次STW暂停, 但G1里面通常是在转移暂停的同时处理这些事情, 所以它的开销是很小的. 可以在 Evacuation Pause 日志中的第一行看到(initial-mark)暂停:
1.631: [GC pause (G1 Evacuation Pause) (young) (initial-mark), 0.0062656 secs]
- 1
- 2
阶段 2: Root Region Scan(Root区扫描). 此阶段标记所有从 “根区域” 可达的存活对象。 根区域包括: 非空的区域, 以及在标记过程中不得不收集的区域。因为在并发标记的过程中迁移对象会造成很多麻烦, 所以此阶段必须在下一次转移暂停之前完成。如果必须启动转移暂停, 则会先要求根区域扫描中止, 等它完成才能继续扫描. 在当前版本的实现中, 根区域是存活的小堆区: y包括下一次转移暂停中肯定会被清理的那部分年轻代小堆区。
1.362: [GC concurrent-root-region-scan-start]
1.364: [GC concurrent-root-region-scan-end, 0.0028513 secs]
- 1
- 2
- 3
阶段 3: Concurrent Mark(并发标记). 此阶段非常类似于CMS: 它只是遍历对象图, 并在一个特殊的位图中标记能访问到的对象. 为了确保标记开始时的快照准确性, 所有应用线程并发对对象图执行的引用更新,G1 要求放弃前面阶段为了标记目的而引用的过时引用。
这是通过使用 Pre-Write
屏障来实现的,(不要和之后介绍的 Post-Write
混淆, 也不要和多线程开发中的内存屏障(memory barriers)相混淆)。Pre-Write屏障的作用是: G1在进行并发标记时, 如果程序将对象的某个属性做了变更, 就会在 log buffers 中存储之前的引用。 由并发标记线程负责处理。
1.364: [GC concurrent-mark-start]
1.645: [GC co ncurrent-mark-end, 0.2803470 secs]
- 1
- 2
- 3
阶段 4: Remark(再次标记). 和CMS类似,这也是一次STW停顿,以完成标记过程。对于G1,它短暂地停止应用线程, 停止并发更新日志的写入, 处理其中的少量信息, 并标记所有在并发标记开始时未被标记的存活对象。这一阶段也执行某些额外的清理, 如引用处理(参见 Evacuation Pause log) 或者类卸载(class unloading)。
1.645: [GC remark 1.645: [Finalize Marking, 0.0009461 secs]
1.646: [GC ref-proc, 0.0000417 secs] 1.646:
[Unloading, 0.0011301 secs], 0.0074056 secs]
[Times: user=0.01 sys=0.00, real=0.01 secs]
- 1
- 2
- 3
- 4
- 5
阶段 5: Cleanup(清理). 最后这个小阶段为即将到来的转移阶段做准备, 统计小堆区中所有存活的对象, 并将小堆区进行排序, 以提升GC的效率. 此阶段也为下一次标记执行所有必需的整理工作(house-keeping activities): 维护并发标记的内部状态。
最后要提醒的是, 所有不包含存活对象的小堆区在此阶段都被回收了。有一部分是并发的: 例如空堆区的回收,还有大部分的存活率计算, 此阶段也需要一个短暂的STW暂停, 以不受应用线程的影响来完成作业. 这种STW停顿的日志如下:
1.652: [GC cleanup 1213M->1213M(1885M), 0.0030492 secs]
[Times: user=0.01 sys=0.00, real=0.00 secs]
- 1
- 2
- 3
如果发现某些小堆区中只包含垃圾, 则日志格式可能会有点不同, 如:
1.872: [GC cleanup 1357M->173M(1996M), 0.0015664 secs]
[Times: user=0.01 sys=0.00, real=0.01 secs]
1.874: [GC concurrent-cleanup-start]
1.876: [GC concurrent-cleanup-end, 0.0014846 secs]
Evacuation Pause: Mixed (转移暂停: 混合模式)
能并发清理老年代中整个整个的小堆区是一种最优情形, 但有时候并不是这样。并发标记完成之后, G1将执行一次混合收集(mixed collection), 不只清理年轻代, 还将一部分老年代区域也加入到 collection set 中。
混合模式的转移暂停(Evacuation pause)不一定紧跟着并发标记阶段。有很多规则和历史数据会影响混合模式的启动时机。比如, 假若在老年代中可以并发地腾出很多的小堆区,就没有必要启动混合模式。
因此, 在并发标记与混合转移暂停之间, 很可能会存在多次 fully-young 转移暂停。
添加到回收集的老年代小堆区的具体数字及其顺序, 也是基于许多规则来判定的。 其中包括指定的软实时性能指标, 存活性,以及在并发标记期间收集的GC效率等数据, 外加一些可配置的JVM选项. 混合收集的过程, 很大程度上和前面的 fully-young gc 是一样的, 但这里我们还要介绍一个概念: remembered sets(历史记忆集)。
Remembered sets (历史记忆集)是用来支持不同的小堆区进行独立回收的。例如,在收集A、B、C区时, 我们必须要知道是否有从D区或者E区指向其中的引用, 以确定他们的存活性. 但是遍历整个堆需要相当长的时间, 这就违背了增量收集的初衷, 因此必须采取某种优化手段. 其他GC算法有独立的 Card Table 来支持年轻代的垃圾收集一样, 而G1中使用的是 Remembered Sets。
如下图所示, 每个小堆区都有一个 remembered set, 列出了从外部指向本区的所有引用。这些引用将被视为附加的 GC root. 注意,在并发标记过程中,老年代中被确定为垃圾的对象会被忽略, 即使有外部引用指向他们: 因为在这种情况下引用者也是垃圾。
接下来的行为,和其他垃圾收集器一样: 多个GC线程并行地找出哪些是存活对象,确定哪些是垃圾:
最后, 存活对象被转移到存活区(survivor regions), 在必要时会创建新的小堆区。现在,空的小堆区被释放, 可用于存放新的对象了。
为了维护 remembered set, 在程序运行的过程中, 只要写入某个字段,就会产生一个 Post-Write 屏障。如果生成的引用是跨区域的(cross-region),即从一个区指向另一个区, 就会在目标区的Remembered Set中,出现一个对应的条目。为了减少 Write Barrier 造成的开销, 将卡片放入Remembered Set 的过程是异步的, 而且经过了很多的优化. 总体上是这样: Write Barrier 把脏卡信息存放到本地缓冲区(local buffer), 有专门的GC线程负责收集, 并将相关信息传给被引用区的 remembered set。
混合模式下的日志, 和纯年轻代模式相比, 可以发现一些有趣的地方:
[
[Update RS (ms)
: Min: 0.7, Avg: 0.8, Max: 0.9, Diff: 0.2, Sum: 6.1]
[Processed Buffers
: Min: 0, Avg: 2.2, Max: 5, Diff: 5, Sum: 18]
[Scan RS (ms)
: Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.8]
[Clear CT: 0.2 ms]
[Redirty Cards: 0.1 ms]
1.[Update RS (ms)
– 因为 Remembered Sets 是并发处理的,必须确保在实际的垃圾收集之前, 缓冲区中的 card 得到处理。如果card数量很多, 则GC并发线程的负载可能就会很高。可能的原因是, 修改的字段过多, 或者CPU资源受限。
[Processed Buffers
– 每个 worker 线程处理了多少个本地缓冲区(local buffer)。[Scan RS (ms)
– 用了多长时间扫描来自RSet的引用。[Clear CT: 0.2 ms]
– 清理 card table 中 cards 的时间。清理工作只是简单地删除“脏”状态, 此状态用来标识一个字段是否被更新的, 供Remembered Sets使用。[Redirty Cards: 0.1 ms]
– 将 card table 中适当的位置标记为 dirty 所花费的时间。”适当的位置”是由GC本身执行的堆内存改变所决定的, 例如引用排队等。
总结
通过本节内容的学习, 你应该对G1垃圾收集器有了一定了解。当然, 为了简洁, 我们省略了很多实现细节, 例如如何处理巨无霸对象(humongous objects)。 综合来看, G1是HotSpot中最先进的准产品级(production-ready)垃圾收集器。重要的是, HotSpot 工程师的主要精力都放在不断改进G1上面, 在新的java版本中,将会带来新的功能和优化。
可以看到, G1 解决了 CMS 中的各种疑难问题, 包括暂停时间的可预测性, 并终结了堆内存的碎片化。对单业务延迟非常敏感的系统来说, 如果CPU资源不受限制,那么G1可以说是 HotSpot 中最好的选择, 特别是在最新版本的Java虚拟机中。当然,这种降低延迟的优化也不是没有代价的: 由于额外的写屏障(write barriers)和更积极的守护线程, G1的开销会更大。所以, 如果系统属于吞吐量优先型的, 又或者CPU持续占用100%, 而又不在乎单次GC的暂停时间, 那么CMS是更好的选择。
总之: G1适合大内存,需要低延迟的场景。
选择正确的GC算法,唯一可行的方式就是去尝试,并找出不对劲的地方, 在下一章我们将给出一般指导原则。
注意,G1可能会成为Java 9的默认GC: http://openjdk.java.net/jeps/248
Shenandoah 的性能
译注: Shenandoah: 谢南多厄河; 情人渡,水手谣; –> 此款GC暂时没有标准的中文译名; 翻译为大水手垃圾收集器?
我们列出了HotSpot中可用的所有 “准生产级” 算法。还有一种还在实验室中的算法, 称为超低延迟垃圾收集器(Ultra-Low-Pause-Time Garbage Collector). 它的设计目标是管理大型的多核服务器上,超大型的堆内存: 管理 100GB 及以上的堆容量, GC暂停时间小于 10ms。 当然,也是需要和吞吐量进行权衡的: 没有GC暂停的时候,算法的实现对吞吐量的性能损失不能超过10%
在新算法作为准产品级进行发布之前, 我们不准备去讨论具体的实现细节, 但它也构建在前面所提到的很多算法的基础上, 例如并发标记和增量收集。但其中有很多东西是不同的。它不再将堆内存划分成多个代, 而是只采用单个空间. 没错, Shenandoah 并不是一款分代垃圾收集器。这也就不再需要 card tables 和 remembered sets. 它还使用转发指针(forwarding pointers), 以及Brooks 风格的读屏障(Brooks style read barrier), 以允许对存活对象的并发复制, 从而减少GC暂停的次数和时间。
关于 Shenandoah 的更多信息,请参考博客: https://rkennke.wordpress.com/, JEP文档: http://openjdk.java.net/jeps/189, 或者Google搜索 “Shenandoah GC“。
请继续阅读下一章: 5. GC 调优(基础篇) - GC参考手册
原文链接: GC Algorithms: Implementations
翻译人员: 铁锚 http://blog.csdn.net/renfufei
翻译时间: 2016年02月06日
微信公众号【Java技术江湖】一位阿里 Java 工程师的技术小站。(关注公众号后回复”Java“即可领取 Java基础、进阶、项目和架构师等免费学习资料,更有数据库、分布式、微服务等热门技术学习视频,内容丰富,兼顾原理和实践,另外也将赠送作者原创的Java学习指南、Java程序员面试指南等干货资源)