During observation of our application (most J2SE, no EJB used),
while the whole Throughput is about 98%, which is acceptable i think,
I find the Full GC is too often while the free heap size is still quite large,
In my understanding, only when there are not enough free heap available, jvm will do a full gc.
Otherwise only small gc will performed.
So I could not know why the frequent full gc observed.
JDK we used are:
java version “1.4.2”
Java™ 2 Runtime Environment, Standard Edition (build 1.4.2-b28)
Java HotSpot™ Client VM (build 1.4.2-b28, mixed mode)
(note: but tried to use jdk1.4.2_08, the gc activity is the same)
java startup parameters:
-server -XX:+PrintGCDetails -Xloggc:.\GC_Platform.log -XX:PermSize=50m -Xmx512m -Xms196m
you can get a general gc log in gcviewer are at:
GC Log output:
0.000: [Full GC 0.000: [Tenured: 0K->2540K(178432K), 0.0914063 secs] 16434K->2540K(198528K), [Perm : 6778K->6778K(51200K)], 0.0915907 secs]
10.384: [GC 10.384: [DefNew: 17983K->1806K(20160K), 0.0326558 secs] 20524K->4346K(198592K), 0.0327726 secs]
19.451: [GC 19.451: [DefNew: 19790K->587K(20160K), 0.0466800 secs] 22330K->4887K(198592K), 0.0501089 secs]
21.623: [Full GC 21.623: [Tenured: 4300K->5052K(178432K), 0.1213009 secs] 6982K->5052K(198592K), [Perm : 10701K->10701K(51200K)], 0.1214923 secs]
32.661: [GC 32.661: [DefNew: 18175K->2240K(20416K), 0.0465995 secs] 23228K->7380K(198848K), 0.0469359 secs]
39.340: [Full GC 39.340: [Tenured: 5140K->7392K(178432K), 0.1787141 secs] 15821K->7392K(198848K), [Perm : 13902K->13902K(51200K)], 0.1788839 secs]
46.529: [GC 46.529: [DefNew: 18111K->2070K(20352K), 0.0380886 secs] 25504K->9463K(198784K), 0.0382113 secs]
50.799: [GC 50.799: [DefNew: 20182K->1737K(20352K), 0.0365351 secs] 27575K->10591K(198784K), 0.0366379 secs]
53.773: [GC 53.773: [DefNew: 19849K->879K(20352K), 0.0246822 secs] 28703K->10839K(198784K), 0.0248319 secs]
54.574: [Full GC 54.574: [Tenured: 9959K->10380K(178432K), 0.2912063 secs] 13242K->10380K(198784K), [Perm : 18333K->18296K(51200K)], 0.2913289 secs]
58.766: [GC 58.766: [DefNew: 18112K->2204K(20352K), 0.0329475 secs] 28492K->12585K(198784K), 0.0343382 secs]
60.505: [Full GC 60.505: [Tenured: 10380K->14402K(178432K), 0.3107448 secs] 23395K->14402K(198784K), [Perm : 21303K->21303K(51200K)], 0.3108887 secs]
60.824: [Full GC 60.824: [Tenured: 14402K->14434K(178432K), 0.2668845 secs] 14446K->14434K(198848K), [Perm : 21303K->21303K(51200K)], 0.2669932 secs]
66.312: [GC 66.314: [DefNew: 18176K->973K(20416K), 0.0260949 secs] 32610K->15407K(198848K), 0.0309115 secs]
71.494: [GC 71.494: [DefNew: 19148K->1805K(20416K), 0.0250356 secs] 33583K->16239K(198848K), 0.0252339 secs]
75.939: [GC 75.939: [DefNew: 19981K->963K(20416K), 0.0201654 secs] 34415K->16228K(198848K), 0.0202827 secs]
81.151: [GC 81.152: [DefNew: 19139K->1129K(20416K), 0.0160375 secs] 34404K->16395K(198848K), 0.0161562 secs]
83.630: [GC 83.630: [DefNew: 19305K->2240K(20416K), 0.0595936 secs] 34571K->20442K(198848K), 0.0597084 secs]
84.312: [GC 84.313: [DefNew: 20415K->1450K(20416K), 0.0323745 secs] 38618K->21890K(198848K), 0.0325019 secs]
85.855: [Full GC 85.856: [Tenured: 20439K->24601K(178432K), 0.3848827 secs] 34113K->24601K(198848K), [Perm : 25524K->25524K(51200K)], 0.3850227 secs]
90.289: [Full GC 90.289: [Tenured: 24601K->18851K(178432K), 0.4745056 secs] 36357K->18851K(198912K), [Perm : 26689K->26594K(51200K)], 0.4794755 secs]
105.245: [GC 105.245: [DefNew: 18367K->1071K(20608K), 0.0241732 secs] 37219K->19922K(199040K), 0.0242961 secs]
150.778: [Full GC 150.778: [Tenured: 18851K->19945K(178432K), 0.3785487 secs] 26867K->19945K(199040K), [Perm : 28737K->28737K(51200K)], 0.3786786 secs]
211.170: [Full GC 211.170: [Tenured: 19945K->20003K(178432K), 0.3783612 secs] 27706K->20003K(198976K), [Perm : 28752K->28752K(51200K)], 0.3784883 secs]
268.675: [GC 268.676: [DefNew: 18303K->254K(20544K), 0.0082376 secs] 38307K->20257K(198976K), 0.0083508 secs]
271.564: [Full GC 271.565: [Tenured: 20003K->20229K(178432K), 0.3945303 secs] 35601K->20229K(198976K), [Perm : 28847K->28847K(51200K)], 0.3946348 secs]
331.977: [Full GC 331.977: [Tenured: 20229K->20072K(178432K), 0.7894126 secs] 35962K->20072K(198976K), [Perm : 28858K->28840K(51200K)], 0.7895193 secs]
392.793: [Full GC 392.793: [Tenured: 20072K->20161K(178432K), 0.6818537 secs] 29151K->20161K(198976K), [Perm : 28859K->28859K(51200K)], 0.6819867 secs]
453.495: [Full GC 453.495: [Tenured: 20161K->20179K(178432K), 0.3913078 secs] 26858K->20179K(198912K), [Perm : 28862K->28862K(51200K)], 0.3914397 secs]
513.905: [Full GC 513.905: [Tenured: 20179K->20198K(178432K), 0.4237008 secs] 26839K->20198K(198912K), [Perm : 28862K->28862K(51200K)], 0.4238075 secs]
574.350: [Full GC 574.350: [Tenured: 20198K->19717K(178432K), 0.5174107 secs] 26841K->19717K(198912K), [Perm : 28864K->28755K(51200K)], 0.5175119 secs]
634.878: [Full GC 634.879: [Tenured: 19717K->19735K(178432K), 0.3772401 secs] 26350K->19735K(198912K), [Perm : 28756K->28756K(51200K)], 0.3773625 secs]
695.266: [Full GC 695.266: [Tenured: 19735K->19769K(178432K), 0.7109638 secs] 26469K->19769K(198912K), [Perm : 28758K->28758K(51200K)], 0.7110638 secs]
755.986: [Full GC 755.986: [Tenured: 19769K->19787K(178432K), 0.3575748 secs] 26170K->19787K(198912K), [Perm : 28770K->28770K(51200K)], 0.3576818 secs]
816.363: [Full GC 816.363: [Tenured: 19787K->18697K(178432K), 0.8332386 secs] 26447K->18697K(198912K), [Perm : 28770K->28282K(51200K)], 0.8333450 secs]
877.215: [Full GC 877.215: [Tenured: 18697K->18721K(178432K), 0.3655750 secs] 25354K->18721K(198912K), [Perm : 28284K->28284K(51200K)], 0.3657093 secs]
937.587: [Full GC 937.587: [Tenured: 18721K->18739K(178432K), 0.7037414 secs] 25341K->18739K(198912K), [Perm : 28287K->28287K(51200K)], 0.7038453 secs]
998.348: [Full GC 998.349: [Tenured: 18739K->18780K(178432K), 0.3696411 secs] 25475K->18780K(198912K), [Perm : 28290K->28290K(51200K)], 0.3697417 secs]
1058.731: [Full GC 1058.731: [Tenured: 18780K->18630K(178432K), 0.8057884 secs] 25486K->18630K(198912K), [Perm : 28291K->28186K(51200K)], 0.8059206 secs]
1119.595: [Full GC 1119.596: [Tenured: 18630K->18668K(178432K), 0.6978599 secs] 25342K->18668K(198912K), [Perm : 28188K->28188K(51200K)], 0.6979597 secs]
1180.311: [Full GC 1180.311: [Tenured: 18668K->18692K(178432K), 0.3538679 secs] 25298K->18692K(198912K), [Perm : 28188K->28188K(51200K)], 0.3539760 secs]
1240.673: [Full GC 1240.673: [Tenured: 18692K->18728K(178432K), 0.6880330 secs] 25038K->18728K(198912K), [Perm : 28193K->28193K(51200K)], 0.6881380 secs]
1301.387: [Full GC 1301.387: [Tenured: 18728K->18654K(178432K), 0.3539372 secs] 25427K->18654K(198912K), [Perm : 28194K->28193K(51200K)], 0.3540453 secs]
1361.754: [Full GC 1361.754: [Tenured: 18654K->18688K(178432K), 0.3648751 secs] 25354K->18688K(198912K), [Perm : 28194K->28194K(51200K)], 0.3649835 secs]
1422.811: [Full GC 1422.811: [Tenured: 18688K->18723K(178432K), 0.4637274 secs] 25538K->18723K(198912K), [Perm : 28196K->28196K(51200K)], 0.4638349 secs]
1483.340: [Full GC 1483.340: [Tenured: 18723K->18758K(178432K), 0.3742308 secs] 25362K->18758K(198912K), [Perm : 28196K->28196K(51200K)], 0.3743400 secs]
1543.736: [Full GC 1543.736: [Tenured: 18758K->18638K(178432K), 0.3586825 secs] 25424K->18638K(198912K), [Perm : 28197K->28196K(51200K)], 0.3587847 secs]
1604.113: [Full GC 1604.113: [Tenured: 18638K->18678K(178432K), 0.3946840 secs] 25393K->18678K(198912K), [Perm : 28197K->28197K(51200K)], 0.3947868 secs]
1664.514: [Full GC 1664.514: [Tenured: 18678K->18714K(178432K), 0.6910755 secs] 25358K->18714K(198912K), [Perm : 28223K->28223K(51200K)], 0.6911591 secs]
1725.222: [Full GC 1725.222: [Tenured: 18714K->18748K(178432K), 0.3588842 secs] 24892K->18748K(198912K), [Perm : 28224K->28224K(51200K)], 0.3589892 secs]
1785.595: [Full GC 1785.595: [Tenured: 18748K->18642K(178432K), 0.4754498 secs] 25452K->18642K(198912K), [Perm : 28224K->28223K(51200K)], 0.4755448 secs]
1846.086: [Full GC 1846.087: [Tenured: 18642K->18686K(178432K), 0.3571730 secs] 25382K->18686K(198912K), [Perm : 28223K->28223K(51200K)], 0.3572800 secs]
1906.449: [Full GC 1906.449: [Tenured: 18686K->18736K(178432K), 0.3534254 secs] 25448K->18736K(198912K), [Perm : 28224K->28224K(51200K)], 0.3535304 secs]
1966.807: [Full GC 1966.807: [Tenured: 18736K->18771K(178432K), 0.4671096 secs] 25432K->18771K(198912K), [Perm : 28225K->28225K(51200K)], 0.4672099 secs]
2027.291: [Full GC 2027.291: [Tenured: 18771K->18648K(178432K), 0.3999047 secs] 25479K->18648K(198912K), [Perm : 28225K->28224K(51200K)], 0.4000103 secs]
2087.699: [Full GC 2087.699: [Tenured: 18648K->18683K(178432K), 0.3626863 secs] 25345K->18683K(198912K), [Perm : 28224K->28224K(51200K)], 0.3628132 secs]
2148.065: [Full GC 2148.065: [Tenured: 18683K->18734K(178432K), 0.4661210 secs] 25519K->18734K(198912K), [Perm : 28224K->28224K(51200K)], 0.4662235 secs]
2208.552: [Full GC 2208.552: [Tenured: 18734K->18766K(178432K), 0.3682870 secs] 25041K->18766K(198912K), [Perm : 28225K->28225K(51200K)], 0.3683912 secs]