CMS collection keep working during holiday
Ken--@newsgroupstats.hk
dragonken at gmail.com
Thu Oct 2 05:24:53 UTC 2008
01/10 is our holiday and my stock quote application was in leisure time on
01/10.
I am surprised that during non-busy hours, my application keep draw around
15-20% cpu loading due to continueously CMS collections.
It seems that -XX:CMSInitiatingOccupancyFraction=70 will not take effect
during non-busy hours. Please find the attached memory chart from jconsole
and gc log.
jvm options:
%JAVA_HOME%\jre\bin\java -server -verbose:gc -XX:+PrintGCDetails
-Xloggc:powerserver_gc.log -showversion -Djava.security.policy=.\java.policy
-Xms4G -Xmx4G -XX:NewSize=1G -XX:+DisableExplicitGC -XX:+UseConcMarkSweepGC
-XX:+UseParNewGC -XX:SurvivorRatio=4 -XX:CMSInitiatingOccupancyFraction=70
-XX:TargetSurvivorRatio=90 -Dcom.sun.management.jmxremote.port=18002
-Dcom.sun.management.jmxremote.authenticate=false
-Dcom.sun.management.jmxremote.ssl=false
Any idea? Please advise.
http://www.nabble.com/file/p19773575/pserver-oldgen.png
http://www.nabble.com/file/p19773575/pserver-oldgen2.png
62446.219: [GC 62446.219: [ParNew: 873856K->174720K(873856K), 0.2927771
secs] 2109161K->1491505K(4019584K), 0.2928679 secs] [Times: user=1.64
sys=0.02, real=0.30 secs]
63537.932: [GC 63537.932: [ParNew: 873856K->174720K(873856K), 0.2936245
secs] 2190641K->1573411K(4019584K), 0.2937111 secs] [Times: user=1.66
sys=0.03, real=0.31 secs]
64576.245: [GC 64576.245: [ParNew: 873856K->174720K(873856K), 0.2805543
secs] 2272547K->1652492K(4019584K), 0.2806343 secs] [Times: user=1.52
sys=0.05, real=0.28 secs]
65665.444: [GC 65665.444: [ParNew: 873856K->174720K(873856K), 0.3126828
secs] 2351628K->1733865K(4019584K), 0.3127696 secs] [Times: user=1.61
sys=0.08, real=0.31 secs]
66761.009: [GC 66761.009: [ParNew: 873856K->174720K(873856K), 0.3386468
secs] 2433001K->1815987K(4019584K), 0.3387269 secs] [Times: user=1.64
sys=0.17, real=0.36 secs]
67839.979: [GC 67839.979: [ParNew: 873856K->174720K(873856K), 0.3359659
secs] 2515123K->1897775K(4019584K), 0.3360704 secs] [Times: user=1.72
sys=0.09, real=0.34 secs]
68936.295: [GC 68936.295: [ParNew: 873856K->174720K(873856K), 0.3439460
secs] 2596911K->1979557K(4019584K), 0.3440326 secs] [Times: user=1.58
sys=0.19, real=0.34 secs]
70019.873: [GC 70019.873: [ParNew: 873856K->174720K(873856K), 0.3758143
secs] 2678693K->2065201K(4019584K), 0.3759026 secs] [Times: user=1.81
sys=0.13, real=0.38 secs]
71123.565: [GC 71123.566: [ParNew: 873856K->174719K(873856K), 0.3515356
secs] 2764337K->2147170K(4019584K), 0.3516129 secs] [Times: user=1.47
sys=0.11, real=0.34 secs]
72227.180: [GC 72227.180: [ParNew: 873855K->174720K(873856K), 0.3775019
secs] 2846306K->2230692K(4019584K), 0.3775869 secs] [Times: user=1.64
sys=0.19, real=0.38 secs]
73334.657: [GC 73334.657: [ParNew: 873856K->174719K(873856K), 0.3546221
secs] 2929828K->2313182K(4019584K), 0.3547042 secs] [Times: user=1.61
sys=0.27, real=0.36 secs]
74434.184: [GC 74434.184: [ParNew: 873855K->174720K(873856K), 0.3884261
secs] 3012318K->2395247K(4019584K), 0.3885106 secs] [Times: user=1.63
sys=0.20, real=0.39 secs]
74434.573: [GC [1 CMS-initial-mark: 2220527K(3145728K)] 2396315K(4019584K),
0.2436187 secs] [Times: user=0.25 sys=0.00, real=0.23 secs]
74434.817: [CMS-concurrent-mark-start]
74437.338: [CMS-concurrent-mark: 2.521/2.521 secs] [Times: user=5.06
sys=0.16, real=2.53 secs]
74437.338: [CMS-concurrent-preclean-start]
74437.369: [CMS-concurrent-preclean: 0.031/0.031 secs] [Times: user=0.03
sys=0.00, real=0.03 secs]
74437.374: [GC[YG occupancy: 176540 K (873856 K)]74437.374: [Rescan
(parallel) , 0.1324063 secs]74437.507: [weak refs processing, 0.1494715
secs] [1 CMS-remark: 2220527K(3145728K)] 2397068K(4019584K), 0.3048030 secs]
[Times: user=0.42 sys=0.00, real=0.31 secs]
74437.694: [CMS-concurrent-sweep-start]
74438.946: [CMS-concurrent-sweep: 1.248/1.252 secs] [Times: user=2.19
sys=0.05, real=1.25 secs]
74438.946: [CMS-concurrent-reset-start]
74438.961: [CMS-concurrent-reset: 0.015/0.015 secs] [Times: user=0.02
sys=0.00, real=0.02 secs]
75525.633: [GC 75525.633: [ParNew: 873856K->174719K(873856K), 0.3452037
secs] 2940674K->2323239K(4019584K), 0.3453060 secs] [Times: user=1.73
sys=0.11, real=0.34 secs]
76628.997: [GC 76628.997: [ParNew: 873855K->174720K(873856K), 0.3680628
secs] 3022375K->2405373K(4019584K), 0.3681462 secs] [Times: user=1.88
sys=0.13, real=0.38 secs]
76629.366: [GC [1 CMS-initial-mark: 2230653K(3145728K)] 2407331K(4019584K),
0.2614019 secs] [Times: user=0.27 sys=0.00, real=0.27 secs]
76629.627: [CMS-concurrent-mark-start]
76632.373: [CMS-concurrent-mark: 2.746/2.746 secs] [Times: user=5.22
sys=0.34, real=2.75 secs]
76632.373: [CMS-concurrent-preclean-start]
76632.383: [CMS-concurrent-preclean: 0.010/0.010 secs] [Times: user=0.02
sys=0.00, real=0.02 secs]
76632.391: [GC[YG occupancy: 176683 K (873856 K)]76632.391: [Rescan
(parallel) , 0.1555281 secs]76632.546: [weak refs processing, 0.0003456
secs] [1 CMS-remark: 2230653K(3145728K)] 2407337K(4019584K), 0.1559517 secs]
[Times: user=0.36 sys=0.00, real=0.16 secs]
76632.562: [CMS-concurrent-sweep-start]
76633.784: [CMS-concurrent-sweep: 1.222/1.222 secs] [Times: user=1.31
sys=0.00, real=1.22 secs]
76633.784: [CMS-concurrent-reset-start]
76633.799: [CMS-concurrent-reset: 0.015/0.015 secs] [Times: user=0.02
sys=0.00, real=0.02 secs]
77722.107: [GC 77722.107: [ParNew: 873856K->174719K(873856K), 0.3346014
secs] 3005732K->2390264K(4019584K), 0.3346905 secs] [Times: user=1.61
sys=0.13, real=0.33 secs]
77722.442: [GC [1 CMS-initial-mark: 2215544K(3145728K)] 2391202K(4019584K),
0.2670180 secs] [Times: user=0.28 sys=0.00, real=0.28 secs]
77722.710: [CMS-concurrent-mark-start]
77725.468: [CMS-concurrent-mark: 2.758/2.758 secs] [Times: user=5.66
sys=0.11, real=2.77 secs]
77725.468: [CMS-concurrent-preclean-start]
77725.478: [CMS-concurrent-preclean: 0.010/0.011 secs] [Times: user=0.00
sys=0.00, real=0.00 secs]
77725.478: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 77730.692:
[CMS-concurrent-abortable-preclean: 0.340/5.213 secs] [Times: user=3.24
sys=0.00, real=5.22 secs]
77730.699: [GC[YG occupancy: 181794 K (873856 K)]77730.700: [Rescan
(parallel) , 0.1554305 secs]77730.855: [weak refs processing, 0.0002146
secs] [1 CMS-remark: 2215544K(3145728K)] 2397339K(4019584K), 0.1557162 secs]
[Times: user=0.27 sys=0.00, real=0.16 secs]
77730.870: [CMS-concurrent-sweep-start]
77732.117: [CMS-concurrent-sweep: 1.247/1.247 secs] [Times: user=1.26
sys=0.00, real=1.24 secs]
77732.117: [CMS-concurrent-reset-start]
77732.132: [CMS-concurrent-reset: 0.015/0.015 secs] [Times: user=0.02
sys=0.00, real=0.01 secs]
77734.136: [GC [1 CMS-initial-mark: 2208798K(3145728K)] 2392348K(4019584K),
0.2699426 secs] [Times: user=0.26 sys=0.00, real=0.27 secs]
77734.406: [CMS-concurrent-mark-start]
77737.261: [CMS-concurrent-mark: 2.851/2.856 secs] [Times: user=5.27
sys=0.34, real=2.86 secs]
77737.261: [CMS-concurrent-preclean-start]
77737.272: [CMS-concurrent-preclean: 0.010/0.010 secs] [Times: user=0.00
sys=0.00, real=0.00 secs]
77737.272: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 77742.481:
[CMS-concurrent-abortable-preclean: 0.339/5.209 secs] [Times: user=3.30
sys=0.00, real=5.22 secs]
77742.487: [GC[YG occupancy: 191586 K (873856 K)]77742.487: [Rescan
(parallel) , 0.1631453 secs]77742.651: [weak refs processing, 0.0001524
secs] [1 CMS-remark: 2208798K(3145728K)] 2400385K(4019584K), 0.1633895 secs]
[Times: user=0.28 sys=0.00, real=0.17 secs]
77742.666: [CMS-concurrent-sweep-start]
77743.864: [CMS-concurrent-sweep: 1.198/1.198 secs] [Times: user=1.22
sys=0.00, real=1.20 secs]
77743.864: [CMS-concurrent-reset-start]
77743.879: [CMS-concurrent-reset: 0.015/0.015 secs] [Times: user=0.02
sys=0.00, real=0.02 secs]
77745.883: [GC [1 CMS-initial-mark: 2203641K(3145728K)] 2398172K(4019584K),
0.2750780 secs] [Times: user=0.25 sys=0.00, real=0.27 secs]
77746.159: [CMS-concurrent-mark-start]
77748.880: [CMS-concurrent-mark: 2.721/2.721 secs] [Times: user=5.36
sys=0.09, real=2.73 secs]
77748.880: [CMS-concurrent-preclean-start]
77748.890: [CMS-concurrent-preclean: 0.010/0.010 secs] [Times: user=0.00
sys=0.00, real=0.00 secs]
77748.890: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 77754.112:
[CMS-concurrent-abortable-preclean: 0.467/5.222 secs] [Times: user=3.33
sys=0.00, real=5.23 secs]
77754.118: [GC[YG occupancy: 197250 K (873856 K)]77754.118: [Rescan
(parallel) , 0.1562518 secs]77754.274: [weak refs processing, 0.0001109
secs] [1 CMS-remark: 2203641K(3145728K)] 2400891K(4019584K), 0.1564752 secs]
[Times: user=0.36 sys=0.00, real=0.17 secs]
77754.290: [CMS-concurrent-sweep-start]
77755.425: [CMS-concurrent-sweep: 1.135/1.135 secs] [Times: user=1.14
sys=0.00, real=1.14 secs]
77755.425: [CMS-concurrent-reset-start]
77755.441: [CMS-concurrent-reset: 0.016/0.016 secs] [Times: user=0.02
sys=0.00, real=0.02 secs]
77757.445: [GC [1 CMS-initial-mark: 2203641K(3145728K)] 2405052K(4019584K),
0.2801865 secs] [Times: user=0.26 sys=0.00, real=0.28 secs]
77757.725: [CMS-concurrent-mark-start]
77760.493: [CMS-concurrent-mark: 2.768/2.768 secs] [Times: user=5.52
sys=0.11, real=2.80 secs]
77760.493: [CMS-concurrent-preclean-start]
77760.504: [CMS-concurrent-preclean: 0.010/0.010 secs] [Times: user=0.02
sys=0.00, real=0.00 secs]
77760.504: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 77765.719:
[CMS-concurrent-abortable-preclean: 0.339/5.216 secs] [Times: user=3.23
sys=0.03, real=5.22 secs]
77765.725: [GC[YG occupancy: 203843 K (873856 K)]77765.725: [Rescan
(parallel) , 0.1573253 secs]77765.883: [weak refs processing, 0.0000936
secs] [1 CMS-remark: 2203641K(3145728K)] 2407484K(4019584K), 0.1575000 secs]
[Times: user=0.38 sys=0.00, real=0.17 secs]
77765.898: [CMS-concurrent-sweep-start]
77767.132: [CMS-concurrent-sweep: 1.234/1.234 secs] [Times: user=1.25
sys=0.00, real=1.23 secs]
77767.132: [CMS-concurrent-reset-start]
77767.147: [CMS-concurrent-reset: 0.015/0.015 secs] [Times: user=0.02
sys=0.00, real=0.02 secs]
77769.151: [GC [1 CMS-initial-mark: 2203641K(3145728K)] 2409821K(4019584K),
0.2889787 secs] [Times: user=0.26 sys=0.00, real=0.28 secs]
77769.440: [CMS-concurrent-mark-start]
77772.168: [CMS-concurrent-mark: 2.728/2.728 secs] [Times: user=5.36
sys=0.13, real=2.75 secs]
77772.168: [CMS-concurrent-preclean-start]
77772.178: [CMS-concurrent-preclean: 0.010/0.010 secs] [Times: user=0.00
sys=0.00, real=0.00 secs]
77772.178: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 77777.294:
[CMS-concurrent-abortable-preclean: 0.344/5.116 secs] [Times: user=3.39
sys=0.00, real=5.13 secs]
77777.302: [GC[YG occupancy: 218737 K (873856 K)]77777.302: [Rescan
(parallel) , 0.1573837 secs]77777.460: [weak refs processing, 0.0000945
secs] [1 CMS-remark: 2203641K(3145728K)] 2422379K(4019584K), 0.1575605 secs]
[Times: user=0.39 sys=0.00, real=0.17 secs]
77777.475: [CMS-concurrent-sweep-start]
77778.609: [CMS-concurrent-sweep: 1.134/1.134 secs] [Times: user=1.14
sys=0.00, real=1.14 secs]
77778.609: [CMS-concurrent-reset-start]
77778.625: [CMS-concurrent-reset: 0.015/0.015 secs] [Times: user=0.02
sys=0.00, real=0.02 secs]
77780.628: [GC [1 CMS-initial-mark: 2203641K(3145728K)] 2424717K(4019584K),
0.2928494 secs] [Times: user=0.28 sys=0.00, real=0.30 secs]
77780.921: [CMS-concurrent-mark-start]
77783.638: [CMS-concurrent-mark: 2.717/2.717 secs] [Times: user=5.33
sys=0.13, real=2.73 secs]
77783.638: [CMS-concurrent-preclean-start]
77783.654: [CMS-concurrent-preclean: 0.016/0.016 secs] [Times: user=0.01
sys=0.00, real=0.02 secs]
77783.654: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 77788.832:
[CMS-concurrent-abortable-preclean: 0.386/5.178 secs] [Times: user=3.36
sys=0.00, real=5.19 secs]
77788.840: [GC[YG occupancy: 226606 K (873856 K)]77788.840: [Rescan
(parallel) , 0.1651500 secs]77789.005: [weak refs processing, 0.0000958
secs] [1 CMS-remark: 2203641K(3145728K)] 2430247K(4019584K), 0.1653619 secs]
[Times: user=0.30 sys=0.00, real=0.17 secs]
77789.021: [CMS-concurrent-sweep-start]
77790.051: [CMS-concurrent-sweep: 1.031/1.031 secs] [Times: user=1.05
sys=0.00, real=1.03 secs]
77790.051: [CMS-concurrent-reset-start]
77790.067: [CMS-concurrent-reset: 0.015/0.015 secs] [Times: user=0.01
sys=0.00, real=0.01 secs]
77792.070: [GC [1 CMS-initial-mark: 2203641K(3145728K)] 2430289K(4019584K),
0.2979185 secs] [Times: user=0.28 sys=0.00, real=0.30 secs]
77792.368: [CMS-concurrent-mark-start]
77795.085: [CMS-concurrent-mark: 2.717/2.717 secs] [Times: user=5.34
sys=0.20, real=2.72 secs]
77795.085: [CMS-concurrent-preclean-start]
77795.095: [CMS-concurrent-preclean: 0.010/0.010 secs] [Times: user=0.02
sys=0.00, real=0.02 secs]
77795.095: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 77800.269:
[CMS-concurrent-abortable-preclean: 0.484/5.174 secs] [Times: user=3.28
sys=0.00, real=5.17 secs]
77800.275: [GC[YG occupancy: 233897 K (873856 K)]77800.275: [Rescan
(parallel) , 0.1660870 secs]77800.442: [weak refs processing, 0.0001040
secs] [1 CMS-remark: 2203641K(3145728K)] 2437538K(4019584K), 0.1662851 secs]
[Times: user=0.31 sys=0.00, real=0.17 secs]
77800.457: [CMS-concurrent-sweep-start]
77801.459: [CMS-concurrent-sweep: 1.002/1.002 secs] [Times: user=1.06
sys=0.00, real=1.00 secs]
77801.459: [CMS-concurrent-reset-start]
77801.474: [CMS-concurrent-reset: 0.015/0.015 secs] [Times: user=0.02
sys=0.00, real=0.02 secs]
77803.477: [GC [1 CMS-initial-mark: 2203641K(3145728K)] 2438755K(4019584K),
0.3026378 secs] [Times: user=0.30 sys=0.00, real=0.30 secs]
77803.780: [CMS-concurrent-mark-start]
77806.515: [CMS-concurrent-mark: 2.735/2.735 secs] [Times: user=5.41
sys=0.11, real=2.73 secs]
77806.515: [CMS-concurrent-preclean-start]
77806.525: [CMS-concurrent-preclean: 0.010/0.010 secs] [Times: user=0.00
sys=0.00, real=0.02 secs]
77806.525: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 77811.723:
[CMS-concurrent-abortable-preclean: 0.374/5.197 secs] [Times: user=3.33
sys=0.00, real=5.22 secs]
77811.726: [GC[YG occupancy: 237551 K (873856 K)]77811.726: [Rescan
(parallel) , 0.1518526 secs]77811.878: [weak refs processing, 0.0000969
secs] [1 CMS-remark: 2203641K(3145728K)] 2441193K(4019584K), 0.1520584 secs]
[Times: user=0.38 sys=0.00, real=0.16 secs]
77811.893: [CMS-concurrent-sweep-start]
77812.890: [CMS-concurrent-sweep: 0.997/0.997 secs] [Times: user=1.08
sys=0.00, real=1.00 secs]
77812.890: [CMS-concurrent-reset-start]
77812.905: [CMS-concurrent-reset: 0.015/0.015 secs] [Times: user=0.02
sys=0.00, real=0.01 secs]
77814.909: [GC [1 CMS-initial-mark: 2203641K(3145728K)] 2445359K(4019584K),
0.3071683 secs] [Times: user=0.28 sys=0.00, real=0.30 secs]
77815.216: [CMS-concurrent-mark-start]
77817.955: [CMS-concurrent-mark: 2.739/2.739 secs] [Times: user=5.33
sys=0.13, real=2.75 secs]
77817.955: [CMS-concurrent-preclean-start]
77817.965: [CMS-concurrent-preclean: 0.010/0.010 secs] [Times: user=0.02
sys=0.00, real=0.02 secs]
77817.965: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 77823.178:
[CMS-concurrent-abortable-preclean: 0.482/5.213 secs] [Times: user=3.27
sys=0.00, real=5.20 secs]
77823.184: [GC[YG occupancy: 243681 K (873856 K)]77823.184: [Rescan
(parallel) , 0.1612718 secs]77823.345: [weak refs processing, 0.0001191
secs] [1 CMS-remark: 2203641K(3145728K)] 2447322K(4019584K), 0.1615056 secs]
[Times: user=0.31 sys=0.00, real=0.17 secs]
77823.361: [CMS-concurrent-sweep-start]
77824.356: [CMS-concurrent-sweep: 0.995/0.995 secs] [Times: user=1.08
sys=0.00, real=1.00 secs]
77824.356: [CMS-concurrent-reset-start]
77824.371: [CMS-concurrent-reset: 0.015/0.015 secs] [Times: user=0.00
sys=0.00, real=0.00 secs]
77825.194: [GC [1 CMS-initial-mark: 2203641K(3145728K)] 2449146K(4019584K),
0.3122333 secs] [Times: user=0.30 sys=0.00, real=0.31 secs]
77825.506: [CMS-concurrent-mark-start]
77828.241: [CMS-concurrent-mark: 2.735/2.735 secs] [Times: user=5.31
sys=0.17, real=2.73 secs]
77828.241: [CMS-concurrent-preclean-start]
77828.252: [CMS-concurrent-preclean: 0.010/0.010 secs] [Times: user=0.03
sys=0.00, real=0.02 secs]
77828.252: [CMS-concurrent-abortable-preclean-start]
--
View this message in context: http://www.nabble.com/CMS-collection-keep-working-during-holiday-tp19773575p19773575.html
Sent from the OpenJDK Hotspot Garbage Collection mailing list archive at Nabble.com.
More information about the hotspot-gc-dev
mailing list