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 閱讀(8508)
評論(2) 編輯 收藏 所屬分類:
Inside JVM