RFR(S): 8010738: G1: Output for full GCs with +PrintGCDetails should contain perm gen size/meta data change info

[Jon Masamitsu]

On 5/15/2013 6:38 PM, Srinivas Ramakrishna wrote:
> Depends on when what you refer to as "capacity" vs "reserved" changes. Can either of those change , or both, change between GCs ? I'd assume its useful to log that which changes at GCs  at a GC and not log that which can change with greater frequency.
>
> Or put another way, when you fill to capacity, is a gc done before expanding beyond? Or can both capacity and reserve change between GCs, thus making it important to print both? I guess I shd just go look at the metadata space allocator instead of writing this long email thought :-)

Filling to capacity does not necessarily prompt a GC.  Both capacity and 
reserved can change
between GC's.  When to print Metaspace metrics between GC's required 
more thought so
didn't happen.

Jon


>
> ysr1729
>
> On May 15, 2013, at 16:19, Jon Masamitsu <jon.masamitsu at oracle.com> wrote:
>
>> On 5/15/2013 1:18 PM, Srinivas Ramakrishna wrote:
>>> To keep it consistent with what we've always had on hotspot (and which is how I was interpreting the output here -- never having looked too closely at recent logging changes), I'd suggest staying with:-
>>>
>>> Used before -- > used after (capacity after)
>> Metaspace is not contiguous and there are VirtualSpaces (reserved space) created and then
>> Chunks are allocated (capacity) out of the VirtualSpaces.  So reserved is not so static as
>> with the heap.   With apologies to Bernd maybe it should be changed to
>>
>> Used before -> Used after (capacity after, reserved after)
>>
>> Jon
>>
>>> Don't know if this is consistent with what's the normal today, but that's what it has been for spaces in the past. Capacity after has usually been interpreted as committed rather than reserved. The former is a more generally useful measure in my experience, compared with the more static latter measure.
>>>
>>> Bernd makes some good points that one might want to keep in mind as these evolve.
>>>
>>> Thanks!
>>> -- Ramki
>>>
>>>
>>> ysr1729
>>>
>>> On May 15, 2013, at 12:33, Jon Masamitsu <jon.masamitsu at oracle.com> wrote:
>>>
>>>> John and I talked about it.  I had not known that with perm the information
>>>> printed was (used, capacity, reserved).  At one point I had been printing
>>>> all 4 for metaspace and breaking GC parsers along the way.  What seems
>>>> like the right thing?
>>>>
>>>> Jon
>>>>
>>>> On 5/15/2013 10:28 AM, John Cuthbertson wrote:
>>>>> Hi Ramki,
>>>>>
>>>>> Sorry for the late response. The bug will take a couple of days before it's visible.
>>>>>
>>>>> I didn't realize it was a bug. My impression was that you had to keep track of how the values change between GCs because I can see how all three values (used, capacity, reserved) would be useful.
>>>>>
>>>>> JohnC
>>>>>
>>>>> On 5/14/2013 11:40 PM, Srinivas Ramakrishna wrote:
>>>>>> ah, thanks Jon! (i am guessing the CR will become visible eventually
>>>>>> on bugs.sun.com? Or should I be looking elsewhere?)
>>>>>>
>>>>>> On Tue, May 14, 2013 at 10:23 AM, Jon Masamitsu
>>>>>> <jon.masamitsu at oracle.com> wrote:
>>>>>>> On 5/13/13 5:40 PM, Srinivas Ramakrishna wrote:
>>>>>>>> Hi John --
>>>>>>>>
>>>>>>>> On Mon, May 6, 2013 at 3:23 PM, John Cuthbertson
>>>>>>>> <john.cuthbertson at oracle.com> wrote:
>>>>>>>>
>>>>>>>>>> 4.896: [Full GC (Allocation Failure) 512M->343M(512M), 4.3640117 secs]
>>>>>>>>>>      [Eden: 0.0B(25.0M)->0.0B(97.0M) Survivors: 0.0B->0.0B Heap:
>>>>>>>>>> 512.0M(512.0M)->343.3M(512.0M)], [Metaspace: 1611K->2433K(6448K)]
>>>>>>>>>>    [Times: user=5.13 sys=0.15, real=4.36 secs]
>>>>>>>>> The information that gets printed mirrors that of the other collectors.
>>>>>>>>> Here's parallel GC:
>>>>>>>>>
>>>>>>>>>> 33.245: [Full GC (Ergonomics) [PSYoungGen: 133632K->3423K(144640K)]
>>>>>>>>>> [ParOldGen: 348158K->348158K(348160K)] 481790K->351581K(492800K),
>>>>>>>>>> [Metaspace: 1612K->2433K(6448K)], 2.5788089 secs] [Times: user=9.96
>>>>>>>>>> sys=0.00, real=2.58 secs]
>>>>>>>>> The information that's printed is the amount of metaspace used before the
>>>>>>>>> GC, the capacity, and the amount of reserved space.
>>>>>>>> Do you know why the "used after" for the metadataspace increased after
>>>>>>>> the full gc?
>>>>>>>> Is that normal, common, rare or abnormal ? :-)
>>>>>>> I think that is a bug.  The "capacity" should be "used" after GC .
>>>>>>>
>>>>>>> CR is 8014546.
>>>>>>>
>>>>>>> Thanks.
>>>>>>>
>>>>>>> Jon
>>>>>>>
>>>>>>> Jon
>>>>>>>
>>>>>>>> thanks John!
>>>>>>>> -- ramki