Where have the Full GCs gone?

[Y Srinivas Ramakrishna]

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
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use at openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use