Promotion Failure with CMS
Florian Binder
java at java4.info
Sun Sep 30 14:44:37 PDT 2012
Hi Saroj,
the first dictionary is for the old gen and the second for the perm gen.
All sizes are in number of words (8 bytes on 64 bit). The negative
values are due an overflow.
See [1] for more detailed information about the promotion and the FreeLists.
[1]:
http://blog.ragozin.info/2011/11/java-gc-hotspots-cms-promotion-buffers.html
- Flo
Am 30.09.2012 08:55, schrieb roz dev:
> 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
> <mailto: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 <tel:26.09.2012%2007>: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
>> <mailto: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 <mailto: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 <tel: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 <tel:2292042936> bytes, 2292042936
>>> <tel: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 <tel:2398571736> bytes, 2398571736
>>> <tel: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 <tel:2186166456> bytes, 2186166456
>>> <tel: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 <tel:2073140800> bytes, 2073140800
>>> <tel: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 <tel:2398660792> bytes, 2398660792
>>> <tel: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 list
>>> hotspot-gc-use at openjdk.java.net <mailto:hotspot-gc-use at openjdk.java.net>
>>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>>
>>
>> _______________________________________________
>> hotspot-gc-use mailing list
>> hotspot-gc-use at openjdk.java.net
>> <mailto: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/20120930/bb923850/attachment-0001.html
More information about the hotspot-gc-use
mailing list