我有这样的代码，很简单：
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。