Ramki,<br>Can you explain how -XX:+CMSClassUnloadingEnabled is going to help? I haven't used that parameter before.<br>Thanks,<br>Fino<br><br><div class="gmail_quote">On Fri, Apr 4, 2008 at 6:42 PM, Y Srinivas Ramakrishna <<a href="mailto:Y.S.Ramakrishna@sun.com">Y.S.Ramakrishna@sun.com</a>> wrote:<br>
<blockquote class="gmail_quote" style="border-left: 1px solid rgb(204, 204, 204); margin: 0pt 0pt 0pt 0.8ex; padding-left: 1ex;"><br>
Hi Keith --<br>
<br>
See inline below:-<br>
<div><div></div><div class="Wj3C7c"><br>
> We are running into issues where ostensibly the memory management<br>
> appears OK; less than 1% of the tome is in GC - when I put this file<br>
> into HPJmeter 3.1;<br>
><br>
> 0.000: [ParNew 47626K->6985K(1883840K), 0.5939434 secs]<br>
> 0.613: [Full GC 6985K->6940K(1883840K), 0.7510576 secs]<br>
> 288.169: [ParNew 399516K->20399K(1883840K), 3.0827681 secs]<br>
> 844.451: [ParNew 412975K->26162K(1883840K), 0.3202843 secs]<br>
> 1491.991: [ParNew 418738K->31914K(1883840K), 0.2347086 secs]<br>
> 2177.292: [ParNew 424490K->37760K(1883840K), 0.3079626 secs]<br>
> 2855.229: [ParNew 430336K->43595K(1883840K), 2.0764301 secs]<br>
> 3575.979: [ParNew 436171K->49438K(1883840K), 0.2961466 secs]<br>
> 3606.470: [ParNew 69808K->49730K(1883840K), 0.0388510 secs]<br>
> 3606.511: [Full GC 49730K->42771K(1883840K), 2.5417084 secs]<br>
> 4292.023: [ParNew 435347K->48662K(1883840K), 0.2445446 secs]<br>
> 4970.650: [ParNew 441238K->54506K(1883840K), 0.2373110 secs]<br>
> 5677.603: [ParNew 447082K->60349K(1883840K), 0.3322904 secs]<br>
> 6367.994: [ParNew 452925K->66188K(1883840K), 0.2645763 secs]<br>
> 7055.852: [ParNew 458764K->72033K(1883840K), 0.8281927 secs]<br>
> 7210.009: [ParNew 167469K->73442K(1883840K), 0.0969525 secs]<br>
> 7210.109: [Full GC 73442K->41123K(1883840K), 2.1642088 secs]<br>
> 7909.604: [ParNew 433699K->47011K(1883840K), 0.2533163 secs]<br>
> 8603.519: [ParNew 439587K->52863K(1883840K), 0.2230794 secs]<br>
> 9289.216: [ParNew 445439K->58709K(1883840K), 0.2359698 secs]<br>
> 9968.793: [ParNew 451285K->64554K(1883840K), 0.2656911 secs]<br>
> 10649.694: [ParNew 457130K->70393K(1883840K), 0.2243246 secs]<br>
> 10813.028: [ParNew 158599K->71696K(1883840K), 0.0770400 secs]<br>
> 10813.107: [Full GC 71696K->41024K(1883840K), 1.7410828 secs]<br>
> 11503.339: [ParNew 433600K->46907K(1883840K), 0.2542805 secs]<br>
> 12191.022: [ParNew 439483K->52751K(1883840K), 0.2257059 secs]<br>
> 12864.793: [ParNew 445327K->58591K(1883840K), 0.2231573 secs]<br>
> 13546.217: [ParNew 451167K->64433K(1883840K), 0.2532376 secs]<br>
> 14247.570: [ParNew 457009K->70278K(1883840K), 0.2111731 secs]<br>
> 14415.581: [ParNew 168788K->71740K(1883840K), 0.0916532 secs]<br>
> 14415.675: [Full GC 71740K->41182K(1883840K), 1.7439608 secs]<br>
> 15096.989: [ParNew 433758K->47062K(1883840K), 0.2752132 secs]<br>
> 15777.472: [ParNew 439638K->52905K(1883840K), 0.2132059 secs]<br>
> 16475.184: [ParNew 445481K->58750K(1883840K), 0.2249407 secs]<br>
> 16956.572: [ParNew 451326K->66543K(1883840K), 0.2237252 secs]<br>
> 17593.401: [ParNew 459119K->72857K(1883840K), 0.2493865 secs]<br>
> 18018.152: [ParNew 313587K->76412K(1883840K), 0.1719212 secs]<br>
> 18018.326: [Full GC 76412K->44673K(1883840K), 1.9000112 secs]<br>
> 18734.462: [ParNew 437249K->50542K(1883840K), 0.2459797 secs]<br>
> 19434.180: [ParNew 443118K->56364K(1883840K), 0.2399764 secs]<br>
> 20026.580: [ParNew 448940K->63103K(1883840K), 0.2327731 secs]<br>
> 20723.692: [ParNew 455679K->68869K(1883840K), 0.2299928 secs]<br>
> 21338.875: [ParNew 461445K->74742K(1883840K), 0.2005874 secs]<br>
> 21620.952: [ParNew 269312K->78103K(1883840K), 0.1174351 secs]<br>
> 21621.072: [Full GC 78103K->45998K(1883840K), 1.8386129 secs]<br>
> 22227.195: [ParNew 438574K->51330K(1883840K), 0.2042002 secs]<br>
> 22696.526: [ParNew 443906K->58015K(1883840K), 0.2154086 secs]<br>
> 23246.252: [ParNew 450591K->63639K(1883840K), 0.2171688 secs]<br>
> 23936.816: [ParNew 456215K->69353K(1883840K), 0.2421265 secs]<br>
> 24529.163: [ParNew 461929K->75718K(1883840K), 0.1985638 secs]<br>
> 25062.082: [ParNew 468294K->82472K(1883840K), 0.2119384 secs]<br>
> 25223.640: [ParNew 205230K->84729K(1883840K), 0.0745738 secs]<br>
> 25223.717: [Full GC 84729K->52981K(1883840K), 1.9445841 secs]<br>
> 25808.453: [ParNew 445557K->58730K(1883840K), 0.2220857 secs]<br>
> 27012.025: [ParNew 450888K->65873K(1883840K), 0.1835305 secs]<br>
> 28826.400: [ParNew 194359K->68617K(1883840K), 0.0476450 secs]<br>
> 28826.450: [Full GC 68617K->33933K(1883840K), 1.3288466 secs]<br>
> 31626.367: [ParNew 426509K->39131K(1883840K), 0.1329507 secs]<br>
> 32428.552: [ParNew 79650K->40294K(1883840K), 0.0451805 secs]<br>
> 32428.600: [Full GC 40294K->29329K(1883840K), 1.0458070 secs]<br>
> 36030.356: [ParNew 157110K->31764K(1883840K), 0.1066607 secs]<br>
> 36030.465: [Full GC 31764K->28476K(1883840K), 0.9791810 secs]<br>
> 39632.163: [ParNew 96572K->30448K(1883840K), 0.0852053 secs]<br>
> 39632.251: [Full GC 30448K->27232K(1883840K), 0.9056725 secs]<br>
> 43233.856: [ParNew 215673K->31439K(1883840K), 0.2064516 secs]<br>
> 43234.074: [Full GC 31439K->28437K(1883840K), 1.1075595 secs]<br>
> 46835.908: [ParNew 302993K->39167K(1883840K), 0.1579830 secs]<br>
> 46836.074: [Full GC 39167K->35187K(1883840K), 1.1977157 secs]<br>
> 50437.975: [ParNew 233401K->40095K(1883840K), 0.1419100 secs]<br>
> 50438.130: [Full GC 40095K->36165K(1883840K), 1.3757682 secs]<br>
> 54040.209: [ParNew 47288K->36927K(1883840K), 2.4154908 secs]<br>
> 54042.656: [Full GC 36927K->35142K(1883840K), 1.7857094 secs]<br>
> 57645.546: [ParNew 48404K->36028K(1883840K), 0.9233543 secs]<br>
> 57646.503: [Full GC 36028K->33941K(1883840K), 1.2575880 secs]<br>
> 61248.475: [ParNew 62613K->36158K(1883840K), 1.5358356 secs]<br>
> 61250.042: [Full GC 36158K->34806K(1883840K), 1.1270633 secs]<br>
> 64852.138: [ParNew 89705K->37904K(1883840K), 2.8467706 secs]<br>
> 64855.019: [Full GC 37904K->36625K(1883840K), 1.2928314 secs]<br>
><br>
<br>
</div></div>Did you notice that towards the end of the log above, your allocation rates<br>
have plummetted and the scavenges themselves are taking pretty long?<br>
Perhaps that gives you some ideas as to what could be happening?<br>
<div class="Ih2E3d"><br>
> Here are our VM args:<br>
><br>
> -server -Xms1840m -Xmx1840m -Xss256k -XX:+UseConcMarkSweepGC<br>
> -XX:NewSize=384m -XX:MaxNewSize=384m -XX:PermSize=256m<br>
> -XX:MaxPermSize=256m -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000<br>
> -Djava.headless.awt=true -Xloggc:gc.log<br>
<br>
</div>I'd suggest experimenting with either:-<br>
<br>
-XX:+ExplicitGCInvokesConcurrent[AndUnloadsClasses] -XX:+CMSClassUnloadingEnabled<br>
<br>
or, perhaps less desirable, but certainly useful from the prespective of your<br>
debugging objectives here:-<br>
<br>
-XX:+DisableExplicitGC -XX:+CMSClassUnloadingEnabled<br>
<div class="Ih2E3d"><br>
><br>
> We see the DGC working every hour - 3600 seconds apart a ParNew<br>
> followed by a Full GC - and there is a plethora of class unloading of<br>
> the Sun reflection classes since we do a lot of RMI - serialisation/deserialisation.<br>
><br>
> Should we increase the frequency of DGC? Not sure why the VM hangs -<br>
> possibly our client code - but we wanted to exclude completely the<br>
> idea that GC is culpable of creating this or contributing to this failure.<br>
<br>
</div>Check that you are not paging and running slow rather than hanging?<br>
<br>
When you get the "hung jvm", if on Solaris, try prstat -L -p <pid> to see<br>
if any threads are active, and also try pstack <pid> (perhaps several<br>
seconds apart, to observe any active threads). If the application shows<br>
no activity (from above), try jstack <pid> (or kill -QUIT <pid>) to<br>
see if you can elicit a java thread stack dump.<br>
<br>
(I was not sure from yr description whether you believed the JVM was<br>
hung or that the jvm was responding -- for example doing the occasional<br>
gc etc -- but the application response had plummeted.)<br>
<br>
-- ramki<br>
<div><div></div><div class="Wj3C7c"><br>
><br>
> thanks<br>
><br>
> keith<br>
><br>
><br>
> _______________________________________________<br>
> hotspot-gc-use mailing list<br>
> <a href="mailto:hotspot-gc-use@openjdk.java.net">hotspot-gc-use@openjdk.java.net</a><br>
> <a href="http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use" target="_blank">http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use</a><br>
_______________________________________________<br>
hotspot-gc-use mailing list<br>
<a href="mailto:hotspot-gc-use@openjdk.java.net">hotspot-gc-use@openjdk.java.net</a><br>
<a href="http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use" target="_blank">http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use</a><br>
</div></div></blockquote></div><br><br clear="all"><br>-- <br>Michael Finocchiaro<br><a href="mailto:michael.finocchiaro@gmail.com">michael.finocchiaro@gmail.com</a><br>Mobile Telephone: +33 6 67 90 64 39<br>MSN: <a href="mailto:le_fino@hotmail.com">le_fino@hotmail.com</a>