G1gc compaction algorithm

Mon Aug 11 17:46:45 UTC 2014

Hi!

Here is our latest log with one Full GC @ 2014-08-11T11:20:02 which is
caused by heap full and allocation request: 144 bytes.

http://81.22.250.165/log/gc-16m-2014-08-11.log

Any ideas how to mitigate this kind of situation? The Full GC makes quite a
difference to the situation but causes a painful pause also.

**
Martin

2014-08-08 4:21 GMT+03:00 Martin Makundi <martin.makundi at koodaripalvelut.com
>:

> Is there any auto tuning parameter that could be activated something like
> adaptive sizing policy that would tune all these parameters automatically?
> It seems like there is some logic behind tuning and statistics maybe it
> could be automatic?
>
> **
> Martin
>
>
> 2014-08-08 2:33 GMT+03:00 Yu Zhang <yu.zhang at oracle.com>:
>
>  This is related to how the remember sets are stored in jvm.  Coarsening
>> is used to reduce memory footprint.  But when coarsening happens, the RSet
>> operations could be expensive.
>>
>> Thanks,
>> Jenny
>>
>> On 8/6/2014 5:18 PM, Martin Makundi wrote:
>>
>> Hi!
>>
>>  Meanwhile, I was wondering what G1RSetRegionEntries and G1RSetSparseRegionEntries
>> do, google didn't give much information about those. How do they work and
>> which things do they affect?
>>
>>  **
>> Martin
>>
>>
>>  2014-08-07 3:14 GMT+03:00 Martin Makundi <
>> martin.makundi at koodaripalvelut.com>:
>>
>>> Hi!
>>>
>>>  Thanks. We were currently running 4M with wastepercent=0 but
>>> unfortunately don't have any logs for that.
>>>
>>>  Will try "-XX:G1HeapRegionSize=16m -XX:G1HeapWastePercent=10
>>> -XX:G1RSetRegionEntries=1792 -XX:G1RSetSparseRegionEntries=40" and post
>>> results later back here.
>>>
>>>  **
>>> Martin
>>>
>>>
>>>  2014-08-07 0:53 GMT+03:00 Yu Zhang <yu.zhang at oracle.com>:
>>>
>>>  Martin,
>>>>
>>>> Thanks for the logs and following up with us.
>>>>
>>>> In this chart, the purple line is the ScanRS time for mixed gc.  At the
>>>> bottom there are grey circles indicating when the initial mark happens.
>>>> The white is the ScanRS time for mixed gc with to-space exhausted.
>>>>
>>>>
>>>> You can see that the first several scanRS after initial-mark is ok,
>>>> then they go up to 7000ms.  For the 16m region size runs, you have
>>>> G1HeapWastePercent=0. (4m region size has G1HeapWastePercent=1).  Because
>>>> of this, g1 will not stop mixed gc till there is no candidate regions.
>>>> From the space claimed by mixed gc, it claims 2-3g heap, but the price is
>>>> too high.  Another disadvantage is it does not start marking phases:
>>>> "do not request concurrent cycle initiation, reason: still doing mixed
>>>> collections, occupancy: 2147483648 bytes, allocation request: 0 bytes,
>>>> threshold: 2147483640 bytes (10.00 %), source: end of GC]"
>>>>
>>>> If you look at the claimable heap in MB, 4m heap region size starts
>>>> mixed gc at lower reclaimable
>>>>
>>>>
>>>> Another thing is there are coarsening for RSet Entries.
>>>>
>>>> Can you do one with
>>>> -XX:G1HeapRegionSize=16m -XX:G1HeapWastePercent=10
>>>> -XX:G1RSetRegionEntries=1792 -XX:G1RSetSparseRegionEntries=40
>>>>
>>>> Thanks,
>>>> Jenny
>>>>
>>>>  On 8/4/2014 9:33 AM, Martin Makundi wrote:
>>>>
>>>> Hi!
>>>>
>>>> Here are the fresh logs:
>>>>
>>>>  http://81.22.250.165/log/gc-16m-2014-08-04.log
>>>>
>>>>  Today we were hit by quite some number of Full GC's with quite short
>>>> intervals and as can be suspected, not so happy users ;)
>>>>
>>>>  Any ideas? I will reduce the region size to 4M for now, because it
>>>> resulted in much fewer full gcs.
>>>>
>>>>  **
>>>> Martin
>>>>
>>>>
>>>>  2014-08-01 1:17 GMT+03:00 Martin Makundi <
>>>> martin.makundi at koodaripalvelut.com>:
>>>>
>>>>> Hmm.. ok, I copy pasted if from the mail, it works after typing
>>>>> manually, thanks.
>>>>>
>>>>>  Problem seems to have been BOTH a whitespace typo AND
>>>>> UnlockDiagnosticOptions was on the right side.
>>>>>
>>>>>  Thanks.
>>>>>
>>>>>  Gathering logs now.
>>>>>
>>>>>  **
>>>>> Martin
>>>>>
>>>>>
>>>>> 2014-08-01 1:01 GMT+03:00 Yu Zhang <yu.zhang at oracle.com>:
>>>>>
>>>>>  maybe some hidden text?
>>>>>>
>>>>>> Thanks,
>>>>>> Jenny
>>>>>>
>>>>>>  On 7/31/2014 2:52 PM, Martin Makundi wrote:
>>>>>>
>>>>>> Strange that it is in the property summary but doesn't allow setting
>>>>>> it.
>>>>>>
>>>>>>
>>>>>> 2014-08-01 0:39 GMT+03:00 Martin Makundi <
>>>>>> martin.makundi at koodaripalvelut.com>:
>>>>>>
>>>>>>> Hi!
>>>>>>>
>>>>>>> UnlockDiagnosticVMOptions  is on (though later (on the right side)
>>>>>>> in the command line). Jvm version is
>>>>>>>
>>>>>>>  java version "1.7.0_55"
>>>>>>> Java(TM) SE Runtime Environment (build 1.7.0_55-b13)
>>>>>>> Java HotSpot(TM) 64-Bit Server VM (build 24.55-b03, mixed mode)
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> 2014-08-01 0:37 GMT+03:00 Yu Zhang <yu.zhang at oracle.com>:
>>>>>>>
>>>>>>>  Martin,
>>>>>>>>
>>>>>>>> These 2 need to run with  -XX:+UnlockDiagnosticVMOptions
>>>>>>>>
>>>>>>>> Thanks,
>>>>>>>> Jenny
>>>>>>>>
>>>>>>>>  On 7/31/2014 2:33 PM, Martin Makundi wrote:
>>>>>>>>
>>>>>>>> Hi!
>>>>>>>>
>>>>>>>>  G1SummarizeRSetStats does not seem to work, jvm says:
>>>>>>>>
>>>>>>>>  Improperly specified VM option 'G1SummarizeRSetStatsPeriod=10'
>>>>>>>> Error: Could not create the Java Virtual Machine.
>>>>>>>> Error: A fatal exception has occurred. Program will exit.
>>>>>>>>
>>>>>>>>  Same for both new options
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> 2014-07-31 20:22 GMT+03:00 Yu Zhang <yu.zhang at oracle.com>:
>>>>>>>>
>>>>>>>>> Martin,
>>>>>>>>>
>>>>>>>>> The ScanRS for mixed gc is extremely long, 1000-9000ms.  Because
>>>>>>>>> it is over pause time goal, minimum old regions can be added to CSet.  So
>>>>>>>>> mixed gc is not keeping up.
>>>>>>>>>
>>>>>>>>> Can do a run keeping 16m region size,  no
>>>>>>>>> G1PrintRegionLivenessInfo, no PrintHeapAtGC.  But -XX:+G1SummarizeRSetStats
>>>>>>>>> -XX:G1SummarizeRSetStatsPeriod=10
>>>>>>>>>
>>>>>>>>> This should tell us more about RSet information.
>>>>>>>>>
>>>>>>>>> While the UpdateRS is not as bad as ScanRS, we can try to push it
>>>>>>>>> to the concurrent threads.  Can you add
>>>>>>>>> -XX:G1RSetUpdatingPauseTimePercent=5.  I am hoping this brings the UpdateRS
>>>>>>>>> down to 50ms.
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> Thanks,
>>>>>>>>> Jenny
>>>>>>>>>
>>>>>>>>> On 7/28/2014 8:27 PM, Martin Makundi wrote:
>>>>>>>>>
>>>>>>>>>> Hi!
>>>>>>>>>>
>>>>>>>>>> We suffered a couple of Full GC's using regionsize 5M (it seems
>>>>>>>>>> to be exact looking at logged actual parameters) and we tried the 16M
>>>>>>>>>> option and this resulted in more severe Full GC behavior.
>>>>>>>>>>
>>>>>>>>>> Here is the promised log for 16 M setting:
>>>>>>>>>> http://81.22.250.165/log/gc-16m.log
>>>>>>>>>>
>>>>>>>>>> We switch back to 5M hoping it will behave more nicely.
>>>>>>>>>>
>>>>>>>>>> **
>>>>>>>>>> Martin
>>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>
>>>>>>
>>>>>
>>>>
>>>>
>>>
>>
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20140811/f32a56f2/attachment-0001.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: image/png
Size: 22281 bytes
Desc: not available
URL: <http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20140811/f32a56f2/attachment-0002.png>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: image/png
Size: 19368 bytes
Desc: not available
URL: <http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20140811/f32a56f2/attachment-0003.png>