Using ParralelOldGC and ParralelGC
I have a java process that is configured with a 240gb heap.... and I have ParallelGCThreads set to 3, and I am specifying both UseParallelGC and UseParallelOldGC. The hardware we are running this on an intel based 4 CPU machine running RHEL.
When I look at the verbosegc output, I have 2 concerns/questions.
1) We are occasionally taking full gc's and when that happens they run for a long time (10 minutes on some occasions).
2) The partial GC's that we are taking appear to be running long to me...but I'm not sure what I should really be expecting for a heap of 240gb. We are definitely not achieving the throughput rates that we want so I'm hoping that there is some way I can reduce the time we are spending in garbage collection and get it back for application work.
Any pointers/observations or suggestions would be greatly appreciated.
Here's a sample of my verbosegc output:
2011-01-03T15:51:39.784-0500: 46.579: [GC [PSYoungGen: 31457280K->4730908K(36700160K)] 31457280K->4730908K(120586240K), 8.9799490 secs] [Times: user=18.57 sys=8.09, real=8.98 secs]
2011-01-03T15:52:27.841-0500: 94.635: [GC [PSYoungGen: 36188188K->5242872K(68157440K)] 36188188K->6546637K(152043520K), 13.4955750 secs] [Times: user=29.21 sys=11.25, real=13.49 secs]
2011-01-03T15:54:09.351-0500: 196.145: [GC [PSYoungGen: 68157432K->5242876K(68157440K)] 69461197K->9756480K(152043520K), 17.7561810 secs] [Times: user=38.65 sys=14.51, real=17.75 secs]
2011-01-03T15:55:31.959-0500: 278.753: [GC [PSYoungGen: 68157436K->5242848K(78643200K)] 72671040K->13141661K(162529280K), 18.5794050 secs] [Times: user=40.76 sys=14.94, real=18.58 secs]
2011-01-03T15:57:01.552-0500: 368.346: [GC [PSYoungGen: 78637454K->5242871K(78643200K)] 86536267K->16226676K(162529280K), 16.5468740 secs] [Times: user=35.36 sys=14.24, real=16.54 secs]
2011-01-03T15:59:02.195-0500: 488.989: [GC [PSYoungGen: 78643191K->5242863K(67652992K)] 89626996K->19602201K(151539072K), 16.1007120 secs] [Times: user=42.35 sys=5.92, real=16.10 secs]
2011-01-03T16:06:14.486-0500: 921.280: [GC [PSYoungGen: 67652975K->8480188K(70890304K)] 82012313K->23713078K(154776384K), 15.8192270 secs] [Times: user=46.03 sys=1.24, real=15.82 secs]
2011-01-03T16:10:11.617-0500: 1158.411: [GC [PSYoungGen: 70890300K->9422078K(72334848K)] 86123190K->25782995K(156220928K), 18.4675290 secs] [Times: user=53.59 sys=1.79, real=18.47 secs]
2011-01-03T16:14:00.334-0500: 1387.129: [GC [PSYoungGen: 70994558K->8248990K(72729280K)] 87355475K->27879488K(156615360K), 21.0684600 secs] [Times: user=57.58 sys=5.29, real=21.07 secs]
2011-01-03T16:18:40.039-0500: 1666.834: [GC [PSYoungGen: 69821470K->4692571K(72448192K)] 89451968K->30545511K(156334272K), 23.0162290 secs] [Times: user=58.09 sys=10.91, real=23.02 secs]
2011-01-03T16:24:35.046-0500: 2021.840: [GC [PSYoungGen: 66195419K->3059840K(64562688K)] 92048359K->33653182K(148448768K), 16.4994020 secs] [Times: user=40.79 sys=8.62, real=16.50 secs]
2011-01-03T16:29:25.540-0500: 2312.335: [GC [PSYoungGen: 64562688K->2320708K(71534528K)] 95156030K->36005427K(155420608K), 12.4523940 secs] [Times: user=31.58 sys=5.38, real=12.46 secs]
2011-01-03T16:33:30.392-0500: 2557.186: [GC [PSYoungGen: 62251588K->2002304K(61933184K)] 95936307K->38033723K(145819264K), 10.2205470 secs] [Times: user=25.97 sys=4.07, real=10.23 secs]
2011-01-03T16:37:39.905-0500: 2806.699: [GC [PSYoungGen: 61933184K->1934784K(71407808K)] 97964603K->39991211K(155293888K), 9.3960420 secs] [Times: user=23.83 sys=3.52, real=9.39 secs]
2011-01-03T16:41:41.675-0500: 3048.469: [GC [PSYoungGen: 61104576K->1996992K(71527936K)] 99161003K->42009523K(155414016K), 9.2863410 secs] [Times: user=23.97 sys=3.41, real=9.28 secs]
2011-01-03T16:45:28.035-0500: 3274.830: [GC [PSYoungGen: 61166784K->2031264K(71263488K)] 101179315K->44063051K(155149568K), 9.6486710 secs] [Times: user=24.76 sys=3.53, real=9.65 secs]
2011-01-03T16:47:46.577-0500: 3413.372: [GC [PSYoungGen: 61218592K->1848786K(71404480K)] 103250379K->45934853K(155290560K), 8.5717550 secs] [Times: user=22.09 sys=3.60, real=8.57 secs]
2011-01-03T16:48:29.744-0500: 3456.538: [GC [PSYoungGen: 61036114K->1651147K(71285184K)] 105122181K->47017572K(155171264K), 5.7034960 secs] [Times: user=14.85 sys=2.19, real=5.70 secs]
2011-01-03T16:49:10.195-0500: 3496.990: [GC [PSYoungGen: 61273739K->3001168K(71462144K)] 106640164K->48782519K(155348224K), 4.5926150 secs] [Times: user=12.90 sys=0.72, real=4.59 secs]
2011-01-03T16:49:48.826-0500: 3535.620: [GC [PSYoungGen: 62623760K->4278076K(70959424K)] 108405111K->50487040K(154845504K), 5.5550420 secs] [Times: user=15.67 sys=0.81, real=5.55 secs]
2011-01-03T16:50:31.769-0500: 3578.564: [GC [PSYoungGen: 64983932K->2546787K(71342016K)] 111192896K->49604598K(155228096K), 4.5551140 secs] [Times: user=12.21 sys=1.44, real=4.56 secs]
2011-01-03T16:51:32.272-0500: 3639.066: [GC [PSYoungGen: 63252643K->383021K(73237248K)] 110310454K->49809042K(157123328K), 4.4164960 secs] [Times: user=8.93 sys=4.17, real=4.42 secs]
2011-01-03T16:54:20.449-0500: 3807.243: [GC [PSYoungGen: 63336749K->611447K(73264896K)] 112762770K->50297100K(157150976K), 2.0226470 secs] [Times: user=5.41 sys=0.42, real=2.02 secs]
2011-01-03T17:25:54.744-0500: 5701.539: [GC [PSYoungGen: 63565175K->5458854K(73400064K)] 113250828K->55758490K(157286144K), 10.9277720 secs] [Times: user=31.76 sys=0.98, real=10.93 secs]
2011-01-03T18:32:05.880-0500: 9672.674: [GC [PSYoungGen: 68673702K->2776892K(65991744K)] 118973338K->58566237K(149877824K), 16.4304430 secs] [Times: user=39.36 sys=9.89, real=16.43 secs]
2011-01-03T18:37:29.010-0500: 9995.804: [GC [PSYoungGen: 65991740K->1151200K(73395648K)] 121781085K->59736558K(157281728K), 8.7055150 secs] [Times: user=20.64 sys=5.03, real=8.70 secs]
2011-01-03T18:42:28.630-0500: 10295.425: [GC [PSYoungGen: 64803680K->1140224K(73182272K)] 123389038K->60886774K(157068352K), 5.4813220 secs] [Times: user=13.60 sys=2.10, real=5.48 secs]
2011-01-03T18:47:33.260-0500: 10600.055: [GC [PSYoungGen: 64792704K->1168032K(74063872K)] 124539254K->62064630K(157949952K), 5.3663870 secs] [Times: user=13.56 sys=2.14, real=5.36 secs]
2011-01-03T18:53:16.314-0500: 10943.108: [GC [PSYoungGen: 66073568K->1244672K(73888128K)] 126970166K->63319390K(157774208K), 5.6129010 secs] [Times: user=14.30 sys=2.08, real=5.61 secs]
2011-01-03T18:58:28.164-0500: 11254.959: [GC [PSYoungGen: 66150208K->1171264K(74576128K)] 128224926K->64501678K(158462208K), 5.7922840 secs] [Times: user=14.38 sys=2.17, real=5.79 secs]
2011-01-03T19:03:49.426-0500: 11576.220: [GC [PSYoungGen: 67243776K->1171328K(74399680K)] 130574190K->65683110K(158285760K), 5.5302320 secs] [Times: user=14.01 sys=2.09, real=5.53 secs]
2011-01-03T19:09:12.114-0500: 11898.908: [GC [PSYoungGen: 67243840K->1201760K(75212800K)] 131755622K->66894958K(159098880K), 5.6979620 secs] [Times: user=14.27 sys=2.02, real=5.70 secs]
2011-01-03T19:13:43.085-0500: 12169.880: [GC [PSYoungGen: 68603168K->1671488K(75045760K)] 134296366K->68576806K(158931840K), 5.9593390 secs] [Times: user=15.75 sys=2.12, real=5.96 secs]
2011-01-03T19:46:35.848-0500: 14142.642: [GC [PSYoungGen: 61713695K->5059235K(75106880K)] 128619013K->73636268K(158992960K), 11.9338360 secs] [Times: user=33.10 sys=2.67, real=11.94 secs]
2011-01-03T19:46:47.782-0500: 14154.576: [Full GC (System) [PSYoungGen: 5059235K->0K(75106880K)] [ParOldGen: 68577032K->72694058K(83886080K)] 73636268K->72694058K(158992960K) [PSPermGen: 52623K->52453K(86016K)], 608.0433990 secs] [Times: user=1460.20 sys=12.01, real=608.04 secs]
2011-01-03T19:56:55.944-0500: 14762.738: [GC [PSYoungGen: 1945645K->64K(75650112K)] 74639704K->72694122K(159536192K), 0.6107920 secs] [Times: user=1.73 sys=0.00, real=0.61 secs]
2011-01-03T19:56:56.555-0500: 14763.349: [Full GC (System) [PSYoungGen: 64K->0K(75650112K)] [ParOldGen: 72694058K->72694029K(83886080K)] 72694122K->72694029K(159536192K) [PSPermGen: 52453K->52453K(86016K)], 333.3150130 secs] [Times: user=736.53 sys=121.68, real=333.31 secs]
2011-01-04T09:54:30.274-0500: 65017.068: [GC [PSYoungGen: 67887104K->7669301K(71417920K)] 140581133K->82912201K(155304000K), 13.2915200 secs] [Times: user=32.53 sys=7.32, real=13.29 secs]
2011-01-04T14:37:29.623-0500: 81996.417: [GC [PSYoungGen: 71417909K->2877K(73817344K)] 146660809K->82922731K(157703424K), 11.3929240 secs] [Times: user=21.01 sys=13.00, real=11.40 secs]
2011-01-04T14:37:41.016-0500: 82007.810: [Full GC [PSYoungGen: 2877K->0K(73817344K)] [ParOldGen: 82919853K->82895116K(129478272K)] 82922731K->82895116K(203295616K) [PSPermGen: 55591K->55507K(86016K)], 336.1626970 secs] [Times: user=773.17 sys=5.97, real=336.16 secs]
2011-01-04T14:54:07.171-0500: 82993.965: [GC [PSYoungGen: 63748608K->1917K(73152128K)] 146643724K->82897034K(202630400K), 0.7518040 secs] [Times: user=2.00 sys=0.05, real=0.75 secs]
2011-01-04T15:00:43.485-0500: 83390.279: [GC [PSYoungGen: 63929085K->3205K(73574016K)] 146824202K->82899583K(203052288K), 0.7096650 secs] [Times: user=2.02 sys=0.00, real=0.71 secs]
2011-01-04T15:06:05.796-0500: 83712.591: [GC [PSYoungGen: 63930373K->9358K(73446144K)] 146826751K->82905886K(202924416K), 0.7295230 secs] [Times: user=2.05 sys=0.03, real=0.73 secs]
2011-01-04T15:11:35.489-0500: 84042.283: [GC [PSYoungGen: 64895502K->9118K(73906752K)] 147792030K->82905750K(203385024K), 0.7091450 secs] [Times: user=2.05 sys=0.00, real=0.71 secs]
2011-01-04T15:19:06.789-0500: 84493.583: [GC [PSYoungGen: 64895262K->2686K(67379648K)] 147791894K->82899334K(196857920K), 0.9721790 secs] [Times: user=1.98 sys=0.29, real=0.97 secs]
2011-01-04T15:26:41.991-0500: 84948.785: [GC [PSYoungGen: 62891198K->1614K(60977408K)] 145787846K->82898262K(190455680K), 0.9268290 secs] [Times: user=2.00 sys=0.23, real=0.93 secs]
2011-01-04T15:37:27.280-0500: 85594.074: [GC [PSYoungGen: 60977358K->4499K(64421760K)] 143874006K->82901147K(193900032K), 0.9230310 secs] [Times: user=2.01 sys=0.22, real=0.92 secs]
2011-01-04T15:54:17.405-0500: 86604.199: [GC [PSYoungGen: 59148179K->2997K(57391360K)] 142044827K->82899644K(186869632K), 0.9227300 secs] [Times: user=2.00 sys=0.22, real=0.92 secs]
2011-01-04T16:04:07.522-0500: 87194.316: [GC [PSYoungGen: 57391349K->3461K(60354432K)] 140287996K->82900108K(189832704K), 0.9105900 secs] [Times: user=2.01 sys=0.20, real=0.91 secs]
2011-01-04T16:11:24.830-0500: 87631.624: [GC [PSYoungGen: 55709509K->5015K(54098240K)] 138606156K->82901662K(183576512K), 0.9046520 secs] [Times: user=2.01 sys=0.19, real=0.90 secs]
2011-01-04T16:19:39.373-0500: 88126.167: [GC [PSYoungGen: 54098199K->3526K(56590016K)] 136994846K->82900174K(186068288K), 0.8966710 secs] [Times: user=2.00 sys=0.19, real=0.90 secs]
2011-01-05T08:41:34.330-0500: 147041.124: [GC [PSYoungGen: 52549958K->3107057K(54169728K)] 135446606K->86003704K(183648000K), 6.4558930 secs] [Times: user=19.11 sys=0.08, real=6.46 secs]
2011-01-05T08:42:47.203-0500: 147113.998: [GC [PSYoungGen: 54169713K->6282170K(55928640K)] 137066360K->89220174K(185406912K), 11.9254630 secs] [Times: user=35.57 sys=0.07, real=11.92 secs]
2011-01-05T08:44:17.068-0500: 147203.862: [GC [PSYoungGen: 55928634K->7698358K(57344832K)] 138866638K->93065219K(186823104K), 19.5886700 secs] [Times: user=54.33 sys=4.35, real=19.59 secs]
2011-01-05T08:45:19.495-0500: 147266.289: [GC [PSYoungGen: 57328533K->10096291K(67648832K)] 142695394K->95464225K(197127104K), 18.3671070 secs] [Times: user=37.75 sys=17.18, real=18.36 secs]
2011-01-05T08:47:29.608-0500: 147396.402: [GC [PSYoungGen: 67506019K->12284524K(69694272K)] 152873953K->98750914K(199172544K), 23.7160870 secs] [Times: user=58.96 sys=12.13, real=23.72 secs]
2011-01-05T08:53:45.287-0500: 147772.081: [GC [PSYoungGen: 69694252K->14191792K(60375744K)] 156160642K->103697355K(189854016K), 31.0143930 secs] [Times: user=80.40 sys=12.39, real=31.01 secs]
2011-01-05T09:01:21.679-0500: 148228.473: [GC [PSYoungGen: 60375728K->11560432K(57744384K)] 149881291K->107132051K(187222656K), 33.1991630 secs] [Times: user=89.35 sys=10.05, real=33.20 secs]
2011-01-05T09:09:54.903-0500: 148741.698: [GC [PSYoungGen: 57744368K->10998084K(63269184K)] 153315987K->110495207K(192747456K), 27.4330280 secs] [Times: user=75.70 sys=6.34, real=27.44 secs]
2011-01-05T09:16:15.800-0500: 149122.594: [GC [PSYoungGen: 54520900K->6947684K(50470528K)] 154018023K->114175343K(179948800K), 31.5850420 secs] [Times: user=80.72 sys=13.44, real=31.59 secs]
2011-01-05T09:22:09.545-0500: 149476.339: [GC [PSYoungGen: 50470500K->3722112K(63629888K)] 157698159K->117971879K(193108160K), 25.4963290 secs] [Times: user=63.78 sys=12.24, real=25.49 secs]
2011-01-05T09:26:32.804-0500: 149739.598: [GC [PSYoungGen: 48408320K->4128995K(62901760K)] 162658087K->122134722K(192380032K), 17.4397520 secs] [Times: user=45.11 sys=6.59, real=17.45 secs]
2011-01-05T09:30:00.575-0500: 149947.369: [GC [PSYoungGen: 48815203K->4531552K(64818112K)] 166820930K->126697186K(194296384K), 18.9428470 secs] [Times: user=49.13 sys=6.99, real=18.94 secs]
2011-01-05T09:30:19.518-0500: 149966.312: [Full GC [PSYoungGen: 4531552K->0K(64818112K)] [ParOldGen: 122165634K->120345197K(167772160K)] 126697186K->120345197K(232590272K) [PSPermGen: 56395K->56393K(86016K)], 562.0673720 secs] [Times: user=1498.34 sys=4.93, real=562.06 secs]
2011-01-05T09:44:21.142-0500: 150807.936: [GC [PSYoungGen: 47579264K->2652853K(64138432K)] 167924461K->122998051K(231910592K), 5.3289190 secs] [Times: user=15.97 sys=0.00, real=5.33 secs]
2011-01-05T09:50:45.830-0500: 151192.625: [GC [PSYoungGen: 50232117K->2924926K(66734208K)] 170577315K->125944186K(234506368K), 11.4943810 secs] [Times: user=32.84 sys=1.37, real=11.49 secs]
2011-01-05T09:51:23.359-0500: 151230.153: [GC [PSYoungGen: 53591358K->1254701K(66155840K)] 176610618K->126896450K(233928000K), 8.4635760 secs] [Times: user=20.32 sys=4.36, real=8.46 secs]
2011-01-05T09:51:59.156-0500: 151265.950: [GC [PSYoungGen: 51921133K->2035502K(67873408K)] 177562882K->127941553K(235645568K), 3.7617910 secs] [Times: user=10.79 sys=0.47, real=3.77 secs]
2011-01-05T09:52:30.146-0500: 151296.940: [GC [PSYoungGen: 54887662K->2531923K(67508096K)] 180793713K->128842350K(235280256K), 4.1871660 secs] [Times: user=11.92 sys=0.64, real=4.18 secs]
2011-01-05T09:53:01.311-0500: 151328.105: [GC [PSYoungGen: 55216742K->2647403K(68581696K)] 181527168K->129627543K(236353856K), 5.1380600 secs] [Times: user=14.35 sys=1.05, real=5.14 secs]
2011-01-05T09:53:51.442-0500: 151378.236: [GC [PSYoungGen: 57504747K->1434299K(68230400K)] 184484887K->129917214K(236002560K), 5.2277040 secs] [Times: user=12.75 sys=2.52, real=5.23 secs]
2011-01-05T09:55:03.798-0500: 151450.592: [GC [PSYoungGen: 56291643K->274901K(69998784K)] 184774558K->130047398K(237770944K), 4.0594860 secs] [Times: user=7.54 sys=2.16, real=4.06 secs]
2011-01-05T11:24:10.866-0500: 156797.660: [GC [PSYoungGen: 57326869K->5836417K(69735488K)] 187099366K->135818370K(237507648K), 11.3222630 secs] [Times: user=33.30 sys=0.32, real=11.33 secs]
2011-01-05T11:30:51.949-0500: 157198.743: [GC [PSYoungGen: 62888385K->6130752K(70881536K)] 192870338K->141992931K(238653696K), 24.4142990 secs] [Times: user=62.47 sys=10.21, real=24.41 secs]