可以通过设置 -Xlog:gc*:gc.log 选项以开启 ZGC 日志。其中 "gc*" 意为打印所有 tag 中以 "gc" 开头的日志，"gc.log" 为日志存储路径。
下面以 AutoMQ 在实际运行时的一次 GC 为例，按照不同的 log tag，解释 ZGC 日志的含义。
"gc,start"，"gc,task"，"gc"
[gc,start ] GC(100) Garbage Collection (Timer)
[gc,task ] GC(100) Using 1 workers
...
[gc ] GC(100) Garbage Collection (Timer) 2240M(36%)->1190M(19%)
-
第 1 行标志了一次 GC 的开始，是进程启动后的第 100 次（从 0 开始计数）GC，触发原因为 "Timer"。ZGC 可能的触发条件有：
Warmup：ZGC 首次启动后的预热。
Allocation Rate：由 ZGC 内部自适应的 GC 频率算法触发。如前文所述，其敏感度受 -XX:ZAllocationSpikeTolerance 控制。
Allocation Stall：在分配对象时，堆可用内存不足时触发。这会导致部分线程阻塞，应尽可能避免该场景。
Timer：当 -XX:ZCollectionInterval 配置不为 0 时，定时触发的 GC。
Proactive：当应用程序空闲时由 ZGC 主动触发，受 -XX:+ZProactive 控制。
System.gc()：在代码中显式调用System.gc()时触发。
Metadata GC Threshold：元数据空间不足时触发。
-
第 2 行意为该次 GC 使用了 1 个并发线程，受 -XX:ConcGCThreads 与 -XX:+UseDynamicNumberOfGCThreads 控制。
-
最后 1 行标志了一次 GC 的开始，GC 开始前堆中占用的内存为 2240M，占堆总大小的 36%；GC 完成后为 1190M，占 19%。
"gc,phases"
[gc,phases ] GC(100) Pause Mark Start 0.005ms
[gc,phases ] GC(100) Concurrent Mark 1952.113ms
[gc,phases ] GC(100) Pause Mark End 0.018ms
[gc,phases ] GC(100) Concurrent Mark Free 0.001ms
[gc,phases ] GC(100) Concurrent Process Non-Strong References 79.422ms
[gc,phases ] GC(100) Concurrent Reset Relocation Set 0.066ms
[gc,phases ] GC(100) Concurrent Select Relocation Set 12.019ms
[gc,phases ] GC(100) Pause Relocate Start 0.009ms
[gc,phases ] GC(100) Concurrent Relocate 149.037ms记录了 ZGC 各个阶段的耗时，其中 "Pause" 与 "Concurrent" 分别标识了 STW 阶段与并发阶段。每次 GC 会存在 3 个 "Pause" 阶段，应主要关注它们的耗时。
-
"gc,load"，
[gc,load ] GC(100) Load: 2.74/2.02/1.54记录了过去 1 分钟、5 分钟、15 分钟的平均负载，即系统的平均活跃进程数。
-
"gc,mmu"
[gc,mmu ] GC(100) MMU: 2ms/93.9%, 5ms/97.6%, 10ms/98.8%, 20ms/99.4%, 50ms/99.7%, 100ms/99.9%记录了 GC 期间的最小可用性（Minimum Mutator Utilization）。以本次 GC 为例，在任何连续的 2ms 的时间窗口中，应用至少能使用 93.9% 的 CPU 时间。
"gc,ref"
[gc,ref ] GC(100) Soft: 6918 encountered, 0 discovered, 0 enqueued
[gc,ref ] GC(100) Weak: 8835 encountered, 1183 discovered, 4 enqueued
[gc,ref ] GC(100) Final: 63 encountered, 3 discovered, 0 enqueued
[gc,ref ] GC(100) Phantom: 957 encountered, 882 discovered, 0 enqueued
记录了 GC 期间不同类型的引用对象的处理情况。各字段含义如下：
-
"Soft"：软引用（SoftReference）。软引用对象会在内存不足时被回收。
-
"Weak"：弱引用（WeakReference）。弱引用对象只要被垃圾收集器发现，就会被回收。
-
"Final"：终结引用（FinalReference）。终结引用允许对象在被垃圾回收之前执行一些特定的清理操作。
-
"Phantom"：幽灵引用（PhantomReference）。幽灵引用通常用于确保对象被完全回收后才执行某些操作，它比终结引用提供了更精确的控制。
-
"encountered"：GC 期间遇到的引用对象的数量。
-
"discovered"：GC 期间发现需要处理的引用对象的数量。
-
"enqueued"：GC 期间加入到引用队列（Reference Queue）中的引用对象的数量。
"gc,reloc"
[gc,reloc ] GC(100) Small Pages: 1013 / 2026M, Empty: 2M, Relocated: 41M, In-Place: 0
[gc,reloc ] GC(100) Medium Pages: 2 / 64M, Empty: 0M, Relocated: 9M, In-Place: 0
[gc,reloc ] GC(100) Large Pages: 3 / 150M, Empty: 0M, Relocated: 0M, In-Place: 0
[gc,reloc ] GC(100) Forwarding Usage: 19M-
前 3 行记录了不同大小的区域在 GC 时的表现。以第 1 行为例：
共有 1013 个小区域，总大小为 2026 MB
整理过程中发现了 2MB 的未被使用的区域
迁移了 41MB 的对象
其中有 0 MB 是原地迁移（该值过大意味着堆可用空间不足）
-
第 4 行记录了迁移对象时，各区域使用的转发表的总大小。
"gc,heap"
[gc,heap ] GC(100) Min Capacity: 6144M(100%)
[gc,heap ] GC(100) Max Capacity: 6144M(100%)
[gc,heap ] GC(100) Soft Max Capacity: 6144M(100%)
[gc,heap ] GC(100) Mark Start Mark End Relocate Start Relocate End High Low
[gc,heap ] GC(100) Capacity: 6144M (100%) 6144M (100%) 6144M (100%) 6144M (100%) 6144M (100%) 6144M (100%)
[gc,heap ] GC(100) Free: 3904M (64%) 3394M (55%) 3372M (55%) 4954M (81%) 4954M (81%) 3340M (54%)
[gc,heap ] GC(100) Used: 2240M (36%) 2750M (45%) 2772M (45%) 1190M (19%) 2804M (46%) 1190M (19%)
[gc,heap ] GC(100) Live: - 543M (9%) 543M (9%) 543M (9%) - -
[gc,heap ] GC(100) Allocated: - 510M (8%) 534M (9%) 570M (9%) - -
[gc,heap ] GC(100) Garbage: - 1696M (28%) 1694M (28%) 75M (1%) - -
[gc,heap ] GC(100) Reclaimed: - - 2M (0%) 1620M (26%) - -记录了该 GC 周期中，不同阶段（标记前、标记后、迁移前、迁移后）的各类内存的大小。具体地说：
-
Capacity：堆的容量。
-
Free：堆中空闲的内存大小，与 Used 相加即为堆的容量。
-
Used：堆中使用的内存大小，其最大值即为 GC 期间堆的最大使用量。
-
Live：堆中存活的对象，即，可达的对象的总大小。
-
Allocated：和上一阶段相比，新分配的对象的大小。
-
Garbage：堆中垃圾对象的总大小。
-
Reclaimed：和上一阶段相比，回收的垃圾对象的大小。
整个阶段格式如下：
[22008.707s][info][gc,phases ] GC(81) O: Old Generation 328M(1%)->358M(1%) 0.544s
[22008.707s][info][gc ] GC(81) Major Collection (Proactive) 1696M(6%)->358M(1%) 0.621s
[22308.714s][info][gc ] GC(82) Major Collection (Proactive)
[22308.714s][info][gc,task ] GC(82) Using 1 Workers for Young Generation
[22308.714s][info][gc,task ] GC(82) Using 1 Workers for Old Generation
[22308.714s][info][gc,phases ] GC(82) Y: Young Generation
[22308.714s][info][gc,phases ] GC(82) Y: Pause Mark Start (Major) 0.128ms
[22308.778s][info][gc,phases ] GC(82) Y: Concurrent Mark 63.619ms
[22308.778s][info][gc,phases ] GC(82) Y: Pause Mark End 0.027ms
[22308.778s][info][gc,phases ] GC(82) Y: Concurrent Mark Free 0.001ms
[22308.778s][info][gc,phases ] GC(82) Y: Concurrent Reset Relocation Set 0.024ms
[22308.781s][info][gc,reloc ] GC(82) Y: Using tenuring threshold: 4 (Computed)
[22308.782s][info][gc,phases ] GC(82) Y: Concurrent Select Relocation Set 3.768ms
[22308.782s][info][gc,phases ] GC(82) Y: Pause Relocate Start 0.017ms
[22308.784s][info][gc,phases ] GC(82) Y: Concurrent Relocate 2.563ms
[22308.784s][info][gc,alloc ] GC(82) Y: Mark Start Mark End Relocate Start Relocate End
[22308.784s][info][gc,alloc ] GC(82) Y: Allocation Stalls: 0 0 0 0
[22308.784s][info][gc,load ] GC(82) Y: Load: 3.30 (7%) / 3.23 (7%) / 4.09 (9%)
[22308.784s][info][gc,mmu ] GC(82) Y: MMU: 2ms/0.0%, 5ms/0.0%, 10ms/29.8%, 20ms/64.9%, 50ms/86.0%, 100ms/93.0%
[22308.784s][info][gc,marking ] GC(82) Y: Mark: 1 stripe(s), 2 proactive flush(es), 1 terminate flush(es), 0 completion(s), 0 continuation(s)
[22308.784s][info][gc,marking ] GC(82) Y: Mark Stack Usage: 32M
[22308.784s][info][gc,nmethod ] GC(82) Y: NMethods: 15195 registered, 1092 unregistered
[22308.784s][info][gc,metaspace] GC(82) Y: Metaspace: 142M used, 144M committed, 544M reserved
[22308.784s][info][gc,reloc ] GC(82) Y: Candidates Selected In-Place Size Empty Relocated
[22308.784s][info][gc,reloc ] GC(82) Y: Small Pages: 675 82 0 1350M 1180M 0M
[22308.784s][info][gc,reloc ] GC(82) Y: Medium Pages: 0 0 0 0M 0M 0M
[22308.784s][info][gc,reloc ] GC(82) Y: Large Pages: 0 0 0 0M 0M 0M
[22308.784s][info][gc,reloc ] GC(82) Y: Forwarding Usage: 0M
[22308.784s][info][gc,reloc ] GC(82) Y: Age Table:
[22308.784s][info][gc,reloc ] GC(82) Y: Live Garbage Small Medium Large
[22308.784s][info][gc,reloc ] GC(82) Y: Eden 0M (0%) 1335M (5%) 668 / 77 0 / 0 0 / 0
[22308.784s][info][gc,reloc ] GC(82) Y: Survivor 1 1M (0%) 0M (0%) 1 / 0 0 / 0 0 / 0
[22308.784s][info][gc,reloc ] GC(82) Y: Survivor 2 2M (0%) 1M (0%) 2 / 1 0 / 0 0 / 0
[22308.784s][info][gc,reloc ] GC(82) Y: Survivor 3 0M (0%) 1M (0%) 1 / 1 0 / 0 0 / 0
[22308.784s][info][gc,reloc ] GC(82) Y: Survivor 4 0M (0%) 1M (0%) 1 / 1 0 / 0 0 / 0
[22308.784s][info][gc,reloc ] GC(82) Y: Survivor 5 0M (0%) 1M (0%) 1 / 1 0 / 0 0 / 0
[22308.784s][info][gc,reloc ] GC(82) Y: Survivor 6 0M (0%) 1M (0%) 1 / 1 0 / 0 0 / 0
[22308.784s][info][gc,heap ] GC(82) Y: Min Capacity: 28672M(100%)
[22308.784s][info][gc,heap ] GC(82) Y: Max Capacity: 28672M(100%)
[22308.784s][info][gc,heap ] GC(82) Y: Soft Max Capacity: 28672M(100%)
[22308.784s][info][gc,heap ] GC(82) Y: Heap Statistics:
[22308.784s][info][gc,heap ] GC(82) Y: Mark Start Mark End Relocate Start Relocate End High Low
[22308.784s][info][gc,heap ] GC(82) Y: Capacity: 28672M (100%) 28672M (100%) 28672M (100%) 28672M (100%) 28672M (100%) 28672M (100%)
[22308.785s][info][gc,heap ] GC(82) Y: Free: 27022M (94%) 27004M (94%) 28184M (98%) 28340M (99%) 28340M (99%) 27004M (94%)
[22308.785s][info][gc,heap ] GC(82) Y: Used: 1650M (6%) 1668M (6%) 488M (2%) 332M (1%) 1668M (6%) 332M (1%)
[22308.785s][info][gc,heap ] GC(82) Y: Young Generation Statistics:
[22308.785s][info][gc,heap ] GC(82) Y: Mark Start Mark End Relocate Start Relocate End
[22308.785s][info][gc,heap ] GC(82) Y: Used: 1350M (5%) 1368M (5%) 188M (1%) 30M (0%)
[22308.785s][info][gc,heap ] GC(82) Y: Live: - 3M (0%) 3M (0%) 3M (0%)
[22308.785s][info][gc,heap ] GC(82) Y: Garbage: - 1346M (5%) 166M (1%) 0M (0%)
[22308.785s][info][gc,heap ] GC(82) Y: Allocated: - 18M (0%) 18M (0%) 25M (0%)
[22308.785s][info][gc,heap ] GC(82) Y: Reclaimed: - - 1180M (4%) 1345M (5%)
[22308.785s][info][gc,heap ] GC(82) Y: Promoted: - - 0M (0%) 0M (0%)
[22308.785s][info][gc,heap ] GC(82) Y: Compacted: - - - 0M (0%)
[22308.785s][info][gc,phases ] GC(82) Y: Young Generation 1650M(6%)->332M(1%) 0.071s
[22308.785s][info][gc,phases ] GC(82) O: Old Generation
[22309.197s][info][gc,phases ] GC(82) O: Concurrent Mark 412.250ms
[22309.197s][info][gc,phases ] GC(82) O: Pause Mark End 0.030ms
[22309.197s][info][gc,phases ] GC(82) O: Concurrent Mark Free 0.001ms
[22309.260s][info][gc,phases ] GC(82) O: Concurrent Process Non-Strong 62.947ms
[22309.260s][info][gc,phases ] GC(82) O: Concurrent Reset Relocation Set 0.002ms
[22309.263s][info][gc,phases ] GC(82) O: Concurrent Select Relocation Set 2.560ms
[22309.263s][info][gc,task ] GC(82) O: Using 2 Workers for Old Generation
[22309.297s][info][gc,task ] GC(82) O: Using 1 Workers for Old Generation
[22309.297s][info][gc,phases ] GC(82) O: Concurrent Remap Roots 34.720ms
[22309.298s][info][gc,phases ] GC(82) O: Pause Relocate Start 0.031ms
[22309.300s][info][gc,phases ] GC(82) O: Concurrent Relocate 2.343ms
[22309.300s][info][gc,alloc ] GC(82) O: Mark Start Mark End Relocate Start Relocate End
[22309.300s][info][gc,alloc ] GC(82) O: Allocation Stalls: 0 0 0 0
[22309.300s][info][gc,load ] GC(82) O: Load: 3.30 (7%) / 3.23 (7%) / 4.09 (9%)
[22309.300s][info][gc,mmu ] GC(82) O: MMU: 2ms/0.0%, 5ms/0.0%, 10ms/29.8%, 20ms/64.9%, 50ms/86.0%, 100ms/93.0%
[22309.300s][info][gc,marking ] GC(82) O: Mark: 1 stripe(s), 2 proactive flush(es), 1 terminate flush(es), 0 completion(s), 0 continuation(s)
[22309.300s][info][gc,marking ] GC(82) O: Mark Stack Usage: 32M
[22309.300s][info][gc,nmethod ] GC(82) O: NMethods: 15194 registered, 1093 unregistered
[22309.300s][info][gc,metaspace] GC(82) O: Metaspace: 142M used, 144M committed, 544M reserved
[22309.300s][info][gc,ref ] GC(82) O: Encountered Discovered Enqueued
[22309.300s][info][gc,ref ] GC(82) O: Soft References: 10074 0 0
[22309.300s][info][gc,ref ] GC(82) O: Weak References: 14843 8448 0
[22309.300s][info][gc,ref ] GC(82) O: Final References: 197 6 0
[22309.300s][info][gc,ref ] GC(82) O: Phantom References: 224 194 0
[22309.300s][info][gc,reloc ] GC(82) O: Candidates Selected In-Place Size Empty Relocated
[22309.300s][info][gc,reloc ] GC(82) O: Small Pages: 53 1 0 106M 0M 1M
[22309.300s][info][gc,reloc ] GC(82) O: Medium Pages: 1 0 0 32M 0M 0M
[22309.300s][info][gc,reloc ] GC(82) O: Large Pages: 9 0 0 162M 0M 0M
[22309.300s][info][gc,reloc ] GC(82) O: Forwarding Usage: 0M
[22309.300s][info][gc,heap ] GC(82) O: Min Capacity: 28672M(100%)
[22309.300s][info][gc,heap ] GC(82) O: Max Capacity: 28672M(100%)
[22309.300s][info][gc,heap ] GC(82) O: Soft Max Capacity: 28672M(100%)
[22309.300s][info][gc,heap ] GC(82) O: Heap Statistics:
[22309.300s][info][gc,heap ] GC(82) O: Mark Start Mark End Relocate Start Relocate End High Low
[22309.300s][info][gc,heap ] GC(82) O: Capacity: 28672M (100%) 28672M (100%) 28672M (100%) 28672M (100%) 28672M (100%) 28672M (100%)
[22309.300s][info][gc,heap ] GC(82) O: Free: 27022M (94%) 28314M (99%) 28312M (99%) 28312M (99%) 28340M (99%) 27004M (94%)
[22309.300s][info][gc,heap ] GC(82) O: Used: 1650M (6%) 358M (1%) 360M (1%) 360M (1%) 1668M (6%) 332M (1%)
[22309.300s][info][gc,heap ] GC(82) O: Old Generation Statistics:
[22309.300s][info][gc,heap ] GC(82) O: Mark Start Mark End Relocate Start Relocate End
[22309.300s][info][gc,heap ] GC(82) O: Used: 300M (1%) 302M (1%) 302M (1%) 302M (1%)
[22309.300s][info][gc,heap ] GC(82) O: Live: - 267M (1%) 267M (1%) 267M (1%)
[22309.300s][info][gc,heap ] GC(82) O: Garbage: - 32M (0%) 32M (0%) 29M (0%)
[22309.300s][info][gc,heap ] GC(82) O: Allocated: - 2M (0%) 2M (0%) 4M (0%)
[22309.300s][info][gc,heap ] GC(82) O: Reclaimed: - - 0M (0%) 2M (0%)
[22309.300s][info][gc,heap ] GC(82) O: Compacted: - - - 1M (0%)
[22309.300s][info][gc,phases ] GC(82) O: Old Generation 332M(1%)->360M(1%) 0.515s
[22309.300s][info][gc ] GC(82) Major Collection (Proactive) 1650M(6%)->360M(1%) 0.587s
[22609.302s][info][gc ] GC(83) Major Collection (Proactive)参考文档：
1062
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
