Help needed on explaining JVM thrashing behavior

Hi there,

We run a webapp on Tomcat 4.1.29 + JDK 1.4.2_02-b03. We've been seeing memory issues in our production environment. It's not an OutOfMemoryError or StackOverflowError or anything of that sort. The symptoms are described below:

Stage 1: GC running normally with Minor GC mostly, with speradic to no Full GC. No disk swap taking place. Service available. This goes on for days.

Stage 2: Minor GC running vigorously 2-3 times a second, with Tenured space still acting normally. No disk swap taking place. Service available. This goes on for some time, usually less than an hour.

Stage 3: Major GC starting to occur, with faster and faster frequency, resulting in heavy disk swap. Effectively denial of service.

You can see the GC outputs from below. What I don't understand or have no insight into is under what circumstances does JVM behave that way. From the GC outputs (both Tenure and New generations), there is no trace of memory leak.

Any help or hints or suggestions are greatly appreciated.

-Alan

0.000: [GC 0.000: [DefNew: 209791K->26176K(235968K), 0.2376840 secs] 209791K->32700K(1202624K), 0.2377370 secs]

94.374: [GC 94.374: [DefNew: 235967K->1222K(235968K), 0.1521990 secs] 242492K->33819K(1202624K), 0.1522450 secs]

178.833: [GC 178.833: [DefNew: 211012K->2321K(235968K), 0.0276120 secs] 243609K->34918K(1202624K), 0.0276610 secs]

286.706: [GC 286.706: [DefNew: 212111K->2662K(235968K), 0.0230090 secs] 244708K->35259K(1202624K), 0.0230570 secs]

394.587: [GC 394.587: [DefNew: 212454K->3260K(235968K), 0.0263890 secs] 245051K->35857K(1202624K), 0.0264400 secs]

486.970: [GC 486.970: [DefNew: 213051K->3356K(235968K), 0.0238240 secs] 245648K->35953K(1202624K), 0.0238740 secs]

584.972: [GC 584.972: [DefNew: 213147K->3425K(235968K), 0.0228920 secs] 245744K->36022K(1202624K), 0.0229630 secs]

683.765: [GC 683.765: [DefNew: 213217K->3458K(235968K), 0.0232650 secs] 245814K->36055K(1202624K), 0.0233160 secs]

788.527: [GC 788.527: [DefNew: 213250K->3758K(235968K), 0.0273670 secs] 245847K->36355K(1202624K), 0.0274350 secs]

885.211: [GC 885.212: [DefNew: 213550K->4191K(235968K), 0.0329590 secs] 246147K->36788K(1202624K), 0.0330250 secs]

960.873: [GC 960.873: [DefNew: 213983K->4154K(235968K), 0.0275660 secs] 246580K->36751K(1202624K), 0.0276340 secs]

1069.269: [GC 1069.269: [DefNew: 213946K->4190K(235968K), 0.0273100 secs] 246543K->36787K(1202624K), 0.0273580 secs]

1183.327: [GC 1183.327: [DefNew: 213982K->4222K(235968K), 0.0277730 secs] 246579K->36819K(1202624K), 0.0278240 secs]

1285.939: [GC 1285.939: [DefNew: 214014K->4130K(235968K), 0.0278460 secs] 246611K->36727K(1202624K), 0.0278920 secs]

1413.854: [GC 1413.854: [DefNew: 213920K->4078K(235968K), 0.0271100 secs] 246517K->36675K(1202624K), 0.0271610 secs]

1507.184: [GC 1507.184: [DefNew: 213869K->4010K(235968K), 0.0263960 secs] 246466K->36607K(1202624K), 0.0264430 secs]

1608.763: [GC 1608.763: [DefNew: 213802K->4424K(235968K), 0.0316100 secs] 246399K->37022K(1202624K), 0.0316570 secs]

1719.036: [GC 1719.036: [DefNew: 214216K->4441K(235968K), 0.0296830 secs] 246814K->37038K(1202624K), 0.0297320 secs]

1822.642: [GC 1822.642: [DefNew: 214233K->4422K(235968K), 0.0287300 secs] 246830K->37019K(1202624K), 0.0287830 secs]

1937.045: [GC 1937.045: [DefNew: 214208K->4596K(235968K), 0.0311750 secs] 246805K->37193K(1202624K), 0.0312220 secs]

2025.646: [GC 2025.646: [DefNew: 214387K->4563K(235968K), 0.0292600 secs] 246984K->37160K(1202624K), 0.0293090 secs]

