随笔 - 41  文章 - 29  trackbacks - 0
<2009年3月>
22232425262728
1234567
891011121314
15161718192021
22232425262728
2930311234

常用链接

留言簿(5)

随笔分类(28)

随笔档案(23)

收藏夹(6)

Inside JVM

Java

java performance

Solr

搜索

  •  

最新评论

阅读排行榜

评论排行榜

This article is trying to summarize what' the JVM GC log and how can we use it to analyse memory issues.

1. How To Generate Sun JVM GC Log

Generally, -Xloggc:d:\gc.log -XX:+PrintGCDetails is enough. Please see following details. And for the full list, please see from http://www.tagtraum.com/gcviewer-vmflags.html#sun.verbose
-verbose:gc
Prints out information about garbage collections to standard out. To print the same information to a file, use -Xloggc:<file>
Example:
[GC 325407K->83000K(776768K), 0.2300771 secs]
[GC 325816K->83372K(776768K), 0.2454258 secs]
[Full GC 267628K->83769K(776768K), 1.8479984 secs]

See -Xloggc
Supported by: 1.3, 1.4, 1.5

-Xloggc:<file>
Prints information about garbage collections to the specified file.
In conjunction with -XX:+PrintGCDetails this is the best setting for the free GCViewer.
Supported by: 1.4, 1.5

-XX:+PrintGCDetails
Instructs the VM to be more verbose when printing out garbage collecion data. Specifically it does not only tell you that there was a collection, but also what impact it had on the different generations.
This flag is very useful when tuning generation sizes.
In conjunction with -Xloggc this is the best setting for the free GCViewer.
Example:
2.459: [GC 2.459: [DefNew: 3967K->0K(4032K), 0.0141600 secs] 8559K->7454K(16320K), 0.0143588 secs]
Supported by: 1.4, 1.5

2. How To Read GC Log


-verbose:gc prints information at every collection
  [GC 325407K                      -> 83000K                     (776768K),                                            0.2300771 secs]   
   [ GC  the combined size of live objects before GC  ->  the combined size of live objects after GC  (the total available space, not counting the space in the permanent generation),  pause time]          
  [GC 325816K->83372K(776768K), 0.2454258 secs]
  [Full GC 267628K->83769K(776768K), 1.8479984 secs]

-XX:+PrintGCDetails for the J2SE Platform version 1.5 
[GC [DefNew:                  64575K
    ->   959K              (64576K),                                    0.0457646 secs]  196016K                         ->                133633K            (261184K),       0.0459067 secs]]
[GC [
young generation:before GC -> after GC (available young generation heap),  pause time ]   entrie heap before GC -> entire heap after GC, (available heap),     pause time                 ]]

[GC [<collector>: <starting occupancy1> -> <ending occupancy1>, <pause time1> secs] <starting occupancy3> -> <ending occupancy3>, <pause time3> secs]

where

<collector> is an internal name for the collector used in the minor collection

<starting occupancy1> is the occupancy of the young generation before the collection

<ending occupancy1> is the occupancy of the young generation after the collection

<pause time1> is the pause time in seconds for the minor collection.

<starting occupancy3> is the occupancy of the entire heap before the collection

<ending occupancy3> is the occupancy of the entire heap after the collection

<pause time3> is the pause time for the entire garbage collection. This would include the time for a major collection is one was done.




Another way is to use GCViewer
GCViewer is a free open source tool to visualize data produced by the Java VM options 
-verbose:gc and -Xloggc<file>. It also calculates garbage collection related performance metrics
(throughput, accumulated pauses, longest pause, etc.). This can be very useful when tuning the garbage collection of a particular application by changing generation sizes or setting the initial heap size.
See here 
for a useful summary of garbage collection related JVM parameters.

3. How To Use GC Log

 Generally, you can see three signals
(1)  the memory collected by young generation == the memory collected by entire heap? such as 64575K-959K=63616K, and 196016K - 133633K = 62383K, which means 63616K - 62383K =1233K memory moved from yougn generation to tenured section. If every GC will cause this operation, the memory is slowly leaking.
(2) the trace of memory collected by GC? does it become smaller and smaller, which mean more and more memory cannot be collected. It is a very obvious sign of memory leak.
(3) does the pause time is longer and longer? >1s is a obvious sign.

From another side, the GC View provides a very good trace which is easier to be analysed.

posted on 2009-03-19 22:27 Justin Chen 阅读(8487) 评论(2)  编辑  收藏 所属分类: Inside JVM

FeedBack:
# re: Inside JVM - GC(Garbage collection) Log and Analysis[未登录] 2009-02-13 08:12 duduli
GC 有三种机制。
怎样优化GC呢?


ps:my english is so poor.  回复  更多评论
  
# re: GC(Garbage collection) Log and Analysis - 2 of Series "Inside JVM"  2015-09-04 17:59 Performance Expert
For free gc log analysis, send the log file to performancetestexpert@gmail.com  回复  更多评论
  

只有注册用户登录后才能发表评论。


网站导航: