Fwd: Promotion Failure with CMS

Sun Sep 23 23:04:27 PDT 2012

Hi All

I am using Java 6 Update 23 with 72GB Heap.

I am getting Promotion Failure with CMS.

2012-09-19T15:27:10.923-0400: 1205700.121: [GC 1205700.121: [ParNew
(promotion failed)
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2421521448 bytes, 2421521448 total
: 21705536K->21705536K(21705536K), 4.5292200 secs]1205704.650: [CMS:
37054811K->18221426K(50919424K), 32.5634240 secs]
53545404K->18221426K(72624960K),
[CMS Perm : 46723K->45384K(77956K)], 37.0928130 secs] [Times: user=57.92
sys=0.02, real=37.09 secs]�

I am trying to understand this log line�

�[CMS: 37054811K->18221426K(50919424K), 32.5634240 secs]

Does it mean that CMS took 32 sec of wall time.

And,�I see the perm gen is also being collected even though max Perm Gen
size is 128 MB.�
Why is that happening?

Another question is: How should I deal with Promotion Failure?

My JVM args are

-server -Xms73278m -Xmx73278m �-XX:MaxPermSize=128m�
-XX:+UseConcMarkSweepGC -XX:+UseParNewGC
-XX:CMSInitiatingOccupancyFraction=65�
-XX:+DisableExplicitGC -XX:NewSize=23552m -XX:MaxNewSize=23552m�
-XX:+PrintGCDateStamps -XX:+PrintSafepointStatistics
-XX:+UseCMSInitiatingOccupancyOnly�
-XX:+CMSParallelRemarkEnabled -XX:+ParallelRefProcEnabled
-XX:+CMSClassUnloadingEnabled�
-XX:+CMSPermGenSweepingEnabled -XX:CMSInitiatingPermOccupancyFraction=68�
-XX:+UseCMSInitiatingOccupancyOnly -verbosegc�
-XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps
-XX:+PrintTenuringDistribution�
-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=/opt/gid/tomcat/srv/solrSlaveTcSrv/logs

Full logs are�

2012-09-19T15:01:27.245-0400: 1204156.443: [GC [1 CMS-initial-mark:
34896031K(50919424K)] 37340642K(72624960K), 0.4650020 secs] [Times:
user=0.46 sys=0.00, real=0.47 secs]�
2012-09-19T15:01:27.710-0400: 1204156.908: [CMS-concurrent-mark-start]
2012-09-19T15:01:29.852-0400: 1204159.050: [CMS-concurrent-mark:
2.140/2.142 secs] [Times: user=12.73 sys=0.14, real=2.14 secs]�
 2012-09-19T15:01:29.852-0400: 1204159.050: [CMS-concurrent-preclean-start]
