CPU differences and CMS GC performance

Thu Jan 6 15:53:52 UTC 2011

Craig,

Please send me a few of the ParNew collections for the old server after the
CMS sweep - after this point

2011-01-04T18:40:53.953-0500: 317402.005: [CMS-concurrent-sweep-start]
2011-01-04T18:40:57.534-0500: 317405.586: [CMS-concurrent-sweep: 
3.565/3.581 secs] [Times: user=4.90 sys=0.07, real=3.58 secs]
2011-01-04T18:40:57.535-0500: 317405.586: [CMS-concurrent-reset-start]
2011-01-04T18:40:57.595-0500: 317405.646: [CMS-concurrent-reset: 
0.060/0.060 secs] [Times: user=0.06 sys=0.00, real=0.06 secs]

Jon

On 01/05/11 08:37, craig yeldell wrote:
> I have a production environment that consists of two different 
> hardware configurations.  We have just replaced half our environment 
> with new  servers that have more RAM and different CPU's.  We left the 
> GC params the same,  the GC behavior has been quite surprising.  I 
> expected to see faster collections on the New and CMS due to the raw 
> cpu test results of the Nehalem, and this held true.  However I also 
> found fewer New collections, and increased CMS collections.
> In a nutshell, I assumed upgrading the CPU alone without touching the 
> GC args would result in improved GC performance.
>
>
> Java info:
>
> Java(TM) SE Runtime Environment (build 1.6.0_20-b02)
> Java HotSpot(TM) 64-Bit Server VM (build 16.3-b01, mixed mode)
> -server -Xmx2500m -Xms2500m -Dsun.rmi.dgc.client.gcInterval=3600000 
> -Dsun.rmi.dgc.server.gcInterval=3600000 -Xss256k 
> -XX:+DisableExplicitGC -XX:PermSize=384m -XX:MaxPermSize=384m 
> -XX:MaxNewSize=888m -XX:NewSize=888m -XX:ParallelGCThreads=6 
> -verbose:gc -Xloggc:vm01.gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps 
> -XX:+HeapDumpOnOutOfMemoryError -XX:+UseConcMarkSweepGC 
> -XX:+CMSClassUnloadingEnabled -XX:SurvivorRatio=4 -XX:+UseTLAB 
> -XX:+UseParNewGC -XX:+UseBiasedLocking -XX:TargetSurvivorRatio=75 
> -XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=80
>
> NOTE: Each server has 4 jvm's running and all vm's in the environment 
> are equally load balanced.
>
> CPU info:
>
> OLD
> 16GB
> CPU frequency:    3.003 GHz (Xeon)
> Number of CPUs: 4
> Number of cores: 8
> Number of threads: 16
>
> NEW
> *32GB*
> CPU frequency:    2.533 GHz (Xeon E5540 Nehalem)
> Number of CPUs: 2
> Number of cores: 8
> Number of threads: 16
>
> Example GC snippet:
>
> Old server:
> 2011-01-04T18:24:02.073-0500: 316390.125: [CMS-concurrent-reset: 
> 0.061/0.061 secs] [Times: user=0.06 sys=0.00, real=0.06 secs]
> 2011-01-04T18:24:12.890-0500: 316400.941: [GC 316400.942: [ParNew: 
> 690252K->93718K(757760K), 0.1300730 secs] 
> 1968696K->1372788K(2408448K), 0.1308690 secs] [Times: user=0.66 
> sys=0.00, real=0.13 secs]
> 2011-01-04T18:24:50.647-0500: 316438.698: [GC 316438.699: [ParNew: 
> 699926K->74785K(757760K), 0.1296920 secs] 
> 1978996K->1355277K(2408448K), 0.1304530 secs] [Times: user=0.61 
> sys=0.00, real=0.13 secs]
> 2011-01-04T18:25:17.854-0500: 316465.905: [GC 316465.906: [ParNew: 
> 680928K->86498K(757760K), 0.1505500 secs] 
> 1961420K->1369830K(2408448K), 0.1513450 secs] [Times: user=0.71 
> sys=0.00, real=0.15 secs]
> 2011-01-04T18:25:50.762-0500: 316498.814: [GC 316498.814: [ParNew: 
> 692706K->69120K(757760K), 0.1385690 secs] 
> 1976038K->1352581K(2408448K), 0.1393620 secs] [Times: user=0.63 
> sys=0.00, real=0.14 secs]
> 2011-01-04T18:26:22.644-0500: 316530.695: [GC 316530.696: [ParNew: 
> 675328K->86476K(757760K), 0.1493580 secs] 
> 1958789K->1372863K(2408448K), 0.1501220 secs] [Times: user=0.66 
> sys=0.00, real=0.15 secs]
> 2011-01-04T18:27:01.951-0500: 316570.003: [GC 316570.003: [ParNew: 
> 692684K->70259K(757760K), 0.1250090 secs] 
> 1979071K->1357514K(2408448K), 0.1257610 secs] [Times: user=0.62 
> sys=0.00, real=0.13 secs]
> 2011-01-04T18:27:28.542-0500: 316596.594: [GC 316596.594: [ParNew: 
> 676467K->88180K(757760K), 0.1030450 secs] 
> 1963722K->1375664K(2408448K), 0.1038090 secs] [Times: user=0.54 
> sys=0.00, real=0.10 secs]
> 2011-01-04T18:27:52.200-0500: 316620.251: [GC 316620.252: [ParNew: 
> 694388K->64015K(757760K), 0.1551250 secs] 
> 1981872K->1351774K(2408448K), 0.1560860 secs] [Times: user=0.79 
> sys=0.00, real=0.15 secs]
> 2011-01-04T18:28:07.789-0500: 316635.841: [GC 316635.841: [ParNew: 
> 670223K->94609K(757760K), 0.1321720 secs] 
> 1957982K->1385077K(2408448K), 0.1329350 secs] [Times: user=0.65 
> sys=0.01, real=0.13 secs]
> 2011-01-04T18:28:38.020-0500: 316666.071: [GC 316666.072: [ParNew: 
> 700817K->64339K(757760K), 0.1169430 secs] 
> 1991285K->1358764K(2408448K), 0.1177070 secs] [Times: user=0.59 
> sys=0.00, real=0.12 secs]
> 2011-01-04T18:29:13.319-0500: 316701.370: [GC 316701.371: [ParNew: 
> 670547K->75587K(757760K), 0.1352400 secs] 
> 1964972K->1370278K(2408448K), 0.1360140 secs] [Times: user=0.63 
> sys=0.00, real=0.13 secs]
> 2011-01-04T18:29:46.586-0500: 316734.637: [GC 316734.638: [ParNew: 
> 681795K->67573K(757760K), 0.1257050 secs] 
> 1976486K->1364337K(2408448K), 0.1265250 secs] [Times: user=0.56 
> sys=0.01, real=0.12 secs]
> 2011-01-04T18:30:31.525-0500: 316779.577: [GC 316779.578: [ParNew: 
> 673781K->65516K(757760K), 0.1143930 secs] 
> 1970545K->1363488K(2408448K), 0.1154980 secs] [Times: user=0.54 
> sys=0.00, real=0.12 secs]
> 2011-01-04T18:30:56.159-0500: 316804.211: [GC 316804.211: [ParNew: 
> 671724K->54331K(757760K), 0.1067750 secs] 
> 1969696K->1353537K(2408448K), 0.1075690 secs] [Times: user=0.53 
> sys=0.00, real=0.11 secs]
> 2011-01-04T18:32:01.256-0500: 316869.308: [GC 316869.308: [ParNew: 
> 660539K->66703K(757760K), 0.1036880 secs] 
> 1959745K->1367053K(2408448K), 0.1044590 secs] [Times: user=0.49 
> sys=0.00, real=0.11 secs]
> 2011-01-04T18:32:31.967-0500: 316900.019: [GC 316900.019: [ParNew: 
> 672911K->54742K(757760K), 0.1121020 secs] 
> 1973261K->1355232K(2408448K), 0.1128580 secs] [Times: user=0.51 
> sys=0.00, real=0.11 secs]
> 2011-01-04T18:33:05.187-0500: 316933.239: [GC 316933.239: [ParNew: 
> 660950K->66592K(757760K), 0.0990360 secs] 
> 1961440K->1368889K(2408448K), 0.0998210 secs] [Times: user=0.49 
> sys=0.00, real=0.10 secs]
> 2011-01-04T18:33:38.693-0500: 316966.745: [GC 316966.745: [ParNew: 
> 672800K->57860K(757760K), 0.1132210 secs] 
> 1975097K->1361914K(2408448K), 0.1139990 secs] [Times: user=0.53 
> sys=0.01, real=0.12 secs]
> 2011-01-04T18:34:33.087-0500: 317021.139: [GC 317021.139: [ParNew: 
> 664068K->74055K(757760K), 0.1268070 secs] 
> 1968122K->1379190K(2408448K), 0.1275670 secs] [Times: user=0.52 
> sys=0.00, real=0.12 secs]
> 2011-01-04T18:34:59.371-0500: 317047.423: [GC 317047.423: [ParNew: 
> 680263K->67454K(757760K), 0.1354760 secs] 
> 1985398K->1374886K(2408448K), 0.1363060 secs] [Times: user=0.61 
> sys=0.01, real=0.14 secs]
> 2011-01-04T18:35:23.757-0500: 317071.809: [GC 317071.809: [ParNew: 
> 673662K->78394K(757760K), 0.1624010 secs] 
> 1981094K->1385967K(2408448K), 0.1632150 secs] [Times: user=0.78 
> sys=0.00, real=0.17 secs]
> 2011-01-04T18:35:45.117-0500: 317093.169: [GC 317093.169: [ParNew: 
> 684602K->66073K(757760K), 0.1161380 secs] 
> 1992175K->1373969K(2408448K), 0.1170380 secs] [Times: user=0.60 
> sys=0.00, real=0.12 secs]
> 2011-01-04T18:36:29.794-0500: 317137.845: [GC 317137.846: [ParNew: 
> 672281K->97964K(757760K), 0.1333770 secs] 
> 1980177K->1406249K(2408448K), 0.1341740 secs] [Times: user=0.68 
> sys=0.00, real=0.13 secs]
> 2011-01-04T18:36:58.710-0500: 317166.762: [GC 317166.762: [ParNew: 
> 704172K->76194K(757760K), 0.1261530 secs] 
> 2012457K->1385682K(2408448K), 0.1269720 secs] [Times: user=0.64 
> sys=0.00, real=0.12 secs]
> 2011-01-04T18:37:27.242-0500: 317195.294: [GC 317195.294: [ParNew: 
> 682402K->88786K(757760K), 0.1270880 secs] 
> 1991890K->1399799K(2408448K), 0.1278570 secs] [Times: user=0.63 
> sys=0.00, real=0.13 secs]
> 2011-01-04T18:38:06.888-0500: 317234.940: [GC 317234.940: [ParNew: 
> 694994K->71919K(757760K), 0.1298460 secs] 
> 2006007K->1385713K(2408448K), 0.1305940 secs] [Times: user=0.63 
> sys=0.00, real=0.13 secs]
> 2011-01-04T18:38:27.888-0500: 317255.940: [GC 317255.941: [ParNew: 
> 678127K->94010K(757760K), 0.1288970 secs] 
> 1991921K->1410066K(2408448K), 0.1296270 secs] [Times: user=0.67 
> sys=0.00, real=0.13 secs]
> 2011-01-04T18:38:58.904-0500: 317286.956: [GC 317286.957: [ParNew: 
> 700218K->71826K(757760K), 0.1199630 secs] 
> 2016274K->1389379K(2408448K), 0.1207380 secs] [Times: user=0.63 
> sys=0.01, real=0.12 secs]
> 2011-01-04T18:39:21.896-0500: 317309.947: [GC 317309.948: [ParNew: 
> 678034K->89229K(757760K), 0.1211860 secs] 
> 1995587K->1407260K(2408448K), 0.1219360 secs] [Times: user=0.62 
> sys=0.00, real=0.12 secs]
> 2011-01-04T18:39:53.845-0500: 317341.897: [GC 317341.897: [ParNew: 
> 695437K->76437K(757760K), 0.1253990 secs] 
> 2013468K->1396004K(2408448K), 0.1261630 secs] [Times: user=0.67 
> sys=0.00, real=0.13 secs]
> 2011-01-04T18:40:18.938-0500: 317366.990: [GC 317366.990: [ParNew: 
> 682645K->91160K(757760K), 0.1523130 secs] 
> 2002212K->1410757K(2408448K), 0.1531110 secs] [Times: user=0.83 
> sys=0.01, real=0.15 secs]
> 2011-01-04T18:40:42.708-0500: 317390.760: [GC 317390.760: [ParNew: 
> 697002K->87022K(757760K), 0.1530570 secs] 
> 2016600K->1408083K(2408448K), 0.1538470 secs] [Times: user=0.71 
> sys=0.01, real=0.16 secs]
> 2011-01-04T18:40:42.867-0500: 317390.919: [GC [1 CMS-initial-mark: 
> 1321060K(1650688K)] 1408857K(2408448K), 0.2067320 secs] [Times: 
> user=0.21 sys=0.00, real=0.21 secs]
> 2011-01-04T18:40:43.075-0500: 317391.126: [CMS-concurrent-mark-start]
> 2011-01-04T18:40:47.573-0500: 317395.625: [CMS-concurrent-mark: 
> 4.486/4.499 secs] [Times: user=12.20 sys=0.13, real=4.50 secs]
> 2011-01-04T18:40:47.574-0500: 317395.625: [CMS-concurrent-preclean-start]
> 2011-01-04T18:40:47.636-0500: 317395.688: [CMS-concurrent-preclean: 
> 0.059/0.063 secs] [Times: user=0.06 sys=0.00, real=0.06 secs]
> 2011-01-04T18:40:47.637-0500: 317395.688: 
> [CMS-concurrent-abortable-preclean-start]
>  CMS: abort preclean due to time 2011-01-04T18:40:52.701-0500: 
> 317400.753: [CMS-concurrent-abortable-preclean: 4.139/5.065 secs] 
> [Times: user=5.46 sys=0.05, real=5.07 secs]
> 2011-01-04T18:40:52.707-0500: 317400.758: [GC[YG occupancy: 432613 K 
> (757760 K)]317400.759: [Rescan (parallel) , 0.9054620 secs]317401.664: 
> [weak refs processing, 0.0017920 secs]317401.666: [class unloading, 
> 0.1888550 secs]317401.855: [scrub symbol & string tables, 0.1271210 
> secs] [1 CMS-remark: 1321060K(1650688K)] 1753674K(2408448K), 1.2454560 
> secs] [Times: user=5.33 sys=0.02, real=1.25 secs]
> 2011-01-04T18:40:53.953-0500: 317402.005: [CMS-concurrent-sweep-start]
> 2011-01-04T18:40:57.534-0500: 317405.586: [CMS-concurrent-sweep: 
> 3.565/3.581 secs] [Times: user=4.90 sys=0.07, real=3.58 secs]
> 2011-01-04T18:40:57.535-0500: 317405.586: [CMS-concurrent-reset-start]
> 2011-01-04T18:40:57.595-0500: 317405.646: [CMS-concurrent-reset: 
> 0.060/0.060 secs] [Times: user=0.06 sys=0.00, real=0.06 secs]
>
> New Server
> 2011-01-04T18:33:40.473-0500: 223993.306: [CMS-concurrent-reset: 
> 0.004/0.004 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
> 2011-01-04T18:33:54.357-0500: 224007.190: [GC 224007.190: [ParNew: 
> 719918K->130085K(757760K), 0.0754960 secs] 
> 2004520K->1415071K(2408448K), 0.0758300 secs] [Times: user=0.42 
> sys=0.00, real=0.07 secs]
> 2011-01-04T18:34:47.106-0500: 224059.939: [GC 224059.939: [ParNew: 
> 736293K->107200K(757760K), 0.0819180 secs] 
> 2021279K->1393051K(2408448K), 0.0822590 secs] [Times: user=0.45 
> sys=0.00, real=0.08 secs]
> 2011-01-04T18:35:07.057-0500: 224079.891: [GC 224079.891: [ParNew: 
> 713408K->134972K(757760K), 0.0886030 secs] 
> 1999259K->1421467K(2408448K), 0.0889400 secs] [Times: user=0.42 
> sys=0.00, real=0.09 secs]
> 2011-01-04T18:35:41.454-0500: 224114.287: [GC 224114.288: [ParNew: 
> 741180K->117493K(757760K), 0.0785680 secs] 
> 2027675K->1404100K(2408448K), 0.0789010 secs] [Times: user=0.44 
> sys=0.00, real=0.08 secs]
> 2011-01-04T18:36:07.806-0500: 224140.640: [GC 224140.640: [ParNew: 
> 723701K->139373K(757760K), 0.0919290 secs] 
> 2010308K->1426255K(2408448K), 0.0922630 secs] [Times: user=0.49 
> sys=0.00, real=0.10 secs]
> 2011-01-04T18:36:40.539-0500: 224173.372: [GC 224173.372: [ParNew: 
> 745581K->118113K(757760K), 0.0912580 secs] 
> 2032463K->1405613K(2408448K), 0.0916060 secs] [Times: user=0.49 
> sys=0.00, real=0.09 secs]
> 2011-01-04T18:37:02.915-0500: 224195.748: [GC 224195.748: [ParNew: 
> 724321K->145077K(757760K), 0.0928130 secs] 
> 2011821K->1434160K(2408448K), 0.0931450 secs] [Times: user=0.48 
> sys=0.00, real=0.09 secs]
> 2011-01-04T18:37:22.451-0500: 224215.284: [GC 224215.284: [ParNew: 
> 751285K->107168K(757760K), 0.0779940 secs] 
> 2040368K->1399901K(2408448K), 0.0783240 secs] [Times: user=0.40 
> sys=0.00, real=0.08 secs]
> 2011-01-04T18:37:53.390-0500: 224246.223: [GC 224246.223: [ParNew: 
> 713376K->123307K(757760K), 0.0920660 secs] 
> 2006109K->1418928K(2408448K), 0.0924470 secs] [Times: user=0.45 
> sys=0.00, real=0.10 secs]
> 2011-01-04T18:38:16.100-0500: 224268.934: [GC 224268.934: [ParNew: 
> 729515K->105143K(757760K), 0.0863940 secs] 
> 2025136K->1402705K(2408448K), 0.0867110 secs] [Times: user=0.43 
> sys=0.00, real=0.09 secs]
> 2011-01-04T18:38:30.499-0500: 224283.332: [GC 224283.333: [ParNew: 
> 711351K->127726K(757760K), 0.0918920 secs] 
> 2008913K->1426844K(2408448K), 0.0922350 secs] [Times: user=0.48 
> sys=0.00, real=0.09 secs]
> 2011-01-04T18:39:09.092-0500: 224321.925: [GC 224321.926: [ParNew: 
> 733934K->106828K(757760K), 0.0962380 secs] 
> 2033052K->1408490K(2408448K), 0.0965730 secs] [Times: user=0.51 
> sys=0.00, real=0.10 secs]
> 2011-01-04T18:39:36.359-0500: 224349.192: [GC 224349.192: [ParNew: 
> 713036K->110615K(757760K), 0.0924370 secs] 
> 2014698K->1413885K(2408448K), 0.0927620 secs] [Times: user=0.49 
> sys=0.00, real=0.09 secs]
> 2011-01-04T18:39:41.489-0500: 224354.322: [GC 224354.322: [ParNew: 
> 716823K->130526K(757760K), 0.1148370 secs] 
> 2020093K->1435557K(2408448K), 0.1152070 secs] [Times: user=0.51 
> sys=0.00, real=0.11 secs]
> 2011-01-04T18:39:58.265-0500: 224371.099: [GC 224371.099: [ParNew: 
> 736734K->112410K(757760K), 0.1139600 secs] 
> 2041765K->1421693K(2408448K), 0.1143070 secs] [Times: user=0.59 
> sys=0.00, real=0.11 secs]
> 2011-01-04T18:40:22.876-0500: 224395.709: [GC 224395.709: [ParNew: 
> 718618K->151551K(757760K), 0.1168680 secs] 
> 2027901K->1464667K(2408448K), 0.1172010 secs] [Times: user=0.58 
> sys=0.00, real=0.12 secs]
> 2011-01-04T18:40:41.288-0500: 224414.121: [GC 224414.121: [ParNew: 
> 757759K->131092K(757760K), 0.1072970 secs] 
> 2070875K->1445457K(2408448K), 0.1076500 secs] [Times: user=0.61 
> sys=0.00, real=0.11 secs]
> 2011-01-04T18:41:06.756-0500: 224439.589: [GC 224439.590: [ParNew: 
> 737300K->151552K(757760K), 0.1244220 secs] 
> 2051665K->1476639K(2408448K), 0.1247530 secs] [Times: user=0.59 
> sys=0.00, real=0.13 secs]
> 2011-01-04T18:41:06.882-0500: 224439.715: [GC [1 CMS-initial-mark: 
> 1325087K(1650688K)] 1477191K(2408448K), 0.1086530 secs] [Times: 
> user=0.10 sys=0.00, real=0.10 secs]
> 2011-01-04T18:41:06.991-0500: 224439.824: [CMS-concurrent-mark-start]
> 2011-01-04T18:41:08.521-0500: 224441.354: [CMS-concurrent-mark: 
> 1.529/1.529 secs] [Times: user=3.31 sys=0.02, real=1.54 secs]
> 2011-01-04T18:41:08.521-0500: 224441.354: [CMS-concurrent-preclean-start]
> 2011-01-04T18:41:08.535-0500: 224441.368: [CMS-concurrent-preclean: 
> 0.014/0.014 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
> 2011-01-04T18:41:08.535-0500: 224441.368: 
> [CMS-concurrent-abortable-preclean-start]
>  CMS: abort preclean due to time 2011-01-04T18:41:13.646-0500: 
> 224446.479: [CMS-concurrent-abortable-preclean: 3.679/5.111 secs] 
> [Times: user=3.99 sys=0.03, real=5.11 secs]
> 2011-01-04T18:41:13.648-0500: 224446.482: [GC[YG occupancy: 220397 K 
> (757760 K)]224446.482: [Rescan (parallel) , 0.0440200 secs]224446.526: 
> [weak refs processing, 0.0059890 secs]224446.532: [class unloading, 
> 0.1417810 secs]224446.674: [scrub symbol & string tables, 0.0489470 
> secs] [1 CMS-remark: 1325087K(1650688K)] 1545485K(2408448K), 0.2519760 
> secs] [Times: user=0.44 sys=0.01, real=0.25 secs]
> 2011-01-04T18:41:13.901-0500: 224446.734: [CMS-concurrent-sweep-start]
> 2011-01-04T18:41:14.791-0500: 224447.624: [CMS-concurrent-sweep: 
> 0.888/0.890 secs] [Times: user=0.91 sys=0.01, real=0.88 secs]
> 2011-01-04T18:41:14.791-0500: 224447.624: [CMS-concurrent-reset-start]
> 2011-01-04T18:41:14.795-0500: 224447.628: [CMS-concurrent-reset: 
> 0.004/0.004 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
> 2011-01-04T18:41:40.336-0500: 224473.169: [GC 224473.170: [ParNew: 
> 757760K->151551K(757760K), 0.1246970 secs] 
> 2061601K->1458549K(2408448K), 0.1250470 secs] [Times: user=0.67 
> sys=0.00, real=0.13 secs]
> 2011-01-04T18:42:15.493-0500: 224508.327: [GC 224508.327: [ParNew: 
> 757759K->151552K(757760K), 0.1264960 secs] 
> 2064757K->1468487K(2408448K), 0.1269000 secs] [Times: user=0.58 
> sys=0.00, real=0.13 secs]
> 2011-01-04T18:42:30.747-0500: 224523.580: [GC 224523.580: [ParNew: 
> 757760K->150109K(757760K), 0.1121970 secs] 
> 2074695K->1469299K(2408448K), 0.1126290 secs] [Times: user=0.56 
> sys=0.00, real=0.12 secs]
> 2011-01-04T18:43:00.779-0500: 224553.612: [GC 224553.612: [ParNew: 
> 756317K->151552K(757760K), 0.1331190 secs] 
> 2075507K->1479534K(2408448K), 0.1334580 secs] [Times: user=0.61 
> sys=0.00, real=0.13 secs]
> 2011-01-04T18:43:00.914-0500: 224553.748: [GC [1 CMS-initial-mark: 
> 1327982K(1650688K)] 1479538K(2408448K), 0.1464550 secs] [Times: 
> user=0.15 sys=0.00, real=0.15 secs]
> 2011-01-04T18:43:01.061-0500: 224553.894: [CMS-concurrent-mark-start]
> 2011-01-04T18:43:02.661-0500: 224555.494: [CMS-concurrent-mark: 
> 1.583/1.600 secs] [Times: user=3.70 sys=0.04, real=1.60 secs]
> 2011-01-04T18:43:02.661-0500: 224555.494: [CMS-concurrent-preclean-start]
> 2011-01-04T18:43:02.675-0500: 224555.509: [CMS-concurrent-preclean: 
> 0.014/0.014 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
> 2011-01-04T18:43:02.676-0500: 224555.509: 
> [CMS-concurrent-abortable-preclean-start]
>  CMS: abort preclean due to time 2011-01-04T18:43:07.909-0500: 
> 224560.742: [CMS-concurrent-abortable-preclean: 3.899/5.234 secs] 
> [Times: user=4.31 sys=0.08, real=5.24 secs]
> 2011-01-04T18:43:07.912-0500: 224560.745: [GC[YG occupancy: 289988 K 
> (757760 K)]224560.745: [Rescan (parallel) , 0.1425160 secs]224560.888: 
> [weak refs processing, 0.0000900 secs]224560.888: [class unloading, 
> 0.1369840 secs]224561.025: [scrub symbol & string tables, 0.0474080 
> secs] [1 CMS-remark: 1327982K(1650688K)] 1617971K(2408448K), 0.3377450 
> secs] [Times: user=0.75 sys=0.00, real=0.34 secs]
> 2011-01-04T18:43:08.250-0500: 224561.083: [CMS-concurrent-sweep-start]
> 2011-01-04T18:43:09.138-0500: 224561.971: [CMS-concurrent-sweep: 
> 0.888/0.888 secs] [Times: user=0.90 sys=0.01, real=0.89 secs]
> 2011-01-04T18:43:09.138-0500: 224561.972: [CMS-concurrent-reset-start]
> 2011-01-04T18:43:09.142-0500: 224561.976: [CMS-concurrent-reset: 
> 0.004/0.004 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
> 2011-01-04T18:43:21.068-0500: 224573.902: [GC 224573.902: [ParNew: 
> 757360K->151551K(757760K), 0.1132670 secs] 
> 2060610K->1458489K(2408448K), 0.1135890 secs] [Times: user=0.59 
> sys=0.00, real=0.11 secs]
> 2011-01-04T18:43:46.517-0500: 224599.350: [GC 224599.350: [ParNew: 
> 757759K->151552K(757760K), 0.1540840 secs] 
> 2064697K->1475010K(2408448K), 0.1544610 secs] [Times: user=0.72 
> sys=0.00, real=0.15 secs]
> 2011-01-04T18:43:46.673-0500: 224599.506: [GC [1 CMS-initial-mark: 
> 1323458K(1650688K)] 1480665K(2408448K), 0.1355380 secs] [Times: 
> user=0.13 sys=0.00, real=0.14 secs]
> 2011-01-04T18:43:46.809-0500: 224599.642: [CMS-concurrent-mark-start]
> 2011-01-04T18:43:48.464-0500: 224601.297: [CMS-concurrent-mark: 
> 1.656/1.656 secs] [Times: user=3.44 sys=0.04, real=1.66 secs]
> 2011-01-04T18:43:48.464-0500: 224601.297: [CMS-concurrent-preclean-start]
> 2011-01-04T18:43:48.478-0500: 224601.311: [CMS-concurrent-preclean: 
> 0.013/0.014 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
> 2011-01-04T18:43:48.478-0500: 224601.311: 
> [CMS-concurrent-abortable-preclean-start]
>  CMS: abort preclean due to time 2011-01-04T18:43:53.604-0500: 
> 224606.437: [CMS-concurrent-abortable-preclean: 4.402/5.126 secs] 
> [Times: user=5.51 sys=0.13, real=5.13 secs]
> 2011-01-04T18:43:53.606-0500: 224606.439: [GC[YG occupancy: 354174 K 
> (757760 K)]224606.439: [Rescan (parallel) , 0.0620250 secs]224606.501: 
> [weak refs processing, 0.0001870 secs]224606.501: [class unloading, 
> 0.1428830 secs]224606.644: [scrub symbol & string tables, 0.0630710 
> secs] [1 CMS-remark: 1323458K(1650688K)] 1677633K(2408448K), 0.2790260 
> secs] [Times: user=0.60 sys=0.00, real=0.28 secs]
> 2011-01-04T18:43:53.886-0500: 224606.719: [CMS-concurrent-sweep-start]
> 2011-01-04T18:43:54.763-0500: 224607.596: [CMS-concurrent-sweep: 
> 0.877/0.877 secs] [Times: user=0.96 sys=0.01, real=0.88 secs]
> 2011-01-04T18:43:54.763-0500: 224607.596: [CMS-concurrent-reset-start]
> 2011-01-04T18:43:54.767-0500: 224607.600: [CMS-concurrent-reset: 
> 0.004/0.004 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
>
>
> _______________________________________________
> hotspot-gc-use mailing list
> hotspot-gc-use at openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/hotspot-gc-dev/attachments/20110106/0f8b86ad/attachment.htm>
-------------- next part --------------
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use at openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use