2115.965: [GC 2115.965: [DefNew: 214355K->4512K(235968K), 0.0290740 secs] 246952K->37109K(1202624K), 0.0291220 secs]

2226.434: [GC 2226.435: [DefNew: 214304K->4726K(235968K), 0.0326460 secs] 246901K->37323K(1202624K), 0.0326940 secs]

2307.104: [GC 2307.104: [DefNew: 214517K->4733K(235968K), 0.0309900 secs] 247114K->37330K(1202624K), 0.0310390 secs]

2404.119: [GC 2404.119: [DefNew: 214525K->4810K(235968K), 0.0316430 secs] 247122K->37407K(1202624K), 0.0316970 secs]

2534.972: [GC 2534.972: [DefNew: 214602K->4814K(235968K), 0.0311620 secs] 247199K->37411K(1202624K), 0.0312100 secs]

2655.142: [GC 2655.142: [DefNew: 214603K->5342K(235968K), 0.0456020 secs] 247200K->37939K(1202624K), 0.0456560 secs]

2763.548: [GC 2763.548: [DefNew: 215134K->5335K(235968K), 0.0336460 secs] 247731K->37932K(1202624K), 0.0336910 secs]

2877.942: [GC 2877.942: [DefNew: 215126K->5180K(235968K), 0.0322420 secs] 247723K->37777K(1202624K), 0.0322910 secs]

2969.243: [GC 2969.243: [DefNew: 214970K->5539K(235968K), 0.0328360 secs] 247567K->38136K(1202624K), 0.0328860 secs]

3079.321: [GC 3079.321: [DefNew: 215331K->5566K(235968K), 0.0330910 secs] 247928K->38163K(1202624K), 0.0331390 secs]

3165.191: [GC 3165.191: [DefNew: 215356K->5523K(235968K), 0.0321970 secs] 247953K->38120K(1202624K), 0.0322420 secs]

3237.009: [GC 3237.009: [DefNew: 215313K->4952K(235968K), 0.0341610 secs] 247910K->38165K(1202624K), 0.0342100 secs]

3319.846: [GC 3319.846: [DefNew: 214744K->3899K(235968K), 0.0314330 secs] 247957K->38201K(1202624K), 0.0314810 secs]

3423.415: [GC 3423.416: [DefNew: 213691K->3720K(235968K), 0.0264050 secs] 247993K->38197K(1202624K), 0.0264720 secs]

3517.261: [GC 3517.261: [DefNew: 213512K->3131K(235968K), 0.0257320 secs] 247989K->38124K(1202624K), 0.0258060 secs]

3607.913: [GC 3607.913: [DefNew: 212923K->3130K(235968K), 0.0220720 secs] 247916K->38167K(1202624K), 0.0221450 secs]

3706.955: [GC 3706.955: [DefNew: 212921K->3125K(235968K), 0.0218030 secs] 247958K->38199K(1202624K), 0.0218750 secs]

3788.363: [GC 3788.363: [DefNew: 212917K->3227K(235968K), 0.0216570 secs] 247991K->38305K(1202624K), 0.0217330 secs]

3875.074: [GC 3875.074: [DefNew: 213019K->2824K(235968K), 0.0214530 secs] 248097K->38124K(1202624K), 0.0215000 secs]

3970.026: [GC 3970.026: [DefNew: 212616K->2540K(235968K), 0.0206110 secs] 247916K->38177K(1202624K), 0.0206620 secs]

4073.301: [GC 4073.301: [DefNew: 212329K->2555K(235968K), 0.0185890 secs] 247966K->38235K(1202624K), 0.0186570 secs]

4168.772: [GC 4168.772: [DefNew: 212346K->2473K(235968K), 0.0176880 secs] 248026K->38183K(1202624K), 0.0177550 secs]

4271.238: [GC 4271.238: [DefNew: 212264K->2491K(235968K), 0.0173230 secs] 247974K->38231K(1202624K), 0.0173730 secs]

4381.117: [GC 4381.117: [DefNew: 212283K->2344K(235968K), 0.0168560 secs] 248023K->38157K(1202624K), 0.0169230 secs]

4485.646: [GC 4485.646: [DefNew: 212136K->2513K(235968K), 0.0167250 secs] 247949K->38331K(1202624K), 0.0167950 secs]

4574.641: [GC 4574.641: [DefNew: 212302K->2546K(235968K), 0.0168210 secs] 248120K->38368K(1202624K), 0.0168700 secs]

