-Xtgc 跟踪

通过启用一个或多个 TGC(跟踪垃圾回收器)跟踪,您可以获取比使用 -verbose:gc 选项更详细的垃圾回收信息。

本部分总结了可用的不同 -Xtgc 跟踪。 输出将写入 stdout 中。 通过用逗号分隔参数(例如 -Xtgc:backtrace,compaction),可以同时启用多个跟踪。

  • xtgc-backtrace
  • xtgc-compaction
  • xtgc-concurrent
  • xtgc-dump
  • xtgc-excessivegc
  • xtgc-freelist
  • xtgc-parallel
  • xtgc-scavenger
  • xtgc-terse

请参阅 -Xtgc 选项 (-Xtgc option)

-Xtgc:backtrace

此跟踪显示跟踪哪个线程触发垃圾回收的信息。

对于 System.gc(),这可能类似于:
"main" (0x0003691C)
这表明 GC 是由名为“main”和 osThread 0x0003691C 的线程触发的。

将为每个全局或清除器回收打印一行,显示触发 GC 的线程。

-Xtgc:compaction

此跟踪显示与压缩相关的信息。

此跟踪类似于:

Compact(3): reason = 7 (forced compaction)
Compact(3): Thread 0, setup stage: 8 ms.
Compact(3): Thread 0, move stage: handled 42842 objects in 13 ms, bytes moved 2258028.
Compact(3): Thread 0, fixup stage: handled 0 objects in 0 ms, root fixup time 1 ms.
Compact(3): Thread 1, setup stage: 0 ms.
Compact(3): Thread 1, move stage: handled 35011 objects in 8 ms, bytes moved 2178352.
Compact(3): Thread 1, fixup stage: handled 74246 objects in 13 ms, root fixup time 0 ms.
Compact(3): Thread 2, setup stage: 0 ms.
Compact(3): Thread 2, move stage: handled 44795 objects in 32 ms, bytes moved 2324172.
Compact(3): Thread 2, fixup stage: handled 6099 objects in 1 ms, root fixup time 0 ms.
Compact(3): Thread 3, setup stage: 8 ms.
Compact(3): Thread 3, move stage: handled 0 objects in 0 ms, bytes moved 0.
Compact(3): Thread 3, fixup stage: handled 44797 objects in 7 ms, root fixup time 0 ms.

此跟踪显示在第三次全局 GC 期间进行了压缩,原因为“7”。 在此示例中,有四个线程正在执行压缩。 跟踪显示每个线程在设置、移动和修复期间执行的工作。 将显示每个阶段的时间,以及每个线程处理的对象数。

-Xtgc:concurrent

此跟踪显示有关并发标记助手线程的一些附加基本信息。

注: 不能将此选项与 -Xgcpolicy:balanced 选项一起使用。 如果同时使用这两个选项,那么 JVM 不会启动。
<CONCURRENT GC BK thread 0x0002645F activated after GC(5)>

<CONCURRENT GC BK thread 0x0002645F (started after GC(5)) traced 25435>

此跟踪显示激活背景线程的时间以及执行的跟踪量(以字节为单位)。

-Xtgc:dump

此跟踪显示在进行全局垃圾回收的清扫阶段后的附加信息。

这是相当大的跟踪 - 一个 GC 输出的样本为:

<GC(4) 13F9FE44 freelen=x000002C4 -- x00000038 spec/jbb/Stock>
<GC(4) 13FA0140 freelen=x00000010>
<GC(4) 13FA0150 freelen=x00000050 -- x0000001C java/lang/String>
<GC(4) 13FA0410 freelen=x000002C4 -- x00000024 spec/jbb/infra/Collections/
     longBTreeNode>
