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

Question

我有一个这样的代码，它非常简单：

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((方法引起的ParNewgc。

Answer 1

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

您也可以尝试通过设置-XX:+DisableExplicitGC标志。比较两次运行之间的日志。