How to Measure Promotion Rate

One of the ways you can measure the promotion rate is to turn on GC logging by specifying -XX:+PrintGCDetails-XX:+PrintGCTimeStamps flags for the JVM. The JVM now starts logging the GC pauses just like in the following snippet:

From the above we can extract the size of the young Generation and the total heap both before and after the collection event. Knowing the consumption of the young generation and the total heap, it is easy to calculate the consumption of the old generation as just the delta between the two. Expressing the information in GC logs as:

Event

Time

Young decreased

Total decreased

Promoted

Promotion rate

1st GC

291ms

28,192K

8,920K

19,272K

66.2 MB/sec

2nd GC

446ms

33,248K

11,400K

21,848K

140.95 MB/sec

3rd GC

829ms

66,560K

30,888K

35,672K

93.14 MB/sec

Total

829ms

76,792K

92.63 MB/sec

will allow us to extract the promotion rate for the measured period. We can see that on average the promotion rate was 92 MB/sec, peaking at 140.95 MB/sec for a while.

Notice that you can extract this information only from minor GC pauses. Full GC pauses do not expose the promotion rate as the change in the old generation usage in GC logs also includes objects cleaned by the major GC.