continuous cms gc. even though it is not hitting CMSInitiatingOccupancyFraction=68 Is thsi a know issue

Thu Nov 22 00:06:22 UTC 2007

I thought Ramki was suggesting separate -XX:CMSInitiatingOccupancyFraction=
and -XX:CMSPermInitiatingOccupancyFraction= options, so the permanent
generation could get relatively more full before starting a CMS cycle.
(And, obviously (?), if -XX:-CMSPermGenSweepingEnabled, then the occupancy
of the permanent generation wouldn't figure into the decision at all.

			... peter

Jon Masamitsu wrote:

> Ramki,
> 
> Are you suggesting that we be able to collect the tenured gen and the
> perm gen separately?  So that in this case we would have seen the
> continuous collections but only of the perm gen?
> 
> Jon
> 
> On Nov 21, 2007, at 2:53 PM, Y Srinivas Ramakrishna wrote:
> 
>>
>> Hi Anuj --
>>
>> the reason is that perm gen collection is enabled and the occupancy of
>> the perm gen has exceeded the triggering threshold. (The criterion 
>> currently
>> is to start the collection if either perm gen or old gen occupancy 
>> exceeds the threshold.)
>> A workaround might be to increase MaxPermSize. The JVM should clearly
>> be more "ergonomic" about this, but even otherwise it might be desirable
>> (what do people feel?) to somehow divorce the two thresholds (which are
>> currently conflated as one).
>>
>> -- ramki.
>>
>> ----- Original Message -----
>> From: Anuj Lal <alal at hotwire.com>
>> Date: Wednesday, November 21, 2007 2:27 pm
>> Subject: continuous cms gc. even though it is not hitting 
>> CMSInitiatingOccupancyFraction=68 Is thsi a know issue
>> To: hotspot-gc-dev at openjdk.java.net
>> Cc: hotspotgc-feedback at sun.com
>>
>>
>>> We just moved to 1.5.0.13 from 1.4.12. It sin production.
>>>
>>> I am opening sun support case too.
>>>
>>>
>>>
>>> -Xms2460m -server
>>>
>>>   -XX:+UseConcMarkSweepGC
>>>
>>> -XX:+UseParNewGC
>>>
>>> -XX:+CMSParallelRemarkEnabled
>>>
>>> -XX:+UseCMSCompactAtFullCollection
>>>
>>> -XX:CMSFullGCsBeforeCompaction=0
>>>
>>> -XX:+HandlePromotionFailure
>>>
>>> -XX:CMSInitiatingOccupancyFraction=68
>>>
>>>  -XX:+UseCMSInitiatingOccupancyOnly
>>>
>>> -Xmx2460m
>>>
>>> -XX:NewSize=462M
>>>
>>> -XX:MaxNewSize=462M
>>>
>>> -XX:MaxTenuringThreshold=5
>>>
>>> -XX:SurvivorRatio=5
>>>
>>> -XX:TargetSurvivorRatio=80
>>>
>>> -XX:PermSize=256M
>>>
>>> -XX:MaxPermSize=256M
>>>
>>> -XX:-DisableExplicitGC
>>>
>>>  -XX:+CMSPermGenSweepingEnabled
>>>
>>> -XX:+CMSClassUnloadingEnabled
>>>
>>>  -XX:CMSMaxAbortablePrecleanTime=1
>>>
>>>
>>>
>>>
>>>
>>> Here I sthe snippet of log.  See used is only used 599703K an jvm keep
>>> doing cms gc
>>>
>>>
>>>
>>> Anuj
>>>
>>>
>>>
>>>
>>>
>>> concurrent mark-sweep generation total 2045952K, used 599703K
>>> [0x6b600000, 0xe8400000, 0xe8400000)
>>>
>>>  concurrent-mark-sweep perm gen total 262144K, used 182700K [0xe8400000,
>>> 0xf8400000, 0xf8400000)
>>>
>>> 474868.841: [ParNew
>>>
>>> Desired survivor size 55364812 bytes, new threshold 5 (max 5)
>>>
>>> - age   1:   11103424 bytes,   11103424 total
>>>
>>> - age   2:    4182448 bytes,   15285872 total
>>>
>>> - age   3:    6066672 bytes,   21352544 total
>>>
>>> - age   4:    7075376 bytes,   28427920 total
>>>
>>> : 363413K->27933K(405504K), 0.1678588 secs]
>>> 963116K->627636K(2451456K)Heap after gc invocations=22744:
>>>
>>>  par new generation   total 405504K, used 27933K [0x4e800000,
>>> 0x6b600000, 0x6b600000)
>>>
>>>   eden space 337920K,   0% used [0x4e800000, 0x4e800000, 0x63200000)
>>>
>>>   from space 67584K,  41% used [0x67400000, 0x68f47550, 0x6b600000)
>>>
>>>   to   space 67584K,   0% used [0x63200000, 0x63200000, 0x67400000)
>>>
>>>  concurrent mark-sweep generation total 2045952K, used 599703K
>>> [0x6b600000, 0xe8400000, 0xe8400000)
>>>
>>>  concurrent-mark-sweep perm gen total 262144K, used 182700K [0xe8400000,
>>> 0xf8400000, 0xf8400000)
>>>
>>> }
>>>
>>> , 0.1688079 secs]
>>>
>>> 474869.011: [GC [1 CMS-initial-mark: 599703K(2045952K)]
>>> 628140K(2451456K), 0.1199002 secs]
>>>
>>> 474869.132: [CMS-concurrent-mark-start]
>>>
>>> 474876.273: [CMS-concurrent-mark: 7.004/7.141 secs]
>>>
>>> 474876.273: [CMS-concurrent-preclean-start]
>>>
>>> 474876.344: [CMS-concurrent-preclean: 0.069/0.071 secs]
>>>
>>> 474876.344: [CMS-concurrent-abortable-preclean-start]
>>>
>>>  CMS: abort preclean due to time 474877.846:
>>> [CMS-concurrent-abortable-preclean: 1.006/1.502 secs]
>>>
>>> 474877.854: [GC[YG occupancy: 211030 K (405504 K)]474877.854: [Rescan
>>> (parallel) , 0.6154592 secs]474878.470: [weak refs processing,
>>>
>>>  0.3838744 secs]474878.854: [class unloading, 0.1124973 secs]474878.966:
>>> [scrub symbol & string tables, 0.0976109 secs] [1 CMS-remar
>>>
>>> k: 599703K(2045952K)] 810733K(2451456K), 1.2858288 secs]
>>>
>>> 474879.150: [CMS-concurrent-sweep-start]
>>>
>>> 474882.602: [CMS-concurrent-sweep: 3.336/3.452 secs]
>>>
>>> 474882.602: [CMS-concurrent-reset-start]
>>>
>>> 474882.846: [CMS-concurrent-reset: 0.244/0.244 secs]
>>>
>>> 474882.985: [GC [1 CMS-initial-mark: 595574K(2045952K)]
>>> 897595K(2451456K), 1.2062837 secs]
>>>
>>> 474884.192: [CMS-concurrent-mark-start]
>>>
>>> 474889.371: [CMS-concurrent-mark: 5.179/5.179 secs]
>>>
>>> 474889.371: [CMS-concurrent-preclean-start]
>>>
>>> 474889.459: [CMS-concurrent-preclean: 0.084/0.088 secs]
>>>
>>> 474889.459: [CMS-concurrent-abortable-preclean-start]
>>>
>>>  CMS: abort preclean due to time 474891.671:
>>> [CMS-concurrent-abortable-preclean: 1.004/2.212 secs]
>>>
>>> 474891.799: [GC[YG occupancy: 330467 K (405504 K)]474891.799: [Rescan
>>> (parallel) , 1.0003167 secs]474892.800: [weak refs processing,
>>>
>>>  0.4521800 secs]474893.252: [class unloading, 0.1199606 secs]474893.372:
>>> [scrub symbol & string tables, 0.1051379 secs] [1 CMS-remar
>>>
>>> k: 595574K(2045952K)] 926042K(2451456K), 1.7586947 secs]
>>>
>>> 474893.562: [CMS-concurrent-sweep-start]
>>>
>>> 474895.970: [CMS-concurrent-sweep: 2.408/2.408 secs]
>>>
>>> 474895.970: [CMS-concurrent-reset-start]
>>>
>>> 474896.187: [CMS-concurrent-reset: 0.217/0.217 secs]
>>>
>>> 474898.296: [GC [1 CMS-initial-mark: 594417K(2045952K)]
>>> 932649K(2451456K), 1.2541899 secs]
>>>
>>> 474899.551: [CMS-concurrent-mark-start]
>>>
>>> 474904.513: [CMS-concurrent-mark: 4.962/4.962 secs]
>>>
>>> 474904.513: [CMS-concurrent-preclean-start]
>>>
>>> 474904.584: [CMS-concurrent-preclean: 0.068/0.071 secs]
>>>
>>> 474904.584: [CMS-concurrent-abortable-preclean-start]
>>>
>>>  CMS: abort preclean due to time 474906.523:
>>> [CMS-concurrent-abortable-preclean: 1.017/1.938 secs]
>>>
>>> 474906.549: [GC[YG occupancy: 346194 K (405504 K)]474906.549: [Rescan
>>> (parallel) , 1.0806458 secs]474907.630: [weak refs processing,
>>>
>>>  0.4560526 secs]474908.086: [class unloading, 0.1184826 secs]474908.205:
>>> [scrub symbol & string tables, 0.0981007 secs] [1 CMS-remar
>>>
>>> k: 594417K(2045952K)] 940611K(2451456K), 1.8293189 secs]
>>>
>>> 474908.379: [CMS-concurrent-sweep-start]
>>>
>>> 474910.636: [CMS-concurrent-sweep: 2.256/2.256 secs]
>>>
>>> 474910.636: [CMS-concurrent-reset-start]
>>>
>>> 474910.782: [CMS-concurrent-reset: 0.146/0.146 secs]
>>>
>>> 474912.320: [GC [1 CMS-initial-mark: 594402K(2045952K)]
>>> 949362K(2451456K), 1.2208158 secs]
>>>
>>> 474913.542: [CMS-concurrent-mark-start]
>>>
>>> 474914.002: [GC {Heap before gc invocations=22744:
>>>
>>>  par new generation   total 405504K, used 365853K [0x4e800000,
>>> 0x6b600000, 0x6b600000)
>>>
>>>   eden space 337920K, 100% used [0x4e800000, 0x63200000, 0x63200000)
>>>
>>>   from space 67584K,  41% used [0x67400000, 0x68f47550, 0x6b600000)
>>>
>>>   to   space 67584K,   0% used [0x63200000, 0x63200000, 0x67400000)
>>>
> 