Two basic questions on -verbosegc and -XX:+PrintTenuringDistribution

[Alexey Ragozin]

Hi,

If you need this information for monitoring, you can get it with JMX.
Some time ago I have written tool displaying GC metrics (similar to GC
log). It is using attach API and JMX to get data from JVM.

It is available at
http://code.google.com/p/gridkit/downloads/detail?name=gcrep.jar
Usage: java -jar gcrep.jar <PID>

But you probably will be more interested in sources, you can find them here
http://code.google.com/p/gridkit/source/browse/branches/aragozin-sandbox/young-gc-bench/src/main/java/org/gridkit/util/monitoring/MBeanGCMonitor.java?spec=svn1461&r=1461

Regards,
Alexey

> Date: Sun, 22 Apr 2012 22:24:31 +0200
> From: Taras Tielkes <taras.tielkes at gmail.com>
> Subject: Two basic questions on -verbosegc and
>        -XX:+PrintTenuringDistribution
> To: hotspot-gc-use at openjdk.java.net
> Message-ID:
>        <CA+R7V78bTOkvaYgwNCPC2MfiqdV-QBtOidz3nUXjb9bwZ5FrNg at mail.gmail.com>
> Content-Type: text/plain; charset=ISO-8859-1
>
> Hi,
>
> We're using a time-series database to store and aggregate monitoring
> data from our systems, including GC behavior.
>
> I'm thinking of adding two metrics:
> * total allocation (in K per minute)
> * total promotion (in K per minute)
>
> The gc logs are the source for this data, and I'd like to verify that
> my understanding of the numbers is correct.
>
> Here's an example verbosegc line of output (we're running ParNew+CMS):
> [GC 2136581.585: [ParNew:345951K->40960K(368640K), 0.0676780 secs]
> 3608692K->3323692K(5201920K), 0.0680220 secs]
>
> a) The delta between the ParNew "before" and "after" is: 345951K-40960K=304991K
> My understanding is that the 304991K is the total of (collected in
> young gen + promoted to tenured gen)
> Since this number of composed of two things, it's not directly useful by itself.
>
> b) The delta between the overall heap "before" and "after" is:
> 3608692K-3323692K=285000K
> I assume that this is effectively the volume that was collected in
> this ParNew cycle.
> Would it be correct to calculate the total allocation rate of the
> running application (in a given period) from summing the total heap
> deltas (in a given timespan)?
>
> I do realize that it's a "collected kilobytes" metric, but I think
> it's close enough to be used as a "delayed" allocation number,
> especially when looking at a timescale of 10 minutes or more.
> It has the additional convenience of requiring to parse the current
> gc.log line only, and not needing to correlate with the preceding
> ParNew event.
>
> c) I take it that the difference between the two deltas (ParNew delta
> and total heap delta) is effectively the promotion volume?
> In the example above, this would give a promotion volume of
> (345951K-40960K)-(3608692K-3323692K)=19991K
>
> d) When looking at -XX:+PrintTenuringDistribution output, I assume the
> distribution reflects the situation *after* the enclosing ParNew event
> in the log.
>
> Thanks in advance for any corrections,
> -tt