时间戳

首页 > 解决方案 > 这是由方法 System.gc() 引起的 CMS gc 吗？

java - 这是由方法 System.gc() 引起的 CMS gc 吗？

问题描述

我有这样的代码，很简单：

public class Main {

    public static void main(String[] args) throws Exception {
        Thread.sleep(5000);
        System.gc();
    }

}

这是我的 JVM 选项：

-XX:+ExplicitGCInvokesConcurrent -XX:+PrintPromotionFailure -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCDateStamps -XX:+PrintGCDetails -server -XX:NewRatio=1 -XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=75 -XX:+UseConcMarkSweepGC -Xloggc:/Users/roger/gc.log -Xms2G -Xmx2G -Xss512k

我可以在路径 dir /Users/roger 中获取 gc 日志文件，并且 gc.log 内容如下：

Java HotSpot(TM) 64-Bit Server VM (25.181-b13) for bsd-amd64 JRE (1.8.0_181-b13), built on Jul 7 2018 01:02:31 by "java_re" with gcc 4.2.1 (Based on Apple Inc. build 5658) (LLVM build 2336.11.00) Memory: 4k page, physical 8388608k(258072k free)

/proc/meminfo:

CommandLine flags: -XX:CMSInitiatingOccupancyFraction=75 -XX:+ExplicitGCInvokesConcurrent -XX:InitialHeapSize=2147483648 -XX:MaxHeapSize=2147483648 -XX:MaxTenuringThreshold=6 -XX:NewRatio=1 -XX:OldPLABSize=16 -XX:+PrintGC -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintPromotionFailure -XX:ThreadStackSize=512 -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseParNewGC 2018-11-03T01:26:37.136-0800: 0.245: Total time for which application threads were stopped: 0.0000852 seconds, Stopping threads took: 0.0000282 seconds 2018-11-03T01:26:37.136-0800: 0.245: Total time for which application threads were stopped: 0.0000434 seconds, Stopping threads took: 0.0000213 seconds 2018-11-03T01:26:37.136-0800: 0.245: Total time for which application threads were stopped: 0.0000500 seconds, Stopping threads took: 0.0000072 seconds 2018-11-03T01:26:38.138-0800: 1.247: Total time for which application threads were stopped: 0.0000811 seconds, Stopping threads took: 0.0000215 seconds 2018-11-03T01:26:41.441-0800: 4.550: Total time for which application threads were stopped: 0.0000860 seconds, Stopping threads took: 0.0000173 seconds 2018-11-03T01:26:42.419-0800: 5.527: [GC (System.gc()) 2018-11-03T01:26:42.419-0800: 5.527: [ParNew: 33556K->536K(943744K), 0.0049418 secs] 33556K->536K(1992320K), 0.0051371 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 2018-11-03T01:26:42.424-0800: 5.533: Total time for which application threads were stopped: 0.0052935 seconds, Stopping threads took: 0.0000191 seconds 2018-11-03T01:26:42.424-0800: 5.533: [GC (CMS Initial Mark) [1 CMS-initial-mark: 0K(1048576K)] 536K(1992320K), 0.0003129 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2018-11-03T01:26:42.424-0800: 5.533: Total time for which application threads were stopped: 0.0003991 seconds, Stopping threads took: 0.0000239 seconds 2018-11-03T01:26:42.424-0800: 5.533: [CMS-concurrent-mark-start] 2018-11-03T01:26:42.438-0800: 5.547: [CMS-concurrent-mark: 0.014/0.014 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 2018-11-03T01:26:42.438-0800: 5.547: [CMS-concurrent-preclean-start] 2018-11-03T01:26:42.440-0800: 5.548: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 2018-11-03T01:26:42.440-0800: 5.548: [GC (CMS Final Remark) [YG occupancy: 536 K (943744 K)]2018-11-03T01:26:42.440-0800: 5.548: [Rescan (parallel) , 0.0010829 secs]2018-11-03T01:26:42.441-0800: 5.550: [weak refs processing, 0.0000814 secs]2018-11-03T01:26:42.441-0800: 5.550: [class unloading, 0.0002646 secs]2018-11-03T01:26:42.441-0800: 5.550: [scrub symbol table, 0.0003364 secs]2018-11-03T01:26:42.442-0800: 5.550: [scrub string table, 0.0001618 secs][1 CMS-remark: 0K(1048576K)] 536K(1992320K), 0.0020665 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 2018-11-03T01:26:42.442-0800: 5.551: Total time for which application threads were stopped: 0.0021350 seconds, Stopping threads took: 0.0000122 seconds 2018-11-03T01:26:42.442-0800: 5.551: [CMS-concurrent-sweep-start] 2018-11-03T01:26:42.442-0800: 5.551: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2018-11-03T01:26:42.442-0800: 5.551: [CMS-concurrent-reset-start] Heap par new generation total 943744K, used 8926K [0x0000000740000000, 0x0000000780000000, 0x0000000780000000) eden space 838912K, 1% used [0x0000000740000000, 0x00000007408315f0, 0x0000000773340000) from space 104832K, 0% used [0x00000007799a0000, 0x0000000779a263b0, 0x0000000780000000) to space 104832K, 0% used [0x0000000773340000, 0x0000000773340000, 0x00000007799a0000) concurrent mark-sweep generation total 1048576K, used 0K [0x0000000780000000, 0x00000007c0000000, 0x00000007c0000000) Metaspace used 3157K, capacity 4568K, committed 4864K, reserved 1056768K class space used 338K, capacity 392K, committed 512K, reserved 1048576K

我们可以在 gc 日志文件中看到一个 CMS gc。CMS gc 是由调用方法 System.gc() 引起的吗？以及如何在 gc 日志中知道这一点？我们只能在 gc 日志中看到由 System.gc() 方法引起的 ParNew gc。

标签： javagarbage-collectionconcurrent-mark-sweep

解决方案

是的，您的日志显示了这一点。但请记住，调用 System.gc() 并不能保证 GC 运行。这是对 JVM 的提示。

您还可以尝试通过设置 -XX:+DisableExplicitGC 标志来验证这一点。比较两次运行之间的日志。

推荐阅读