G1 Logging and Phases

[Tony Printezis]

Ryan,

Hi. See inline.

Highley, Ryan wrote:
>
> Hello,
>
> I have a few validation questions based on the following G1 GC log 
> excerpt.
>
> 19.298: [GC pause (young) (initial-mark) 2141M->1957M(4000M)20.433: 
> [GC concurrent-mark-start]
>
> , 1.1346080 secs]
>
> 20.721: [GC pause (young)20.761: [GC concurrent-mark-end, 0.2501590 sec]
>
> 2300M->2119M(4000M), 1.3597880 secs]
>
> 22.081: [GC remark, 0.0012060 secs]
>
> 22.083: [GC concurrent-count-start]
>
> 22.452: [GC pause (young) 2469M->2119M(4000M), 0.3101740 secs]
>
> 22.976: [GC concurrent-count-end, 0.8934030]
>
> 23.063: [GC cleanup 2435M->639M(4000M), 0.0142190 secs]
>
> 23.078: [GC concurrent-cleanup-start]
>
> 23.086: [GC concurrent-cleanup-end, 0.0083300]
>
> 23.108: [GC pause (young) 660M->338M(4000M), 0.2031580 secs]
>
> 23.632: [GC pause (partial) 668M->346M(4000M), 0.3303010 secs]
>
> From what I read in concurrentMarkThread.cpp and g1CollectorPolicy.cpp 
> in the current OpenJDK 7 G1 source code, could I please get the 
> following confirmed or denied to ensure my understanding is correct?
>
> The “GC pause” lines are indeed stop-the-world pauses as blatantly 
> marked. J
>
Yes.
>
> The “GC pause (young)” lines are only evacuating young gen regions.
>
Yes.
>
> The “GC pause (young) (initial-mark)” line is both evacuating young 
> gen regions and prepping for a full collection with initial marking of 
> roots.
>
>
Yes, provided by a "full collection" you mean a marking cycle (by "full 
collections" we refer to GCs that collect the entire heap in a STW phase).
>
> The “remark” line is also a stop-the-world pause, i.e. the G1 “Final 
> Marking Pause” noted in the G1 whitepaper.
>
Yes.
>
> The “cleanup” line is also a stop-the-world pause and finalizes the 
> live object counts and sizes.
>
Yes. And it also reclaims regions that have no live objects.
>
> The heap allocated size should be the ending size reported on the 
> “cleanup” line plus any allocations and/or GC activity that occur 
> during the concurrent cleanup phase.
>
>
I'm not quite sure what you're trying to say. The line below

23.063: [GC cleanup 2435M->639M(4000M), 0.0142190 secs]

says that there was a lot of garbage in your heap and the marking phase 
found 1796MB worth of regions that contained no live objects. So, they 
were reclaimed during cleanup.
>
> All “concurrent” lines run concurrently with application threads, 
> similar to the CMS behavior, and in a set of one or more 
> ConcurrentMarkThread instances.
>
There's only one ConcurrentMarkThread (which is the "controller" thread 
if you want), which spawns parallel workers.

Tony
>
>
> Thank you for your help,
>
> Ryan
>
> ------------------------------------------------------------------------
>
> _______________________________________________
> hotspot-gc-use mailing list
> hotspot-gc-use at openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>