4661.710: [GC 4661.710: [DefNew: 212336K->2455K(235968K), 0.0217210 secs] 248158K->38657K(1202624K), 0.0217690 secs]

4763.633: [GC 4763.633: [DefNew: 212247K->2451K(235968K), 0.0172560 secs] 248449K->38668K(1202624K), 0.0173280 secs]

4852.094: [GC 4852.095: [DefNew: 212242K->2399K(235968K), 0.0164590 secs] 248459K->38641K(1202624K), 0.0165070 secs]

4949.037: [GC 4949.037: [DefNew: 212191K->2327K(235968K), 0.0174160 secs] 248433K->38705K(1202624K), 0.0174630 secs]

5044.327: [GC 5044.327: [DefNew: 212119K->2423K(235968K), 0.0169100 secs] 248497K->38802K(1202624K), 0.0169780 secs]

5120.605: [GC 5120.605: [DefNew: 212215K->2368K(235968K), 0.0166040 secs] 248594K->38753K(1202624K), 0.0166520 secs]

5205.686: [GC 5205.686: [DefNew: 212160K->2231K(235968K), 0.0170860 secs] 248545K->38771K(1202624K), 0.0171530 secs]

5300.439: [GC 5300.439: [DefNew: 212023K->2859K(235968K), 0.0243270 secs] 248563K->39429K(1202624K), 0.0243770 secs]

5387.079: [GC 5387.079: [DefNew: 212651K->2836K(235968K), 0.0195600 secs] 249221K->39457K(1202624K), 0.0196050 secs]

5488.546: [GC 5488.546: [DefNew: 212628K->3018K(235968K), 0.0209390 secs] 249249K->39644K(1202624K), 0.0209870 secs]

5575.905: [GC 5575.905: [DefNew: 212810K->2420K(235968K), 0.0201850 secs] 249436K->39543K(1202624K), 0.0202370 secs]

5685.494: [GC 5685.494: [DefNew: 212212K->2500K(235968K), 0.0189770 secs] 249334K->39622K(1202624K), 0.0190440 secs]

5780.607: [GC 5780.607: [DefNew: 212292K->2356K(235968K), 0.0186670 secs] 249414K->39512K(1202624K), 0.0187160 secs]

5886.376: [GC 5886.376: [DefNew: 212148K->1946K(235968K), 0.0182750 secs] 249304K->39438K(1202624K), 0.0183240 secs]

5965.605: [GC 5965.605: [DefNew: 211736K->1922K(235968K), 0.0172190 secs] 249229K->39436K(1202624K), 0.0172870 secs]

6059.595: [GC 6059.595: [DefNew: 211714K->1934K(235968K), 0.0168330 secs] 249228K->39452K(1202624K), 0.0169010 secs]

6094.181: [GC 6094.181: [DefNew: 211650K->1940K(235968K), 0.0135830 secs] 249168K->39463K(1202624K), 0.0136350 secs]

6094.422: [GC 6094.422: [DefNew: 211677K->2048K(235968K), 0.0110610 secs] 249200K->39582K(1202624K), 0.0111130 secs]

6094.670: [GC 6094.670: [DefNew: 211815K->1956K(235968K), 0.0110270 secs] 249349K->39514K(1202624K), 0.0110800 secs]

6094.933: [GC 6094.934: [DefNew: 211696K->2290K(235968K), 0.0115150 secs] 249253K->39848K(1202624K), 0.0115650 secs]

6095.207: [GC 6095.207: [DefNew: 212079K->2340K(235968K), 0.0113080 secs] 249637K->39903K(1202624K), 0.0113580 secs]

6095.488: [GC 6095.488: [DefNew: 212116K->2132K(235968K), 0.0110160 secs] 249678K->39697K(1202624K), 0.0110670 secs]

6095.778: [GC 6095.778: [DefNew: 211570K->2488K(235968K), 0.0114850 secs] 249135K->40058K(1202624K), 0.0115360 secs]

6096.080: [GC 6096.080: [DefNew: 212090K->2556K(235968K), 0.0117170 secs] 249660K->40127K(1202624K), 0.0117690 secs]

6096.388: [GC 6096.388: [DefNew: 212131K->2610K(235968K), 0.0115110 secs] 249702K->40190K(1202624K), 0.0115610 secs]

6096.705: [GC 6096.705: [DefNew: 212300K->2295K(235968K), 0.0112480 secs] 249880K->39876K(1202624K), 0.0113010 secs]

6097.026: [GC 6097.026: [DefNew: 211349K->2723K(235968K), 0.0116770 secs] 248929K->40308K(1202624K), 0.0117280 secs]