<GC(4) 13FA0788 freelen=x00000004 -- x00000050 java/lang/Object[]>
<GC(4) 13FA0864 freelen=x00000010>
<GC(4) 13FA0874 freelen=x0000005C -- x0000001C java/lang/String>
<GC(4) 13FA0B4C freelen=x000002C4 -- x00000038 spec/jbb/Stock>
<GC(4) 13FA0E48 freelen=x00000010>
<GC(4) 13FA0E58 freelen=x00000068 -- x0000001C java/lang/String>
<GC(4) 13FA1148 freelen=x000002C4 -- x00000038 spec/jbb/Stock>
<GC(4) 13FA1444 freelen=x00000010>
<GC(4) 13FA1454 freelen=x0000006C -- x0000001C java/lang/String>
<GC(4) 13FA174C freelen=x000002C4 -- x00000038 spec/jbb/Stock>
<GC(4) 13FA1A48 freelen=x00000010>
<GC(4) 13FA1A58 freelen=x00000054 -- x0000001C java/lang/String>
<GC(4) 13FA1D20 freelen=x000002C4 -- x00000038 spec/jbb/Stock>
<GC(4) 13FA201C freelen=x00000010>
<GC(4) 13FA202C freelen=x00000044 -- x0000001C java/lang/String>
<GC(4) 13FA22D4 freelen=x000002C4 -- x00000038 spec/jbb/Stock>
<GC(4) 13FA25D0 freelen=x00000010>
<GC(4) 13FA25E0 freelen=x00000048 -- x0000001C java/lang/String>
<GC(4) 13FA2890 freelen=x000002C4 -- x00000038 spec/jbb/Stock>
<GC(4) 13FA2B8C freelen=x00000010>
<GC(4) 13FA2B9C freelen=x00000068 -- x0000001C java/lang/String>
<GC(4) 13FA2E8C freelen=x000002C4 -- x00000038 spec/jbb/Stock>
<GC(4) 13FA3188 freelen=x00000010>

将为系统中的每个空闲块输出一行,包括暗物质(由于某种原因而不显示在空闲列表上的空闲块,原因通常是因为这些块太小)。 每行都包含基地址和块大小(字节)。 如果堆中的块后跟对象,那么还会输出对象的大小和类名。

-Xtgc:excessiveGC

此跟踪显示垃圾回收周期的统计信息。

在完成垃圾回收周期后,将生成跟踪条目:

excessiveGC: gcid="10" intimems="122.269" outtimems="1.721" \
             percent="98.61" averagepercent="37.89"

此跟踪显示在执行垃圾回收时花费的时间量和垃圾回收外花费的时间量。 在此示例中,垃圾回收周期 10 花费 122.269 毫秒完成,在垃圾回收 9 和 10 之间花费的时间为 1.721 毫秒。 这些统计信息显示垃圾回收占从垃圾回收 9 结束到垃圾回收 10 结束间总时间的 98.61%。 花费在垃圾回收上的平均时间为 37.89%。

当垃圾回收中的平均时间达到 95% 时,将生成附加的跟踪条目:

excessiveGC: gcid="65" percentreclaimed="1.70" freedelta="285728" \
             activesize="16777216" currentsize="16777216" maxiumumsize="16777216"

此跟踪显示回收的垃圾量。 在此示例中,垃圾回收 65 释放了 285728 字节,占据了堆总大小的 1.7%。 此示例还显示堆已扩展至其最大大小(请参阅 -Xmx)。

当垃圾回收中的平均时间达到 95% 且垃圾回收释放的可用空间百分比低于 3% 时,将生成另一个跟踪条目:

excessiveGC: gcid="65" percentreclaimed="1.70" minimum="3.00" excessive gc raised

然后,JVM 将抛出 OutOfMemoryError。

-Xtgc:freelist

在垃圾回收之前,此跟踪输出自上次 GC 以来有关空闲列表和分配统计信息的信息。

此跟踪输出空闲列表上的项数,包括“延迟”条目(带有清除器,未使用的一半空间是延迟的空闲列表条目)。 对于 TLH 和非 TLH 分配,这将输出分配总数、平均分配大小和分配期间废弃的字节总数。 对于非 TLH 分配,还会包括在找到足够大的条目之前,搜索的平均条目数。

 *8* free         0
  *8* deferred     0
total                0
<Alloc TLH: count 3588, size 3107, discard 31>
<  non-TLH: count 6219, search 0, size 183, discard 0>

-Xtgc:parallel

此跟踪显示在全局垃圾回收的标记和清理阶段,有关平行线程活动的统计信息。

Mark:   busy  stall  tail   acquire   release
   0:      30    30     0        0         3
   1:      53     7     0       91        94
   2:      29    31     0       37        37
   3:      37    24     0      243       237
Sweep:  busy   idle sections 127  merge 0
   0:      10     0    96
   1:       8     1     0
   2:       8     1    31
   3:       8     1     0

此跟踪显示四个线程 (0-3) 以及垃圾回收的标记阶段和清理阶段中,每个线程完成的工作。

对于垃圾回收的标记阶段,显示“忙碌”、“停顿”和“结束”状态所花费的时间(以毫秒为单位)。 同时,还显示在标记阶段每个线程获取和发布的工作包数量。

