Is CMS cycle can collect finalize objects

[Srinivas Ramakrishna]

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,
the behaviour should be good if you turn off parallel marking in CMS, viz
-XX:-CMSConcurrentMTEnabled (or whatever
the flag is called now). Are you able to check that?

Adding Stefan to the cc, just in case.
-- ramki

On Tue, Nov 29, 2011 at 2:06 PM, Koji Noguchi <knoguchi at yahoo-inc.com>wrote:

>  Thanks Krystal for your update.
>
> I don’t know why I’m getting a different result than yours.
>
>
> > * After the second CMS collection, the Java heap used goes down
> to 61747K,
> >
> In my case, it stays above 800MBytes...
>
> Attached is the memory footprint with
> CMS(-XX:+UseCMSInitiatingOccupancyOnly
> -XX:CMSInitiatingOccupancyFraction=95 -XX:+UseConcMarkSweepGC) and
> without(fullgc).
>
> It was interesting to see
>
>    1. FullGC case eventually stabilizing to having each FullGC releasing
>    half of the heap (500M) due to finalizer requiring two GCs.
>    2. CMS case still stayed above 800M but there were a few times when
>    memory footprint dropped.
>
>
> 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.
>
> Thanks again for all your inputs.
>
> Koji
>
>
> On 11/24/11 1:45 PM, "Srinivas Ramakrishna" <ysr1729 at gmail.com> wrote:
>
> Hi Kris, thanks for running the test case and figuring that out, and
> saving us further investigation of
> the submitted test case from Koji.
>
> Hopefully you or Koji will be able to find a simple test case that
> illustrates the real issue.
>
> thanks!
> -- ramki
>
>
> On Thu, Nov 24, 2011 at 1:52 AM, Krystal Mok <rednaxelafx at gmail.com>
> wrote:
>
> Hi Koji and Ramki,
>
> 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.
>
> I ran the test case on a 64-bit Linux HotSpot Server VM, on JDK 6 update
> 29.
>
> My .hotspotrc is at [1].
>
> 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.
> UsePSAdaptiveSurvivorSizePolicy has no effect when CMS is in use, so it's
> omitted from my configuration, too.
>
> By using -XX:+PrintReferenceGC, the gc log will show when and how many
> finalizable object are discovered.
>
> 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]".
>
> A part of the GC log can be found at [2]. This log shows two CMS
> collections cycles, in between dozens of minor collections.
>
> * 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;
> * During the re-mark phase of the first CMS collection, 46400
> FinalReferences were discovered;
> * 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);
> * 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;
> * 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.
>
> This behavior looks normal to me -- it's what the VM arguments were
> telling the VM to do.
> 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.
>
> We'd need another test case to study, because this one doesn't really
> repro the problem.
>
> 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.
>
> - Kris
>
> [1]: https://gist.github.com/1390876#file_.hotspotrc
> [2]: https://gist.github.com/1390876#file_gc.partial.log
> [3]:
> http://mail.openjdk.java.net/pipermail/nio-dev/2011-November/001480.html
>
>
> On Thu, Nov 24, 2011 at 7:11 AM, Srinivas Ramakrishna <ysr1729 at gmail.com>
> wrote:
>
> Hi Koji --
>
> Thanks for the test case, that should definitely help with the
> dentification of the problem. I'll see if
> i can find some spare time to pursue it one of these days (but can't
> promise), so please
> do open that Oracle support ticket to get the requisite resource allocated
> for the official
> investigation.
>
> Thanks again for boiling it down to a simple test case, and i'll update if
> i identify the
> root cause...
>
> -- ramki
>
>
> On Tue, Nov 22, 2011 at 1:06 PM, Koji Noguchi <knoguchi at yahoo-inc.com>
> wrote:
>
> This is from an old thread in 2011 April but we're still seeing the same
> problem with (nio) Socket instances not getting collecting by CMS.
>
> Opened http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=7113118
>
> Thanks,
> Koji
>
>
> (From
>
> http://mail.openjdk.java.net/pipermail/hotspot-gc-use/2011-April/subject.htm
> l)
> On 4/25/11 8:37 AM, "Y. Srinivas Ramakrishna" <y.s.ramakrishna at oracle.com>
> >
> wrote:
> > On 4/25/2011 9:10 AM, Bharath Mundlapudi wrote:
> > > Hi Ramki,
> > >
> > > Thanks for the detailed explanation. I was trying to
> > > run some tests for your questions. Here are the answers to some of your
> > > questions.
> > >
> > >>> What are the symptoms?
> > > java.net.SocksSocketImpl objects are not getting cleaned up after a CMS
> > cycle. I see the direct
> > > correlation to java.lang.ref.Finalizer objects. Overtime, this fills up
> > > the old generation and CMS going in loop occupying complete one core.
> > > But when we trigger Full GC, these objects are garbage collected.
> >
> > OK, thanks.
> >
> > >
> > > You
> > >   mentioned that CMS cycle does cleanup these objects provided we
> enable
> > > class unloading. Are you suggesting -XX:+ClassUnloading or
> > > -XX:+CMSClassUnloadingEnabled? I have tried with later and
> > >
> > > didn't
> > >   succeed.  Our pern gen is relatively constant, by enabling this, are
> we
> > >   introducing performance overhead? We have room for CPU cycles and
> perm
> > > gen is relatively small, so this may be fine. Just that we want to see
> > > these objects should GC'ed in CMS cycle.
> > >
> > >
> > > Do you have any suggestion w.r.t. to which flags should i be using to
> > trigger this?
> >
> > For the issue you are seeing the -XX:+CMSClassUnloadingFlag will
> > not make a difference in the accumulation of the socket objects
> > because there is no "projection" as far as i can tell of these
> > into the perm gen, esepcially since as you say there is no class
> > loading going on (since your perm gen size remains constant after
> > start-up).
> >
>
> > However, keeping class unloading enabled via this flag should
> > hopefully not have much of an impact on your pause times given that
> > the perm gen is small. The typical effect you will see if class
> > unloading is enabled is that the CMS remark pause times are a bit
> > longer (if you enable PrintGCDetails you will see messages
> > such as "scrub string table" and "scrub symbol table", "code cache"
> > etc. BY comparing the CMS-remark pause details and times with
> > and without enabling class unloading you will get a good idea
> > of its impact. In some cases, eben though you pay a small price
> > in terms of increased CMS-remark pause times, you will make up
> > for that in terms of faster scavenges etc., so it might well
> > be worthwhile.
> >
> > In the very near future, we may end up turning that on
> > by default for CMS because the savings from leaving it off
> > by default are much smaller now and it can often lead to
> > other issues if class unloading is turned off.
> >
> > So bottom line is: it will not affect the accumulation of
> > your socket objects, but it's a good idea to keep class
> > unloading by CMS enabled anyway.
> >
> > >
> > >
> > >>> What does jmap -finalizerinfo on your process show?
> > >>> What does -XX:+PrintClassHistogram show as accumulating in the
> > heap?
> > >>> (Are they one specific type of Finalizer objects or all
> > varieties?)
> > >
> > > Jmap -histo shows the above class is keep accumulating. Infact,
> > > finalizerinfo doesn't show any objects on this process.
> >
> > OK, that shows that the objects are somehow not discovered by
> > CMS as being eligible for finalization. Although one can imagine
> > a one cycle delay (because of floating garbage) with CMS finding
> > these objects to be unreachable and hence eligible for finalization,
> > continuing accumulation of these objects over a period of time
> > (and presumably many CMS cycles) seems strange and almost
> > definitely a CMS bug especially as you find that a full STW
> > gc does indeed reclaim them.
> >
> > >
> > >
> > >
> > >>> Did the problem start in 6u21? Or are those the only versions
> > >>> you tested and found that there was an issue?
> > > We
> > >   have seen this problem in 6u21. We were on 6u12 earlier and didn't
> run
> > > into this problem. But can't say this is a build particular, since lots
> > > of things have changed.
> >
> > Can you boil down this behavior into a test case that you are able
> > to share with us?
> > If so, please file a bug with the test case
> > and send me the CR id and I'll take a look.
> >
> > Oh, and before you do that, can you please check the latest public
> > release (6u24 or 6u25?) to see if the problem still reproduces?
> >
> > thanks, and sorry I could not be of more help without a bug
> > report or a test case.
> >
> > -- ramki
> >
> > >
> > > Thanks in anticipation,
> > > -Bharath
> > >
>
>
>
> _______________________________________________
> 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: <https://mail.openjdk.org/pipermail/hotspot-gc-dev/attachments/20111129/10bd293b/attachment.htm>
-------------- next part --------------
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use at openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use