K
Kieran McPeake
Hi,
I have a Solaris Java 1.4.2 server application using the following GC
settings:
-Xms800m -Xmx800m
-XX:+UseConcMarkSweepGC -XX:+CMSParallelRemarkEnabled
-XX:+UseParNewGC
-XX:+DisableExplicitGC
-XX:MaxNewSize=200m -XX:NewSize=200m
I have tried a range of other heap sizes and new ratios.
I see performance dips when CMS GCs are occurring. At the end of this
file is some trace from CMS GC collector (with the New GCs filtered out
to make it less verbose).
The above GC settings do deliver pretty high throughput without any
significant "stop the world" pauses BUT there is a noticable performance
drop coinciding with each CMS occurance. This consists of an approx 20
second CPU spike and a temporary but unacceptable increase in
latency/decrease in application responsiveness
I read e.g. at
http://java.sun.com/developer/technicalArticles/Programming/turbo/ that
CMS should work (mostly) in parallel using one thread (so I expected on
a high Spec multiprocessor Solaris box not near capacity to have enough
resources to keep handling traffic during CMS with very little degradation.
Some questions:
1)Has anyone else seen this behaviour and were you able to resolve it?
2)Has anyone used CMS on Solaris with Java 1.4.2 and Java 5 and was it
different wrt performace?
3)If you see anything odd in the GC trace below I'd welome comments
4)Any other advice?
Thanks,
Kieran
1367.560: [GC [1 CMS-initial-mark: 256358K(512000K)] 256406K(818944K),
0.0249547 secs]
1367.585: [CMS-concurrent-mark-start]
1368.760: [CMS-concurrent-mark: 1.175/1.175 secs]
1368.760: [CMS-concurrent-preclean-start]
1375.952: [CMS-concurrent-preclean: 7.164/7.192 secs]
1375.974: [GC1375.974: [Rescan (parallel) , 1.6286538 secs]1377.603:
[weak refs processing, 1.3178250 secs] [1 CMS-remark: 256358K(512000K)]
414648K(818944K), 3.2283900 secs]
1379.203: [CMS-concurrent-sweep-start]
1380.978: [CMS-concurrent-sweep: 1.654/1.774 secs]
1380.978: [CMS-concurrent-reset-start]
1381.065: [CMS-concurrent-reset: 0.087/0.087 secs]
1486.669: [GC [1 CMS-initial-mark: 257889K(512000K)] 257905K(818944K),
0.0065299 secs]
1486.676: [CMS-concurrent-mark-start]
1487.916: [CMS-concurrent-mark: 1.240/1.240 secs]
1487.916: [CMS-concurrent-preclean-start]
1491.614: [CMS-concurrent-preclean: 3.688/3.698 secs]
1491.633: [GC1491.633: [Rescan (parallel) , 0.3504421 secs]1491.984:
[weak refs processing, 0.1659178 secs] [1 CMS-remark: 257889K(512000K)]
355471K(818944K), 0.5528251 secs]
1492.187: [CMS-concurrent-sweep-start]
1494.069: [CMS-concurrent-sweep: 1.882/1.882 secs]
1494.070: [CMS-concurrent-reset-start]
1494.108: [CMS-concurrent-reset: 0.038/0.038 secs]
//Ive filtered out lines like:
//2762.262: [GC 2762.262: [ParNew: 306688K->0K(306944K), 0.0490561 secs]
//553602K->250514K(818944K), 0.0492641 secs]
I have a Solaris Java 1.4.2 server application using the following GC
settings:
-Xms800m -Xmx800m
-XX:+UseConcMarkSweepGC -XX:+CMSParallelRemarkEnabled
-XX:+UseParNewGC
-XX:+DisableExplicitGC
-XX:MaxNewSize=200m -XX:NewSize=200m
I have tried a range of other heap sizes and new ratios.
I see performance dips when CMS GCs are occurring. At the end of this
file is some trace from CMS GC collector (with the New GCs filtered out
to make it less verbose).
The above GC settings do deliver pretty high throughput without any
significant "stop the world" pauses BUT there is a noticable performance
drop coinciding with each CMS occurance. This consists of an approx 20
second CPU spike and a temporary but unacceptable increase in
latency/decrease in application responsiveness
I read e.g. at
http://java.sun.com/developer/technicalArticles/Programming/turbo/ that
CMS should work (mostly) in parallel using one thread (so I expected on
a high Spec multiprocessor Solaris box not near capacity to have enough
resources to keep handling traffic during CMS with very little degradation.
Some questions:
1)Has anyone else seen this behaviour and were you able to resolve it?
2)Has anyone used CMS on Solaris with Java 1.4.2 and Java 5 and was it
different wrt performace?
3)If you see anything odd in the GC trace below I'd welome comments
4)Any other advice?
Thanks,
Kieran
1367.560: [GC [1 CMS-initial-mark: 256358K(512000K)] 256406K(818944K),
0.0249547 secs]
1367.585: [CMS-concurrent-mark-start]
1368.760: [CMS-concurrent-mark: 1.175/1.175 secs]
1368.760: [CMS-concurrent-preclean-start]
1375.952: [CMS-concurrent-preclean: 7.164/7.192 secs]
1375.974: [GC1375.974: [Rescan (parallel) , 1.6286538 secs]1377.603:
[weak refs processing, 1.3178250 secs] [1 CMS-remark: 256358K(512000K)]
414648K(818944K), 3.2283900 secs]
1379.203: [CMS-concurrent-sweep-start]
1380.978: [CMS-concurrent-sweep: 1.654/1.774 secs]
1380.978: [CMS-concurrent-reset-start]
1381.065: [CMS-concurrent-reset: 0.087/0.087 secs]
1486.669: [GC [1 CMS-initial-mark: 257889K(512000K)] 257905K(818944K),
0.0065299 secs]
1486.676: [CMS-concurrent-mark-start]
1487.916: [CMS-concurrent-mark: 1.240/1.240 secs]
1487.916: [CMS-concurrent-preclean-start]
1491.614: [CMS-concurrent-preclean: 3.688/3.698 secs]
1491.633: [GC1491.633: [Rescan (parallel) , 0.3504421 secs]1491.984:
[weak refs processing, 0.1659178 secs] [1 CMS-remark: 257889K(512000K)]
355471K(818944K), 0.5528251 secs]
1492.187: [CMS-concurrent-sweep-start]
1494.069: [CMS-concurrent-sweep: 1.882/1.882 secs]
1494.070: [CMS-concurrent-reset-start]
1494.108: [CMS-concurrent-reset: 0.038/0.038 secs]
//Ive filtered out lines like:
//2762.262: [GC 2762.262: [ParNew: 306688K->0K(306944K), 0.0490561 secs]
//553602K->250514K(818944K), 0.0492641 secs]