对于垃圾回收的清理阶段,显示“忙碌”和“空闲”状态所花费时间(以毫秒为单位)。 同时,还显示每个线程处理的清理区块数量,包括总数 (127)。 还会显示总合并时间(0 毫秒)。

-Xtgc:scavenger

此跟踪在每次清除器回收后,显示一个柱状图。

注: 不能将此选项与 -Xgcpolicy:balanced 选项一起使用。 如果同时使用这两个选项,那么 JVM 不会启动。

将显示一个图形,其中显示仍保留在幸存者空间中的不同对象类,以及每个类出现的次数和每个对象的年龄(已对其进行翻转的次数)。 下面显示了单次清除后的输出样本:

{SCAV: tgcScavenger OBJECT HISTOGRAM}

{SCAV: | class | instances of age 0-14 in semi-space |
{SCAV: java/lang/ref/SoftReference 0 3 0 0 0 0 0 0 0 0 0 0 0 0 0
{SCAV: java/io/FileOutputStream 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0
{SCAV: sun/nio/cs/StreamEncoder$ConverterSE 0 4 0 0 0 0 0 0 0 0 0 0 0 0 0
{SCAV: java/io/FileInputStream 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0
{SCAV: char[][] 0 102 0 0 0 0 0 0 0 0 0 0 0 0 0
{SCAV: java/lang/ref/SoftReference[] 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0
{SCAV: java/io/BufferedOutputStream 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0
{SCAV: java/io/BufferedWriter 0 4 0 0 0 0 0 0 0 0 0 0 0 0 0
{SCAV: java/io/OutputStreamWriter 0 4 0 0 0 0 0 0 0 0 0 0 0 0 0
{SCAV: java/io/PrintStream 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0
{SCAV: java/io/BufferedInputStream 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0
{SCAV: java/lang/Thread[] 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0
{SCAV: java/lang/ThreadGroup[] 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0
{SCAV: sun/io/ByteToCharCp1252 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0
{SCAV: sun/io/CharToByteCp1252 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0

-Xtgc:terse

此跟踪将对垃圾回收之前和之后整个堆的内容进行转储。

这是相当大的跟踪。 对于堆中的每个对象或可用块,将生成一行跟踪输出。 每行都包含基地址(如果是分配的对象,那么为“a”,如果为空闲块,那么为“f”)和以字节表示的块大小,如果是对象,还会包含其类名。 下面显示了一个样本:

*DH(1)* 230AD778 a x0000001C java/lang/String
*DH(1)* 230AD794 a x00000048 char[]
*DH(1)* 230AD7DC a x00000018 java/lang/StringBuffer
*DH(1)* 230AD7F4 a x00000030 char[]
*DH(1)* 230AD824 a x00000054 char[]
*DH(1)* 230AD878 a x0000001C java/lang/String
*DH(1)* 230AD894 a x00000018 java/util/HashMapEntry
*DH(1)* 230AD8AC a x0000004C char[]
*DH(1)* 230AD8F8 a x0000001C java/lang/String
*DH(1)* 230AD914 a x0000004C char[]
*DH(1)* 230AD960 a x00000018 char[]
*DH(1)* 230AD978 a x0000001C java/lang/String
*DH(1)* 230AD994 a x00000018 char[]
*DH(1)* 230AD9AC a x00000018 java/lang/StringBuffer
*DH(1)* 230AD9C4 a x00000030 char[]
*DH(1)* 230AD9F4 a x00000054 char[]
*DH(1)* 230ADA48 a x0000001C java/lang/String
*DH(1)* 230ADA64 a x00000018 java/util/HashMapEntry
*DH(1)* 230ADA7C a x00000050 char[]
*DH(1)* 230ADACC a x0000001C java/lang/String
*DH(1)* 230ADAE8 a x00000050 char[]
*DH(1)* 230ADB38 a x00000018 char[]
*DH(1)* 230ADB50 a x0000001C java/lang/String
*DH(1)* 230ADB6C a x00000018 char[]
*DH(1)* 230ADB84 a x00000018 java/lang/StringBuffer
*DH(1)* 230ADB9C a x00000030 char[]
*DH(1)* 230ADBCC a x00000054 char[]
*DH(1)* 230ADC20 a x0000001C java/lang/String
*DH(1)* 230ADC3C a x00000018 java/util/HashMapEntry
*DH(1)* 230ADC54 a x0000004C char[]