6097.351: [GC 6097.351: [DefNew: 212296K->2358K(235968K), 0.0111780 secs] 249881K->39949K(1202624K), 0.0112280 secs]

6097.680: [GC 6097.681: [DefNew: 212063K->2789K(235968K), 0.0119460 secs] 249654K->40414K(1202624K), 0.0119960 secs]

6098.018: [GC 6098.018: [DefNew: 212144K->2285K(235968K), 0.0121210 secs] 249770K->40020K(1202624K), 0.0121700 secs]

6098.363: [GC 6098.363: [DefNew: 211652K->2780K(235968K), 0.0114580 secs] 249386K->40514K(1202624K), 0.0115080 secs]

6098.705: [GC 6098.705: [DefNew: 211767K->2558K(235968K), 0.0122270 secs] 249502K->40560K(1202624K), 0.0122770 secs]

6099.053: [GC 6099.053: [DefNew: 212011K->2602K(235968K), 0.0102180 secs] 250013K->40605K(1202624K), 0.0102690 secs]

6099.397: [GC 6099.397: [DefNew: 211935K->2118K(235968K), 0.0096670 secs] 249938K->40141K(1202624K), 0.0097190 secs]

6099.741: [GC 6099.741: [DefNew: 211400K->2146K(235968K), 0.0095400 secs] 249423K->40169K(1202624K), 0.0095910 secs]

6100.088: [GC 6100.088: [DefNew: 211216K->2658K(235968K), 0.0106830 secs] 249239K->40734K(1202624K), 0.0107370 secs]

6100.440: [GC 6100.440: [DefNew: 212427K->2696K(235968K), 0.0101620 secs] 250503K->40774K(1202624K), 0.0102140 secs]

6100.794: [GC 6100.794: [DefNew: 212374K->2728K(235968K), 0.0100350 secs] 250451K->40814K(1202624K), 0.0100850 secs]

6101.146: [GC 6101.146: [DefNew: 211728K->2051K(235968K), 0.0122100 secs] 249814K->40852K(1202624K), 0.0122600 secs]

6101.506: [GC 6101.506: [DefNew: 211405K->2066K(235968K), 0.0064670 secs] 250207K->40891K(1202624K), 0.0065160 secs]

6101.853: [GC 6101.853: [DefNew: 211191K->2075K(235968K), 0.0059630 secs] 250016K->40926K(1202624K), 0.0060110 secs]

6102.202: [GC 6102.202: [DefNew: 211702K->2108K(235968K), 0.0059290 secs] 250553K->40962K(1202624K), 0.0059770 secs]

6102.554: [GC 6102.554: [DefNew: 210962K->2143K(235968K), 0.0058970 secs] 249816K->40999K(1202624K), 0.0059460 secs]

6102.904: [GC 6102.904: [DefNew: 210924K->2112K(235968K), 0.0062260 secs] 249780K->41033K(1202624K), 0.0062760 secs]

6103.265: [GC 6103.265: [DefNew: 211659K->2115K(235968K), 0.0058540 secs] 250580K->41070K(1202624K), 0.0058980 secs]

6103.614: [GC 6103.614: [DefNew: 210606K->2075K(235968K), 0.0058130 secs] 249561K->41100K(1202624K), 0.0058610 secs]

6103.965: [GC 6103.965: [DefNew: 211539K->2106K(235968K), 0.0059180 secs] 250564K->41134K(1202624K), 0.0059970 secs]

6104.316: [GC 6104.316: [DefNew: 211389K->2048K(235968K), 0.0057470 secs] 250417K->41166K(1202624K), 0.0057920 secs]

6104.665: [GC 6104.665: [DefNew: 211494K->1389K(235968K), 0.0044120 secs] 250612K->40507K(1202624K), 0.0044580 secs]

6105.014: [GC 6105.014: [DefNew: 210891K->1411K(235968K), 0.0044220 secs] 250009K->40529K(1202624K), 0.0044670 secs]

6105.365: [GC 6105.365: [DefNew: 210573K->2144K(235968K), 0.0054230 secs] 249691K->41262K(1202624K), 0.0054710 secs]

6105.718: [GC 6105.718: [DefNew: 211720K->1452K(235968K), 0.0045990 secs] 250839K->40570K(1202624K), 0.0046460 secs]

6106.066: [GC 6106.067: [DefNew: 210185K->2204K(235968K), 0.0054030 secs] 249303K->41323K(1202624K), 0.0054480 secs]

