5.CMS垃圾收集器输出日志详解：

使用CMS垃圾收集器(JVM命令行选项：-XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -verbose:gc)，垃圾收集器输出日志格式化如下：

(1).Minor GC日志详解：

[GC

[ParNew: 14784K->1600K(14784K), 0.0184961 secs]

38262K->31810K(63936K), 0.0185291 secs]

[Times: user=0.06 sys=0.00, real=0.00 secs]

A. 标签GC表明这是Minor GC的日志输出。

B. 第2行ParNew: 14784K->1600K(14784K)是新生代信息，如果使用CMS并发垃圾收集器，新生代会自动使用多线程的垃圾收集器ParNew(使用-XX:+UseParNewGC开启)，ParNew表示为了配合CMS垃圾收集器在新生代使用的是多线程垃圾胡搜机器ParNew，如果配合CMS使用的是串行垃圾收集器，这里的标签则为DefNew。”->”左边的14784K是垃圾收集前新生代占用量，”->”右边的1600K是垃圾收集后新生代占用量即Survivor的占用量，括号中的14784K是新生代大小。

C. 第3行38262K->31810K(63936K)是垃圾收集前后java堆的占用量和java堆的大小，与前面的Throughput中的含义相同。

D. 第4行是垃圾收集CPU使用时间，与之前Throughput中的含义相同。

(2).Full GC日志详解：

[GC

[1 CMS-initial-mark: 30210K(49152K)] 31810K(63936K), 0.0015854 secs]

[Times: user=0.00 sys=0.00, real=0.00 secs]

[CMS-concurrent-mark: 0.098/0.098 secs]

[Times: user=0.36 sys=0.00, real=0.11 secs]

[CMS-concurrent-preclean: 0.001/0.001 secs]

[Times: user=0.00 sys=0.00, real=0.00 secs]

[GC

[YG occupancy: 2116 K (14784 K)]

[Rescan (parallel) , 0.0005306 secs]

[weak refs processing, 0.0000034 secs]

[1 CMS-remark: 30210K(49152K)] 32326K(63936K), 0.0005675 secs]

[Times: user=0.00 sys=0.00, real=0.00 secs]

[CMS-concurrent-sweep: 0.021/0.021 secs]

[Times: user=0.13 sys=0.00, real=0.03 secs]

[CMS-concurrent-reset: 0.000/0.000 secs]

[Times: user=0.00 sys=0.00, real=0.00 secs]

A.第2行[1 CMS-initial-mark: 30210K(49152K)] 31810K(63936K)是CMS初始标记阶段，30210K是垃圾收集前老年代占用量，49152K老年代大小，31810K是垃圾收集前堆占用，括号中的63936K是java堆大小。

B.第4行CMS-concurrent-mark是CMS并发标记阶段。

C.第6行CMS-concurrent-preclean是CMS的并发预清除阶段。

D.第12行1 CMS-remark: 30210K(49152K)] 32326K(63936K)是CMS的重新标记阶段，30210K是垃圾收集前老年代占用量，49152K老年代大小，32326K是垃圾收集前堆占用，括号中的63936K是java堆大小。

E.第14行CMS-concurrent-sweep是CMS的并发清除阶段。

F.第16行CMS-concurrent-reset是CMS最后阶段，为下一轮并发收集周期做准备。

CMS垃圾收集周期中堆减少量，需要通过CMS开始和结束的Minor GC来观察。

6.包含时间戳的垃圾收集日志：

还是以Throughput为例，说明两种包含时间戳的垃圾收集日志：

(1).输出自JVM启动以来到垃圾收集之间流逝的秒数：

使用-XX:+PrintGCTimeStamps结合-XX:+PrintGCDetails 的JVM命令行选项，可以在垃圾收集日志中输出自JVM启动以来到垃圾收集之间流逝的秒数，垃圾收集日志如下：

0.479: [GC

[PSYoungGen: 8959K->640K(8960K)] 12468K->8096K(19904K), 0.0081423 secs]

[Times: user=0.03 sys=0.00, real=0.01 secs]

0.487: [Full GC

[PSYoungGen: 640K->0K(8960K)]

[PSOldGen: 7456K->8094K(17088K)] 8096K->8094K(26048K)

[PSPermGen: 2148K->2148K(12288K)], 0.0154271 secs]

[Times: user=0.02 sys=0.00, real=0.02 secs]

(2).输出符合ISO8601标准的时间戳：
使用-XX:+PrintGCDateStamps结合-XX:+PrintGCDetails的JVM命令行选项，可以在垃圾收集日志中输出形如YYYY-MM-DD-T-HH-MM-SS.mmm-TZ的时间戳，垃圾收集日志如下：

2015-05-13T14:51:04.781+0800: [GC

[PSYoungGen: 8950K->640K(8960K)]

12472K->8100K(19904K), 0.0075851 secs]

