G1GC, Java8u40ea, Metaspace questions
Yu Zhang
yu.zhang at oracle.com
Tue Feb 17 19:22:35 UTC 2015
Jon,
Here is the version:
Java HotSpot(TM) 64-Bit Server VM (25.40-b25) for windows-amd64 JRE
(1.8.0_40-ea-b23), built on Jan 27 2015 19:35:49 by "java_re" with MS
VC++ 10.0 (VS2010)
Wolfang,
Thanks for the logs. But the one you sent me seems pretty well
behaved. There is no full gc. The interval between initial-marking for
metesapce is not getting longer. Do you have a log that you saw the
high-warter mark is getting higher, so the concurrent marking is less
frequent, then there is a full gc?
Thanks,
Jenny
On 2/13/2015 11:46 AM, Jon Masamitsu wrote:
>
> 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
> That's correct.
>
>> adjusting it will only change the behaviour at startup. Correct me if
>> I am wrong but after the first collect ergonomics
>
> If "at startup" includes the first time the metaspace reaches
> MetaspaceSize, yes that is also correct.
>
>> would take over and adjust that mark according to
>> Min/MaxMetaspaceFreeRatio, right? My problem is that I have to
> Right.
>
>> 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.
>>
>> 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
>
> You're running on a 32 bit system, right? Can you run this and let us
> know what comes out.
>
> java -XX:+UseG1GC -XX:+PrintGCDetails -version
>
> I expect something like
>
> java version "1.9.0-ea"
> Java(TM) SE Runtime Environment (build 1.9.0-ea-b10)
> Java HotSpot(TM) Server VM (build 25.0-b62, mixed mode)
> Heap
> garbage-first heap total 65536K, used 0K [0xa1400000, 0xa5400000,
> 0xe1400000)
> region size 1024K, 1 young (1024K), 0 survivors (0K)
> Metaspace used 1418K, capacity 2200K, committed 2200K, reserved
> 4400K
>
>
>> "commited" is not actually used by the JVM and can still be used by
>> the OS for filesystem cache and the such?
>
> If not committed, it is not being used by the JVM but the OS might not
> use
> the space for anything else since the memory has been reserved.
> Depends on
> the OS.
>
>>
>> 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 think you are right again. One explanation for what you are
> seeing is that
> the high-water-mark has grown too high. The concurrent collection for
> metadata has been started but there isn't enough metadata available for
> the needed allocations (runs out and then the full GC happens). I don't
> understand yet why you have so much metaspace reserved but not
> committed yet so don't know if this is actually what you are seeing.
>
> Jon
>
>>
>> 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
>>>
>>
>>
>
> _______________________________________________
> hotspot-gc-use mailing list
> hotspot-gc-use at openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20150217/26ab8cfe/attachment.html>
More information about the hotspot-gc-use
mailing list