6106.415: [GC 6106.415: [DefNew: 210836K->2234K(235968K), 0.0055360 secs] 249955K->41352K(1202624K), 0.0055850 secs]

6106.767: [GC 6106.767: [DefNew: 211680K->2263K(235968K), 0.0053840 secs] 250798K->41381K(1202624K), 0.0054300 secs]

6107.117: [GC 6107.117: [DefNew: 211333K->2292K(235968K), 0.0053850 secs] 250451K->41410K(1202624K), 0.0054280 secs]

6107.468: [GC 6107.468: [DefNew: 211318K->1550K(235968K), 0.0045530 secs] 250437K->40668K(1202624K), 0.0045990 secs]

6107.820: [GC 6107.820: [DefNew: 210453K->2349K(235968K), 0.0055510 secs] 249571K->41468K(1202624K), 0.0055970 secs]

6108.172: [GC 6108.172: [DefNew: 211937K->1587K(235968K), 0.0045820 secs] 251055K->40705K(1202624K), 0.0046270 secs]

6108.529: [GC 6108.529: [DefNew: 211129K->2407K(235968K), 0.0056960 secs] 250247K->41525K(1202624K), 0.0057570 secs]

6108.882: [GC 6108.882: [DefNew: 211267K->2433K(235968K), 0.0057660 secs] 250385K->41552K(1202624K), 0.0058190 secs]

6109.237: [GC 6109.237: [DefNew: 212145K->1642K(235968K), 0.0047590 secs] 251264K->40761K(1202624K), 0.0048060 secs]

6109.585: [GC 6109.585: [DefNew: 209977K->2485K(235968K), 0.0055810 secs] 249095K->41604K(1202624K), 0.0056270 secs]

6109.941: [GC 6109.941: [DefNew: 212101K->1677K(235968K), 0.0048170 secs] 251220K->40796K(1202624K), 0.0048660 secs]

6110.290: [GC 6110.290: [DefNew: 210924K->1694K(235968K), 0.0046390 secs] 250044K->40813K(1202624K), 0.0046840 secs]

6110.641: [GC 6110.641: [DefNew: 209873K->2565K(235968K), 0.0059100 secs] 248992K->41684K(1202624K), 0.0059730 secs]

6111.000: [GC 6111.000: [DefNew: 211610K->1730K(235968K), 0.0049510 secs] 250729K->40850K(1202624K), 0.0050000 secs]

6111.354: [GC 6111.354: [DefNew: 210967K->2615K(235968K), 0.0059760 secs] 250086K->41735K(1202624K), 0.0060480 secs]

6111.706: [GC 6111.706: [DefNew: 212397K->2640K(235968K), 0.0058110 secs] 251516K->41759K(1202624K), 0.0058730 secs]

6112.060: [GC 6112.060: [DefNew: 212409K->2697K(235968K), 0.0060060 secs] 251528K->41816K(1202624K), 0.0060530 secs]

6112.411: [GC 6112.411: [DefNew: 211431K->2690K(235968K), 0.0059320 secs] 250550K->41809K(1202624K), 0.0059770 secs]

6112.767: [GC 6112.767: [DefNew: 211292K->2716K(235968K), 0.0060670 secs] 250412K->41835K(1202624K), 0.0061310 secs]

6113.121: [GC 6113.121: [DefNew: 211158K->2739K(235968K), 0.0061090 secs] 250277K->41859K(1202624K), 0.0061570 secs]

6113.477: [GC 6113.477: [DefNew: 212371K->2763K(235968K), 0.0060200 secs] 251490K->41883K(1202624K), 0.0060850 secs]

6113.828: [GC 6113.828: [DefNew: 210707K->2786K(235968K), 0.0060120 secs] 249826K->41906K(1202624K), 0.0060720 secs]

6114.185: [GC 6114.186: [DefNew: 212098K->1877K(235968K), 0.0050330 secs] 251218K->40996K(1202624K), 0.0050810 secs]

6114.538: [GC 6114.538: [DefNew: 209961K->2834K(235968K), 0.0061270 secs] 249080K->41953K(1202624K), 0.0061740 secs]

6114.889: [GC 6114.889: [DefNew: 210769K->2857K(235968K), 0.0060710 secs] 249889K->41976K(1202624K), 0.0061200 secs]

6115.243: [GC 6115.243: [DefNew: 211718K->1922K(235968K), 0.0050970 secs] 250837K->41042K(1202624K), 0.0051430 secs]

