<!DOCTYPE html PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN">
<html>
<head>
<meta content="text/html;charset=windows-1252"
http-equiv="Content-Type">
</head>
<body bgcolor="#ffffff" text="#000000">
Try -XX+ParallelRefProcEnabled<br>
<br>
Your spending much of the pause time doing Reference processing<br>
<br>
89.867: [GC[YG occupancy: 420 K (274752 K)]89.867: [Rescan (parallel) ,
0.0242770 secs]89.892: [weak refs processing, 1.3860230 secs] [1
CMS-remark: 4198190K(6635136K)] 4198611K(6909888K), 1.4164670 secs]
[Times: user=1.68 sys=0.01, real=1.41 secs]<br>
<br>
(see the "[weak refs processing, 1.3860230 secs]") so doing it in
parallel might<br>
help. ParallelRefProcEnabled isn't always a win so it's not "on" by
default.<br>
<br>
You might also try -XX:+CMSScavengeBeforeRemark. That's a just a guess.<br>
Sometimes doing a minor collection before the remark helps.<br>
<br>
On 08/31/10 08:22, noam katzowicz wrote:
<blockquote cite="mid:SNT108-W11C7575D28055DFA3A6544E38A0@phx.gbl"
type="cite">
<style><!--
.hmmessage P
{
margin:0px;
padding:0px
}
body.hmmessage
{
font-size: 10pt;
font-family:Tahoma
}
--></style>Hello.<br>
<br>
We are running JBoss AS over RH5, using java 6u21, with the following
GC params:<br>
<br>
-Xms6750m -Xmx6750m <br>
-XX:+UseConcMarkSweepGC <br>
-XX:SurvivorRatio=128 <br>
-XX:MaxTenuringThreshold=0 <br>
-XX:+UseCompressedOops <br>
-XX:CMSInitiatingOccupancyFraction=60 <br>
-Dsun.rmi.dgc.client.gcInterval=3600000 <br>
-Dsun.rmi.dgc.server.gcInterval=3600000 <br>
-XX:+PrintGCTimeStamps -XX:+PrintGCDetails
-XX:+PrintTenuringDistribution<br>
<br>
We are experiencing relatively long GC pause time of over 1 second.<br>
Our application allocates hundreds of MBs per second. We’ve tried
different generation sizes but the above was the best we came up with.
Your help is appreciated.<br>
<br>
<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0596370 secs]
4422502K->4173928K(6909888K), 0.0606730 secs] [Times: user=0.44
sys=0.03, real=0.06 secs] <br>
89.486: [CMS-concurrent-preclean: 1.308/1.649 secs] [Times: user=10.32
sys=2.30, real=1.65 secs] <br>
89.487: [CMS-concurrent-abortable-preclean-start]<br>
89.804: [GC 89.804: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0603670 secs]
4446568K->4198190K(6909888K), 0.0614310 secs] [Times: user=0.48
sys=0.03, real=0.07 secs] <br>
89.866: [CMS-concurrent-abortable-preclean: 0.293/0.379 secs] [Times:
user=2.42 sys=0.54, real=0.38 secs] <br>
89.867: [GC[YG occupancy: 420 K (274752 K)]89.867: [Rescan (parallel) ,
0.0242770 secs]89.892: [weak refs processing, 1.3860230 secs] [1
CMS-remark: 4198190K(6635136K)] 4198611K(6909888K), 1.4164670 secs]
[Times: user=1.68 sys=0.01, real=1.41 secs] <br>
91.284: [CMS-concurrent-sweep-start]<br>
91.590: [GC 91.591: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0675550 secs]
4371287K->4128966K(6909888K), 0.0683470 secs] [Times: user=0.56
sys=0.01, real=0.07 secs] <br>
91.860: [GC 91.860: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0604320 secs]
4308368K->4053829K(6909888K), 0.0612020 secs] [Times: user=0.41
sys=0.01, real=0.06 secs] <br>
92.786: [GC 92.787: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.1028730 secs]
3964957K->3753351K(6909888K), 0.1038490 secs] [Times: user=0.80
sys=0.02, real=0.10 secs] <br>
93.106: [GC 93.107: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0487000 secs]
3949085K->3699496K(6909888K), 0.0494470 secs] [Times: user=0.32
sys=0.01, real=0.05 secs] <br>
93.371: [GC 93.371: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0430620 secs]
3905862K->3652769K(6909888K), 0.0438800 secs] [Times: user=0.33
sys=0.01, real=0.05 secs] <br>
94.637: [GC 94.638: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0564930 secs]
3416325K->3164258K(6909888K), 0.0575000 secs] [Times: user=0.44
sys=0.02, real=0.06 secs] <br>
94.863: [CMS-concurrent-sweep: 3.107/3.578 secs] [Times: user=16.85
sys=3.23, real=3.58 secs] <br>
94.863: [CMS-concurrent-reset-start]<br>
94.878: [CMS-concurrent-reset: 0.015/0.015 secs] [Times: user=0.03
sys=0.01, real=0.02 secs] <br>
95.981: [GC 95.981: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0514980 secs]
3405940K->3152334K(6909888K), 0.0524610 secs] [Times: user=0.44
sys=0.01, real=0.05 secs] <br>
100.179: [GC 100.180: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0676510 secs]
3424974K->3178150K(6909888K), 0.0686240 secs] [Times: user=0.58
sys=0.00, real=0.07 secs] <br>
100.909: [GC 100.909: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0707060 secs]
3450790K->3202638K(6909888K), 0.0717030 secs] [Times: user=0.55
sys=0.01, real=0.07 secs] <br>
101.613: [GC 101.613: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272636K->0K(274752K), 0.0667270 secs]
3475274K->3224061K(6909888K), 0.0678240 secs] [Times: user=0.50
sys=0.01, real=0.07 secs] <br>
102.072: [GC 102.073: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272635K->0K(274752K), 0.0590350 secs]
3496696K->3241246K(6909888K), 0.0601190 secs] [Times: user=0.44
sys=0.00, real=0.06 secs] <br>
102.756: [GC 102.756: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272613K->0K(274752K), 0.0630060 secs]
3513860K->3262602K(6909888K), 0.0640320 secs] [Times: user=0.49
sys=0.00, real=0.07 secs] <br>
103.452: [GC 103.453: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0533390 secs]
3535242K->3280184K(6909888K), 0.0543760 secs] [Times: user=0.41
sys=0.01, real=0.06 secs] <br>
104.462: [GC 104.462: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0729890 secs]
3552824K->3299003K(6909888K), 0.0740260 secs] [Times: user=0.48
sys=0.01, real=0.07 secs] <br>
106.274: [GC 106.274: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0609880 secs]
3571643K->3314370K(6909888K), 0.0619510 secs] [Times: user=0.41
sys=0.00, real=0.06 secs] <br>
108.154: [GC 108.155: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.1251050 secs]
3587010K->3343996K(6909888K), 0.1261630 secs] [Times: user=0.71
sys=0.02, real=0.13 secs] <br>
108.882: [GC 108.883: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0952060 secs]
3616636K->3369490K(6909888K), 0.0962930 secs] [Times: user=0.64
sys=0.01, real=0.10 secs] <br>
109.482: [GC 109.482: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272936K->0K(274752K), 0.0791270 secs]
3642426K->3392040K(6909888K), 0.0800830 secs] [Times: user=0.53
sys=0.01, real=0.08 secs] <br>
109.948: [GC 109.949: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 273038K->0K(274752K), 0.0835410 secs]
3665079K->3417813K(6909888K), 0.0845680 secs] [Times: user=0.57
sys=0.00, real=0.08 secs] <br>
110.035: [GC 110.035: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 64K->0K(274752K), 0.0088490 secs] 3417877K->3417828K(6909888K),
0.0093860 secs] [Times: user=0.09 sys=0.00, real=0.01 secs] <br>
110.484: [GC 110.485: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0880810 secs]
3690468K->3443727K(6909888K), 0.0890560 secs] [Times: user=0.59
sys=0.00, real=0.09 secs] <br>
110.910: [GC 110.910: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0860790 secs]
3716367K->3475451K(6909888K), 0.0870070 secs] [Times: user=0.58
sys=0.02, real=0.08 secs] <br>
111.276: [GC 111.277: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272639K->0K(274752K), 0.0772230 secs]
3748091K->3503686K(6909888K), 0.0782780 secs] [Times: user=0.47
sys=0.02, real=0.08 secs] <br>
111.658: [GC 111.659: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0754700 secs]
3776326K->3532682K(6909888K), 0.0763440 secs] [Times: user=0.54
sys=0.01, real=0.07 secs] <br>
112.068: [GC 112.068: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0705680 secs]
3805322K->3559619K(6909888K), 0.0714610 secs] [Times: user=0.47
sys=0.02, real=0.07 secs] <br>
112.497: [GC 112.498: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0779750 secs]
3832259K->3589461K(6909888K), 0.0788830 secs] [Times: user=0.50
sys=0.01, real=0.08 secs] <br>
112.911: [GC 112.911: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0728900 secs]
3862101K->3616744K(6909888K), 0.0738560 secs] [Times: user=0.52
sys=0.00, real=0.07 secs] <br>
113.362: [GC 113.363: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0609030 secs]
3889384K->3638477K(6909888K), 0.0619050 secs] [Times: user=0.44
sys=0.01, real=0.06 secs] <br>
113.829: [GC 113.829: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272614K->0K(274752K), 0.0641940 secs]
3911091K->3659305K(6909888K), 0.0653490 secs] [Times: user=0.48
sys=0.01, real=0.06 secs] <br>
114.311: [GC 114.311: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0618170 secs]
3931945K->3681619K(6909888K), 0.0626970 secs] [Times: user=0.50
sys=0.01, real=0.06 secs] <br>
114.841: [GC 114.842: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0670890 secs]
3954259K->3711036K(6909888K), 0.0680540 secs] [Times: user=0.52
sys=0.02, real=0.07 secs] <br>
115.356: [GC 115.357: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0623700 secs]
3983676K->3737945K(6909888K), 0.0633630 secs] [Times: user=0.49
sys=0.00, real=0.07 secs] <br>
115.829: [GC 115.830: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0665900 secs]
4010585K->3766876K(6909888K), 0.0676240 secs] [Times: user=0.51
sys=0.01, real=0.06 secs] <br>
116.271: [GC 116.271: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272630K->0K(274752K), 0.0594280 secs]
4039506K->3796861K(6909888K), 0.0603620 secs] [Times: user=0.46
sys=0.02, real=0.06 secs] <br>
116.716: [GC 116.717: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0724150 secs]
4069501K->3825191K(6909888K), 0.0733430 secs] [Times: user=0.52
sys=0.01, real=0.08 secs] <br>
117.145: [GC 117.146: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0664990 secs]
4097831K->3853057K(6909888K), 0.0675760 secs] [Times: user=0.48
sys=0.00, real=0.07 secs] <br>
117.543: [GC 117.545: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0650350 secs]
4125697K->3880562K(6909888K), 0.0673450 secs] [Times: user=0.49
sys=0.01, real=0.07 secs] <br>
117.956: [GC 117.956: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0664410 secs]
4153202K->3907935K(6909888K), 0.0673980 secs] [Times: user=0.49
sys=0.02, real=0.07 secs] <br>
118.385: [GC 118.386: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272631K->0K(274752K), 0.0655070 secs]
4180566K->3934925K(6909888K), 0.0664120 secs] [Times: user=0.50
sys=0.01, real=0.07 secs] <br>
118.826: [GC 118.827: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272608K->0K(274752K), 0.0605390 secs]
4207533K->3964211K(6909888K), 0.0616050 secs] [Times: user=0.50
sys=0.02, real=0.06 secs] <br>
119.233: [GC 119.234: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0656870 secs]
4236851K->3991065K(6909888K), 0.0666900 secs] [Times: user=0.50
sys=0.02, real=0.07 secs] <br>
119.301: [GC [1 CMS-initial-mark: 3991065K(6635136K)]
3991071K(6909888K), 0.0091650 secs] [Times: user=0.01 sys=0.00,
real=0.01 secs] <br>
119.311: [CMS-concurrent-mark-start]<br>
119.699: [GC 119.699: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0647090 secs]
4263705K->4019961K(6909888K), 0.0656290 secs] [Times: user=0.53
sys=0.01, real=0.06 secs] <br>
120.081: [GC 120.082: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0641110 secs]
4292601K->4048334K(6909888K), 0.0649070 secs] [Times: user=0.50
sys=0.01, real=0.06 secs] <br>
120.538: [GC 120.539: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0677200 secs]
4320974K->4075491K(6909888K), 0.0687990 secs] [Times: user=0.49
sys=0.03, real=0.07 secs] <br>
120.621: [CMS-concurrent-mark: 1.076/1.310 secs] [Times: user=10.66
sys=1.73, real=1.31 secs] <br>
120.621: [CMS-concurrent-preclean-start]<br>
120.942: [GC 120.943: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0736770 secs]
4348131K->4104969K(6909888K), 0.0747430 secs] [Times: user=0.51
sys=0.03, real=0.07 secs] <br>
121.337: [GC 121.338: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0569980 secs]
4377609K->4126623K(6909888K), 0.0579070 secs] [Times: user=0.48
sys=0.03, real=0.06 secs] <br>
121.766: [GC 121.767: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272615K->0K(274752K), 0.0590140 secs]
4399238K->4148770K(6909888K), 0.0599510 secs] [Times: user=0.44
sys=0.03, real=0.06 secs] <br>
122.174: [GC 122.175: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0531420 secs]
4421410K->4167895K(6909888K), 0.0540310 secs] [Times: user=0.45
sys=0.03, real=0.05 secs] <br>
122.257: [CMS-concurrent-preclean: 1.306/1.636 secs] [Times: user=10.25
sys=2.21, real=1.63 secs] <br>
122.257: [CMS-concurrent-abortable-preclean-start]<br>
122.631: [GC 122.631: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0528220 secs]
4440535K->4187654K(6909888K), 0.0537160 secs] [Times: user=0.46
sys=0.02, real=0.05 secs] <br>
122.696: [CMS-concurrent-abortable-preclean: 0.355/0.439 secs] [Times:
user=2.50 sys=0.52, real=0.44 secs] <br>
122.698: [GC[YG occupancy: 7874 K (274752 K)]122.698: [Rescan
(parallel) , 0.0253430 secs]122.723: [weak refs processing, 1.1038100
secs] [1 CMS-remark: 4187654K(6635136K)] 4195529K(6909888K), 1.1357970
secs] [Times: user=1.42 sys=0.01, real=1.14 secs] <br>
123.834: [CMS-concurrent-sweep-start]<br>
124.060: [GC 124.061: [ParNew<br>
Desired survivor size 1081344 bytes, new threshold 0 (max 0)<br>
: 272640K->0K(274752K), 0.0690300 secs]
4399395K->4167257K(6909888K), 0.0698010 secs] [Times: user=0.52
sys=0.02, real=0.07 secs] <br>
<br>
<pre wrap="">
<hr size="4" width="90%">
_______________________________________________
hotspot-gc-use mailing list
<a class="moz-txt-link-abbreviated" href="mailto:hotspot-gc-use@openjdk.java.net">hotspot-gc-use@openjdk.java.net</a>
<a class="moz-txt-link-freetext" href="http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use">http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use</a>
</pre>
</blockquote>
</body>
</html>