<html><head><meta http-equiv="Content-Type" content="text/html charset=utf-8"></head><body style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space;"><div>Hi Elliot</div><div><br></div>As Ramki so assutely suggested, you need to add -XX:+CMSClassUnloading.<div><br></div><div>Ramki, should we file a bug for the ParNew (promotion failed) being corrupted by a CMS cycle?<br><div><br></div><div>Regards,</div><div>Kirk</div><div><br><div><div><div>On Jul 8, 2014, at 8:18 AM, Elliot Barlas <<a href="mailto:Elliot.Barlas@citrix.com">Elliot.Barlas@citrix.com</a>> wrote:</div><br class="Apple-interchange-newline"><blockquote type="cite"><div fpstyle="1" ocsi="0" style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant: normal; font-weight: normal; letter-spacing: normal; line-height: normal; orphans: auto; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; widows: auto; word-spacing: 0px; -webkit-text-stroke-width: 0px; word-wrap: break-word;"><div style="direction: ltr; font-family: Tahoma; font-size: 10pt;">JDK and JVM options:<div><br></div><div><div>$ /usr/java/jdk1.7.0_51/bin/java -version</div><div><span style="font-size: 10pt;">java version "1.7.0_51"</span></div><div><span style="font-size: 10pt;">Java(TM) SE Runtime Environment (build 1.7.0_51-b13)</span></div><div><span style="font-size: 10pt;">Java HotSpot(TM) 64-Bit Server VM (build 24.51-b03, mixed mode)</span></div><div><br></div><div>-Xms2048m</div><div><span style="font-size: 10pt;">-Xmx2048m</span></div><div><span style="font-size: 10pt;">-XX:PermSize=256m</span></div><div><span style="font-size: 10pt;">-XX:MaxPermSize=256m</span></div><div><span style="font-size: 10pt;">-XX:+UseConcMarkSweepGC</span></div><div><span style="font-size: 10pt;">-XX:+PrintClassHistogram</span></div><div><span style="font-size: 10pt;">-XX:+DisableExplicitGC</span></div><div><span style="font-size: 10pt;">-XX:+PrintGCDateStamps</span></div><div><span style="font-size: 10pt;">-XX:+PrintGCDetails</span></div><div><span style="font-size: 10pt;">-XX:+PrintTenuringDistribution</span></div><div><span style="font-size: 10pt;">-XX:+HeapDumpOnOutOfMemoryError</span></div><div><span style="font-size: 10pt;">-XX:HeapDumpPath=<logs dir></span></div><div><span style="font-size: 10pt;">-Xloggc:<log path></span></div></div><div><br><div style="font-family: 'Times New Roman'; font-size: 16px;"><hr tabindex="-1"><div id="divRpF600407" style="direction: ltr;"><font face="Tahoma" size="2"><b>From:</b><span class="Apple-converted-space"> </span>Kirk Pepperdine [<a href="mailto:kirk@kodewerk.com">kirk@kodewerk.com</a>]<br><b>Sent:</b><span class="Apple-converted-space"> </span>Monday, July 07, 2014 11:13 PM<br><b>To:</b><span class="Apple-converted-space"> </span>Srinivas Ramakrishna<br><b>Cc:</b><span class="Apple-converted-space"> </span>Elliot Barlas; <a href="mailto:hotspot-gc-dev@openjdk.java.net">hotspot-gc-dev@openjdk.java.net</a> <a href="http://openjdk.java.net">openjdk.java.net</a><br><b>Subject:</b><span class="Apple-converted-space"> </span>Re: Continuous CMS Collections Followed By Concurrent Mode Failure<br></font><br></div><div></div><div>Hi Ramki and Elliot,<div><br></div><div>That was actually my guess. There is only 1 perm record in the file and although it shows that perm is grossly over-sized (ok, there is only one record ;-)) all of the recovery comes from the CMF which suggests perm is involved. All of the other CMS cycles are clearly due to tenured never being below the initiating occupancy fraction. Even without a young collection the initial marks are constantly reporting an occupancy of >1920xxxK of 1929xxxK. Oddly enough the ParNew’s only once promoted enough to trip the concurrent mode failure and oddly enough each of the CMS cycles (without the intervening ParNew) seem to recover about 1xxK bytes per cycle.</div><div><br></div><div><div>2014-06-10T22:56:18.793-0700: 4999527.565: [GC [1 CMS-initial-mark: 1920286K(1926784K)] 2051254K(2080128K), 0.3388330 secs] [Times: user=0.33 sys=0.00, real=0.33 secs] </div><div>…...</div><div>2014-06-10T22:56:26.242-0700: 4999535.014: [GC2014-06-10T22:56:26.242-0700: 4999535.014: [ParNew2014-06-10T22:56:26.256-0700: 4999535.028: [CMS-concurrent-abortable-preclean: 1.948/3.114 secs] [Times: user=1.93 sys=0.12, real=3.11 secs] </div><div> (promotion failed)</div><div>Desired survivor size 8716288 bytes, new threshold 6 (max 6)</div><div>- age 1: 1036320 bytes, 1036320 total</div><div>- age 2: 825248 bytes, 1861568 total</div><div>- age 3: 119024 bytes, 1980592 total</div><div>- age 4: 113784 bytes, 2094376 total</div><div>- age 5: 129024 bytes, 2223400 total</div><div>- age 6: 154976 bytes, 2378376 total</div><div>: 141769K->140729K(153344K), 0.3807730 secs]2014-06-10T22:56:26.623-0700: 4999535.395: [CMS</div><div> (concurrent mode failure): 1920816K->50773K(1926784K), 28.3938140 secs] 2062055K->50773K(2080128K), [CMS Perm : 48657K->41071K(262144K)], 28.7750370 secs] [Times: user=1.65 sys=0.03, real=28.78 secs] </div><div><div>2014-06-10T22:58:41.361-0700: 4999670.133: [GC2014-06-10T22:58:41.361-0700: 4999670.133: [ParNew</div><div>Desired survivor size 8716288 bytes, new threshold 6 (max 6)</div><div>- age 1: 1239232 bytes, 1239232 total</div><div>: 136320K->2239K(153344K), 0.0223680 secs] 187093K->53012K(2080128K), 0.0226340 secs] [Times: user=0.05 sys=0.00, real=0.02 secs] </div></div><div><br></div><div>Note the corrupted formatting of the ParNew (promotion failed).</div><div><br></div><div>Elliot, can you post the jdk version you are using?</div><div><br></div><div>Regards,</div><div>Kirk</div><div><br></div><div><br></div><div><div>On Jul 8, 2014, at 2:37 AM, Srinivas Ramakrishna <<a href="mailto:ysr1729@gmail.com" target="_blank">ysr1729@gmail.com</a>> wrote:</div><br class="Apple-interchange-newline"><blockquote type="cite"><div dir="ltr">Haven't looked at yr log, but from yr description I suspect you need to enable class unloading. That's one thing STW GC does by default that CMS doesn't (at least until 7uXX) do by default.<div><br></div><div>-XX:+CMSClassUnoadingEnabled </div><div><br></div><div>-- ramki</div></div><div class="gmail_extra"><br><br><div class="gmail_quote">On Mon, Jul 7, 2014 at 10:39 AM, Elliot Barlas<span class="Apple-converted-space"> </span><span dir="ltr"><<a href="mailto:Elliot.Barlas@citrix.com" target="_blank">Elliot.Barlas@citrix.com</a>></span><span class="Apple-converted-space"> </span>wrote:<br><blockquote class="gmail_quote" style="margin: 0px 0px 0px 0.8ex; border-left-width: 1px; border-left-color: rgb(204, 204, 204); border-left-style: solid; padding-left: 1ex;"><div style="direction: ltr; font-family: Tahoma; font-size: 10pt;">Hi all, I have a question about CMS collections and I'm hoping you can help.<div><br></div><div><div>The GC log for my Java application indicates continuous CMS GC followed by a concurrent mode failure stop-the-world collection that reclaims nearly the entire heap.</div><div><br></div><div>Why are the CMS collections failing to clear the old generation? Why is a concurrent mode failure stop-the-world collection required?</div><div><br></div><div>CMS collections like the one below occurred continuously for several days before a concurrent mode failure finally forced a stop-the-world collection that cleared space. Notice how the CMS collections recover almost no space, while the collection following the promotion failure reduces the old generation from 1.92 GB to 50.7 MB.</div><div><br></div><div>Is it due to objects kept alive by dead, uncollected objects in the permanent generation, which are only discarded during a STW collection? Should I consider using ‑XX:+CMSClassUnloadingEnabled to address this?</div><div><br></div></div><div><br></div><div>----- Complete CMS collection in GC log -----</div><div><br></div><div><div>2014-06-10T22:54:45.999-0700: 4999434.771: [GC [1 CMS-initial-mark: 1920327K(1926784K)] 2050302K(2080128K), 0.3369430 secs] [Times: user=0.34 sys=0.00, real=0.33 secs] </div><div>2014-06-10T22:54:46.338-0700: 4999435.111: [CMS-concurrent-mark-start]</div><div>2014-06-10T22:54:50.543-0700: 4999439.315: [CMS-concurrent-mark: 4.204/4.204 secs] [Times: user=4.21 sys=0.08, real=4.20 secs] </div><div>2014-06-10T22:54:50.543-0700: 4999439.315: [CMS-concurrent-preclean-start]</div><div>2014-06-10T22:54:50.573-0700: 4999439.345: [CMS-concurrent-preclean: 0.023/0.030 secs] [Times: user=0.02 sys=0.00, real=0.04 secs] </div><div>2014-06-10T22:54:50.573-0700: 4999439.346: [CMS-concurrent-abortable-preclean-start]</div><div>2014-06-10T22:54:54.599-0700: 4999443.371: [GC2014-06-10T22:54:54.599-0700: 4999443.372: [ParNew</div><div>Desired survivor size 8716288 bytes, new threshold 6 (max 6)</div><div>- age 1: 1410440 bytes, 1410440 total</div><div>- age 2: 181888 bytes, 1592328 total</div><div>- age 3: 117864 bytes, 1710192 total</div><div>- age 4: 136792 bytes, 1846984 total</div><div>- age 5: 161296 bytes, 2008280 total</div><div>- age 6: 2488416 bytes, 4496696 total</div><div>: 141989K->5449K(153344K), 0.1317090 secs] 2062317K->1925911K(2080128K), 0.1321970 secs] [Times: user=0.23 sys=0.01, real=0.14 secs] </div><div> CMS: abort preclean due to time 2014-06-10T22:54:55.606-0700: 4999444.378: [CMS-concurrent-abortable-preclean: 2.600/5.033 secs] [Times: user=2.88 sys=0.08, real=5.03 secs] </div><div>2014-06-10T22:54:55.611-0700: 4999444.384: [GC[YG occupancy: 10356 K (153344 K)]2014-06-10T22:54:55.612-0700: 4999444.384: [Rescan (parallel) , 0.1665620 secs]2014-06-10T22:54:55.778-0700: 4</div><div>999444.550: [weak refs processing, 0.0000440 secs]2014-06-10T22:54:55.778-0700: 4999444.551: [scrub string table, 0.0010220 secs] [1 CMS-remark: 1920462K(1926784K)] 1930818K(2080128K), 0.1678710 secs] [Times: user=0.28 sys=0.00, real=0.17 secs] </div><div>2014-06-10T22:54:55.780-0700: 4999444.552: [CMS-concurrent-sweep-start]</div><div>2014-06-10T22:54:57.554-0700: 4999446.326: [CMS-concurrent-sweep: 1.775/1.775 secs] [Times: user=1.82 sys=0.01, real=1.78 secs] </div><div>2014-06-10T22:54:57.554-0700: 4999446.327: [CMS-concurrent-reset-start]</div><div>2014-06-10T22:54:57.564-0700: 4999446.336: [CMS-concurrent-reset: 0.009/0.009 secs] [Times: user=0.01 sys=0.01, real=0.01 secs]</div></div><div><br></div><div><br></div><div>----- Concurrent mode failure GC log ------</div><div><br></div><div><div>2014-06-10T22:56:18.793-0700: 4999527.565: [GC [1 CMS-initial-mark: 1920286K(1926784K)] 2051254K(2080128K), 0.3388330 secs] [Times: user=0.33 sys=0.00, real=0.33 secs] </div><div>2014-06-10T22:56:19.132-0700: 4999527.904: [CMS-concurrent-mark-start]</div><div>2014-06-10T22:56:23.112-0700: 4999531.884: [CMS-concurrent-mark: 3.976/3.980 secs] [Times: user=4.07 sys=0.04, real=3.99 secs] </div><div>2014-06-10T22:56:23.112-0700: 4999531.885: [CMS-concurrent-preclean-start]</div><div>2014-06-10T22:56:23.141-0700: 4999531.914: [CMS-concurrent-preclean: 0.022/0.029 secs] [Times: user=0.01 sys=0.01, real=0.03 secs] </div><div>2014-06-10T22:56:23.141-0700: 4999531.914: [CMS-concurrent-abortable-preclean-start]</div><div>2014-06-10T22:56:26.242-0700: 4999535.014: [GC2014-06-10T22:56:26.242-0700: 4999535.014: [ParNew2014-06-10T22:56:26.256-0700: 4999535.028: [CMS-concurrent-abortable-preclean: 1.948/3.114 secs] [Times: user=1.93 sys=0.12, real=3.11 secs] </div><div> (promotion failed)</div><div>Desired survivor size 8716288 bytes, new threshold 6 (max 6)</div><div>- age 1: 1036320 bytes, 1036320 total</div><div>- age 2: 825248 bytes, 1861568 total</div><div>- age 3: 119024 bytes, 1980592 total</div><div>- age 4: 113784 bytes, 2094376 total</div><div>- age 5: 129024 bytes, 2223400 total</div><div>- age 6: 154976 bytes, 2378376 total</div><div>: 141769K->140729K(153344K), 0.3807730 secs]2014-06-10T22:56:26.623-0700: 4999535.395: [CMS</div><div> (concurrent mode failure): 1920816K->50773K(1926784K), 28.3938140 secs] 2062055K->50773K(2080128K), [CMS Perm : 48657K->41071K(262144K)], 28.7750370 secs] [Times: user=1.65 sys=0.03, real=28.78 secs] </div></div><div><br></div><div><br></div><div>----- Background -----</div><div><br></div><div><p>$ /usr/java/jdk1.7.0_51/bin/java -version</p><p>java version "1.7.0_51"</p><p>Java(TM) SE Runtime Environment (build 1.7.0_51-b13)</p><p>Java HotSpot(TM) 64-Bit Server VM (build 24.51-b03, mixed mode)</p><p><br></p><p>-Xms2048m</p><p>-Xmx2048m</p><p>-XX:PermSize=256m</p><p>-XX:MaxPermSize=256m</p><p>-XX:+UseConcMarkSweepGC</p><p>-XX:+PrintClassHistogram</p><p>-XX:+DisableExplicitGC</p><p>-XX:+PrintGCDateStamps</p><p>-XX:+PrintGCDetails</p><p>-XX:+PrintTenuringDistribution</p><p>-XX:+HeapDumpOnOutOfMemoryError</p><p>-XX:HeapDumpPath=<logs dir></p><div><br class="webkit-block-placeholder"></div><p>-Xloggc:<log path></p></div><div><br></div><div>Thanks,</div><div>Elliot</div></div></blockquote></div></div></blockquote></div></div></div></div></div></div></div></blockquote></div><br></div></div></div></body></html>