G1GC, Java8u40ea, Metaspace questions

Fri Feb 13 19:20:40 UTC 2015

On 2/13/2015 10:25 AM, Wolfgang Pedot wrote:
> Thanks for your reply,
>
> I was under the impression that the MetaspaceSize is only used as a 
> starting value for the high-water mark and adjusting it will only 
> change the behaviour at startup. Correct me if I am wrong but after 
> the first collect ergonomics would take over and adjust that mark 
> according to Min/MaxMetaspaceFreeRatio, right? My problem is that I 
> have to deal with lots of short lived generated classes and it would 
> be a step back to have the garbage-collector set a low mark right 
> before a class-generation spike and then do a Full-GC before raising 
> it again (Full-GC currently takes ~10sec on the real system). Although 
> with MaxMetaSpaceFreeRation being 70% by default that would probably 
> not happen that often.
Your understanding is correct.  MetaspaceSize is the starting value, as 
well as minimum metadata space size.  When there is a need to expand 
metaspace, it only expands between MinMetaspaceExpansion and 
MaxMetaspaceExpansion; or if the requested space > 
MaxMetaspaceExpansion, it expands by the requested space + 
MinMetaspaceExpansion.  The GC ergonomics decides the expansion, but 
every time it expanses, a full gc happens.
Do you see metaspace shrink a lot?
>
> As for my first question, it is still not clear to me why Metaspace 
> "capacity" never seemed to reach "commited" during my first tests. I 
> have checked the logs for the current instance and with the higher 
> maximum-setting "capacity" and "commited" actually can get quite close 
> now but both are nowhere near the allowed maximum even after I have 
> driven the JVM into multiple FullGCs by creating classes like crazy. 
> Can I assume that RAM that is not "commited" is not actually used by 
> the JVM and can still be used by the OS for filesystem cache and the 
> such?
Yes, if it is not committed, OS can use it.  As why committed/capacity 
not reach max before full gc, I can think of several possible reasons:
1. The full gc is caused by expansion, by this expansion, we have not 
reached the max limit.
2. There are some Auxiliary data structure, but should not take too much 
memory
I still think if you raise  MetaspaceSize, you can avoid a lot of expansion.
>
> Now to my second question:
>
> I was not talking about Full-GC there, what I was referring to is such 
> a log-line:
>
> [G1Ergonomics (Concurrent Cycles) request concurrent cycle initiation, 
> reason: requested by GC cause, GC cause: Metadata GC Threshold]
>
> this tells me that G1 will trigger a concurrent cycle when the 
> Metaspace threshold is reached and sometimes that leads to classes 
> getting unloaded BEFORE there is a FullGC for the very same reason. I 
> would very much prefer this happening more often and FullGC only being 
> used as a last-resort. Unfortunately most of the time there is a 
> FullGC triggered right after I see the request for a concurrent cycle, 
> this means that I can only benefit from concurrent class unloading if 
> there is enough activity in old-gen to trigger concurrent cycles 
> because of heap-occupation. If G1 would use a lower Metaspace 
> threshold to initiate a concurrent cycle there would be a higher 
> chance for classes to get unloaded without a FullGC even if heap 
> occupation is currently low. That would be similar to what is going on 
> in the heap, concurrent cycles are started before the limit is reached 
> and a FullGC is required. Am I wrong here?
I will forward your question to the developer.  IIRC, after 
ClassUnloadingWithConcurrentMark is in place there is some changes in 
how metadata threshold is handled.  But I am not quite sure.  I will 
follow up on this later.
>
> Wolfgang
>
>
>
> Am 13.02.2015 18:20, schrieb Yu Zhang:
>> Wolfgang,
>>
>> Please see my comments in line.
>> Thanks,
>> Jenny
>> On 2/13/2015 5:36 AM, Wolfgang Pedot wrote:
>>> Hello,
>>>
>>> my last mail regarding this topic seems to have been lost somewhere 
>>> but thats not really a problem because my questions have changed:
>>>
>>> I am currently evaluation 8u40 early-access (b21 and b23) for an 
>>> application server which, unfortunately, generates a fair amount of 
>>> short-lived dynamic classes. So far it runs on 7u67 and has enough 
>>> PermGen space to survive most days with 1 FullGC to get rid of the 
>>> classes. This situation is somewhat acceptable but I am really 
>>> looking forward to not requiring FullGCs for class unloading, hence 
>>> my tests with 8u40ea.
>>> I am testing on a smaller system with much less headroom in PermGen 
>>> and as a first shot I just renamed MaxPermSize to MaxMetaspaceSize 
>>> and everything looked OK at first, classes where unloaded without 
>>> FullGCs and I was happy. When the Metaspace baseline-usage grew I 
>>> noticed that there where quite some FullGCs after all and when 
>>> looking closer I noticed that they came in pairs:
>>>
>>> 276129.049: [Full GC (Metadata GC Threshold) 
>>> 2015-02-05T17:03:04.509+0100: 276129.049: [GC 
>>> concurrent-root-region-scan-end, 0.0001449 secs]
>>> 2015-02-05T17:03:04.509+0100: 276129.049: [GC concurrent-mark-start]
>>>   492M->476M(904M), 1.5020455 secs]
>>>     [Eden: 0.0B(336.0M)->0.0B(352.0M) Survivors: 16.0M->0.0B Heap: 
>>> 492.2M(904.0M)->476.4M(904.0M)], [Metaspace: 
>>> 183332K->183332K(1247232K)]
>>>   [Times: user=2.74 sys=0.01, real=1.50 secs]
>>> 2015-02-05T17:03:06.011+0100: 276130.551: [Full GC (Last ditch 
>>> collection)  476M->468M(904M), 1.4614149 secs]
>>>     [Eden: 0.0B(352.0M)->0.0B(360.0M) Survivors: 0.0B->0.0B Heap: 
>>> 476.4M(904.0M)->468.0M(904.0M)], [Metaspace: 
>>> 183332K->178688K(1247232K)]
>>>   [Times: user=2.62 sys=0.01, real=1.46 secs]
>>>
>>> MaxMetaspaceSize was set to 228M at the time so it was not 
>>> completely full yet the JVM threw in a "Last ditch collection" after 
>>> every (quite frequent) FullGC to desperately try and free some 
>>> Metaspace.
>>> I even got to the point where the JVM threw OOME:Metaspace errors 
>>> even though according to the numbers Metaspace was nowhere near full 
>>> (different settings though).
>> MaxMetaspaceSize is the maximum size Metadata space can expand to.  
>> GC will start with metadata space defined by MetaspaceSize, then 
>> expand/shrink it.  When it needs to expand it, a 'Metadata GC 
>> Threshold' full gc is called.  To avoid this kind of full gc, you can 
>> increase MetaspaceSize.
>>
>> In jdk8u40, ClassUnloadingWithConcurrentMark(default true) so that 
>> the classes can be unloaded with concurrent marking.  This will 
>> reduce the chance of running into Metadata GC Threshold' full gc
>>
>>> After banging my head against various settings regarding Metaspace I 
>>> decided to run some worst-case tests on my laptop with different 
>>> MaxMetaspaceSize-values (no other metaspace related settings). My 
>>> test generates lots of classes while causing only minor increases in 
>>> old-gen so the JVM runs into FullGC (Metaspace threshold) 
>>> consistently. I discovered that the reported Metaspace-Size in the 
>>> gclog (and jconsole) never actually reaches the configured maximum 
>>> but instead tops out at about 85% of that value. "Commited" will be 
>>> the Maxsize but "capacity" never goes that high and since my 
>>> test-system did not have enough headroom to cover that it was 
>>> collecting because of Metaspace way to often.
>>>
>>> This brings me to my first question: What is the reason why the JVM 
>>> (appearantly) does not use the whole space it is allowed to use?  Is 
>>> other stuff stored in there but not reported or is there some kind 
>>> of overhead?
>>>
>>> After giving the test-system more headroom it appears to work OK but 
>>> it always takes a couple of days use before Metaspace-baseline evens 
>>> out so I will see next week if that did the trick, I dont really 
>>> want to go "no limit".
>>>
>>> Now a more general question:
>>> I noticed that G1 also triggers a concurrent marking cycle because 
>>> of "Metaspace threshold", is it using the same threshold that would 
>>> also trigger a FullGC or is it slightly lower? Is that treshold 
>>> visible somewhere?
>>> The reason I am asking is that I want to keep FullGCs down to a 
>>> minimum so if the class count rises reasonably slow even without 
>>> causing much oldgen-increase should the concurrent cycle be 
>>> triggered before the JVM throws in a FullGC most of the time?
>> You are talking about Full GC caused by 2 reasons:
>>
>>  *
>>     Metaspace threshold: we can avoid this my increasing 
>> MetadataspaceSize
>>
>>   * Allocation Failure: usually this happens after a few 'to-space
>>     exhausted'.  I think this is not what you see in your log. A lot
>>     of time this is caused by poor tuning.  The marking cycles are
>>     triggered after initial marking.  And when initial marking is
>>     triggered, is decided by InitiatingHeapOccupancyPercent
>>
>>> Quite a long Mail for two questions, any hints would be greatly 
>>> appreciated!
>>>
>>> Wolfgang
>>> _______________________________________________
>>> hotspot-gc-use mailing list
>>> hotspot-gc-use at openjdk.java.net
>>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>>
>
>