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

[Jon Masamitsu]

Changes look good.

Jon

On 04/08/13 11:56, John Cuthbertson wrote:
> Hi Everyone,
>
> Thomas Schatzl has reviewed these change (thanks Thomas!) so I'm 
> looking for one additional reviewer. Any takers?
>
> Thanks,
>
> JohnC
>
> On 3/27/2013 3:12 PM, John Cuthbertson wrote:
>> 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
>>
>