有人可以理解G1垃圾收集器的输出吗？ [英] Can someone make sense of the G1 garbage collector output?
本文介绍了有人可以理解G1垃圾收集器的输出吗？的处理方法，对大家解决问题具有一定的参考价值，需要的朋友们下面随着小编来一起学习吧！
问题描述
我正在用G1垃圾回收器运行Java程序，使用以下选项：
-XX：-UseBiasedLocking
-XX：+ UnlockExperimentalVMOptions
-XX：+ UseG1GC
-verbose：gc -XX：+ PrintGCTimeStamps -XX：+ PrintGCDetails -Xloggc：/var/tmp/gclog.out
输出如下所示...
44900.297：[GC暂停（年轻）44900.386（初始标记），0.08894851秒]
：[GC并发标记开始]
[并行时间：83.7毫秒]
[GC工作人员开始时间（ms）：44900297.6 44900297.6 44900297.6 44900297.6 44900297.6 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7
平均值：44900297.7，最小值：44900297.6，最大值：44900297.7，Diff：0.1]
[更新RS（ms）：23.5 24.3 25.0 25.0 23.9 24.4 25.2 24.1 25.7 24.7 24.8 24.4 24.7
平均值：24.6，最小值：23.5，最大值：25.7，差值：2.1]
[已处理的缓冲区：16 19 19 23 20 24 18 18 18 17 20 16 19
总计：247，平均19，最小16，最大24，差异8]
[外部根扫描（毫秒）：2.2 2.7 2.2 2.6 [ms）：0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 3.0 b1 b平均值：2.4，最小值：1.1，最大值：3.1，Diff：2.0]
0.0 0.0 0.0
平均值0.0，最小值：0.0，最大值：0.0，差值：0.0]
[扫描RS（ms）：14.1 14.6 14.5 14.3 14.6 14.2 14.4 14.5 14.0 13.9 14.6 14.5 14.0
平均值：14.3，最小值：13.9，最大值：14.6，差值：0.8]
[对象副本（毫秒）：41.4 39.5 39.4 39.0 39.6 39.5 39.1 41.4 39.0 39.3 39.3 39.8 39.5
平均值：39.7，终点（ms）：1.3 1.4 1.5 1.6 1.5 1.4 1.6 1.4 1.5 1.7 1.5 1.4 1.3
平均1.5，最小值：1.3，最大值：1.7最小值：39.0，最大值：41.4，差值：2.4] ，差额：0.4]
[终止尝试次数：1185 1205 1219 1436 1171 1231 1471 1237 1461 1526 1353 1259 1170
总计：16924，平均值：1301，最小值：1170，最大值：1526，差值：356]
[GC工作结束时间（ms）：44900380.2 44900380.2 44900380.2 44900380.2 44900380.2 44900380.3 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2
平均值：44900380.2，最小值：44900380.2，最大值：44900380.3，差值：0.1]
[GC工人时间（ms）：82.6 82.6 82.6 82.6 82.6 82.6 82.5 82.6 82.5 82.5 82.5 82.5 82.5
平均82.6，最小82.5，最大82.6，差异0.1]
[其他：1.2 ms]
[清除CT：0.5 ms]
[其他：4.8 ms]
[选择CSet：0.0ms]
[1331M-> 830M（1840M）]
[时间：用户= 1.07 sys = 0.01，实际= 0.09秒]
44901.205：[GC $ GCA并发标记结束，0.8186002秒]
44901.205：[GC备注，0.0258621秒]
[时间：用户= 0.02 sys = 0.00，实际= 0.03秒]
44901.231： -count-start]
44901.479：[GC并发计数结束，0.2478477]
44901.479：[GC清除940M-> 931M（1840M），0.0073079秒]
任何人都可以理解发生了什么？
解决方案
免责声明
我绝不会精通垃圾首先垃圾收集器和这个
的问题激励我第一次检查它。有可能
我的一些信息可能有误。
简介
要获取关于垃圾优先垃圾收集器（G1GC），
垃圾优先垃圾收集器（这里，
这里，这里和此处）是一种价值
的宝贵资源。您可以在这里找到G1GC
。 HotSpot词汇表适用于
了解JVM条款。以下文章对进一步了解垃圾收集
也有帮助：
有了这些资源和OpenJDK 7 调试 build ，
您可以开始了解G1GC日志。
定义
使用上面引用的论文和网页，以下是一些有用的
术语定义：
- 并发标记：两者都提供收集完整性，
标识通过紧缩疏散回收的地区。提供
收集器完整性，而不会对
收集集合的区域选择强加任何订单。提供实时数据信息，允许区域以垃圾优先顺序收集
。 - 堆：使用的内存区域用于动态内存分配的JVM。
- 堆区：堆被分区为一组相等大小的堆
区域。 Garbage-First堆被分成大小相同的堆区域，每个
a连续的虚拟内存区域。 - 标记位图：包含一位每个地址可以是
的一个对象的开始。
- 记住的集合：一个数据结构，指示
区域之外的堆位置可能包含指向该区域中对象的指针。每个区域都有一个
关联的记忆集合，它表示所有可能包含区域内（实况）对象的
指针的位置。垃圾 - 首先记住设置
记录来自所有地区的指针（有一些例外）。当前缓冲区或
修改卡序列。一个数据结构，记录
代之间的指针。
- 根集：一组已知可直接访问的对象。
源代码
为了更好地理解G1GC日志，我使用了以下OpenJDK 7
源文件：
$ b $ ul
- hotspot / src / share / vm / gc_implementation / g1 / concurrentMarkThread.cpp
- 热点/ src / share / vm / gc_implementation / g1 / concurrentMark.hpp
- 热点/ src / share / vm / gc_implementation / g1 / concurrentMark.hpp hotspot / src / share / vm / gc_implementation / g1 / g1_specialized_oop_closures.hpp
- 热点/ src / share / vm / gc_implementation / g1 / g1CollectedHeap.cpp
- hotspot / src / share / vm / gc_implementation / g1 / g1CollectedHeap.hpp
- hotspot / src / share / vm / gc_implementation / g1 / g1CollectorPolicy.cpp b
- hotspot / src / share / vm / gc_implementation / g1 / g1CollectorPolicy.hpp
- hotspot / src / share / vm / gc_implementation / g1 / g1OopClosures.hpp
- 热点/ sr c / share / vm / gc_implementation / g1 / g1OopClosures.inline.hpp
- hotspot / src / share / vm / gc_implementation / g1 / g1RemSet.cpp
- hotspot / src / share / vm / memory / sharedHeap.cpp
- hotspot / src / share / vm / memory / sharedHeap.hpp hotspot / src / share / vm / utilities / taskqueue.hpp
- hotspot / src / share / vm / runtime / timer.cpp
- 热点/ src / share / vm / runtime / timer.hpp
- hotspot / src / share / vm / gc_implementation / g1 / vm_operations_g1.cpp
- 热点/
$ b日志分析
44900.297：[GC pause（young）（initial-标记），0.08894851秒]
^^^^^^^^^^^从JVM开始经过的秒数
^^^^^^^^^在安全点处收集暂停
^ ^^^^^^^完整的年轻GC模式
^^^^^^^^^^^^^^^最后一次停顿包括ini tial mark
^^^^^^^^^^^^^^^^^^在方法
中运行秒数44900.386：[GC concurrent-mark-start]
^^^^ ^^^^^^^从JVM开始经过的秒
^^^^^^^^^^^^^^^^^^^^^^^^^^并发标记线程开始
[并行时间：83.7毫秒]
^^^^^^^^^^^^^^^^^^^^^^^^^所有GC工作线程完成$ b的经过的毫秒数$ b [GC工作人员开始时间（ms）：44900297.6 44900297.6 44900297.6 44900297.6 44900297.6 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7
^^^^^^^^^^^^^^^^^^^^^^ ^^^^^^^^^^^^^ ...从JVM开始启动GC工作线程开始的秒数
平均值：44900297.7，最小值：44900297.6，最大值：44900297.7，差值：0.1]
^^^^^^^^^^^^^^^^^^^^^^平均GC工作线程启动时间（从JVM启动开始经过的秒数）
^^^^^^^^^^ ^^^^^^^最小GC工作线程启动时间（从JVM启动开始经过的秒数）
^^^^^^^^^^^^^^^^^最大GC工作线程启动时间（从JVM启动开始经过的秒数）
^^^^^^^^^^^^^^总计秒数开始所有GC工作线程
[更新RS（ms）：23.5 24.3 25.0 25.0 23.9 24.4 25.2 24.1 25.7 24.7 24.8 24.4 24.7
^^^^^^^^^^^^^^^ ^^^^^^^^ ...在疏散暂停期间，每个GC工作线程更新记忆集合中卡片的经过的毫秒数
平均值：24.6，最小值：23.5，最大值：25.7，差值：2.1]
^^^^^^^^^^^^^^^^^更新的平均GC工作线程毫秒RS
^^^^^^^^^^^^更新GC工作线程的最小线程毫秒数RS
^^^^^^^^^^^^更新GC工作线程毫秒数RS
^^^^^^^^^^^^^^ GC工作人员的最小/最大增量线程毫秒更新RS
[处理后的缓冲区：16 19 19 23 20 24 18 18 18 17 2 0 16 19
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ ...每个GC工作线程处理的总记忆集缓冲区
总和：247，平均值：19，最小值：16，最大值：24，差值：8]
^^^^^^^^^^ ...处理的总记忆集缓冲区的摘要信息所有GC工作线程
[Ext Root Scanning（ms）：2.2 2.7 2.2 2.6 3.0 3.1 2.2 1.1 2.3 3.0 2.2 2.4 2.9
^^^^^^^^^^^^^^^^^ ^^^^^^^^^^^^^^^ ...每个GC工作线程在疏散暂停期间处理堆根的经过的毫秒数
平均值：2.4，最小值：1.1，最大值：3.1，差值：2.0]
^^^^^^^ ...所有GC工作线程在疏散暂停期间处理堆根所花费的总毫秒数摘要信息
[Mark Stack Scanning（ms）：0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^。 ..在撤离暂停期间，每个GC工作线程扫描标记堆栈中的强根的经过的毫秒数
平均值：0.0，最小值：0.0，最大值：0.0，差值：0.0]
^^^^^^^ ...所有GC工作线程在撤离暂停期间扫描标记堆栈中强根的总毫秒数摘要信息
[扫描RS（ms）：14.1 14.6 14.5 14.3 14.6 14.2 14.4 14.5 14.0 13.9 14.6 14.5 14.0
^^^^^^^^^^^^^^^^^^^^^^ .. 。每个GC工作线程扫描堆区域中的脏卡以更新记录集的经过的毫秒数
平均值：14.3，最小值：13.9，最大值：14.6，比较值：0.8]
^^^^ ^^^^^^^^^ ...所有GC工作线程扫描堆区域中的脏卡以更新记录集合所花费的总毫秒数摘要信息
[Object Copy（ms））：41.4 39.5 39.4 39.0 39.6 39.5 39.1 41.4 39.0 39.3 39.3 39.8 39.5
^^^^^^^^^^^^^^^^^^^^^^^^^^ ...每个地理标志工作者的耗时毫秒线程扫描根集，以便在避难暂停期间包含在该堆区域的记忆集合中的指针
平均值：39.7，最小值：39。 0，最大值：41.4，差值：2.4]
^^^^^^^^^^^^^ ...所有GC工作线程扫描根集的累计经过的毫秒数摘要信息，指向要包含的指针这个堆区在撤退暂停期间记住的集合
[终止（ms）：1.3 1.4 1.5 1.6 1.5 1.4 1.6 1.4 1.5 1.7 1.5 1.4 1.3
^^^^^^^^^^^^^^ ^^^^^^^^^^^^ ...每个GC工作线程终止的毫秒数，用于终止扫描根集的指针，以便在疏散暂停期间包含在这个堆区域的记忆集中
平均值：1.5，Min ：1.3，最大值：1.7，Diff：0.4]
^^^^^^^^^^^^^^ ...所有GC工作线程终止扫描根集的累计已用毫秒总结信息在撤离暂停期间包括在这个堆区的记忆集中
[终止尝试次数：1185 1205 1219 1436 1171 1231 1471 1237 1461 1526 1353 1259 1170
^^^^^^^^^^^^^ ^^^^^^^^^^^^^^^^^^^^ ...每个GC工作线程的总尝试次数在撤离暂停期间终止扫描根集合以指向包括在该堆区域的记忆集合
总和：16924，平均值：1301，最小值：1170，最大值：1526，差值：356]
^ ^^ ^^^^^^^^^^^^ ...所有GC工作线程尝试终止扫描根集的摘要信息，用于在疏散暂停期间包含在此堆区的记忆集中的指针
[GC工人结束时间（ms）：44900380.2 44900380.2 44900380.2 44900380.2 44900380.2 44900380.3 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2
^^^^^^^^^^^^^^^^^^^^^^^^^^ ^^^^^^^ ...从JVM启动开始，GC工作线程结束$ s $ b平均值：44900380.2，最小值：44900380.2，最大值：44900380.3，Diff：0.1]
^^^^^^ ^^^^^^ ...从JVM启动开始，GC工作线程以所有GC工作线程结束的总耗用秒数摘要信息
[GC工作时间（ms）：82.6 82.6 82.6 82.6 82.6 82.6 82.5 82.6 82.5 82.5 82.5 82.5 82.5
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ ...每个GC工作者的经过的毫秒数为
平均值：82.6，最小值：82.5，最大值：82.6，差值：0.1]
^^^^^^^^^^^^^ ...所有GC工作线程总消耗毫秒数的摘要信息
[Other：1.2 ms]
^^^^^^^^^^^^^^^^^^^^^^ GC并行处理期间的其他毫秒数;基本上，总毫秒减：更新RS，ext根扫描，标记堆栈扫描，扫描RS，对象复制，终止
[Clear CT：0.5 ms]
^^^^^^^^^^^ ^^^^^^^^^^^^清除脏卡表列表的总毫秒数
[其他：4.8 ms]
^^^^^^^^^^^^^^^ ^^^^^此GC暂停中的总毫秒数不平行并清除CT
[选择CSet：0.0 ms]
^^^^^^^^^^^^^^^^^ ^^^^^^^^^^^^选择年轻堆区添加到集合集的总毫秒数
[1331M-> 830M（1840M）]
^^^^^堆大小更改此垃圾回收器
^^^^^此集合暂停之前的总堆大小
^^^^此集合暂停后的总堆大小
^^^^^总堆大小容量这个垃圾收集器
[Times：user = 1.07 sys = 0.01，real = 0.09 secs]
^^^^^^^^执行秒数（使用TraceCPUTime类;构造函数初始化时间为零，析构函数打印时间）
^^^^^^^^^^ U所有线程的执行秒数
^^^^^^^^^系统执行秒数
^^^^^^^^^^^实时（挂钟）执行秒数
44901.205： [GC并发标记结束，0.8186002秒]
^^^^^^^^^^^从JVM开始经过的秒数
^^^^^^^^^^^^^^^ ^^^^^^^^^并发标记线程结束
^^^^^^^^^^^^^执行并发标记线程的总秒数
44901.205：[GC备注，0.0258621秒]
^^^^^^^^^^^从JVM开始经过的秒数
^^^^^^^^^^所有堆根同时重新标记，最终工作
[Times ：user = 0.02 sys = 0.00，real = 0.03 secs]
^^^^^^^^执行秒数（使用TraceCPUTime类;构造函数初始化时间为零，析构函数打印时间）
^^^^^^^^^^所有线程的用户执行秒数
^^^^^^^^^系统执行秒数
^^^^^^^^^^^实时（挂钟）执行时间秒
44901.231：[GC并发计数开始]
^^^^^^^^^^^经过秒钟JVM start
^^^^^^^^^^^^^^^^^^^^^^^^^^^开始同时标记活物
44901.479：[GC并发计数-end，0.2478477]
^^^^^^^^^^^从JVM开始经过的秒数
^^^^^^^^^^^^^^^^^^^^^ ^^^^^^结束活标的同时标记
^^^^^^^^^^^^活标记同时标记的总秒数
44901.479：[GC清除940M-> 931M（1840M），0.0073079秒]
^^^^^^^^^^^从JVM开始经过的秒数
^^^^^^^^^^^同时标记清除（世界停止在这个检查点）
^ ...这个g的堆大小变化垃圾收集器
^^^^此操作前的堆总大小
^^^^此操作后的堆总大小
^^^^^此垃圾收集器的堆大小总容量
执行并发标记清除的总秒数
OpenJDK 7 G1GC
如果您可以构建调试复制 OpenJDK 7，您将有更多的
JVM选项可供您使用，这将为您提供有关
G1GC的更多信息。使用以下命令获取所有JVM选项的列表：java -XX：+ AggressiveOpts -XX：+ UnlockDiagnosticVMOptions -XX ：+ PrintFlagsFinal -XX：+ PrintFlagsWithComments -version
输出显示以下可用的G1GC选项;这不是一个全部
的列表，只是一些我认为是有意思的。intx G1CardCountCacheExpandThreshold = 16扩展卡如果特定条目的冲突数超过此值，则计数缓存。
uintx G1ConcMarkForceOverflow = 0在并发标记过程中强制溢出的次数
double G1ConcMarkStepDurationMillis = 10.000000 {product}单个并发标记步骤的目标持续时间（以毫秒为单位）。
intx G1ConcRSHotCardLimit = 4定义（> =）热卡的阈值。
intx G1ConcRSLogCacheSize = 10浓度RS热卡缓存长度的基数2。
bool G1ConcRegionFreeingVerbose = false在并发区域释放期间启用冗长性
intx G1ConfidencePercent = 50 {product} MMU /暂停预测的置信度
bool G1DeferredRSUpdate = true如果为true，则使用延期RS更新
bool G1FixedEdenSize = false设置后，G1将不分配未使用的生存空间区域
uintx G1FixedSurvivorSpaceSize = 0如果非0为G1幸存空间的大小，否则SurvivorRatio用于确定大小
bool G1FixedTenuringThreshold = false设置后，G1不会调整使用期限
bool G1Gen = true如果为true，则将启用代G1 = b $ b uintx G1HeapRegionSize = 0 {product} G1区域的大小。
intx G1InitYoungSurvRatio = 50新分配字节的预期存活率
intx G1MarkRegionStackSize = 1048576 {product}用于并发标记的区域堆栈的大小。
intx G1MarkingOverheadPercent = 0并发标记的开销
intx G1MarkingVerboseLevel = 0标记代码的详细级别（0-4）
intx G1MaxHotCardCountSizePercent = 25热卡计数高速缓存的最大大小为最大堆的卡数的百分比。
intx G1MaxVerifyFailures = -1要打印的验证失败的最大数目。 -1表示全部打印。
intx G1PausesBtwnConcMark = -1如果为正数，则浓缩标记之间的暂停数量为固定数量
intx G1PolicyVerbose = 0 G1策略决策的详细级别
bool G1PrintCTFilterStats = false如果为true，则在RS过滤器上打印统计信息有效性
布尔G1PrintHeapRegions = false {诊断}如果设置G1将打印关于哪些区域正在分配以及哪些区域被回收的信息。
bool G1PrintOopAppls = false如果为true，则将封闭应用程序打印到外部loc。
bool G1PrintParCleanupStats = false如果为true，则显示关于并行清理的额外统计信息。
bool G1PrintReachableAtInitialMark = false初始标记暂停时可达到的对象转储
ccstr G1PrintReachableBaseFile =可到达对象转储的基本文件名
bool G1PrintRegionLivenessInfo = false {product}打印所有区域的活性信息在标记周期结束时的堆中。
bool G1RSCountHisto = false如果为true，则在每次暂停后打印RS占用率的直方图
bool G1RSLogCheckCardTable = false如果为true，则验证在RS日志处理后没有脏的卡剩余。
bool G1RSScrubVerbose = false如果为true，则使用详细输出进行RS清理。
intx G1RSetRegionEntries = 0 {product}我们保留位图的区域的最大数量。默认情况下将根据人体工程学设置。
intx G1RSetRegionEntriesBase = 256每个MB在细粒度表中的最大区域数。
uintx G1RSetScanBlockSize = 64 {product}在RSet扫描期间工作线程声明的工作单元的大小。
intx G1RSetSparseRegionEntries = 0 {product}稀疏表中每个区域的最大条目数。默认情况下将按照人体工程学设置。
intx G1RSetSparseRegionEntriesBase = 4每MB中稀疏表中每个区域的最大条目数。
intx G1RSetUpdatingPauseTimePercent = 10 {product}收集暂停期间允许在过程RS更新缓冲区上花费的时间的目标百分比。
bool G1RecordHRRSEvents = false如果为true，则将最近的调用记录到rem集合操作中。
布尔型G1RecordHRRSOops = false如果为true，则将最近的调用记录到rem集合操作中。
intx G1RefProcDrainInterval = 10 {product}排出并发标记工作队列之前处理的发现引用对象的数量。
intx G1ReservePercent = 10 {product}它决定了我们应该在堆中保留的最小备用数，以最小化升级失败的可能性。
uintx G1SATBBufferEnqueueingThresholdPercent = 60 {product}排队前，每个mutator线程都会尝试对其生成的SATB缓冲区执行一些筛选。如果后过滤保留条目的百分比超过此阈值，则缓冲区将被排队处理。值为0指定增变器线程不应该进行这样的过滤。
intx G1SATBBufferSize = 1024 {product} SATB日志缓冲区中的条目数。
bool G1SATBPrintStubs = false如果为true，则为SATB屏障打印生成的存根
intx G1SATBProcessCompletedThreshold = 20触发日志处理的已完成缓冲区数。
bool G1ScrubRemSets = true如果为true，则在清理后执行RS清理。
uintx G1SecondaryFreeListAppendLength = 5我们将在每个追加操作中添加到辅助空闲列表的区域数量
bool G1StressConcRegionFreeing = false强调并发区域释放操作
uintx G1StressConcRegionFreeingDelayMillis = 0期间的人工延迟并发区域释放
bool G1SummarizeConcMark = false {诊断}汇总并发标记信息
bool G1SummarizeRSetStats = false {诊断}汇总记忆的集处理信息
intx G1SummarizeRSetStatsPeriod = 0 {我们将在其中生成更新缓冲区处理信息（0表示不定期生成此信息）;它还需要-XX：+ G1SummarizeRSetStats
bool G1TraceConcRefinement = false {diagnostic}跟踪G1并发优化
布尔G1TraceMarkStackOverflow = false如果为true，则为ovflw重新启动CM的额外调试代码。
intx G1UpdateBufferSize = 256 {product}更新缓冲区的大小
bool G1VerifyDuringGCPrintReachable = false如果浓标记验证失败，则转储可到达的对象
intx G1YoungSurvRateNumRegionsSummary = 0我们为其打印存活率汇总。
bool G1YoungSurvRateVerbose = false根据年龄打印年轻区域的存活率。
要查看使用OpenJDK 7 debug
build提供的G1GC信息，使用了下面的测试程序：
import java.lang.ref.WeakReference;
import java.util.ArrayList;
import java.util.Iterator;
import java.util.List;
import java.util.Random;
公共类G1GCTest实现了Runnable {
private int iterations = 0;
private final Random rnd = new Random（）;
private final List< Object> young = new ArrayList< Object>（1000）;
private final List< WeakReference< Object>> old =
new ArrayList< WeakReference< Object>>（100000）;
private void clearOld（）{
int clearedCnt = 0;
for（final Iterator< WeakReference< Object>> iter = old.iterator（）; iter
.hasNext（）;）
{
final WeakReference< Object> ref = iter.next（）;
if（null == ref.get（））{
iter.remove（）;
clearedCnt ++;
}
if（0< clearedCnt）{
System.out.println（Cleared+ clearedCnt
+对旧对象的弱引用。 ）;
public void run（）{
if（0 == ++ iterations％10000）{
System.out.println（ iterations =+ iterations +，young.size（）=
+ young.size（）+，old.size（）=+ old.size（））;
clearOld（）;
尝试{
Thread.sleep（100）;
} catch（final Throwable e）{
//什么也不做！
}
}
if（rnd.nextBoolean（））{
young.add（new byte [1000]）;
}
if（rnd.nextBoolean（）&！young.isEmpty（））{
final int nextInt = Math.abs（rnd.nextInt（））;
final int idx = nextInt％young.size（）;
final Object obj = young.remove（idx）;
old.add（new WeakReference< Object>（obj））;
}
}
public static void main(final String[] args) {
final G1GCTest t = new G1GCTest();
while (1000000 > t.iterations) {
t.run();
}
}
}
And executed it using:
java -Xms8m -Xmx8m -XX:+UnlockExperimentalVMOptions -XX:+UseG1GC -XX:+PrintGC -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -XX:+G1SummarizeConcMark -XX:+G1SummarizeRSetStats -XX:+G1YoungSurvRateVerbose -XX:G1PolicyVerbose=2 -verbose:gc G1GCTest
The output of which was very verbose, but provides a slew of information that
could prove useful if you’re doing some GC tuning.I am running a Java program with the G1 garbage collector using the following options:
-XX:-UseBiasedLocking -XX:+UnlockExperimentalVMOptions -XX:+UseG1GC -verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:/var/tmp/gclog.outThe output looks like this...
44900.297: [GC pause (young)44900.386 (initial-mark), 0.08894851 secs] : [GC concurrent-mark-start] [Parallel Time: 83.7 ms] [GC Worker Start Time (ms): 44900297.6 44900297.6 44900297.6 44900297.6 44900297.6 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7 Avg: 44900297.7, Min: 44900297.6, Max: 44900297.7, Diff: 0.1] [Update RS (ms): 23.5 24.3 25.0 25.0 23.9 24.4 25.2 24.1 25.7 24.7 24.8 24.4 24.7 Avg: 24.6, Min: 23.5, Max: 25.7, Diff: 2.1] [Processed Buffers : 16 19 19 23 20 24 18 18 18 17 20 16 19 Sum: 247, Avg: 19, Min: 16, Max: 24, Diff: 8] [Ext Root Scanning (ms): 2.2 2.7 2.2 2.6 3.0 3.1 2.2 1.1 2.3 3.0 2.2 2.4 2.9 Avg: 2.4, Min: 1.1, Max: 3.1, Diff: 2.0] [Mark Stack Scanning (ms): 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 Avg: 0.0, Min: 0.0, Max: 0.0, Diff: 0.0] [Scan RS (ms): 14.1 14.6 14.5 14.3 14.6 14.2 14.4 14.5 14.0 13.9 14.6 14.5 14.0 Avg: 14.3, Min: 13.9, Max: 14.6, Diff: 0.8] [Object Copy (ms): 41.4 39.5 39.4 39.0 39.6 39.5 39.1 41.4 39.0 39.3 39.3 39.8 39.5 Avg: 39.7, Min: 39.0, Max: 41.4, Diff: 2.4] [Termination (ms): 1.3 1.4 1.5 1.6 1.5 1.4 1.6 1.4 1.5 1.7 1.5 1.4 1.3 Avg: 1.5, Min: 1.3, Max: 1.7, Diff: 0.4] [Termination Attempts : 1185 1205 1219 1436 1171 1231 1471 1237 1461 1526 1353 1259 1170 Sum: 16924, Avg: 1301, Min: 1170, Max: 1526, Diff: 356] [GC Worker End Time (ms): 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2 44900380.3 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2 Avg: 44900380.2, Min: 44900380.2, Max: 44900380.3, Diff: 0.1] [GC Worker Times (ms): 82.6 82.6 82.6 82.6 82.6 82.6 82.5 82.6 82.5 82.5 82.5 82.5 82.5 Avg: 82.6, Min: 82.5, Max: 82.6, Diff: 0.1] [Other: 1.2 ms] [Clear CT: 0.5 ms] [Other: 4.8 ms] [Choose CSet: 0.0 ms] [ 1331M->830M(1840M)] [Times: user=1.07 sys=0.01, real=0.09 secs] 44901.205: [GC concurrent-mark-end, 0.8186002 sec] 44901.205: [GC remark, 0.0258621 secs] [Times: user=0.02 sys=0.00, real=0.03 secs] 44901.231: [GC concurrent-count-start] 44901.479: [GC concurrent-count-end, 0.2478477] 44901.479: [GC cleanup 940M->931M(1840M), 0.0073079 secs]Can anyone make sense of what is going on?
解决方案Disclaimer
I am in no way well versed on the Garbage-First Garbage Collector and this question inspired me to check it out for the first time. There is a chance I may be wrong with some of my information.
Intro
To get more information about the Garbage-First Garbage Collector (G1GC), the Garbage-First Garbage Collection paper (here, here, here and here) is an invaluable resource. You can find an introduction to the G1GC here. The HotSpot Glossary comes in handy to understand JVM terms. The following papers were also helpful in further understanding Garbage Collection:
- A Hard Look at Hard Real-Time Garbage Collection: here and here
- Non-Blocking Garbage Collection for Multiprocessors: here and here
- Non-blocking Root Scanning for Real-Time Garbage Collection: here
- Non-blocking Object Copy for Real-Time Garbage Collection: here and here
With these resources and an OpenJDK 7 debug build, you can start to understand the G1GC log.
Definitions
Using the papers and web pages referenced above, here are some useful definitions of terms that came up most often:
- concurrent marking: Both provides collection "completeness" and identifies regions ripe for reclamation via compacting evacuation. Provides collector completeness without imposing any order on region choice for collection sets. Provides the live data information that allows regions to be collected in "garbage-first" order.
- heap: The area of memory used by the JVM for dynamic memory allocation.
- heap region: The heap is partitioned into a set of equal-sized heap regions. The Garbage-First heap is divided into equal-sized heap regions, each a contiguous range of virtual memory.
- marking bitmap: Contains one bit for each address that can be the start of an object.
- remembered set: A data structure that indicates heap locations outside the region that may contain pointers to objects in the region. Each region has an associated remembered set, which indicates all locations that might contain pointers to (live) objects within the region. Garbage-First remembered sets record pointers from all regions (with some exceptions). A current buffer or sequence of modified cards. A data structure that records pointers between generations.
- root set: A set of objects which is known to be directly accessible. The locations from which all live objects are reachable.
Source Code
To understand the G1GC log better, I used the following OpenJDK 7 source files:
- hotspot/src/share/vm/gc_implementation/g1/concurrentMarkThread.cpp
- hotspot/src/share/vm/gc_implementation/g1/concurrentMark.cpp
- hotspot/src/share/vm/gc_implementation/g1/concurrentMark.hpp
- hotspot/src/share/vm/gc_implementation/g1/g1_specialized_oop_closures.hpp
- hotspot/src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp
- hotspot/src/share/vm/gc_implementation/g1/g1CollectedHeap.hpp
- hotspot/src/share/vm/gc_implementation/g1/g1CollectorPolicy.cpp
- hotspot/src/share/vm/gc_implementation/g1/g1CollectorPolicy.hpp
- hotspot/src/share/vm/gc_implementation/g1/g1OopClosures.hpp
- hotspot/src/share/vm/gc_implementation/g1/g1OopClosures.inline.hpp
- hotspot/src/share/vm/gc_implementation/g1/g1RemSet.cpp
- hotspot/src/share/vm/memory/sharedHeap.cpp
- hotspot/src/share/vm/memory/sharedHeap.hpp
- hotspot/src/share/vm/utilities/taskqueue.hpp
- hotspot/src/share/vm/runtime/timer.cpp
- hotspot/src/share/vm/runtime/timer.hpp
- hotspot/src/share/vm/gc_implementation/g1/vm_operations_g1.cpp
- hotspot/src/share/vm/gc_implementation/g1/vm_operations_g1.hpp
Log Analysis
Below is an annotated copy of the G1GC log in question.
44900.297: [GC pause (young) (initial-mark), 0.08894851 secs] ^^^^^^^^^^^ Elapsed seconds from JVM start ^^^^^^^^^ Collection pause at safe-point ^^^^^^^^ In full young GC mode ^^^^^^^^^^^^^^^ Last pause included initial mark ^^^^^^^^^^^^^^^^^^ Elapsed seconds in method 44900.386: [GC concurrent-mark-start] ^^^^^^^^^^^ Elapsed seconds from JVM start ^^^^^^^^^^^^^^^^^^^^^^^^^^ Concurrent mark thread started [Parallel Time: 83.7 ms] ^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Elapsed milliseconds for all GC worker threads to finish [GC Worker Start Time (ms): 44900297.6 44900297.6 44900297.6 44900297.6 44900297.6 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^... Elapsed seconds from JVM start that GC worker threads were started Avg: 44900297.7, Min: 44900297.6, Max: 44900297.7, Diff: 0.1] ^^^^^^^^^^^^^^^^^^^^^^ Average GC worker thread start time (elapsed seconds from JVM start) ^^^^^^^^^^^^^^^^^ Minimum GC worker thread start time (elapsed seconds from JVM start) ^^^^^^^^^^^^^^^^^ Maximum GC worker thread start time (elapsed seconds from JVM start) ^^^^^^^^^^^^^^ Total seconds to start all GC worker threads [Update RS (ms): 23.5 24.3 25.0 25.0 23.9 24.4 25.2 24.1 25.7 24.7 24.8 24.4 24.7 ^^^^^^^^^^^^^^^^^^^^^^^^... Elapsed milliseconds for each GC worker thread to update cards in remembered sets during an evacuation pause Avg: 24.6, Min: 23.5, Max: 25.7, Diff: 2.1] ^^^^^^^^^^^^^^^^^ Average GC worker thread milliseconds to update RS ^^^^^^^^^^^^ Minimum GC worker thread milliseconds to update RS ^^^^^^^^^^^^ Maximum GC worker thread milliseconds to update RS ^^^^^^^^^^^^^^ Minimum/maximum delta of GC worker thread milliseconds to update RS [Processed Buffers : 16 19 19 23 20 24 18 18 18 17 20 16 19 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^... Total remembered set buffers processed by each GC worker thread Sum: 247, Avg: 19, Min: 16, Max: 24, Diff: 8] ^^^^^^^^^^... Summary information for total remembered set buffers processed by all GC worker thread [Ext Root Scanning (ms): 2.2 2.7 2.2 2.6 3.0 3.1 2.2 1.1 2.3 3.0 2.2 2.4 2.9 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^... Elapsed milliseconds for each GC worker thread to process heap roots during an evacuation pause Avg: 2.4, Min: 1.1, Max: 3.1, Diff: 2.0] ^^^^^^^... Summary information for total elapsed milliseconds for all GC worker thread to process heap roots during an evacuation pause [Mark Stack Scanning (ms): 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^... Elapsed milliseconds for each GC worker thread to scan strong roots in the mark stack during an evacuation pause Avg: 0.0, Min: 0.0, Max: 0.0, Diff: 0.0] ^^^^^^^... Summary information for total milliseconds for all GC worker thread to scan strong roots in the mark stack during an evacuation pause [Scan RS (ms): 14.1 14.6 14.5 14.3 14.6 14.2 14.4 14.5 14.0 13.9 14.6 14.5 14.0 ^^^^^^^^^^^^^^^^^^^^^^... Elapsed milliseconds for each GC worker thread to scan for dirty cards in a heap region to update the remembered set Avg: 14.3, Min: 13.9, Max: 14.6, Diff: 0.8] ^^^^^^^^^^^^^... Summary information for total elapsed milliseconds for all GC worker thread to scan for dirty cards in a heap region to update the remembered set [Object Copy (ms): 41.4 39.5 39.4 39.0 39.6 39.5 39.1 41.4 39.0 39.3 39.3 39.8 39.5 ^^^^^^^^^^^^^^^^^^^^^^^^^^... Elapsed milliseconds for each GC worker thread to scan root sets for pointers to include in this heap region's remembered set during an evacuation pause Avg: 39.7, Min: 39.0, Max: 41.4, Diff: 2.4] ^^^^^^^^^^^^^... Summary information for total elapsed milliseconds for all GC worker thread to scan root sets for pointers to include in this heap region's remembered set during an evacuation pause [Termination (ms): 1.3 1.4 1.5 1.6 1.5 1.4 1.6 1.4 1.5 1.7 1.5 1.4 1.3 ^^^^^^^^^^^^^^^^^^^^^^^^^^... Elapsed milliseconds for each GC worker thread to terminate scanning root sets for pointers to include in this heap region's remembered set during an evacuation pause Avg: 1.5, Min: 1.3, Max: 1.7, Diff: 0.4] ^^^^^^^^^^^^^^... Summary information for total elapsed milliseconds for all GC worker thread to terminate scanning root sets for pointers to include in this heap region's remembered set during an evacuation pause [Termination Attempts : 1185 1205 1219 1436 1171 1231 1471 1237 1461 1526 1353 1259 1170 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^... Total attempts for each GC worker thread to terminate scanning root sets for pointers to include in this heap region's remembered set during an evacuation pause Sum: 16924, Avg: 1301, Min: 1170, Max: 1526, Diff: 356] ^^^^^^^^^^^^^^^... Summary information for total attempts for all GC worker thread to terminate scanning root sets for pointers to include in this heap region's remembered set during an evacuation pause [GC Worker End Time (ms): 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2 44900380.3 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^... Elapsed seconds from JVM start that GC worker threads ended Avg: 44900380.2, Min: 44900380.2, Max: 44900380.3, Diff: 0.1] ^^^^^^^^^^^^... Summary information for total elapsed seconds from JVM start that GC worker threads ended for all GC worker threads [GC Worker Times (ms): 82.6 82.6 82.6 82.6 82.6 82.6 82.5 82.6 82.5 82.5 82.5 82.5 82.5 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^... Elapsed milliseconds for each GC worker threads Avg: 82.6, Min: 82.5, Max: 82.6, Diff: 0.1] ^^^^^^^^^^^^^... Summary information for total elapsed milliseconds for all GC worker threads [Other: 1.2 ms] ^^^^^^^^^^^^^^^^^^^^^^^ Other milliseconds during GC parallel processing; basically, total milliseconds minus: update RS, ext root scanning, mark stack scanning, scan RS, object copy, termination [Clear CT: 0.5 ms] ^^^^^^^^^^^^^^^^^^^^^^^ Total milliseconds cleaning up the dirty card tables list [Other: 4.8 ms] ^^^^^^^^^^^^^^^^^^^^ Total milliseconds in this GC pause not spent in parallel and clear CT [Choose CSet: 0.0 ms] ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Total milliseconds to choose young heap regions to add to the collection set [ 1331M->830M(1840M)] ^^^^^ Heap size change for this garbage collector ^^^^^ Total heap size before this collection pause ^^^^ Total heap size after this collection pause ^^^^^ Total heap size capacity for this garbage collector [Times: user=1.07 sys=0.01, real=0.09 secs] ^^^^^^^^ Execution seconds (uses TraceCPUTime class; constructor initializes times to zero, destructor prints times) ^^^^^^^^^^ User execution seconds for all threads ^^^^^^^^^ System execution seconds ^^^^^^^^^^^ Real (wall clock) execution seconds 44901.205: [GC concurrent-mark-end, 0.8186002 sec] ^^^^^^^^^^^ Elapsed seconds from JVM start ^^^^^^^^^^^^^^^^^^^^^^^^ Concurrent mark thread ended ^^^^^^^^^^^^^ Total seconds executing concurrent mark thread 44901.205: [GC remark, 0.0258621 secs] ^^^^^^^^^^^ Elapsed seconds from JVM start ^^^^^^^^^^ Concurrent re-marking of all heap roots, final work [Times: user=0.02 sys=0.00, real=0.03 secs] ^^^^^^^^ Execution seconds (uses TraceCPUTime class; constructor initializes times to zero, destructor prints times) ^^^^^^^^^^ User execution seconds for all threads ^^^^^^^^^ System execution seconds ^^^^^^^^^^^ Real (wall clock) execution seconds 44901.231: [GC concurrent-count-start] ^^^^^^^^^^^ Elapsed seconds from JVM start ^^^^^^^^^^^^^^^^^^^^^^^^^^^ Start concurrent marking of live objects 44901.479: [GC concurrent-count-end, 0.2478477] ^^^^^^^^^^^ Elapsed seconds from JVM start ^^^^^^^^^^^^^^^^^^^^^^^^^^^ End concurrent marking of live objects ^^^^^^^^^^^^ Total seconds to do concurrent marking of live objects 44901.479: [GC cleanup 940M->931M(1840M), 0.0073079 secs] ^^^^^^^^^^^ Elapsed seconds from JVM start ^^^^^^^^^^^ Concurrent marking cleanup (world is stopped at this checkpoint) ^... Heap size change for this garbage collector ^^^^ Total heap size before this operation ^^^^ Total heap size after this operation ^^^^^ Total heap size capacity for this garbage collector ^^^^^^^^^^^^^^ Total seconds executing concurrent marking cleanupOpenJDK 7 G1GC
If you can build a debug copy of OpenJDK 7, you'll have a few more JVM options available to you that will give you even further information about G1GC. Use the following command to get a list of all JVM options:
java -XX:+AggressiveOpts -XX:+UnlockDiagnosticVMOptions -XX:+PrintFlagsFinal -XX:+PrintFlagsWithComments -versionThe output shows the following G1GC options available; this is not an all inclusive list, just some I thought were intersting.
intx G1CardCountCacheExpandThreshold = 16 Expand the card count cache if the number of collisions for a particular entry exceeds this value. uintx G1ConcMarkForceOverflow = 0 The number of times we'll force an overflow during concurrent marking double G1ConcMarkStepDurationMillis = 10.000000 {product} Target duration of individual concurrent marking steps in milliseconds. intx G1ConcRSHotCardLimit = 4 The threshold that defines (>=) a hot card. intx G1ConcRSLogCacheSize = 10 Log base 2 of the length of conc RS hot-card cache. bool G1ConcRegionFreeingVerbose = false Enables verboseness during concurrent region freeing intx G1ConfidencePercent = 50 {product} Confidence level for MMU/pause predictions bool G1DeferredRSUpdate = true If true, use deferred RS updates bool G1FixedEdenSize = false When set, G1 will not allocate unused survivor space regions uintx G1FixedSurvivorSpaceSize = 0 If non-0 is the size of the G1 survivor space, otherwise SurvivorRatio is used to determine the size bool G1FixedTenuringThreshold = false When set, G1 will not adjust the tenuring threshold bool G1Gen = true If true, it will enable the generational G1 uintx G1HeapRegionSize = 0 {product} Size of the G1 regions. intx G1InitYoungSurvRatio = 50 Expected Survival Rate for newly allocated bytes intx G1MarkRegionStackSize = 1048576 {product} Size of the region stack for concurrent marking. intx G1MarkingOverheadPercent = 0 Overhead of concurrent marking intx G1MarkingVerboseLevel = 0 Level (0-4) of verboseness of the marking code intx G1MaxHotCardCountSizePercent = 25 The maximum size of the hot card count cache as a percentage of the number of cards for the maximum heap. intx G1MaxVerifyFailures = -1 The maximum number of verification failrues to print. -1 means print all. intx G1PausesBtwnConcMark = -1 If positive, fixed number of pauses between conc markings intx G1PolicyVerbose = 0 The verbosity level on G1 policy decisions bool G1PrintCTFilterStats = false If true, print stats on RS filtering effectiveness bool G1PrintHeapRegions = false {diagnostic} If set G1 will print information on which regions are being allocated and which are reclaimed. bool G1PrintOopAppls = false When true, print applications of closures to external locs. bool G1PrintParCleanupStats = false When true, print extra stats about parallel cleanup. bool G1PrintReachableAtInitialMark = false Reachable object dump at the initial mark pause ccstr G1PrintReachableBaseFile = The base file name for the reachable object dumps bool G1PrintRegionLivenessInfo = false {product} Prints the liveness information for all regions in the heap at the end of a marking cycle. bool G1RSCountHisto = false If true, print a histogram of RS occupancies after each pause bool G1RSLogCheckCardTable = false If true, verify that no dirty cards remain after RS log processing. bool G1RSScrubVerbose = false When true, do RS scrubbing with verbose output. intx G1RSetRegionEntries = 0 {product} Max number of regions for which we keep bitmaps.Will be set ergonomically by default intx G1RSetRegionEntriesBase = 256 Max number of regions in a fine-grain table per MB. uintx G1RSetScanBlockSize = 64 {product} Size of a work unit of cards claimed by a worker threadduring RSet scanning. intx G1RSetSparseRegionEntries = 0 {product} Max number of entries per region in a sparse table.Will be set ergonomically by default. intx G1RSetSparseRegionEntriesBase = 4 Max number of entries per region in a sparse table per MB. intx G1RSetUpdatingPauseTimePercent = 10 {product} A target percentage of time that is allowed to be spend on process RS update buffers during the collection pause. bool G1RecordHRRSEvents = false When true, record recent calls to rem set operations. bool G1RecordHRRSOops = false When true, record recent calls to rem set operations. intx G1RefProcDrainInterval = 10 {product} The number of discovered reference objects to process before draining concurrent marking work queues. intx G1ReservePercent = 10 {product} It determines the minimum reserve we should have in the heap to minimize the probability of promotion failure. uintx G1SATBBufferEnqueueingThresholdPercent = 60 {product} Before enqueueing them, each mutator thread tries to do some filtering on the SATB buffers it generates. If post-filtering the percentage of retained entries is over this threshold the buffer will be enqueued for processing. A value of 0 specifies that mutator threads should not do such filtering. intx G1SATBBufferSize = 1024 {product} Number of entries in an SATB log buffer. bool G1SATBPrintStubs = false If true, print generated stubs for the SATB barrier intx G1SATBProcessCompletedThreshold = 20 Number of completed buffers that triggers log processing. bool G1ScrubRemSets = true When true, do RS scrubbing after cleanup. uintx G1SecondaryFreeListAppendLength = 5 The number of regions we will add to the secondary free list at every append operation bool G1StressConcRegionFreeing = false It stresses the concurrent region freeing operation uintx G1StressConcRegionFreeingDelayMillis = 0 Artificial delay during concurrent region freeing bool G1SummarizeConcMark = false {diagnostic} Summarize concurrent mark info bool G1SummarizeRSetStats = false {diagnostic} Summarize remembered set processing info intx G1SummarizeRSetStatsPeriod = 0 {diagnostic} The period (in number of GCs) at which we will generate update buffer processing info (0 means do not periodically generate this info); it also requires -XX:+G1SummarizeRSetStats bool G1TraceConcRefinement = false {diagnostic} Trace G1 concurrent refinement bool G1TraceMarkStackOverflow = false If true, extra debugging code for CM restart for ovflw. intx G1UpdateBufferSize = 256 {product} Size of an update buffer bool G1VerifyDuringGCPrintReachable = false If conc mark verification fails, dump reachable objects intx G1YoungSurvRateNumRegionsSummary = 0 the number of regions for which we'll print a surv rate summary. bool G1YoungSurvRateVerbose = false print out the survival rate of young regions according to age.To see what kind of G1GC information is provided using the OpenJDK 7 debug build, I used the following test program:
import java.lang.ref.WeakReference; import java.util.ArrayList; import java.util.Iterator; import java.util.List; import java.util.Random; public class G1GCTest implements Runnable { private int iterations = 0; private final Random rnd = new Random(); private final List<Object> young = new ArrayList<Object>(1000); private final List<WeakReference<Object>> old = new ArrayList<WeakReference<Object>>(100000); private void clearOld() { int clearedCnt = 0; for (final Iterator<WeakReference<Object>> iter = old.iterator(); iter .hasNext();) { final WeakReference<Object> ref = iter.next(); if (null == ref.get()) { iter.remove(); clearedCnt++; } } if (0 < clearedCnt) { System.out.println("Cleared " + clearedCnt + " weak references to old objects."); } } public void run() { if (0 == ++iterations % 10000) { System.out.println("iterations=" + iterations + ", young.size()=" + young.size() + ", old.size()=" + old.size()); clearOld(); try { Thread.sleep(100); } catch (final Throwable e) { // Do nothing! } } if (rnd.nextBoolean()) { young.add(new byte[1000]); } if (rnd.nextBoolean() && !young.isEmpty()) { final int nextInt = Math.abs(rnd.nextInt()); final int idx = nextInt % young.size(); final Object obj = young.remove(idx); old.add(new WeakReference<Object>(obj)); } } public static void main(final String[] args) { final G1GCTest t = new G1GCTest(); while (1000000 > t.iterations) { t.run(); } } }And executed it using:
java -Xms8m -Xmx8m -XX:+UnlockExperimentalVMOptions -XX:+UseG1GC -XX:+PrintGC -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -XX:+G1SummarizeConcMark -XX:+G1SummarizeRSetStats -XX:+G1YoungSurvRateVerbose -XX:G1PolicyVerbose=2 -verbose:gc G1GCTestThe output of which was very verbose, but provides a slew of information that could prove useful if you're doing some GC tuning.
这篇关于有人可以理解G1垃圾收集器的输出吗？的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！
查看全文
