Where have the Full GCs gone?
Moazam Raja
moazam at apple.com
Tue Nov 4 15:26:14 PST 2008
Ramki, thanks!
Do you know if there is a tool which I can feed this GC log into and
get some graphs?
-Moazam
On Nov 4, 2008, at 2:49 PM, Y Srinivas Ramakrishna wrote:
> Hi Moazam --
>
> With the CMS collector, look for GC lines tagged with the
> string "CMS". Those indicate CMS collection activity.
> Please refer to the GC tuning guide (under "low pause collector,"
> for sample output.
>
> There may also be full stop-world collections because of,
> for example, promotion failure, which may not be explicitly called
> out as a scavenge bails to a full collection. In those cases,
> look for the string "fail".
>
> In more recent JVM's in addition to the "gc invocations" count
> (which you see in yr +PrintHeapAtGC output below), you will also
> see "full = ..." counts which will tell you the number of major
> cycles that happened.
>
> If you have jstat on OS X, then jstat -gc would also give you
> FGC and FGCT which are respectively the number of and time spent
> in major gc cycles (these counters however are if i recall correctly
> somewhat misleading in the case of CMS).
>
> -- ramki
>
> ----- Original Message -----
> From: Moazam Raja <moazam at apple.com>
> Date: Tuesday, November 4, 2008 2:41 pm
> Subject: Where have the Full GCs gone?
> To: hotspot-gc-use at openjdk.java.net
>
>
>> Hi all, I'm running a test and recording GC information on a Tomcat
>> application and have noticed that even after a few days, there are no
>>
>> 'Full GC' markers. Am I reading the log incorrectly, or are the Full
>>
>> GCs getting logged elsewhere?
>>
>> I'm using Java 1.5.0_13 on OS X with the following flags,
>>
>> -Xms=2048m -Xmx=2048m
>> -server -XX:+UseConcMarkSweepGC
>> -Xloggc:/var/tmp/GC.log
>> -verbose:gc
>> -XX:+PrintGCDetails
>> -XX:+PrintHeapAtGC
>> -XX:+PrintClassHistogram
>> -XX:+PrintGCApplicationConcurrentTime
>>
>>
>> A sample of the output from my GC log:
>>
>>
>> Application time: 1.4105823 seconds
>> 82558.187: [GC {Heap before gc invocations=111716:
>> par new generation total 21184K, used 21120K [0x0000000107270000,
>>
>> 0x0000000108730000, 0x0000000108730000)
>> eden space 21120K, 100% used [0x0000000107270000,
>> 0x0000000108710000, 0x0000000108710000)
>> from space 64K, 0% used [0x0000000108710000, 0x0000000108710000,
>>
>> 0x0000000108720000)
>> to space 64K, 0% used [0x0000000108720000, 0x0000000108720000,
>>
>> 0x0000000108730000)
>> concurrent mark-sweep generation total 20950272K, used 5483440K
>> [0x0000000108730000, 0x0000000607270000, 0x0000000607270000)
>> concurrent-mark-sweep perm gen total 39296K, used 23575K
>> [0x0000000607270000, 0x00000006098d0000, 0x000000060c670000)
>> 82558.187: [ParNew: 21120K->0K(21184K), 0.0669633 secs] 5504560K-
>>> 5487545K(20971456K)Heap after gc invocations=111717:
>> par new generation total 21184K, used 0K [0x0000000107270000,
>> 0x0000000108730000, 0x0000000108730000)
>> eden space 21120K, 0% used [0x0000000107270000,
>> 0x0000000107270000, 0x0000000108710000)
>> from space 64K, 0% used [0x0000000108720000, 0x0000000108720000,
>>
>> 0x0000000108730000)
>> to space 64K, 0% used [0x0000000108710000, 0x0000000108710000,
>>
>> 0x0000000108720000)
>> concurrent mark-sweep generation total 20950272K, used 5487545K
>> [0x0000000108730000, 0x0000000607270000, 0x0000000607270000)
>> concurrent-mark-sweep perm gen total 39296K, used 23575K
>> [0x0000000607270000, 0x00000006098d0000, 0x000000060c670000)
>> }
>> , 0.0672098 secs]
>>
>> Application time: 0.4661567 seconds
>> 82558.721: [GC {Heap before gc invocations=111717:
>> par new generation total 21184K, used 21120K [0x0000000107270000,
>>
>> 0x0000000108730000, 0x0000000108730000)
>> eden space 21120K, 100% used [0x0000000107270000,
>> 0x0000000108710000, 0x0000000108710000)
>> from space 64K, 0% used [0x0000000108720000, 0x0000000108720000,
>>
>> 0x0000000108730000)
>> to space 64K, 0% used [0x0000000108710000, 0x0000000108710000,
>>
>> 0x0000000108720000)
>> concurrent mark-sweep generation total 20950272K, used 5487545K
>> [0x0000000108730000, 0x0000000607270000, 0x0000000607270000)
>> concurrent-mark-sweep perm gen total 39296K, used 23575K
>> [0x0000000607270000, 0x00000006098d0000, 0x000000060c670000)
>> 82558.721: [ParNew: 21120K->0K(21184K), 0.0591967 secs] 5508665K-
>>> 5491650K(20971456K)Heap after gc invocations=111718:
>> par new generation total 21184K, used 0K [0x0000000107270000,
>> 0x0000000108730000, 0x0000000108730000)
>> eden space 21120K, 0% used [0x0000000107270000,
>> 0x0000000107270000, 0x0000000108710000)
>> from space 64K, 0% used [0x0000000108710000, 0x0000000108710000,
>>
>> 0x0000000108720000)
>> to space 64K, 0% used [0x0000000108720000, 0x0000000108720000,
>>
>> 0x0000000108730000)
>> concurrent mark-sweep generation total 20950272K, used 5491650K
>> [0x0000000108730000, 0x0000000607270000, 0x0000000607270000)
>> concurrent-mark-sweep perm gen total 39296K, used 23575K
>> [0x0000000607270000, 0x00000006098d0000, 0x000000060c670000)
>> }
>> , 0.0594283 secs]
>>
>> Application time: 0.0590593 seconds
>> 82558.840: [GC {Heap before gc invocations=111718:
>> par new generation total 21184K, used 21120K [0x0000000107270000,
>>
>> 0x0000000108730000, 0x0000000108730000)
>> eden space 21120K, 100% used [0x0000000107270000,
>> 0x0000000108710000, 0x0000000108710000)
>> from space 64K, 0% used [0x0000000108710000, 0x0000000108710000,
>>
>> 0x0000000108720000)
>> to space 64K, 0% used [0x0000000108720000, 0x0000000108720000,
>>
>> 0x0000000108730000)
>> concurrent mark-sweep generation total 20950272K, used 5491650K
>> [0x0000000108730000, 0x0000000607270000, 0x0000000607270000)
>> concurrent-mark-sweep perm gen total 39296K, used 23575K
>> [0x0000000607270000, 0x00000006098d0000, 0x000000060c670000)
>> 82558.840: [ParNew: 21120K->0K(21184K), 0.0589090 secs] 5512770K-
>>> 5496450K(20971456K)Heap after gc invocations=111719:
>> par new generation total 21184K, used 0K [0x0000000107270000,
>> 0x0000000108730000, 0x0000000108730000)
>> eden space 21120K, 0% used [0x0000000107270000,
>> 0x0000000107270000, 0x0000000108710000)
>> from space 64K, 0% used [0x0000000108720000, 0x0000000108720000,
>>
>> 0x0000000108730000)
>> to space 64K, 0% used [0x0000000108710000, 0x0000000108710000,
>>
>> 0x0000000108720000)
>> concurrent mark-sweep generation total 20950272K, used 5496450K
>> [0x0000000108730000, 0x0000000607270000, 0x0000000607270000)
>> concurrent-mark-sweep perm gen total 39296K, used 23575K
>> [0x0000000607270000, 0x00000006098d0000, 0x000000060c670000)
>> }
>> , 0.0592058 secs]
>>
>>
>> -Moazam
>>
>> _______________________________________________
>> hotspot-gc-use mailing list
>> hotspot-gc-use at openjdk.java.net
>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
More information about the hotspot-gc-use
mailing list