RFR(S): 8010780: G1: Eden occupancy/capacity output wrong after a full GC

[John Cuthbertson]

Hi Everyone,

Can I have a couple of volunteers look review this fix? The webrev can 
be found at: http://cr.openjdk.java.net/~johnc/8010780/webrev.0/

Summary:
One of the performance team spotted and error in the G1 logs following a 
full GC:

411.322: [G1Ergonomics (Mixed GCs)  (to-space exhausted), 0.4279260 secs]
   ....
    [Eden: 0.0B(1840.0M)->0.0B(1840.0M) Survivors: 0.0B->0.0B Heap: 
36.0G(36.0G)->36.0G(36.0G)]
  [Times: user=1.13 sys=0.10, real=0.43 secs]

411.336: [Full GC (Allocation Failure) 35G->18G(36G), 8.0471890 secs]
  [Times: user=8.50 sys=0.01, real=8.05 secs]

433.639: [GC pause (G1 Evacuation Pause) (young) 433.640: [G1Ergonomics 
(CSet Construction) start choosing CSet, _pending_cards: 26203, 
predicted base time: 13.50 ms, remaining time: 186.50 ms, target pause 
time: 200.00 ms]
  433.640: [G1Ergonomics (CSet Construction) add young regions to CSet, 
eden: 148 regions, survivors: 0 regions, predicted young region time: 
164.22 ms]
  433.640: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 
148 regions, survivors: 0 regions, old: 0 regions, predicted pause time: 
177.72 ms, target pause time: 200.00 ms]

  433.895: [G1Ergonomics (Concurrent Cycles) request concurrent cycle 
initiation, reason: occupancy higher than threshold, occupancy: 
21458059264 bytes, allocation request: 0 bytes, threshold: 17394617520 
bytes (45.00 %), source: end of GC]
, 0.2552910 secs]
....
    [Eden: 2368.0M(1840.0M)->0.0B(1632.0M) Survivors: 0.0B->304.0M Heap: 
20.7G(36.0G)->20.2G(36.0G)]

The heap transition line for the GC after the full GC was displaying the 
eden capacity that was calculated by the GC preceding the full GC rather 
than the eden capacity calculated at the end of the of the full GC. As a 
result the reported eden occupancy is much larger than the reported 
capacity.

The main part of the fix is the moving of 
G1CollectorPolicy::_prev_eden_capacity from 
G1CollectorPolicy::print_detailed_heap_transition() to 
G1CollectorPolicy::record_collection_pause_start(). The code that 
records the heap state before the GC has been refactored into a separate 
routine and is invoked at the start of both an incremental and full GC.

Additionally I added a more detailed heap transition message to the full 
GC output:

> 1.989: [Full GC (Allocation Failure) 256M->234M(256M), 2.3966795 secs]
>    [Eden: 0.0B(12.0M)->0.0B(12.0M) Survivors: 0.0B->0.0B Heap: 
> 256.0M(256.0M)->234.7M(256.0M)]
>  [Times: user=3.00 sys=0.00, real=2.40 secs]
>

for validation purposes.

Testing:
GCOld with a small heap (128m) and +G1PrintHeapRegions

Thanks,

JohnC