Promotion Failure with CMS

roz dev rozdev29 at gmail.com
Sat Sep 29 23:55:22 PDT 2012


Hi Flo

I did change the young gen to be 5gb and old gen remains at 71 gb

It seems to be doing much better. I have also added the
flag -XX:PrintFLSStatistics=1 and it is generating lots of details which I
am unable to understand.

Can you please explain the following snippet? I also see some negative
values in the logs!

2012-09-26T11:16:53.466-0400: 12.858: [GC Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 939524096
Max   Chunk Size: 939524096
Number of Blocks: 1
Av.  Block  Size: 939524096
Tree      Height: 1
Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 0
Max   Chunk Size: 0
Number of Blocks: 0
Tree      Height: 0
12.858: [ParNew
Desired survivor size 268435456 bytes, new threshold 1 (max 4)
- age   1:  533371448 bytes,  533371448 total
: 4194304K->524287K(4718592K), 2.7813530 secs]
4194304K->1350811K(79167488K)After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 832970895
Max   Chunk Size: 832970895
Number of Blocks: 1
Av.  Block  Size: 832970895
Tree      Height: 1
After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 0
Max   Chunk Size: 0
Number of Blocks: 0
Tree      Height: 0
, 2.7814790 secs] [Times: user=13.07 sys=2.08, real=2.78 secs]
2012-09-26T11:17:02.318-0400: 21.710: [GC Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 832970895
Max   Chunk Size: 832970895
Number of Blocks: 1
Av.  Block  Size: 832970895
Tree      Height: 1
Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 0
Max   Chunk Size: 0
Number of Blocks: 0
Tree      Height: 0
21.710: [ParNew
Desired survivor size 268435456 bytes, new threshold 1 (max 4)
- age   1:  536867776 bytes,  536867776 total
: 4718591K->524288K(4718592K), 1.5187290 secs]
5545115K->3258775K(79167488K)After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 586062032
Max   Chunk Size: 586062032
Number of Blocks: 1
Av.  Block  Size: 586062032
Tree      Height: 1
After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 0
Max   Chunk Size: 0
Number of Blocks: 0
Tree      Height: 0
, 1.5188420 secs] [Times: user=17.75 sys=1.45, real=1.52 secs]
2012-09-26T11:17:10.114-0400: 29.506: [GC Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 586062032
Max   Chunk Size: 586062032
Number of Blocks: 1
Av.  Block  Size: 586062032
Tree      Height: 1
Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 0
Max   Chunk Size: 0
Number of Blocks: 0
Tree      Height: 0
29.506: [ParNew
Desired survivor size 268435456 bytes, new threshold 1 (max 4)
- age   1:  536867728 bytes,  536867728 total
: 4718592K->524288K(4718592K), 1.5884280 secs]
7453079K->5253131K(79167488K)After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 330538004
Max   Chunk Size: 330538004
Number of Blocks: 1
Av.  Block  Size: 330538004
Tree      Height: 1
After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 0
Max   Chunk Size: 0
Number of Blocks: 0
Tree      Height: 0
, 1.5885450 secs] [Times: user=18.91 sys=1.11, real=1.58 secs]
2012-09-26T11:17:56.698-0400: 76.090: [GC Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 330538004
Max   Chunk Size: 330538004
Number of Blocks: 1
Av.  Block  Size: 330538004
Tree      Height: 1
Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 0
Max   Chunk Size: 0
Number of Blocks: 0
Tree      Height: 0
76.090: [ParNew
Desired survivor size 268435456 bytes, new threshold 1 (max 4)
- age   1:  533393704 bytes,  533393704 total
: 4714804K->524288K(4718592K), 0.5038280 secs]
9443648K->6771727K(79167488K)After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 136647554
Max   Chunk Size: 136647554
Number of Blocks: 1
Av.  Block  Size: 136647554
Tree      Height: 1
After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 0
Max   Chunk Size: 0
Number of Blocks: 0
Tree      Height: 0
, 0.5039750 secs] [Times: user=4.79 sys=1.70, real=0.51 secs]
2012-09-26T11:18:15.041-0400: 94.433: [GC Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 136647554
Max   Chunk Size: 136647554
Number of Blocks: 1
Av.  Block  Size: 136647554
Tree      Height: 1
Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 0
Max   Chunk Size: 0
Number of Blocks: 0
Tree      Height: 0
94.433: [ParNew
Desired survivor size 268435456 bytes, new threshold 1 (max 4)
- age   1:  528800632 bytes,  528800632 total
: 4718592K->524288K(4718592K), 0.4277130 secs]
10966031K->8539624K(79167488K)After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: -89872095
Max   Chunk Size: -89872095
Number of Blocks: 1
Av.  Block  Size: -89872095
Tree      Height: 1
After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 0
Max   Chunk Size: 0
Number of Blocks: 0
Tree      Height: 0
, 0.4278530 secs] [Times: user=4.05 sys=2.63, real=0.43 secs]
2012-09-26T11:18:28.863-0400: 108.255: [GC Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: -89872095
Max   Chunk Size: -89872095
Number of Blocks: 1
Av.  Block  Size: -89872095
Tree      Height: 1
Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 0
Max   Chunk Size: 0
Number of Blocks: 0
Tree      Height: 0
108.255: [ParNew
Desired survivor size 268435456 bytes, new threshold 1 (max 4)
- age   1:  486933200 bytes,  486933200 total
: 4718592K->524288K(4718592K), 0.3134540 secs]
12733928K->9945250K(79167488K)After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: -269607864
Max   Chunk Size: -269607864
Number of Blocks: 1
Av.  Block  Size: -269607864
Tree      Height: 1
After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 0
Max   Chunk Size: 0
Number of Blocks: 0
Tree      Height: 0
, 0.3135850 secs] [Times: user=3.11 sys=1.83, real=0.32 secs]
2012-09-26T11:18:51.898-0400: 131.290: [GC Before GC:

Thanks
Saroj


On Wed, Sep 26, 2012 at 3:29 AM, Florian Binder <java at java4.info> wrote:

>  Hi Saroj,
>
> no every object is promoted separately. But if you have some large arrays
> you need some large chunks for them. So in your case you do not need 2gb of
> contiguous free space but a lot of contiguous 200kb to 30mb chunks.
> With -XX:PrintFLSStatistics=1 you get some interesting information about
> the FreeChunks which includes the MaxChunkSize as well.
>
> Flo
>
>
> Am 26.09.2012 07:55, schrieb roz dev:
>
> Hi Flo
>
>  I have a follow up question.
>
>  Is Promotion failure caused by un-availability of contiguous free space
> in old gen for whole of young gen? If my young gen has 2 GB of live data
> set which contains of objects of different sizes like 200kb to 30 mb,and
> promotion failure happens -is it because GC is trying to fit in all 2gb in
> contiguous space in old gen?
>
>  Thanks
> Saroj
>
> On Tue, Sep 25, 2012 at 3:25, roz dev <rozdev29 at gmail.com> wrote:
>
>> Hi Flo
>>
>>  Thanks for your inputs. We are using Solr 4 for doing sorting for lots
>> of searches and Solr is creating lots of arrays, behind the scene to do the
>> sorting.
>>
>>  This is causing our memory consumption to be higher than usual. We are
>> planning to change the young gen to be 5 gb and see what happens.
>>
>>  We will keep you all posted.
>>
>>  Thanks
>> Saroj
>>
>>
>> On Tue, Sep 25, 2012 at 3:16 AM, Florian Binder <java at java4.info> wrote:
>>
>>>  Hi Roz,
>>>
>>> you have a very large new generation. This results in a lot of objects
>>> being promoted in each minor collection. In your cases it tries to promote
>>> about 2gb of data to the 48gb old generation with about 16gb of free space.
>>> Probably due to fragmentation this can't be done. Do you have large objects
>>> (arrays) in your application?
>>> Have you already tried to reduce your new generation? Maybe 2gb are
>>> enough? This would result in less data for promotion and more space for the
>>> old generation which reduces fragmentation problems.
>>>
>>> Since there has been a bug resulting in (more) fragmentation you should
>>> update to >= 6u25 (see [1]).
>>>
>>> Promotion failures always result in a full (stw) collection, which took
>>> in your case 32 seconds.
>>>
>>>
>>> [1]: http://bugs.sun.com/view_bug.do?bug_id=6999988
>>>
>>> Regards,
>>> Flo
>>>
>>>
>>>
>>> Am 24.09.2012 22 <24.09.2012%2022>:50, schrieb roz dev:
>>>
>>>
>>> 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]?
>>>
>>>
>>>
>>>
>>>  _______________________________________________
>>> hotspot-gc-use mailing listhotspot-gc-use at openjdk.java.nethttp://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>>>
>>>
>>>
>>> _______________________________________________
>>> 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: http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20120929/d0cc67cd/attachment-0001.html 


More information about the hotspot-gc-use mailing list