problem in gc with incremental mode

Y. S. Ramakrishna y.s.ramakrishna at oracle.com
Thu Nov 4 09:54:52 PDT 2010 

Also, consider whether you really need to use iCMS, or you could
make do with regular CMS (if you have sufficiently many
cores) and can scale back the # parallel threads used by CMS
marking to reduce the impact on mutators. This can often be a
more suitable configuration for multi-core platforms than
the use of iCMS (the latter because of the way it paces itself,
can often carry more floating garbage than regular CMS where the
cycle starts and completes more quickly).

-- ramki

On 11/04/10 09:51, Y. S. Ramakrishna 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:your-email-address>.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
>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>

More information about the hotspot-gc-use mailing list