<html><head><meta http-equiv="Content-Type" content="text/html charset=us-ascii"></head><body style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space;" class="">Hi Nezih,<div class=""><br class=""></div><div class="">Can you share your GC log.</div><div class=""><br class=""></div><div class="">Kind regards,</div><div class="">Kirk Pepperdine</div><div class=""><br class=""><div><blockquote type="cite" class=""><div class="">On Apr 28, 2017, at 12:52 AM, nezih yigitbasi <<a href="mailto:nezihyigitbasi@gmail.com" class="">nezihyigitbasi@gmail.com</a>> wrote:</div><br class="Apple-interchange-newline"><div class=""><div dir="ltr" class="">My first question is incorrect actually, so I am giving a better example to rephrase my question. At time "2017-04-26T03:12:24.259-0700" there is a young GC that took 35.47 s, where object copy took 28983.4 ms. In that event I see the following log:<div class=""><br class=""></div><div class=""><div class=""> [Eden: 7168.0M(7168.0M)->0.0B(7168.0M) Survivors: 1024.0M->1024.0M Heap: 153.4G(160.0G)->149.4G(160.0G)]</div><div class=""><br class=""></div><div class="">My interpretation for this is, ~4GB of garbage was collected from heap in total and we see that eden usage goes down by ~7GB, this means ~3GB of the eden was live objects. Is this interpretation correct? If it is, how come copying over 3GB takes ~29s? In your answer you said "most of the object copy time is dealing with the Remember Set", can you please give some details about what kind of operations on rsets are done during the object copy phase, and can we see that from these logs?</div><div class=""><br class=""></div><div class="">Thanks again,</div><div class="">Nezih</div><div class=""><br class=""></div></div></div><div class="gmail_extra"><br class=""><div class="gmail_quote">2017-04-27 17:20 GMT-07:00 nezih yigitbasi <span dir="ltr" class=""><<a href="mailto:nezihyigitbasi@gmail.com" target="_blank" class="">nezihyigitbasi@gmail.com</a>></span>:<br class=""><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr" class="">Thanks for the suggestions. We use the default pause time. And here is our entire set of JVM args: <a href="https://gist.github.com/nezihyigitbasi/04f5fdb9c32ac56097011819e20602d8" target="_blank" class="">https://gist.github.com/<wbr class="">nezihyigitbasi/<wbr class="">04f5fdb9c32ac56097011819e20602<wbr class="">d8</a><div class=""><br class=""></div><div class="">I have some followup questions:<br class=""><div class=""><div class=""><br class=""></div><div class="">- In some case the object copy took 39406.8 ms, even if the remembered set is ~30GB isn't this too slow (that's <1GB/s of data)?</div><div class="">- Is there any way to reduce the rset overhead?</div><div class="">- My initial thought when I saw the high object copy times was there may be some sort of contention to have such a low throughput during the copy. Although it may not be the case here, I just wonder whether there is a way to see the amount of contention from the gc logs?</div><span class="HOEnZb"><font color="#888888" class=""><div class=""><br class=""></div><div class="">Nezih</div></font></span><div class=""><div class="h5"><div class=""><br class=""></div><div class=""><div class=""><div class="gmail_extra"><br class=""><div class="gmail_quote">2017-04-27 16:58 GMT-07:00 Jenny Zhang <span dir="ltr" class=""><<a href="mailto:yu.zhang@oracle.com" target="_blank" class="">yu.zhang@oracle.com</a>></span>:<br class=""><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">Hi, Hezih,<br class="">
<br class="">
It seems this workload is very heavy on Remember Set. It has about 31G native memory for RSet (old gen) and still with coarsening.<br class="">
<br class="">
What is you pause time goal? The default (200ms) might be too small for you. Can you increase that so G1 can increase the young gen size? Since there is not much promotion, I guess most of the object copy time is dealing with the Remember Set.<br class="">
<br class="">
There are other things you can try, like increase the G1RSetReginEntries, but the memory footprint will be bigger.<br class="">
<br class="">
So if you can, I suggest increase the pause time goal first.<br class="">
<br class="">
Thanks<span class="m_8770557251507851110gmail-HOEnZb"><font color="#888888" class=""><br class="">
<br class="">
Jenny</font></span><div class="m_8770557251507851110gmail-HOEnZb"><div class="m_8770557251507851110gmail-h5"><br class="">
<br class="">
<br class="">
<br class="">
On 4/27/2017 9:22 AM, nezih yigitbasi wrote:<br class="">
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
Hi,<br class="">
We see huge object copy times (and relatively high termination times) during young GCs in our production system running on Java 1.8.0_112-b15. You can find the GC logs here: <a href="https://gist.github.com/nezihyigitbasi/1f7a92da7860908a611cb1197bd8626b" rel="noreferrer" target="_blank" class="">https://gist.github.com/nezihy<wbr class="">igitbasi/1f7a92da7860908a611cb<wbr class="">1197bd8626b</a><br class="">
<br class="">
The young GC times start going high after the timestamp "2017-04-26T03:07:22.164-0700"<wbr class="">.<br class="">
<br class="">
I will appreciate if you can give some details about:<br class="">
- what goes into the "Object Copy" phase during young GCs and how we can reduce it.<br class="">
- why we see high Termination times and what we can do about it<br class="">
<br class="">
Thanks,<br class="">
Nezih<br class="">
</blockquote>
<br class="">
</div></div></blockquote></div><br class=""></div></div></div></div></div></div></div></div>
</blockquote></div><br class=""></div>
</div></blockquote></div><br class=""></div></body></html>