Odd G1GC behavior on 8u91
Poonam Bajaj Parhar
poonam.bajaj at oracle.com
Thu Aug 25 16:54:59 UTC 2016
Hello Vitaly,
On 8/25/2016 9:35 AM, Vitaly Davidovich wrote:
> Hi Poonam,
>
> On Thu, Aug 25, 2016 at 12:28 PM, Poonam Bajaj Parhar
> <poonam.bajaj at oracle.com <mailto:poonam.bajaj at oracle.com>> wrote:
>
> Hello Vitaly,
>
> On 8/24/2016 3:55 PM, Vitaly Davidovich wrote:
>>
>>
>> On Wed, Aug 24, 2016 at 6:29 PM, Poonam Bajaj Parhar
>> <poonam.bajaj at oracle.com <mailto:poonam.bajaj at oracle.com>> wrote:
>>
>> Also, do you see entries like "/[G1Ergonomics (Mixed GCs) do
>> not start mixed GCs, reason:" /in the GC logs which mean that
>> the mixed GCs are not happening due to some reason. What is
>> the reason listed with these log entries?
>>
>> Hi Poonam,
>>
>> Yes, I do see a few those, but only very early in the process
>> lifetime, and nowhere near the Full GCs.
>>
>> 2016-08-24T10:33:04.733+0000: 8.460: [SoftReference, 0 refs,
>> 0.0010108 secs]2016-08-24T10:33:04.734+0000: 8.461:
>> [WeakReference, 383 refs, 0.0006608
>> secs]2016-08-24T10:33:04.735+0000: 8.462: [FinalReference, 4533
>> refs, 0.0020491 secs]2016-08-24T10:33:04.737+0000: 8.464:
>> [PhantomReference, 0 refs, 15 refs, 0.0011945
>> secs]2016-08-24T10:33:04.738+0000: 8.465: [JNI Weak Reference,
>> 0.0000360 secs] 8.467: [G1Ergonomics (Mixed GCs) do not start
>> mixed GCs, reason: concurrent cycle is about to start]
>> 2016-08-24T10:35:22.846+0000: 146.574: [SoftReference, 0 refs,
>> 0.0011450 secs]2016-08-24T10:35:22.847+0000: 146.575:
>> [WeakReference, 440 refs, 0.0006071
>> secs]2016-08-24T10:35:22.848+0000: 146.575: [FinalReference, 7100
>> refs, 0.0018074 secs]2016-08-24T10:35:22.850+0000: 146.577:
>> [PhantomReference, 0 refs, 76 refs, 0.0013148
>> secs]2016-08-24T10:35:22.851+0000: 146.579: [JNI Weak Reference,
>> 0.0000443 secs] 146.584: [G1Ergonomics (Mixed GCs) do not start
>> mixed GCs, reason: concurrent cycle is about to start]
>> 2016-08-24T10:35:56.507+0000: 180.234: [SoftReference, 0 refs,
>> 0.0010184 secs]2016-08-24T10:35:56.508+0000: 180.235:
>> [WeakReference, 138 refs, 0.0006883
>> secs]2016-08-24T10:35:56.508+0000: 180.236: [FinalReference, 3682
>> refs, 0.0023152 secs]2016-08-24T10:35:56.511+0000: 180.238:
>> [PhantomReference, 0 refs, 45 refs, 0.0012558
>> secs]2016-08-24T10:35:56.512+0000: 180.239: [JNI Weak Reference,
>> 0.0000197 secs] 180.247: [G1Ergonomics (Mixed GCs) do not start
>> mixed GCs, reason: concurrent cycle is about to start]
>
> The above entries should be okay.
>
>> 2016-08-24T10:37:33.387+0000: 277.114: [SoftReference, 0 refs,
>> 0.0010965 secs]2016-08-24T10:37:33.388+0000: 277.115:
>> [WeakReference, 5 refs, 0.0006378
>> secs]2016-08-24T10:37:33.388+0000: 277.116: [FinalReference, 3440
>> refs, 0.0028640 secs]2016-08-24T10:37:33.391+0000: 277.119:
>> [PhantomReference, 0 refs, 0 refs, 0.0011392
>> secs]2016-08-24T10:37:33.392+0000: 277.120: [JNI Weak Reference,
>> 0.0000148 secs] 277.130: [G1Ergonomics (Mixed GCs) do not start
>> mixed GCs, reason: candidate old regions not available]
>>
> If these appear only during the startup, I won't worry about these
> too.
>
> Do you see mixed GCs happening later during the run? If yes, then
> it's just that the mixed GCs are not quite enough to keep pace
> with the allocations/promotions into the old regions.
>
> To increase the number of old regions included into the cset, you
> could try increasing the value of /G1MixedGCLiveThresholdPercent.
> /
>
> So as I mentioned in my earlier email today, we tried using IHOP=55
> (instead of 75). There are very long Object Copy and Finalize Marking
> times now, although the heap cleanup is pretty good. I didn't see any
> Full GCs with that setting, but the very long Full GC pauses are just
> replaced by extremely long Finalize Marking times (and fairly long
> Object Copy times).
Yes, I was just reading that particular log that you had sent. The
object copying times are very high.
/ [Object Copy (ms): Min: 22450.6, Avg: 22615.0, Max: 22768.2,
Diff: 317.5, Sum: 520143.9]/
Could you try increasing the value of MaxTenuringThreshold or remove
this option altogether. That would help in letting the objects die in
the young regions itself and would avoid copying them to the old regions.
Thanks,
Poonam
>
> Thanks
>
> /
> /Thanks,
> Poonam
>
>> Does that tell you anything?
>>
>>
>> Thanks,
>> Poonam
>>
>> On 8/24/2016 3:18 PM, Jenny Zhang wrote:
>>> More comments about the questions
>>>
>>> Thanks
>>> Jenny
>>>
>>> On 8/24/2016 11:43 AM, Vitaly Davidovich wrote:
>>>> Right before the Full GC, ergonomics report a failure to
>>>> expand the heap due to an allocation request of 32 bytes.
>>>> Is this implying that a mutator tried to allocate 32 bytes
>>>> but couldn't? How do I reconcile that with Eden+Survivor
>>>> occupancy reported right above that?
>>> Yes, it means the mutator tries to allocate 32byte but can
>>> not get it. Heap won't expand as it already reaches max heap.
>>>
>>> Do you see any humongous objects allocatoin?
>>>>
>>>> Young gen is sized to 30GB, total heap is 96GB. Allocation
>>>> rate of the application is roughly 1GB/s. Am I correct in
>>>> assuming that allocation is outpacing concurrent marking,
>>>> based on the above? What tunable(s) would you advise to
>>>> tweak to get G1 to keep up with the allocation rate? I'm ok
>>>> taking some throughput hit to mitigate 90s+ pauses.
>>>>
>>> The entire log might give a better picture. Especially if
>>> the marking cycle is triggered, how well the mixed gc cleans
>>> up the heap.
>>>
>>> _______________________________________________
>>> hotspot-gc-use mailing list
>>> hotspot-gc-use at openjdk.java.net
>>> <mailto:hotspot-gc-use at openjdk.java.net>
>>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>>> <http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use>
>>
>>
>> _______________________________________________
>> hotspot-gc-use mailing list
>> hotspot-gc-use at openjdk.java.net
>> <mailto:hotspot-gc-use at openjdk.java.net>
>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>> <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/20160825/94525636/attachment.html>
More information about the hotspot-gc-use
mailing list