6115.594: [GC 6115.594: [DefNew: 211133K->2901K(235968K), 0.0061600 secs] 250253K->42021K(1202624K), 0.0062240 secs]

6115.947: [GC 6115.947: [DefNew: 212598K->2924K(235968K), 0.0061980 secs] 251717K->42044K(1202624K), 0.0062600 secs]

6116.298: [GC 6116.298: [DefNew: 211044K->2946K(235968K), 0.0061780 secs] 250164K->42066K(1202624K), 0.0062410 secs]

6116.650: [GC 6116.650: [DefNew: 212150K->1981K(235968K), 0.0050430 secs] 251271K->41101K(1202624K), 0.0051090 secs]

...

8573.433: [GC 8573.433: [DefNew: 216844K->9856K(235968K), 0.0388220 secs] 748207K->560933K(1202624K), 0.0388640 secs]

8573.808: [GC 8573.808: [DefNew: 216860K->9857K(235968K), 0.0390080 secs] 767937K->580649K(1202624K), 0.0390510 secs]

8574.183: [GC 8574.184: [DefNew: 216876K->9858K(235968K), 0.0397220 secs] 787668K->600367K(1202624K), 0.0397640 secs]

8574.559: [GC 8574.559: [DefNew: 216892K->9859K(235968K), 0.0391420 secs] 807401K->620085K(1202624K), 0.0391830 secs]

8574.935: [GC 8574.935: [DefNew: 216909K->9859K(235968K), 0.0401090 secs] 827135K->639806K(1202624K), 0.0401520 secs]

8575.323: [GC 8575.323: [DefNew: 216925K->9860K(235968K), 0.0392600 secs] 846871K->659527K(1202624K), 0.0393080 secs]

8575.701: [GC 8575.701: [DefNew: 216941K->9861K(235968K), 0.0456310 secs] 866608K->679251K(1202624K), 0.0457000 secs]

8576.083: [GC 8576.083: [DefNew: 216957K->9862K(235968K), 0.0399820 secs] 886347K->698975K(1202624K), 0.0400450 secs]

8576.460: [GC 8576.460: [DefNew: 216974K->9862K(235968K), 0.0407330 secs] 906087K->718701K(1202624K), 0.0407900 secs]

8576.837: [GC 8576.837: [DefNew: 216990K->9863K(235968K), 0.0411830 secs] 925829K->738429K(1202624K), 0.0412240 secs]

8577.215: [GC 8577.215: [DefNew: 217006K->9864K(235968K), 0.0435720 secs] 945572K->758158K(1202624K), 0.0436260 secs]

8577.595: [GC 8577.595: [DefNew: 217022K->9865K(235968K), 0.0396870 secs] 965317K->777889K(1202624K), 0.0397290 secs]

8577.971: [GC 8577.971: [DefNew: 217039K->217039K(235968K), 0.0000190 secs]8577.971: [Tenured: 768024K->68594K(966656K), 0.4244010 secs] 985063K->68594K(1202624K

), 0.4244860 secs]

8578.733: [GC 8578.733: [DefNew: 207189K->19731K(235968K), 0.0609250 secs] 275784K->117925K(1202624K), 0.0609690 secs]

8579.130: [GC 8579.130: [DefNew: 226936K->9867K(235968K), 0.0602940 secs] 325130K->147527K(1202624K), 0.0603350 secs]

8579.527: [GC 8579.527: [DefNew: 217087K->9868K(235968K), 0.0365640 secs] 354747K->167263K(1202624K), 0.0366090 secs]

8579.900: [GC 8579.900: [DefNew: 217104K->9868K(235968K), 0.0383320 secs] 374499K->187001K(1202624K), 0.0383750 secs]

8580.276: [GC 8580.276: [DefNew: 217120K->9869K(235968K), 0.0383440 secs] 394253K->206741K(1202624K), 0.0383860 secs]

8580.651: [GC 8580.651: [DefNew: 217136K->9870K(235968K), 0.0376040 secs] 414008K->226481K(1202624K), 0.0376460 secs]

8581.025: [GC 8581.026: [DefNew: 217152K->9871K(235968K), 0.0383670 secs] 433764K->246224K(1202624K), 0.0384110 secs]

8581.400: [GC 8581.400: [DefNew: 217169K->9871K(235968K), 0.0377040 secs] 453522K->265968K(1202624K), 0.0377480 secs]

8581.775: [GC 8581.775: [DefNew: 217185K->9872K(235968K), 0.0383920 secs] 473281K->285713K(1202624K), 0.0384340 secs]

