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創建遠程連接即可進行遠程監控。

轉載于:https://blog.51cto.com/10988776/1746097

總結

以上是生活随笔為你收集整理的老李分享：《Java Performance》笔记2——JVM命令行选项及垃圾收集日志解析 2的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。