iCMS question

Jon Masamitsu jon.masamitsu at oracle.com
Tue Aug 31 13:54:35 PDT 2010


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
> 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/04c8eeeb/attachment-0001.html 


More information about the hotspot-gc-use mailing list