8582.150: [GC 8582.150: [DefNew: 217201K->9873K(235968K), 0.0383650 secs] 493042K->305460K(1202624K), 0.0384060 secs]

8582.527: [GC 8582.527: [DefNew: 217217K->9873K(235968K), 0.0381910 secs] 512804K->325208K(1202624K), 0.0382350 secs]

8582.902: [GC 8582.902: [DefNew: 217233K->9874K(235968K), 0.0379350 secs] 532568K->344958K(1202624K), 0.0379790 secs]

8583.277: [GC 8583.277: [DefNew: 217250K->9875K(235968K), 0.0384100 secs] 552334K->364709K(1202624K), 0.0384520 secs]

8583.652: [GC 8583.652: [DefNew: 217266K->9876K(235968K), 0.0384750 secs] 572100K->384462K(1202624K), 0.0385160 secs]

8584.028: [GC 8584.028: [DefNew: 217282K->9876K(235968K), 0.0384640 secs] 591869K->404216K(1202624K), 0.0385090 secs]

8584.406: [GC 8584.406: [DefNew: 217298K->9877K(235968K), 0.0384900 secs] 611638K->423972K(1202624K), 0.0385330 secs]

8584.781: [GC 8584.782: [DefNew: 217315K->9878K(235968K), 0.0392630 secs] 631409K->443729K(1202624K), 0.0393050 secs]

8585.158: [GC 8585.158: [DefNew: 217331K->9879K(235968K), 0.0384030 secs] 651182K->463488K(1202624K), 0.0384450 secs]

8585.534: [GC 8585.534: [DefNew: 217347K->9879K(235968K), 0.0390440 secs] 670956K->483248K(1202624K), 0.0390860 secs]

8585.911: [GC 8585.911: [DefNew: 217363K->9880K(235968K), 0.0386250 secs] 690732K->503009K(1202624K), 0.0386680 secs]

8586.287: [GC 8586.287: [DefNew: 217380K->9881K(235968K), 0.0395520 secs] 710509K->522772K(1202624K), 0.0396100 secs]

8586.663: [GC 8586.664: [DefNew: 217396K->9882K(235968K), 0.0389580 secs] 730288K->542537K(1202624K), 0.0390150 secs]

8587.040: [GC 8587.040: [DefNew: 217412K->9882K(235968K), 0.0388730 secs] 750068K->562303K(1202624K), 0.0389330 secs]

8587.417: [GC 8587.417: [DefNew: 217428K->9883K(235968K), 0.0388700 secs] 769849K->582070K(1202624K), 0.0389340 secs]

8587.794: [GC 8587.794: [DefNew: 217445K->9884K(235968K), 0.0389560 secs] 789632K->601839K(1202624K), 0.0390230 secs]

8588.170: [GC 8588.170: [DefNew: 217461K->9885K(235968K), 0.0395250 secs] 809417K->621610K(1202624K), 0.0395840 secs]

8588.547: [GC 8588.547: [DefNew: 217477K->9885K(235968K), 0.0395990 secs] 829203K->641382K(1202624K), 0.0396540 secs]

8588.925: [GC 8588.925: [DefNew: 217493K->9886K(235968K), 0.0397540 secs] 848990K->661155K(1202624K), 0.0398140 secs]

8589.303: [GC 8589.303: [DefNew: 217510K->9887K(235968K), 0.0403830 secs] 868779K->680930K(1202624K), 0.0404460 secs]

8589.681: [GC 8589.681: [DefNew: 217526K->9887K(235968K), 0.0414050 secs] 888569K->700706K(1202624K), 0.0414830 secs]

8590.062: [GC 8590.062: [DefNew: 217542K->9888K(235968K), 0.0406820 secs] 908361K->720484K(1202624K), 0.0407420 secs]

8590.440: [GC 8590.440: [DefNew: 217558K->9889K(235968K), 0.0419700 secs] 928154K->740264K(1202624K), 0.0420280 secs]

8590.820: [GC 8590.820: [DefNew: 217575K->9890K(235968K), 0.0403670 secs] 947949K->760044K(1202624K), 0.0404310 secs]

8591.197: [GC 8591.197: [DefNew: 217591K->217591K(235968K), 0.0000200 secs]8591.197: [Tenured: 750154K->68660K(966656K), 0.4285270 secs] 967746K->68660K(1202624K

), 0.4286290 secs]

8591.963: [GC 8591.963: [DefNew: 207716K->19781K(235968K), 0.0610030 secs] 276377K->118117K(1202624K), 0.0610610 secs]

