iCMS question
Jon Masamitsu
jon.masamitsu at oracle.com
Tue Aug 31 16:14:36 PDT 2010
If a larger heap helps, consider using the survivor spaces again.
Most of the time the survivor spaces help filter out short-lived
objects from the CMS gen and keeps fragmentation down.
Good luck.
On 08/31/10 14:05, Adam Hawthorne wrote:
> Thanks, somehow I missed the obvious answer.
>
> Adam
>
> --
> Adam Hawthorne
> Software Engineer
> BASIS International Ltd.
> www.basis.com <http://www.basis.com>
> +1.505.345.5232 Phone
>
>
> On Tue, Aug 31, 2010 at 16:54, Jon Masamitsu <jon.masamitsu at oracle.com
> <mailto:jon.masamitsu at oracle.com>> wrote:
>
> I think the short answer is that your heap is full.
>
> This is a minor collection that turns into a full collection (so you
> don't see the telltale "Full GC" message).
>
>
> 2010-08-26T15:45:13.130+0200: 38710.806: [GC 38710.806: [ParNew
> (promotion failed): 235520K->235520K(235712K), 1.0952192
> secs]38711.901: [CMS2010-08-26T15:45:14.222+0200: 38711.903:
> [CMS-concurrent-mark: 1.934/5.410 secs] [Times: user=8.20
> sys=0.25, real=5.41 secs]
> (concurrent mode failure): 943043K->933853K(943744K), 4.0906398
> secs] 1172473K->933853K(1179456K), [CMS Perm :
> 97361K->97361K(131072K)] icms_dc=86 , 5.1861184 secs] [Times:
> user=5.18 sys=0.00, real=5.18 secs]
>
> After the full collection the heap is still mostly full.
>
> 943043K->933853K(943744K)
>
> I think your advice to increase the size of the should will help.
>
>
> On 08/31/10 12:36, Adam Hawthorne wrote:
>> Hi all,
>>
>> I'm looking at an i-cms log, and I don't understand why I'm
>> seeing what I'm seeing. Any help is appreciated. At about
>> 38718.035 in the log below, icms_dc begins to report 100, and
>> just after that I see several back-to-back concurrent mode
>> failures. During that time, the ParNew collections are reporting
>> that they're doing no work. This happens on and off for about 20
>> minutes in the log. Obviously the collections are taking
>> seconds, but I don't see a Full GC every time. What is it doing
>> when it's not doing a full GC? Is the continual CMS collection
>> preventing the young generation from being collected (or perhaps
>> collecting it simultaneously)? When icms_dc=100, does that imply
>> the application is stopped?
>>
>> There was some uninformed command line twiddling going on here,
>> so the GC parameters were:
>> -Xmx1152m
>> -Xms256m
>> -XX:NewRatio=4
>> -XX:MaxPermSize=128m
>> -XX:+UseParNewGC
>> -XX:-CMSParallelRemarkEnabled
>> -XX:+UseConcMarkSweepGC
>> -XX:+CMSPermGenSweepingEnabled
>> -XX:+UseCMSCompactAtFullCollection
>> -XX:CMSFullGCsBeforeCompaction=1
>> -XX:+CMSClassUnloadingEnabled
>> -XX:+CMSIncrementalMode
>> -XX:+CMSIncrementalPacing
>> -XX:CMSInitiatingOccupancyFraction=50
>> -XX:ParallelGCThreads=1
>> -XX:MaxTenuringThreshold=0
>> -XX:SurvivorRatio=1024
>> -XX:SoftRefLRUPolicyMSPerMB=1000
>> -XX:+DisableExplicitGC
>> -XX:+PrintGCDetails
>> -XX:+PrintGCTimeStamps
>> -XX:+PrintGCDateStamps
>>
>> I had them
>> remove -XX:ParallelGCThreads=1, -XX:MaxTenuringThreshold=0,
>> and -XX:SurvivorRatio=1024 , thinking that since the duty cycle
>> was approaching 100%, and because the ParNew pause times were so
>> low, we could probably afford to spend more time doing young gc's
>> instead of promoting. I'm thinking I should probably tell them
>> to increase their -Xmx and decrease their NewRatio as well. Is
>> there anything else? I haven't done much tuning of i-cms in
>> general, but the standard i-cms safety options don't seem like
>> they would help here.
>>
>> Here's the log excerpt:
>>
>> 2010-08-26T15:44:42.836+0200: 38680.510: [GC 38680.510: [ParNew:
>> 235520K->0K(235712K), 0.0187551 secs] 1158126K->923156K(1179456K)
>> icms_dc=41 , 0.0189305 secs] [Times: user=0.02 sys=0.00,
>> real=0.02 secs]
>> 2010-08-26T15:44:43.179+0200: 38680.861: [GC [1 CMS-initial-mark:
>> 923156K(943744K)] 996964K(1179456K), 0.0526219 secs] [Times:
>> user=0.06 sys=0.00, real=0.06 secs]
>> 2010-08-26T15:44:43.241+0200: 38680.914: [CMS-concurrent-mark-start]
>> 2010-08-26T15:44:44.021+0200: 38681.695: [GC 38681.695: [ParNew:
>> 235520K->0K(235712K), 0.0196054 secs] 1158676K->923705K(1179456K)
>> icms_dc=41 , 0.0197785 secs] [Times: user=0.02 sys=0.00,
>> real=0.02 secs]
>> 2010-08-26T15:44:45.160+0200: 38682.831: [GC 38682.831: [ParNew:
>> 235520K->0K(235712K), 0.0199663 secs] 1159225K->924310K(1179456K)
>> icms_dc=41 , 0.0201448 secs] [Times: user=0.01 sys=0.00,
>> real=0.02 secs]
>> 2010-08-26T15:44:46.127+0200: 38683.797: [GC 38683.797: [ParNew:
>> 235520K->0K(235712K), 0.0549963 secs] 1159830K->930710K(1179456K)
>> icms_dc=56 , 0.0551800 secs] [Times: user=0.05 sys=0.00,
>> real=0.05 secs]
>> 2010-08-26T15:44:47.562+0200: 38685.246: [CMS-concurrent-mark:
>> 1.903/4.332 secs] [Times: user=6.77 sys=0.25, real=4.32 secs]
>> 2010-08-26T15:44:47.562+0200: 38685.246:
>> [CMS-concurrent-preclean-start]
>> 2010-08-26T15:44:47.828+0200: 38685.506: [GC 38685.507: [ParNew:
>> 235520K->0K(235712K), 0.0180149 secs] 1166230K->931150K(1179456K)
>> icms_dc=56 , 0.0182051 secs] [Times: user=0.02 sys=0.00,
>> real=0.01 secs]
>> 2010-08-26T15:44:48.108+0200: 38685.790:
>> [CMS-concurrent-preclean: 0.023/0.543 secs] [Times: user=0.55
>> sys=0.05, real=0.55 secs]
>> 2010-08-26T15:44:48.108+0200: 38685.790:
>> [CMS-concurrent-abortable-preclean-start]
>> 2010-08-26T15:44:48.483+0200: 38686.158:
>> [CMS-concurrent-abortable-preclean: 0.040/0.368 secs] [Times:
>> user=0.41 sys=0.02, real=0.38 secs]
>> 2010-08-26T15:44:48.483+0200: 38686.159: [GC[YG occupancy: 136856
>> K (235712 K)]38686.159: [Rescan (non-parallel) 38686.159: [grey
>> object rescan, 0.0041031 secs]38686.163: [root rescan, 0.1153851
>> secs], 0.1195876 secs]38686.279: [weak refs processing, 0.0012088
>> secs]38686.280: [class unloading, 0.0143079 secs]38686.294:
>> [scrub symbol & string tables, 0.0159790 secs] [1 CMS-remark:
>> 931150K(943744K)] 1068006K(1179456K), 0.1563910 secs] [Times:
>> user=0.16 sys=0.00, real=0.16 secs]
>> 2010-08-26T15:44:48.639+0200: 38686.316: [CMS-concurrent-sweep-start]
>> 2010-08-26T15:44:49.138+0200: 38686.808: [GC 38686.808: [ParNew:
>> 235520K->0K(235712K), 0.0183463 secs] 1166540K->931466K(1179456K)
>> icms_dc=56 , 0.0185256 secs] [Times: user=0.02 sys=0.00,
>> real=0.02 secs]
>> 2010-08-26T15:44:49.637+0200: 38687.307: [CMS-concurrent-sweep:
>> 0.470/0.992 secs] [Times: user=1.47 sys=0.02, real=1.00 secs]
>> 2010-08-26T15:44:49.637+0200: 38687.307: [CMS-concurrent-reset-start]
>> 2010-08-26T15:44:49.637+0200: 38687.313: [CMS-concurrent-reset:
>> 0.005/0.005 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
>> 2010-08-26T15:44:50.277+0200: 38687.948: [GC 38687.948: [ParNew:
>> 235520K->0K(235712K), 0.0177987 secs] 1158207K->923110K(1179456K)
>> icms_dc=42 , 0.0179840 secs] [Times: user=0.02 sys=0.00,
>> real=0.02 secs]
>> 2010-08-26T15:44:50.604+0200: 38688.280: [GC [1 CMS-initial-mark:
>> 923110K(943744K)] 992484K(1179456K), 0.0509414 secs] [Times:
>> user=0.05 sys=0.00, real=0.05 secs]
>> 2010-08-26T15:44:50.651+0200: 38688.331: [CMS-concurrent-mark-start]
>> 2010-08-26T15:44:51.478+0200: 38689.157: [GC 38689.157: [ParNew:
>> 235520K->0K(235712K), 0.0178124 secs] 1158630K->923567K(1179456K)
>> icms_dc=42 , 0.0179821 secs] [Times: user=0.02 sys=0.00,
>> real=0.02 secs]
>> 2010-08-26T15:44:52.632+0200: 38690.306: [GC 38690.306: [ParNew:
>> 235520K->0K(235712K), 0.0180970 secs] 1159087K->924012K(1179456K)
>> icms_dc=42 , 0.0182661 secs] [Times: user=0.02 sys=0.00,
>> real=0.02 secs]
>> 2010-08-26T15:44:53.740+0200: 38691.422: [GC 38691.422: [ParNew:
>> 235520K->0K(235712K), 0.0267182 secs] 1159532K->925696K(1179456K)
>> icms_dc=42 , 0.0269020 secs] [Times: user=0.03 sys=0.00,
>> real=0.03 secs]
>> 2010-08-26T15:44:54.520+0200: 38692.201: [CMS-concurrent-mark:
>> 1.894/3.870 secs] [Times: user=5.74 sys=0.13, real=3.87 secs]
>> 2010-08-26T15:44:54.520+0200: 38692.201:
>> [CMS-concurrent-preclean-start]
>> 2010-08-26T15:44:54.551+0200: 38692.222:
>> [CMS-concurrent-preclean: 0.015/0.020 secs] [Times: user=0.05
>> sys=0.02, real=0.03 secs]
>> 2010-08-26T15:44:54.551+0200: 38692.222:
>> [CMS-concurrent-abortable-preclean-start]
>> 2010-08-26T15:44:54.894+0200: 38692.573: [GC 38692.573: [ParNew:
>> 235520K->0K(235712K), 0.0186037 secs] 1161216K->926149K(1179456K)
>> icms_dc=42 , 0.0187843 secs] [Times: user=0.02 sys=0.00,
>> real=0.02 secs]
>> 2010-08-26T15:44:55.581+0200: 38693.250:
>> [CMS-concurrent-abortable-preclean: 0.050/1.028 secs] [Times:
>> user=1.05 sys=0.01, real=1.03 secs]
>> 2010-08-26T15:44:55.581+0200: 38693.251: [GC[YG occupancy: 140686
>> K (235712 K)]38693.251: [Rescan (non-parallel) 38693.251: [grey
>> object rescan, 0.0043953 secs]38693.255: [root rescan, 0.1209735
>> secs], 0.1254680 secs]38693.376: [weak refs processing, 0.0013433
>> secs]38693.378: [class unloading, 0.0142815 secs]38693.392:
>> [scrub symbol & string tables, 0.0160091 secs] [1 CMS-remark:
>> 926149K(943744K)] 1066835K(1179456K), 0.1624119 secs] [Times:
>> user=0.16 sys=0.00, real=0.16 secs]
>> 2010-08-26T15:44:55.737+0200: 38693.414: [CMS-concurrent-sweep-start]
>> 2010-08-26T15:44:56.205+0200: 38693.879: [GC 38693.880: [ParNew:
>> 235520K->0K(235712K), 0.0188069 secs] 1161648K->926599K(1179456K)
>> icms_dc=42 , 0.0189967 secs] [Times: user=0.02 sys=0.00,
>> real=0.02 secs]
>> 2010-08-26T15:44:56.891+0200: 38694.563: [CMS-concurrent-sweep:
>> 0.474/1.149 secs] [Times: user=1.64 sys=0.02, real=1.15 secs]
>> 2010-08-26T15:44:56.891+0200: 38694.563: [CMS-concurrent-reset-start]
>> 2010-08-26T15:44:56.891+0200: 38694.569: [CMS-concurrent-reset:
>> 0.006/0.006 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
>> 2010-08-26T15:44:57.343+0200: 38695.018: [GC 38695.018: [ParNew:
>> 235520K->0K(235712K), 0.0187471 secs] 1156567K->921554K(1179456K)
>> icms_dc=32 , 0.0189332 secs] [Times: user=0.02 sys=0.00,
>> real=0.02 secs]
>> 2010-08-26T15:44:57.718+0200: 38695.402: [GC [1 CMS-initial-mark:
>> 921554K(943744K)] 1001837K(1179456K), 0.0572313 secs] [Times:
>> user=0.06 sys=0.00, real=0.06 secs]
>> 2010-08-26T15:44:57.780+0200: 38695.460: [CMS-concurrent-mark-start]
>> 2010-08-26T15:44:58.545+0200: 38696.224: [GC 38696.225: [ParNew:
>> 235520K->0K(235712K), 0.0183404 secs] 1157074K->922009K(1179456K)
>> icms_dc=32 , 0.0185097 secs] [Times: user=0.02 sys=0.00,
>> real=0.01 secs]
>> 2010-08-26T15:45:00.167+0200: 38697.850: [GC 38697.850: [ParNew:
>> 235520K->0K(235712K), 0.0196135 secs] 1157529K->922547K(1179456K)
>> icms_dc=32 , 0.0197977 secs] [Times: user=0.03 sys=0.00,
>> real=0.03 secs]
>> 2010-08-26T15:45:01.321+0200: 38698.992: [GC 38698.992: [ParNew:
>> 235520K->0K(235712K), 0.0187905 secs] 1158067K->923023K(1179456K)
>> icms_dc=32 , 0.0189818 secs] [Times: user=0.01 sys=0.00,
>> real=0.02 secs]
>> 2010-08-26T15:45:02.476+0200: 38700.146: [GC 38700.146: [ParNew:
>> 235520K->0K(235712K), 0.0180207 secs] 1158543K->923471K(1179456K)
>> icms_dc=32 , 0.0181892 secs] [Times: user=0.01 sys=0.00,
>> real=0.01 secs]
>> 2010-08-26T15:45:03.615+0200: 38701.284: [GC 38701.284: [ParNew:
>> 235520K->0K(235712K), 0.0186408 secs] 1158991K->923976K(1179456K)
>> icms_dc=32 , 0.0188287 secs] [Times: user=0.02 sys=0.00,
>> real=0.02 secs]
>> 2010-08-26T15:45:04.051+0200: 38701.735: [CMS-concurrent-mark:
>> 1.899/6.275 secs] [Times: user=8.16 sys=0.06, real=6.27 secs]
>> 2010-08-26T15:45:04.051+0200: 38701.735:
>> [CMS-concurrent-preclean-start]
>> 2010-08-26T15:45:04.083+0200: 38701.756:
>> [CMS-concurrent-preclean: 0.016/0.021 secs] [Times: user=0.05
>> sys=0.02, real=0.03 secs]
>> 2010-08-26T15:45:04.083+0200: 38701.756:
>> [CMS-concurrent-abortable-preclean-start]
>> 2010-08-26T15:45:04.753+0200: 38702.434: [GC 38702.435: [ParNew:
>> 235520K->0K(235712K), 0.0184004 secs] 1159496K->924427K(1179456K)
>> icms_dc=32 , 0.0185851 secs] [Times: user=0.02 sys=0.00,
>> real=0.02 secs]
>> 2010-08-26T15:45:05.409+0200: 38703.087:
>> [CMS-concurrent-abortable-preclean: 0.063/1.331 secs] [Times:
>> user=1.39 sys=0.03, real=1.33 secs]
>> 2010-08-26T15:45:05.409+0200: 38703.088: [GC[YG occupancy: 141725
>> K (235712 K)]38703.088: [Rescan (non-parallel) 38703.088: [grey
>> object rescan, 0.0041240 secs]38703.093: [root rescan, 0.1200361
>> secs], 0.1242579 secs]38703.213: [weak refs processing, 0.0010203
>> secs]38703.214: [class unloading, 0.0142923 secs]38703.228:
>> [scrub symbol & string tables, 0.0170438 secs] [1 CMS-remark:
>> 924427K(943744K)] 1066152K(1179456K), 0.1618864 secs] [Times:
>> user=0.17 sys=0.00, real=0.17 secs]
>> 2010-08-26T15:45:05.580+0200: 38703.250: [CMS-concurrent-sweep-start]
>> 2010-08-26T15:45:06.017+0200: 38703.687: [GC 38703.687: [ParNew:
>> 235520K->0K(235712K), 0.0425827 secs] 1159944K->929053K(1179456K)
>> icms_dc=32 , 0.0427672 secs] [Times: user=0.03 sys=0.00,
>> real=0.03 secs]
>> 2010-08-26T15:45:07.202+0200: 38704.873: [GC 38704.873: [ParNew:
>> 235520K->0K(235712K), 0.0179344 secs] 1161562K->926484K(1179456K)
>> icms_dc=32 , 0.0181045 secs] [Times: user=0.01 sys=0.00,
>> real=0.02 secs]
>> 2010-08-26T15:45:07.608+0200: 38705.282: [CMS-concurrent-sweep:
>> 0.472/2.032 secs] [Times: user=2.53 sys=0.08, real=2.03 secs]
>> 2010-08-26T15:45:07.608+0200: 38705.282: [CMS-concurrent-reset-start]
>> 2010-08-26T15:45:07.608+0200: 38705.288: [CMS-concurrent-reset:
>> 0.005/0.005 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
>> 2010-08-26T15:45:08.341+0200: 38706.012: [GC 38706.012: [ParNew:
>> 235520K->0K(235712K), 0.0180667 secs] 1162004K->926949K(1179456K)
>> icms_dc=24 , 0.0182417 secs] [Times: user=0.02 sys=0.00,
>> real=0.02 secs]
>> 2010-08-26T15:45:08.747+0200: 38706.425: [GC [1 CMS-initial-mark:
>> 926949K(943744K)] 1019208K(1179456K), 0.0677621 secs] [Times:
>> user=0.06 sys=0.00, real=0.06 secs]
>> 2010-08-26T15:45:08.809+0200: 38706.493: [CMS-concurrent-mark-start]
>> 2010-08-26T15:45:09.480+0200: 38707.158: [GC 38707.159: [ParNew:
>> 235520K->0K(235712K), 0.0477314 secs] 1162469K->932300K(1179456K)
>> icms_dc=39 , 0.0479217 secs] [Times: user=0.05 sys=0.00,
>> real=0.05 secs]
>> 2010-08-26T15:45:10.463+0200: 38708.133: [GC 38708.133: [ParNew:
>> 235520K->0K(235712K), 0.0371965 secs] 1167820K->936491K(1179456K)
>> icms_dc=54 , 0.0373840 secs] [Times: user=0.03 sys=0.00,
>> real=0.03 secs]
>> 2010-08-26T15:45:12.085+0200: 38709.770: [GC 38709.770: [ParNew:
>> 235520K->0K(235712K), 0.0185757 secs] 1172011K->936953K(1179456K)
>> icms_dc=69 , 0.0187606 secs] [Times: user=0.03 sys=0.00,
>> real=0.03 secs]
>> 2010-08-26T15:45:13.130+0200: 38710.806: [GC 38710.806: [ParNew
>> (promotion failed): 235520K->235520K(235712K), 1.0952192
>> secs]38711.901: [CMS2010-08-26T15:45:14.222+0200: 38711.903:
>> [CMS-concurrent-mark: 1.934/5.410 secs] [Times: user=8.20
>> sys=0.25, real=5.41 secs]
>> (concurrent mode failure): 943043K->933853K(943744K), 4.0906398
>> secs] 1172473K->933853K(1179456K), [CMS Perm :
>> 97361K->97361K(131072K)] icms_dc=86 , 5.1861184 secs] [Times:
>> user=5.18 sys=0.00, real=5.18 secs]
>> 2010-08-26T15:45:18.372+0200: 38716.052: [GC [1 CMS-initial-mark:
>> 933853K(943744K)] 950390K(1179456K), 0.0155216 secs] [Times:
>> user=0.01 sys=0.00, real=0.02 secs]
>> 2010-08-26T15:45:18.387+0200: 38716.068: [CMS-concurrent-mark-start]
>> 2010-08-26T15:45:19.355+0200: 38717.035: [GC 38717.035: [ParNew:
>> 235520K->0K(235712K), 0.0623713 secs] 1169373K->942749K(1179456K)
>> icms_dc=100 , 0.0625660 secs] [Times: user=0.06 sys=0.00,
>> real=0.06 secs]
>> 2010-08-26T15:45:20.509+0200: 38718.182: [CMS-concurrent-mark:
>> 1.964/2.114 secs] [Times: user=4.57 sys=0.11, real=2.12 secs]
>> 2010-08-26T15:45:20.509+0200: 38718.182:
>> [CMS-concurrent-preclean-start]
>> 2010-08-26T15:45:20.525+0200: 38718.202:
>> [CMS-concurrent-preclean: 0.015/0.020 secs] [Times: user=0.02
>> sys=0.02, real=0.02 secs]
>> 2010-08-26T15:45:20.525+0200: 38718.202:
>> [CMS-concurrent-abortable-preclean-start]
>> 2010-08-26T15:45:20.540+0200: 38718.222: [GC 38718.222: [ParNew:
>> 235520K->235520K(235712K), 0.0000592 secs]38718.222:
>> [CMS2010-08-26T15:45:20.540+0200: 38718.223:
>> [CMS-concurrent-abortable-preclean: 0.004/0.021 secs] [Times:
>> user=0.02 sys=0.00, real=0.01 secs]
>> (concurrent mode failure): 942749K->936038K(943744K), 4.0650806
>> secs] 1178269K->936038K(1179456K), [CMS Perm :
>> 97371K->97371K(131072K)] icms_dc=100 , 4.0653451 secs] [Times:
>> user=4.07 sys=0.00, real=4.07 secs]
>> 2010-08-26T15:45:24.612+0200: 38722.289: [GC [1 CMS-initial-mark:
>> 936038K(943744K)] 936042K(1179456K), 0.0023357 secs] [Times:
>> user=0.00 sys=0.00, real=0.00 secs]
>> 2010-08-26T15:45:24.612+0200: 38722.291: [CMS-concurrent-mark-start]
>> 2010-08-26T15:45:26.141+0200: 38723.817: [GC 38723.817: [ParNew:
>> 235520K->235520K(235712K), 0.0000588 secs]38723.817:
>> [CMS2010-08-26T15:45:27.030+0200: 38724.709:
>> [CMS-concurrent-mark: 1.935/2.418 secs] [Times: user=3.65
>> sys=0.19, real=2.42 secs]
>> (concurrent mode failure): 936038K->942227K(943744K), 4.9718511
>> secs] 1171558K->942227K(1179456K), [CMS Perm :
>> 97393K->97393K(131072K)] icms_dc=100 , 4.9721115 secs] [Times:
>> user=4.98 sys=0.00, real=4.98 secs]
>> 2010-08-26T15:45:31.117+0200: 38728.790: [GC [1 CMS-initial-mark:
>> 942227K(943744K)] 942270K(1179456K), 0.0025839 secs] [Times:
>> user=0.00 sys=0.00, real=0.00 secs]
>> 2010-08-26T15:45:31.117+0200: 38728.793: [CMS-concurrent-mark-start]
>> 2010-08-26T15:45:32.084+0200: 38729.758: [GC 38729.759: [ParNew:
>> 235520K->235520K(235712K), 0.0000623 secs]38729.759:
>> [CMS2010-08-26T15:45:33.051+0200: 38730.736:
>> [CMS-concurrent-mark: 1.934/1.943 secs] [Times: user=3.28
>> sys=0.19, real=1.93 secs]
>> (concurrent mode failure): 942227K->943743K(943744K), 4.9442127
>> secs] 1177747K->948024K(1179456K), [CMS Perm :
>> 97396K->97396K(131072K)] icms_dc=100 , 4.9446265 secs] [Times:
>> user=4.91 sys=0.02, real=4.94 secs]
>> 2010-08-26T15:45:37.029+0200: 38734.704: [GC [1 CMS-initial-mark:
>> 943743K(943744K)] 948026K(1179456K), 0.0067733 secs] [Times:
>> user=0.00 sys=0.00, real=0.00 secs]
>> 2010-08-26T15:45:37.029+0200: 38734.711: [CMS-concurrent-mark-start]
>> 2010-08-26T15:45:38.745+0200: 38736.419: [Full GC 38736.419:
>> [CMS2010-08-26T15:45:39.463+0200: 38737.138:
>> [CMS-concurrent-mark: 1.952/2.427 secs] [Times: user=3.95
>> sys=0.16, real=2.43 secs]
>> (concurrent mode failure): 943743K->943743K(943744K), 4.7856092
>> secs] 1179455K->949021K(1179456K), [CMS Perm :
>> 97406K->97406K(131072K)] icms_dc=100 , 4.7857927 secs] [Times:
>> user=4.79 sys=0.00, real=4.79 secs]
>> 2010-08-26T15:45:43.534+0200: 38741.206: [GC [1 CMS-initial-mark:
>> 943743K(943744K)] 949287K(1179456K), 0.0080127 secs] [Times:
>> user=0.00 sys=0.00, real=0.00 secs]
>> 2010-08-26T15:45:43.534+0200: 38741.214: [CMS-concurrent-mark-start]
>> 2010-08-26T15:45:44.455+0200: 38742.136: [Full GC 38742.136:
>> [CMS2010-08-26T15:45:45.484+0200: 38743.168:
>> [CMS-concurrent-mark: 1.952/1.954 secs] [Times: user=3.26
>> sys=0.05, real=1.95 secs]
>> (concurrent mode failure): 943743K->943743K(943744K), 4.9692415
>> secs] 1179440K->949759K(1179456K), [CMS Perm :
>> 97406K->97406K(131072K)] icms_dc=100 , 4.9694250 secs] [Times:
>> user=4.96 sys=0.02, real=4.98 secs]
>> 2010-08-26T15:45:49.883+0200: 38747.569: [GC [1 CMS-initial-mark:
>> 943743K(943744K)] 953372K(1179456K), 0.0086197 secs] [Times:
>> user=0.02 sys=0.00, real=0.02 secs]
>> 2010-08-26T15:45:49.899+0200: 38747.578: [CMS-concurrent-mark-start]
>> 2010-08-26T15:45:50.960+0200: 38748.634: [Full GC 38748.634:
>> [CMS2010-08-26T15:45:51.833+0200: 38749.515:
>> [CMS-concurrent-mark: 1.927/1.938 secs] [Times: user=3.23
>> sys=0.11, real=1.93 secs]
>> (concurrent mode failure): 943743K->937800K(943744K), 4.9818453
>> secs] 1179455K->937800K(1179456K), [CMS Perm :
>> 97407K->97407K(131072K)] icms_dc=100 , 4.9820296 secs] [Times:
>> user=4.95 sys=0.02, real=4.98 secs]
>> 2010-08-26T15:45:55.936+0200: 38753.617: [GC [1 CMS-initial-mark:
>> 937800K(943744K)] 938528K(1179456K), 0.0024408 secs] [Times:
>> user=0.00 sys=0.00, real=0.00 secs]
>> 2010-08-26T15:45:55.936+0200: 38753.620: [CMS-concurrent-mark-start]
>> 2010-08-26T15:45:56.950+0200: 38754.630: [GC 38754.631: [ParNew:
>> 235520K->235520K(235712K), 0.0000597 secs]38754.631:
>> [CMS2010-08-26T15:45:57.995+0200: 38755.679:
>> [CMS-concurrent-mark: 2.057/2.059 secs] [Times: user=3.29
>> sys=0.23, real=2.06 secs]
>> (concurrent mode failure): 937800K->936173K(943744K), 5.1274815
>> secs] 1173320K->936173K(1179456K), [CMS Perm :
>> 97407K->97407K(131072K)] icms_dc=100 , 5.1277524 secs] [Times:
>> user=5.13 sys=0.00, real=5.13 secs]
>> 2010-08-26T15:46:02.535+0200: 38760.215: [GC [1 CMS-initial-mark:
>> 936173K(943744K)] 936184K(1179456K), 0.0024186 secs] [Times:
>> user=0.00 sys=0.00, real=0.00 secs]
>> 2010-08-26T15:46:02.535+0200: 38760.218: [CMS-concurrent-mark-start]
>> 2010-08-26T15:46:03.611+0200: 38761.290: [GC 38761.290: [ParNew
>> (promotion failed): 235520K->235520K(235712K), 0.1302956
>> secs]38761.420: [CMS2010-08-26T15:46:04.609+0200: 38762.289:
>> [CMS-concurrent-mark: 1.938/2.071 secs] [Times: user=3.54
>> sys=0.11, real=2.07 secs]
>> (concurrent mode failure): 943229K->939271K(943744K), 4.9629545
>> secs] 1171693K->939271K(1179456K), [CMS Perm :
>> 97407K->97407K(131072K)] icms_dc=100 , 5.0934938 secs] [Times:
>> user=5.09 sys=0.00, real=5.10 secs]
>>
>> Thanks again for any help,
>>
>> Adam
>>
>> --
>> Adam Hawthorne
>> Software Engineer
>> BASIS International Ltd.
>> www.basis.com <http://www.basis.com>
>> +1.505.345.5232 Phone
>> ------------------------------------------------------------------------
>>
>> _______________________________________________
>> 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/20100831/1bc6f0cb/attachment-0001.html
More information about the hotspot-gc-use
mailing list