Is CMS cycle can collect finalize objects

Stefan Karlsson stefan.karlsson at oracle.com
Wed Nov 30 09:02:33 UTC 2011


On 11/30/2011 07:16 AM, Srinivas Ramakrishna wrote:
> 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?

If it's the same bug -XX:-CMSConcurrentMTEnabled should fix it.

I instrumented and ran the small reproducer in the bug report for bug 
7113118 <http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=7113118>. 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.

StefanK

>
> 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 
> <mailto: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
>     <http://ysr1729@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 <http://rednaxelafx@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 <http://ysr1729@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
>                 <http://knoguchi@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://hotspot-gc-use@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://hotspot-gc-use@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/20111130/2c7360c3/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


More information about the hotspot-gc-dev mailing list