[Times: user=0.06 sys=0.00, real=0.01 secs]

2015-05-13T14:51:04.796+0800: [Full GC

[PSYoungGen: 640K->0K(8960K)]

[PSOldGen: 7460K->8097K(17920K)] 8100K->8097K(26880K)

[PSPermGen: 2148K->2148K(12288K)], 0.0151887 secs]

[Times: user=0.01 sys=0.00, real=0.02 secs]

使用时间戳可以计算Minor GC和Full GC的时间持续时间和频率，并推测它们的预期及进行垃圾收集器调优。

7.将垃圾收集日志保存到文件中：

使用-Xloggc:<filename>的JVM命令行选项，可以将垃圾收集的统计数据直接输出到文件(<filename>是保存的文件名)，以便离线分析。结合-Xloggc:<filename>和 -XX:+PrintGCDetails的JVM命令行选项，即使不使用-XX:+PrintGCTimeStamps选项，日志中也会自动添加时间戳，垃圾收集日志如下：

0.266: [GC

[PSYoungGen: 14464K->640K(17280K)]

25830K->18558K(35456K), 0.0129438 secs]

[Times: user=0.00 sys=0.02, real=0.02 secs]

0.279: [Full GC

[PSYoungGen: 640K->379K(17280K)]

[PSOldGen: 17918K->18175K(32896K)]

18558K->18555K(50176K)

[PSPermGen: 2148K->2148K(12288K)], 0.0332880 secs]

[Times: user=0.03 sys=0.00, real=0.03 secs]

垃圾收集日志文件可以使用GCHisto(可以从http://java.net/projects/gchisto下载)读取分析。

8.垃圾收集日志报告应用停止时间和应用并发时间：

通过使用-XX:+PrintGCApplicationConcurrentTime和-XX:+PrintGCApplicationStoppedTime的JVM命令行选项，同时结合-XX:+PrintGCDetails可以报告应用在安全点操作之间的运行时间，以及阻塞java线程的时间，日志格式如下：

Application time: 0.0296541 seconds

[GC

[PSYoungGen: 4160K->638K(4800K)]

4160K->2216K(15744K), 0.0053580 secs]

[Times: user=0.00 sys=0.00, real=0.00 secs]

Total time for which application threads were stopped: 0.0054412 seconds

Application time: 0.0113375 seconds

[GC

[PSYoungGen: 4798K->638K(8960K)]

6376K->4156K(19904K), 0.0066910 secs]

[Times: user=0.00 sys=0.00, real=0.00 secs]

Total time for which application threads were stopped: 0.0068062 seconds

通过观察安全点操作，有助于理解和量化延迟对JVM的影响，也可以用来辨别是JVM安全点操作还是应用程序引入的延迟。

9.显示垃圾收集：

System.gc()调用引起的显示垃圾收集会在垃圾收集的日志输出中有(System)标记，例子如下：

[Full GC (System)

[PSYoungGen: 0K->0K(4800K)]

[PSOldGen: 151K->151K(10944K)]

151K->151K(15744K)

[PSPermGen: 2138K->2138K(12288K)], 0.0032678 secs]

[Times: user=0.02 sys=0.00, real=0.02 secs]

如果发现垃圾收集是显示调用引起的，可以调查原因，然后决定是从源码中移除System.gc()调用，或是通过-XX:+DisableExplicitGC禁止显示垃圾收集。

10.VisualVM远程连接监控：

(1).使用jstatd远程监控：

VisualVM远程连接监控时，必须在远程系统运行后台程序jstatd，jstatd虽然JDK5和JDK6发布，但是不包括在Java5或Java6的JRE中。

jstatd会启动Java RMI服务器，监控HotSpot VM的创建和终止，并为远程监控工具如VisualVM提供关联和监控远程java应用的接口。运行jstatd必须和运行被监控的java应用具有相同的用户凭证，因此必须部署安全管理器和安全策略文件，安全策略文件例子如下：

grant codebase “file:${java.home}/../lib/tools.jar” {

permission java.security.AllPermission;

};

假定上述的安全策略文件被保存为名叫jstatd.policy的文件，则可以使用如下的命令启用该策略并启动jstatd：

jstatd -J-Djava.security.policy=<path to policy file>/jstatd.policy

当远程系统运行jstatd后，可以在本地系统运行jps加远程主机名，验证能否关联远程的jstatd(jps不带主机名参数，列出本地能被监控的应用，如果带主机名参数，返回远程可被监控的java应用)，例如远程主机名叫testromete，则例如：

$ jps testremote

2622 jstatd

jps返回jstatd，则说明远程系统上的jstatd已经配置成功，启动VisualVM创建远程连接即可进行远程监控。