Hi Stefan and Ramki,<div><br></div><div>I've been looking at 7112034 since it was sent for review. I'll see if I can get one of our production site machines that encountered the problem try out -XX:-CMSConcurrentMTEnabled without the SocketAdaptor patch. Will report back later.</div>
<div><br></div><div>Thanks a lot for the fix!</div><div><br></div><div>- Kris<br><br><div class="gmail_quote">On Wed, Nov 30, 2011 at 5:02 PM, Stefan Karlsson <span dir="ltr"><<a href="mailto:stefan.karlsson@oracle.com" target="_blank">stefan.karlsson@oracle.com</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><u></u>
<div bgcolor="#ffffff" text="#000000"><div>
On 11/30/2011 07:16 AM, Srinivas Ramakrishna wrote:
<blockquote type="cite">Who knows, may be this is related to the other CMS CR
that Stefan just sent out a review request for. If I understand
correctly then,<br>
the behaviour should be good if you turn off parallel marking in
CMS, viz -XX:-CMSConcurrentMTEnabled (or whatever<br>
the flag is called now). Are you able to check that?<br>
</blockquote>
<br></div>
If it's the same bug -XX:-CMSConcurrentMTEnabled should fix it.<br>
<br>
I instrumented and ran the small reproducer in the bug report for
bug <font face="Calibri, Verdana, Helvetica, Arial"><span style="font-size:11pt"></span></font><font face="Calibri,
Verdana, Helvetica, Arial"><a href="http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=7113118" target="_blank">7113118</a></font>. I agree with Krystal's
earlier assessment of that reproducer. We actually do discover most
Finalizers, but we need a second GC to clean them out.<br>
<br>
StefanK<div><div></div><div><br>
<br>
<blockquote type="cite"><br>
Adding Stefan to the cc, just in case.<br>
-- ramki<br>
<br>
<div class="gmail_quote">On Tue, Nov 29, 2011 at 2:06 PM, Koji
Noguchi <span dir="ltr"><<a href="mailto:knoguchi@yahoo-inc.com" target="_blank">knoguchi@yahoo-inc.com</a>></span>
wrote:<br>
<blockquote class="gmail_quote" style="margin:0pt 0pt 0pt 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div>
<font face="Calibri, Verdana, Helvetica, Arial"><span style="font-size:11pt">Thanks Krystal for your update.<br>
<br>
I don’t know why I’m getting a different result than
yours.
<div><br>
<br>
> * After the second CMS collection, the Java heap
used goes down to 61747K, <br>
><br>
</div>
In my case, it stays above 800MBytes...<br>
<br>
Attached is the memory footprint with
CMS(-XX:+UseCMSInitiatingOccupancyOnly
-XX:CMSInitiatingOccupancyFraction=95
-XX:+UseConcMarkSweepGC) and without(fullgc).<br>
<br>
It was interesting to see<br>
</span></font>
<ol>
<li><font face="Calibri, Verdana, Helvetica, Arial"><span style="font-size:11pt">FullGC case eventually
stabilizing to having each FullGC releasing half of
the heap (500M) due to finalizer requiring two GCs.
</span></font></li>
<li><font face="Calibri, Verdana, Helvetica, Arial"><span style="font-size:11pt">CMS case still stayed above
800M but there were a few times when memory
footprint dropped.<br>
</span></font></li>
</ol>
<font face="Calibri, Verdana, Helvetica, Arial"><span style="font-size:11pt"><br>
In any cases, I’m pretty sure your SocketAdaptor [3]
patch would workaround the CMS issue I’m facing. So
this is no longer urgent to me as long as that change
gets into a future java version.<br>
<br>
Thanks again for all your inputs.<span><font color="#888888"><br>
<br>
Koji</font></span>
<div>
<div><br>
<br>
On 11/24/11 1:45 PM, "Srinivas Ramakrishna" <<a href="http://ysr1729@gmail.com" target="_blank">ysr1729@gmail.com</a>>
wrote:<br>
<br>
</div>
</div>
</span></font>
<div>
<div>
<blockquote><font face="Calibri, Verdana, Helvetica,
Arial"><span style="font-size:11pt">Hi Kris,
thanks for running the test case and figuring that
out, and saving us further investigation of<br>
the submitted test case from Koji.<br>
<br>
Hopefully you or Koji will be able to find a
simple test case that illustrates the real issue.<br>
<br>
thanks!<br>
-- ramki<br>
<br>
<br>
On Thu, Nov 24, 2011 at 1:52 AM, Krystal Mok <<a href="http://rednaxelafx@gmail.com" target="_blank">rednaxelafx@gmail.com</a>>
wrote:<br>
</span></font>
<blockquote><font face="Calibri, Verdana, Helvetica,
Arial"><span style="font-size:11pt">Hi Koji and
Ramki,<br>
<br>
I had a look at the repro test case in
Bug 7113118. I don't think the test case is
showing the same problem as the original one
caused by SocksSocketImpl objects. The way this
test case is behaving is exactly what the VM
arguments told it to do.<br>
<br>
I ran the test case on a 64-bit Linux HotSpot
Server VM, on JDK 6 update 29.<br>
<br>
My .hotspotrc is at [1].<br>
<br>
SurvivorRatio doesn't need to be set explicitly,
because when CMS is in use and
MaxTenuringThreshold is 0 (or AlwaysTenure is
true), the SurvivorRatio will automatically be
set to 1024 by ergonomics.<br>
UsePSAdaptiveSurvivorSizePolicy has no effect
when CMS is in use, so it's omitted from my
configuration, too.<br>
<br>
By using -XX:+PrintReferenceGC, the gc log will
show when and how many finalizable object are
discovered.<br>
<br>
The VM arguments given force all surviving
object from minor collections to be promoted
into the old generation, and none of the minor
collections had a chance to discovery any
ready-to-be-collected FinalReferences, so minor
GC logs aren't of interest in this case. All of
the minor GC log lines show "[FinalReference, 0
refs, xxx secs]".<br>
<br>
A part of the GC log can be found at [2]. This
log shows two CMS collections cycles, in between
dozens of minor collections.<br>
<br>
* Before the first of these two CMS collections,
the Java heap used is 971914K, and then the CMS
occupancy threshold is crossed so a CMS
collection cycle starts;<br>
* During the re-mark phase of the first CMS
collection, 46400 FinalReferences were
discovered;<br>
* After the first CMS collection, the Java heap
used is still high, at 913771K, because the
finalizable objects need another old generation
collection to be collected (either CMS or full
GC is fine);<br>
* During the re-mark phase of the second CMS
collection, 3000 FinalReferences were
discovered, these are from promoted objects from
the minor collections in between;<br>
* After the second CMS collection, the Java heap
used goes down to 61747K, as the finalizable
objects discovered from the first CMS collection
are indeed finalized and then collected during
the second CMS collection.<br>
<br>
This behavior looks normal to me -- it's what
the VM arguments were telling the VM to do.<br>
The reason that the Java heap used size was
swing up and down is because the actual live
data set was very low, but
the CMSInitiatingOccupancyFraction was set too
high so concurrent collections are started too
late. If the initiating threshold were set to a
smaller value, say 20, then the test case would
behave quite reasonably.<br>
<br>
We'd need another test case to study, because
this one doesn't really repro the problem.<br>
<br>
After we applied the patch to SocketAdaptor [3],
we don't see this kind of CMS/finalization
problem in production anymore. Should we hit one
of these again, I'll try to get more info from
our production site and see if I can trace down
the real problem.<br>
<br>
- Kris<br>
<br>
[1]: <a href="https://gist.github.com/1390876#file_.hotspotrc" target="_blank">https://gist.github.com/1390876#file_.hotspotrc</a><br>
[2]: <a href="https://gist.github.com/1390876#file_gc.partial.log" target="_blank">https://gist.github.com/1390876#file_gc.partial.log</a><br>
[3]: <a href="http://mail.openjdk.java.net/pipermail/nio-dev/2011-November/001480.html" target="_blank">http://mail.openjdk.java.net/pipermail/nio-dev/2011-November/001480.html</a><br>
<br>
<br>
On Thu, Nov 24, 2011 at 7:11 AM, Srinivas
Ramakrishna <<a href="http://ysr1729@gmail.com" target="_blank">ysr1729@gmail.com</a>>
wrote:<br>
</span></font>
<blockquote><font face="Calibri, Verdana, Helvetica,
Arial"><span style="font-size:11pt">Hi Koji --<br>
<br>
Thanks for the test case, that should
definitely help with the dentification of the
problem. I'll see if<br>
i can find some spare time to pursue it one of
these days (but can't promise), so please<br>
do open that Oracle support ticket to get the
requisite resource allocated for the official<br>
investigation.<br>
<br>
Thanks again for boiling it down to a simple
test case, and i'll update if i identify the<br>
root cause...<br>
<br>
-- ramki<br>
<br>
<br>
On Tue, Nov 22, 2011 at 1:06 PM, Koji Noguchi
<<a href="http://knoguchi@yahoo-inc.com" target="_blank">knoguchi@yahoo-inc.com</a>>
wrote:<br>
</span></font>
<blockquote><font face="Calibri, Verdana,
Helvetica, Arial"><span style="font-size:11pt">This is from an old thread in 2011
April but we're still seeing the same<br>
problem with (nio) Socket instances not
getting collecting by CMS.<br>
<br>
Opened <a href="http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=7113118" target="_blank">http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=7113118</a><br>
<br>
Thanks,<br>
Koji<br>
<br>
<br>
(From<br>
<a href="http://mail.openjdk.java.net/pipermail/hotspot-gc-use/2011-April/subject.htm" target="_blank">http://mail.openjdk.java.net/pipermail/hotspot-gc-use/2011-April/subject.htm</a><br>
l)<br>
On 4/25/11 8:37 AM, "Y. Srinivas
Ramakrishna" <<a>y.s.ramakrishna@oracle.com></a>><br>
wrote:<br>
> On 4/25/2011 9:10 AM, Bharath
Mundlapudi wrote:<br>
> > Hi Ramki,<br>
> ><br>
> > Thanks for the detailed
explanation. I was trying to<br>
> > run some tests for your questions.
Here are the answers to some of your<br>
> > questions.<br>
> ><br>
> >>> What are the symptoms?<br>
> > java.net.SocksSocketImpl objects
are not getting cleaned up after a CMS<br>
> cycle. I see the direct<br>
> > correlation to
java.lang.ref.Finalizer objects. Overtime,
this fills up<br>
> > the old generation and CMS going
in loop occupying complete one core.<br>
> > But when we trigger Full GC, these
objects are garbage collected.<br>
><br>
> OK, thanks.<br>
><br>
> ><br>
> > You<br>
> > mentioned that CMS cycle does
cleanup these objects provided we enable<br>
> > class unloading. Are you
suggesting -XX:+ClassUnloading or<br>
> > -XX:+CMSClassUnloadingEnabled? I
have tried with later and<br>
> ><br>
> > didn't<br>
> > succeed. Our pern gen is
relatively constant, by enabling this, are
we<br>
> > introducing performance
overhead? We have room for CPU cycles and
perm<br>
> > gen is relatively small, so this
may be fine. Just that we want to see<br>
> > these objects should GC'ed in CMS
cycle.<br>
> ><br>
> ><br>
> > Do you have any suggestion w.r.t.
to which flags should i be using to<br>
> trigger this?<br>
><br>
> For the issue you are seeing the
-XX:+CMSClassUnloadingFlag will<br>
> not make a difference in the
accumulation of the socket objects<br>
> because there is no "projection" as far
as i can tell of these<br>
> into the perm gen, esepcially since as
you say there is no class<br>
> loading going on (since your perm gen
size remains constant after<br>
> start-up).<br>
><br>
<br>
> However, keeping class unloading
enabled via this flag should<br>
> hopefully not have much of an impact on
your pause times given that<br>
> the perm gen is small. The typical
effect you will see if class<br>
> unloading is enabled is that the CMS
remark pause times are a bit<br>
> longer (if you enable PrintGCDetails
you will see messages<br>
> such as "scrub string table" and "scrub
symbol table", "code cache"<br>
> etc. BY comparing the CMS-remark pause
details and times with<br>
> and without enabling class unloading
you will get a good idea<br>
> of its impact. In some cases, eben
though you pay a small price<br>
> in terms of increased CMS-remark pause
times, you will make up<br>
> for that in terms of faster scavenges
etc., so it might well<br>
> be worthwhile.<br>
><br>
> In the very near future, we may end up
turning that on<br>
> by default for CMS because the savings
from leaving it off<br>
> by default are much smaller now and it
can often lead to<br>
> other issues if class unloading is
turned off.<br>
><br>
> So bottom line is: it will not affect
the accumulation of<br>
> your socket objects, but it's a good
idea to keep class<br>
> unloading by CMS enabled anyway.<br>
><br>
> ><br>
> ><br>
> >>> What does jmap
-finalizerinfo on your process show?<br>
> >>> What does
-XX:+PrintClassHistogram show as
accumulating in the<br>
> heap?<br>
> >>> (Are they one specific
type of Finalizer objects or all<br>
> varieties?)<br>
> ><br>
> > Jmap -histo shows the above class
is keep accumulating. Infact,<br>
> > finalizerinfo doesn't show any
objects on this process.<br>
><br>
> OK, that shows that the objects are
somehow not discovered by<br>
> CMS as being eligible for finalization.
Although one can imagine<br>
> a one cycle delay (because of floating
garbage) with CMS finding<br>
> these objects to be unreachable and
hence eligible for finalization,<br>
> continuing accumulation of these
objects over a period of time<br>
> (and presumably many CMS cycles) seems
strange and almost<br>
> definitely a CMS bug especially as you
find that a full STW<br>
> gc does indeed reclaim them.<br>
><br>
> ><br>
> ><br>
> ><br>
> >>> Did the problem start in
6u21? Or are those the only versions<br>
> >>> you tested and found that
there was an issue?<br>
> > We<br>
> > have seen this problem in 6u21.
We were on 6u12 earlier and didn't run<br>
> > into this problem. But can't say
this is a build particular, since lots<br>
> > of things have changed.<br>
><br>
> Can you boil down this behavior into a
test case that you are able<br>
> to share with us?<br>
> If so, please file a bug with the test
case<br>
> and send me the CR id and I'll take a
look.<br>
><br>
> Oh, and before you do that, can you
please check the latest public<br>
> release (6u24 or 6u25?) to see if the
problem still reproduces?<br>
><br>
> thanks, and sorry I could not be of
more help without a bug<br>
> report or a test case.<br>
><br>
> -- ramki<br>
><br>
> ><br>
> > Thanks in anticipation,<br>
> > -Bharath<br>
> ><br>
<br>
<br>
<br>
_______________________________________________<br>
hotspot-gc-use mailing list<br>
<a href="http://hotspot-gc-use@openjdk.java.net" target="_blank">hotspot-gc-use@openjdk.java.net</a><br>
<a href="http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use" target="_blank">http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use</a><br>
</span></font></blockquote>
<font face="Calibri, Verdana, Helvetica, Arial"><span style="font-size:11pt"><br>
<br>
_______________________________________________<br>
hotspot-gc-use mailing list<br>
<a href="http://hotspot-gc-use@openjdk.java.net" target="_blank">hotspot-gc-use@openjdk.java.net</a><br>
<a href="http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use" target="_blank">http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use</a><br>
<br>
</span></font></blockquote>
<font face="Calibri, Verdana, Helvetica, Arial"><span style="font-size:11pt"><br>
</span></font></blockquote>
<font face="Calibri, Verdana, Helvetica, Arial"><span style="font-size:11pt"><br>
<br>
</span></font></blockquote>
</div>
</div>
</div>
</blockquote>
</div>
<br>
<pre><fieldset></fieldset>
_______________________________________________
hotspot-gc-use mailing list
<a href="mailto:hotspot-gc-use@openjdk.java.net" target="_blank">hotspot-gc-use@openjdk.java.net</a>
<a href="http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use" target="_blank">http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use</a>
</pre>
</blockquote>
<br>
</div></div></div>
<br>_______________________________________________<br>
hotspot-gc-use mailing list<br>
<a href="mailto:hotspot-gc-use@openjdk.java.net" target="_blank">hotspot-gc-use@openjdk.java.net</a><br>
<a href="http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use" target="_blank">http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use</a><br>
<br></blockquote></div><br></div>