第5章研究了所有垃圾收集器的一般行为，包括适用于所有GC算法的JVM标志：如何选择堆大小、分代大小、日志等等。垃圾收集的基本调优可在许多情况下都是足够的了。如果没有的话，那么就应该检查使用的GC算法的具体操作，以确定如何更改其参数，以最大限度地减少GC对应用程序的影响。
调优某个收集器所需的关键信息是启用该收集器时来自GC日志的数据。本章首先从日志输出的角度来看每个算法，这让我们了解GC算法如何工作，以及如何调整它以更好地工作。然后，每个部分都包含调优信息，以实现更好的性能。
本章还将详细介绍一些新的实验性收集器。在撰写本文时，这些收集器可能还不是100%可靠的，但到Java的下一个LTS版本发布时，可能会成为成熟的的收集器(就像G1 GC开始时是一个实验性收集器，现在是JDK 11中的默认值)。
一些不寻常的情况会影响所有 GC 算法的性能：分配非常大的对象、既不是短期对象也不是长期对象，等等。这些情况将在本章末尾说明。
Understanding the Throughput Collector
我们首先从吞吐量收集器开始。尽管我G1 GC 收集器通常是我们的首选，但吞吐量收集器的细节更容易理解，并为理解其工作原理奠定了更好的基础。
回想第5章，垃圾收集器必须执行三种基本操作：发现未使用的对象【mark】、释放其内存【sweep】以及压缩堆【compact】。吞吐量收集器在同一个GC周期内完成所有这些操作；这些操作统称为一个收集【collection】。这些收集器可以在单个操作中收集年轻代或老年代。
图6-1显示了年轻代收集前后的堆：
Figure 6-1. A throughput GC young collection
当伊甸区被填满时，就会触发一次年轻代收集。年轻代收集将所有对象移出伊甸区：一些对象移到其中一个幸存者空间(上图中的S0)，一些对象移到现在包含更多对象的老年代。当然，许多对象被丢弃，因为它们不再被引用。
因为伊甸区在此操作后通常是空的，所以可以认为它已被压缩了。
在带有 PrintGCDetails 的 JDK 8 GC 日志中，吞吐量收集器的 Monor GC 如下所示：
17.806: [GC (Allocation Failure) [PSYoungGen: 227983K->14463K(264128K)]
280122K->66610K(613696K), 0.0169320 secs]
[Times: user=0.05 sys=0.00, real=0.02 secs]此 GC 发生在程序启动后 17.806 秒。年轻代中的对象现在占用 14463 KB (14MB，全部在幸存者空间中)；在GC之前，它们占用了227,983 KB (227 MB)。此时，年轻代的总大小是264 MB。
同时，堆的整体入住率【occupancy 】(包括年轻代和老年代)从 280 MB 减少到 66 MB ，此时，整个堆的大小是 613 MB。这个操作花了不到 0.02 秒(实际输出是0.0169320)。由于年轻的收集是由多个线程(在此配置中是四个线程)完成的，因此程序的CPU时间比实时时间要多。
JDK 11中相同的日志看起来像这样:
[17.805s][info][gc,start ] GC(4) Pause Young (Allocation Failure)
[17.806s][info][gc,heap ] GC(4) PSYoungGen: 227983K->14463K(264128K)
[17.806s][info][gc,heap ] GC(4) ParOldGen: 280122K->66610K(613696K)
[17.806s][info][gc,metaspace ] GC(4) Metaspace: 3743K->3743K(1056768K)
[17.806s][info][gc ] GC(4) Pause Young (Allocation Failure)
496M->79M(857M) 16.932ms
[17.086s][info][gc,cpu ] GC(4) User=0.05s Sys=0.00s Real=0.02s这里的信息是一样的；只是格式不同而已。这段日志记录有好几行；前面的日志条目实际上是一行(但不以这种格式复制)。这个日志还打印出元空间【metaspace】的大小，但是在年轻的收集期间元空间【metaspace】的大小永远不会改变。这个元空间【metaspace】也不包括在这个示例的第 5 行报告的总堆大小中。
图6-2显示了 Full GC前后的堆。
Figure 6-2. A throughput full GC
老年代收集释放了年轻代中的一切。遗留在老代中的唯一对象是那些具有活跃引用【active references】的对象，所有这些对象都已被压缩，所以老年代的开始部分全部被占用，而其余部分则是空闲的。.
GC 日志是这样的：
64.546: [Full GC (Ergonomics) [PSYoungGen: 15808K->0K(339456K)]
[ParOldGen: 457753K->392528K(554432K)] 473561K->392528K(893888K)
[Metaspace: 56728K->56728K(115392K)], 1.3367080 secs]
[Times: user=4.44 sys=0.01, real=1.34 secs]年轻代现在占用 0 个字节（它的大小为 339 MB）。请注意，图中的幸存者空间也被清除了。老年代的数据量从 457 MB 减少到 392 MB，因此整个堆的使用量从 473 MB 减少到 392 MB。元空间的大小不变；在大多数 Full GC 期间，它是不会被收集的。（如果元空间空间不足，JVM 将运行一个 Full GC 来收集它，您会看到元空间的大小发生了变化；后面我将进一步展示它。）因为在一个 Full GC 中有更多的工作要做，所以它花费了1.3 秒的实时时间和 4.4 秒的CPU时间（同样是四个并行线程）。
类似的 JDK 11日志如下:
[63.205s][info][gc,start ] GC(13) Pause Full (Ergonomics)
[63.205s][info][gc,phases,start] GC(13) Marking Phase
[63.314s][info][gc,phases ] GC(13) Marking Phase 109.273ms
[63.314s][info][gc,phases,start] GC(13) Summary Phase
[63.316s][info][gc,phases ] GC(13) Summary Phase 1.470ms
[63.316s][info][gc,phases,start] GC(13) Adjust Roots
[63.331s][info][gc,phases ] GC(13) Adjust Roots 14.642ms
[63.331s][info][gc,phases,start] GC(13) Compaction Phase
[63.482s][info][gc,phases ] GC(13) Compaction Phase 1150.792ms
[64.482s][info][gc,phases,start] GC(13) Post Compact
[64.546s][info][gc,phases ] GC(13) Post Compact 63.812ms
[64.546s][info][gc,heap ] GC(13) PSYoungGen: 15808K->0K(339456K)
[64.546s][info][gc,heap ] GC(13) ParOldGen: 457753K->392528K(554432K)
[64.546s][info][gc,metaspace ] GC(13) Metaspace: 56728K->56728K(115392K)
[64.546s][info][gc ] GC(13) Pause Full (Ergonomics)
462M->383M(823M) 1336.708ms
[64.546s][info][gc,cpu ] GC(13) User=4.446s Sys=0.01s Real=1.34sQUICK SUMMARY
- 吞吐量收集器有两个操作：Minor GC 和 Full GC ，每个 GC 都对目标分代进行标记、释放和压缩
- 从 GC 日志中获取的时间是确定GC对使用这些收集器的应用程序的总体影响的一种快速方法
Adaptive and Static Heap Size Tuning
吞吐量收集器的调优与暂停时间有关，并在总体堆大小与老代和新代的大小之间取得平衡。
这里有两个点需要权衡考虑。
首先，我们有时间与空间的经典编程权衡。更大的堆将消耗机器上更多的内存，使用这些内存的好处是(至少在一定程度上)应用程序将拥有更高的吞吐量。
第二个权衡关系到执行 GC 所需的时长。可以通过增加堆大小来减少 Full GC 暂停次数，但是由于 GC 时间变长了，这可能会产生平均响应时间增加的不利影响。类似地，可以通过将更多的堆分配给年轻代而不是老一代来缩短 Full GC 暂停时间，但这反过来又会增加老年代 GC 收集的频率。
这些权衡的效果如图 6-3 所示。此图显示了以不同堆大小运行的普通 REST 服务器的最大吞吐量。由于只有 256 MB 的堆，服务器在 GC 上花费了大量时间（实际上占总时间的 36%）；结果，吞吐量受到限制。随着堆大小的增加，吞吐量迅速增加——直到堆大小设置为 1,500 MB。在那之后，吞吐量增长的速度不那么快了：此时应用程序并没有受到GC的限制（大约 6% 的时间在 GC ）。收益递减规律已经悄然出现：应用程序可以使用额外的内存来获得吞吐量，但收益变得更加有限。
堆大小达到 4,500 MB 后，吞吐量开始略有下降。此时，应用程序已经达到了第二个权衡：额外的内存导致了更长的 GC 周期，而这些更长的周期——即使频率不那么频繁——也会降低整体吞吐量。
该图中的数据是通过禁用JVM中的自适应调整大小参数获得的;最小和最大堆大小设置为相同的值。可以在任何应用程序上运行实验，并确定堆和代的最佳大小，但通常更容易让JVM做出这些决定(这通常是发生的，因为默认情况下启用了自适应大小)。
此图中的数据是通过禁用 JVM 中的自适应参数获得的；最小和最大堆大小设置为相同的值。可以在任何应用程序上运行实验并确定堆和代的最佳大小，但让 JVM 做出这些决定通常更容易（这通常会发生，因为KVM默认启用自适应）。
Figure 6-3. Throughput with various heap sizes
吞吐量收集器中的自适应将调整堆(以及代)的大小，以满足其暂停时间目标。这些目标是用这些标志设置的：
- -XX:MaxGCPauseMillis=N 设置最大GC暂停时间
- -XX:GCTimeRatio=N 设置GC时间占比
MaxGCPauseMillis 参数指定应用程序愿意容忍的最大暂停时间。将其设置为 0 或 50 ms 之类的小值可能很诱人。请注意，这个目标同时适用于 Minor GC 和 Full GC。如果使用了一个非常小的值，应用程序最终将得到一个非常小的老年代：例如，一个可以在50毫秒内清理完的老年代。这将导致JVM非常频繁地执行 Full GC，并且性能将会很差。把这个值设为可以实现的目标。缺省情况下，没有设置此参数。
GCTimeRatio标志指定了您希望应用程序花费在GC上的时间(与应用程序级线程应该运行的时间相比)。它是一个比率，所以 N 的值需要一些思考。这个值被用在下面的等式中，用来确定应用程序线程在理想情况下应该运行的时间百分比:
GCTimeRatio 参数的默认值为99。将该值代入方程可以得到0.99，这意味着我们的目标是将 99% 的时间用于应用程序处理，而仅将1%的时间用于GC。但不要被这些数字在默认情况下是如何排列的所迷惑。GCTimeRatio为95并不意味着GC应该运行高达5%的时间:它意味着GC应该运行达1.94%的时间。
确定你想让应用程序执行工作的最小时间百分比(比如95%)，然后从这个方程计算GCTimeRatio的值，这是很容易的:
对于95%(0.95)的吞吐量目标，该方程生成的GCTimeRatio为19。
JVM使用这两个参数在由初始堆大小(-Xms)和最大堆大小(-Xmx)建立的边界内设置堆的大小。MaxGCPauseMillis参数优先：如果设置了它，将调整年轻代和年老代的大小，直到达到暂停时间目标。一旦发生这种情况，堆的总体大小就会增加，直到满足时间比目标为止。一旦这两个目标都得到满足，JVM将尝试减少堆的大小，以便最终得到满足这两个目标的最小堆。
因为默认情况下没有设置暂停时间目标，所以自适应的通常效果是堆（和代）大小将增加，直到满足 GCTimeRatio 目标。但实际上，该标志的默认设置是乐观的。当然，您的经验会有所不同，但我更习惯于看到应用程序花费 3% 到 6% 的时间在GC上，并且运行得很好。有时我甚至在内存严重受限的环境中工作；这些应用程序最终会花费10%到15%的时间在GC上。GC对这些应用程序的性能有很大的影响，但总体性能目标仍然得到了满足。
因此，最佳设置会根据应用程序的目标而有所不同。在没有其他目标的情况下，我从19的时间比率开始(GC占用 5%)。
表 6-1 显示了这种动态调优对于需要小堆和很少进行GC的应用程序的效果(普通 REST 服务器很少有长期存在的对象)。
| GC settings | End heap size | Percent time in GC | OPS |
|---|---|---|---|
| Default | 649 MB | 0.9% | 9.2 |
|
| 560 MB | 1.0% | 9.2 |
|
| 2 GB | 0.04% | 9.2 |
默认情况下，堆的最小大小为 64 MB，最大大小为 2 GB（因为机器有 8 GB 的物理内存）。在这种情况下，GCTimeRatio 就像预期的那样工作：堆动态调整为 649 MB，此时应用程序在 GC 中花费了大约 1% 的总时间。
在本例中，设置 MaxGCPauseMillis 参数将开始减少堆的大小，以满足暂停时间目标。因为垃圾收集器在这个例子中要执行的工作很少，所以它成功了，并且仍然可以只花费总GC时间的1%，同时保持9.2 OPS的吞吐量。
最后，请注意，堆并不总是越多越好。一个完整的 2 GB 堆确实意味着应用程序可以在 GC 上花费更少的时间，但 GC 并不是这里的主要性能因素，因此吞吐量不会增加。像往常一样，花时间优化应用程序的错误区域并没有帮助。
如果更改了相同的应用程序，使每个用户的前 50 个请求保存在全局缓存中(例如，JPA 缓存就会这样做)，垃圾收集器就必须更加努力地工作。表 6-2 显示了这种情况下的权衡取舍。
| GC settings | End heap size | Percent time in GC | OPS |
|---|---|---|---|
| Default | 1.7 GB | 9.3% | 8.4 |
|
| 588 MB | 15.1% | 7.9 |
|
| 2 GB | 5.1% | 9.0 |
|
| 2.1 GB | 8.8% | 9.0 |
在 GC 中花费大量时间的测试中，GC 行为是不同的。在这个测试中，JVM 永远无法满足 1% 的吞吐量目标；它尽最大努力适应默认目标并使用 1.7 GB 空间完成合理的工作。
当给出不切实际的暂停时间为目标时，应用程序的行为会变得更糟。为了实现 50 毫秒的收集时间，堆保持在 588 MB，但这意味着 GC 现在变得过于频繁。因此，吞吐量显着下降。在这个场景中，通过将初始堆大小和最大堆大小都设置为 2GB 来指示 JVM 利用整个堆，可以获得更好的性能。
最后，表格的最后一行显示了当堆的大小合理，并且我们将实际的时间比目标设置为 5% 时，会发生什么。JVM自己确定大约2 GB是最优的堆大小，并且它实现了与手工调优的情况相同的吞吐量。
Understanding the G1 Garbage Collector
G1 GC 对堆中的离散区域【regions】进行操作。每个区域【regions】（默认情况下大约有 2,048 个）既可以属于老年代，也可以属于年轻代，而且分代区域不必是连续的。在老年代中使用区域的想法是，当并发后台线程【concurrent background threads】查找未引用的对象时，某些区域将比其他区域包含更多的垃圾。区域的实际收集仍然需要停止应用程序线程【Stop The World】，但是G1 GC可以专注于大部分是垃圾的区域，并且只花费一点点时间清空这些区域。这种方法——只清除大部分是垃圾的区域——就是 G1 GC 的名字由来：garbage first。
这不适用于年轻代中的区域：在年轻代 GC 期间，整个年轻代要么被释放，要么被提升（即到幸存区或老年代）。尽管如此，年轻代仍是根据区域定义的，那么调整代的大小就会容易得多。
G1 GC 也被称为并发收集器【concurrent collector】，因为老年代中空闲对象的标记与应用程序线程同时发生（即它们仍然在运行）。但它并不是完全并发的，因为年轻代的标记和压缩需要停止所有应用程序线程，而老年代的压缩也是在应用程序线程停止时发生的。
G1 GC有四个逻辑操作：
- 一个年轻代收集、
- 一个后台并发标记周期
- 一个混合收集
- 如果需要的话，一个 Full GC
我们将依次查看它们，从图 6-4 所示的G1 GC年轻代收集开始。
Figure 6-4. A G1 GC young collection
这个图中的每个小方块代表一个 G1 GC 区域。每个区域的数据用黑色区域表示，每个区域的字母表示该区域所属的代([E]den， [O]ld generation， [S]urvival space)。空的区域不属于任何代；G1 GC 将它们任意用于它认为必要的任何代。
当伊甸区填满时（在本例中，在填满四个区域之后）触发 G1 GC 年轻收集。收集完成后，伊甸区是空的（尽管已为其分配了区域，随着应用程序的进行，伊甸园将开始充满数据）。至少有一个区域被分配给幸存区（本例中部分填充），并且一些数据已经移入老年代。
G1 中的 GC 日志说明此收集器与其他收集器中的略有不同。 JDK 8 示例日志是使用 PrintGCDetails 获取的，但 G1 GC 日志中要远比这更详细。这些示例仅显示了一些重要的行。
以下是年轻代的标准收集日志：
23.430: [GC pause (young), 0.23094400 secs]
...
[Eden: 1286M(1286M)->0B(1212M)
Survivors: 78M->152M Heap: 1454M(4096M)->242M(4096M)]
[Times: user=0.85 sys=0.05, real=0.23 secs]年轻代的收集耗时 0.23 秒，期间 GC 线程消耗了 0.85 秒的 CPU 时间。 1,286 MB 的对象被移出伊甸区（自适应调整大小为 1,212 MB）；其中 74 MB 被移动到幸存者空间（它的大小从 78 M 增加到 152 MB），其余的被释放。我们通过观察到总堆占用减少了 1,212 MB，我们知道它们被释放了。在一般情况下，幸存区中的一些对象可能已经被移动到老年代，如果幸存区已满，伊甸区中的一些对象会被直接提升到老年代——在这种情况下，老年代内存占用会增加。
JDK 11中类似的日志如下所示：
[23.200s][info ][gc,start ] GC(10) Pause Young (Normal)
(G1 Evacuation Pause)
[23.200s][info ][gc,task ] GC(10) Using 4 workers of 4 for evacuation
[23.430s][info ][gc,phases ] GC(10) Pre Evacuate Collection Set: 0.0ms
[23.430s][info ][gc,phases ] GC(10) Evacuate Collection Set: 230.3ms
[23.430s][info ][gc,phases ] GC(10) Post Evacuate Collection Set: 0.5ms
[23.430s][info ][gc,phases ] GC(10) Other: 0.1ms
[23.430s][info ][gc,heap ] GC(10) Eden regions: 643->606(606)
[23.430s][info ][gc,heap ] GC(10) Survivor regions: 39->76(76)
[23.430s][info ][gc,heap ] GC(10) Old regions: 67->75
[23.430s][info ][gc,heap ] GC(10) Humongous regions: 0->0
[23.430s][info ][gc,metaspace ] GC(10) Metaspace: 18407K->18407K(1067008K)
[23.430s][info ][gc ] GC(10) Pause Young (Normal)
(G1 Evacuation Pause)
1454M(4096M)->242M(4096M) 230.104ms
[23.430s][info ][gc,cpu ] GC(10) User=0.85s Sys=0.05s Real=0.23s一个并发 G1 GC 周期的开始和结束如图6-5所示：
Figure 6-5. Concurrent collection performed by G1 GC
该图显示了三个需要注意的重要现象。
首先，年轻代的占用已经改变了：这说明在并发周期中至少会有一个（可能更多）年轻代集合发生。因此，标记周期之前的伊甸区已被完全释放，并且开始在新的伊甸区上进行分配【allocated】。
其次，一些区域现在用 X 标记。这些区域属于老年代（注意它们仍然包含数据）——它们是在标记周期中已确定主要包含垃圾的区域。
最后，请注意老年代（由标记为 O 或 X 的区域组成）实际上在周期完成后被占用更多。这是因为在标记周期中发生的年轻代收集将数据提升到了老年代。此外，标记周期实际上并没有释放老一代中的任何数据：它只是识别出大部分是垃圾的区域。来自这些区域的数据将在稍后的周期中释放。
G1 GC 并发周期有多个阶段，其中一些阶段会停止所有的应用程序线程，而另一些阶段则不会。第一个阶段称为初始标记【initial-mark】（在 JDK 8 中）或并发启动【concurrent start】（在 JDK 11 中）。该阶段停止所有应用程序线程——部分原因是它还执行一个年轻代收集，并设置周期的下一个阶段。
在JDK 8中，它看起来是这样的：
50.541: [GC pause (G1 Evacuation pause) (young) (initial-mark), 0.27767100 secs]
... lots of other data ...
[Eden: 1220M(1220M)->0B(1220M)
Survivors: 144M->144M Heap: 3242M(4096M)->2093M(4096M)]
[Times: user=1.02 sys=0.04, real=0.28 secs]在JDK 11中是这样的：
[50.261s][info ][gc,start ] GC(11) Pause Young (Concurrent Start)
(G1 Evacuation Pause)
[50.261s][info ][gc,task ] GC(11) Using 4 workers of 4 for evacuation
[50.541s][info ][gc,phases ] GC(11) Pre Evacuate Collection Set: 0.1ms
[50.541s][info ][gc,phases ] GC(11) Evacuate Collection Set: 25.9ms
[50.541s][info ][gc,phases ] GC(11) Post Evacuate Collection Set: 1.7ms
[50.541s][info ][gc,phases ] GC(11) Other: 0.2ms
[50.541s][info ][gc,heap ] GC(11) Eden regions: 1220->0(1220)
[50.541s][info ][gc,heap ] GC(11) Survivor regions: 144->144(144)
[50.541s][info ][gc,heap ] GC(11) Old regions: 1875->1946
[50.541s][info ][gc,heap ] GC(11) Humongous regions: 3->3
[50.541s][info ][gc,metaspace ] GC(11) Metaspace: 52261K->52261K(1099776K)
[50.541s][info ][gc ] GC(11) Pause Young (Concurrent Start)
(G1 Evacuation Pause)
1220M->0B(1220M) 280.055ms
[50.541s][info ][gc,cpu ] GC(11) User=1.02s Sys=0.04s Real=0.28s与常规的年轻收集一样，应用程序线程被停止（0.28 秒），年轻代被清空（因此伊甸区的大小为 0 ）。 71 MB 的数据从年轻代移到了老年代。这在 JDK 8 中有点难以分辨（它是 2,093 – 3,242 + 1,220）； JDK 11 的输出更清楚地表明了这一点。
另一方面，JDK 11 的输出包含对我们尚未讨论的一些内容的引用。首先是大小以区域为单位，而不是以 MB 为单位。我们将在本章后面讨论区域大小，但在此示例中，区域大小为 1 MB。此外，JDK 11 提到了一个新领域：humongous regions。这是老年代的一部分，本章稍后也会讨论。
Phase 1: Initial Mark 此阶段标记所有可直接从GC Root 访问到的对象。在CMS中，它需要一个单独的STW，但在G1中，它通常是紧跟在在年轻代的疏散暂停之后，所以它的开销是很小的。
初始标记【initial-mark】（在 JDK 8 中）或并发启动【concurrent start】（在 JDK 11 中）日志消息宣布后台并发周期【background concurrent cycle】已经开始。由于标记周期阶段的初始标记也需要停止所有应用程序线程，因此 G1 GC 利用年轻代 GC 周期来完成这项工作。将初始标记阶段添加到年轻 GC 的影响并不是很大：它比前面的年轻代收集多使用了 20% 的CPU 周期，虽然停顿的时间只稍微长一点（幸运的是，机器上有用于并行G1线程的空闲CPU周期，否则暂停时间会更长）。
Phase 2: Root Region Scan 此阶段段标记了从所谓的根区域【root region】（即那些不是空的且我们可能最终不得不在标记周期的中间进行收集的区域）可以到达的所有活动对象。由于在并发标记的中间移动东西会导致麻烦，这个阶段必须在下一个疏散暂停开始之前完成。在当前的实现中，根区域指的是幸存区，G1 GC 扫描初始标记的幸存区以查找对旧代的引用，并标记被引用的对象。
接下来，G1 GC 扫描根区域【root region】:
50.819: [GC concurrent-root-region-scan-start]
51.408: [GC concurrent-root-region-scan-end, 0.5890230]
[50.819s][info ][gc ] GC(20) Concurrent Cycle
[50.819s][info ][gc,marking ] GC(20) Concurrent Clear Claimed Marks
[50.828s][info ][gc,marking ] GC(20) Concurrent Clear Claimed Marks 0.008ms
[50.828s][info ][gc,marking ] GC(20) Concurrent Scan Root Regions
[51.408s][info ][gc,marking ] GC(20) Concurrent Scan Root Regions 589.023ms这需要 0.58 秒，但不会停止应用程序线程；它只使用后台线程。然而，这个阶段不能被年轻代收集打断，因此为这些后台线程提供可用的 CPU 周期是至关重要的。如果在根区域扫描【root region scanning】期间年轻代恰好填满，则年轻代收集（已停止所有应用程序线程）必须等待根扫描完成。实际上，这意味着收集年轻代的时间比平时更长。这种情况在 GC 日志中显示如下：
350.994: [GC pause (young)
351.093: [GC concurrent-root-region-scan-end, 0.6100090]
351.093: [GC concurrent-mark-start],0.37559600 secs]
[350.384s][info][gc,marking ] GC(50) Concurrent Scan Root Regions
[350.384s][info][gc,marking ] GC(50) Concurrent Scan Root Regions 610.364ms
[350.994s][info][gc,marking ] GC(50) Concurrent Mark (350.994s)
[350.994s][info][gc,marking ] GC(50) Concurrent Mark From Roots
[350.994s][info][gc,task ] GC(50) Using 1 workers of 1 for marking
[350.994s][info][gc,start ] GC(51) Pause Young (Normal) (G1 Evacuation Pause)此处的 GC 暂停在根区域扫描【root region scanning】结束之前开始。在 JDK 8 中，GC 日志中的交错输出表明年轻代收集必须暂停以等待根区域扫描完成才能继续进行。在 JDK 11 中，这有点难以检测：您必须注意根区域扫描结束的时间戳与下一次年轻收集开始的时间戳完全相同。
无论哪种情况，都不可能确切地知道年轻代收集到底延迟了多长时间。在本例中，不一定延迟整个 610 毫秒；在那段时间里（直到年轻代真正填满），事情还在继续。但是在这种情况下，时间戳显示应用程序线程额外等待了大约 100 毫秒——这就是为什么年轻 GC 暂停的持续时间比该日志中其他暂停的平均持续时间长约 100 毫秒（如果这种情况频繁发生，则表明需要更好地调整 G1 GC，如下一节所述。）
Phase 3: Concurrent Mark. 阶段段与 CMS 非常相似：它只是遍历对象图，并在一个特殊的位图中标记访问的对象。为了确保满足原始快照【snapshot-at-the beginning】的语义，G1 GC要求应用程序线程对对象图进行的所有并发更新都留下之前的引用，以供标记。这是通过使用Pre-Write屏障(不要与Post-Write屏障和与多线程编程相关的内存屏障混淆)来实现的。它们的功能是，当 G1 处于并发标记【Concurrent Marking】状态时，你写入一个属性字段时，必须将之前的引用存储在所谓的日志缓冲区【log buffers】中，以供并发标记【Concurrent Marking】线程处理。
在根区域扫描之后，G1 GC 进入并发标记【concurrent marking】阶段。这完全在后台发生；开始和结束时会打印一条消息：
111.382: [GC concurrent-mark-start]
....
120.905: [GC concurrent-mark-end, 9.5225160 sec]
[111.382s][info][gc,marking ] GC(20) Concurrent Mark (111.382s)
[111.382s][info][gc,marking ] GC(20) Concurrent Mark From Roots
...
[120.905s][info][gc,marking ] GC(20) Concurrent Mark From Roots 9521.994ms
[120.910s][info][gc,marking ] GC(20) Concurrent Preclean
[120.910s][info][gc,marking ] GC(20) Concurrent Preclean 0.522ms
[120.910s][info][gc,marking ] GC(20) Concurrent Mark (111.382s, 120.910s)
9522.516ms并发标记可以被打断，因此在这个阶段可能会发生年轻代收集(因此在有省略号的地方会有很多GC输出)。
标记阶段之后是重标记阶段和正常的清理阶段。
Phase 4: Remark. 这是一个停止世界的暂停，就像在 CMS 中看到的那样。对于G1，它会短暂地暂停应用程序线程，以停止并发更新日志的流入，并处理剩下的少量更新日志，并标记在并发标记【Concurrent Marking】周期启动时仍在活动的任何尚未标记的对象。此阶段还执行一些额外的清理，例如引用处理【reference processing】(请参阅疏散暂停日志)或类卸载【class unloading】。
Phase 5. Cleanup. 最后一个阶段为即将到来的疏散阶段做好准备，计算堆区域中的所有活动对象，并根据预期的 GC 效率对这些区域进行排序。它还执行为并发标记的下一次迭代维护内部状态所需的所有内务管理活动。最后但并非最不重要的是，在此阶段将回收完全不包含活动对象的区域。这个阶段的某些部分是并发的，例如空区域回收【empty region reclamation】和活跃度计算【liveness calculation】，但是它还需要在应用程序线程不干扰的情况下短暂的停止状态暂停来完成图片。
120.910: [GC remark 120.959:
[GC ref-PRC, 0.0000890 secs], 0.0718990 secs]
[Times: user=0.23 sys=0.01, real=0.08 secs]
120.985: [GC cleanup 3510M->3434M(4096M), 0.0111040 secs]
[Times: user=0.04 sys=0.00, real=0.01 secs]
[120.909s][info][gc,start ] GC(20) Pause Remark
[120.909s][info][gc,stringtable] GC(20) Cleaned string and symbol table,
strings: 1369 processed, 0 removed,
symbols: 17173 processed, 0 removed
[120.985s][info][gc ] GC(20) Pause Remark 2283M->862M(3666M) 80.412ms
[120.985s][info][gc,cpu ] GC(20) User=0.23s Sys=0.01s Real=0.08s这些阶段会停止应用程序线程，尽管通常是很短的时间。接下来，一个额外的清理阶段并发发生（并发清理）:
120.996: [GC concurrent-cleanup-start]
120.996: [GC concurrent-cleanup-end, 0.0004520]
[120.878s][info][gc,start ] GC(20) Pause Cleanup
[120.879s][info][gc ] GC(20) Pause Cleanup 1313M->1313M(3666M) 1.192ms
[120.879s][info][gc,cpu ] GC(20) User=0.00s Sys=0.00s Real=0.00s
[120.879s][info][gc,marking ] GC(20) Concurrent Cleanup for Next Mark
[120.996s][info][gc,marking ] GC(20) Concurrent Cleanup for Next Mark
117.168ms
[120.996s][info][gc ] GC(20) Concurrent Cycle 70,177.506ms这样，正常的G1 GC后台标记周期【background marking cycle】就完成了——至少在寻找垃圾的过程中是这样。但迄今为止，真正被释放的还很少。在清理阶段有一小部分内存被回收，但G1 GC在这一阶段真正做的是识别大部分是垃圾并且可以回收的旧区域（图6-5中标记为X的区域）。
现在G1 GC 执行一系列 Mixed GCs。它们被称为混合，因为它们除了执行正常的年轻代收集之外，还收集一些被标记的区域。Mixed GC 的效果如图 6-6 所示。
和年轻代收集一样，G1 GC 已经完全清空了伊甸区并调整了幸存区空间。此外，还收集了两个标记区域。众所周知，这些区域中大部分是垃圾，因此其中很大一部分被释放了。这些区域中的任何活动数据都被移动到另一个区域（就像活动数据从年轻代移动到老年代的区域一样）。这就是 G1 GC 压缩老年代的方式——随着G1 GC的进行，像这样移动对象实质上是在压缩堆。
Figure 6-6. Mixed GC performed by G1 GC
Mixed GC 操作日志通常是这样的:
79.826: [GC pause (mixed), 0.26161600 secs]
....
[Eden: 1222M(1222M)->0B(1220M)
Survivors: 142M->144M Heap: 3200M(4096M)->1964M(4096M)]
[Times: user=1.01 sys=0.00, real=0.26 secs]
[3.800s][info][gc,start ] GC(24) Pause Young (Mixed) (G1 Evacuation Pause)
[3.800s][info][gc,task ] GC(24) Using 4 workers of 4 for evacuation
[3.800s][info][gc,phases ] GC(24) Pre Evacuate Collection Set: 0.2ms
[3.825s][info][gc,phases ] GC(24) Evacuate Collection Set: 250.3ms
[3.826s][info][gc,phases ] GC(24) Post Evacuate Collection Set: 0.3ms
[3.826s][info][gc,phases ] GC(24) Other: 0.4ms
[3.826s][info][gc,heap ] GC(24) Eden regions: 1222->0(1220)
[3.826s][info][gc,heap ] GC(24) Survivor regions: 142->144(144)
[3.826s][info][gc,heap ] GC(24) Old regions: 1834->1820
[3.826s][info][gc,heap ] GC(24) Humongous regions: 4->4
[3.826s][info][gc,metaspace ] GC(24) Metaspace: 3750K->3750K(1056768K)
[3.826s][info][gc ] GC(24) Pause Young (Mixed) (G1 Evacuation Pause)
3791M->3791M(3983M) 124.390ms
[3.826s][info][gc,cpu ] GC(24) User=1.01s Sys=0.00s Real=0.26s
[3.826s][info][gc,start ] GC(25) Pause Young (Mixed) (G1 Evacuation Pause)请注意，整个堆使用量减少的不仅仅是从 eden 中删除的 1,222 MB。这个差异（16 MB）似乎很小，但请记住，一些幸存区也同时被提升到老年代；此外，每个Mixed GC 只清理目标老年代区域的一部分。随着我们的继续，您将看到确保 Mixed GC 清理出足够的内存是非常重要的，它可以防止未来出现并发失败【concurrent failures】。
在JDK 11中，第一个 Mixed GC被标记为 Prepared Mixed，并紧跟在并发清理【concurrent cleanup】之后。
Mixed GC 循环周期将一直持续到（几乎）所有标记的区域都已收集完毕，此时 G1 GC 将恢复到常规的年轻代 GC 循环周期。最终，G1 GC 将开始另一个并发标记循环周期，以确定接下来应该释放老年代中的哪些区域。
尽管在 Mixed GC 循环周期内，通常标记的 GC 原因是（Mixed），但有时在并发标记之后的年轻代收集的 GC 原因被标记为常规回收（即 G1 Evacuation Pause）。如果并发循环在老年代中发现了可以完全释放的区域，那么这些区域会在常规的年轻代疏散暂停期间被回收。从技术上讲，这不是收集器实现中的 mixed cycle 。但从逻辑上讲，它是：对象正在从年轻代中被释放或被提升到老年代，同时垃圾对象（实际上是区域）正在从老年代中释放出来。
如果一切顺利，这就是您将在 GC 日志中看到的全部 GC 活动集。但也有一些失败场景需要考虑。
有时您会在日志中观察到 Full GC，这表明更多的调整（可能包括更多的堆空间）将有利于应用程序的性能。 Full GC 主要由下面四个原因触发：
Concurrent mode failure
G1 GC 开启了一个标记循环周期【marking cycle】，但是在循环完成之前老年代就被填满了。在这种情况下，G1 GC 中止标记周期【marking cycle】：
51.408: [GC concurrent-mark-start]
65.473: [Full GC 4095M->1395M(4096M), 6.1963770 secs]
[Times: user=7.87 sys=0.00, real=6.20 secs]
71.669: [GC concurrent-mark-abort]
[51.408][info][gc,marking ] GC(30) Concurrent Mark From Roots
...
[65.473][info][gc ] GC(32) Pause Full (G1 Evacuation Pause)
4095M->1305M(4096M) 60,196.377
...
[71.669s][info][gc,marking ] GC(30) Concurrent Mark From Roots 191ms
[71.669s][info][gc,marking ] GC(30) Concurrent Mark Abort此失败意味着应该增加堆大小，或者 G1 GC 后台处理必须更早开启，或者必须调整循环周期以更快地运行（例如通过使用更多的后台线程）。有关如何执行此操作的细节如下。
Promotion failure
当 G1 GC 完成了一个标记循环周期【marking cycle】，并开始执行 Mixed GC 以清理老年代区域。在它清理足够的空间之前，从年轻代提升了太多的对象，所以老年代仍然空间耗尽。在日志中体现为 Full GC 紧跟在 Mixed GC 之后：
2226.224: [GC pause (mixed)
2226.440: [SoftReference, 0 refs, 0.0000060 secs]
2226.441: [WeakReference, 0 refs, 0.0000020 secs]
2226.441: [FinalReference, 0 refs, 0.0000010 secs]
2226.441: [PhantomReference, 0 refs, 0.0000010 secs]
2226.441: [JNI Weak Reference, 0.0000030 secs]
(to-space exhausted), 0.2390040 secs]
....
[Eden: 0.0B(400.0M)->0.0B(400.0M)
Survivors: 0.0B->0.0B Heap: 2006.4M(2048.0M)->2006.4M(2048.0M)]
[Times: user=1.70 sys=0.04, real=0.26 secs]
2226.510: [Full GC (Allocation Failure)
2227.519: [SoftReference, 4329 refs, 0.0005520 secs]
2227.520: [WeakReference, 12646 refs, 0.0010510 secs]
2227.521: [FinalReference, 7538 refs, 0.0005660 secs]
2227.521: [PhantomReference, 168 refs, 0.0000120 secs]
2227.521: [JNI Weak Reference, 0.0000020 secs]
2006M->907M(2048M), 4.1615450 secs]
[Times: user=6.76 sys=0.01, real=4.16 secs]
[2226.224s][info][gc ] GC(26) Pause Young (Mixed)
(G1 Evacuation Pause)
2048M->2006M(2048M) 26.129ms
...
[2226.510s][info][gc,start ] GC(27) Pause Full (G1 Evacuation Pause)这种失败意味着 Mixed GC 需要更快地进行；每个年轻代收集需要处理老年代中的更多区域。
Evacuation failure
在执行年轻代收集时，幸存区和老年代中没有足够的空间容纳所有幸存的对象。这在 GC 日志中作为一种特殊的年轻代 GC 出现：
60.238: [GC pause (young) (to-space overflow), 0.41546900 secs]
[60.238s][info][gc,start ] GC(28) Pause Young (Concurrent Start)
(G1 Evacuation Pause)
[60.238s][info][gc,task ] GC(28) Using 4 workers of 4
for evacuation
[60.238s][info][gc ] GC(28) To-space exhausted这表明堆在很大程度上已满或碎片化严重。 G1 GC 将尝试进行补偿，但您可以预期这会以糟糕的方式结束：JVM 将诉诸于执行 Full GC。克服这一问题的简单方法是增加堆大小，尽管在“高级调优”中给出了可能的解决方案。
Humongous allocation failure
分配非常大对象的应用程序可以触发 G1 GC 中的另一种 Full GC；有关更多详细信息（包括如何避免它），请参阅 “G1 GC allocation of humongous objects”。在 JDK 8 中，如果不使用特殊的日志记录参数，就无法诊断这种情况，但在 JDK 11 中，会显示以下日志：
[3023.091s][info][gc,start ] GC(54) Pause Full (G1 Humongous Allocation)Metadata GC threshold
正如我前面提到的，元空间【Metaspace 】本质上是一个单独的堆，并且独立于主堆进行收集。它不是通过 G1 GC 收集的，但是当它需要在 JDK 8 中收集时，G1 GC 将在主堆上执行一次 Full GC（紧跟在年轻代收集之后）：
0.0535: [GC (Metadata GC Threshold) [PSYoungGen: 34113K->20388K(291328K)]
73838K->60121K(794112K), 0.0282912 secs]
[Times: user=0.05 sys=0.01, real=0.03 secs]
0.0566: [Full GC (Metadata GC Threshold) [PSYoungGen: 20388K->0K(291328K)]
[ParOldGen: 39732K->46178K(584192K)] 60121K->46178K(875520K),
[Metaspace: 59040K->59036K(1101824K)], 0.1121237 secs]
[Times: user=0.28 sys=0.01, real=0.11 secs]在JDK 11中，元空间可以在不需要 Full GC 的基础上被收集/调整大小。
QUICK SUMMARY
- G1 有多个循环周期（以及并发周期内的阶段），调优良好的 G1 的 JVM 应该只经历年轻代收集周期、混合收集周期，以及并发 GC 标记周期。
- G1 的一些并发阶段会出现小暂停。
- 如有必要，应调整 G1 以避免 Full GC 。
Tuning G1 GC
优化 G1 GC的主要目标是确保没有并发模式失败【concurrent mode failure】或疏散失败【evacuation failure】，最终避免由其衍生出的 Full GC。当出现频繁的年轻代 GC 必须等待根区域扫描完成时，我们也可以使用避免 Full GC 的手段来优化。
在 JDK 8 中进行调优以防止 Full GC 至关重要，因为当 G1 GC 在 JDK 8 中执行 Full GC 时，它使用单个线程来执行此操作。这会产生比平时更长的暂停时间。在 JDK 11 中，Full GC 由多个线程执行，从而导致更短的暂停时间（本质上与使用吞吐量收集器的 Full GC 具有相同的暂停时间）。这种差异是如果您使用 G1 GC 最好更新到 JDK 11 的原因之一（尽管如果可以避免 Full GC 的发生， JDK 8 应用程序将执行得很好）。
其次，调优可以最小化过程中出现的暂停。
以下是避免 Full GC 的选项：
- 增加老年代的大小，可以通过增加堆空间的整体大小，也可以通过调整代与代之间的比例来实现。
- 增加后台线程的数量(假设有足够的CPU的话)。
- 频繁地执行 G1 GC 后台活动。
- 增加在 Mixed GC 循环周期中完成的工作量。
这里可以应用很多调优，但 G1 GC 的目标之一是它不需要调优那么多。为此，G1 GC 主要通过一个参数进行调优：即 -XX:MaxGCPauseMillis=N，该标志也用于调优吞吐量收集器。
当使用 G1 GC 时（与吞吐量收集器不同），该参数确实有一个默认值：200 毫秒。如果 G1 GC 的任何 Stop-The-World 阶段的暂停时间开始超过该值，G1 GC 将尝试补偿——调整年轻代与老年代的比率，调整堆大小，更早地开启后台处理，改变任期阈值【tenuring threshold】，以及（最重要的是）在 Mixed GC 循环期间处理更多或更少的老年代区域。
这里需要进行一些权衡：如果减小 MaxGCPauseMillis 的值，则年轻大小将收缩以满足暂停时间目标，但将执行更频繁的年轻代 GC。此外，在 Mixed GC 期间可以收集的老年代区域的数量也将减少以满足暂停时间目标，这增加了【concurrent mode failure】的机会。
如果设置暂停时间目标并不能阻止 Full GC 的发生，则可以单独调整这些各个方面。调整 G1 GC 的堆大小的方式与其他 GC 算法相同。
TUNING THE G1 BACKGROUND THREADS
您可以认为 G1 GC 的并发标记【concurrent marking】与应用程序线程处于竞速关系：G1 GC 清除老年代的速度必须比应用程序将新数据推送到老年代的速度更快。为此，请尝试增加后台标记线程的数量（假设机器上有足够的 CPU 可用的话）。
G1 GC 使用了两组线程集。第一组线程集是通过您在第 5 章中首次看到的，它是通过 XX:ParallelGCThreads=N 参数控制的。该值会影响应用程序线程必须暂停时（即STW时）的线程数：年轻代收集、混合收集，以及并发标记循环周期【concurrent remark cycle】必须停止应用线程的阶段。第二个参数是 -XX:ConcGCThreads=N，它影响用于并发标记时的线程数。
ConcGCThreads 的默认值由于下面的公式决定：
这里的除法是基于整数的（向下取整，并非四舍五入），因此如果有5条并行线程，那么只会有1条并发线程，而2条并发线程则适用于6~9条并行线程，依此类推。
增加后台扫描线程的数量将使并发循环周期变得更短，这应该使 G1 GC 在 Mixed GC 循环周期中更容易在其他线程再次填满老年代之前完成对老年代的释放。一如既往，这是建立在CPU周期是可用的假设之上的；否则，扫描线程将抢占应用程序的 CPU，并真实地引入暂停，正如我们在第 5 章中比较将串行收集器与 G1 GC 时看到的那样。
TUNING G1 GC TO RUN MORE (OR LESS) FREQUENTLY
如果 G1 GC 更早开启后台标记循环周期，那么它也可以赢得与应用线程的竞速。当堆达到 -XX:InitiatingHeapOccupancyPercent=N 指定的占用率（默认值为 45）时，该循环开启。该百分比指的是整个堆，而不仅仅是老年代。
InitiatingHeapOccupancyPercent 值是常数； G1 GC 在尝试满足其暂停时间目标时从不更改该数字。如果该值设置得太高，应用程序将最终执行 Full GC，因为在堆的其余部分填满之前并发标记阶段没有足够的时间完成。如果该值太小，，应用程序将执行更多的后台 GC 处理工作。
当然，在某些时候，这些后台线程将不得不运行，因此硬件可能有足够的 CPU 来容纳它们。尽管如此，过于频繁地运行它们可能会导致严重的损失，因为在并发标记循环周期内的那些必须停止应用程序的阶段，将不得不出现更多的小暂停。这些停顿会很快累积起来，因此应避免为 G1 GC 过于频繁地执行后台扫描。在一个并发标记循环周期后检查堆的大小，并确保 InitiatingHeapOccupancyPercent 值设置得高于此值。
TUNING G1 GC MIXED GC CYCLES
在一个并发标记循环周期之后，G1 GC 不能开始另一个新的并发标记循环周期，直到老年代中所有之前标记的区域都被收集完为止。所以另一种让 G1 GC 更早开始标记循环的方法是在 Mixed GC 循环周期中一次处理更多的区域（这样最终 Mixed GC 循环周期会更少）。
Mixed GC 所做的工作量取决于三个因素。首先是并发标记循环周期发现有多少区域主要是垃圾。我们没有办法直接影响这一点：如果某个区域 85% 的是垃圾，那么该区域就被声明为符合在 Mixed GC 循环周期进行回收的条件。
第二个因素是 G1 GC 处理这些区域的最大 Mixed GC 循环周期数，由参数 -XX:G1MixedGCCountTarget=N 的值指定。默认值为 8；降低该值有助于克服提升失败【promotion failures】（这以在 Mixed GC 循环周期期间增加更长的暂停时间为代价）。
最后，第三个因素是 GC 暂停的最大期望时长（即 MaxGCPauseMillis 指定）。 G1MixedGCCountTarget 参数指定的 Mixed GC 循环周期数是一个上限；如果时间在暂停目标内还有富余，G1 GC 将收集超过八分之一（或已指定的任何值）的被标记的老年代区域。增加 MaxGCPauseMillis 参数的值允许在每次 Mixed GC 期间收集更多的老年代区域，这反过来可以允许 G1 GC 更快地开始下一个并发标记循环周期。
QUICK SUMMARY
- G1 GC调优应该首先设置一个合理的暂停时间目标。
- 如果 Full GC 仍然是一个问题，并且堆大小不能增加，特定的调优可以应用于特定的故障
- 要使后台线程运行得更频繁，请调整 InitiatingHeapOccupancyPercent。
- 如果有额外的CPU可用，可以通过 ConcGCThreads 参数调整线程数。
- 为了防止提升失败，减小 G1MixedGCCountTarget 的大小。
Understanding the CMS Collector
尽管不推荐使用 CMS 收集器，但它在当前的 JDK 版本中仍然可用。因此，本节介绍如何调整它，以及它被弃用的原因。
CMS 包含3个基本操作：
- 年轻代收集（需暂停所有应用线程）
- 运行一个并发循环周期来清理老年代中的数据
- 如果需要的话，运行一个 Full GC 来压缩老年代
图 6-7 描绘的是 CMS 中的年轻代收集。
Figure 6-7. Young collection performed by CMS
CMS 年轻代收集类似于吞吐量收集器的年轻代收集：数据从伊甸区移动到一个幸存区（如果幸存区填满，则直接进入老年代）。
CMS 的 GC 日志条目也类似（我将仅展示 JDK 8 日志格式）：
89.853: [GC 89.853: [ParNew: 629120K->69888K(629120K), 0.1218970 secs]
1303940K->772142K(2027264K), 0.1220090 secs]
[Times: user=0.42 sys=0.02, real=0.12 secs]年轻代的大小目前为 629 MB；收集后，剩余 69 MB（在幸存区中）。类似地，整个堆的大小为 2,027 MB——其中在收集后占用 772 MB 。整个过程花费了 0.12 秒（见 real ），尽管并行 GC 线程在 CPU 上的占用时间为 0.42 秒。
CMS 中的并发循环周期如图 6-8 所示：
CMS 根据堆的占用情况启动一个并发循环周期。当它足够满时，将启启动对堆进行循环遍历并删除其中对象的后台线程。在循环结束时，堆看起来像底部的图。请注意，老年代没有被压缩：有分配对象的区域和空闲区域。当年轻代收集【YGC】将对象从伊甸区移动到老年代时，JVM 将尝试使用这些空闲区域来保存对象。通常这些对象不适合其中一个空闲区域，这就是为什么在 CMS 循环周期之后，堆的高水位标记更大。
Figure 6-8. Concurrent collection performed by CMS
在 GC 日志中，此循环周期显示为多个阶段。尽管大部分的并发循环周期使用后台线程，但某些阶段还是会引入短暂的暂停【STW】，所有应用程序线程都会暂停。
Phase 1: Initial Mark. 这是 CMS 期间的两个 STW 事件之一。此阶段的目标是标记老年代中的所有这些对象：这些对象要么直连 GC Root，要么是由年轻代中的某个存活对象引用的。后者很重要，因为老年代是单独收集的。
并发循环周期从初始标记【initial-mark】阶段开始，该阶段暂停所有应用程序线程：
89.976: [GC [1 CMS-initial-mark: 702254K(1398144K)]
772530K(2027264K), 0.0830120 secs]
[Times: user=0.08 sys=0.00, real=0.08 secs]初始标记【initial-mark】负责查找堆中的所有 GC Root 对象。第一组数值显示的是对象当前占用 1398MB 的老年代中的 702MB，而第二组数值显示的是整个 2027MB 堆的占用量为 772MB。在 CMS 周期的这个阶段，应用程序线程总计暂停了 0.08 秒。
Phase 2: Concurrent Mark. 在这个阶段，垃圾收集器遍历老年代并标记所有活动对象，从初始标记【initial-mark】阶段中找到的根开始。顾名思义，并发标记【Concurrent Mark】阶段与您的应用程序同时运行，并且不会停止应用程序线程。请注意，并非老年代中的所有活动对象都可以被标记，因为应用程序在标记期间会改变引用。
下一个阶段是并发标记【concurrent mark】阶段，它不会停止应用程序线程。该阶段的 GC 日志中由以下几行表示：
90.059: [CMS-concurrent-mark-start]
90.887: [CMS-concurrent-mark: 0.823/0.828 secs]
[Times: user=1.11 sys=0.00, real=0.83 secs]标记阶段共计花费了 0.83 秒（以及 1.11 秒的 CPU 时间）。由于它只是一个标记阶段，它没有对堆占用做任何事情，所以没有显示有关的数据。如果有数据，它可能会显示在这 0.83 秒内，由于应用程序线程此时在继续执行，年轻代中分配的对象在堆中的增长。
Phase 3: Concurrent Preclean. 这又是一个并发阶段，与应用程序线程并行运行，而不是停止它们。当并发标记【Concurrent Mark】阶段与应用程序同时运行时，某一些引用已被更改。每当发生这种情况时，JVM 都会将包含突变对象的堆区域（称为“卡【Card】”）标记为“脏”（这称为卡标记）。在预清理阶段，对这些脏对象进行重新计算，并对可达的对象进行标记。当这一切完成后，卡被清洗。
接下来是并发预清理【Concurrent Preclean】阶段，它也与应用程序线程并发运行：
90.887: [CMS-concurrent-preclean-start]
90.892: [CMS-concurrent-preclean: 0.005/0.005 secs]
[Times: user=0.01 sys=0.00, real=0.01 secs]Phase 4: Concurrent Abortable Preclean. 同样，该阶段也不会停止应用程序的线程。这阶段试图尽可能多地从需要 STW 的重新标记【Remark】中解脱出来。这个阶段的确切持续时间取决于许多因素，因为它一直在迭代做同样的事情，直到满足其中一个中止条件为止（例如迭代次数、完成的有用工作量、经过的挂钟时间等）。细心地读者会问该阶段到底是如何做的，简而言之，就是等待年轻代的内存占用达到 50%。
Phase 5: Final Remark. 这是循环周期内的第二个也是最后一个 STW 阶段。这个STW 阶段的目标是最终标记老年代中的所有活动对象。由于之前的预清理阶段是并发的，它们可能无法跟上应用程序的突变速度【mutating speeds】。需要一次 STW 来结束这一切磨难。通常 CMS 会在年轻代尽可能为空时尝试运行重新标记【Remark】阶段，以消除多个 SWT 阶段连续发生的可能性。在这五个标记阶段之后，老年代中的所有活动对象都被标记，现在垃圾收集器将通过清理【Sweep】阶段，来回收被占用的空间。
下一个阶段是重新标记【Remark】阶段，但它涉及到多个操作：
90.892: [CMS-concurrent-abortable-preclean-start]
92.392: [GC 92.393: [ParNew: 629120K->69888K(629120K), 0.1289040 secs]
1331374K->803967K(2027264K), 0.1290200 secs]
[Times: user=0.44 sys=0.01, real=0.12 secs]
94.473: [CMS-concurrent-abortable-preclean: 3.451/3.581 secs]
[Times: user=5.03 sys=0.03, real=3.58 secs]
94.474: [GC[YG occupancy: 466937 K (629120 K)]
94.474: [Rescan (parallel) , 0.1850000 secs]
94.659: [weak refs processing, 0.0000370 secs]
94.659: [scrub string table, 0.0011530 secs]
[1 CMS-remark: 734079K(1398144K)]
1201017K(2027264K), 0.1863430 secs]
[Times: user=0.60 sys=0.01, real=0.18 secs]等等，CMS不是刚执行了预清理阶段吗？这个可中止的预清理【abortable-preclean】阶段是怎么回事？
使用可中止的预清理【abortable-preclean】阶段是因为 remark 阶段不是并发的——它将停止所有应用程序线程。 CMS 希望尽量避免出现年轻代收集后紧随着重新标记【Remark】阶段的情况，在这种情况下，应用程序线程将由于两个连续的暂停操作【back-to-back pause operations】而被停止。这里的目标是通过防止连续暂停【back-to-back pauses】来最小化暂停时长。
因此，可中止的预清理【abortable-preclean】阶段一直等到年轻代大约 50% 占用为止。理论上，这介于两个年轻代收集之间，让 CMS 有最好的机会来避免那些连续停顿【back-to-back pauses】。在此示例中，可中止的预清理【abortable-preclean】阶段从 90.8 秒开始，并等待大约 1.5 秒以使常规年轻收集发生（在日志中的 92.392 秒处）。 CMS 使用过去的行为来计算下一次年轻代收集可能发生的时间——在这种情况下，CMS 计算出它会在大约 4.2 秒内发生。因此，在 2.1 秒后（94.4 秒），CMS 结束预清理阶段（它称之为中止该阶段，即使这是停止该阶段的唯一方法）。然后，最后，CMS 执行重新标记【Remark】阶段，将应用程序线程暂停 0.18 秒（应用程序线程在可中止的预清理【abortable-preclean】阶段没有暂停）。
接下来是另一个并发阶段——清理【Sweep】阶段:
94.661: [CMS-concurrent-sweep-start]
95.223: [GC 95.223: [ParNew: 629120K->69888K(629120K), 0.1322530 secs]
999428K->472094K(2027264K), 0.1323690 secs]
[Times: user=0.43 sys=0.00, real=0.13 secs]
95.474: [CMS-concurrent-sweep: 0.680/0.813 secs]
[Times: user=1.45 sys=0.00, real=0.82 secs]清理【Sweep】阶段耗时 0.82 秒，并与应用程序线程同时运行。它恰好被一个年轻代收集打断。这个年轻代收集与清理【Sweep】阶段没有任何关系，但是这里留下一个例子，年轻代收集可以与老年代收集阶段同时发生。在图 6-8 中，注意年轻代的状态在并发收集期间发生了变化——在扫描阶段可能发生了任意数量的年轻代收集（并且由于可中止的预清理【abortable-preclean】，至少会有一个年轻代收集发生）。
接下来是并发重置【concurrent reset】阶段：
95.474: [CMS-concurrent-reset-start]
95.479: [CMS-concurrent-reset: 0.005/0.005 secs]
[Times: user=0.00 sys=0.00, real=0.00 secs]这是最后一个并发阶段；CMS 循环周期至此完成，在老年代找到的未引用对象现在都被释放了（产生如图 6-8 所示的堆）。不幸的是，日志没有提供任何关于释放了多少对象的信息。重置行没有提供有关堆占用的任何信息。要了解这一点，我们需要查看下一个年轻代收集：
98.049: [GC 98.049: [ParNew: 629120K->69888K(629120K), 0.1487040 secs]
1031326K->504955K(2027264K), 0.1488730 secs]现在与老年代在 89.853 秒（CMS 周期开始之前）时的占用情况比较一下，当时老年代大概是 703 MB（整个堆当时占用了 772 MB，其中包括 69 MB 的幸存区，所以老年代占用了剩余 703 MB）。在 98.049 秒的收集中，老年代大约占 504 MB；因此，CMS 循环清理了大约 199 MB 的内存。
如果一切顺利的话，这将是 CMS 运行的唯一循环周期，也是将出现在 CMS GC 日志中的唯一日志消息。但是还有 3 条消息要查找，这表明 CMS 遇到了问题。第一个是并发模式失败：
267.006: [GC 267.006: [ParNew: 629120K->629120K(629120K), 0.0000200 secs]
267.006: [CMS267.350: [CMS-concurrent-mark: 2.683/2.804 secs]
[Times: user=4.81 sys=0.02, real=2.80 secs]
(concurrent mode failure):
1378132K->1366755K(1398144K), 5.6213320 secs]
2007252K->1366755K(2027264K),
[CMS Perm : 57231K->57222K(95548K)], 5.6215150 secs]
[Times: user=5.63 sys=0.00, real=5.62 secs]当一个年轻代收集发生时，此时老年代没有足够的空间来容纳所有预期被提升的对象，CMS 执行一个 Full GC。所有应用程序线程都停止了，老年代中的所有死对象都被清理了，将其堆占用减少到 1,366 MB——但这一操作使应用程序线程暂停了整整 5.6 秒。该操作是单线程的，这也是它需要这么长时间的原因之一（也是随着堆的增长，并发模式失败【concurrent mode failures】会变得更糟的原因之一）。
这种并发模式失败【concurrent mode failures】是不推荐使用 CMS 的主要原因。 G1 GC 可能会出现并发模式故障，但是当它回退到 Full GC 时，Full GC 在 JDK 11 中是并行发生的（尽管在 JDK 8 中没有）。 CMS Full GC 的执行时间会长很多倍，因为它必须在单个线程中执行。
第二个问题发生在老年代有足够的空间来容纳提升的对象，但可用空间碎片化严重，因此提升失败：
6043.903: [GC 6043.903:
[ParNew (promotion failed): 614254K->629120K(629120K), 0.1619839 secs]
6044.217: [CMS: 1342523K->1336533K(2027264K), 30.7884210 secs]
2004251K->1336533K(1398144K),
[CMS Perm : 57231K->57231K(95548K)], 28.1361340 secs]
[Times: user=28.13 sys=0.38, real=28.13 secs]这里，CMS 启动了一个年轻代收集，并假设存在空间来容纳所有提升的对象（否则，它会宣布并发模式失败【concurrent mode failures】）。这个假设被证明是不正确的：CMS 无法提升对象，因为老年代碎片化严重（或者，根本无法完全提升，因为要提升的内存量比 CMS 预期的要大）。
结果，在年轻代收集过程中（所有线程都已停止），CMS 收集并压缩了整个老年代。好消息是，随着堆的压缩，碎片问题已经得到解决（至少在一段时间内）。但这伴随着一个 28 秒的停顿时间。这个时间比 CMS 发生并发模式失败【concurrent mode failures】时要长得多，因为整个堆都被压缩了；而并发模式失败【concurrent mode failures】只是释放了堆中的对象。此时的堆看起来就像它在吞吐量收集器的 Full GC 结束时所做的那样（图 6-2）：年轻代完全为空，而老年代已被压缩。
最后一种问题，CMS日志可能会显示一个 Full GC，没有任何常见的并发 GC 消息：
279.803: [Full GC 279.803:
[CMS: 88569K->68870K(1398144K), 0.6714090 secs]
558070K->68870K(2027264K),
[CMS Perm : 81919K->77654K(81920K)],
0.6716570 secs]这发生在元空间已被填满并需要收集时。 CMS 不收集元空间，因此如果它填满，则需要 Full GC 来丢弃任何未引用的类。 “高级调优”部分会展示了如何克服这个问题。
QUICK SUMMARY
- CMS 有多个 GC 操作，但我们预期的操作是 Minor GC 和并发循环周期。
- CMS 中的并发模式失败和提升失败，它们代价高昂；应调整 CMS 以尽可能避免这些情况。
- 默认情况下，CMS不收集元空间。
扫一扫
963
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