2012-09-19T15:01:30.046-0400: 1204159.245: [CMS-concurrent-preclean:
0.192/0.194 secs] [Times: user=0.19 sys=0.00, real=0.19 secs]�
2012-09-19T15:01:30.046-0400: 1204159.245:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T15:01:35.234-0400: 1204164.433:
[CMS-concurrent-abortable-preclean: 5.026/5.188 secs] [Times: user=6.93
sys=0.01, real=5.19 secs]�
2012-09-19T15:01:35.235-0400: 1204164.433: [GC[YG occupancy: 3499130 K
(21705536 K)]1204164.433: [Rescan (parallel) , 0.2566170 secs]1204164.690:
[weak refs processing, 0.3779280 secs] [1 CMS-remark: 34896031K(50919424K)]
38395161K(72624960K), 0.6379830 secs] [Times: user=10.99 sys=0.01,
real=0.64 secs]�
2012-09-19T15:01:35.873-0400: 1204165.071: [CMS-concurrent-sweep-start]
2012-09-19T15:02:09.680-0400: 1204198.878: [CMS-concurrent-sweep:
33.805/33.807 secs] [Times: user=40.49 sys=0.12, real=33.80 secs]�
2012-09-19T15:02:09.680-0400: 1204198.878: [CMS-concurrent-reset-start]
2012-09-19T15:02:09.790-0400: 1204198.988: [CMS-concurrent-reset:
0.110/0.110 secs] [Times: user=0.11 sys=0.00, real=0.11 secs]�
2012-09-19T15:07:54.896-0400: 1204544.094: [GC 1204544.094: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2350102440 bytes, 2350102440 total
: 21705536K->2411712K(21705536K), 1.2991600 secs]
39356156K->23512228K(72624960K), 1.2992650 secs] [Times: user=16.03
sys=0.01, real=1.30 secs]�
2012-09-19T15:15:09.066-0400: 1204978.265: [GC 1204978.265: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2427844296 bytes, 2427844296 total
: 21705536K->2411712K(21705536K), 1.6306700 secs]
42806052K->29854665K(72624960K), 1.6307870 secs] [Times: user=22.58
sys=0.05, real=1.63 secs]�
2012-09-19T15:20:51.315-0400: 1205320.513: [GC 1205320.513: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2292042936 bytes, 2292042936 total
: 21705536K->2411712K(21705536K), 1.5484080 secs]
49148489K->34251580K(72624960K), 1.5485200 secs] [Times: user=21.24
sys=0.04, real=1.55 secs]�
2012-09-19T15:27:10.923-0400: 1205700.121: [GC 1205700.121: [ParNew
(promotion failed)
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2421521448 bytes, 2421521448 total
: 21705536K->21705536K(21705536K), 4.5292200 secs]1205704.650: [CMS:
37054811K->18221426K(50919424K), 32.5634240 secs]
53545404K->18221426K(72624960K),
[CMS Perm : 46723K->45384K(77956K)], 37.0928130 secs] [Times: user=57.92
sys=0.02, real=37.09 secs]�
2012-09-19T15:35:38.721-0400: 1206207.920: [GC 1206207.920: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2410186856 bytes, 2410186856 total
: 19293824K->2411712K(21705536K), 0.6405050 secs]
37515250K->22899742K(72624960K), 0.6406260 secs] [Times: user=11.15
sys=0.02, real=0.64 secs]�
2012-09-19T15:36:23.120-0400: 1206252.318: [GC 1206252.319: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2398571736 bytes, 2398571736 total
: 21705536K->2411712K(21705536K), 1.2799480 secs]
42193566K->26210207K(72624960K), 1.2800840 secs] [Times: user=18.69
sys=0.05, real=1.28 secs]�
2012-09-19T15:42:05.249-0400: 1206594.447: [GC 1206594.447: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2387771616 bytes, 2387771616 total
: 21705536K->2411712K(21705536K), 1.6001020 secs]
45504031K->32137231K(72624960K), 1.6002430 secs] [Times: user=21.98
sys=0.05, real=1.60 secs]�
2012-09-19T15:48:22.748-0400: 1206971.946: [GC 1206971.946: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2186166456 bytes, 2186166456 total
: 21705536K->2411712K(21705536K), 1.0172150 secs]
51431055K->35601035K(72624960K), 1.0173520 secs] [Times: user=14.43
sys=0.01, real=1.02 secs]�
2012-09-19T15:48:23.766-0400: 1206972.964: [GC [1 CMS-initial-mark:
33189323K(50919424K)] 35624491K(72624960K), 0.4248680 secs] [Times:
user=0.42 sys=0.00, real=0.42 secs]�
2012-09-19T15:48:24.191-0400: 1206973.389: [CMS-concurrent-mark-start]
2012-09-19T15:48:26.114-0400: 1206975.312: [CMS-concurrent-mark:
1.922/1.923 secs] [Times: user=10.17 sys=0.00, real=1.92 secs]�
2012-09-19T15:48:26.114-0400: 1206975.312: [CMS-concurrent-preclean-start]
2012-09-19T15:48:26.276-0400: 1206975.475: [CMS-concurrent-preclean:
0.161/0.163 secs] [Times: user=0.16 sys=0.00, real=0.17 secs]�
2012-09-19T15:48:26.276-0400: 1206975.475:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T15:48:31.387-0400: 1206980.586:
[CMS-concurrent-abortable-preclean: 4.582/5.111 secs] [Times: user=5.02
sys=0.01, real=5.11 secs]�
2012-09-19T15:48:31.388-0400: 1206980.586: [GC[YG occupancy: 2751488 K
(21705536 K)]1206980.586: [Rescan (parallel) , 0.1391430 secs]1206980.725:
[weak refs processing, 0.2528810 secs] [1 CMS-remark: 33189323K(50919424K)]
35940812K(72624960K), 0.3932910 secs] [Times: user=6.48 sys=0.02, real=0.39
secs]�
2012-09-19T15:48:31.781-0400: 1206980.980: [CMS-concurrent-sweep-start]
2012-09-19T15:48:50.677-0400: 1206999.875: [CMS-concurrent-sweep:
18.894/18.896 secs] [Times: user=22.16 sys=0.04, real=18.89 secs]�
2012-09-19T15:48:50.677-0400: 1206999.875: [CMS-concurrent-reset-start]
2012-09-19T15:48:50.787-0400: 1206999.986: [CMS-concurrent-reset:
0.110/0.110 secs] [Times: user=0.11 sys=0.00, real=0.11 secs]�
2012-09-19T15:50:46.472-0400: 1207115.670: [GC 1207115.671: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2460495072 bytes, 2460495072 total
: 21705536K->2411712K(21705536K), 1.5029900 secs]
38573074K->22241303K(72624960K), 1.5031370 secs] [Times: user=21.39
sys=0.01, real=1.51 secs]�
2012-09-19T15:52:31.997-0400: 1207221.195: [GC 1207221.195: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2383579648 bytes, 2383579648 total
: 21705536K->2411712K(21705536K), 1.5506250 secs]
41535127K->25853570K(72624960K), 1.5507680 secs] [Times: user=19.89
sys=0.03, real=1.55 secs]�
2012-09-19T15:57:11.344-0400: 1207500.543: [GC 1207500.543: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2418667680 bytes, 2418667680 total
: 21705536K->2411712K(21705536K), 1.0315930 secs]
45147394K->30233927K(72624960K), 1.0317280 secs] [Times: user=16.29
sys=0.02, real=1.04 secs]�
2012-09-19T16:03:18.945-0400: 1207868.144: [GC 1207868.144: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2073140800 bytes, 2073140800 total
: 21705536K->2411712K(21705536K), 0.9741820 secs]
49527751K->33922371K(72624960K), 0.9743210 secs] [Times: user=14.52
sys=0.03, real=0.98 secs]�
2012-09-19T16:05:52.719-0400: 1208021.918: [GC 1208021.918: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2398660792 bytes, 2398660792 total
: 21705536K->2411712K(21705536K), 1.2001310 secs]
53216195K->36484638K(72624960K), 1.2002770 secs] [Times: user=18.38
sys=0.01, real=1.20 secs]�
2012-09-19T16:05:53.920-0400: 1208023.118: [GC [1 CMS-initial-mark:
34072926K(50919424K)] 36624798K(72624960K), 1.8306890 secs] [Times:
user=1.83 sys=0.00, real=1.83 secs]�
2012-09-19T16:05:55.751-0400: 1208024.949: [CMS-concurrent-mark-start]
2012-09-19T16:05:57.927-0400: 1208027.125: [CMS-concurrent-mark:
2.174/2.176 secs] [Times: user=14.51 sys=0.02, real=2.17 secs]�
2012-09-19T16:05:57.927-0400: 1208027.125: [CMS-concurrent-preclean-start]
2012-09-19T16:05:58.165-0400: 1208027.363: [CMS-concurrent-preclean:
0.234/0.238 secs] [Times: user=0.47 sys=0.00, real=0.24 secs]�
2012-09-19T16:05:58.165-0400: 1208027.363:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T16:06:03.630-0400: 1208032.828:
[CMS-concurrent-abortable-preclean: 5.403/5.465 secs] [Times: user=14.12
sys=0.09, real=5.47 secs]�
2012-09-19T16:06:03.630-0400: 1208032.829: [GC[YG occupancy: 6072639 K
(21705536 K)]1208032.829: [Rescan (parallel) , 0.8860860 secs]1208033.715:
[weak refs processing, 0.3105550 secs] [1 CMS-remark: 34072926K(50919424K)]
40145566K(72624960K), 1.2026100 secs] [Times: user=19.96 sys=0.06,
real=1.20 secs]�
2012-09-19T16:06:04.833-0400: 1208034.031: [CMS-concurrent-sweep-start]
2012-09-19T16:06:19.800-0400: 1208048.999: [CMS-concurrent-sweep:
14.966/14.967 secs] [Times: user=35.33 sys=0.08, real=14.96 secs]�
2012-09-19T16:06:19.800-0400: 1208048.999: [CMS-concurrent-reset-start]
2012-09-19T16:06:19.943-0400: 1208049.141: [CMS-concurrent-reset:
0.142/0.143 secs] [Times: user=0.37 sys=0.00, real=0.15 secs]�
2012-09-19T16:07:21.398-0400: 1208110.596: [GC 1208110.596: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2387743168 bytes, 2387743168 total
: 21705536K->2411712K(21705536K), 1.8267340 secs]
42297347K->26739701K(72624960K), 1.8268780 secs] [Times: user=21.04
sys=0.02, real=1.83 secs]�
2012-09-19T16:13:02.036-0400: 1208451.234: [GC 1208451.234: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2417601496 bytes, 2417601496 total
: 21705536K->2411712K(21705536K), 1.0754340 secs]
46033525K->31104089K(72624960K), 1.0755760 secs] [Times: user=16.57
sys=0.02, real=1.08 secs]�
2012-09-19T16:19:50.919-0400: 1208860.118: [GC 1208860.118: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2224714248 bytes, 2224714248 total
: 21705536K->2411712K(21705536K), 0.9404780 secs]
50397913K->34043411K(72624960K), 0.9406210 secs] [Times: user=13.76
sys=0.02, real=0.94 secs]�
2012-09-19T16:21:15.475-0400: 1208944.674: [GC 1208944.674: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2373230808 bytes, 2373230808 total
: 21705536K->2411712K(21705536K), 1.6938340 secs]
53337235K->37215628K(72624960K), 1.6939800 secs] [Times: user=24.51
sys=0.01, real=1.69 secs]�
2012-09-19T16:21:17.170-0400: 1208946.368: [GC [1 CMS-initial-mark:
34803916K(50919424K)] 37383403K(72624960K), 1.7897590 secs] [Times:
user=1.79 sys=0.00, real=1.79 secs]�
2012-09-19T16:21:18.960-0400: 1208948.158: [CMS-concurrent-mark-start]
2012-09-19T16:21:21.069-0400: 1208950.268: [CMS-concurrent-mark:
2.108/2.109 secs] [Times: user=14.17 sys=0.26, real=2.11 secs]�
2012-09-19T16:21:21.069-0400: 1208950.268: [CMS-concurrent-preclean-start]
2012-09-19T16:21:21.251-0400: 1208950.449: [CMS-concurrent-preclean:
0.176/0.182 secs] [Times: user=0.36 sys=0.00, real=0.18 secs]�
2012-09-19T16:21:21.251-0400: 1208950.449:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T16:21:26.370-0400: 1208955.568:
[CMS-concurrent-abortable-preclean: 5.098/5.119 secs] [Times: user=11.54
sys=0.02, real=5.12 secs]�
2012-09-19T16:21:26.370-0400: 1208955.569: [GC[YG occupancy: 5968310 K
(21705536 K)]1208955.569: [Rescan (parallel) , 0.9728550 secs]1208956.542:
[weak refs processing, 0.3221900 secs] [1 CMS-remark: 34803916K(50919424K)]
40772226K(72624960K), 1.2982350 secs] [Times: user=22.61 sys=0.03,
real=1.30 secs]�
2012-09-19T16:21:27.669-0400: 1208956.867: [CMS-concurrent-sweep-start]
2012-09-19T16:21:44.728-0400: 1208973.927: [CMS-concurrent-sweep:
17.058/17.060 secs] [Times: user=31.59 sys=0.14, real=17.06 secs]�
2012-09-19T16:21:44.728-0400: 1208973.927: [CMS-concurrent-reset-start]
2012-09-19T16:21:44.840-0400: 1208974.039: [CMS-concurrent-reset:
0.112/0.112 secs] [Times: user=0.11 sys=0.00, real=0.11 secs]�
2012-09-19T16:23:52.538-0400: 1209101.736: [GC 1209101.736: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2357893472 bytes, 2357893472 total
: 21705536K->2411712K(21705536K), 2.0079260 secs]
34169902K->18601965K(72624960K), 2.0080740 secs] [Times: user=21.50
sys=0.02, real=2.01 secs]�
2012-09-19T16:29:24.424-0400: 1209433.622: [GC 1209433.622: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2425786112 bytes, 2425786112 total
: 21705536K->2411712K(21705536K), 1.0279680 secs]
37895789K->22391524K(72624960K), 1.0281140 secs] [Times: user=15.65
sys=0.03, real=1.03 secs]�
2012-09-19T16:35:06.086-0400: 1209775.284: [GC 1209775.285: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2153754552 bytes, 2153754552 total
: 21705536K->2411712K(21705536K), 0.9293720 secs]
41685348K->25078010K(72624960K), 0.9295330 secs] [Times: user=13.61
sys=0.02, real=0.93 secs]�
2012-09-19T16:40:04.948-0400: 1210074.146: [GC 1210074.147: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2437220840 bytes, 2437220840 total
: 21705197K->2411712K(21705536K), 1.2694790 secs]
44371495K->29947147K(72624960K), 1.2696300 secs] [Times: user=19.46
sys=0.03, real=1.27 secs]�
2012-09-19T16:49:53.870-0400: 1210663.069: [GC 1210663.069: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2376432592 bytes, 2376432592 total
: 21705536K->2411712K(21705536K), 1.7397380 secs]
49240971K->35310555K(72624960K), 1.7398790 secs] [Times: user=23.69
sys=0.02, real=1.74 secs]�
2012-09-19T16:52:23.866-0400: 1210813.065: [GC 1210813.065: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2439001880 bytes, 2439001880 total
: 21705536K->2411712K(21705536K), 1.3439640 secs]
54604379K->40035814K(72624960K), 1.3441040 secs] [Times: user=21.34
sys=0.01, real=1.35 secs]�
2012-09-19T16:52:25.211-0400: 1210814.410: [GC [1 CMS-initial-mark:
37624102K(50919424K)] 40038087K(72624960K), 1.6134520 secs] [Times:
user=1.61 sys=0.00, real=1.61 secs]�
2012-09-19T16:52:26.825-0400: 1210816.023: [CMS-concurrent-mark-start]
2012-09-19T16:52:28.386-0400: 1210817.584: [CMS-concurrent-mark:
1.561/1.561 secs] [Times: user=9.00 sys=0.02, real=1.56 secs]�
2012-09-19T16:52:28.386-0400: 1210817.584: [CMS-concurrent-preclean-start]
2012-09-19T16:52:28.537-0400: 1210817.735: [CMS-concurrent-preclean:
0.151/0.151 secs] [Times: user=0.15 sys=0.00, real=0.15 secs]�
2012-09-19T16:52:28.537-0400: 1210817.735:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T16:52:34.627-0400: 1210823.825:
[CMS-concurrent-abortable-preclean: 6.088/6.090 secs] [Times: user=7.15
sys=0.03, real=6.09 secs]�
2012-09-19T16:52:34.627-0400: 1210823.826: [GC[YG occupancy: 3169714 K
(21705536 K)]1210823.826: [Rescan (parallel) , 0.1626070 secs]1210823.988:
[weak refs processing, 0.6387270 secs] [1 CMS-remark: 37624102K(50919424K)]
40793817K(72624960K), 0.8019840 secs] [Times: user=14.17 sys=0.00,
real=0.81 secs]�
2012-09-19T16:52:35.429-0400: 1210824.628: [CMS-concurrent-sweep-start]
2012-09-19T16:52:56.236-0400: 1210845.435: [CMS-concurrent-sweep:
20.805/20.807 secs] [Times: user=23.82 sys=0.07, real=20.80 secs]�
2012-09-19T16:52:56.236-0400: 1210845.435: [CMS-concurrent-reset-start]
2012-09-19T16:52:56.348-0400: 1210845.546: [CMS-concurrent-reset:
0.112/0.112 secs] [Times: user=0.11 sys=0.00, real=0.11 secs]�
2012-09-19T17:00:46.738-0400: 1211315.937: [GC 1211315.937: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2417214312 bytes, 2417214312 total
: 21705536K->2411712K(21705536K), 1.9604930 secs]
38068500K->23797868K(72624960K), 1.9606370 secs] [Times: user=21.82
sys=0.03, real=1.96 secs]�
2012-09-19T17:05:45.710-0400: 1211614.909: [GC 1211614.909: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2225068272 bytes, 2225068272 total
: 21705536K->2411712K(21705536K), 1.2344920 secs]
43091692K->27073558K(72624960K), 1.2346430 secs] [Times: user=17.69
sys=0.02, real=1.23 secs]�
2012-09-19T17:06:54.552-0400: 1211683.751: [GC 1211683.751: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2288133464 bytes, 2288133464 total
: 21699223K->2411712K(21705536K), 1.3697670 secs]
46361069K->29840752K(72624960K), 1.3699080 secs] [Times: user=17.56
sys=0.02, real=1.37 secs]�
2012-09-19T17:12:45.320-0400: 1212034.518: [GC 1212034.519: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2408574944 bytes, 2408574944 total
: 21698462K->2411712K(21705536K), 1.0969040 secs]
49127503K->34055195K(72624960K), 1.0970500 secs] [Times: user=16.65
sys=0.02, real=1.10 secs]�
2012-09-19T17:20:32.770-0400: 1212501.968: [GC 1212501.968: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2381937432 bytes, 2381937432 total
: 21705536K->2411712K(21705536K), 1.5183390 secs]
53349019K->38472088K(72624960K), 1.5184860 secs] [Times: user=21.92
sys=0.02, real=1.51 secs]�
2012-09-19T17:20:34.289-0400: 1212503.487: [GC [1 CMS-initial-mark:
36060376K(50919424K)] 38503822K(72624960K), 1.6810820 secs] [Times:
user=1.68 sys=0.00, real=1.68 secs]�
2012-09-19T17:20:35.970-0400: 1212505.169: [CMS-concurrent-mark-start]
2012-09-19T17:20:37.978-0400: 1212507.176: [CMS-concurrent-mark:
2.005/2.008 secs] [Times: user=13.29 sys=0.10, real=2.00 secs]�
2012-09-19T17:20:37.978-0400: 1212507.176: [CMS-concurrent-preclean-start]
2012-09-19T17:20:38.142-0400: 1212507.341: [CMS-concurrent-preclean:
0.163/0.164 secs] [Times: user=0.33 sys=0.00, real=0.17 secs]�
2012-09-19T17:20:38.142-0400: 1212507.341:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T17:20:43.152-0400: 1212512.351:
[CMS-concurrent-abortable-preclean: 4.803/5.010 secs] [Times: user=10.01
sys=0.02, real=5.01 secs]�
2012-09-19T17:20:43.153-0400: 1212512.351: [GC[YG occupancy: 5984286 K
(21705536 K)]1212512.351: [Rescan (parallel) , 0.8108530 secs]1212513.162:
[weak refs processing, 0.2624590 secs] [1 CMS-remark: 36060376K(50919424K)]
42044663K(72624960K), 1.0741980 secs] [Times: user=16.70 sys=0.03,
real=1.07 secs]�
2012-09-19T17:20:44.227-0400: 1212513.426: [CMS-concurrent-sweep-start]
2012-09-19T17:21:15.026-0400: 1212544.225: [GC 1212544.225: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 1522699480 bytes, 1522699480 total
: 21705536K->2411712K(21705536K), 1.7429780 secs]
41487445K->24642149K(72624960K), 1.7431010 secs] [Times: user=17.79
sys=0.01, real=1.74 secs]�
2012-09-19T17:21:17.756-0400: 1212546.955: [CMS-concurrent-sweep:
31.779/33.529 secs] [Times: user=90.52 sys=0.71, real=33.53 secs]�
2012-09-19T17:21:17.756-0400: 1212546.955: [CMS-concurrent-reset-start]
 2012-09-19T17:21:17.882-0400: 1212547.081: [CMS-concurrent-reset:
0.126/0.126 secs] [Times: user=0.75 sys=0.01, real=0.12 secs]�
2012-09-19T17:24:03.183-0400: 1212712.382: [GC 1212712.382: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2404185344 bytes, 2404185344 total
: 21697370K->2411712K(21705536K), 0.8254390 secs]
41216868K->24475242K(72624960K), 0.8255760 secs] [Times: user=13.07
sys=0.01, real=0.83 secs]�
2012-09-19T17:30:38.194-0400: 1213107.392: [GC 1213107.393: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2353594784 bytes, 2353594784 total
: 21705536K->2411712K(21705536K), 1.0813640 secs]
43769066K->28037507K(72624960K), 1.0815090 secs] [Times: user=16.17
sys=0.02, real=1.08 secs]�
2012-09-19T17:35:29.815-0400: 1213399.014: [GC 1213399.014: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2379361760 bytes, 2379361760 total
: 21705536K->2411712K(21705536K), 1.5729320 secs]
47331331K->31768452K(72624960K), 1.5730850 secs] [Times: user=22.19
sys=0.02, real=1.57 secs]�
2012-09-19T17:36:12.192-0400: 1213441.390: [GC 1213441.390: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 1423485152 bytes, 1423485152 total
: 21705536K->2411712K(21705536K), 1.4825910 secs]
51062276K->34299654K(72624960K), 1.4827340 secs] [Times: user=17.28
sys=0.04, real=1.48 secs]�
2012-09-19T17:40:37.989-0400: 1213707.187: [GC 1213707.187: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2433779400 bytes, 2433779400 total
: 21705536K->2411712K(21705536K), 1.0255740 secs]
53593478K->37819703K(72624960K), 1.0257230 secs] [Times: user=16.20
sys=0.02, real=1.03 secs]�
2012-09-19T17:40:39.015-0400: 1213708.214: [GC [1 CMS-initial-mark:
35407991K(50919424K)] 37819723K(72624960K), 0.6942680 secs] [Times:
user=0.69 sys=0.00, real=0.69 secs]�
2012-09-19T17:40:39.710-0400: 1213708.908: [CMS-concurrent-mark-start]
2012-09-19T17:40:41.631-0400: 1213710.829: [CMS-concurrent-mark:
1.919/1.921 secs] [Times: user=10.95 sys=0.10, real=1.92 secs]�
2012-09-19T17:40:41.631-0400: 1213710.829: [CMS-concurrent-preclean-start]
2012-09-19T17:40:41.806-0400: 1213711.005: [CMS-concurrent-preclean:
0.174/0.176 secs] [Times: user=0.18 sys=0.00, real=0.18 secs]�
2012-09-19T17:40:41.806-0400: 1213711.005:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T17:40:46.999-0400: 1213716.198:
[CMS-concurrent-abortable-preclean: 5.176/5.193 secs] [Times: user=6.74
sys=0.02, real=5.19 secs]�
2012-09-19T17:40:47.000-0400: 1213716.198: [GC[YG occupancy: 2959483 K
(21705536 K)]1213716.198: [Rescan (parallel) , 0.1798620 secs]1213716.378:
[weak refs processing, 0.5651400 secs] [1 CMS-remark: 35407991K(50919424K)]
38367474K(72624960K), 0.7471080 secs] [Times: user=12.79 sys=0.02,
real=0.75 secs]�
2012-09-19T17:40:47.747-0400: 1213716.945: [CMS-concurrent-sweep-start]
2012-09-19T17:41:06.202-0400: 1213735.401: [CMS-concurrent-sweep:
18.454/18.455 secs] [Times: user=23.44 sys=0.05, real=18.45 secs]�
2012-09-19T17:41:06.202-0400: 1213735.401: [CMS-concurrent-reset-start]
2012-09-19T17:41:06.314-0400: 1213735.512: [CMS-concurrent-reset:
0.112/0.112 secs] [Times: user=0.11 sys=0.00, real=0.11 secs]�
2012-09-19T17:47:21.742-0400: 1214110.940: [GC 1214110.940: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2232926112 bytes, 2232926112 total
: 21705536K->2411712K(21705536K), 1.3109780 secs]
38279387K->21880013K(72624960K), 1.3111290 secs] [Times: user=14.51
sys=0.01, real=1.31 secs]�
2012-09-19T17:50:44.133-0400: 1214313.332: [GC 1214313.332: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2459330320 bytes, 2459330320 total
: 21705536K->2411712K(21705536K), 1.4565120 secs]
41173837K->24877803K(72624960K), 1.4566650 secs] [Times: user=21.30
sys=0.01, real=1.46 secs]�
2012-09-19T17:51:22.210-0400: 1214351.408: [GC 1214351.408: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 1630011968 bytes, 1630011968 total
: 21705536K->2411712K(21705536K), 1.4506370 secs]
44171627K->27250773K(72624960K), 1.4507810 secs] [Times: user=17.25
sys=0.02, real=1.45 secs]�
2012-09-19T17:57:51.308-0400: 1214740.506: [GC 1214740.506: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2421783368 bytes, 2421783368 total
: 21705536K->2411712K(21705536K), 1.3556900 secs]
46544597K->32028101K(72624960K), 1.3558340 secs] [Times: user=20.72
sys=0.03, real=1.35 secs]�
2012-09-19T18:03:56.856-0400: 1215106.055: [GC 1215106.055: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2146249712 bytes, 2146249712 total
: 21705536K->2411712K(21705536K), 0.8510950 secs]
51321925K->34737849K(72624960K), 0.8512420 secs] [Times: user=13.10
sys=0.02, real=0.85 secs]�
2012-09-19T18:09:26.088-0400: 1215435.287: [GC 1215435.287: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2106309344 bytes, 2106309344 total
: 21703267K->2411712K(21705536K), 0.7556880 secs]
54029405K->36827410K(72624960K), 0.7558660 secs] [Times: user=12.23
sys=0.00, real=0.76 secs]�
2012-09-19T18:09:26.846-0400: 1215436.044: [GC [1 CMS-initial-mark:
34415698K(50919424K)] 36831593K(72624960K), 0.7076840 secs] [Times:
user=0.71 sys=0.00, real=0.71 secs]�
2012-09-19T18:09:27.553-0400: 1215436.752: [CMS-concurrent-mark-start]
2012-09-19T18:09:29.579-0400: 1215438.777: [CMS-concurrent-mark:
2.026/2.026 secs] [Times: user=11.04 sys=0.01, real=2.02 secs]�
2012-09-19T18:09:29.579-0400: 1215438.778: [CMS-concurrent-preclean-start]
2012-09-19T18:09:29.770-0400: 1215438.969: [CMS-concurrent-preclean:
0.188/0.191 secs] [Times: user=0.19 sys=0.00, real=0.19 secs]�
2012-09-19T18:09:29.770-0400: 1215438.969:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T18:09:35.136-0400: 1215444.334:
[CMS-concurrent-abortable-preclean: 5.351/5.365 secs] [Times: user=6.35
sys=0.01, real=5.37 secs]�
2012-09-19T18:09:35.136-0400: 1215444.335: [GC[YG occupancy: 2801872 K
(21705536 K)]1215444.335: [Rescan (parallel) , 0.1205040 secs]1215444.455:
[weak refs processing, 0.3741090 secs] [1 CMS-remark: 34415698K(50919424K)]
37217570K(72624960K), 0.4971130 secs] [Times: user=8.51 sys=0.01, real=0.50
secs]�
2012-09-19T18:09:35.633-0400: 1215444.832: [CMS-concurrent-sweep-start]
2012-09-19T18:10:01.274-0400: 1215470.473: [CMS-concurrent-sweep:
25.637/25.641 secs] [Times: user=31.88 sys=0.15, real=25.63 secs]�
2012-09-19T18:10:01.274-0400: 1215470.473: [CMS-concurrent-reset-start]
2012-09-19T18:10:01.385-0400: 1215470.584: [CMS-concurrent-reset:
0.111/0.111 secs] [Times: user=0.31 sys=0.00, real=0.11 secs]�
2012-09-19T18:16:29.996-0400: 1215859.194: [GC 1215859.194: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 1660017184 bytes, 1660017184 total
: 21705536K->2411712K(21705536K), 1.1722460 secs]
40726570K->23381371K(72624960K), 1.1723950 secs] [Times: user=12.66
sys=0.01, real=1.17 secs]�
2012-09-19T18:21:01.076-0400: 1216130.274: [GC 1216130.274: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2457083680 bytes, 2457083680 total
: 21705536K->2411712K(21705536K), 1.5114590 secs]
42675195K->25698534K(72624960K), 1.5116040 secs] [Times: user=21.32
sys=0.01, real=1.52 secs]�
2012-09-19T18:21:44.438-0400: 1216173.636: [GC 1216173.636: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 1243267632 bytes, 1243267632 total
: 21700806K->2411712K(21705536K), 1.4682340 secs]
44987628K->28050833K(72624960K), 1.4683770 secs] [Times: user=17.19
sys=0.02, real=1.47 secs]�
2012-09-19T18:27:53.735-0400: 1216542.933: [GC 1216542.933: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2430034040 bytes, 2430034040 total
: 21703814K->2411712K(21705536K), 1.1685370 secs]
47342936K->31507787K(72624960K), 1.1686820 secs] [Times: user=18.12
sys=0.02, real=1.16 secs]�
2012-09-19T18:33:28.043-0400: 1216877.242: [GC 1216877.242: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2314207048 bytes, 2314207048 total
: 21705536K->2411712K(21705536K), 0.9057240 secs]
50801611K->34348033K(72624960K), 0.9058760 secs] [Times: user=13.99
sys=0.02, real=0.91 secs]�
2012-09-19T18:35:58.880-0400: 1217028.078: [GC 1217028.078: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2462255528 bytes, 2462255528 total
: 21705536K->2411712K(21705536K), 1.5261400 secs]
53641857K->37397377K(72624960K), 1.5262910 secs] [Times: user=22.67
sys=0.02, real=1.52 secs]�
2012-09-19T18:36:00.407-0400: 1217029.605: [GC [1 CMS-initial-mark:
34985665K(50919424K)] 37582779K(72624960K), 1.9763230 secs] [Times:
user=1.98 sys=0.00, real=1.98 secs]�
2012-09-19T18:36:02.383-0400: 1217031.582: [CMS-concurrent-mark-start]
2012-09-19T18:36:04.678-0400: 1217033.876: [CMS-concurrent-mark:
2.292/2.295 secs] [Times: user=16.09 sys=0.08, real=2.29 secs]�
2012-09-19T18:36:04.678-0400: 1217033.877: [CMS-concurrent-preclean-start]
2012-09-19T18:36:04.903-0400: 1217034.102: [CMS-concurrent-preclean:
0.218/0.225 secs] [Times: user=0.50 sys=0.01, real=0.23 secs]�
2012-09-19T18:36:04.903-0400: 1217034.102:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T18:36:10.677-0400: 1217039.875:
[CMS-concurrent-abortable-preclean: 5.710/5.773 secs] [Times: user=13.27
sys=0.02, real=5.77 secs]�
2012-09-19T18:36:10.677-0400: 1217039.876: [GC[YG occupancy: 8017741 K
(21705536 K)]1217039.876: [Rescan (parallel) , 1.5275220 secs]1217041.403:
[weak refs processing, 0.3659120 secs] [1 CMS-remark: 34985665K(50919424K)]
43003406K(72624960K), 1.9043950 secs] [Times: user=33.25 sys=0.06,
real=1.91 secs]�
2012-09-19T18:36:12.582-0400: 1217041.780: [CMS-concurrent-sweep-start]
2012-09-19T18:36:38.321-0400: 1217067.520: [CMS-concurrent-sweep:
25.737/25.739 secs] [Times: user=59.44 sys=0.13, real=25.73 secs]�
2012-09-19T18:36:38.321-0400: 1217067.520: [CMS-concurrent-reset-start]
2012-09-19T18:36:38.350-0400: 1217067.549: [GC 1217067.549: [ParNew
Desired survivor size 1234796544 bytes, new threshold 4 (max 4)
- age � 1: 1106070680 bytes, 1106070680 total
: 21705536K->2411712K(21705536K), 1.8299440 secs]
40768505K->23835308K(72624960K), 1.8300830 secs] [Times: user=17.99
sys=0.03, real=1.83 secs]�
2012-09-19T18:36:40.302-0400: 1217069.500: [CMS-concurrent-reset:
0.150/1.980 secs] [Times: user=18.49 sys=0.05, real=1.98 secs]�
2012-09-19T18:40:15.003-0400: 1217284.201: [GC 1217284.201: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 1871666400 bytes, 1871666400 total
- age � 2: �561479112 bytes, 2433145512 total
: 21696028K->2411712K(21705536K), 0.7011670 secs]
43119624K->26041879K(72624960K), 0.7013200 secs] [Times: user=12.05
sys=0.02, real=0.70 secs]�
2012-09-19T18:46:53.967-0400: 1217683.166: [GC 1217683.166: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2249380768 bytes, 2249380768 total
: 21705536K->2411712K(21705536K), 1.0108940 secs]
45335703K->29355936K(72624960K), 1.0110450 secs] [Times: user=14.64
sys=0.04, real=1.01 secs]�
2012-09-19T18:51:11.798-0400: 1217940.996: [GC 1217940.996: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2444045688 bytes, 2444045688 total
: 21705536K->2411712K(21705536K), 1.6623450 secs]
48649760K->32928022K(72624960K), 1.6624950 secs] [Times: user=24.34
sys=0.03, real=1.66 secs]�
2012-09-19T18:51:51.734-0400: 1217980.932: [GC 1217980.932: [ParNew
Desired survivor size 1234796544 bytes, new threshold 4 (max 4)
- age � 1: 1050514368 bytes, 1050514368 total
: 21705536K->2411712K(21705536K), 1.4671220 secs]
52221846K->35252158K(72624960K), 1.4672670 secs] [Times: user=16.64
sys=0.04, real=1.47 secs]�
2012-09-19T18:53:41.896-0400: 1218091.094: [GC 1218091.094: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 1774634544 bytes, 1774634544 total
- age � 2: �630513808 bytes, 2405148352 total
: 21705536K->2411712K(21705536K), 0.6064350 secs]
54545982K->36301208K(72624960K), 0.6065830 secs] [Times: user=10.39
sys=0.00, real=0.60 secs]�
2012-09-19T18:53:42.503-0400: 1218091.702: [GC [1 CMS-initial-mark:
33889496K(50919424K)] 36301208K(72624960K), 0.7708310 secs] [Times:
user=0.78 sys=0.00, real=0.77 secs]�
2012-09-19T18:53:43.274-0400: 1218092.473: [CMS-concurrent-mark-start]
2012-09-19T18:53:46.090-0400: 1218095.288: [CMS-concurrent-mark:
2.815/2.815 secs] [Times: user=17.31 sys=0.06, real=2.82 secs]�
 2012-09-19T18:53:46.090-0400: 1218095.288: [CMS-concurrent-preclean-start]
