problem in gc with incremental mode

Jon Masamitsu jon.masamitsu at oracle.com
Sun Nov 7 20:04:18 PST 2010


The incremental mode of CMS was implemented for running CMS on machines
with a single hardware thread.  The idea was that CMS does work concurrently
with the application but with a single hardware thread, when CMS ran in
a concurrent phase, it would still be stopping the application (CMS would
use the single hardware thread and there would be nothing for the 
application
to run on).  So the incremental mode of CMS does the concurrent phases
in increments and gives up the hardware thread to the application on
a regular basis.  On a 4 processor machine I would not recommend the 
incremental
mode.    If you have not tried the regular CMS (no incremental mode),
I recommend that you try it.  Overall it is more efficient.

On 11/6/10 11:32 PM, Dori Rabin wrote:
> Thanks fo your replies...
> I am  running on jdk1.6.0_04 and OS is Linux 2.4.21-37.ELsmp, I have 4 
> processors on the machine
> About sharing the log file it might be a little problematic now so 
> let's discuss it if no other option
> I also thought of getting rid of the incremental mode but I am afraid 
> of the effect of long pauses on our realtime application due to the 
> stop the world phase of CMS....
> I didn't quiet understand what exactly you meant by "scale back the # 
> parallel threads used by the CMS..." is there a parameter I need to 
> set for that ? if yes what should be its value ?
> Thanks
> Dori
> On Thu, Nov 4, 2010 at 6:51 PM, Y. S. Ramakrishna 
> <y.s.ramakrishna at oracle.com <mailto:y.s.ramakrishna at oracle.com>> wrote:
>
>     Hi Dori --
>
>     What's the version of JDK you are running? Can you share a
>     complete log?
>     It appears as though the iCMS "auto-pacing" is, for some reason, not
>     kicking in "soon enough"; one workaround is to use turn off
>     auto-pacing
>     and use an explicit duty-cycle (which has its own disadvantages).
>
>     I'd suggest filing a bug, and including a complete log file showing
>     the problem.
>
>     thanks.
>     -- ramki
>
>     On 11/04/10 06:27, Rabin Dori wrote:
>     > Hi,
>     >
>     > Once in a while and for a reason I cannot understand the CMS
>     kicks up
>     > too late which causes a promotion failure and full GC that takes
>     very
>     > long (more than 2 minutes which causes other problems)…
>     >
>     > My question is how to tune the gc flags in order to make sure
>     that the
>     > concurrent sweep will always occur in parallel (incremental mode)
>     > without long pause stop the world but also without reaching its
>     maximum
>     > capacity ?
>     >
>     >
>     >
>     > (I know that in my case the *CMSInitiatingOccupancyFraction*=60 is
>     > ignored because of the CMSIncrementalMode
>     >
>     > And from looking in the log file we can see that the old generation
>     > reaches size of 835’959K out of 843’000K at the time the concurrent
>     > failure (I marked this line in red)
>     >
>     >
>     >
>     > *_I am running the jvm with the following parameters :_*
>     >
>     > wrapper.java.additional.4=-XX:NewSize=200m
>     >
>     > wrapper.java.additional.5=-XX:SurvivorRatio=6
>     >
>     > wrapper.java.additional.6=-XX:MaxTenuringThreshold=4
>     >
>     > wrapper.java.additional.7=-XX:+CMSIncrementalMode
>     >
>     > wrapper.java.additional.8=-XX:+CMSIncrementalPacing
>     >
>     > wrapper.java.additional.9=-XX:+DisableExplicitGC
>     >
>     > wrapper.java.additional.10=-XX:+UseConcMarkSweepGC
>     >
>     > wrapper.java.additional.11=-XX:+CMSClassUnloadingEnabled
>     >
>     > wrapper.java.additional.12=-XX:+PrintGCDetails
>     >
>     > wrapper.java.additional.13=-XX:+PrintGCTimeStamps
>     >
>     > wrapper.java.additional.14=-XX:-TraceClassUnloading
>     >
>     > wrapper.java.additional.15=-XX:+HeapDumpOnOutOfMemoryError
>     >
>     > wrapper.java.additional.16=-verbose:gc
>     >
>     > wrapper.java.additional.17=-XX:CMSInitiatingOccupancyFraction=60
>     >
>     > wrapper.java.additional.18=-XX:+UseCMSInitiatingOccupancyOnly
>     >
>     > wrapper.java.additional.19=-XX:+PrintTenuringDistribution
>     >
>     >
>     >
>     >
>     >
>     > *_Extracts from the log file:_*
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:54:33 | Desired survivor size
>     13107200
>     > bytes, new threshold 4 (max 4)
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:54:33 | - age   1:     544000
>     > bytes,     544000 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:54:33 | - age   2:     346320
>     > bytes,     890320 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:54:33 | - age   3:     262800
>     > bytes,    1153120 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:54:33 | - age   4:     238528
>     > bytes,    1391648 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:54:33 | : 155621K->2065K(179200K),
>     > 0.1046330 secs] 988712K->835373K(1022976K) icms_dc=0 , 0.1047500
>     secs]
>     > [Times: user=0.00 sys=0.00, real=0.11 secs]
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:55:54 | 422097.583: [GC
>     422097.583:
>     > [ParNew
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:55:54 |
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:55:54 | Desired survivor size
>     13107200
>     > bytes, new threshold 4 (max 4)
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:55:54 | - age   1:     577104
>     > bytes,     577104 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:55:54 | - age   2:     261856
>     > bytes,     838960 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:55:54 | - age   3:     298832
>     > bytes,    1137792 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:55:54 | - age   4:     259176
>     > bytes,    1396968 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:55:54 | : 155664K->2386K(179200K),
>     > 0.0498010 secs] 988972K->835920K(1022976K) icms_dc=0 , 0.0499370
>     secs]
>     > [Times: user=0.00 sys=0.00, real=0.05 secs]
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:57:27 | 422190.993: [GC
>     422190.993:
>     > [ParNew
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:57:28 |
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:57:28 | Desired survivor size
>     13107200
>     > bytes, new threshold 4 (max 4)
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:57:28 | - age   1:     676656
>     > bytes,     676656 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:57:28 | - age   2:     283376
>     > bytes,     960032 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:57:28 | - age   3:     239472
>     > bytes,    1199504 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:57:28 | - age   4:     264960
>     > bytes,    1464464 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:57:28 | : 155986K->1918K(179200K),
>     > 0.0652010 secs] 989520K->835699K(1022976K) icms_dc=0 , 0.0653200
>     secs]
>     > [Times: user=0.01 sys=0.00, real=0.07 secs]
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:58:54 | 422277.406: [GC
>     422277.406:
>     > [ParNew
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:58:54 | Desired survivor size
>     13107200
>     > bytes, new threshold 4 (max 4)
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:58:54 | - age   1:     615944
>     > bytes,     615944 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:58:54 | - age   2:     334120
>     > bytes,     950064 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:58:54 | - age   3:     276736
>     > bytes,    1226800 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:58:54 | - age   4:     236424
>     > bytes,    1463224 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 04:58:54 | : 155518K->1928K(179200K),
>     > 0.0378730 secs] 989299K->835959K(1022976K) icms_dc=0 , 0.0379920
>     secs]
>     > [Times: user=0.00 sys=0.00, real=0.04 secs]
>     >
>     > INFO   | jvm 1    | 2010/11/02 05:00:23 | 422366.439: [GC
>     422366.439:
>     > [ParNew
>     >
>     > INFO   | jvm 1    | 2010/11/02 05:00:23 |  (promotion failed)
>     >
>     > INFO   | jvm 1    | 2010/11/02 05:00:23 | Desired survivor size
>     13107200
>     > bytes, new threshold 4 (max 4)
>     >
>     > INFO   | jvm 1    | 2010/11/02 05:00:23 | - age   1:     574000
>     > bytes,     574000 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 05:00:23 | - age   2:     315432
>     > bytes,     889432 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 05:00:23 | - age   3:     281216
>     > bytes,    1170648 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 05:00:23 | - age   4:     271776
>     > bytes,    1442424 total
>     >
>     > INFO   | jvm 1    | 2010/11/02 05:00:23 | :
>     155528K->155689K(179200K),
>     > 0.1007840 secs]422366.540: [CMS
>     >
>     > INFO   | jvm 1    | 2010/11/02 05:01:46 | [Unloading class
>     > sun.reflect.GeneratedMethodAccessor121]
>     >
>     > INFO   | jvm 1    | 2010/11/02 05:01:46 | [Unloading class
>     > sun.reflect.GeneratedMethodAccessor119]
>     >
>     > INFO   | jvm 1    | 2010/11/02 05:01:46 | [Unloading class
>     > sun.reflect.GeneratedMethodAccessor124]
>     >
>     > INFO   | jvm 1    | 2010/11/02 05:01:46 | [Unloading class
>     > sun.reflect.GeneratedMethodAccessor123]
>     >
>     > INFO   | jvm 1    | 2010/11/02 05:01:46 | [Unloading class
>     > sun.reflect.GeneratedMethodAccessor120]
>     >
>     > INFO   | jvm 1    | 2010/11/02 05:01:46 | [Unloading class
>     > sun.reflect.GeneratedMethodAccessor122]
>     >
>     > ERROR  | wrapper  | 2010/11/02 05:02:37 | JVM appears hung:
>     Timed out
>     > waiting for signal from JVM.
>     >
>     >
>     >
>     >
>     >
>     > *Dori Rabin*
>     >
>     > *cid:image001.gif at 01CB69E7.E5E45760*
>     >
>     >
>     >
>     > *cid:image002.jpg at 01CB69E7.E5E45760*
>     >
>     > T. +972-3-123-4567   F. +972-3- 766-3559   M. +972-54- 4232-706
>     >
>     > Email: mailto:Dori <mailto:Dori> <mailto:your-email-address
>     <mailto:your-email-address>>.Rabin at starhome.com
>     <mailto:Rabin at starhome.com>
>     >
>     >
>     >
>     >
>     >
>     > *cid:image003.gif at 01CB69E7.E5E45760* <http://www.starhome.com/>
>     > *cid:image004.gif at 01CB69E7.E5E45760*
>     > <http://blog.starhome.com/>   *cid:image005.gif at 01CB69E7.E5E45760*
>     > <http://bit.ly/9SbzNs>   *cid:image006.gif at 01CB69E7.E5E45760*
>     > <http://bit.ly/aoU2m3>   *cid:image007.gif at 01CB69E7.E5E45760*
>     > <http://linkd.in/bjscKL>
>     >
>     > This email contains proprietary and/or confidential information of
>     > Starhome. If you
>     >
>     > have received this email in error, please delete all copies without
>     > delay and do not
>     >
>     > copy, distribute, or rely on any information contained in this
>     email.
>     > Thank you!
>     >
>     >
>     >
>     >
>     >
>     >
>     >
>     >
>     >
>     ------------------------------------------------------------------------
>     >
>     > _______________________________________________
>     > hotspot-gc-use mailing list
>     > hotspot-gc-use at openjdk.java.net
>     <mailto: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
>     <mailto: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: http://mail.openjdk.java.net/pipermail/hotspot-gc-dev/attachments/20101107/f84e83a9/attachment.html 
-------------- 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