8592.365: [GC 8592.365: [DefNew: 227513K->9892K(235968K), 0.0611000 secs] 325849K->147794K(1202624K), 0.0611670 secs]

8592.767: [GC 8592.767: [DefNew: 217640K->9893K(235968K), 0.0366790 secs] 355541K->167580K(1202624K), 0.0367400 secs]

8593.142: [GC 8593.142: [DefNew: 217656K->9893K(235968K), 0.0381440 secs] 375343K->187368K(1202624K), 0.0382010 secs]

8593.526: [GC 8593.526: [DefNew: 217672K->9894K(235968K), 0.0395870 secs] 395147K->207158K(1202624K), 0.0396530 secs]

8593.905: [GC 8593.905: [DefNew: 217688K->9895K(235968K), 0.0381590 secs] 414952K->226949K(1202624K), 0.0382240 secs]

8594.292: [GC 8594.292: [DefNew: 217705K->9896K(235968K), 0.0388760 secs] 434759K->246742K(1202624K), 0.0389360 secs]

8594.668: [GC 8594.668: [DefNew: 217721K->9896K(235968K), 0.0381550 secs] 454567K->266536K(1202624K), 0.0382140 secs]

8595.044: [GC 8595.044: [DefNew: 217737K->9897K(235968K), 0.0383560 secs] 474377K->286331K(1202624K), 0.0384160 secs]

8595.422: [GC 8595.423: [DefNew: 217753K->9898K(235968K), 0.0381780 secs] 494188K->306128K(1202624K), 0.0382360 secs]

8595.799: [GC 8595.799: [DefNew: 217769K->9899K(235968K), 0.0385220 secs] 514000K->325927K(1202624K), 0.0385800 secs]

8596.175: [GC 8596.175: [DefNew: 217786K->9899K(235968K), 0.0385130 secs] 533814K->345727K(1202624K), 0.0385810 secs]

8596.586: [GC 8596.586: [DefNew: 217802K->9900K(235968K), 0.0418120 secs] 553630K->365528K(1202624K), 0.0418780 secs]

8597.005: [GC 8597.005: [DefNew: 217818K->9901K(235968K), 0.0428970 secs] 573447K->385331K(1202624K), 0.0429480 secs]

8597.438: [GC 8597.438: [DefNew: 217834K->9902K(235968K), 0.0424670 secs] 593265K->405136K(1202624K), 0.0425370 secs]

8597.865: [GC 8597.865: [DefNew: 217851K->9902K(235968K), 0.0437990 secs] 613085K->424942K(1202624K), 0.0438640 secs]

[26152 byte] By [AXUa] at [2007-10-3 8:54:56]
# 1
The JVM options are as follow:JAVA_OPTS_STARTUP="-Dmgr.name=rbcs_tomcat -Xms1200m -Xmx1200m -verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -XX:NewSize=256m -XX:MaxNewSize=256m -XX:PermSize=192m -XX:MaxPermSize=256m"Thanks,-Alan
AXUa at 2007-7-15 4:05:00 > top of Java-index,Java HotSpot Virtual Machine,HotSpot Internals...
# 2

The memory allocation rate of your program appears to be higher towards the

end than it was towards the start of the GC log snippet that you posted.

Do you expect the memory allocation rate to be steady through the

length of the application execution sequence that the GC log represents?

ramki_at_jdca at 2007-7-15 4:05:00 > top of Java-index,Java HotSpot Virtual Machine,HotSpot Internals...
# 3

In case anyone's wondering, this is caused by an ill-fated routine that gets into an infinite loop while doing string concatenation. The infinite loop only occurs when certain UserAgent is present, thus explaining the unpredictability of the problem.

The problem was detected when performing a Java Thread Dump on the JVM once the JVM gets into that fanatic state of Garbage Collection.

-Alan

AXUa at 2007-7-15 4:05:00 > top of Java-index,Java HotSpot Virtual Machine,HotSpot Internals...
# 4

To answer your question, Ramki. The memory usage pattern should be consistent with number of requests we receive through Tomcat container. So, it should be steady throughout unless you run into traffic spikes, which are rare. The consistent behavior of higher memory consumption towards the end is the result of StringBuffer expansion in an infinite loop when certain UserAgent string is encountered.

See my posting moments ago about what the problem was and how it was detected.

Thanks for responding to my posting.

AXUa at 2007-7-15 4:05:00 > top of Java-index,Java HotSpot Virtual Machine,HotSpot Internals...