2012-09-19T18:53:46.248-0400: 1218095.447: [CMS-concurrent-preclean:
0.158/0.159 secs] [Times: user=0.16 sys=0.00, real=0.16 secs]�
2012-09-19T18:53:46.249-0400: 1218095.447:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T18:53:51.841-0400: 1218101.040:
[CMS-concurrent-abortable-preclean: 5.589/5.593 secs] [Times: user=6.55
sys=0.02, real=5.59 secs]�
2012-09-19T18:53:51.842-0400: 1218101.040: [GC[YG occupancy: 3272505 K
(21705536 K)]1218101.040: [Rescan (parallel) , 0.4305780 secs]1218101.471:
[weak refs processing, 0.3288280 secs] [1 CMS-remark: 33889496K(50919424K)]
37162001K(72624960K), 0.7617080 secs] [Times: user=11.97 sys=0.03,
real=0.76 secs]�
2012-09-19T18:53:52.604-0400: 1218101.802: [CMS-concurrent-sweep-start]
2012-09-19T18:54:18.738-0400: 1218127.936: [CMS-concurrent-sweep:
26.132/26.134 secs] [Times: user=29.71 sys=0.07, real=26.13 secs]�
2012-09-19T18:54:18.738-0400: 1218127.936: [CMS-concurrent-reset-start]
2012-09-19T18:54:18.872-0400: 1218128.071: [CMS-concurrent-reset:
0.134/0.134 secs] [Times: user=0.22 sys=0.00, real=0.14 secs]�
2012-09-19T19:01:26.745-0400: 1218555.943: [GC 1218555.943: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2430082904 bytes, 2430082904 total
: 21705536K->2411712K(21705536K), 1.2778790 secs]
36212125K->21117788K(72624960K), 1.2780300 secs] [Times: user=16.56
sys=0.03, real=1.28 secs]�
2012-09-19T19:03:48.811-0400: 1218698.009: [GC 1218698.009: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2328215200 bytes, 2328215200 total
: 21705536K->2411712K(21705536K), 1.2502030 secs]
40411612K->24341014K(72624960K), 1.2503450 secs] [Times: user=16.32
sys=0.04, real=1.25 secs]�
2012-09-19T19:16:44.991-0400: 1219474.189: [GC 1219474.189: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2399892048 bytes, 2399892048 total
: 21705536K->2411712K(21705536K), 1.3983010 secs]
43634838K->28933980K(72624960K), 1.3984430 secs] [Times: user=19.77
sys=0.05, real=1.40 secs]�
2012-09-19T19:21:00.106-0400: 1219729.304: [GC 1219729.304: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2187193256 bytes, 2187193256 total
: 21705536K->2411712K(21705536K), 1.1693690 secs]
48227804K->31642801K(72624960K), 1.1695190 secs] [Times: user=16.59
sys=0.02, real=1.17 secs]�
2012-09-19T19:27:52.799-0400: 1220141.997: [GC 1220141.997: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2380584432 bytes, 2380584432 total
: 21705536K->2411712K(21705536K), 1.5083580 secs]
50936625K->35114203K(72624960K), 1.5085140 secs] [Times: user=19.83
sys=0.04, real=1.51 secs]�
2012-09-19T19:35:34.315-0400: 1220603.513: [GC 1220603.513: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2240262192 bytes, 2240262192 total
: 21705536K->2411712K(21705536K), 1.2261110 secs]
54408027K->38249757K(72624960K), 1.2262710 secs] [Times: user=17.34
sys=0.03, real=1.23 secs]�
2012-09-19T19:35:35.542-0400: 1220604.740: [GC [1 CMS-initial-mark:
35838045K(50919424K)] 38249814K(72624960K), 1.0356820 secs] [Times:
user=1.04 sys=0.00, real=1.04 secs]�
2012-09-19T19:35:36.578-0400: 1220605.776: [CMS-concurrent-mark-start]
2012-09-19T19:35:38.291-0400: 1220607.489: [CMS-concurrent-mark:
1.710/1.713 secs] [Times: user=11.72 sys=0.37, real=1.71 secs]�
2012-09-19T19:35:38.291-0400: 1220607.489: [CMS-concurrent-preclean-start]
2012-09-19T19:35:38.442-0400: 1220607.640: [CMS-concurrent-preclean:
0.150/0.151 secs] [Times: user=0.40 sys=0.00, real=0.15 secs]�
2012-09-19T19:35:38.442-0400: 1220607.640:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T19:35:44.061-0400: 1220613.260:
[CMS-concurrent-abortable-preclean: 5.592/5.619 secs] [Times: user=12.59
sys=0.10, real=5.62 secs]�
2012-09-19T19:35:44.062-0400: 1220613.260: [GC[YG occupancy: 4431835 K
(21705536 K)]1220613.260: [Rescan (parallel) , 0.3015270 secs]1220613.562:
[weak refs processing, 0.8065760 secs] [1 CMS-remark: 35838045K(50919424K)]
40269880K(72624960K), 1.1085100 secs] [Times: user=19.70 sys=0.00,
real=1.11 secs]�
2012-09-19T19:35:45.170-0400: 1220614.369: [CMS-concurrent-sweep-start]
2012-09-19T19:36:14.054-0400: 1220643.252: [CMS-concurrent-sweep:
28.880/28.884 secs] [Times: user=43.05 sys=0.12, real=28.88 secs]�
2012-09-19T19:36:14.054-0400: 1220643.253: [CMS-concurrent-reset-start]
2012-09-19T19:36:14.167-0400: 1220643.366: [CMS-concurrent-reset:
0.113/0.113 secs] [Times: user=0.12 sys=0.00, real=0.11 secs]�
2012-09-19T19:45:09.486-0400: 1221178.684: [GC 1221178.685: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2253774040 bytes, 2253774040 total
: 21700667K->2411712K(21705536K), 2.0685330 secs]
40323727K->26527562K(72624960K), 2.0687170 secs] [Times: user=24.02
sys=0.04, real=2.06 secs]�
2012-09-19T19:50:40.617-0400: 1221509.815: [GC 1221509.815: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2085928328 bytes, 2085928328 total
: 21705536K->2411712K(21705536K), 0.8648170 secs]
45821386K->27766681K(72624960K), 0.8649770 secs] [Times: user=12.49
sys=0.01, real=0.87 secs]�
2012-09-19T19:57:42.794-0400: 1221931.992: [GC 1221931.993: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2360882968 bytes, 2360882968 total
: 21705536K->2411712K(21705536K), 1.4738390 secs]
47060505K->32251138K(72624960K), 1.4739890 secs] [Times: user=19.80
sys=0.03, real=1.47 secs]�
2012-09-19T20:05:47.539-0400: 1222416.737: [GC 1222416.737: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2338952936 bytes, 2338952936 total
: 21705536K->2411712K(21705536K), 1.2738710 secs]
51544962K->35731056K(72624960K), 1.2740290 secs] [Times: user=18.41
sys=0.03, real=1.27 secs]�
2012-09-19T20:05:48.814-0400: 1222418.012: [GC [1 CMS-initial-mark:
33319344K(50919424K)] 35795244K(72624960K), 1.4323360 secs] [Times:
user=1.44 sys=0.00, real=1.44 secs]�
2012-09-19T20:05:50.246-0400: 1222419.444: [CMS-concurrent-mark-start]
2012-09-19T20:05:52.001-0400: 1222421.200: [CMS-concurrent-mark:
1.753/1.755 secs] [Times: user=11.03 sys=0.08, real=1.75 secs]�
2012-09-19T20:05:52.001-0400: 1222421.200: [CMS-concurrent-preclean-start]
2012-09-19T20:05:52.149-0400: 1222421.348: [CMS-concurrent-preclean:
0.147/0.148 secs] [Times: user=0.30 sys=0.00, real=0.15 secs]�
2012-09-19T20:05:52.149-0400: 1222421.348:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T20:05:57.667-0400: 1222426.865:
[CMS-concurrent-abortable-preclean: 5.511/5.518 secs] [Times: user=11.29
sys=0.30, real=5.52 secs]�
2012-09-19T20:05:57.667-0400: 1222426.866: [GC[YG occupancy: 4962956 K
(21705536 K)]1222426.866: [Rescan (parallel) , 0.7847230 secs]1222427.650:
[weak refs processing, 0.3743230 secs] [1 CMS-remark: 33319344K(50919424K)]
38282300K(72624960K), 1.1594530 secs] [Times: user=20.39 sys=0.05,
real=1.16 secs]�
2012-09-19T20:05:58.827-0400: 1222428.025: [CMS-concurrent-sweep-start]
2012-09-19T20:06:46.604-0400: 1222475.802: [CMS-concurrent-sweep:
47.772/47.777 secs] [Times: user=77.46 sys=0.25, real=47.77 secs]�
2012-09-19T20:06:46.604-0400: 1222475.802: [CMS-concurrent-reset-start]
2012-09-19T20:06:46.741-0400: 1222475.939: [CMS-concurrent-reset:
0.137/0.137 secs] [Times: user=0.21 sys=0.01, real=0.13 secs]�
2012-09-19T20:08:18.712-0400: 1222567.910: [GC 1222567.910: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2270196408 bytes, 2270196408 total
: 21705536K->2411712K(21705536K), 1.7962520 secs]
37550865K->21630309K(72624960K), 1.7964060 secs] [Times: user=19.85
sys=0.01, real=1.80 secs]�
2012-09-19T20:16:26.008-0400: 1223055.206: [GC 1223055.206: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2253907984 bytes, 2253907984 total
: 21699063K->2411712K(21705536K), 1.0858330 secs]
40917661K->25292456K(72624960K), 1.0859820 secs] [Times: user=15.71
sys=0.03, real=1.09 secs]�
2012-09-19T20:20:55.429-0400: 1223324.627: [GC 1223324.627: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2140983328 bytes, 2140983328 total
: 21705536K->2411712K(21705536K), 1.0729440 secs]
44586280K->27718495K(72624960K), 1.0730980 secs] [Times: user=15.78
sys=0.02, real=1.07 secs]�
2012-09-19T20:24:29.085-0400: 1223538.284: [GC 1223538.284: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2419695216 bytes, 2419695216 total
: 21705536K->2411712K(21705536K), 1.5448300 secs]
47012319K->30660831K(72624960K), 1.5449870 secs] [Times: user=19.70
sys=0.04, real=1.55 secs]�
2012-09-19T20:32:16.829-0400: 1224006.027: [GC 1224006.028: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2262692960 bytes, 2262692960 total
: 21705536K->2411712K(21705536K), 0.9236170 secs]
49954655K->33824485K(72624960K), 0.9237680 secs] [Times: user=14.35
sys=0.02, real=0.93 secs]�
2012-09-19T20:35:50.757-0400: 1224219.955: [GC 1224219.955: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2258269144 bytes, 2258269144 total
: 21705536K->2411712K(21705536K), 1.1717740 secs]
53118309K->36386565K(72624960K), 1.1719260 secs] [Times: user=17.15
sys=0.02, real=1.17 secs]�
2012-09-19T20:35:51.929-0400: 1224221.128: [GC [1 CMS-initial-mark:
33974853K(50919424K)] 36524766K(72624960K), 1.7719080 secs] [Times:
user=1.77 sys=0.00, real=1.78 secs]�
2012-09-19T20:35:53.701-0400: 1224222.900: [CMS-concurrent-mark-start]
2012-09-19T20:35:55.419-0400: 1224224.617: [CMS-concurrent-mark:
1.715/1.717 secs] [Times: user=12.11 sys=0.43, real=1.71 secs]�
2012-09-19T20:35:55.419-0400: 1224224.617: [CMS-concurrent-preclean-start]
2012-09-19T20:35:55.567-0400: 1224224.765: [CMS-concurrent-preclean:
0.148/0.148 secs] [Times: user=0.39 sys=0.00, real=0.15 secs]�
2012-09-19T20:35:55.567-0400: 1224224.765:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T20:36:02.090-0400: 1224231.288:
[CMS-concurrent-abortable-preclean: 6.521/6.523 secs] [Times: user=14.99
sys=0.03, real=6.52 secs]�
2012-09-19T20:36:02.090-0400: 1224231.288: [GC[YG occupancy: 7753835 K
(21705536 K)]1224231.289: [Rescan (parallel) , 0.8859230 secs]1224232.175:
[weak refs processing, 0.4122590 secs] [1 CMS-remark: 33974853K(50919424K)]
41728688K(72624960K), 1.2987190 secs] [Times: user=21.78 sys=0.05,
real=1.30 secs]�
2012-09-19T20:36:03.389-0400: 1224232.587: [CMS-concurrent-sweep-start]
2012-09-19T20:36:35.050-0400: 1224264.249: [CMS-concurrent-sweep:
31.658/31.661 secs] [Times: user=46.30 sys=0.13, real=31.66 secs]�
2012-09-19T20:36:35.050-0400: 1224264.249: [CMS-concurrent-reset-start]
2012-09-19T20:36:35.161-0400: 1224264.359: [CMS-concurrent-reset:
0.110/0.110 secs] [Times: user=0.11 sys=0.00, real=0.11 secs]�
2012-09-19T20:39:26.925-0400: 1224436.123: [GC 1224436.124: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2330584544 bytes, 2330584544 total
: 21705536K->2411712K(21705536K), 1.9456060 secs]
33585198K->17669504K(72624960K), 1.9457570 secs] [Times: user=20.58
sys=0.03, real=1.95 secs]�
2012-09-19T20:45:16.981-0400: 1224786.180: [GC 1224786.180: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2222203472 bytes, 2222203472 total
: 21705536K->2411712K(21705536K), 0.9708830 secs]
36963328K->20541465K(72624960K), 0.9710330 secs] [Times: user=14.35
sys=0.03, real=0.97 secs]�
2012-09-19T20:50:57.289-0400: 1225126.488: [GC 1225126.488: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2265831504 bytes, 2265831504 total
: 21705536K->2411712K(21705536K), 1.2047810 secs]
39835289K->23703865K(72624960K), 1.2049350 secs] [Times: user=17.15
sys=0.04, real=1.21 secs]�
2012-09-19T20:54:42.548-0400: 1225351.747: [GC 1225351.747: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2419795984 bytes, 2419795984 total
: 21705536K->2411712K(21705536K), 1.5418840 secs]
42997689K->27838614K(72624960K), 1.5420290 secs] [Times: user=20.45
sys=0.04, real=1.54 secs]�
2012-09-19T21:03:50.745-0400: 1225899.943: [GC 1225899.943: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2325424168 bytes, 2325424168 total
: 21705536K->2411712K(21705536K), 0.9835000 secs]
47132438K->31095988K(72624960K), 0.9836480 secs] [Times: user=14.63
sys=0.03, real=0.98 secs]�
2012-09-19T21:08:56.864-0400: 1226206.062: [GC 1226206.063: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2382172728 bytes, 2382172728 total
: 21705536K->2411712K(21705536K), 1.3058300 secs]
50389812K->35942058K(72624960K), 1.3059810 secs] [Times: user=19.60
sys=0.03, real=1.30 secs]�
2012-09-19T21:08:58.171-0400: 1226207.369: [GC [1 CMS-initial-mark:
33530346K(50919424K)] 35956669K(72624960K), 1.3523020 secs] [Times:
user=1.36 sys=0.00, real=1.36 secs]�
2012-09-19T21:08:59.523-0400: 1226208.721: [CMS-concurrent-mark-start]
2012-09-19T21:09:01.248-0400: 1226210.447: [CMS-concurrent-mark:
1.725/1.725 secs] [Times: user=9.60 sys=0.09, real=1.72 secs]�
2012-09-19T21:09:01.248-0400: 1226210.447: [CMS-concurrent-preclean-start]
2012-09-19T21:09:01.404-0400: 1226210.602: [CMS-concurrent-preclean:
0.154/0.156 secs] [Times: user=0.18 sys=0.01, real=0.16 secs]�
2012-09-19T21:09:01.404-0400: 1226210.602:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T21:09:06.861-0400: 1226216.059:
[CMS-concurrent-abortable-preclean: 5.454/5.457 secs] [Times: user=6.78
sys=0.04, real=5.45 secs]�
2012-09-19T21:09:06.861-0400: 1226216.060: [GC[YG occupancy: 3227736 K
(21705536 K)]1226216.060: [Rescan (parallel) , 0.2039640 secs]1226216.264:
[weak refs processing, 0.4757570 secs] [1 CMS-remark: 33530346K(50919424K)]
36758082K(72624960K), 0.6803770 secs] [Times: user=11.77 sys=0.00,
real=0.69 secs]�
2012-09-19T21:09:07.542-0400: 1226216.740: [CMS-concurrent-sweep-start]
2012-09-19T21:09:34.197-0400: 1226243.396: [CMS-concurrent-sweep:
26.654/26.655 secs] [Times: user=32.61 sys=0.22, real=26.65 secs]�
2012-09-19T21:09:34.197-0400: 1226243.396: [CMS-concurrent-reset-start]
2012-09-19T21:09:34.308-0400: 1226243.506: [CMS-concurrent-reset:
0.110/0.110 secs] [Times: user=0.11 sys=0.00, real=0.11 secs]�
2012-09-19T21:19:28.862-0400: 1226838.061: [GC 1226838.061: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2329660864 bytes, 2329660864 total
: 21705536K->2411712K(21705536K), 1.6734810 secs]
37247393K->21593275K(72624960K), 1.6736210 secs] [Times: user=17.86
sys=0.02, real=1.67 secs]�
2012-09-19T21:22:03.676-0400: 1226992.874: [GC 1226992.874: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2359544128 bytes, 2359544128 total
: 21698140K->2411712K(21705536K), 1.5900630 secs]
40879703K->26065388K(72624960K), 1.5902130 secs] [Times: user=22.22
sys=0.03, real=1.59 secs]�
2012-09-19T21:30:07.129-0400: 1227476.328: [GC 1227476.328: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2322355976 bytes, 2322355976 total
: 21705536K->2411712K(21705536K), 1.4599960 secs]
45359212K->30244494K(72624960K), 1.4601440 secs] [Times: user=19.61
sys=0.02, real=1.46 secs]�
2012-09-19T21:35:58.724-0400: 1227827.923: [GC 1227827.923: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2126455984 bytes, 2126455984 total
: 21705536K->2411712K(21705536K), 1.1943990 secs]
49538318K->33251004K(72624960K), 1.1945480 secs] [Times: user=16.99
sys=0.06, real=1.19 secs]�
2012-09-19T21:38:16.509-0400: 1227965.707: [GC 1227965.707: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2192233656 bytes, 2192233656 total
: 21702996K->2411712K(21705536K), 1.4159820 secs]
52542289K->36592338K(72624960K), 1.4161290 secs] [Times: user=18.43
sys=0.04, real=1.42 secs]�
2012-09-19T21:38:17.927-0400: 1227967.126: [GC [1 CMS-initial-mark:
34180626K(50919424K)] 36603628K(72624960K), 0.8771240 secs] [Times:
user=0.88 sys=0.00, real=0.88 secs]�
2012-09-19T21:38:18.805-0400: 1227968.003: [CMS-concurrent-mark-start]
2012-09-19T21:38:20.392-0400: 1227969.590: [CMS-concurrent-mark:
1.585/1.587 secs] [Times: user=9.25 sys=0.04, real=1.59 secs]�
2012-09-19T21:38:20.392-0400: 1227969.590: [CMS-concurrent-preclean-start]
2012-09-19T21:38:20.540-0400: 1227969.738: [CMS-concurrent-preclean:
0.147/0.148 secs] [Times: user=0.16 sys=0.00, real=0.15 secs]�
2012-09-19T21:38:20.540-0400: 1227969.738:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T21:38:25.599-0400: 1227974.798:
[CMS-concurrent-abortable-preclean: 5.057/5.059 secs] [Times: user=6.93
sys=0.03, real=5.05 secs]�
2012-09-19T21:38:25.599-0400: 1227974.798: [GC[YG occupancy: 3408080 K
(21705536 K)]1227974.798: [Rescan (parallel) , 0.1828490 secs]1227974.981:
[weak refs processing, 0.5776630 secs] [1 CMS-remark: 34180626K(50919424K)]
37588706K(72624960K), 0.7612650 secs] [Times: user=13.30 sys=0.01,
real=0.77 secs]�
2012-09-19T21:38:26.361-0400: 1227975.559: [CMS-concurrent-sweep-start]
2012-09-19T21:38:53.118-0400: 1228002.316: [CMS-concurrent-sweep:
26.755/26.757 secs] [Times: user=30.59 sys=0.14, real=26.75 secs]�
2012-09-19T21:38:53.118-0400: 1228002.316: [CMS-concurrent-reset-start]
2012-09-19T21:38:53.228-0400: 1228002.426: [CMS-concurrent-reset:
0.110/0.110 secs] [Times: user=0.11 sys=0.00, real=0.11 secs]�
2012-09-19T21:43:05.820-0400: 1228255.019: [GC 1228255.019: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2209508208 bytes, 2209508208 total
: 21705536K->2411712K(21705536K), 1.3205270 secs]
35925428K->19722076K(72624960K), 1.3206750 secs] [Times: user=15.46
sys=0.01, real=1.32 secs]�
2012-09-19T21:50:46.207-0400: 1228715.406: [GC 1228715.406: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2071614968 bytes, 2071614968 total
: 21705536K->2411712K(21705536K), 0.8427720 secs]
39015900K->21921652K(72624960K), 0.8429240 secs] [Times: user=12.41
sys=0.01, real=0.84 secs]�
2012-09-19T21:51:25.252-0400: 1228754.451: [GC 1228754.451: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2163450112 bytes, 2163450112 total
: 21705536K->2411712K(21705536K), 1.1751760 secs]
41215476K->24397543K(72624960K), 1.1753160 secs] [Times: user=16.61
sys=0.02, real=1.18 secs]�
2012-09-19T21:54:40.630-0400: 1228949.828: [GC 1228949.828: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2365406144 bytes, 2365406144 total
: 21705536K->2411712K(21705536K), 1.3015300 secs]
43691367K->27381459K(72624960K), 1.3016730 secs] [Times: user=17.42
sys=0.03, real=1.30 secs]�
2012-09-19T22:01:06.456-0400: 1229335.654: [GC 1229335.654: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2345594640 bytes, 2345594640 total
: 21705536K->2411712K(21705536K), 0.9276090 secs]
46675283K->30377281K(72624960K), 0.9277610 secs] [Times: user=14.09
sys=0.03, real=0.92 secs]�
2012-09-19T22:05:48.230-0400: 1229617.428: [GC 1229617.428: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2351394248 bytes, 2351394248 total
: 21705536K->2411712K(21705536K), 1.3992780 secs]
49671105K->33691395K(72624960K), 1.3994270 secs] [Times: user=20.47
sys=0.03, real=1.40 secs]�
2012-09-19T22:06:45.242-0400: 1229674.440: [GC 1229674.440: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 1413815928 bytes, 1413815928 total
: 21704375K->2411712K(21705536K), 1.4582500 secs]
52984058K->36514764K(72624960K), 1.4583930 secs] [Times: user=17.37
sys=0.03, real=1.45 secs]�
2012-09-19T22:06:46.703-0400: 1229675.901: [GC [1 CMS-initial-mark:
34103052K(50919424K)] 36526012K(72624960K), 0.5981120 secs] [Times:
user=0.60 sys=0.00, real=0.59 secs]�
2012-09-19T22:06:47.301-0400: 1229676.500: [CMS-concurrent-mark-start]
2012-09-19T22:06:49.054-0400: 1229678.252: [CMS-concurrent-mark:
1.753/1.753 secs] [Times: user=11.37 sys=0.37, real=1.76 secs]�
2012-09-19T22:06:49.054-0400: 1229678.252: [CMS-concurrent-preclean-start]
2012-09-19T22:06:49.209-0400: 1229678.407: [CMS-concurrent-preclean:
0.154/0.155 secs] [Times: user=0.22 sys=0.00, real=0.15 secs]�
2012-09-19T22:06:49.209-0400: 1229678.407:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T22:06:54.494-0400: 1229683.692:
[CMS-concurrent-abortable-preclean: 5.281/5.285 secs] [Times: user=6.54
sys=0.03, real=5.29 secs]�
2012-09-19T22:06:54.494-0400: 1229683.693: [GC[YG occupancy: 3174440 K
(21705536 K)]1229683.693: [Rescan (parallel) , 0.1567660 secs]1229683.850:
[weak refs processing, 0.5073830 secs] [1 CMS-remark: 34103052K(50919424K)]
37277493K(72624960K), 0.6650760 secs] [Times: user=11.50 sys=0.00,
real=0.66 secs]�
2012-09-19T22:06:55.160-0400: 1229684.358: [CMS-concurrent-sweep-start]
2012-09-19T22:07:25.215-0400: 1229714.413: [CMS-concurrent-sweep:
30.053/30.055 secs] [Times: user=37.54 sys=0.11, real=30.05 secs]�
2012-09-19T22:07:25.215-0400: 1229714.413: [CMS-concurrent-reset-start]
2012-09-19T22:07:25.325-0400: 1229714.523: [CMS-concurrent-reset:
0.110/0.110 secs] [Times: user=0.16 sys=0.00, real=0.11 secs]�
2012-09-19T22:10:27.152-0400: 1229896.350: [GC 1229896.350: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2415697816 bytes, 2415697816 total
: 21705536K->2411712K(21705536K), 1.0934160 secs]
34674839K->17895359K(72624960K), 1.0935660 secs] [Times: user=14.40
sys=0.01, real=1.09 secs]�
2012-09-19T22:18:07.770-0400: 1230356.968: [GC 1230356.968: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2210607072 bytes, 2210607072 total
: 21705536K->2411712K(21705536K), 1.0761930 secs]
37189183K->21087317K(72624960K), 1.0763400 secs] [Times: user=14.42
sys=0.03, real=1.08 secs]�
2012-09-19T22:21:02.740-0400: 1230531.938: [GC 1230531.938: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2426521024 bytes, 2426521024 total
: 21705536K->2411712K(21705536K), 1.2050320 secs]
40381141K->23697395K(72624960K), 1.2051860 secs] [Times: user=17.78
sys=0.02, real=1.20 secs]�
2012-09-19T22:23:28.966-0400: 1230678.164: [GC 1230678.164: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2344033000 bytes, 2344033000 total
: 21703357K->2411712K(21705536K), 1.6559260 secs]
42989040K->27830871K(72624960K), 1.6560720 secs] [Times: user=21.01
sys=0.02, real=1.66 secs]�
2012-09-19T22:29:18.303-0400: 1231027.502: [GC 1231027.502: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2224648144 bytes, 2224648144 total
: 21705536K->2411712K(21705536K), 0.9591950 secs]
47124695K->30961885K(72624960K), 0.9593420 secs] [Times: user=14.24
sys=0.04, real=0.96 secs]�
2012-09-19T22:36:29.735-0400: 1231458.933: [GC 1231458.933: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2077457056 bytes, 2077457056 total
: 21705536K->2411712K(21705536K), 0.9120650 secs]
50255709K->33474640K(72624960K), 0.9122030 secs] [Times: user=13.41
sys=0.02, real=0.91 secs]�
2012-09-19T22:41:57.371-0400: 1231786.569: [GC 1231786.569: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2400642016 bytes, 2400642016 total
: 21705536K->2411712K(21705536K), 1.8151110 secs]
52768464K->38581380K(72624960K), 1.8152680 secs] [Times: user=26.11
sys=0.03, real=1.81 secs]�
2012-09-19T22:41:59.187-0400: 1231788.385: [GC [1 CMS-initial-mark:
36169668K(50919424K)] 38581406K(72624960K), 0.8194020 secs] [Times:
user=0.82 sys=0.00, real=0.82 secs]�
2012-09-19T22:42:00.006-0400: 1231789.205: [CMS-concurrent-mark-start]
2012-09-19T22:42:01.789-0400: 1231790.988: [CMS-concurrent-mark:
1.781/1.783 secs] [Times: user=9.16 sys=0.03, real=1.79 secs]�
2012-09-19T22:42:01.790-0400: 1231790.988: [CMS-concurrent-preclean-start]
2012-09-19T22:42:01.932-0400: 1231791.130: [CMS-concurrent-preclean:
0.142/0.142 secs] [Times: user=0.14 sys=0.00, real=0.14 secs]�
2012-09-19T22:42:01.932-0400: 1231791.130:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T22:42:07.452-0400: 1231796.651:
[CMS-concurrent-abortable-preclean: 5.011/5.521 secs] [Times: user=5.05
sys=0.01, real=5.52 secs]�
2012-09-19T22:42:07.453-0400: 1231796.651: [GC[YG occupancy: 2500368 K
(21705536 K)]1231796.651: [Rescan (parallel) , 0.0913870 secs]1231796.743:
[weak refs processing, 0.4235550 secs] [1 CMS-remark: 36169668K(50919424K)]
38670036K(72624960K), 0.5152170 secs] [Times: user=9.06 sys=0.00, real=0.51
secs]�
2012-09-19T22:42:07.968-0400: 1231797.167: [CMS-concurrent-sweep-start]
2012-09-19T22:42:39.765-0400: 1231828.963: [CMS-concurrent-sweep:
31.795/31.797 secs] [Times: user=34.91 sys=0.11, real=31.80 secs]�
2012-09-19T22:42:39.765-0400: 1231828.963: [CMS-concurrent-reset-start]
2012-09-19T22:42:39.877-0400: 1231829.075: [CMS-concurrent-reset:
0.112/0.112 secs] [Times: user=0.21 sys=0.00, real=0.11 secs]�
2012-09-19T22:50:24.746-0400: 1232293.945: [GC 1232293.945: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2294296616 bytes, 2294296616 total
: 21705536K->2411712K(21705536K), 1.8260460 secs]
35876437K->21127909K(72624960K), 1.8261920 secs] [Times: user=21.21
sys=0.01, real=1.83 secs]�
2012-09-19T22:55:04.459-0400: 1232573.657: [GC 1232573.657: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2413353392 bytes, 2413353392 total
: 21705536K->2411712K(21705536K), 1.6731370 secs]
40421733K->25522037K(72624960K), 1.6732850 secs] [Times: user=21.59
sys=0.02, real=1.67 secs]�
2012-09-19T23:04:19.742-0400: 1233128.940: [GC 1233128.940: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2332941528 bytes, 2332941528 total
: 21705536K->2411712K(21705536K), 1.0046690 secs]
44815861K->28970541K(72624960K), 1.0048150 secs] [Times: user=14.70
sys=0.03, real=1.00 secs]�
2012-09-19T23:06:23.531-0400: 1233252.730: [GC 1233252.730: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2276313352 bytes, 2276313352 total
: 21705536K->2411712K(21705536K), 1.1500000 secs]
48264365K->32113994K(72624960K), 1.1501500 secs] [Times: user=17.60
sys=0.02, real=1.15 secs]�
2012-09-19T23:12:20.390-0400: 1233609.589: [GC 1233609.589: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2337675920 bytes, 2337675920 total
: 21705536K->2411712K(21705536K), 1.8596780 secs]
51407818K->36175157K(72624960K), 1.8598260 secs] [Times: user=23.62
sys=0.05, real=1.86 secs]�
2012-09-19T23:12:22.250-0400: 1233611.449: [GC [1 CMS-initial-mark:
33763445K(50919424K)] 36175393K(72624960K), 0.6653750 secs] [Times:
user=0.67 sys=0.00, real=0.66 secs]�
2012-09-19T23:12:22.916-0400: 1233612.114: [CMS-concurrent-mark-start]
2012-09-19T23:12:24.653-0400: 1233613.852: [CMS-concurrent-mark:
1.735/1.737 secs] [Times: user=10.07 sys=0.25, real=1.74 secs]�
2012-09-19T23:12:24.653-0400: 1233613.852: [CMS-concurrent-preclean-start]
2012-09-19T23:12:24.816-0400: 1233614.015: [CMS-concurrent-preclean:
0.161/0.163 secs] [Times: user=0.17 sys=0.00, real=0.17 secs]�
2012-09-19T23:12:24.816-0400: 1233614.015:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T23:12:30.537-0400: 1233619.736:
[CMS-concurrent-abortable-preclean: 5.599/5.721 secs] [Times: user=6.55
sys=0.02, real=5.72 secs]�
2012-09-19T23:12:30.538-0400: 1233619.736: [GC[YG occupancy: 2965629 K
(21705536 K)]1233619.736: [Rescan (parallel) , 0.1588340 secs]1233619.895:
[weak refs processing, 0.4072150 secs] [1 CMS-remark: 33763445K(50919424K)]
36729074K(72624960K), 0.5678800 secs] [Times: user=9.72 sys=0.01, real=0.56
secs]�
2012-09-19T23:12:31.106-0400: 1233620.304: [CMS-concurrent-sweep-start]
2012-09-19T23:13:08.154-0400: 1233657.353: [CMS-concurrent-sweep:
37.046/37.048 secs] [Times: user=41.77 sys=0.15, real=37.05 secs]�
2012-09-19T23:13:08.154-0400: 1233657.353: [CMS-concurrent-reset-start]
2012-09-19T23:13:08.264-0400: 1233657.463: [CMS-concurrent-reset:
0.110/0.110 secs] [Times: user=0.13 sys=0.00, real=0.11 secs]�
2012-09-19T23:20:45.125-0400: 1234114.324: [GC 1234114.324: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2358578488 bytes, 2358578488 total
: 21705536K->2411712K(21705536K), 1.5124070 secs]
35905333K->20143067K(72624960K), 1.5125550 secs] [Times: user=18.48
sys=0.02, real=1.51 secs]�
2012-09-19T23:22:22.427-0400: 1234211.626: [GC 1234211.626: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 1860644016 bytes, 1860644016 total
: 21705536K->2411712K(21705536K), 1.4687990 secs]
39436891K->23086447K(72624960K), 1.4689390 secs] [Times: user=17.86
sys=0.04, real=1.47 secs]�
2012-09-19T23:29:27.741-0400: 1234636.939: [GC 1234636.939: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2402944632 bytes, 2402944632 total
: 21705536K->2411712K(21705536K), 0.9468950 secs]
42380271K->26714172K(72624960K), 0.9470810 secs] [Times: user=15.04
sys=0.02, real=0.95 secs]�
2012-09-19T23:35:29.046-0400: 1234998.244: [GC 1234998.244: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2348032512 bytes, 2348032512 total
: 21705536K->2411712K(21705536K), 1.4391510 secs]
46007996K->29989355K(72624960K), 1.4393020 secs] [Times: user=20.27
sys=0.04, real=1.43 secs]�
2012-09-19T23:37:41.522-0400: 1235130.721: [GC 1235130.721: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2216575440 bytes, 2216575440 total
: 21705536K->2411712K(21705536K), 1.4460970 secs]
49283179K->32964170K(72624960K), 1.4462370 secs] [Times: user=18.16
sys=0.04, real=1.45 secs]�
2012-09-19T23:46:52.635-0400: 1235681.833: [GC 1235681.833: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2338136864 bytes, 2338136864 total
: 21705536K->2411712K(21705536K), 1.0007820 secs]
52257994K->36539452K(72624960K), 1.0009280 secs] [Times: user=15.23
sys=0.03, real=1.00 secs]�
2012-09-19T23:46:53.636-0400: 1235682.835: [GC [1 CMS-initial-mark:
34127740K(50919424K)] 36539476K(72624960K), 0.7711200 secs] [Times:
user=0.78 sys=0.00, real=0.77 secs]�
2012-09-19T23:46:54.407-0400: 1235683.606: [CMS-concurrent-mark-start]
2012-09-19T23:46:56.165-0400: 1235685.364: [CMS-concurrent-mark:
1.755/1.758 secs] [Times: user=10.27 sys=0.04, real=1.76 secs]�
2012-09-19T23:46:56.165-0400: 1235685.364: [CMS-concurrent-preclean-start]
2012-09-19T23:46:56.324-0400: 1235685.523: [CMS-concurrent-preclean:
0.157/0.159 secs] [Times: user=0.26 sys=0.01, real=0.16 secs]�
2012-09-19T23:46:56.325-0400: 1235685.523:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-19T23:47:02.215-0400: 1235691.413:
[CMS-concurrent-abortable-preclean: 5.579/5.891 secs] [Times: user=5.90
sys=0.01, real=5.89 secs]�
2012-09-19T23:47:02.216-0400: 1235691.414: [GC[YG occupancy: 2699015 K
(21705536 K)]1235691.414: [Rescan (parallel) , 0.1079030 secs]1235691.522:
[weak refs processing, 0.4813260 secs] [1 CMS-remark: 34127740K(50919424K)]
36826755K(72624960K), 0.5900810 secs] [Times: user=10.42 sys=0.01,
real=0.59 secs]�
2012-09-19T23:47:02.806-0400: 1235692.004: [CMS-concurrent-sweep-start]
2012-09-19T23:47:30.159-0400: 1235719.358: [CMS-concurrent-sweep:
27.349/27.354 secs] [Times: user=30.05 sys=0.08, real=27.35 secs]�
2012-09-19T23:47:30.159-0400: 1235719.358: [CMS-concurrent-reset-start]
2012-09-19T23:47:30.270-0400: 1235719.468: [CMS-concurrent-reset:
0.110/0.110 secs] [Times: user=0.18 sys=0.00, real=0.11 secs]�
2012-09-19T23:50:52.990-0400: 1235922.189: [GC 1235922.189: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2334894992 bytes, 2334894992 total
: 21705536K->2411712K(21705536K), 1.7766110 secs]
37041097K->21016169K(72624960K), 1.7767530 secs] [Times: user=21.41
sys=0.03, real=1.78 secs]�
2012-09-19T23:54:39.306-0400: 1236148.504: [GC 1236148.504: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2318030184 bytes, 2318030184 total
: 21705536K->2411712K(21705536K), 1.6101610 secs]
40309993K->24554312K(72624960K), 1.6103040 secs] [Times: user=20.23
sys=0.03, real=1.61 secs]�
2012-09-20T00:03:37.892-0400: 1236687.091: [GC 1236687.091: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2344234304 bytes, 2344234304 total
: 21705536K->2411712K(21705536K), 1.0148350 secs]
43848136K->27869199K(72624960K), 1.0149720 secs] [Times: user=14.84
sys=0.06, real=1.01 secs]�
2012-09-20T00:10:04.216-0400: 1237073.414: [GC 1237073.414: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2441376240 bytes, 2441376240 total
: 21705536K->2411712K(21705536K), 1.2224260 secs]
47163023K->31993375K(72624960K), 1.2225700 secs] [Times: user=18.71
sys=0.03, real=1.22 secs]�
2012-09-20T00:20:22.840-0400: 1237692.038: [GC 1237692.038: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2376625224 bytes, 2376625224 total
: 21705536K->2411712K(21705536K), 1.5113490 secs]
51287199K->36778679K(72624960K), 1.5115310 secs] [Times: user=21.57
sys=0.02, real=1.51 secs]�
2012-09-20T00:20:24.352-0400: 1237693.550: [GC [1 CMS-initial-mark:
34366967K(50919424K)] 36867490K(72624960K), 1.4484480 secs] [Times:
user=1.45 sys=0.00, real=1.45 secs]�
2012-09-20T00:20:25.800-0400: 1237694.999: [CMS-concurrent-mark-start]
2012-09-20T00:20:27.323-0400: 1237696.521: [CMS-concurrent-mark:
1.520/1.523 secs] [Times: user=9.60 sys=0.01, real=1.52 secs]�
2012-09-20T00:20:27.323-0400: 1237696.521: [CMS-concurrent-preclean-start]
2012-09-20T00:20:27.470-0400: 1237696.669: [CMS-concurrent-preclean:
0.147/0.147 secs] [Times: user=0.29 sys=0.00, real=0.15 secs]�
2012-09-20T00:20:27.470-0400: 1237696.669:
[CMS-concurrent-abortable-preclean-start]
�CMS: abort preclean due to time 2012-09-20T00:20:33.206-0400: 1237702.405:
[CMS-concurrent-abortable-preclean: 5.733/5.736 secs] [Times: user=13.27
sys=0.03, real=5.74 secs]�
2012-09-20T00:20:33.208-0400: 1237702.406: [GC[YG occupancy: 4773144 K
(21705536 K)]1237702.406: [Rescan (parallel) , 0.4220490 secs]1237702.828:
[weak refs processing, 0.5246790 secs] [1 CMS-remark: 34366967K(50919424K)]
39140111K(72624960K), 0.9472340 secs] [Times: user=16.13 sys=0.02,
real=0.94 secs]�
2012-09-20T00:20:34.155-0400: 1237703.353: [CMS-concurrent-sweep-start]
2012-09-20T00:21:02.963-0400: 1237732.162: [CMS-concurrent-sweep:
28.805/28.808 secs] [Times: user=44.27 sys=0.09, real=28.81 secs]�
2012-09-20T00:21:02.963-0400: 1237732.162: [CMS-concurrent-reset-start]
2012-09-20T00:21:03.075-0400: 1237732.274: [CMS-concurrent-reset:
0.112/0.112 secs] [Times: user=0.22 sys=0.00, real=0.11 secs]�
2012-09-20T00:28:22.906-0400: 1238172.105: [GC 1238172.105: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2180555272 bytes, 2180555272 total
: 21700246K->2411712K(21705536K), 2.2482870 secs]
37361406K->23665555K(72624960K), 2.2484350 secs] [Times: user=25.54
sys=0.04, real=2.25 secs]�
2012-09-20T00:36:35.279-0400: 1238664.478: [GC 1238664.478: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2399466536 bytes, 2399466536 total
: 21705536K->2411712K(21705536K), 1.2165830 secs]
42959379K->26796541K(72624960K), 1.2167290 secs] [Times: user=17.77
sys=0.02, real=1.21 secs]�
2012-09-20T00:41:58.241-0400: 1238987.439: [GC 1238987.439: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2379780352 bytes, 2379780352 total
: 21705536K->2411712K(21705536K), 1.5069060 secs]
46090365K->30828849K(72624960K), 1.5070520 secs] [Times: user=20.20
sys=0.03, real=1.51 secs]�
2012-09-20T00:53:39.025-0400: 1239688.223: [GC 1239688.223: [ParNew
Desired survivor size 1234796544 bytes, new threshold 1 (max 4)
- age � 1: 2401140664 bytes, 2401140664 total
: 21705536K->2411712K(21705536K), 1.3168800 secs]
50122673K->34513451K(72624960K), 1.3170240 secs] [Times: user=18.32
sys=0.04, real=1.32 secs]�
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20120923/198896ee/attachment-0001.html 